"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bYandex: -verbose -size-limit 1024 -test.run '^(TestServerSideMoveWithFilter|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncCompareDest|TestSyncIgnoreErrors|TestSyncIgnoreTimes)$'" - Starting (try 2/5)
2025/04/21 03:05:11 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-pocebir2yoje"
2025/04/21 03:05:11 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/21 03:05:11 DEBUG : Creating backend with remote "TestYandex:rclone-test-pocebir2yoje"
2025/04/21 03:05:12 DEBUG : Creating backend with remote "/tmp/rclone1088229363"
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
2025/04/21 03:05:18 INFO  : existing.rclone_chunk.001_1y6q1f: Moved (server-side) to: existing
2025/04/21 03:05:19 DEBUG : existing: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:05:19 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for checks to finish
2025/04/21 03:05:19 DEBUG : existing: Unchanged skipping
2025/04/21 03:05:19 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for transfers to finish
2025/04/21 03:05:19 DEBUG : Waiting for deletions to finish
2025/04/21 03:05:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
2025/04/21 03:05:20 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/04/21 03:05:20 DEBUG : existing: skip slow MD5 on source file, hashing in-transit
2025/04/21 03:05:20 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for checks to finish
2025/04/21 03:05:20 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for transfers to finish
2025/04/21 03:05:27 INFO  : existing: Deleted
2025/04/21 03:05:30 INFO  : existing.rclone_chunk.001_1y6xu4: Moved (server-side) to: existing
2025/04/21 03:05:30 DEBUG : existing: md5 = 8ee2027983915ec78acc45027d874316 OK
2025/04/21 03:05:30 INFO  : existing: Copied (replaced existing)
2025/04/21 03:05:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
--- PASS: TestSyncIgnoreTimes (24.81s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
2025/04/21 03:05:42 INFO  : b/potato.rclone_chunk.001_1y7eqa: Moved (server-side) to: b/potato
2025/04/21 03:05:48 INFO  : c/non empty space.rclone_chunk.001_1y7jvg: Moved (server-side) to: c/non empty space
2025/04/21 03:05:48 INFO  : d: Making directory
2025/04/21 03:05:49 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/21 03:05:50 DEBUG : c/non empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:05:50 DEBUG : c/non empty space: Unchanged skipping
2025/04/21 03:05:50 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for checks to finish
2025/04/21 03:05:50 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for transfers to finish
2025/04/21 03:05:50 DEBUG : a/potato2: skip slow MD5 on source file, hashing in-transit
2025/04/21 03:05:57 INFO  : a/potato2.rclone_chunk.001_1y7r9v: Moved (server-side) to: a/potato2.rclone_chunk.001
2025/04/21 03:05:59 INFO  : a/potato2.rclone_chunk.002_1y7r9v: Moved (server-side) to: a/potato2.rclone_chunk.002
2025/04/21 03:06:01 DEBUG : a/potato2: md5 = d6548b156ea68a4e003e786df99eee76 OK
2025/04/21 03:06:01 INFO  : a/potato2: Copied (new)
2025/04/21 03:06:01 DEBUG : Waiting for deletions to finish
2025/04/21 03:06:07 INFO  : b/potato: Deleted
2025/04/21 03:06:07 INFO  : d: Removing directory
2025/04/21 03:06:12 INFO  : b: Removing directory
2025/04/21 03:06:17 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': deleted 2 directories
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
--- PASS: TestSyncIgnoreErrors (72.38s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
2025/04/21 03:06:55 INFO  : b/potato.rclone_chunk.001_1y9ehr: Moved (server-side) to: b/potato
2025/04/21 03:07:00 INFO  : c/non empty space.rclone_chunk.001_1y9kxr: Moved (server-side) to: c/non empty space
2025/04/21 03:07:00 INFO  : d: Making directory
2025/04/21 03:07:01 INFO  : d/e: Making directory
2025/04/21 03:07:02 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/21 03:07:03 DEBUG : c/non empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:07:03 DEBUG : c/non empty space: Unchanged skipping
2025/04/21 03:07:03 DEBUG : a/potato2: skip slow MD5 on source file, hashing in-transit
2025/04/21 03:07:03 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for checks to finish
2025/04/21 03:07:03 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Waiting for transfers to finish
2025/04/21 03:07:10 INFO  : a/potato2.rclone_chunk.001_1y9s4x: Moved (server-side) to: a/potato2.rclone_chunk.001
2025/04/21 03:07:12 INFO  : a/potato2.rclone_chunk.002_1y9s4x: Moved (server-side) to: a/potato2.rclone_chunk.002
2025/04/21 03:07:15 DEBUG : a/potato2: md5 = d6548b156ea68a4e003e786df99eee76 OK
2025/04/21 03:07:15 INFO  : a/potato2: Copied (new)
2025/04/21 03:07:15 DEBUG : Waiting for deletions to finish
2025/04/21 03:07:20 INFO  : b/potato: Deleted
2025/04/21 03:07:20 INFO  : d/e: Removing directory
2025/04/21 03:07:25 INFO  : d: Removing directory
2025/04/21 03:07:29 INFO  : b: Removing directory
2025/04/21 03:07:34 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': deleted 3 directories
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (77.35s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
2025/04/21 03:08:06 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-pasilet3kavi"
2025/04/21 03:08:06 DEBUG : Config file has changed externally - reloading
2025/04/21 03:08:06 DEBUG : Creating backend with remote "TestYandex:rclone-test-pasilet3kavi"
2025/04/21 03:08:14 INFO  : potato2.rclone_chunk.001_1ybkb4: Moved (server-side) to: potato2.rclone_chunk.001
2025/04/21 03:08:15 INFO  : potato2.rclone_chunk.002_1ybkb4: Moved (server-side) to: potato2.rclone_chunk.002
2025/04/21 03:08:27 INFO  : empty space.rclone_chunk.001_1ybv2u: Moved (server-side) to: empty space
2025/04/21 03:08:34 INFO  : potato3.rclone_chunk.001_1yc4li: Moved (server-side) to: potato3.rclone_chunk.001
2025/04/21 03:08:36 INFO  : potato3.rclone_chunk.002_1yc4li: Moved (server-side) to: potato3.rclone_chunk.002
2025/04/21 03:08:38 DEBUG : pacer: low level retry 1/10 (error [500 - InternalServerError] Internal Server Error (Ошибка сервера.))
2025/04/21 03:08:38 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/21 03:08:39 DEBUG : pacer: Reducing sleep to 15ms
2025/04/21 03:08:40 DEBUG : pacer: Reducing sleep to 11.25ms
2025/04/21 03:08:40 DEBUG : pacer: Reducing sleep to 10ms
    sync_test.go:1705: Server side move (if possible) Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje' -> Chunked 'TestChunkerChunk50bYandex:rclone-test-pasilet3kavi'
2025/04/21 03:08:47 INFO  : empty space.rclone_chunk.001_1ycjw7: Moved (server-side) to: empty space
2025/04/21 03:08:54 INFO  : potato3.rclone_chunk.001_1ycpqn: Moved (server-side) to: potato3.rclone_chunk.001
2025/04/21 03:08:56 INFO  : potato3.rclone_chunk.002_1ycpqn: Moved (server-side) to: potato3.rclone_chunk.002
2025/04/21 03:08:59 DEBUG : empty space: Excluded (Size Filter)
2025/04/21 03:08:59 DEBUG : empty space: Excluded
2025/04/21 03:08:59 DEBUG : empty space: Excluded (Size Filter)
2025/04/21 03:08:59 DEBUG : empty space: Excluded
2025/04/21 03:08:59 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/21 03:08:59 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/21 03:08:59 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pasilet3kavi': Waiting for checks to finish
2025/04/21 03:08:59 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pasilet3kavi': Waiting for transfers to finish
2025/04/21 03:09:00 DEBUG : potato2: move 2 data chunks...
2025/04/21 03:09:02 INFO  : potato2.rclone_chunk.001: Moved (server-side)
2025/04/21 03:09:04 INFO  : potato2.rclone_chunk.002: Moved (server-side)
2025/04/21 03:09:06 INFO  : potato2: Moved (server-side)
2025/04/21 03:09:09 INFO  : potato2: Moved (server-side)
2025/04/21 03:09:12 INFO  : potato3: Deleted
2025/04/21 03:09:12 DEBUG : potato3: move 2 data chunks...
2025/04/21 03:09:13 INFO  : potato3.rclone_chunk.001: Moved (server-side)
2025/04/21 03:09:15 INFO  : potato3.rclone_chunk.002: Moved (server-side)
2025/04/21 03:09:16 INFO  : potato3: Moved (server-side)
2025/04/21 03:09:18 INFO  : potato3: Moved (server-side)
2025/04/21 03:09:21 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-qudeqir5bihi"
2025/04/21 03:09:21 DEBUG : Config file has changed externally - reloading
2025/04/21 03:09:21 DEBUG : Creating backend with remote "TestYandex:rclone-test-qudeqir5bihi"
2025/04/21 03:09:22 DEBUG : empty space: Excluded (Size Filter)
2025/04/21 03:09:22 DEBUG : empty space: Excluded
2025/04/21 03:09:22 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/21 03:09:22 DEBUG : potato3: Need to transfer - File not found at Destination
2025/04/21 03:09:22 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-qudeqir5bihi': Waiting for checks to finish
2025/04/21 03:09:22 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-qudeqir5bihi': Waiting for transfers to finish
2025/04/21 03:09:22 DEBUG : potato3: move 2 data chunks...
2025/04/21 03:09:23 DEBUG : potato2: move 2 data chunks...
2025/04/21 03:09:24 INFO  : potato2.rclone_chunk.001: Moved (server-side)
2025/04/21 03:09:25 INFO  : potato3.rclone_chunk.001: Moved (server-side)
2025/04/21 03:09:26 INFO  : potato2.rclone_chunk.002: Moved (server-side)
2025/04/21 03:09:26 INFO  : potato3.rclone_chunk.002: Moved (server-side)
2025/04/21 03:09:28 INFO  : potato3: Moved (server-side)
2025/04/21 03:09:29 INFO  : potato2: Moved (server-side)
2025/04/21 03:09:30 INFO  : potato3: Moved (server-side)
2025/04/21 03:09:31 INFO  : potato2: Moved (server-side)
2025/04/21 03:09:33 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-qudeqir5bihi': Purge remote
2025/04/21 03:10:01 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pasilet3kavi': Purge remote
--- PASS: TestServerSideMoveWithFilter (142.91s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje'", Local "Local file system at /tmp/rclone1088229363", Modify Window "1ns"
2025/04/21 03:10:29 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst"
2025/04/21 03:10:29 DEBUG : Config file has changed externally - reloading
2025/04/21 03:10:29 DEBUG : Creating backend with remote "TestYandex:rclone-test-pocebir2yoje/dst"
2025/04/21 03:10:30 DEBUG : Creating backend with remote "TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/CompareDest"
2025/04/21 03:10:30 DEBUG : Creating backend with remote "TestYandex:rclone-test-pocebir2yoje/CompareDest"
2025/04/21 03:10:31 DEBUG : one: Need to transfer - File not found at Destination
2025/04/21 03:10:31 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:10:31 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:10:31 DEBUG : one: skip slow MD5 on source file, hashing in-transit
2025/04/21 03:10:40 INFO  : one.rclone_chunk.001_1yfk7d: Moved (server-side) to: one
2025/04/21 03:10:40 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/04/21 03:10:40 INFO  : one: Copied (new)
2025/04/21 03:10:40 DEBUG : Waiting for deletions to finish
2025/04/21 03:10:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/21 03:10:41 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:10:42 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:10:42 DEBUG : one: skip slow MD5 on source file, hashing in-transit
2025/04/21 03:10:50 INFO  : one: Deleted
2025/04/21 03:10:52 INFO  : one.rclone_chunk.001_1yfvp5: Moved (server-side) to: one
2025/04/21 03:10:52 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK
2025/04/21 03:10:52 INFO  : one: Copied (replaced existing)
2025/04/21 03:10:52 DEBUG : Waiting for deletions to finish
2025/04/21 03:11:02 INFO  : dst/one: Deleted
2025/04/21 03:11:03 INFO  : dst/one.rclone_chunk.001_1yg7xt: Moved (server-side) to: dst/one
2025/04/21 03:11:09 INFO  : CompareDest/one.rclone_chunk.001_1yggqw: Moved (server-side) to: CompareDest/one
2025/04/21 03:11:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/21 03:11:11 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:11:12 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:12 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/21 03:11:12 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:11:12 DEBUG : Waiting for deletions to finish
2025/04/21 03:11:12 INFO  : There was nothing to transfer
2025/04/21 03:11:19 INFO  : CompareDest/two.rclone_chunk.001_1ygrum: Moved (server-side) to: CompareDest/two
2025/04/21 03:11:21 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/21 03:11:22 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:22 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/21 03:11:22 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:11:22 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:22 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/21 03:11:22 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:11:22 DEBUG : Waiting for deletions to finish
2025/04/21 03:11:22 INFO  : There was nothing to transfer
2025/04/21 03:11:23 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/21 03:11:23 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:23 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/21 03:11:23 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:11:24 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:24 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/21 03:11:24 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:11:24 DEBUG : Waiting for deletions to finish
2025/04/21 03:11:24 INFO  : There was nothing to transfer
2025/04/21 03:11:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/21 03:11:26 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:26 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/21 03:11:27 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/04/21 03:11:27 DEBUG : two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/04/21 03:11:27 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/21 03:11:27 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:11:27 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:11:27 DEBUG : Waiting for deletions to finish
2025/04/21 03:11:27 INFO  : There was nothing to transfer
2025/04/21 03:11:29 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/21 03:11:29 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/04/21 03:11:29 DEBUG : two: Need to transfer - File not found at Destination
2025/04/21 03:11:29 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for checks to finish
2025/04/21 03:11:29 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/04/21 03:11:29 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/21 03:11:29 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje/dst': Waiting for transfers to finish
2025/04/21 03:11:29 DEBUG : two: skip slow MD5 on source file, hashing in-transit
2025/04/21 03:11:35 INFO  : two.rclone_chunk.001_1yh6w8: Moved (server-side) to: two
2025/04/21 03:11:35 DEBUG : two: md5 = 2379e4ce8c3380e996ab0509f17069ad OK
2025/04/21 03:11:35 INFO  : two: Copied (new)
2025/04/21 03:11:35 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCompareDest (95.94s)
PASS
2025/04/21 03:12:05 DEBUG : Chunked 'TestChunkerChunk50bYandex:rclone-test-pocebir2yoje': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bYandex: -verbose -size-limit 1024 -test.run '^(TestServerSideMoveWithFilter|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncCompareDest|TestSyncIgnoreErrors|TestSyncIgnoreTimes)$'" - Finished OK in 6m58.351191206s (try 2/5)