Dropbox rclone mount Error messages?

Thunder · August 14, 2022, 12:17pm

Hello Guys, I changed my rclone mount config now to this one here:

[Service]
User=sbuser
Group=sbuser
Type=notify
ExecStartPre=/bin/sleep 10
ExecStart=/usr/bin/rclone mount \
  --user-agent='Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.131 Safari/537.36' \
  --config=/home/sbuser/.config/rclone/rclone.conf \
  --allow-other \
  --allow-non-empty \
  --rc \
  --rc-no-auth \
  --rc-addr=localhost:5572 \
  --vfs-read-chunk-size=64M \
  --vfs-read-chunk-size-limit=2048M \
  --buffer-size=64M \
  --poll-interval=15s \
  --dir-cache-time=1000h \
  --timeout=10m \
  --dropbox-chunk-size=64M \
  --tpslimit=12 \
  --tpslimit-burst=12 \
  --disable-http2 \
  --bind=SERVER_IP \
  --umask=002 \
  --log-file=/opt/rclone/rclone_vfs.log \
  -v \
  DB: /mnt/remote
ExecStartPost=/usr/bin/rclone rc vfs/refresh recursive=true --rc-addr localhost:5572 _async=true
ExecStop=/bin/fusermount -uz /mnt/remote
Restart=on-abort
RestartSec=5
StartLimitInterval=60s
StartLimitBurst=3

I still get those error message quite frequently:

2022/08/14 12:04:46 INFO  : Dropbox root '': Change notify listener failure: upstream request timeout
2022/08/14 12:17:07 INFO  : Dropbox root '': Change notify listener failure: upstream request timeout
2022/08/14 12:25:28 INFO  : Dropbox root '': Change notify listener failure: upstream request timeout
2022/08/14 12:29:34 INFO  : Dropbox root '': Change notify listener failure: upstream request timeout
2022/08/14 12:40:05 INFO  : Dropbox root '': Change notify listener failure: upstream request timeout

I checked the network etc , i do not have any proxy running here .

the DB: remote is a union of 2 crypted Dropbox remotes .
Rclone mount is running directly on the server as service at startup.
I even disabled the cloudflare proxy (which wasnt used for rclone connections anyway) .

Nothing helps.

Also I think that this is somehow impacting performance.
When I open Video Files in Plex it takes 5-10 Seconds versus 2-3 Seconds on Google. When I Fast forward or rewind it takes 3-6 Seconds to continue Playback versus 1-2 in google.
Any suggestions?

Also I encountered something when uploading to Dropbox:
I upload multiple Files at once and sometimes my rclone throws some errors after startup like these:

2022-08-14 13:34:00,282 - INFO       - process              - execute                        - 2022/08/14 13:34:00 INFO  : Starting transaction limiter: max 12 transactions/s with burst 12
2022-08-14 13:34:07,872 - INFO       - process              - execute                        - 2022/08/14 13:34:07 ERROR : TV/TV4K/The Wheel of Time/Season 1/The Wheel of Time (2021) - S01E05 - Blood Calls Blood [WEBDL-2160p][HDR10Plus][EAC3 5.1][DE+EN][h265]-w4k.mkv: Failed to copy: 1 error: db-tv-crypt: path/conflict/folder/.
2022-08-14 13:34:07,872 - INFO       - process              - execute                        - 2022/08/14 13:34:07 ERROR : TV/TV4K/The Wheel of Time/Season 1/The Wheel of Time (2021) - S01E05 - Blood Calls Blood [WEBDL-2160p][HDR10Plus][EAC3 5.1][DE+EN][h265]-w4k.mkv: Not deleting source as copy failed: 1 error: db-tv-crypt: path/conflict/folder/.

It happens only when rclone tries to upload multiple Files to a new Folder, like a new series just added.
For example if rclone is trying to upload 5 Episodes at the same time (so basically this will happen only at start of uploading, because only then it starts uploads at exact same time) one of them will work and the others will throw the error above.
When i execute upload command again, even those files are uploaded.

Animosity022 · August 14, 2022, 12:34pm

If @ncw is sure that isn't a rclone message, that would be the thing that I try to figure out as that's something in the middle timing things out / blocking something.

That's from a rclone debug log as well? I've never seen that nor have any idea what that would be.

Thunder · August 14, 2022, 1:49pm

I dont know what else I could have a look on... I disabled everything what could be "in the middle". There is nothing left.

There is Ubuntu 22.04, with installed rclone which mounts a Dropbox mount. directly. without anything between.

For uploading i use cloudplow which utilizes rclone for uploading : GitHub - l3uddz/cloudplow: Automatic rclone remote uploader, with support for multiple remote/folder pairings. UnionFS Cleaner functionality: Deletion of UnionFS whiteout files and their corresponding files on rclone remotes. Automatic remote syncer: Sync between different remotes via a Scaleway server instance, that is created and destroyed at every sync.

So just forget about the first part in the error message. The important error is after the "ERROR: " Word

Also strange is , After Dropbox Root '' there should be the name of the Dropbox root like in this Message:

Dropbox root 'uj4cklee8ft58j45ajfeug2es': Commiting uploads - please wait...

So it seems that It cannot detect the Dropbox root for some case?

Animosity022 · August 14, 2022, 2:19pm

Is it a home built thing? Rented VPS? Rented dedicated?

I'm not sure what you mean by this.

Snippets are super tough to answer as there's no context around it to be sure. Can you share a full log?

Thunder · August 15, 2022, 9:37am

Its a rented Dedicated Hetzner Server.

The rclone Error is this thing:

2022/08/14 13:34:07 ERROR : TV/TV4K/The Wheel of Time/Season 1/The Wheel of Time (2021) - S01E05 - Blood Calls Blood [WEBDL-2160p][HDR10Plus][EAC3 5.1][DE+EN][h265]-w4k.mkv: Failed to copy: 1 error: db-tv-crypt: path/conflict/folder/.

The Part before this is from cloudplow which calls rclone for uploads.

With the "commiting uploads " Message is just wanted to point out how the "Dropbox root" message usually looks for example when uploading:

 Checking:
 Transferring:
 * Movies/Movies4K/Avatar… MA 5.1][x265]-QfG.mkv: 99% /77.198Gi, 21.103Mi/s, 15s
 <6>INFO  : Movies/Movies4K/Avatar (2009)/Avatar (2009) Extended Cut [imdb-tt0499549][WEBDL-2160p][PQ][DTS-HD MA 5.1][x265]-QfG.mkv: Copied (new)
 <6>INFO  : Movies/Movies4K/Avatar (2009)/Avatar (2009) Extended Cut [imdb-tt0499549][WEBDL-2160p][PQ][DTS-HD MA 5.1][x265]-QfG.mkv: Deleted
 <3>ERROR : Attempt 1/1 failed with 2 errors and: 1 error: db-movies-crypt: too_many_write_operations/.
 <6>INFO  :
 Transferred:       201.255 GiB / 201.255 GiB, 100%, 3.412 MiB/s, ETA 0s
 Errors:                 2 (retrying may help)
 Checks:                18 / 18, 100%
 Deleted:                8 (files), 0 (dirs)
 Renamed:                8
 Transferred:            8 / 8, 100%
 Elapsed time:    1h3m46.9s
 <6>INFO  : Dropbox root 'uj4cklee8ft58j45ajfeug2es': Commiting uploads - please wait...
 <6>INFO  : Dropbox root 'uj4cklee8ft58j45ajfeug2es': Commiting uploads - please wait...

Between the Brackets is some client ID or similar.
Versus the message i get when i look at the logfile of the mount:

INFO  : Dropbox root '': Change notify listener failure: upstream request timeout

Animosity022 · August 15, 2022, 11:26am

That means you are getting rate limited and should stick within ~12 TPS per second.

That's still just a snippet of a log. You'd need to share the full rclone command.

I don't use / nor am I familiar with cloudplow on what it does or how it executes rclone commands.

The goal for me is to see the full rclone command being executed with a full debug log.

rclone copy /etc/hosts DB: -vvv
2022/08/15 07:23:41 DEBUG : Setting --config "/opt/rclone/rclone.conf" from environment variable RCLONE_CONFIG="/opt/rclone/rclone.conf"
2022/08/15 07:23:41 DEBUG : rclone: Version "v1.59.1" starting with parameters ["rclone" "copy" "/etc/hosts" "DB:" "-vvv"]
2022/08/15 07:23:41 DEBUG : Creating backend with remote "/etc/hosts"
2022/08/15 07:23:41 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2022/08/15 07:23:41 DEBUG : fs cache: adding new entry for parent of "/etc/hosts", "/etc"
2022/08/15 07:23:41 DEBUG : Creating backend with remote "DB:"
2022/08/15 07:23:41 DEBUG : DB: Loaded invalid token from config file - ignoring
2022/08/15 07:23:41 DEBUG : Saving config "token" in section "DB" of the config file
2022/08/15 07:23:41 DEBUG : DB: Saved new token in config file
2022/08/15 07:23:41 DEBUG : hosts: Size and modification time the same (differ by 359.309548ms, within tolerance 1s)
2022/08/15 07:23:41 DEBUG : hosts: Unchanged skipping
2022/08/15 07:23:41 INFO  :
Transferred:   	          0 B / 0 B, -, 0 B/s, ETA -
Checks:                 1 / 1, 100%
Elapsed time:         0.4s

2022/08/15 07:23:41 DEBUG : 6 go routines active
2022/08/15 07:23:41 INFO  : Dropbox root '': Commiting uploads - please wait...

That would show us the answer.

Thunder · August 15, 2022, 1:17pm

- 2022/08/15 14:57:30 DEBUG : rclone: Version "v1.59.0" starting with parameters ["/usr/bin/rclone" "move" "/mnt/local/Media" "db-union:Media" "--config=/home/sbuser/.config/rclone/rclone.conf" "--checkers=16" "--fast-list" "--dropbox-chunk-size=128M" "--low-level-retries=2" "--retries=1" "--skip-links" "--tpslimit=12" "--tpslimit-burst=12" "--stats=60s" "--transfers=8" "--user-agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.131 Safari/537.36" "--verbose=3" "--exclude=**partial~" "--exclude=**_HIDDEN~" "--exclude=*.db"]
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "/mnt/local/Media"
 - 2022/08/15 14:57:30 DEBUG : local: detected overridden config - adding "{HK82T}" suffix to name
 - 2022/08/15 14:57:30 DEBUG : Using config file from "/home/sbuser/.config/rclone/rclone.conf"
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "/mnt/local/Media" to be canonical "local{HK82T}:/mnt/local/Media"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-union:Media"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-tv-crypt:"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-movies-crypt:"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-tv:"
 - 2022/08/15 14:57:30 DEBUG : db-tv: detected overridden config - adding "{OgfZc}" suffix to name
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-movies:"
 - 2022/08/15 14:57:30 DEBUG : db-movies: detected overridden config - adding "{OgfZc}" suffix to name
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "db-tv:" to be canonical "db-tv{OgfZc}:"
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "db-movies:" to be canonical "db-movies{OgfZc}:"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-movies-crypt:Media"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-tv-crypt:Media"
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-movies:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : db-movies: detected overridden config - adding "{OgfZc}" suffix to name
 - 2022/08/15 14:57:30 DEBUG : Creating backend with remote "db-tv:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : db-tv: detected overridden config - adding "{OgfZc}" suffix to name
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "db-tv:uj4cklee8u0o8j4bqjfeug2eqs" to be canonical "db-tv{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "db-movies:uj4cklee8u0o8j4bqjfeug2eqs" to be canonical "db-movies{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : fs cache: switching user supplied name "db-tv:uj4cklee8u0o8j4bqjfeug2eqs" for canonical name "db-tv{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : fs cache: switching user supplied name "db-movies:uj4cklee8u0o8j4bqjfeug2eqs" for canonical name "db-movies{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : union root 'Media': actionPolicy = *policy.EpAll, createPolicy = *policy.EpMfs, searchPolicy = *policy.FF
 - 2022/08/15 14:57:31 DEBUG : union root 'Media': Waiting for checks to finish
 - 2022/08/15 14:57:31 DEBUG : union root 'Media': Waiting for transfers to finish
 - 2022/08/15 14:57:33 DEBUG : pacer: low level retry 1/2 (error too_many_write_operations/..)
 - 2022/08/15 14:57:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms
 - 2022/08/15 14:57:33 DEBUG : pacer: low level retry 1/2 (error too_many_write_operations/.)
 - 2022/08/15 14:57:33 DEBUG : pacer: Rate limited, increasing sleep to 40ms
 - 2022/08/15 14:57:33 DEBUG : pacer: Reducing sleep to 30ms
 - 2022/08/15 14:57:33 DEBUG : pacer: low level retry 2/2 (error too_many_write_operations/)
 - 2022/08/15 14:57:33 DEBUG : pacer: Rate limited, increasing sleep to 60ms
 - 2022/08/15 14:57:33 ERROR : Movies/Movies4K/Jumanji Welcome to the Jungle (2017)/Jumanji Welcome to the Jungle (2017) [imdb-tt2283362][Remux-2160p][DV HDR10][DTS-HD MA 5.1][HEVC]-TSCC.mkv: Failed to copy: 1 error: db-movies-crypt: too_many_write_operations/
 - 2022/08/15 14:57:33 ERROR : Movies/Movies4K/Jumanji Welcome to the Jungle (2017)/Jumanji Welcome to the Jungle (2017) [imdb-tt2283362][Remux-2160p][DV HDR10][DTS-HD MA 5.1][HEVC]-TSCC.mkv: Not deleting source as copy failed: 1 error: db-movies-crypt: too_many_write_operations/
 - 2022/08/15 14:57:33 DEBUG : pacer: Reducing sleep to 45ms
 - 2022/08/15 14:57:33 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 1/108
 - 2022/08/15 14:57:34 DEBUG : pacer: Reducing sleep to 33.75ms
 - 2022/08/15 14:57:34 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 1/14
 - 2022/08/15 14:57:39 DEBUG : pacer: Reducing sleep to 25.3125ms
 - 2022/08/15 14:57:39 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 2/108
 - 2022/08/15 14:57:40 DEBUG : pacer: Reducing sleep to 18.984375ms
 - 2022/08/15 14:57:40 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 2/14
 - 2022/08/15 14:57:45 DEBUG : pacer: Reducing sleep to 14.238281ms
 - 2022/08/15 14:57:45 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 3/108
 - 2022/08/15 14:57:47 DEBUG : pacer: Reducing sleep to 10.67871ms
 - 2022/08/15 14:57:47 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 3/14
 - 2022/08/15 14:57:50 DEBUG : pacer: Reducing sleep to 10ms
 - 2022/08/15 14:57:50 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 4/108
 - 2022/08/15 14:57:55 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 4/14
 - 2022/08/15 14:57:57 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 5/108
 - 2022/08/15 14:58:00 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 5/14
 - 2022/08/15 14:58:05 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 6/108
 - 2022/08/15 14:58:07 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 6/14
 - 2022/08/15 14:58:09 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 7/108
 - 2022/08/15 14:58:11 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 7/14
 - 2022/08/15 14:58:13 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 8/108
 - 2022/08/15 14:58:15 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 8/14
 - 2022/08/15 14:58:17 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 9/108
 - 2022/08/15 14:58:19 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 9/14
 - 2022/08/15 14:58:22 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 10/108
 - 2022/08/15 14:58:26 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/ik7o0aic9i8fkebl5g9l4noldc/iqquttalf19h3uqq74t3ksuh78/c0ok1239n8neai4tlel0jjc1efd0trotnhpvt1cenlqhc50sdmo3l20gk7b174pi9olrishqg5vs3mf3jt87o2go1nvvvpvkuulkbs8: Uploading chunk 10/14
 - 2022/08/15 14:58:28 DEBUG : ik7o0aic9i8fkebl5g9l4noldc/b61i9c39bt5f7oc4t1smlds5no/97ha4dtrsks6nu70e6ocmq4gco81h3o833jron08d08vvu1497cg/flkbitj1rqmr9qo4027o30u4g97n6q5cpl4dfvgrj9pbnec6shra0ir441j8r17da8t91adqemojasskuavck5lieu0h3br02u3gn09rdggvotolpnv5hvqn92242p9q: Uploading chunk 11/108
 - 2022/08/15 15:08:23 ERROR : Attempt 1/1 failed with 1 errors and: 1 error: db-movies-crypt: too_many_write_operations/
- 2022/08/15 15:08:23 INFO  :
- Transferred:        15.168 GiB / 15.168 GiB, 100%, 14.218 MiB/s, ETA 0s
- Errors:                 1 (retrying may help)
- Checks:                 5 / 5, 100%
- Deleted:                2 (files), 0 (dirs)
- Renamed:                2
- Transferred:            2 / 2, 100%
- Elapsed time:     10m52.7s
- 2022/08/15 15:08:23 DEBUG : 10 go routines active
- 2022/08/15 15:08:23 INFO  : Dropbox root 'uj4cklee8u0o8j4bqjfeug2eqs': Commiting uploads - please wait...
- 2022/08/15 15:08:23 INFO  : Dropbox root 'uj4cklee8u0o8j4bqjfeug2eqs': Commiting uploads - please wait...
- 2022/08/15 15:08:23 Failed to move: 1 error: db-movies-crypt: too_many_write_operations/
- Finished uploading to remote: db-union
- Removed empty directories from '/mnt/local/Media' with mindepth: 2
- Finished upload
- 'do_upload' from 'cloudplow.py' finished in 10 minutes and 52 seconds

Thats a complete uplaod log (i snipped all the chunk uploads in between because there was nothing important happening)

Animosity022 · August 15, 2022, 1:23pm

If the config has items that are overriding things, it appends that as you can see in the top of the log:

 - 2022/08/15 14:57:30 DEBUG : db-tv: detected overridden config - adding "{OgfZc}" suffix to name
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "db-tv:uj4cklee8u0o8j4bqjfeug2eqs" to be canonical "db-tv{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : fs cache: renaming cache item "db-movies:uj4cklee8u0o8j4bqjfeug2eqs" to be canonical "db-movies{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : fs cache: switching user supplied name "db-tv:uj4cklee8u0o8j4bqjfeug2eqs" for canonical name "db-tv{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"
 - 2022/08/15 14:57:30 DEBUG : fs cache: switching user supplied name "db-movies:uj4cklee8u0o8j4bqjfeug2eqs" for canonical name "db-movies{OgfZc}:uj4cklee8u0o8j4bqjfeug2eqs"

So at the end, it gives you the proper name again:

- 2022/08/15 15:08:23 INFO  : Dropbox root 'uj4cklee8u0o8j4bqjfeug2eqs': Commiting uploads - please wait...

That's documented here:

Thunder · August 15, 2022, 1:35pm

I dont get it ?
What does it mean?

My rclone config is a standard config for dropbox and encrypted remotes on top. So what does get overridden?

[db-movies]
type = dropbox
client_id = xXX
client_secret = XXX
token = {"access_token":"XXX","token_type":"bearer","refresh_token":"XXX","expiry":"2022-08-15T16:39:22.811129918+02:00"}

[db-tv]
type = dropbox
client_id = XXX
client_secret = XXXX
token = {"access_token":"XXX","token_type":"bearer","refresh_token":"XXXX","expiry":"2022-08-15T16:17:54.049512715+02:00"}

[db-movies-crypt]
type = crypt
remote = db-movies:
password = XXX
password2 = XXX

[db-tv-crypt]
type = crypt
remote = db-tv:
password = YXX
password2 = CCCC

Animosity022 · August 15, 2022, 1:44pm

It's really a non thing as it just means something on the command line overrode a parameter.

If you supply extra configuration to a backend by command line flag, environment variable or connection string then rclone will add a suffix based on the hash of the config to the name of the remote, eg

Thunder · August 15, 2022, 1:45pm

Okay understand.

But as you can see, i specified --tpslimit 12 and still i got too_many_writes

Animosity022 · August 15, 2022, 1:47pm

Do you have unique app registrations for each dropbox remote or are they shared?

Thunder · August 15, 2022, 3:07pm

uniqe registrations for each remote.

but i am using union to merge 2 remotes together

Animosity022 · August 15, 2022, 3:16pm

Are they mounted as well as being uploaded to?

I split out my uploads on their own app registrations to never impact my mounts before I just moved away from upload and just let vfs-cache-mode full do it's thing.

If they aren't split out, you'd probably want to limit each app reg to around 12 tps or try going to 11, 10, 9, etc and find the right spot for your setup.

Thunder · August 16, 2022, 3:29pm

Yes they are .

I encountered a new problem with uploading, which basically stalled rclone for almost 15 hours now:

- <3>ERROR : Dropbox root 'uj4cklee8u0o8j4bqjfeug2eqs/ik7o0aic9i8fkebl5g9l4noldc': sync batch commit: failed to commit batch length 1: batch commit failed:
- <6>INFO  :
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 4.186 MiB/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:      43m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 4.062Mi/s, -
- <6>INFO  :
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 89.192 KiB/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:      44m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 86.568Ki/s, -
- <6>INFO  :
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 1.855 KiB/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:      45m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 1.801Ki/s, -
- <6>INFO  :
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 39 B/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:      46m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 38/s, -
- <6>INFO  :
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 0 B/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:      47m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 0/s, -
- Tracked first occurrence of trigger: ' 0/s,'. Expiring in 62 seconds at 2022-08-16 01:04:40

Now this error message appears again and again:

- Transferred:       198.729 GiB / 198.722 GiB, 100%, 0 B/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:    17h8m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 0/s, -
- Tracked trigger: ' 0/s,' has occurred 2/16 times within 62 seconds
- <6>INFO  :
- Tracking of trigger: ' 0/s,' has expired, resetting occurrence count and timeout
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 0 B/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:    17h9m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 0/s, -
- Tracked first occurrence of trigger: ' 0/s,'. Expiring in 62 seconds at 2022-08-16 17:26:40
- <6>INFO  :
- Transferred:       198.729 GiB / 198.722 GiB, 100%, 0 B/s, ETA -
- Checks:                18 / 19, 95%
- Deleted:                9 (files), 0 (dirs)
- Renamed:                9
- Transferred:            9 / 10, 90%
- Elapsed time:   17h10m0.3s
- Checking:
- Transferring:
- * Movies/Predator (1987)…[DTS 5.1][AVC]-HDS.mkv:100% /28.181Gi, 0/s, -
- Tracked trigger: ' 0/s,' has occurred 2/16 times within 62 seconds

What does this mean?

Animosity022 · August 16, 2022, 3:34pm

No idea as that seems to be a cloudplow thing.

Thunder · August 17, 2022, 7:48am

Dont think so:

github.com/rclone/rclone

dropbox (batch) upload encounters internal_error/, eventually stalls for hours

opened 04:43PM - 28 Jul 21 UTC

borkd

bug Remote: Dropbox configuration

#### The associated forum post URL from `https://forum.rclone.org` #### What …is the problem you are having with rclone? Periodic "batch didn't complete" errors, and "internal_error/", eventually stalls for hours. ``` $ rclone --compress-level 6 copy --max-age 24h --immutable data dropbox:abcd-db/2021/ab/data --transfers=16 --fast-list -P 2021-07-28 00:27:30 ERROR : Dropbox root 'abcd-db/2021/ab/data': sync batch commit: failed to commit batch length 3: wait for batch failed after 120 tries: batch didn't complete 2021-07-28 00:57:38 ERROR : Dropbox root 'abcd-db/2021/ab/data': sync batch commit: failed to commit batch length 9: wait for batch failed after 120 tries: batch didn't complete 2021-07-28 04:24:40 ERROR : Dropbox root 'abcd-db/2021/ab/data': sync batch commit: failed to commit batch length 2: wait for batch failed after 120 tries: internal_error/ 2021-07-28 04:37:48 ERROR : Dropbox root 'abcd-db/2021/ab/data': sync batch commit: failed to commit batch length 1: wait for batch failed after 120 tries: internal_error/ 2021-07-28 09:09:56 ERROR : Dropbox root 'abcd-db/2021/ab/data': sync batch commit: failed to commit batch length 1: wait for batch failed after 120 tries: batch didn't complete Transferred: 47.007Gi / 94.672 GiByte, 50%, 0 Byte/s, ETA 0s Transferred: 9874 / 19898, 50% Elapsed time: 13h12m36.2s Transferring: * 16/1603f1e23740fdc0409…b92b03273b94a4d7994f13:100% /4.351Mi, 0/s, 0s * 16/16047c392cef6414c62…d865c52cd2d52fde0b5e65:100% /4.636Mi, 0/s, 0s * 16/1605dc8faed7a97b6bd…3438aa9271816e1648eb48:100% /4.117Mi, 0/s, 0s * 15/1567bd4c08f70c36bbc…f3f5db36379d3232bd628c:100% /5.355Mi, 0/s, 0s * 15/156ed0c5721219d689e…816a40ec6221eb3afdbcd2:100% /4.329Mi, 0/s, 0s * 15/156effb85b203ff1779…80d73e24fe8f4e39b4ab1a:100% /4.113Mi, 0/s, 0s * 15/156f5780f0bf3d57449…9017b188391d5d62daa2b6:100% /4.320Mi, 0/s, 0s * 15/156fdf0842375137277…559906589bf2eeb15de4f2:100% /4.643Mi, 0/s, 0s * 15/15709b7f128dafbba0b…cd03e3ba53c4a09c0d891f:100% /4.260Mi, 0/s, 0s * 15/1570e79fbae580647e0…b65602d7daa0327437b7bc:100% /4.752Mi, 0/s, 0s * 15/15725bb2b702a4300aa…11e3eb291f8dfa35fbbe3e:100% /4.692Mi, 0/s, 0s * 15/157260c8b208be72180…e8f15f2a0a19d7d4f89f46:100% /4.638Mi, 0/s, 0s * 26/26f4361399afb974e2b…5bd21da68d5650530b7262:100% /6.773Mi, 0/s, 0s * 26/26f46f7f4c6a12a2059…2030baa9c2e93bbe8969ca:100% /4.063Mi, 0/s, 0s * 1f/1f62c5168ac628a2cdb…858604af9efbb8c8a36f39:100% /4.039Mi, 0/s, 0s * 2f/2f3a2118cd0763edf31…e0364bab861cd16e74f33f:100% /4.758Mi, 0/s, 0s ``` #### What is your rclone version (output from `rclone version`) ``` rclone v1.56.0 - os/version: debian 9.13 (64 bit) - os/kernel: 4.19.0-0.bpo.13-amd64 (x86_64) - os/type: linux - os/arch: amd64 - go/version: go1.16.5 - go/linking: static - go/tags: none ``` #### Which OS you are using and how many bits (e.g. Windows 7, 64 bit) #### Which cloud storage system are you using? (e.g. Google Drive) Dropbox #### The command you were trying to run (e.g. `rclone copy /tmp remote:tmp`) ``` rclone --compress-level 6 copy --max-age 24h --immutable data dropbox:abcd-db/2021/ab/data --transfers=16 --fast-list -P ``` #### A log from the command with the `-vv` flag (e.g. output from `rclone -vv copy /tmp remote:tmp`) Rerunning with `-vv` now. Will update when problems are logged #### How to use GitHub * Please use the 👍 [reaction](https://blog.github.com/2016-03-10-add-reactions-to-pull-requests-issues-and-comments/) to show that you are affected by the same issue. * Please don't comment if you have no relevant information to add. It's just extra noise for everyone subscribed to this issue. * Subscribe to receive notifications on status change and new comments.

It seems that i get this error when rclone is trying to upload at 0 bytes per second for some reason:

 * TV4K/Breaking Bad/Seas…[x265]-WONDERWOMAN.mkv:  0% /5.208Gi, 0/s, -

also this was the first error, this is clearly rclone:

<3>ERROR : Dropbox root 'uj4cklee8u0o8j4bqjfeug2eqs/ik7o0aic9i8fkebl5g9l4noldc': sync batch commit: failed to commit batch length 1: batch commit failed:

Animosity022 · August 17, 2022, 12:05pm

Feel free to comment in the issue.

Without seeing the rclone command being run, it's tough to say it's the same.

There are a few issues for uploading to dropbox out there as well.

My experience is not using cloudplow and using just rclone and I migratd my GDrive over without any issue and have been uploading for some time now without an issue.

I'm one person so I could be just lucky too.

system · September 16, 2022, 12:06pm

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