Transfer on Mega in FTP mode is not working

What is the problem you are having with rclone?

I'm trying to use mega (FTP) and crypt for uploading a file. The issue is that I got this error.

ERROR : Attempt 3/3 failed with 1 errors and: update stor: 250 Requested file action okay, completed.

The file is not on my mega account but what is strange is that I see an upload if I check mega-transfers

What is your rclone version (output from rclone version)

rclone v1.55.1
- os/type: linux
- os/arch: amd64
- go/version: go1.16.3
- go/linking: static
- go/tags: none

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Debian GNU/Linux 9.9 (stretch)

Which cloud storage system are you using? (eg Google Drive)

Mega (FTP) with Crypt in rclone

The command you were trying to run (eg rclone copy /tmp remote:tmp)

rclone copy -P /media/a/b.mp4 mega-crypt-ftp:/SYNC/a/b/c/d/e/ --log-file log.log

The rclone config contents with secrets removed.

[mega-ftp]
type = ftp
host = 127.0.0.1
port = 4990
pass = x

[mega-crypt-ftp]
type = crypt
remote = mega-ftp:/y/z/
filename_encryption = standard
password = x
password2 = x

A log from the command with the -vv flag

2021/06/02 18:25:30 DEBUG : Using config file from "/home/user/.config/rclone/rclone.conf"
2021/06/02 18:25:30 DEBUG : rclone: Version "v1.55.1" starting with parameters ["rclone" "copy" "-P" "/media/a/b.mp4" "mega-crypt-ftp:/SYNC/a/b/c/d/e/" "--log-file" "log.log" "-vv"]
2021/06/02 18:25:30 DEBUG : Creating backend with remote "/media/a/b.mp4"
2021/06/02 18:25:30 DEBUG : fs cache: adding new entry for parent of "/media/a/b.mp4", "/media/a"
2021/06/02 18:25:30 DEBUG : Creating backend with remote "mega-crypt-ftp:/SYNC/a/b/c/d/e/"
2021/06/02 18:25:30 DEBUG : Creating backend with remote "mega-ftp:/y/z/c/b/a/d/e/f"
2021/06/02 18:25:30 DEBUG : ftp://127.0.0.1:4990/y/z/c/b/a/d/e/f: Connecting to FTP server
2021/06/02 18:25:30 DEBUG : b.mp4: Need to transfer - File not found at Destination
2021/06/02 18:37:50 DEBUG : ftp://127.0.0.1:4990/y/z/c/b/a/d/e/f: Connecting to FTP server
2021/06/02 18:37:50 DEBUG : ttt: Removed after failed upload: 250 Requested file action okay, completed.
2021/06/02 18:37:50 ERROR : b.mp4: Failed to copy: update stor: 250 Requested file action okay, completed.
2021/06/02 18:37:50 ERROR : Attempt 1/3 failed with 1 errors and: update stor: 250 Requested file action okay, completed.
2021/06/02 18:37:50 DEBUG : b.mp4: Need to transfer - File not found at Destination
2021/06/02 18:49:57 DEBUG : ftp://127.0.0.1:4990/y/z/c/b/a/d/e/f: Connecting to FTP server
2021/06/02 18:49:57 DEBUG : ttt: Removed after failed upload: 250 Requested file action okay, completed.
2021/06/02 18:49:57 ERROR : b.mp4: Failed to copy: update stor: 250 Requested file action okay, completed.
2021/06/02 18:49:57 ERROR : Attempt 2/3 failed with 1 errors and: update stor: 250 Requested file action okay, completed.
2021/06/02 18:49:57 DEBUG : b.mp4: Need to transfer - File not found at Destination
2021/06/02 19:03:03 DEBUG : ftp://127.0.0.1:4990/y/z/c/b/a/d/e/f: Connecting to FTP server
2021/06/02 19:03:03 DEBUG : ttt: Removed after failed upload: 250 Requested file action okay, completed.
2021/06/02 19:03:03 ERROR : b.mp4: Failed to copy: update stor: 250 Requested file action okay, completed.
2021/06/02 19:03:03 ERROR : Attempt 3/3 failed with 1 errors and: update stor: 250 Requested file action okay, completed.
2021/06/02 19:03:03 INFO  :
Transferred:        4.399G / 4.399 GBytes, 100%, 2.000 MBytes/s, ETA 0s
Errors:                 1 (retrying may help)
Elapsed time:     37m33.0s

2021/06/02 19:03:03 DEBUG : 3 go routines active
2021/06/02 19:03:03 Failed to copy: update stor: 250 Requested file action okay, completed.

My configuration looks right because I can use rclone ls, rclone lsd or rclone mount correctly.
If there are other test needed don't hesitate to ask.

hello,
please post the full debug log

Hello,

I have updated the command and the debug log to reflect the amount of folder I use too.
I have replaced all the filenames and folder I hope it's not a problem.

i do not use mega and would never use ftp.

now that we have a debug log, perhaps somebody else can comment.

The reason of using FTP is because the webdav of mega is "limited".

They got an overflow security at 2MB and advice that if the webdav must send more than 2MB data it's maybe not the good method but I didn't get an answer if FTP would be better or not.

The github issue for reference is WEBdav buffer overflow with folders with many files · Issue #507 · meganz/MEGAcmd · GitHub

I tried debugging a bit more and I see that rclone is removing the file

2021/06/02 19:03:03 DEBUG : ttt: Removed after failed upload: 250 Requested file action okay, completed.

Is there a way to tell to rclone of not removing the file in case there is an error. Maybe 250 code is seeing a something bad when it's good?

An example on how use goftp library showed this code

c, err := ftp.Dial(Server)
data := bytes.NewBufferString("Hello World")
err = c.Stor(BasePath + "/" + "test-file.txt", data)
if err != nil {
        panic(err)
}

And when I try to use it with some difficulties it showed 250 as an error, maybe that could be the issue?

Not currently.

I am thinking of changing rclone so it doesn't do that. It is "mostly" the right thing to do, but sometimes isn't.

Try this and see if it helps

v1.56.0-beta.5552.e3a77f218.fix-no-remove-error on branch fix-no-remove-error (uploaded in 15-30 mins)

Hello

Thanks I give it a try without "crypt" this time so the log will be easier to read
I got some rclone variables but I not think they could make some issues

$RCLONE_IMMUTABLE 
$RCLONE_INTERACTIVE  
$RCLONE_PROGRESS     
$RCLONE_TIMEOUT      
$RCLONE_TRANSFERS
$ RCLONE_INTERACTIVE=0 rclone copy current.ip mega-test:/ --retries 1 --low-level-retries 1 -vv --dump-bodies
2021/06/16 14:29:12 NOTICE: --dump-bodies is obsolete - please use --dump bodies instead
2021/06/16 14:29:12 DEBUG : rclone: Version "v1.56.0-beta.5552.e3a77f218.fix-no-remove-error" starting with parameters ["rclone" "copy" "current.ip" "mega-test:/" "--retries" "1" "--low-level-retries" "1" "-vv" "--dump-bodies"]
2021/06/16 14:29:12 DEBUG : Creating backend with remote "current.ip"
2021/06/16 14:29:12 DEBUG : Using config file from "/home/user/.config/rclone/rclone.conf"
2021/06/16 14:29:12 DEBUG : fs cache: adding new entry for parent of "current.ip", "/home/user"
2021/06/16 14:29:12 DEBUG : Creating backend with remote "mega-test:/"
2021/06/16 14:29:12 DEBUG : Creating backend with remote "mega-ftp:/sdfize/folder/TEST"
2021/06/16 14:29:12 DEBUG : ftp://127.0.0.1:4990/sdfize/folder/TEST: Connecting to FTP server
2021/06/16 14:29:12 DEBUG : FTP Rx: "220 Wellcome to FTP MEGA Server"
2021/06/16 14:29:12 DEBUG : FTP Tx: "USER anonymous"
2021/06/16 14:29:12 DEBUG : FTP Rx: "331 User name okay, need password"
2021/06/16 14:29:12 DEBUG : FTP Tx: PASS *****
2021/06/16 14:29:12 DEBUG : FTP Rx: "230 User logged in, proceed"
2021/06/16 14:29:12 DEBUG : FTP Tx: "FEAT"        
2021/06/16 14:29:12 DEBUG : FTP Rx: "211-Features:"
2021/06/16 14:29:12 DEBUG : FTP Rx: " SIZE"
2021/06/16 14:29:12 DEBUG : FTP Rx: " PROT"                                        
2021/06/16 14:29:12 DEBUG : FTP Rx: " EPSV"                              
2021/06/16 14:29:12 DEBUG : FTP Rx: " PBSZ"                               
2021/06/16 14:29:12 DEBUG : FTP Rx: " UTF8 ON"                                                      
2021/06/16 14:29:12 DEBUG : FTP Rx: "211 End"                                       
2021/06/16 14:29:12 DEBUG : FTP Tx: "TYPE I"                                    
2021/06/16 14:29:12 DEBUG : FTP Rx: "200 OK"                                                                   
2021/06/16 14:29:12 DEBUG : FTP Tx: "OPTS UTF8 ON"                                                             
2021/06/16 14:29:12 DEBUG : FTP Rx: "200 All good"                                                                       
2021/06/16 14:29:12 DEBUG : FTP Tx: "EPSV"
2021/06/16 14:29:12 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||1507|)"
2021/06/16 14:29:12 DEBUG : FTP Tx: "LIST /sdfize/folder"
2021/06/16 14:29:12 DEBUG : FTP Rx: "150 Here comes the directory listing"
2021/06/16 14:29:12 DEBUG : FTP Rx: "226 Closing data connection. Requested file action successful."
2021/06/16 14:29:12 DEBUG : fs cache: renaming cache item "mega-test:/" to be canonical "mega-ftp:/sdfize/folder/TEST"
2021/06/16 14:29:12 DEBUG : FTP Tx: "EPSV"                                                 
2021/06/16 14:29:12 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||1507|)"                            
2021/06/16 14:29:12 DEBUG : FTP Tx: "LIST /sdfize/folder/TEST"
2021/06/16 14:29:12 DEBUG : FTP Rx: "150 Here comes the directory listing"
2021/06/16 14:29:12 DEBUG : FTP Rx: "226 Closing data connection. Requested file action successful."
2021/06/16 14:29:13 DEBUG : FTP Tx: "EPSV"                                              
2021/06/16 14:29:13 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||1507|)"
2021/06/16 14:29:13 DEBUG : FTP Tx: "STOR /sdfize/folder/TEST/current.ip"
2021/06/16 14:29:13 DEBUG : FTP Rx: "150 Opening data connection for storing /sdfize/folder/TEST/current.ip"
2021/06/16 14:29:13 DEBUG : FTP Rx: "250 Requested file action okay, completed."
2021/06/16 14:29:13 DEBUG : FTP Tx: "QUIT"      
2021/06/16 14:29:14 DEBUG : ftp://127.0.0.1:4990/sdfize/folder/TEST: Connecting to FTP server
2021/06/16 14:29:14 DEBUG : FTP Rx: "220 Wellcome to FTP MEGA Server"
2021/06/16 14:29:14 DEBUG : FTP Tx: "USER anonymous"                                                                                                                                         
2021/06/16 14:29:14 DEBUG : FTP Rx: "331 User name okay, need password"                 
2021/06/16 14:29:14 DEBUG : FTP Tx: PASS *****                                                                                                                                                                                     
2021/06/16 14:29:14 DEBUG : FTP Rx: "230 User logged in, proceed"    
2021/06/16 14:29:14 DEBUG : FTP Tx: "FEAT"                                                                                                         
2021/06/16 14:29:14 DEBUG : FTP Rx: "211-Features:"                                                                                                     
2021/06/16 14:29:14 DEBUG : FTP Rx: " SIZE"                           
2021/06/16 14:29:14 DEBUG : FTP Rx: " PROT"                                                       
2021/06/16 14:29:14 DEBUG : FTP Rx: " EPSV"                                                             
2021/06/16 14:29:14 DEBUG : FTP Rx: " PBSZ"                          
2021/06/16 14:29:14 DEBUG : FTP Rx: " UTF8 ON"      
2021/06/16 14:29:14 DEBUG : FTP Rx: "211 End"                          
2021/06/16 14:29:14 DEBUG : FTP Tx: "TYPE I"  
2021/06/16 14:29:14 DEBUG : FTP Rx: "200 OK"                     
2021/06/16 14:29:14 DEBUG : FTP Tx: "OPTS UTF8 ON"
2021/06/16 14:29:14 DEBUG : FTP Rx: "200 All good" 
2021/06/16 14:29:14 DEBUG : FTP Tx: "EPSV" 
2021/06/16 14:29:14 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||1508|)"
2021/06/16 14:29:14 DEBUG : FTP Tx: "LIST /sdfize/folder/TEST"
2021/06/16 14:29:14 DEBUG : FTP Rx: "150 Here comes the directory listing"
2021/06/16 14:29:14 DEBUG : FTP Rx: "226 Closing data connection. Requested file action successful."
2021/06/16 14:29:14 DEBUG : FTP Tx: "DELE /sdfize/folder/TEST/current.ip"
2021/06/16 14:29:15 DEBUG : FTP Rx: "250 Requested file action okay, completed."
2021/06/16 14:29:15 DEBUG : current.ip: Removed after failed upload: 250 Requested file action okay, completed.
2021/06/16 14:29:15 ERROR : current.ip: Failed to copy: update stor: 250 Requested file action okay, completed.
2021/06/16 14:29:15 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 250 Requested file action okay, completed.
2021/06/16 14:29:15 INFO  :               
Transferred:             14 / 14 Byte, 100%, 6 Byte/s, ETA 0s                      
Errors:                 1 (retrying may help)                       
Elapsed time:         2.4s                                                
                                                                                                    
2021/06/16 14:29:15 DEBUG : 2 go routines active                                                                                 
2021/06/16 14:29:15 Failed to copy: update stor: 250 Requested file action okay, completed.
$ mega-ls folder/TEST/
folder/TEST/:                                                   
test-file.txt                                                             

It looks like the DELE it's stil here

Hmm, I think that is the wrong approach.

That 250 error does look odd, I agree. I don't think it should be returning a 250 but let's try ignoring it and see if that works

v1.56.0-beta.5552.71faa1b0c.fix-ftp-upload on branch fix-ftp-upload (uploaded in 15-30 mins)

Thanks, I will try in about 30min

If it works I will ping Mega to know if it's expected because it's true that the library also see it has an error. It's kinda.. weird ^^

Thanks @ncw it is a victory!! ^^

It's working I tested my copy command without and with crypt now I will go see a bit with mega about it before closing here in case they can explain why 250

Great, glad it is working.

I'd feel happy putting that patch into rclone, but if you can get an explanation from Mega - even better!

I've merged this to master now which means it will be in the latest beta in 15-30 minutes and released in v1.56

Thanks

Mega didn't really answered just "do an issue on github"... So I did it yesterday if in a little week I have no answer I will mail the support again so that maybe it will hurry the developers to give an answer.

1 Like

Hi @ncw

I got an answer on the github issue.
It's a valid answer in a RFC.

Thanks for digging into that. I'm happy with the change - it shouldn't affect anything else and if it agrees with the RFC - even better!