"./sync.test -test.v -test.timeout 1h0m0s -remote TestYandex: -verbose -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideCopyOverSelf|TestServerSideMoveOverSelf|TestSyncBackupDirWithSuffixKeepExtension|TestSyncConcurrentDelete|TestSyncReplaceDirModTime)$'" - Starting (try 2/5) 2025/02/21 04:51:54 DEBUG : Creating backend with remote "TestYandex:rclone-test-jonovov0tome" 2025/02/21 04:51:54 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/02/21 04:51:54 DEBUG : Creating backend with remote "/tmp/rclone4012599330" === RUN TestServerSideCopyOverSelf run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:51:59 DEBUG : Creating backend with remote "TestYandex:rclone-test-kipemow2ciko" sync_test.go:626: Server side copy (if possible) Yandex rclone-test-jonovov0tome -> Yandex rclone-test-kipemow2ciko 2025/02/21 04:52:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/21 04:52:00 DEBUG : Yandex rclone-test-kipemow2ciko: Waiting for checks to finish 2025/02/21 04:52:00 DEBUG : Yandex rclone-test-kipemow2ciko: Waiting for transfers to finish 2025/02/21 04:52:03 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/02/21 04:52:03 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:52:09 DEBUG : Yandex rclone-test-kipemow2ciko: Waiting for checks to finish 2025/02/21 04:52:09 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/21 04:52:09 DEBUG : Yandex rclone-test-kipemow2ciko: Waiting for transfers to finish 2025/02/21 04:52:10 DEBUG : sub dir/hello world: server side copy: renaming existing object to "sub dir/hello world.macenub3" before starting 2025/02/21 04:52:12 DEBUG : sub dir/hello world.macenub3: server side copy: removing renamed existing file after operation 2025/02/21 04:52:17 DEBUG : sub dir/hello world: md5 = 00321a507bdb420dbbd4f53c733b1505 OK 2025/02/21 04:52:17 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:52:18 DEBUG : Yandex rclone-test-kipemow2ciko: Purge remote --- PASS: TestServerSideCopyOverSelf (40.47s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:52:39 DEBUG : Creating backend with remote "TestYandex:rclone-test-lojuwek0reso" sync_test.go:671: Server side copy (if possible) Yandex rclone-test-jonovov0tome -> Yandex rclone-test-lojuwek0reso 2025/02/21 04:52:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/21 04:52:40 DEBUG : Yandex rclone-test-lojuwek0reso: Waiting for checks to finish 2025/02/21 04:52:40 DEBUG : Yandex rclone-test-lojuwek0reso: Waiting for transfers to finish 2025/02/21 04:52:43 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/02/21 04:52:43 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:52:47 DEBUG : Yandex rclone-test-lojuwek0reso: Using server-side directory move 2025/02/21 04:52:48 INFO : Yandex rclone-test-lojuwek0reso: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/21 04:52:49 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/21 04:52:49 DEBUG : Yandex rclone-test-lojuwek0reso: Waiting for checks to finish 2025/02/21 04:52:49 DEBUG : Yandex rclone-test-lojuwek0reso: Waiting for transfers to finish 2025/02/21 04:52:52 INFO : sub dir/hello world: Deleted 2025/02/21 04:52:54 INFO : sub dir/hello world: Moved (server-side) fstest.go:121: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:121 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:126 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:145 /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:691 Error: Should be true Test: TestServerSideMoveOverSelf Messages: sub dir/hello world: Modification time difference too big |-115239h52m58s| > 1ns (want 2011-12-30 12:59:59 +0000 UTC vs got 2025-02-21 04:52:57 +0000 UTC) (precision 1ns) 2025/02/21 04:52:58 DEBUG : testing file moves 2025/02/21 04:52:59 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/02/21 04:52:59 DEBUG : Yandex rclone-test-lojuwek0reso: Waiting for checks to finish 2025/02/21 04:52:59 DEBUG : Yandex rclone-test-lojuwek0reso: Waiting for transfers to finish 2025/02/21 04:53:03 INFO : sub dir/hello world: Deleted 2025/02/21 04:53:04 INFO : sub dir/hello world: Moved (server-side) run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" Diff of "logger" and "lsf" 2c2 < 2025-02-21 04:52:57.000000000;c0e6b00e2b2068ef74d2ed582114e376;24;sub dir/hello world --- > 2025-02-21 04:53:04.000000000;c0e6b00e2b2068ef74d2ed582114e376;24;sub dir/hello world sync_test.go:3072: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:3072 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:697 Error: Received unexpected error: logger does not match lsf! logger: 2025-02-21 04:52:57.000000000;c0e6b00e2b2068ef74d2ed582114e376;24;sub dir/hello world lsf: 2025-02-21 04:53:04.000000000;c0e6b00e2b2068ef74d2ed582114e376;24;sub dir/hello world Test: TestServerSideMoveOverSelf 2025/02/21 04:53:05 DEBUG : Yandex rclone-test-lojuwek0reso: Purge remote --- FAIL: TestServerSideMoveOverSelf (42.61s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:53:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/21 04:53:18 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/21 04:53:18 DEBUG : Yandex rclone-test-jonovov0tome: Waiting for checks to finish 2025/02/21 04:53:18 DEBUG : Yandex rclone-test-jonovov0tome: Waiting for transfers to finish 2025/02/21 04:53:20 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/02/21 04:53:20 INFO : sub dir/hello world: Copied (new) 2025/02/21 04:53:20 INFO : sub dir/hello world: Deleted 2025/02/21 04:53:29 DEBUG : nested/sub dir/file: md5 = 83d3784ea62518eafc60e98d84f877ad OK 2025/02/21 04:53:29 INFO : nested/sub dir/file: Copied (new) 2025/02/21 04:53:29 INFO : nested/sub dir/file: Deleted 2025/02/21 04:53:29 INFO : sub dir: Removing directory 2025/02/21 04:53:29 INFO : nested/sub dir: Removing directory 2025/02/21 04:53:29 INFO : nested: Removing directory 2025/02/21 04:53:29 DEBUG : Local file system at /tmp/rclone4012599330: deleted 3 directories run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" --- PASS: TestMoveWithDeleteEmptySrcDirs (47.16s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:54:11 DEBUG : Creating backend with remote "TestYandex:rclone-test-jonovov0tome/dst" 2025/02/21 04:54:11 DEBUG : Creating backend with remote "TestYandex:rclone-test-jonovov0tome/backup" 2025/02/21 04:54:12 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/21 04:54:12 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:54:12 DEBUG : two: Unchanged skipping 2025/02/21 04:54:12 DEBUG : Yandex rclone-test-jonovov0tome/dst: Waiting for checks to finish 2025/02/21 04:54:14 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/21 04:54:14 DEBUG : Yandex rclone-test-jonovov0tome/dst: Waiting for transfers to finish 2025/02/21 04:54:16 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/02/21 04:54:16 INFO : one: Copied (new) 2025/02/21 04:54:16 DEBUG : Waiting for deletions to finish 2025/02/21 04:54:18 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/21 04:54:18 INFO : three.txt: Moved into backup dir 2025/02/21 04:54:22 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/21 04:54:22 DEBUG : Yandex rclone-test-jonovov0tome/dst: Waiting for checks to finish 2025/02/21 04:54:22 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:54:22 DEBUG : two: Unchanged skipping 2025/02/21 04:54:26 INFO : one-2019-01-01: Deleted 2025/02/21 04:54:27 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/21 04:54:27 DEBUG : Yandex rclone-test-jonovov0tome/dst: Waiting for transfers to finish 2025/02/21 04:54:29 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/02/21 04:54:29 INFO : one: Copied (new) 2025/02/21 04:54:29 DEBUG : Waiting for deletions to finish 2025/02/21 04:54:33 INFO : three-2019-01-01.txt: Deleted 2025/02/21 04:54:35 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/21 04:54:35 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDirWithSuffixKeepExtension (56.82s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:56:36 DEBUG : Yandex rclone-test-jonovov0tome: Waiting for checks to finish 2025/02/21 04:56:36 DEBUG : both1: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both0: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both11: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both10: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both1: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both12: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both12: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both13: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both0: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both14: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both14: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both15: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both11: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both16: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both16: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both17: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both17: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both18: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both18: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both19: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both19: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both2: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both2: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both3: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both3: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both4: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both4: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both5: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both5: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both6: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both6: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both7: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both7: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both8: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both8: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both9: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/02/21 04:56:36 DEBUG : both9: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both10: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both13: Unchanged skipping 2025/02/21 04:56:36 DEBUG : both15: Unchanged skipping 2025/02/21 04:56:36 DEBUG : Yandex rclone-test-jonovov0tome: Waiting for transfers to finish 2025/02/21 04:56:36 DEBUG : Waiting for deletions to finish 2025/02/21 04:56:39 INFO : only17: Deleted 2025/02/21 04:56:39 INFO : only10: Deleted 2025/02/21 04:56:40 INFO : only0: Deleted 2025/02/21 04:56:42 INFO : only6: Deleted 2025/02/21 04:56:43 INFO : only3: Deleted 2025/02/21 04:56:43 INFO : only1: Deleted 2025/02/21 04:56:44 INFO : only15: Deleted 2025/02/21 04:56:46 INFO : only18: Deleted 2025/02/21 04:56:46 INFO : only7: Deleted 2025/02/21 04:56:46 INFO : only4: Deleted 2025/02/21 04:56:49 INFO : only12: Deleted 2025/02/21 04:56:50 INFO : only14: Deleted 2025/02/21 04:56:50 INFO : only2: Deleted 2025/02/21 04:56:50 INFO : only11: Deleted 2025/02/21 04:56:52 INFO : only5: Deleted 2025/02/21 04:56:53 INFO : only8: Deleted 2025/02/21 04:56:54 INFO : only13: Deleted 2025/02/21 04:56:54 INFO : only9: Deleted 2025/02/21 04:56:55 INFO : only16: Deleted 2025/02/21 04:56:58 INFO : only19: Deleted run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" --- PASS: TestSyncConcurrentDelete (188.03s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:58:09 DEBUG : empty_dir: Making directory with metadata 2025/02/21 04:58:09 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/21 04:58:09 DEBUG : empty_on_remote: Making directory with metadata 2025/02/21 04:58:09 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/21 04:58:09 INFO : empty_on_remote: Making directory 2025/02/21 04:58:10 INFO : empty_on_remote: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" 2025/02/21 04:58:15 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/02/21 04:58:15 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/02/21 04:58:15 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/02/21 04:58:15 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Yandex rclone-test-jonovov0tome", Local "Local file system at /tmp/rclone4012599330", Modify Window "1ns" --- PASS: TestSyncReplaceDirModTime (42.31s) FAIL 2025/02/21 04:58:52 DEBUG : Yandex rclone-test-jonovov0tome: Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestYandex: -verbose -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideCopyOverSelf|TestServerSideMoveOverSelf|TestSyncBackupDirWithSuffixKeepExtension|TestSyncConcurrentDelete|TestSyncReplaceDirModTime)$'" - Finished ERROR in 7m3.78371356s (try 2/5): exit status 1: Failed [TestServerSideMoveOverSelf]