Uploads start repeatedly failing after a while using rc sync/copy vs rclone copy for Dropbox

Help and Support
1

I could really use some help on figuring out where I went wrong here or how to troubleshoot further. I only started using rclone rc sync/copy or move recently for copies/moves as I wanted to convert some of the metrics or core/stats into a visual dashboard. I have been successfully using it to mount a drive in past without any problems though.

What is the problem you are having with rclone?

While doing a normal 'rclone copy' to a crypt on dropbox it works without any problems, it's not the same case when starting rclone rcd (command's below) and launching a copy from a local drive or even google drive to a dropbox crypt using rclone rc. I have tried to do the uploads both with or without the crypt to eliminate the issue as well. It has the same issue which I believe is Dropbox related. What happens is that when rclone rc sync/copy is launched that some of my files are successfully transferred at first (usually varies from 1-70files and around 1-10gb), and the later transfers start repeatedly failing till (I restart rcd). I have around 5 app keys created for Dropbox and am using these for different tests. The error I usually see appear when rc sync/copy fails is and the command ends is:

2023/06/09 02:06:19 Failed to rc: failed to read rc response: 500 Internal Server Error: {
        "error": "upload failed: batcher is shutting down",
        "input": {
                "deleteEmptySrcDirs": "true",
                "dstFs": "dbcm40:TEST",
                "srcFs": "/sbx/mnt/remotes/AXUNION/a-anime-1/"
        },
        "path": "sync/copy",
        "status": 500
}

Run the command 'rclone version' and share the full output of the command.

I have tried a few versions so far and compiled it from source the last time. I also tried it inside an alpine container. This was last:

rclone v1.63.0-DEV
- os/version: ubuntu 20.04 (64 bit)
- os/kernel: 5.4.0-144-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.20.5
- go/linking: static
- go/tags: none

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

Dropbox (crypt)

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

OK - This command works without any hiccups for me:

rclone copy "$SRC" "$DST:"   --transfers=4 --buffer-size=32M --tpslimit-burst=0 --tpslimit=12 -vP

NOK - This is how I setup my rcd, the options are all done separate as I was testing with disabling them one by one. If needed I can send my options/get, but these should be all the settings I change from default and when checking all of these were set as I wanted.

rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"LogLevel": INFO}}'
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"DisableHTTP2": true}}'   
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"filter": {"ExcludeFrom": ["/data/exclude.filter"]}}'  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"TPSLimit": 12}}'  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"TPSLimitBurst": 0}}'  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"ServerSideAcrossConfigs": true}}'  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"SizeOnly": true}}'  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"main": {"Transfers": 4}}’  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS options/set --json '{"filter": {"MinAge": "60"}}'  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics  --rc-user $USER --rc-pass $PASS core/bwlimit rate=“off”  
rclone rc --rc-addr "$IP:59999" --rc-enable-metrics --rc-user $USER --rc-pass $PASS sync/copy srcFs="$SRC" dstFs="$DST" deleteEmptySrcDirs=true --log-file "$filelog"

The rclone config contents with secrets removed.

[dbcm40]
type = crypt
remote = dbm40:/Backup/ritualist
password = ***
password2 = ***
filename_encryption = obfuscate

[dbm40]
type = dropbox
client_id = ***
client_secret = ***
token = ***

A log from the command with the -vv flag

...
2023/06/09 01:02:43 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - 10 [1080p].mkv: Copied (new)
2023/06/09 01:02:44 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - 13 [1080p].mkv: Copied (new)
2023/06/09 01:02:57 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - 12 [1080p].mkv: Copied (new)
2023/06/09 01:03:04 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 01 [1080p].mkv: Copied (new)
2023/06/09 01:03:12 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 02 [1080p].mkv: Copied (new)
2023/06/09 01:03:15 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 03 [1080p].mkv: Copied (new)
2023/06/09 01:03:34 INFO  : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 04 [1080p].mkv: Copied (new)
#Here after 40 transfers it started to fail
2023/06/09 01:04:10 ERROR : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 07 [1080p].mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:04:23 ERROR : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 08 [1080p].mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:04:35 INFO  : Dropbox root 'Backup/ritualist/64.sdrs': Commiting uploads - please wait...
2023/06/09 01:04:36 ERROR : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 06 [1080p].mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:04:38 ERROR : XDCC/XDCC-Arutha/3-Nen D-Gumi Glass no Kamen/[HorribleSubs] K - Return of Kings - 05 [1080p].mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:04:38 ERROR : rc: "sync/copy": error: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:12:46 ERROR : XDCC/XDCC-Thora/Appleseed_(2004)_[720p,HDTV,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: batcher is shutting down
2023/06/09 01:12:46 ERROR : Cancelling sync due to fatal error: upload failed: batcher is shutting down
2023/06/09 01:13:08 ERROR : XDCC/XDCC-Thora/Afro_Samurai_Resurrection_(2009)_[1080p,BluRay,x264]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:13:24 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[1080p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:13:30 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[720p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:13:30 ERROR : rc: "sync/copy": error: upload failed: batcher is shutting down
2023/06/09 01:21:46 ERROR : XDCC/XDCC-Thora/Appleseed_(2004)_[720p,HDTV,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: batcher is shutting down
2023/06/09 01:21:46 ERROR : Cancelling sync due to fatal error: upload failed: batcher is shutting down
2023/06/09 01:22:02 ERROR : XDCC/XDCC-Thora/Afro_Samurai_Resurrection_(2009)_[1080p,BluRay,x264]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:22:28 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[720p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:22:32 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[1080p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:22:32 ERROR : rc: "sync/copy": error: upload failed: batcher is shutting down

#rclone rc sync/copy was relaunched 3rd time here. It gives 'Failed to rc: connection failed: Post "http://100.72.154.112:59999/sync/copy": net/http: timeout awaiting response headers"' error in cli in that case and ends.

2023/06/09 01:31:08 ERROR : XDCC/XDCC-Thora/Appleseed_(2004)_[720p,HDTV,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: batcher is shutting down
2023/06/09 01:31:08 ERROR : Cancelling sync due to fatal error: upload failed: batcher is shutting down
2023/06/09 01:31:36 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[720p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:31:48 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[1080p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:31:52 ERROR : XDCC/XDCC-Thora/Afro_Samurai_Resurrection_(2009)_[1080p,BluRay,x264]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/09 01:31:52 ERROR : rc: "sync/copy": error: upload failed: batcher is shutting down

Any tips or guidance is appreciated

2

Given that rclone copy works I would think that for some reason rc does not use all set options correctly and as it is with Dropbox API limits are reached and uploads fail.

I would try passing flags using _config, e.g.:

rclone rc sync/copy ... _config='{"TPSLimit": 12}' _config='{"TPSLimitBurst": 0}'  _config='{"Transfers": 4}'

Other thing is that long running rc jobs should be run with the _async flag, as explained in docs

3

Thanks for the tip with _async. This is indeed a rather big copy/move job with over 1k files at least. Reading about the timeout errors I thought it would be the solution for sure, but sadly I still got the same results. I tried adjusting the commands (like below) but without any changes. What I did notice is that core/stats reports upload progress continuing and the files only fail at the very end.

rclone rc --rc-addr "$IP:59999" --rc-enable-metrics --rc-user $USER --rc-pass $PASS sync/copy srcFs="$SRC" dstFs="$DST" deleteE
mptySrcDirs=true --log-file "$filelog" _async=true  _config='{"TPSLimit": 12}' _config='{"TPSLimitBurst": 0}'  _config='{"Transfers": 4
}'  _async=true

Here one of core/stats before the file was "done" uploading

rclone rc core/stats  --rc-addr "$IP:59999" --rc-user $USER --rc-pass $PASS
... 
              {
                        "bytes": 7021062267,
                        "eta": null,
                        "group": "job/8449",
                        "name": "XDCC/XDCC-Thora/Appleseed_Ex_Machina_(2007)_[1080p,BluRay,x264]_-_THORA.mkv",
                        "percentage": 100,
                        "size": 7019348523,
                        "speed": 19230689.004250024,
                        "speedAvg": 15068548.31695426
                }
        ],
        "transfers": 1
}


cat /data/transfers.log | tail -3
2023/06/09 19:50:22 ERROR : XDCC/XDCC-Thora/Appleseed_Ex_Machina_(2007)_[1080p,BluRay,x264]_-_THORA.mkv: Failed to copy: upload failed: batcher is shutting down
2023/06/09 19:50:22 ERROR : Cancelling sync due to fatal error: upload failed: batcher is shutting down
2023/06/09 19:50:47 ERROR : XDCC/XDCC-Thora/Akira_(1988)_[1080p,BluRay,x264,DTS]_-_THORA.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
4

OK I have no clue - but as you said that rclone copy works so there is some problem with rc. But I am not sure how we can debug it with more details:)

5

@ncw may I ask you to have a look at this issue? We can not figure out why rc sync/copy fails when the same rclone copy works

6

This error has a different cause. It means the dropbox backend has fallen out of the backend cache before the operation has completed.

I have figured out the problem - it is to do with the lifetimes of the backends when called via the rc

Try this

v1.63.0-beta.7067.4211af95e.fix-rc-backend-shutdown on branch fix-rc-backend-shutdown (uploaded in 15-30 mins)

1 Like
7

Sorry that one didn't build properly, try this one instead

v1.63.0-beta.7067.7a3c16553.fix-rc-backend-shutdown on branch fix-rc-backend-shutdown (uploaded in 15-30 mins)

8

First of all huge thanks, I just tried this and it looks way better. I still got a few errors (12/300files), but I don't think they are related to base of this issue. I'll keep testing further this night.

2023/06/12 20:17:43 ERROR : Hylia/Kami-sama Minarai_ Himitsu no Cocotama/Kami-sama Minarai_ Himitsu no Cocotama Episode 23.mkv: Failed to copy: context canceled
2023/06/12 20:17:43 ERROR : Hylia/Kami-sama Minarai_ Himitsu no Cocotama/Kami-sama Minarai_ Himitsu no Cocotama Episode 20.mkv: Failed to copy: context canceled
2023/06/12 20:17:54 ERROR : Hylia/Kami-sama Minarai_ Himitsu no Cocotama/Kami-sama Minarai_ Himitsu no Cocotama Episode 22.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/12 20:18:00 ERROR : Hylia/Kami-sama Minarai_ Himitsu no Cocotama/Kami-sama Minarai_ Himitsu no Cocotama Episode 24.mkv: Failed to copy: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled
2023/06/12 20:18:00 ERROR : rc: "sync/copy": error: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": context canceled

In retrospect, 'when' it fails it does look like 4 transfers fail all at once at once. I'll have to verify either it happens during a normal copy too though and is some gift from dropbox.

9

That is great!

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

Hmm, context canceled errors are when an internal part of rclone cancels a transfer or a job. For example when an rc job finishes all the things which depended on it will be cancelled.

It would be nice to see the lines before that context canceled error - maybe there is a clue there.

10

i updated to the latest beta and i can share some logs in case the latest beta didnt fix it since am still testing

11

Logs would be good - thanks!

12

Sorry for the long delay, as it's summer I tried to run away from my problems. I updated to the rclone 1.64 version today, but in my case the error seemed worse.
failing-on-1.64.txt (98.3 KB)

From what I remember by now the previous fixed 1.63 version had better results with failures only 10% of the time. I'll track it and post logs for it as well for anyone still interested and post it here in a bit

PS. Found it but to my surprise it gave me similar results as all transfers seemed to fail. To confirm that dropbox is not blocking me atm I also started a normal copy, but it succeeds without a problem.
failing-on1-.63.txt (156.9 KB)

13

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.