"./operations.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestCopyFileCopyDest|TestDeduplicateNewestByHash|TestDirMove|TestRmdirsWithFilter)$'" - Starting (try 2/5) 2025/09/27 04:29:00 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tedowan7mutu" 2025/09/27 04:29:00 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/09/27 04:29:01 DEBUG : Creating backend with remote "/tmp/rclone1438957967" === RUN TestCopyFileCopyDest run.go:180: Remote "files root 'rclone-test-tedowan7mutu'", Local "Local file system at /tmp/rclone1438957967", Modify Window "1s" 2025/09/27 04:29:01 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tedowan7mutu/dst" 2025/09/27 04:29:01 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tedowan7mutu/CopyDest" 2025/09/27 04:29:02 DEBUG : one: Need to transfer - File not found at Destination 2025/09/27 04:29:03 DEBUG : one: Dst hash empty - aborting Src hash check 2025/09/27 04:29:03 INFO : one: Copied (new) 2025/09/27 04:29:05 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/09/27 04:29:06 DEBUG : one: Dst hash empty - aborting Src hash check 2025/09/27 04:29:06 INFO : one: Copied (replaced existing) 2025/09/27 04:29:11 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tedowan7mutu/BackupDir" 2025/09/27 04:29:12 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/09/27 04:29:12 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/09/27 04:29:12 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/09/27 04:29:13 INFO : one: Moved (server-side) 2025/09/27 04:29:16 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK 2025/09/27 04:29:16 INFO : one: Copied (server-side copy) 2025/09/27 04:29:16 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/09/27 04:29:19 DEBUG : two: Need to transfer - File not found at Destination 2025/09/27 04:29:19 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/09/27 04:29:22 DEBUG : two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK 2025/09/27 04:29:22 INFO : two: Copied (server-side copy) 2025/09/27 04:29:22 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/09/27 04:29:23 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/09/27 04:29:23 DEBUG : two: Unchanged skipping 2025/09/27 04:29:25 DEBUG : three: Need to transfer - File not found at Destination 2025/09/27 04:29:26 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/09/27 04:29:26 DEBUG : three: Destination not found in --copy-dest 2025/09/27 04:29:27 DEBUG : three: md5 = 1bccb9dccb3e9f6a3f9d2a8bdb54b7f5 OK 2025/09/27 04:29:27 INFO : three: Copied (new) --- PASS: TestCopyFileCopyDest (28.98s) === RUN TestDeduplicateNewestByHash run.go:180: Remote "files root 'rclone-test-tedowan7mutu'", Local "Local file system at /tmp/rclone1438957967", Modify Window "1s" 2025/09/27 04:29:33 INFO : files root 'rclone-test-tedowan7mutu': Looking for duplicate md5 hashes using newest mode. 2025/09/27 04:29:33 NOTICE: 02573aecdf601879c5eee2f6295bbe19: Found 2 files with duplicate md5 hashes 2025/09/27 04:29:34 INFO : one: Deleted 2025/09/27 04:29:34 NOTICE: 02573aecdf601879c5eee2f6295bbe19: Deleted 1 extra copies fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/dedupe_test.go:164 Error: Should be true Test: TestDeduplicateNewestByHash Messages: listing wrong, want another (100), not-one (5) got also/one (100), another (100), not-one (5) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/dedupe_test.go:164 /usr/local/go/src/runtime/asm_amd64.s:1700 Error: Should be true Test: TestDeduplicateNewestByHash Messages: Unexpected file "also/one" --- FAIL: TestDeduplicateNewestByHash (13.86s) === RUN TestRmdirsWithFilter run.go:180: Remote "files root 'rclone-test-tedowan7mutu'", Local "Local file system at /tmp/rclone1438957967", Modify Window "1s" 2025/09/27 04:29:44 INFO : A1: Making directory 2025/09/27 04:29:44 INFO : A1/B1: Making directory 2025/09/27 04:29:44 INFO : A1/B1/C1: Making directory 2025/09/27 04:29:46 DEBUG : removing 1 level 3 directories 2025/09/27 04:29:46 INFO : A1/B1/C1: Removing directory 2025/09/27 04:29:46 DEBUG : removing 1 level 2 directories 2025/09/27 04:29:46 INFO : A1/B1: Removing directory 2025/09/27 04:29:46 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A1/B1 not empty`) 2025/09/27 04:29:46 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/27 04:29:46 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A1/B1 not empty`) 2025/09/27 04:29:46 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/09/27 04:29:46 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A1/B1 not empty`) 2025/09/27 04:29:46 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/09/27 04:29:47 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A1/B1 not empty`) 2025/09/27 04:29:47 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/09/27 04:29:47 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A1/B1 not empty`) 2025/09/27 04:29:47 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/09/27 04:29:47 DEBUG : pacer: low level retry 6/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A1/B1 not empty`) 2025/09/27 04:29:47 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/09/27 04:29:47 DEBUG : pacer: Reducing sleep to 480ms 2025/09/27 04:29:48 DEBUG : pacer: Reducing sleep to 360ms 2025/09/27 04:29:48 DEBUG : pacer: Reducing sleep to 270ms 2025/09/27 04:29:49 DEBUG : pacer: Reducing sleep to 202.5ms 2025/09/27 04:29:49 DEBUG : pacer: Reducing sleep to 151.875ms 2025/09/27 04:29:49 DEBUG : pacer: Reducing sleep to 113.90625ms 2025/09/27 04:29:49 DEBUG : pacer: Reducing sleep to 85.429687ms --- PASS: TestRmdirsWithFilter (5.78s) === RUN TestDirMove run.go:180: Remote "files root 'rclone-test-tedowan7mutu'", Local "Local file system at /tmp/rclone1438957967", Modify Window "1s" 2025/09/27 04:29:49 DEBUG : pacer: Reducing sleep to 64.072265ms 2025/09/27 04:29:50 DEBUG : pacer: Reducing sleep to 48.054198ms 2025/09/27 04:29:51 DEBUG : pacer: Reducing sleep to 36.040648ms 2025/09/27 04:29:51 DEBUG : pacer: Reducing sleep to 27.030486ms 2025/09/27 04:29:51 DEBUG : pacer: Reducing sleep to 20.272864ms 2025/09/27 04:29:52 DEBUG : pacer: Reducing sleep to 15.204648ms 2025/09/27 04:29:52 DEBUG : pacer: Reducing sleep to 11.403486ms 2025/09/27 04:29:53 DEBUG : pacer: Reducing sleep to 10ms 2025/09/27 04:29:54 INFO : A1/B2: Making directory 2025/09/27 04:29:54 INFO : A1/B1/C3: Making directory 2025/09/27 04:29:58 INFO : A2/one: Moved (server-side) to: A3/one 2025/09/27 04:29:58 INFO : A2/two: Moved (server-side) to: A3/two 2025/09/27 04:29:58 INFO : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five 2025/09/27 04:29:58 INFO : A2/B1/three: Moved (server-side) to: A3/B1/three 2025/09/27 04:29:58 INFO : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four 2025/09/27 04:29:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A2/B1 not empty`) 2025/09/27 04:29:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/27 04:29:59 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A2/B1 not empty`) 2025/09/27 04:29:59 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/09/27 04:29:59 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A2/B1 not empty`) 2025/09/27 04:29:59 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/09/27 04:29:59 DEBUG : pacer: Reducing sleep to 60ms 2025/09/27 04:29:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A2 not empty`) 2025/09/27 04:29:59 DEBUG : pacer: Rate limited, increasing sleep to 120ms 2025/09/27 04:30:00 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A2 not empty`) 2025/09/27 04:30:00 DEBUG : pacer: Rate limited, increasing sleep to 240ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 180ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 135ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 101.25ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 75.9375ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 56.953125ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 42.714843ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 32.036132ms 2025/09/27 04:30:00 DEBUG : pacer: Reducing sleep to 24.027099ms 2025/09/27 04:30:01 INFO : files root 'rclone-test-tedowan7mutu': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes 2025/09/27 04:30:01 DEBUG : pacer: Reducing sleep to 18.020324ms 2025/09/27 04:30:01 DEBUG : pacer: Reducing sleep to 13.515243ms 2025/09/27 04:30:01 DEBUG : pacer: Reducing sleep to 10.136432ms 2025/09/27 04:30:01 DEBUG : pacer: Reducing sleep to 10ms 2025/09/27 04:30:03 INFO : A3/one: Moved (server-side) to: A4/one 2025/09/27 04:30:03 INFO : A3/B1/three: Moved (server-side) to: A4/B1/three 2025/09/27 04:30:03 INFO : A3/B1/C1/four: Moved (server-side) to: A4/B1/C1/four 2025/09/27 04:30:03 INFO : A3/B1/C2/five: Moved (server-side) to: A4/B1/C2/five 2025/09/27 04:30:03 INFO : A3/two: Moved (server-side) to: A4/two 2025/09/27 04:30:04 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A3/B1 not empty`) 2025/09/27 04:30:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/27 04:30:04 DEBUG : pacer: Reducing sleep to 15ms 2025/09/27 04:30:04 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A3 not empty`) 2025/09/27 04:30:04 DEBUG : pacer: Rate limited, increasing sleep to 30ms 2025/09/27 04:30:04 DEBUG : pacer: Reducing sleep to 22.5ms 2025/09/27 04:30:04 DEBUG : pacer: Reducing sleep to 16.875ms 2025/09/27 04:30:04 DEBUG : pacer: Reducing sleep to 12.65625ms 2025/09/27 04:30:04 DEBUG : pacer: Reducing sleep to 10ms 2025/09/27 04:30:07 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A4/B1 not empty`) 2025/09/27 04:30:07 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/27 04:30:07 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A4/B1 not empty`) 2025/09/27 04:30:07 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/09/27 04:30:07 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A4/B1 not empty`) 2025/09/27 04:30:07 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/09/27 04:30:07 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A4/B1 not empty`) 2025/09/27 04:30:07 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/09/27 04:30:07 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A4/B1 not empty`) 2025/09/27 04:30:07 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/09/27 04:30:08 DEBUG : pacer: Reducing sleep to 240ms 2025/09/27 04:30:08 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tedowan7mutu/A4 not empty`) 2025/09/27 04:30:08 DEBUG : pacer: Rate limited, increasing sleep to 480ms 2025/09/27 04:30:08 DEBUG : pacer: Reducing sleep to 360ms 2025/09/27 04:30:09 DEBUG : pacer: Reducing sleep to 270ms --- PASS: TestDirMove (19.35s) FAIL 2025/09/27 04:30:09 DEBUG : files root 'rclone-test-tedowan7mutu': Purge remote 2025/09/27 04:30:09 DEBUG : pacer: Reducing sleep to 202.5ms "./operations.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestCopyFileCopyDest|TestDeduplicateNewestByHash|TestDirMove|TestRmdirsWithFilter)$'" - Finished ERROR in 1m9.152256231s (try 2/5): exit status 1: Failed [TestDeduplicateNewestByHash]