"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bYandex: -verbose -fast-list -size-limit 1024 -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideMoveOverSelf|TestServerSideMoveWithFilter|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncBackupDirWithSuffix|TestSyncCompareDest|TestSyncNoEmptyDirectories|TestSyncSuffix)$'" - Starting (try 2/5) 2025/01/15 02:53:26 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yenofab8quxo" 2025/01/15 02:53:26 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/15 02:53:26 DEBUG : Creating backend with remote "TestYandex:rclone-test-yenofab8quxo" 2025/01/15 02:53:26 DEBUG : Reset feature "ListR" 2025/01/15 02:53:26 DEBUG : Creating backend with remote "/tmp/rclone2521168858" === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:53:26 INFO : sub dir2: Making directory 2025/01/15 02:53:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 02:53:28 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Waiting for checks to finish 2025/01/15 02:53:28 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Waiting for transfers to finish 2025/01/15 02:53:28 DEBUG : sub dir/hello world: skip slow MD5 on source file, hashing in-transit 2025/01/15 02:53:34 INFO : sub dir/hello world.rclone_chunk.001_45m6hd: Moved (server-side) to: sub dir/hello world 2025/01/15 02:53:34 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/01/15 02:53:34 INFO : sub dir/hello world: Copied (new) 2025/01/15 02:53:34 DEBUG : Waiting for deletions to finish --- PASS: TestSyncNoEmptyDirectories (17.70s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:53:53 INFO : sub dir/hello world.rclone_chunk.001_45mnrr: Moved (server-side) to: sub dir/hello world 2025/01/15 02:53:54 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda" 2025/01/15 02:53:54 DEBUG : Creating backend with remote "TestYandex:rclone-test-kelafiw0tuda" 2025/01/15 02:53:55 DEBUG : Reset feature "ListR" sync_test.go:671: Server side copy (if possible) Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo' -> Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda' 2025/01/15 02:53:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 02:53:56 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Waiting for checks to finish 2025/01/15 02:53:56 DEBUG : sub dir/hello world: copy non-chunked object... 2025/01/15 02:53:56 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Waiting for transfers to finish 2025/01/15 02:53:59 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/01/15 02:53:59 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:54:11 INFO : sub dir/hello world: Deleted 2025/01/15 02:54:14 INFO : sub dir/hello world.rclone_chunk.001_45n5uj: Moved (server-side) to: sub dir/hello world 2025/01/15 02:54:15 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Using server-side directory move 2025/01/15 02:54:16 INFO : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/15 02:54:17 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/15 02:54:17 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Waiting for checks to finish 2025/01/15 02:54:17 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Waiting for transfers to finish 2025/01/15 02:54:21 INFO : sub dir/hello world: Deleted 2025/01/15 02:54:21 DEBUG : sub dir/hello world: move non-chunked object... 2025/01/15 02:54:23 INFO : sub dir/hello world: Moved (server-side) 2025/01/15 02:54:23 INFO : sub dir/hello world: Moved (server-side) 2025/01/15 02:54:31 INFO : sub dir/hello world.rclone_chunk.001_45nrum: Moved (server-side) to: sub dir/hello world 2025/01/15 02:54:32 DEBUG : testing file moves 2025/01/15 02:54:33 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/01/15 02:54:33 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Waiting for checks to finish 2025/01/15 02:54:33 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Waiting for transfers to finish 2025/01/15 02:54:36 INFO : sub dir/hello world: Deleted 2025/01/15 02:54:36 DEBUG : sub dir/hello world: move non-chunked object... 2025/01/15 02:54:38 INFO : sub dir/hello world: Moved (server-side) 2025/01/15 02:54:38 INFO : sub dir/hello world: Moved (server-side) run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:54:41 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-kelafiw0tuda': Purge remote --- PASS: TestServerSideMoveOverSelf (71.39s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:55:04 INFO : b/potato.rclone_chunk.001_45om78: Moved (server-side) to: b/potato 2025/01/15 02:55:12 INFO : c/non empty space.rclone_chunk.001_45ovmo: Moved (server-side) to: c/non empty space 2025/01/15 02:55:12 INFO : d: Making directory 2025/01/15 02:55:12 INFO : d/e: Making directory 2025/01/15 02:55:15 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/15 02:55:15 DEBUG : a/potato2: skip slow MD5 on source file, hashing in-transit 2025/01/15 02:55:16 DEBUG : c/non empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:55:16 DEBUG : c/non empty space: Unchanged skipping 2025/01/15 02:55:16 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Waiting for checks to finish 2025/01/15 02:55:16 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Waiting for transfers to finish 2025/01/15 02:55:23 INFO : a/potato2.rclone_chunk.001_45p50g: Moved (server-side) to: a/potato2.rclone_chunk.001 2025/01/15 02:55:25 INFO : a/potato2.rclone_chunk.002_45p50g: Moved (server-side) to: a/potato2.rclone_chunk.002 2025/01/15 02:55:29 DEBUG : a/potato2: md5 = d6548b156ea68a4e003e786df99eee76 OK 2025/01/15 02:55:29 INFO : a/potato2: Copied (new) 2025/01/15 02:55:29 DEBUG : Waiting for deletions to finish 2025/01/15 02:55:34 INFO : b/potato: Deleted 2025/01/15 02:55:34 INFO : d/e: Removing directory 2025/01/15 02:55:38 INFO : d: Removing directory 2025/01/15 02:55:43 INFO : b: Removing directory 2025/01/15 02:55:48 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': deleted 3 directories run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (82.06s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:56:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 02:56:18 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/01/15 02:56:18 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Waiting for checks to finish 2025/01/15 02:56:18 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Waiting for transfers to finish 2025/01/15 02:56:18 DEBUG : sub dir/hello world: skip slow MD5 on source file, hashing in-transit 2025/01/15 02:56:19 DEBUG : nested/sub dir/file: skip slow MD5 on source file, hashing in-transit 2025/01/15 02:56:24 INFO : sub dir/hello world.rclone_chunk.001_45qwdz: Moved (server-side) to: sub dir/hello world 2025/01/15 02:56:24 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/01/15 02:56:24 INFO : sub dir/hello world: Copied (new) 2025/01/15 02:56:24 INFO : sub dir/hello world: Deleted 2025/01/15 02:56:25 INFO : nested/sub dir/file.rclone_chunk.001_45qxpw: Moved (server-side) to: nested/sub dir/file 2025/01/15 02:56:25 DEBUG : nested/sub dir/file: md5 = 83d3784ea62518eafc60e98d84f877ad OK 2025/01/15 02:56:25 INFO : nested/sub dir/file: Copied (new) 2025/01/15 02:56:25 INFO : nested/sub dir/file: Deleted 2025/01/15 02:56:25 INFO : sub dir: Removing directory 2025/01/15 02:56:25 INFO : nested/sub dir: Removing directory 2025/01/15 02:56:25 INFO : nested: Removing directory 2025/01/15 02:56:25 DEBUG : Local file system at /tmp/rclone2521168858: deleted 3 directories run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" --- PASS: TestMoveWithDeleteEmptySrcDirs (36.21s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:56:54 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-tedoguj3gugi" 2025/01/15 02:56:54 DEBUG : Config file has changed externally - reloading 2025/01/15 02:56:54 DEBUG : Creating backend with remote "TestYandex:rclone-test-tedoguj3gugi" 2025/01/15 02:56:54 DEBUG : Reset feature "ListR" 2025/01/15 02:57:00 DEBUG : pacer: low level retry 1/10 (error [500 - InternalServerError] Internal Server Error (Ошибка сервера.)) 2025/01/15 02:57:00 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/01/15 02:57:01 DEBUG : pacer: Reducing sleep to 15ms 2025/01/15 02:57:01 DEBUG : pacer: Reducing sleep to 11.25ms 2025/01/15 02:57:02 DEBUG : pacer: Reducing sleep to 10ms 2025/01/15 02:57:04 INFO : potato2.rclone_chunk.001_45rx8e: Moved (server-side) to: potato2.rclone_chunk.001 2025/01/15 02:57:06 INFO : potato2.rclone_chunk.002_45rx8e: Moved (server-side) to: potato2.rclone_chunk.002 2025/01/15 02:57:15 INFO : empty space.rclone_chunk.001_45sbz2: Moved (server-side) to: empty space 2025/01/15 02:57:23 INFO : potato3.rclone_chunk.001_45sh4w: Moved (server-side) to: potato3.rclone_chunk.001 2025/01/15 02:57:25 INFO : potato3.rclone_chunk.002_45sh4w: Moved (server-side) to: potato3.rclone_chunk.002 sync_test.go:1705: Server side move (if possible) Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo' -> Chunked 'TestChunkerChunk50bYandex:rclone-test-tedoguj3gugi' 2025/01/15 02:57:35 INFO : empty space.rclone_chunk.001_45sv9q: Moved (server-side) to: empty space 2025/01/15 02:57:44 INFO : potato3.rclone_chunk.001_45t2md: Moved (server-side) to: potato3.rclone_chunk.001 2025/01/15 02:57:49 INFO : potato3.rclone_chunk.002_45t2md: Moved (server-side) to: potato3.rclone_chunk.002 2025/01/15 02:57:53 DEBUG : empty space: Excluded (Size Filter) 2025/01/15 02:57:53 DEBUG : empty space: Excluded 2025/01/15 02:57:53 DEBUG : empty space: Excluded (Size Filter) 2025/01/15 02:57:53 DEBUG : empty space: Excluded 2025/01/15 02:57:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 02:57:53 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/15 02:57:53 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-tedoguj3gugi': Waiting for checks to finish 2025/01/15 02:57:53 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-tedoguj3gugi': Waiting for transfers to finish 2025/01/15 02:57:54 DEBUG : potato2: move 2 data chunks... 2025/01/15 02:57:56 INFO : potato2.rclone_chunk.001: Moved (server-side) 2025/01/15 02:57:58 INFO : potato2.rclone_chunk.002: Moved (server-side) 2025/01/15 02:58:00 INFO : potato2: Moved (server-side) 2025/01/15 02:58:05 INFO : potato3: Deleted 2025/01/15 02:58:05 DEBUG : potato3: move 2 data chunks... 2025/01/15 02:58:05 INFO : potato2: Moved (server-side) 2025/01/15 02:58:07 INFO : potato3.rclone_chunk.001: Moved (server-side) 2025/01/15 02:58:09 INFO : potato3.rclone_chunk.002: Moved (server-side) 2025/01/15 02:58:11 INFO : potato3: Moved (server-side) 2025/01/15 02:58:14 INFO : potato3: Moved (server-side) 2025/01/15 02:58:16 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yeyesiy3nike" 2025/01/15 02:58:16 DEBUG : Config file has changed externally - reloading 2025/01/15 02:58:16 DEBUG : Creating backend with remote "TestYandex:rclone-test-yeyesiy3nike" 2025/01/15 02:58:16 DEBUG : Reset feature "ListR" 2025/01/15 02:58:17 DEBUG : empty space: Excluded (Size Filter) 2025/01/15 02:58:17 DEBUG : empty space: Excluded 2025/01/15 02:58:17 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 02:58:17 DEBUG : potato3: Need to transfer - File not found at Destination 2025/01/15 02:58:17 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yeyesiy3nike': Waiting for checks to finish 2025/01/15 02:58:17 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yeyesiy3nike': Waiting for transfers to finish 2025/01/15 02:58:17 DEBUG : potato3: move 2 data chunks... 2025/01/15 02:58:17 DEBUG : potato2: move 2 data chunks... 2025/01/15 02:58:19 INFO : potato2.rclone_chunk.001: Moved (server-side) 2025/01/15 02:58:19 INFO : potato3.rclone_chunk.001: Moved (server-side) 2025/01/15 02:58:21 INFO : potato2.rclone_chunk.002: Moved (server-side) 2025/01/15 02:58:22 INFO : potato3.rclone_chunk.002: Moved (server-side) 2025/01/15 02:58:23 INFO : potato2: Moved (server-side) 2025/01/15 02:58:23 INFO : potato3: Moved (server-side) 2025/01/15 02:58:26 INFO : potato3: Moved (server-side) 2025/01/15 02:58:26 INFO : potato2: Moved (server-side) 2025/01/15 02:58:28 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yeyesiy3nike': Purge remote 2025/01/15 02:58:39 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-tedoguj3gugi': Purge remote --- PASS: TestServerSideMoveWithFilter (116.62s) === RUN TestSyncCompareDest run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 02:58:50 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst" 2025/01/15 02:58:50 DEBUG : Creating backend with remote "TestYandex:rclone-test-yenofab8quxo/dst" 2025/01/15 02:58:51 DEBUG : Reset feature "ListR" 2025/01/15 02:58:51 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/CompareDest" 2025/01/15 02:58:51 DEBUG : Creating backend with remote "TestYandex:rclone-test-yenofab8quxo/CompareDest" 2025/01/15 02:58:51 DEBUG : Reset feature "ListR" 2025/01/15 02:58:53 DEBUG : one: Need to transfer - File not found at Destination 2025/01/15 02:58:53 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 02:58:53 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 02:58:53 DEBUG : one: skip slow MD5 on source file, hashing in-transit 2025/01/15 02:59:00 INFO : one.rclone_chunk.001_45v7rh: Moved (server-side) to: one 2025/01/15 02:59:00 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK 2025/01/15 02:59:00 INFO : one: Copied (new) 2025/01/15 02:59:00 DEBUG : Waiting for deletions to finish 2025/01/15 02:59:03 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 02:59:03 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 02:59:03 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 02:59:03 DEBUG : one: skip slow MD5 on source file, hashing in-transit 2025/01/15 02:59:12 INFO : one: Deleted 2025/01/15 02:59:14 INFO : one.rclone_chunk.001_45vhll: Moved (server-side) to: one 2025/01/15 02:59:14 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK 2025/01/15 02:59:14 INFO : one: Copied (replaced existing) 2025/01/15 02:59:14 DEBUG : Waiting for deletions to finish 2025/01/15 02:59:24 INFO : dst/one: Deleted 2025/01/15 02:59:26 INFO : dst/one.rclone_chunk.001_45vuyh: Moved (server-side) to: dst/one 2025/01/15 02:59:29 DEBUG : pacer: low level retry 1/10 (error [500 - InternalServerError] Internal Server Error (Ошибка сервера.)) 2025/01/15 02:59:29 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/01/15 02:59:30 DEBUG : pacer: Reducing sleep to 15ms 2025/01/15 02:59:30 DEBUG : pacer: Reducing sleep to 11.25ms 2025/01/15 02:59:31 DEBUG : pacer: Reducing sleep to 10ms 2025/01/15 02:59:34 INFO : CompareDest/one.rclone_chunk.001_45w46v: Moved (server-side) to: CompareDest/one 2025/01/15 02:59:36 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 02:59:36 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 02:59:37 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:59:37 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 02:59:37 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 02:59:37 DEBUG : Waiting for deletions to finish 2025/01/15 02:59:37 INFO : There was nothing to transfer 2025/01/15 02:59:44 INFO : CompareDest/two.rclone_chunk.001_45wguw: Moved (server-side) to: CompareDest/two 2025/01/15 02:59:47 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:59:47 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/15 02:59:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 02:59:47 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 02:59:48 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:59:48 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 02:59:48 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 02:59:48 DEBUG : Waiting for deletions to finish 2025/01/15 02:59:48 INFO : There was nothing to transfer 2025/01/15 02:59:52 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:59:52 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/15 02:59:52 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 02:59:52 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 02:59:52 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:59:52 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 02:59:52 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 02:59:52 DEBUG : Waiting for deletions to finish 2025/01/15 02:59:52 INFO : There was nothing to transfer 2025/01/15 02:59:56 DEBUG : two: Modification times differ by -119h59m59.876543211s: 2011-12-30 12:59:59 +0000 UTC, 2011-12-25 12:59:59.123456789 +0000 UTC 2025/01/15 02:59:56 DEBUG : two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK 2025/01/15 02:59:56 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/15 02:59:56 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 02:59:56 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 02:59:57 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 02:59:57 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 02:59:57 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 02:59:57 DEBUG : Waiting for deletions to finish 2025/01/15 02:59:57 INFO : There was nothing to transfer 2025/01/15 03:00:01 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/01/15 03:00:01 DEBUG : two: Need to transfer - File not found at Destination 2025/01/15 03:00:01 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 03:00:01 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 03:00:02 DEBUG : two: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:00:02 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 03:00:02 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 03:00:02 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 03:00:12 INFO : two.rclone_chunk.001_45x4la: Moved (server-side) to: two 2025/01/15 03:00:12 DEBUG : two: md5 = 2379e4ce8c3380e996ab0509f17069ad OK 2025/01/15 03:00:12 INFO : two: Copied (new) 2025/01/15 03:00:12 DEBUG : Waiting for deletions to finish --- PASS: TestSyncCompareDest (108.77s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 03:00:45 INFO : dst/one.rclone_chunk.001_45y6lg: Moved (server-side) to: dst/one 2025/01/15 03:00:51 INFO : dst/two.rclone_chunk.001_45yc4y: Moved (server-side) to: dst/two 2025/01/15 03:00:56 INFO : dst/three.txt.rclone_chunk.001_45yicx: Moved (server-side) to: dst/three.txt 2025/01/15 03:00:57 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst" 2025/01/15 03:00:57 DEBUG : Creating backend with remote "TestYandex:rclone-test-yenofab8quxo/dst" 2025/01/15 03:00:58 DEBUG : Reset feature "ListR" 2025/01/15 03:00:58 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/backup" 2025/01/15 03:00:58 DEBUG : Creating backend with remote "TestYandex:rclone-test-yenofab8quxo/backup" 2025/01/15 03:00:58 DEBUG : Reset feature "ListR" 2025/01/15 03:00:59 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 03:00:59 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 03:00:59 DEBUG : two: Unchanged skipping 2025/01/15 03:00:59 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 03:00:59 DEBUG : one: move non-chunked object... 2025/01/15 03:01:03 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:01:03 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:01:03 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 03:01:03 DEBUG : one: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:01:09 INFO : one.rclone_chunk.001_45ythl: Moved (server-side) to: one 2025/01/15 03:01:09 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/01/15 03:01:09 INFO : one: Copied (new) 2025/01/15 03:01:09 DEBUG : Waiting for deletions to finish 2025/01/15 03:01:09 DEBUG : three.txt: move non-chunked object... 2025/01/15 03:01:11 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:01:11 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:01:11 INFO : three.txt: Moved into backup dir 2025/01/15 03:01:22 INFO : dst/three.txt.rclone_chunk.001_45z6u2: Moved (server-side) to: dst/three.txt 2025/01/15 03:01:23 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 03:01:23 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 03:01:23 DEBUG : two: Unchanged skipping 2025/01/15 03:01:23 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for checks to finish 2025/01/15 03:01:28 INFO : one.bak: Deleted 2025/01/15 03:01:28 DEBUG : one: move non-chunked object... 2025/01/15 03:01:30 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:01:30 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:01:30 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst': Waiting for transfers to finish 2025/01/15 03:01:30 DEBUG : one: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:01:33 DEBUG : pacer: low level retry 1/10 (error [500 - InternalServerError] Internal Server Error (Ошибка сервера.)) 2025/01/15 03:01:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/01/15 03:01:34 DEBUG : pacer: Reducing sleep to 15ms 2025/01/15 03:01:34 DEBUG : pacer: Reducing sleep to 11.25ms 2025/01/15 03:01:35 DEBUG : pacer: Reducing sleep to 10ms 2025/01/15 03:01:37 INFO : one.rclone_chunk.001_45zkq4: Moved (server-side) to: one 2025/01/15 03:01:37 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/01/15 03:01:37 INFO : one: Copied (new) 2025/01/15 03:01:37 DEBUG : Waiting for deletions to finish 2025/01/15 03:01:44 INFO : three.txt.bak: Deleted 2025/01/15 03:01:44 DEBUG : three.txt: move non-chunked object... 2025/01/15 03:01:46 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:01:46 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:01:46 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDirWithSuffix (101.26s) === RUN TestSyncSuffix run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo'", Local "Local file system at /tmp/rclone2521168858", Modify Window "1ns" 2025/01/15 03:02:32 INFO : dst/one.rclone_chunk.001_460zo5: Moved (server-side) to: dst/one 2025/01/15 03:02:38 INFO : dst/two.rclone_chunk.001_461al6: Moved (server-side) to: dst/two 2025/01/15 03:02:41 DEBUG : pacer: low level retry 1/10 (error [500 - InternalServerError] Internal Server Error (Ошибка сервера.)) 2025/01/15 03:02:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/01/15 03:02:42 DEBUG : pacer: Reducing sleep to 15ms 2025/01/15 03:02:42 DEBUG : pacer: Reducing sleep to 11.25ms 2025/01/15 03:02:42 DEBUG : pacer: Reducing sleep to 10ms 2025/01/15 03:02:45 INFO : dst/three.txt.rclone_chunk.001_461hha: Moved (server-side) to: dst/three.txt 2025/01/15 03:02:45 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-yenofab8quxo/dst" 2025/01/15 03:02:45 DEBUG : Config file has changed externally - reloading 2025/01/15 03:02:45 DEBUG : Creating backend with remote "TestYandex:rclone-test-yenofab8quxo/dst" 2025/01/15 03:02:46 DEBUG : Reset feature "ListR" 2025/01/15 03:02:47 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 03:02:47 DEBUG : one: move non-chunked object... 2025/01/15 03:02:50 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:02:50 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:02:50 DEBUG : one: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:02:57 INFO : one.rclone_chunk.001_461sz8: Moved (server-side) to: one 2025/01/15 03:02:57 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/01/15 03:02:57 INFO : one: Copied (new) 2025/01/15 03:02:58 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 03:02:58 DEBUG : two: Unchanged skipping 2025/01/15 03:02:59 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/01/15 03:02:59 DEBUG : three.txt: move non-chunked object... 2025/01/15 03:03:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:03:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:03:01 DEBUG : three.txt: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:03:12 INFO : three.txt.rclone_chunk.001_46238v: Moved (server-side) to: three.txt 2025/01/15 03:03:12 DEBUG : three.txt: md5 = 91341eed84691a83caea73aa785736d5 OK 2025/01/15 03:03:12 INFO : three.txt: Copied (new) 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:2491 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: dst/one: Modification time difference too big |-114470h2m56.876543211s| > 1ns (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2025-01-15 03:02:56 +0000 UTC) (precision 1ns) 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:2497 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: dst/one: Modification time difference too big |-114470h2m56.876543211s| > 1ns (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2025-01-15 03:02:56 +0000 UTC) (precision 1ns) 2025/01/15 03:03:15 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 03:03:20 INFO : one.bak: Deleted 2025/01/15 03:03:20 DEBUG : one: move non-chunked object... 2025/01/15 03:03:21 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:03:21 INFO : one: Moved (server-side) to: one.bak 2025/01/15 03:03:22 DEBUG : one: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:03:28 INFO : one.rclone_chunk.001_462ove: Moved (server-side) to: one 2025/01/15 03:03:28 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/01/15 03:03:28 INFO : one: Copied (new) 2025/01/15 03:03:29 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2025/01/15 03:03:29 DEBUG : two: Unchanged skipping 2025/01/15 03:03:30 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/01/15 03:03:35 INFO : three.txt.bak: Deleted 2025/01/15 03:03:35 DEBUG : three.txt: move non-chunked object... 2025/01/15 03:03:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:03:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 03:03:37 DEBUG : three.txt: skip slow MD5 on source file, hashing in-transit 2025/01/15 03:03:43 INFO : three.txt.rclone_chunk.001_4633cf: Moved (server-side) to: three.txt 2025/01/15 03:03:43 DEBUG : three.txt: md5 = 423e01c5e84a30d129b97aedb6e219a9 OK 2025/01/15 03:03:43 INFO : three.txt: Copied (new) 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:2521 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2523 Error: Should be true Test: TestSyncSuffix Messages: dst/one.bak: Modification time difference too big |-114470h3m21.876543211s| > 1ns (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2025-01-15 03:03:21 +0000 UTC) (precision 1ns) --- FAIL: TestSyncSuffix (107.46s) FAIL 2025/01/15 03:04:08 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-yenofab8quxo': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bYandex: -verbose -fast-list -size-limit 1024 -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideMoveOverSelf|TestServerSideMoveWithFilter|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncBackupDirWithSuffix|TestSyncCompareDest|TestSyncNoEmptyDirectories|TestSyncSuffix)$'" - Finished ERROR in 10m46.386249469s (try 2/5): exit status 1: Failed [TestSyncSuffix]