"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestNothingToTransferWithoutEmptyDirs|TestSyncAfterChangingFilesSizeOnly|TestSyncBackupDirWithSuffix|TestSyncSuffix|TestSyncWithExclude)$'" - Starting (try 2/5) 2025/04/22 06:02:38 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-zadaved5kewe" 2025/04/22 06:02:38 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/22 06:02:39 DEBUG : Starting OpenDrive session with ID: c0549051340cde3dc36e6ee147032c2ae48aaf1baa0f2d39a93a24fecd5efddf 2025/04/22 06:02:39 DEBUG : Creating backend with remote "/tmp/rclone3506503620" === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:02:40 DEBUG : potato: Uploading chunk 0, size=60, remain=0 2025/04/22 06:02:42 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/22 06:02:42 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe': Waiting for checks to finish 2025/04/22 06:02:42 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe': Waiting for transfers to finish 2025/04/22 06:02:42 DEBUG : potato: Uploading chunk 0, size=21, remain=0 2025/04/22 06:02:43 DEBUG : potato: md5 = 100defcf18c42a1e0dc42a789b107cd2 OK 2025/04/22 06:02:43 INFO : potato: Copied (replaced existing) 2025/04/22 06:02:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.42s) === RUN TestSyncWithExclude run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:02:44 DEBUG : potato2: Uploading chunk 0, size=60, remain=0 2025/04/22 06:02:46 DEBUG : empty space: Uploading chunk 0, size=1, remain=0 2025/04/22 06:02:47 DEBUG : enormous: Excluded (Size Filter) 2025/04/22 06:02:47 DEBUG : enormous: Excluded 2025/04/22 06:02:47 DEBUG : potato2: Excluded (Size Filter) 2025/04/22 06:02:47 DEBUG : potato2: Excluded 2025/04/22 06:02:47 DEBUG : potato2: Excluded (Size Filter) 2025/04/22 06:02:47 DEBUG : potato2: Excluded 2025/04/22 06:02:47 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/22 06:02:47 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe': Waiting for checks to finish 2025/04/22 06:02:47 DEBUG : empty space: Unchanged skipping 2025/04/22 06:02:47 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe': Waiting for transfers to finish 2025/04/22 06:02:47 DEBUG : Waiting for deletions to finish 2025/04/22 06:02:47 INFO : There was nothing to transfer run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:02:48 DEBUG : enormous: Excluded (Size Filter) 2025/04/22 06:02:48 DEBUG : enormous: Excluded 2025/04/22 06:02:48 DEBUG : potato2: Excluded (Size Filter) 2025/04/22 06:02:48 DEBUG : potato2: Excluded 2025/04/22 06:02:48 DEBUG : potato2: Excluded (Size Filter) 2025/04/22 06:02:48 DEBUG : potato2: Excluded 2025/04/22 06:02:48 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s) 2025/04/22 06:02:48 DEBUG : empty space: Unchanged skipping 2025/04/22 06:02:48 DEBUG : Local file system at /tmp/rclone3506503620: Waiting for checks to finish 2025/04/22 06:02:48 DEBUG : Local file system at /tmp/rclone3506503620: Waiting for transfers to finish 2025/04/22 06:02:48 DEBUG : Waiting for deletions to finish 2025/04/22 06:02:48 INFO : There was nothing to transfer run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" --- PASS: TestSyncWithExclude (5.45s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:02:50 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0 2025/04/22 06:02:52 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0 2025/04/22 06:02:54 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0 2025/04/22 06:02:55 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-zadaved5kewe/dst" 2025/04/22 06:02:56 DEBUG : Starting OpenDrive session with ID: 56b1a95e46ea62fecebc8ac4425876affd318defcf4f4a4ce5ea2a85a7cec5e4 2025/04/22 06:02:56 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-zadaved5kewe/backup" 2025/04/22 06:02:57 DEBUG : Starting OpenDrive session with ID: 59bb24570fc05f77f7848388cc61e384bed695496e22aef5644a01776972b9f4 2025/04/22 06:02:58 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/22 06:02:58 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/22 06:02:58 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe/dst': Waiting for checks to finish 2025/04/22 06:02:58 DEBUG : two: Unchanged skipping 2025/04/22 06:02:58 INFO : one: Moved (server-side) to: one.bak 2025/04/22 06:02:58 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe/dst': Waiting for transfers to finish 2025/04/22 06:02:59 DEBUG : one: Uploading chunk 0, size=4, remain=0 2025/04/22 06:03:00 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/04/22 06:03:00 INFO : one: Copied (new) 2025/04/22 06:03:00 DEBUG : Waiting for deletions to finish 2025/04/22 06:03:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/22 06:03:01 INFO : three.txt: Moved into backup dir 2025/04/22 06:03:02 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0 2025/04/22 06:03:03 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/22 06:03:03 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/22 06:03:03 DEBUG : two: Unchanged skipping 2025/04/22 06:03:03 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe/dst': Waiting for checks to finish 2025/04/22 06:03:04 INFO : one.bak: Deleted 2025/04/22 06:03:04 INFO : one: Moved (server-side) to: one.bak 2025/04/22 06:03:04 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe/dst': Waiting for transfers to finish 2025/04/22 06:03:05 DEBUG : one: Uploading chunk 0, size=5, remain=0 2025/04/22 06:03:06 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/04/22 06:03:06 INFO : one: Copied (new) 2025/04/22 06:03:06 DEBUG : Waiting for deletions to finish 2025/04/22 06:03:06 INFO : three.txt.bak: Deleted 2025/04/22 06:03:06 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/22 06:03:06 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDirWithSuffix (19.23s) === RUN TestSyncSuffix run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:03:09 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0 2025/04/22 06:03:11 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0 2025/04/22 06:03:13 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0 2025/04/22 06:03:14 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-zadaved5kewe/dst" 2025/04/22 06:03:15 DEBUG : Starting OpenDrive session with ID: dd78c2227295930e4f01b7eda2b96d4ba9628599318e0e4293c8fed9a4a49b28 2025/04/22 06:03:15 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/22 06:03:16 DEBUG : one: same parent dir (ODFfODQ1MDUwOF91cWRXNg) - using file/rename instead of move_copy for one.bak 2025/04/22 06:03:16 INFO : one: Moved (server-side) to: one.bak 2025/04/22 06:03:17 DEBUG : one: Uploading chunk 0, size=4, remain=0 2025/04/22 06:03:18 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/04/22 06:03:18 INFO : one: Copied (new) 2025/04/22 06:03:18 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/22 06:03:18 DEBUG : two: Unchanged skipping 2025/04/22 06:03:18 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/22 06:03:19 DEBUG : three.txt: same parent dir (ODFfODQ1MDUwOF91cWRXNg) - using file/rename instead of move_copy for three.txt.bak 2025/04/22 06:03:19 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/22 06:03:19 DEBUG : three.txt: Uploading chunk 0, size=6, remain=0 2025/04/22 06:03:20 DEBUG : three.txt: md5 = 91341eed84691a83caea73aa785736d5 OK 2025/04/22 06:03:20 INFO : three.txt: Copied (new) fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2491 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: listing wrong, want dst/one (4), dst/one.bak (3), dst/three.txt (6), dst/three.txt.bak (5), dst/two (3) got dst/one (4), dst/one.bak (3), dst/three.txt.bak (6), dst/two (3) fstest.go:137: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:137 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:143 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:189 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2491 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: OpenDrive root 'rclone-test-zadaved5kewe'/dst/three.txt.bak: md5 hash incorrect - expecting "35d6d33467aae9a2e3dccb4b6b027878" got "91341eed84691a83caea73aa785736d5" fstest.go:144: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:144 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:189 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2491 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Not equal: expected: 5 actual : 6 Test: TestSyncSuffix Messages: dst/three.txt.bak: size incorrect file=5 vs obj=6 fstest.go:197: Not found "dst/three.txt" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2491 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Not equal: expected: 0 actual : 1 Test: TestSyncSuffix Messages: 1 objects not found fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2497 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: listing wrong, want dst/one (4), dst/one.bak (3), dst/three.txt (6), dst/three.txt.bak (5), dst/two (3) got dst/one (4), dst/one.bak (3), dst/three.txt.bak (6), dst/two (3) fstest.go:137: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:137 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:143 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:189 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2497 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: OpenDrive root 'rclone-test-zadaved5kewe'/dst/three.txt.bak: md5 hash incorrect - expecting "35d6d33467aae9a2e3dccb4b6b027878" got "91341eed84691a83caea73aa785736d5" fstest.go:144: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:144 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:189 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2497 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Not equal: expected: 5 actual : 6 Test: TestSyncSuffix Messages: dst/three.txt.bak: size incorrect file=5 vs obj=6 fstest.go:197: Not found "dst/three.txt" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2497 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Not equal: expected: 0 actual : 1 Test: TestSyncSuffix Messages: 1 objects not found 2025/04/22 06:03:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/22 06:03:38 INFO : one.bak: Deleted 2025/04/22 06:03:38 DEBUG : one: same parent dir (ODFfODQ1MDUwOF91cWRXNg) - using file/rename instead of move_copy for one.bak 2025/04/22 06:03:38 INFO : one: Moved (server-side) to: one.bak 2025/04/22 06:03:39 DEBUG : one: Uploading chunk 0, size=5, remain=0 2025/04/22 06:03:40 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/04/22 06:03:40 INFO : one: Copied (new) 2025/04/22 06:03:40 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/22 06:03:40 DEBUG : two: Unchanged skipping 2025/04/22 06:03:40 DEBUG : three.txt: Need to transfer - File not found at Destination 2025/04/22 06:03:41 DEBUG : three.txt: Uploading chunk 0, size=19, remain=0 2025/04/22 06:03:42 DEBUG : three.txt: md5 = 423e01c5e84a30d129b97aedb6e219a9 OK 2025/04/22 06:03:42 INFO : three.txt: Copied (new) --- FAIL: TestSyncSuffix (35.38s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:03:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/22 06:03:44 INFO : sub dir: Making directory 2025/04/22 06:03:44 INFO : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" --- PASS: TestNothingToTransferWithEmptyDirs (16.13s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" 2025/04/22 06:04:00 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/22 06:04:00 INFO : sub dir: Making directory 2025/04/22 06:04:00 INFO : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" run.go:180: Remote "OpenDrive root 'rclone-test-zadaved5kewe'", Local "Local file system at /tmp/rclone3506503620", Modify Window "1s" --- PASS: TestNothingToTransferWithoutEmptyDirs (15.97s) FAIL 2025/04/22 06:04:16 DEBUG : OpenDrive root 'rclone-test-zadaved5kewe': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestNothingToTransferWithoutEmptyDirs|TestSyncAfterChangingFilesSizeOnly|TestSyncBackupDirWithSuffix|TestSyncSuffix|TestSyncWithExclude)$'" - Finished ERROR in 1m38.111580956s (try 2/5): exit status 1: Failed [TestSyncSuffix]