"./sync.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestServerSideMove|TestSyncAfterChangingFilesSizeOnly|TestSyncWithUpdateOlder)$'" - Starting (try 2/5)
2026/05/30 03:45:16 DEBUG : Creating backend with remote "TestDropbox:rclone-test-qijubep4heje"
2026/05/30 03:45:16 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/05/30 03:45:17 DEBUG : Creating backend with remote "/tmp/rclone940344815"
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:198: Remote "Dropbox root 'rclone-test-qijubep4heje'", Local "Local file system at /tmp/rclone940344815", Modify Window "1s"
2026/05/30 03:45:18 DEBUG : potato: Uploading chunk 1/1
2026/05/30 03:45:18 DEBUG : potato: Uploading chunk 2/1
2026/05/30 03:45:18 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "potato" to batch
2026/05/30 03:45:19 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:19 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: potato
2026/05/30 03:45:20 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: potato
2026/05/30 03:45:20 DEBUG : potato: size = 21 (Local file system at /tmp/rclone940344815)
2026/05/30 03:45:20 DEBUG : potato: size = 60 (Dropbox root 'rclone-test-qijubep4heje')
2026/05/30 03:45:20 DEBUG : potato: Sizes differ
2026/05/30 03:45:20 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Waiting for checks to finish
2026/05/30 03:45:20 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Waiting for transfers to finish
2026/05/30 03:45:20 DEBUG : potato: Uploading chunk 1/1
2026/05/30 03:45:21 DEBUG : potato: Uploading chunk 2/1
2026/05/30 03:45:21 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "potato" to batch
2026/05/30 03:45:21 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:21 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: potato
2026/05/30 03:45:22 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: potato
2026/05/30 03:45:22 DEBUG : potato: size = 21 OK
2026/05/30 03:45:22 DEBUG : potato: dropbox = 0197254cbba805b9754cad440989632d5cfed8fd4bc27f7e5b8ba7f1d4814ac0 OK
2026/05/30 03:45:22 INFO  : potato: Copied (replaced existing)
2026/05/30 03:45:22 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingFilesSizeOnly (6.99s)
=== RUN   TestSyncWithUpdateOlder
    run.go:198: Remote "Dropbox root 'rclone-test-qijubep4heje'", Local "Local file system at /tmp/rclone940344815", Modify Window "1s"
2026/05/30 03:45:24 DEBUG : one: Uploading chunk 1/1
2026/05/30 03:45:24 DEBUG : one: Uploading chunk 2/1
2026/05/30 03:45:25 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "one" to batch
2026/05/30 03:45:25 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:25 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: one
2026/05/30 03:45:26 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: one
2026/05/30 03:45:26 DEBUG : two: Uploading chunk 1/1
2026/05/30 03:45:27 DEBUG : two: Uploading chunk 2/1
2026/05/30 03:45:27 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "two" to batch
2026/05/30 03:45:27 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:27 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: two
2026/05/30 03:45:28 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: two
2026/05/30 03:45:28 DEBUG : three: Uploading chunk 1/1
2026/05/30 03:45:29 DEBUG : three: Uploading chunk 2/1
2026/05/30 03:45:29 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "three" to batch
2026/05/30 03:45:29 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:29 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: three
2026/05/30 03:45:30 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: three
2026/05/30 03:45:30 DEBUG : four: Uploading chunk 1/1
2026/05/30 03:45:31 DEBUG : four: Uploading chunk 2/1
2026/05/30 03:45:31 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "four" to batch
2026/05/30 03:45:32 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:32 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: four
2026/05/30 03:45:32 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: four
2026/05/30 03:45:33 DEBUG : five: Need to transfer - File not found at Destination
2026/05/30 03:45:33 DEBUG : four: size = 4 (Local file system at /tmp/rclone940344815)
2026/05/30 03:45:33 DEBUG : four: size = 8 (Dropbox root 'rclone-test-qijubep4heje')
2026/05/30 03:45:33 DEBUG : four: Sizes differ
2026/05/30 03:45:33 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2026/05/30 03:45:33 DEBUG : one: Destination is newer than source, skipping
2026/05/30 03:45:33 DEBUG : two: size = 3 OK
2026/05/30 03:45:33 DEBUG : three: size = 5 OK
2026/05/30 03:45:33 DEBUG : three: Sizes identical
2026/05/30 03:45:33 DEBUG : two: dropbox = 313db63e0283ab2a9bc72e9a0ac749da1d3acf708fcd1a7848767244dd2f17e8 (Local file system at /tmp/rclone940344815)
2026/05/30 03:45:33 DEBUG : two: dropbox = 00b165e375c521d9e15870a04a889919b652d5f0b499d7e4f9304fb142dc36d8 (Dropbox root 'rclone-test-qijubep4heje')
2026/05/30 03:45:33 DEBUG : two: dropbox differ
2026/05/30 03:45:33 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Waiting for checks to finish
2026/05/30 03:45:33 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2026/05/30 03:45:33 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Waiting for transfers to finish
2026/05/30 03:45:33 DEBUG : five: Uploading chunk 1/1
2026/05/30 03:45:33 DEBUG : two: Uploading chunk 1/1
2026/05/30 03:45:33 DEBUG : four: Uploading chunk 1/1
2026/05/30 03:45:33 DEBUG : two: Uploading chunk 2/1
2026/05/30 03:45:33 DEBUG : five: Uploading chunk 2/1
2026/05/30 03:45:34 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "two" to batch
2026/05/30 03:45:34 DEBUG : four: Uploading chunk 2/1
2026/05/30 03:45:34 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "four" to batch
2026/05/30 03:45:34 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "five" to batch
2026/05/30 03:45:34 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:34 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 3 starting with: two
2026/05/30 03:45:36 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 3 starting with: two
2026/05/30 03:45:36 DEBUG : five: size = 4 OK
2026/05/30 03:45:36 DEBUG : two: size = 3 OK
2026/05/30 03:45:36 DEBUG : four: size = 4 OK
2026/05/30 03:45:36 DEBUG : two: dropbox = 313db63e0283ab2a9bc72e9a0ac749da1d3acf708fcd1a7848767244dd2f17e8 OK
2026/05/30 03:45:36 DEBUG : four: dropbox = ad1d7d5339655cf0a7e22a8560b56f563ea95eba7b0a043776c99a4db108702a OK
2026/05/30 03:45:36 INFO  : two: Copied (replaced existing)
2026/05/30 03:45:36 INFO  : four: Copied (replaced existing)
2026/05/30 03:45:36 DEBUG : five: dropbox = 785ec2cf1199779cb1593eac85d7465db3603834e9edd6d1420f2b369bb01dc3 OK
2026/05/30 03:45:36 INFO  : five: Copied (new)
2026/05/30 03:45:36 DEBUG : Waiting for deletions to finish
2026/05/30 03:45:36 DEBUG : five: size = 4 OK
2026/05/30 03:45:36 DEBUG : four: size = 4 OK
2026/05/30 03:45:36 DEBUG : three: size = 5 OK
2026/05/30 03:45:36 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Waiting for checks to finish
2026/05/30 03:45:36 DEBUG : one: Destination is newer than source, skipping
2026/05/30 03:45:36 DEBUG : two: size = 3 OK
2026/05/30 03:45:36 DEBUG : four: dropbox = ad1d7d5339655cf0a7e22a8560b56f563ea95eba7b0a043776c99a4db108702a OK
2026/05/30 03:45:36 DEBUG : four: Size and dropbox of src and dst objects identical
2026/05/30 03:45:36 DEBUG : five: dropbox = 785ec2cf1199779cb1593eac85d7465db3603834e9edd6d1420f2b369bb01dc3 OK
2026/05/30 03:45:36 DEBUG : five: Size and dropbox of src and dst objects identical
2026/05/30 03:45:36 DEBUG : two: dropbox = 313db63e0283ab2a9bc72e9a0ac749da1d3acf708fcd1a7848767244dd2f17e8 OK
2026/05/30 03:45:36 DEBUG : two: Size and dropbox of src and dst objects identical
2026/05/30 03:45:36 DEBUG : five: Destination mod time is within 1s of source and files identical, skipping
2026/05/30 03:45:36 DEBUG : two: Destination mod time is within 1s of source and files identical, skipping
2026/05/30 03:45:36 DEBUG : four: Destination mod time is within 1s of source and files identical, skipping
2026/05/30 03:45:36 DEBUG : three: dropbox = 1dbfa84faa926d00a27e7578746a13ad3063e0e9bde3b25015e545ad80f5f703 (Local file system at /tmp/rclone940344815)
2026/05/30 03:45:36 DEBUG : three: dropbox = 8c4bfd5e4dc14d49026d0a5aa224be92b3af4b622e8c08296defc8e299b0b6fa (Dropbox root 'rclone-test-qijubep4heje')
2026/05/30 03:45:36 DEBUG : three: dropbox differ
2026/05/30 03:45:36 DEBUG : three: Destination mod time is within 1s of source but files differ, transferring
2026/05/30 03:45:36 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Waiting for transfers to finish
2026/05/30 03:45:36 DEBUG : three: Uploading chunk 1/1
2026/05/30 03:45:37 DEBUG : three: Uploading chunk 2/1
2026/05/30 03:45:37 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "three" to batch
2026/05/30 03:45:37 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:37 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: three
2026/05/30 03:45:38 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: three
2026/05/30 03:45:38 DEBUG : three: size = 5 OK
2026/05/30 03:45:38 DEBUG : three: dropbox = 1dbfa84faa926d00a27e7578746a13ad3063e0e9bde3b25015e545ad80f5f703 OK
2026/05/30 03:45:38 INFO  : three: Copied (replaced existing)
2026/05/30 03:45:38 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncWithUpdateOlder (18.75s)
=== RUN   TestServerSideMove
    run.go:198: Remote "Dropbox root 'rclone-test-qijubep4heje'", Local "Local file system at /tmp/rclone940344815", Modify Window "1s"
2026/05/30 03:45:42 DEBUG : Creating backend with remote "TestDropbox:rclone-test-zobafoy6vere"
2026/05/30 03:45:43 DEBUG : potato2: Uploading chunk 1/1
2026/05/30 03:45:43 DEBUG : potato2: Uploading chunk 2/1
2026/05/30 03:45:44 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "potato2" to batch
2026/05/30 03:45:44 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:44 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: potato2
2026/05/30 03:45:45 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: potato2
2026/05/30 03:45:45 DEBUG : empty space: Uploading chunk 1/1
2026/05/30 03:45:45 DEBUG : empty space: Uploading chunk 2/1
2026/05/30 03:45:46 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "empty space" to batch
2026/05/30 03:45:46 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:46 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: empty space
2026/05/30 03:45:47 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: empty space
2026/05/30 03:45:47 DEBUG : potato3: Uploading chunk 1/1
2026/05/30 03:45:48 DEBUG : potato3: Uploading chunk 2/1
2026/05/30 03:45:48 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Adding "potato3" to batch
2026/05/30 03:45:48 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Batch idle for 500ms so committing
2026/05/30 03:45:48 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committing sync batch length 1 starting with: potato3
2026/05/30 03:45:49 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Committed sync batch length 1 starting with: potato3
    sync_test.go:1736: Server side move (if possible) Dropbox root 'rclone-test-qijubep4heje' -> Dropbox root 'rclone-test-zobafoy6vere'
2026/05/30 03:45:50 DEBUG : empty space: Uploading chunk 1/1
2026/05/30 03:45:51 DEBUG : empty space: Uploading chunk 2/1
2026/05/30 03:45:51 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Adding "empty space" to batch
2026/05/30 03:45:51 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Batch idle for 500ms so committing
2026/05/30 03:45:51 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Committing sync batch length 1 starting with: empty space
2026/05/30 03:45:52 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Committed sync batch length 1 starting with: empty space
2026/05/30 03:45:52 DEBUG : potato3: Uploading chunk 1/1
2026/05/30 03:45:53 DEBUG : potato3: Uploading chunk 2/1
2026/05/30 03:45:53 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Adding "potato3" to batch
2026/05/30 03:45:54 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Batch idle for 500ms so committing
2026/05/30 03:45:54 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Committing sync batch length 1 starting with: potato3
2026/05/30 03:45:54 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Committed sync batch length 1 starting with: potato3
2026/05/30 03:45:54 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Using server-side directory move
2026/05/30 03:45:55 INFO  : Dropbox root 'rclone-test-zobafoy6vere': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2026/05/30 03:45:55 DEBUG : potato2: Need to transfer - File not found at Destination
2026/05/30 03:45:55 DEBUG : empty space: size = 1 OK
2026/05/30 03:45:55 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2026/05/30 03:45:55 DEBUG : empty space: Unchanged skipping
2026/05/30 03:45:55 DEBUG : potato3: size = 68 (Dropbox root 'rclone-test-qijubep4heje')
2026/05/30 03:45:55 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Waiting for checks to finish
2026/05/30 03:45:55 DEBUG : potato3: size = 60 (Dropbox root 'rclone-test-zobafoy6vere')
2026/05/30 03:45:55 DEBUG : potato3: Sizes differ
2026/05/30 03:45:56 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2026/05/30 03:45:56 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/05/30 03:45:56 DEBUG : pacer: Reducing sleep to 15ms
2026/05/30 03:45:56 INFO  : potato3: Deleted
2026/05/30 03:45:56 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2026/05/30 03:45:56 DEBUG : pacer: Rate limited, increasing sleep to 30ms
2026/05/30 03:45:57 INFO  : empty space: Deleted
2026/05/30 03:45:57 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Waiting for transfers to finish
2026/05/30 03:45:57 DEBUG : pacer: Reducing sleep to 22.5ms
2026/05/30 03:45:57 INFO  : potato2: Moved (server-side)
2026/05/30 03:45:57 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2026/05/30 03:45:57 DEBUG : pacer: Rate limited, increasing sleep to 45ms
2026/05/30 03:45:58 DEBUG : pacer: Reducing sleep to 33.75ms
2026/05/30 03:45:58 INFO  : potato3: Moved (server-side)
2026/05/30 03:45:59 DEBUG : pacer: Reducing sleep to 25.3125ms
2026/05/30 03:45:59 DEBUG : Creating backend with remote "TestDropbox:rclone-test-wayobir8tina"
2026/05/30 03:45:59 DEBUG : Dropbox root 'rclone-test-wayobir8tina': Using server-side directory move
2026/05/30 03:46:01 INFO  : Dropbox root 'rclone-test-wayobir8tina': Server side directory move succeeded
2026/05/30 03:46:01 DEBUG : pacer: Reducing sleep to 18.984375ms
2026/05/30 03:46:01 ERROR : error listing: directory not found
2026/05/30 03:46:01 DEBUG : Dropbox root 'rclone-test-wayobir8tina': Purge remote
2026/05/30 03:46:02 DEBUG : Dropbox root 'rclone-test-zobafoy6vere': Purge remote
2026/05/30 03:46:02 DEBUG : pacer: Reducing sleep to 14.238281ms
2026/05/30 03:46:02 NOTICE: purge failed: path_lookup/not_found/
--- PASS: TestServerSideMove (20.08s)
PASS
2026/05/30 03:46:03 DEBUG : Dropbox root 'rclone-test-qijubep4heje': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestServerSideMove|TestSyncAfterChangingFilesSizeOnly|TestSyncWithUpdateOlder)$'" - Finished OK in 46.816033433s (try 2/5)