"./operations.test -test.v -test.timeout 1h0m0s -remote TestMailru: -verbose -test.run '^(TestCheck|TestCheckDownload|TestCheckSizeOnly|TestCheckSum|TestCheckSumDownload|TestCopyFile|TestCopyFileBackupDir|TestCopyFileCompareDest|TestCopyFileCopyDest|TestCopyLongFile|TestMultithreadCopy|TestMultithreadCopyAbort|TestParseSumFile)$'" - Starting (try 3/5) 2025/03/27 05:07:36 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo" 2025/03/27 05:07:36 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/27 05:07:36 DEBUG : Creating backend with remote "/tmp/rclone562393184" === RUN TestMultithreadCopy run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" multithread_test.go:121: multithread writing not supported 2025/03/27 05:07:36 ERROR : : error listing: directory not found --- SKIP: TestMultithreadCopy (0.08s) === RUN TestMultithreadCopyAbort run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" multithread_test.go:121: multithread writing not supported 2025/03/27 05:07:36 ERROR : : error listing: directory not found --- SKIP: TestMultithreadCopyAbort (0.09s) === RUN TestCheck run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:07:36 DEBUG : [rclone-test-kejotib6tufo]: new meta server: https://cld-extapi.datacloudmail.ru/meta/ === RUN TestCheck/1 === RUN TestCheck/2 === RUN TestCheck/3 2025/03/27 05:07:37 DEBUG : potato2: File has been put by hash from source === RUN TestCheck/4 === RUN TestCheck/5 2025/03/27 05:07:38 DEBUG : remotepotato: File has been put by hash from source === RUN TestCheck/6 === RUN TestCheck/7 --- PASS: TestCheck (2.83s) --- PASS: TestCheck/1 (0.13s) --- PASS: TestCheck/2 (0.09s) --- PASS: TestCheck/3 (0.10s) --- PASS: TestCheck/4 (0.11s) --- PASS: TestCheck/5 (0.10s) --- PASS: TestCheck/6 (0.12s) --- PASS: TestCheck/7 (0.13s) === RUN TestCheckDownload run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 === RUN TestCheckDownload/3 2025/03/27 05:07:40 DEBUG : potato2: File has been put by hash from source === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 2025/03/27 05:07:41 DEBUG : remotepotato: File has been put by hash from source === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 --- PASS: TestCheckDownload (3.90s) --- PASS: TestCheckDownload/1 (0.35s) --- PASS: TestCheckDownload/2 (0.13s) --- PASS: TestCheckDownload/3 (0.16s) --- PASS: TestCheckDownload/4 (0.27s) --- PASS: TestCheckDownload/5 (0.29s) --- PASS: TestCheckDownload/6 (0.26s) --- PASS: TestCheckDownload/7 (0.35s) === RUN TestCheckSizeOnly run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 === RUN TestCheckSizeOnly/3 2025/03/27 05:07:44 DEBUG : potato2: File has been put by hash from source === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2025/03/27 05:07:44 DEBUG : remotepotato: File has been put by hash from source === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (2.62s) --- PASS: TestCheckSizeOnly/1 (0.14s) --- PASS: TestCheckSizeOnly/2 (0.12s) --- PASS: TestCheckSizeOnly/3 (0.11s) --- PASS: TestCheckSizeOnly/4 (0.11s) --- PASS: TestCheckSizeOnly/5 (0.10s) --- PASS: TestCheckSizeOnly/6 (0.11s) --- PASS: TestCheckSizeOnly/7 (0.10s) === RUN TestParseSumFile run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:07:46 DEBUG : test.sum: File has been put by hash from source 2025/03/27 05:07:46 DEBUG : [rclone-test-kejotib6tufo]: Lock file server: locks 1, url https://cloclo62.datacloudmail.ru/oauth-get/ 2025/03/27 05:07:46 DEBUG : [rclone-test-kejotib6tufo]: Unlock file server: locks 0, url https://cloclo62.datacloudmail.ru/oauth-get/ 2025/03/27 05:07:46 NOTICE: test.sum: improperly formatted checksum line 4 2025/03/27 05:07:46 NOTICE: test.sum: improperly formatted checksum line 5 2025/03/27 05:07:46 NOTICE: test.sum: improperly formatted checksum line 6 2025/03/27 05:07:46 NOTICE: test.sum: 2 warning(s) suppressed... 2025/03/27 05:07:46 DEBUG : test.sum: File has been put by hash from source 2025/03/27 05:07:46 DEBUG : [rclone-test-kejotib6tufo]: Lock file server: locks 1, url https://cloclo62.datacloudmail.ru/oauth-get/ 2025/03/27 05:07:46 DEBUG : [rclone-test-kejotib6tufo]: Unlock file server: locks 0, url https://cloclo62.datacloudmail.ru/oauth-get/ 2025/03/27 05:07:46 NOTICE: test.sum: improperly formatted checksum line 4 2025/03/27 05:07:46 NOTICE: test.sum: improperly formatted checksum line 5 2025/03/27 05:07:46 NOTICE: test.sum: improperly formatted checksum line 6 2025/03/27 05:07:46 NOTICE: test.sum: 2 warning(s) suppressed... --- PASS: TestParseSumFile (1.13s) === RUN TestCheckSum run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:07:47 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/data" check_test.go:353: [rclone-test-kejotib6tufo/data] lacks md5, skipping --- SKIP: TestCheckSum (0.36s) === RUN TestCheckSumDownload run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:07:47 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/data" 2025/03/27 05:07:47 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest1 2025/03/27 05:07:49 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest2 2025/03/27 05:07:49 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest3 2025/03/27 05:07:50 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest4 2025/03/27 05:07:51 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest5 2025/03/27 05:07:52 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest6 2025/03/27 05:07:53 DEBUG : test.sum: File has been put by hash from source === RUN TestCheckSumDownload/subtest7 --- PASS: TestCheckSumDownload (7.84s) --- PASS: TestCheckSumDownload/subtest1 (0.71s) --- PASS: TestCheckSumDownload/subtest2 (0.29s) --- PASS: TestCheckSumDownload/subtest3 (0.43s) --- PASS: TestCheckSumDownload/subtest4 (0.46s) --- PASS: TestCheckSumDownload/subtest5 (0.44s) --- PASS: TestCheckSumDownload/subtest6 (0.45s) --- PASS: TestCheckSumDownload/subtest7 (0.50s) === RUN TestCopyFile run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:07:55 DEBUG : file1: Need to transfer - File not found at Destination 2025/03/27 05:07:55 DEBUG : file1: mailru = 66696c653120636f6e74656e7473000000000000 OK 2025/03/27 05:07:55 INFO : file1: Copied (new) to: sub/file2 2025/03/27 05:07:55 DEBUG : file1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/03/27 05:07:55 DEBUG : file1: Unchanged skipping 2025/03/27 05:07:56 DEBUG : [rclone-test-kejotib6tufo]: don't need to copy/move sub/file2, it is already at target location --- PASS: TestCopyFile (1.81s) === RUN TestCopyLongFile run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" copy_test.go:153: Test only runs on local --- SKIP: TestCopyLongFile (0.18s) === RUN TestCopyFileBackupDir run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:07:57 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/backup" 2025/03/27 05:07:57 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2025/03/27 05:07:58 DEBUG : [rclone-test-kejotib6tufo/backup]: new meta server: https://cld-extapi.datacloudmail.ru/meta/ 2025/03/27 05:07:58 DEBUG : [rclone-test-kejotib6tufo/backup]: mkDirs by part "/rclone-test-kejotib6tufo/backup/dst" 2025/03/27 05:07:58 INFO : dst/file1: Moved (server-side) 2025/03/27 05:07:59 DEBUG : dst/file1: mailru = 66696c653120636f6e74656e7473000000000000 OK 2025/03/27 05:07:59 INFO : dst/file1: Copied (new) --- PASS: TestCopyFileBackupDir (3.58s) === RUN TestCopyFileCompareDest run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:08:00 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/dst" 2025/03/27 05:08:01 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/CompareDest" 2025/03/27 05:08:01 DEBUG : one: Need to transfer - File not found at Destination 2025/03/27 05:09:01 DEBUG : pacer: low level retry 1/10 (error Get "https://dispatcher.cloud.mail.ru/m": dial tcp 95.163.37.87:443: i/o timeout) 2025/03/27 05:09:01 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/03/27 05:10:01 DEBUG : pacer: low level retry 2/10 (error Get "https://dispatcher.cloud.mail.ru/m": dial tcp 95.163.37.87:443: i/o timeout) 2025/03/27 05:10:01 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/03/27 05:10:01 DEBUG : pacer: Reducing sleep to 300ms 2025/03/27 05:10:01 DEBUG : [rclone-test-kejotib6tufo/dst]: new meta server: https://cld-extapi.datacloudmail.ru/meta/ 2025/03/27 05:10:01 DEBUG : pacer: Reducing sleep to 225ms 2025/03/27 05:10:01 DEBUG : pacer: Reducing sleep to 168.75ms 2025/03/27 05:10:02 DEBUG : pacer: Reducing sleep to 126.5625ms 2025/03/27 05:10:02 DEBUG : one: mailru = 6f6e650000000000000000000000000000000000 OK 2025/03/27 05:10:02 INFO : one: Copied (new) 2025/03/27 05:10:02 DEBUG : pacer: Reducing sleep to 100ms 2025/03/27 05:10:02 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/27 05:10:03 DEBUG : one: mailru = 6f6e657432000000000000000000000000000000 OK 2025/03/27 05:10:03 INFO : one: Copied (replaced existing) 2025/03/27 05:10:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/27 05:10:04 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/27 05:10:04 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/27 05:10:05 DEBUG : two: Need to transfer - File not found at Destination 2025/03/27 05:10:05 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/27 05:10:05 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/27 05:10:05 DEBUG : two: Need to transfer - File not found at Destination 2025/03/27 05:10:05 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/27 05:10:05 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/27 05:10:06 DEBUG : two: Need to transfer - File not found at Destination 2025/03/27 05:10:06 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/27 05:10:06 DEBUG : two: mailru = 74776f7433000000000000000000000000000000 OK 2025/03/27 05:10:06 INFO : two: Copied (new) --- PASS: TestCopyFileCompareDest (127.41s) === RUN TestCopyFileCopyDest run.go:180: Remote "[rclone-test-kejotib6tufo]", Local "Local file system at /tmp/rclone562393184", Modify Window "1s" 2025/03/27 05:10:08 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/dst" 2025/03/27 05:10:08 DEBUG : Config file has changed externally - reloading 2025/03/27 05:10:08 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/CopyDest" 2025/03/27 05:10:08 DEBUG : one: Need to transfer - File not found at Destination 2025/03/27 05:10:08 DEBUG : [rclone-test-kejotib6tufo/dst]: new meta server: https://cld-extapi.datacloudmail.ru/meta/ 2025/03/27 05:10:09 DEBUG : one: mailru = 6f6e650000000000000000000000000000000000 OK 2025/03/27 05:10:09 INFO : one: Copied (new) 2025/03/27 05:10:09 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/27 05:10:09 DEBUG : one: mailru = 6f6e657432000000000000000000000000000000 OK 2025/03/27 05:10:09 INFO : one: Copied (replaced existing) 2025/03/27 05:10:10 DEBUG : Creating backend with remote "TestMailru:rclone-test-kejotib6tufo/BackupDir" 2025/03/27 05:10:11 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/27 05:10:11 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/27 05:10:11 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/27 05:10:11 DEBUG : [rclone-test-kejotib6tufo/BackupDir]: new meta server: https://cld-extapi.datacloudmail.ru/meta/ 2025/03/27 05:10:11 INFO : one: Moved (server-side) 2025/03/27 05:10:12 DEBUG : one: mailru = 6f6e657432000000000000000000000000000000 OK 2025/03/27 05:10:12 INFO : one: Copied (server-side copy) 2025/03/27 05:10:12 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/27 05:10:13 DEBUG : two: Need to transfer - File not found at Destination 2025/03/27 05:10:13 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/27 05:10:13 DEBUG : two: mailru = 74776f0000000000000000000000000000000000 OK 2025/03/27 05:10:13 INFO : two: Copied (server-side copy) 2025/03/27 05:10:13 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/27 05:10:14 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/27 05:10:14 DEBUG : two: Unchanged skipping 2025/03/27 05:10:15 DEBUG : three: Need to transfer - File not found at Destination 2025/03/27 05:10:15 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/27 05:10:15 DEBUG : three: Destination not found in --copy-dest 2025/03/27 05:10:15 DEBUG : three: mailru = 7468726565743300000000000000000000000000 OK 2025/03/27 05:10:15 INFO : three: Copied (new) --- PASS: TestCopyFileCopyDest (9.86s) PASS 2025/03/27 05:10:18 DEBUG : [rclone-test-kejotib6tufo]: Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestMailru: -verbose -test.run '^(TestCheck|TestCheckDownload|TestCheckSizeOnly|TestCheckSum|TestCheckSumDownload|TestCopyFile|TestCopyFileBackupDir|TestCopyFileCompareDest|TestCopyFileCopyDest|TestCopyLongFile|TestMultithreadCopy|TestMultithreadCopyAbort|TestParseSumFile)$'" - Finished OK in 2m42.066178925s (try 3/5)