"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestBase64|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncBackupDirWithSuffix)$'" - Starting (try 3/5) 2025/08/12 04:05:21 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-meratup4qoni" 2025/08/12 04:05:21 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/08/12 04:05:21 DEBUG : Starting OpenDrive session with ID: d996e2cdcfcaca7114d02ee61286aace360711562692f80a315dfa19e74d6a5e 2025/08/12 04:05:22 DEBUG : Creating backend with remote "/tmp/rclone2343269543" === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "OpenDrive root 'rclone-test-meratup4qoni'", Local "Local file system at /tmp/rclone2343269543", Modify Window "1s" 2025/08/12 04:05:23 DEBUG : b/potato: Uploading chunk 0, size=21, remain=0 2025/08/12 04:05:26 DEBUG : c/non empty space: Uploading chunk 0, size=5, remain=0 2025/08/12 04:05:27 INFO : d: Making directory 2025/08/12 04:05:27 INFO : d/e: Making directory 2025/08/12 04:05:28 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/08/12 04:05:28 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/08/12 04:05:28 DEBUG : c/non empty space: Unchanged skipping 2025/08/12 04:05:29 DEBUG : OpenDrive root 'rclone-test-meratup4qoni': Waiting for checks to finish 2025/08/12 04:05:29 DEBUG : OpenDrive root 'rclone-test-meratup4qoni': Waiting for transfers to finish 2025/08/12 04:05:29 DEBUG : a/potato2: Uploading chunk 0, size=60, remain=0 2025/08/12 04:05:31 DEBUG : a/potato2: md5 = d6548b156ea68a4e003e786df99eee76 OK 2025/08/12 04:05:31 INFO : a/potato2: Copied (new) 2025/08/12 04:05:31 DEBUG : Waiting for deletions to finish 2025/08/12 04:05:31 INFO : b/potato: Deleted 2025/08/12 04:05:31 INFO : d/e: Removing directory 2025/08/12 04:05:31 INFO : d: Removing directory 2025/08/12 04:05:31 INFO : b: Removing directory 2025/08/12 04:05:32 DEBUG : OpenDrive root 'rclone-test-meratup4qoni': deleted 3 directories fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:289: Sleeping for 6s just to make sure --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (20.01s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "OpenDrive root 'rclone-test-meratup4qoni'", Local "Local file system at /tmp/rclone2343269543", Modify Window "1s" 2025/08/12 04:05:43 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0 2025/08/12 04:05:45 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0 2025/08/12 04:05:47 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0 2025/08/12 04:05:48 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-meratup4qoni/dst" 2025/08/12 04:05:49 DEBUG : Starting OpenDrive session with ID: 1e96cdff5f8c73a89db6f012a5381183d38ba9cb176a1543d10061cdad039741 2025/08/12 04:05:49 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-meratup4qoni/backup" 2025/08/12 04:05:49 DEBUG : Starting OpenDrive session with ID: ec6ed61a8116dd3b85761b9e61e5f15d667d769a3970d74315d4c5dad3b9a07c 2025/08/12 04:05:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/08/12 04:05:50 DEBUG : OpenDrive root 'rclone-test-meratup4qoni/dst': Waiting for checks to finish 2025/08/12 04:05:50 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/08/12 04:05:50 DEBUG : two: Unchanged skipping 2025/08/12 04:05:51 INFO : one: Moved (server-side) to: one.bak 2025/08/12 04:05:51 DEBUG : OpenDrive root 'rclone-test-meratup4qoni/dst': Waiting for transfers to finish 2025/08/12 04:05:52 DEBUG : one: Uploading chunk 0, size=4, remain=0 2025/08/12 04:05:53 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/08/12 04:05:53 INFO : one: Copied (new) 2025/08/12 04:05:53 DEBUG : Waiting for deletions to finish 2025/08/12 04:05:54 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/08/12 04:05:54 INFO : three.txt: Moved into backup dir fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2428 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: listing wrong, want backup/one.bak (3), backup/three.txt.bak (5), dst/one (4), dst/two (3) got backup/one.bak (4), backup/three.txt.bak (5), dst/two (3) fstest.go:140: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:140 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:146 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2428 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: OpenDrive root 'rclone-test-meratup4qoni'/backup/one.bak: md5 hash incorrect - expecting "f97c5d29941bfb1b2fdab0874906ab82" got "c7957179c41f69d44f217a108c7915d8" fstest.go:147: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:147 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2428 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Not equal: expected: 3 actual : 4 Test: TestSyncBackupDirWithSuffix Messages: backup/one.bak: size incorrect file=3 vs obj=4 fstest.go:124: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2428 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: backup/one.bak: Modification time difference too big |-95456h54m52.500000001s| > 1s (want 2001-02-03 04:05:06.499999999 +0000 UTC vs got 2011-12-25 12:59:59 +0000 UTC) (precision 1s) fstest.go:200: Not found "dst/one" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2428 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Not equal: expected: 0 actual : 1 Test: TestSyncBackupDirWithSuffix Messages: 1 objects not found 2025/08/12 04:06:03 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0 fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2434 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: listing wrong, want backup/one.bak (3), backup/three.txt.bak (5), dst/one (4), dst/three.txt (6), dst/two (3) got backup/one.bak (4), backup/three.txt.bak (5), dst/three.txt (6), dst/two (3) fstest.go:140: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:140 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:146 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2434 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: OpenDrive root 'rclone-test-meratup4qoni'/backup/one.bak: md5 hash incorrect - expecting "f97c5d29941bfb1b2fdab0874906ab82" got "c7957179c41f69d44f217a108c7915d8" fstest.go:147: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:147 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2434 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Not equal: expected: 3 actual : 4 Test: TestSyncBackupDirWithSuffix Messages: backup/one.bak: size incorrect file=3 vs obj=4 fstest.go:124: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2434 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: backup/one.bak: Modification time difference too big |-95456h54m52.500000001s| > 1s (want 2001-02-03 04:05:06.499999999 +0000 UTC vs got 2011-12-25 12:59:59 +0000 UTC) (precision 1s) fstest.go:200: Not found "dst/one" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347 /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:2434 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2461 Error: Not equal: expected: 0 actual : 1 Test: TestSyncBackupDirWithSuffix Messages: 1 objects not found 2025/08/12 04:06:14 DEBUG : one: Need to transfer - File not found at Destination 2025/08/12 04:06:14 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/08/12 04:06:14 DEBUG : two: Unchanged skipping 2025/08/12 04:06:14 DEBUG : OpenDrive root 'rclone-test-meratup4qoni/dst': Waiting for checks to finish 2025/08/12 04:06:14 DEBUG : OpenDrive root 'rclone-test-meratup4qoni/dst': Waiting for transfers to finish 2025/08/12 04:06:14 DEBUG : one: Uploading chunk 0, size=5, remain=0 2025/08/12 04:06:16 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/08/12 04:06:16 INFO : one: Copied (new) 2025/08/12 04:06:16 DEBUG : Waiting for deletions to finish 2025/08/12 04:06:16 INFO : three.txt.bak: Deleted 2025/08/12 04:06:16 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/08/12 04:06:16 INFO : three.txt: Moved into backup dir fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:289: Sleeping for 6s just to make sure --- FAIL: TestSyncBackupDirWithSuffix (44.80s) === RUN TestBase64 run.go:180: Remote "OpenDrive root 'rclone-test-meratup4qoni'", Local "Local file system at /tmp/rclone2343269543", Modify Window "1s" 2025/08/12 04:06:26 DEBUG : toe: transformed to: dG9l 2025/08/12 04:06:27 DEBUG : toe: transformed to: dG9l 2025/08/12 04:06:27 INFO : dG9l: Making directory 2025/08/12 04:06:27 DEBUG : toe: transformed to: dG9l 2025/08/12 04:06:27 DEBUG : toe: transformed to: dG9l 2025/08/12 04:06:27 DEBUG : toe/toe: transformed to: dG9l/dG9l 2025/08/12 04:06:27 INFO : dG9l/dG9l: Making directory 2025/08/12 04:06:27 DEBUG : toe/toe: transformed to: dG9l/dG9l 2025/08/12 04:06:27 DEBUG : toe.txt: transformed to: dG9lLnR4dA== 2025/08/12 04:06:27 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA== 2025/08/12 04:06:27 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/08/12 04:06:27 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA== 2025/08/12 04:06:27 DEBUG : OpenDrive root 'rclone-test-meratup4qoni': Waiting for checks to finish 2025/08/12 04:06:27 DEBUG : OpenDrive root 'rclone-test-meratup4qoni': Waiting for transfers to finish 2025/08/12 04:06:28 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Uploading chunk 0, size=11, remain=0 2025/08/12 04:06:29 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/08/12 04:06:29 INFO : toe/toe/toe.txt: Copied (new) to: dG9l/dG9l/dG9lLnR4dA== 2025/08/12 04:06:29 DEBUG : Waiting for deletions to finish 2025/08/12 04:06:30 DEBUG : dG9l: transformed to: toe 2025/08/12 04:06:30 DEBUG : dG9l: transformed to: toe 2025/08/12 04:06:30 DEBUG : toe: Directory modification time the same (differ by -122.823776ms, within tolerance 1s) 2025/08/12 04:06:30 DEBUG : Added delayed dir = "toe", newDst=toe 2025/08/12 04:06:30 DEBUG : dG9l: transformed to: toe 2025/08/12 04:06:30 DEBUG : dG9l/dG9l: transformed to: toe/toe 2025/08/12 04:06:30 INFO : toe/toe: Set directory modification time (using SetModTime) 2025/08/12 04:06:30 DEBUG : Added delayed dir = "toe/toe", newDst=toe/toe 2025/08/12 04:06:30 DEBUG : dG9lLnR4dA==: transformed to: toe.txt 2025/08/12 04:06:30 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Size and modification time the same (differ by 499.999999ms, within tolerance 1s) 2025/08/12 04:06:30 DEBUG : dG9l/dG9l/dG9lLnR4dA==: transformed to: toe/toe/toe.txt 2025/08/12 04:06:30 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Unchanged skipping 2025/08/12 04:06:30 DEBUG : Local file system at /tmp/rclone2343269543: Waiting for checks to finish 2025/08/12 04:06:30 DEBUG : Local file system at /tmp/rclone2343269543: Waiting for transfers to finish 2025/08/12 04:06:30 DEBUG : Waiting for deletions to finish run.go:125: removing dir "dG9l/dG9l" failed - try 1/3: folder not empty --- PASS: TestBase64 (7.10s) FAIL 2025/08/12 04:06:33 DEBUG : OpenDrive root 'rclone-test-meratup4qoni': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestBase64|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncBackupDirWithSuffix)$'" - Finished ERROR in 1m13.314595051s (try 3/5): exit status 1: Failed [TestSyncBackupDirWithSuffix]