"./operations.test -test.v -test.timeout 1h0m0s -remote TestCryptSwift: -verbose" - Starting (try 1/5) 2022/03/24 06:42:32 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6" 2022/03/24 06:42:32 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/03/24 06:42:32 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6.bin" 2022/03/24 06:42:33 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6" 2022/03/24 06:42:33 DEBUG : Creating backend with remote "/tmp/rclone2624659225" === RUN TestDoMultiThreadCopy --- PASS: TestDoMultiThreadCopy (0.00s) === RUN TestMultithreadCalculateChunks === RUN TestMultithreadCalculateChunks/{size:1_streams:10_wantPartSize:65536_wantStreams:1} === RUN TestMultithreadCalculateChunks/{size:1048576_streams:1_wantPartSize:1048576_wantStreams:1} === RUN TestMultithreadCalculateChunks/{size:1048576_streams:2_wantPartSize:524288_wantStreams:2} === RUN TestMultithreadCalculateChunks/{size:1048577_streams:2_wantPartSize:589824_wantStreams:2} === RUN TestMultithreadCalculateChunks/{size:1048575_streams:2_wantPartSize:524288_wantStreams:2} --- PASS: TestMultithreadCalculateChunks (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1_streams:10_wantPartSize:65536_wantStreams:1} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048576_streams:1_wantPartSize:1048576_wantStreams:1} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048576_streams:2_wantPartSize:524288_wantStreams:2} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048577_streams:2_wantPartSize:589824_wantStreams:2} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048575_streams:2_wantPartSize:524288_wantStreams:2} (0.00s) === RUN TestMultithreadCopy run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" === RUN TestMultithreadCopy/{size:131071_streams:2} 2022/03/24 06:42:34 DEBUG : file1: md5 = 3724c94be5bbc4adaf88bfe3ab73a93a OK 2022/03/24 06:42:34 DEBUG : file1: Starting multi-thread copy with 2 parts of size 64Ki 2022/03/24 06:42:34 DEBUG : file1: multi-thread copy: stream 2/2 (65536-131071) size 63.999Ki starting 2022/03/24 06:42:34 DEBUG : file1: multi-thread copy: stream 1/2 (0-65536) size 64Ki starting 2022/03/24 06:42:34 DEBUG : file1: multi-thread copy: stream 1/2 (0-65536) size 64Ki finished 2022/03/24 06:42:34 DEBUG : file1: multi-thread copy: stream 2/2 (65536-131071) size 63.999Ki finished 2022/03/24 06:42:34 DEBUG : file1: Finished multi-thread copy with 2 parts of size 64Ki === RUN TestMultithreadCopy/{size:131072_streams:2} 2022/03/24 06:42:35 DEBUG : file1: md5 = 68c853f991072d9c2711a905250041a3 OK 2022/03/24 06:42:35 DEBUG : file1: Starting multi-thread copy with 2 parts of size 64Ki 2022/03/24 06:42:35 DEBUG : file1: multi-thread copy: stream 2/2 (65536-131072) size 64Ki starting 2022/03/24 06:42:35 DEBUG : file1: multi-thread copy: stream 1/2 (0-65536) size 64Ki starting 2022/03/24 06:42:35 DEBUG : file1: multi-thread copy: stream 1/2 (0-65536) size 64Ki finished 2022/03/24 06:42:35 DEBUG : file1: multi-thread copy: stream 2/2 (65536-131072) size 64Ki finished 2022/03/24 06:42:35 DEBUG : file1: Finished multi-thread copy with 2 parts of size 64Ki === RUN TestMultithreadCopy/{size:131073_streams:2} 2022/03/24 06:42:36 DEBUG : file1: md5 = 19128aecfd1136127d376527b278b82a OK 2022/03/24 06:42:36 DEBUG : file1: Starting multi-thread copy with 2 parts of size 128Ki 2022/03/24 06:42:36 DEBUG : file1: multi-thread copy: stream 2/2 (131072-131073) size 1 starting 2022/03/24 06:42:36 DEBUG : file1: multi-thread copy: stream 1/2 (0-131072) size 128Ki starting 2022/03/24 06:42:36 DEBUG : file1: multi-thread copy: stream 2/2 (131072-131073) size 1 finished 2022/03/24 06:42:36 DEBUG : file1: multi-thread copy: stream 1/2 (0-131072) size 128Ki finished 2022/03/24 06:42:36 DEBUG : file1: Finished multi-thread copy with 2 parts of size 128Ki --- PASS: TestMultithreadCopy (3.04s) --- PASS: TestMultithreadCopy/{size:131071_streams:2} (0.98s) --- PASS: TestMultithreadCopy/{size:131072_streams:2} (0.99s) --- PASS: TestMultithreadCopy/{size:131073_streams:2} (0.76s) === RUN TestSizeDiffers --- PASS: TestSizeDiffers (0.00s) === RUN TestReOpen === RUN TestReOpen/Seek === RUN TestReOpen/Seek/Basics === RUN TestReOpen/Seek/ErrorAtStart === RUN TestReOpen/Seek/WithErrors 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 2 bytes: retry 1/10: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 3 bytes: retry 2/10: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 6 bytes: retry 3/10: test error === RUN TestReOpen/Seek/TooManyErrors 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 2 bytes: retry 1/3: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 3 bytes: retry 2/3: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 6 bytes: retry 3/3: test error 2022/03/24 06:42:37 DEBUG : potato: Reopen failed after 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/Range === RUN TestReOpen/Range/Basics === RUN TestReOpen/Range/ErrorAtStart === RUN TestReOpen/Range/WithErrors 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 2 bytes: retry 1/10: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 3 bytes: retry 2/10: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 6 bytes: retry 3/10: test error === RUN TestReOpen/Range/TooManyErrors 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 2 bytes: retry 1/3: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 3 bytes: retry 2/3: test error 2022/03/24 06:42:37 DEBUG : potato: Reopening on read failure after 6 bytes: retry 3/3: test error 2022/03/24 06:42:37 DEBUG : potato: Reopen failed after 6 bytes read: failed to reopen: too many retries --- PASS: TestReOpen (0.00s) --- PASS: TestReOpen/Seek (0.00s) --- PASS: TestReOpen/Seek/Basics (0.00s) --- PASS: TestReOpen/Seek/ErrorAtStart (0.00s) --- PASS: TestReOpen/Seek/WithErrors (0.00s) --- PASS: TestReOpen/Seek/TooManyErrors (0.00s) --- PASS: TestReOpen/Range (0.00s) --- PASS: TestReOpen/Range/Basics (0.00s) --- PASS: TestReOpen/Range/ErrorAtStart (0.00s) --- PASS: TestReOpen/Range/WithErrors (0.00s) --- PASS: TestReOpen/Range/TooManyErrors (0.00s) === RUN TestCheck run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:42:37 DEBUG : rutabaga: md5 = a6c20b07cd515673cb806bcbe9789eb2 OK === RUN TestCheck/1 === RUN TestCheck/2 2022/03/24 06:42:38 DEBUG : empty space: md5 = f20682cbb94263d6a5cafe199ff3e88e OK === RUN TestCheck/3 2022/03/24 06:42:38 DEBUG : potato2: md5 = c50da61c00651b28d1963212491b1248 OK === RUN TestCheck/4 === RUN TestCheck/5 2022/03/24 06:42:40 DEBUG : remotepotato: md5 = f7731e9a520c4a483300ebfa9a3758a3 OK === RUN TestCheck/6 === RUN TestCheck/7 --- PASS: TestCheck (5.32s) --- PASS: TestCheck/1 (0.18s) --- PASS: TestCheck/2 (0.11s) --- PASS: TestCheck/3 (0.05s) --- PASS: TestCheck/4 (0.21s) --- PASS: TestCheck/5 (0.15s) --- PASS: TestCheck/6 (0.14s) --- PASS: TestCheck/7 (0.10s) === RUN TestCheckFsError 2022/03/24 06:42:42 DEBUG : Creating backend with remote "non-existent" 2022/03/24 06:42:42 DEBUG : Creating backend with remote "non-existent" 2022/03/24 06:42:42 DEBUG : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/non-existent: Waiting for checks to finish 2022/03/24 06:42:42 ERROR : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/non-existent: error reading source root directory: directory not found 2022/03/24 06:42:42 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/non-existent: 2 differences found 2022/03/24 06:42:42 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/non-existent: 2 errors while checking --- PASS: TestCheckFsError (0.00s) === RUN TestCheckDownload run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:42:42 DEBUG : rutabaga: md5 = 4b5eff8b10fb12d292c5463bf82cfca1 OK === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 2022/03/24 06:42:44 DEBUG : empty space: md5 = 09e8942c2df101e3a46ec5fccfc8644c OK === RUN TestCheckDownload/3 2022/03/24 06:42:44 DEBUG : potato2: md5 = eaa4b7cbf5bffbecd593d553deb1f49a OK === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 2022/03/24 06:42:45 DEBUG : remotepotato: md5 = 7da9ad5d16ec63a363abb761c63b0130 OK === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 --- PASS: TestCheckDownload (5.29s) --- PASS: TestCheckDownload/1 (0.09s) --- PASS: TestCheckDownload/2 (0.10s) --- PASS: TestCheckDownload/3 (0.23s) --- PASS: TestCheckDownload/4 (0.22s) --- PASS: TestCheckDownload/5 (0.09s) --- PASS: TestCheckDownload/6 (0.10s) --- PASS: TestCheckDownload/7 (0.18s) === RUN TestCheckSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:42:48 DEBUG : rutabaga: md5 = 7ad51778f6d4a64aac5de5a01f507c43 OK === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 2022/03/24 06:42:48 DEBUG : empty space: md5 = 3f671064d917611cc051d904045a886a OK === RUN TestCheckSizeOnly/3 2022/03/24 06:42:49 DEBUG : potato2: md5 = 3980d38f85e1d1bc8f23773c56fc6800 OK === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2022/03/24 06:42:50 DEBUG : remotepotato: md5 = 37a2cec1282531030b96ff73df072e44 OK === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (4.84s) --- PASS: TestCheckSizeOnly/1 (0.04s) --- PASS: TestCheckSizeOnly/2 (0.12s) --- PASS: TestCheckSizeOnly/3 (0.04s) --- PASS: TestCheckSizeOnly/4 (0.04s) --- PASS: TestCheckSizeOnly/5 (0.18s) --- PASS: TestCheckSizeOnly/6 (0.14s) --- PASS: TestCheckSizeOnly/7 (0.15s) === RUN TestCheckEqualReaders --- PASS: TestCheckEqualReaders (0.00s) === RUN TestParseSumFile run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:42:52 DEBUG : test.sum: md5 = 672422a37ea45a299d2b58bed1d7612f OK 2022/03/24 06:42:52 NOTICE: test.sum: improperly formatted checksum line 4 2022/03/24 06:42:52 NOTICE: test.sum: improperly formatted checksum line 5 2022/03/24 06:42:52 NOTICE: test.sum: improperly formatted checksum line 6 2022/03/24 06:42:52 NOTICE: test.sum: 2 warning(s) suppressed... 2022/03/24 06:42:53 DEBUG : test.sum: md5 = 65fba466727892c7dd42d407ee824dff OK 2022/03/24 06:42:53 NOTICE: test.sum: improperly formatted checksum line 4 2022/03/24 06:42:53 NOTICE: test.sum: improperly formatted checksum line 5 2022/03/24 06:42:53 NOTICE: test.sum: improperly formatted checksum line 6 2022/03/24 06:42:53 NOTICE: test.sum: 2 warning(s) suppressed... --- PASS: TestParseSumFile (1.28s) === RUN TestCheckSum run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:42:53 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/data" 2022/03/24 06:42:53 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/data.bin" 2022/03/24 06:42:54 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/data" check_test.go:356: Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/data' lacks md5, skipping --- SKIP: TestCheckSum (1.31s) === RUN TestCheckSumDownload run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:42:55 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/data" 2022/03/24 06:42:55 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/data.bin" 2022/03/24 06:42:55 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/data" 2022/03/24 06:42:56 DEBUG : data/banana: md5 = 5533a0000fe202071712606615fd7b82 OK 2022/03/24 06:42:56 DEBUG : test.sum: md5 = 5e3e816e72ab3ac09362430c56496329 OK === RUN TestCheckSumDownload/subtest1 2022/03/24 06:42:58 DEBUG : data/potato: md5 = b6825b4f03e6d2f832fd43addfaee6c5 OK 2022/03/24 06:42:58 DEBUG : test.sum: md5 = 59731a6c51426c2e458e56d467645ef8 OK === RUN TestCheckSumDownload/subtest2 2022/03/24 06:42:59 DEBUG : test.sum: md5 = ca24c4ad73255a035505f7d269902729 OK === RUN TestCheckSumDownload/subtest3 2022/03/24 06:43:00 DEBUG : test.sum: md5 = c35a344267bc9d242551ea4d8f0d69f7 OK === RUN TestCheckSumDownload/subtest4 2022/03/24 06:43:01 DEBUG : test.sum: md5 = 1d06de14390049ade23e64691eb99d5b OK === RUN TestCheckSumDownload/subtest5 2022/03/24 06:43:01 DEBUG : test.sum: md5 = 82c4bc41f4188f73c3d77d6365b48252 OK === RUN TestCheckSumDownload/subtest6 2022/03/24 06:43:02 DEBUG : data/banana: md5 = 679ec80102744a473a3e1713a42edc3c OK 2022/03/24 06:43:02 DEBUG : data/potato: md5 = 1475bc9c77553a2f465b94284a7bfc46 OK 2022/03/24 06:43:03 DEBUG : test.sum: md5 = cfeb9f2bface70e8af2220d02994c336 OK === RUN TestCheckSumDownload/subtest7 --- PASS: TestCheckSumDownload (9.78s) --- PASS: TestCheckSumDownload/subtest1 (0.19s) --- PASS: TestCheckSumDownload/subtest2 (0.25s) --- PASS: TestCheckSumDownload/subtest3 (0.25s) --- PASS: TestCheckSumDownload/subtest4 (0.16s) --- PASS: TestCheckSumDownload/subtest5 (0.17s) --- PASS: TestCheckSumDownload/subtest6 (0.16s) --- PASS: TestCheckSumDownload/subtest7 (0.35s) === RUN TestDeduplicateInteractive run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateInteractive (0.23s) === RUN TestDeduplicateSkip run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateSkip (0.29s) === RUN TestDeduplicateSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateSizeOnly (0.09s) === RUN TestDeduplicateFirst run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateFirst (0.08s) === RUN TestDeduplicateNewest run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateNewest (0.09s) === RUN TestDeduplicateNewestByHash run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:36: Can't run this test without a hash --- SKIP: TestDeduplicateNewestByHash (0.09s) === RUN TestDeduplicateOldest run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateOldest (0.08s) === RUN TestDeduplicateLargest run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateLargest (0.09s) === RUN TestDeduplicateSmallest run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateSmallest (0.18s) === RUN TestDeduplicateRename run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateRename (0.08s) === RUN TestMergeDirs run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" dedupe_test.go:267: Can't merge directories --- SKIP: TestMergeDirs (0.08s) === RUN TestListDirSorted run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:06 DEBUG : a.txt: md5 = d7b1c57b1fd387d5c195c553f68d97ba OK 2022/03/24 06:43:07 DEBUG : zend.txt: md5 = 915dff33e871ffe39e500f80bcf3a6a0 OK 2022/03/24 06:43:07 DEBUG : sub dir/hello world: md5 = 10069c181524596761e5e2f72b30ab81 OK 2022/03/24 06:43:07 DEBUG : sub dir/hello world2: md5 = 1fa9ae43d0d9c154f8ec321f2ede121e OK 2022/03/24 06:43:08 DEBUG : sub dir/ignore dir/.ignore: md5 = c33d458dc72f72094299c656b59a0e1a OK 2022/03/24 06:43:08 DEBUG : sub dir/ignore dir/should be ignored: md5 = 4e54819bafb753d162f5b82b54f10ec4 OK 2022/03/24 06:43:09 DEBUG : sub dir/sub sub dir/hello world3: md5 = 579df7dfda7dc0b1df0a52c55b372fc6 OK 2022/03/24 06:43:10 DEBUG : a.txt: Excluded 2022/03/24 06:43:10 DEBUG : sub dir/hello world: Excluded 2022/03/24 06:43:10 DEBUG : sub dir/hello world2: Excluded 2022/03/24 06:43:10 DEBUG : sub dir/hello world: Excluded 2022/03/24 06:43:10 DEBUG : sub dir/hello world2: Excluded 2022/03/24 06:43:10 DEBUG : sub dir/ignore dir: Excluded 2022/03/24 06:43:10 DEBUG : sub dir/ignore dir: Excluded --- PASS: TestListDirSorted (6.53s) === RUN TestListJSON run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:14 DEBUG : file1: md5 = 601a2bca625a1e804a623a93bb7f6838 OK 2022/03/24 06:43:17 DEBUG : sub/file2: md5 = 600db89c5565b9bfead4e621a756e5f6 OK === RUN TestListJSON/Default === RUN TestListJSON/FilesOnly === RUN TestListJSON/DirsOnly === RUN TestListJSON/Recurse === RUN TestListJSON/SubDir === RUN TestListJSON/NoModTime === RUN TestListJSON/NoMimeType === RUN TestListJSON/ShowHash === RUN TestListJSON/HashTypes 2022/03/24 06:43:18 ERROR : file1: Failed to read hash: hash type not supported --- PASS: TestListJSON (6.87s) --- PASS: TestListJSON/Default (0.08s) --- PASS: TestListJSON/FilesOnly (0.17s) --- PASS: TestListJSON/DirsOnly (0.11s) --- PASS: TestListJSON/Recurse (0.12s) --- PASS: TestListJSON/SubDir (0.17s) --- PASS: TestListJSON/NoModTime (0.13s) --- PASS: TestListJSON/NoMimeType (0.19s) --- PASS: TestListJSON/ShowHash (0.08s) --- PASS: TestListJSON/HashTypes (0.15s) === RUN TestStatJSON run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:19 DEBUG : file1: md5 = afc9ecfe4f2e86c149c6aa636d3579ad OK 2022/03/24 06:43:20 DEBUG : sub/file2: md5 = 4058b9050cbd48ee3147e85db946eee0 OK === RUN TestStatJSON/Root === RUN TestStatJSON/RootFilesOnly === RUN TestStatJSON/RootDirsOnly === RUN TestStatJSON/Dir === RUN TestStatJSON/File === RUN TestStatJSON/NotFound === RUN TestStatJSON/DirFilesOnly === RUN TestStatJSON/FileFilesOnly === RUN TestStatJSON/NotFoundFilesOnly === RUN TestStatJSON/DirDirsOnly === RUN TestStatJSON/FileDirsOnly === RUN TestStatJSON/NotFoundDirsOnly === RUN TestStatJSON/RootNotFound 2022/03/24 06:43:22 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/notfound" 2022/03/24 06:43:22 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/notfound.bin" 2022/03/24 06:43:22 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/notfound" --- PASS: TestStatJSON (4.25s) --- PASS: TestStatJSON/Root (0.04s) --- PASS: TestStatJSON/RootFilesOnly (0.00s) --- PASS: TestStatJSON/RootDirsOnly (0.27s) --- PASS: TestStatJSON/Dir (0.09s) --- PASS: TestStatJSON/File (0.04s) --- PASS: TestStatJSON/NotFound (0.19s) --- PASS: TestStatJSON/DirFilesOnly (0.05s) --- PASS: TestStatJSON/FileFilesOnly (0.04s) --- PASS: TestStatJSON/NotFoundFilesOnly (0.05s) --- PASS: TestStatJSON/DirDirsOnly (0.14s) --- PASS: TestStatJSON/FileDirsOnly (0.17s) --- PASS: TestStatJSON/NotFoundDirsOnly (0.04s) --- PASS: TestStatJSON/RootNotFound (1.11s) === RUN TestMkdir run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:23 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': Making directory 2022/03/24 06:43:24 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': Making directory --- PASS: TestMkdir (0.20s) === RUN TestLsd run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:24 DEBUG : sub dir/hello world: md5 = bf8d1331f56b8a24444629f5a1b943ef OK --- PASS: TestLsd (0.96s) === RUN TestLs run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:25 DEBUG : potato2: md5 = b4b0441f798be6d7ae80a0dca94b7ff3 OK 2022/03/24 06:43:25 DEBUG : empty space: md5 = 38d68f433fd3a91c83dff02cb75fc221 OK --- PASS: TestLs (1.18s) === RUN TestLsWithFilesFrom run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:26 DEBUG : potato2: md5 = f7ead3fc60a6cd4230607aeaf993a990 OK 2022/03/24 06:43:26 DEBUG : empty space: md5 = acd94ab73176e48a82b146519d8bbd10 OK 2022/03/24 06:43:26 DEBUG : empty space: Excluded --- PASS: TestLsWithFilesFrom (1.41s) === RUN TestLsLong run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:27 DEBUG : potato2: md5 = 1311d75133a6a09aff46d5657946c0ae OK 2022/03/24 06:43:28 DEBUG : empty space: md5 = 1928207467607651ff7b35e1f6e727dd OK --- PASS: TestLsLong (1.57s) === RUN TestHashSums run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:29 DEBUG : potato2: md5 = 7856d4ecb88332ffce304b372bd8f8ff OK 2022/03/24 06:43:29 DEBUG : empty space: md5 = 0bd6d86f1ed58e8f17b041cf4694a2ed OK --- PASS: TestHashSums (5.79s) === RUN TestHashSumsWithErrors 2022/03/24 06:43:35 DEBUG : Creating backend with remote ":memory:" 2022/03/24 06:43:35 ERROR : file1: hash unsupported: hash type not supported --- PASS: TestHashSumsWithErrors (0.00s) === RUN TestHashStream 2022/03/24 06:43:35 DEBUG : Creating md5 hash of 0 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating md5 hash of 0 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating sha1 hash of 0 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating sha1 hash of 0 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating md5 hash of 12 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating md5 hash of 12 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating sha1 hash of 12 bytes read from input stream 2022/03/24 06:43:35 DEBUG : Creating sha1 hash of 12 bytes read from input stream --- PASS: TestHashStream (0.00s) === RUN TestSuffixName --- PASS: TestSuffixName (0.00s) === RUN TestCount run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:35 DEBUG : potato2: md5 = 1fa15d5eb944830c305026a9243c2b25 OK 2022/03/24 06:43:36 DEBUG : empty space: md5 = eb678329f8f3adfd6137a35163e9c253 OK 2022/03/24 06:43:37 DEBUG : sub dir/potato3: md5 = ae35fa9c7f508a437cd8c9cee5e53540 OK --- PASS: TestCount (3.50s) === RUN TestDelete run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:39 DEBUG : small: md5 = b3d61ae327a1b7775ed676657f0f5261 OK 2022/03/24 06:43:40 DEBUG : medium: md5 = 5246e65d0ed17693e68b1c4e0dc26624 OK 2022/03/24 06:43:40 DEBUG : large: md5 = fd128d7e66bddf150471176200fcf51f OK 2022/03/24 06:43:41 DEBUG : Waiting for deletions to finish 2022/03/24 06:43:41 DEBUG : large: Excluded from sync (and deletion) 2022/03/24 06:43:41 INFO : small: Deleted 2022/03/24 06:43:41 INFO : medium: Deleted --- PASS: TestDelete (3.84s) === RUN TestRetry 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 1/5 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 2/5 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 1/5 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 2/5 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 3/5 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 4/5 2022/03/24 06:43:42 DEBUG : Received error: EOF - low level retry 5/5 --- PASS: TestRetry (0.00s) === RUN TestCat run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:42 DEBUG : file1: md5 = 3fad6888d05ee2a86e275313053301d6 OK 2022/03/24 06:43:43 DEBUG : file2: md5 = b930a5fd3af000462319542b00aa1c7b OK --- PASS: TestCat (2.35s) === RUN TestPurge 2022/03/24 06:43:44 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-huradaz8deqolef5boliroz1" 2022/03/24 06:43:44 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/03/24 06:43:44 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-huradaz8deqolef5boliroz1.bin" 2022/03/24 06:43:45 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-huradaz8deqolef5boliroz1" 2022/03/24 06:43:45 DEBUG : Creating backend with remote "/tmp/rclone695912892" run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-huradaz8deqolef5boliroz1'", Local "Local file system at /tmp/rclone695912892", Modify Window "1ns" 2022/03/24 06:43:48 DEBUG : A1/B1/C1/one: md5 = 55429bd0540879b9815fddda3523c186 OK 2022/03/24 06:43:48 DEBUG : A2: Making directory 2022/03/24 06:43:48 DEBUG : A1/B2: Making directory 2022/03/24 06:43:48 DEBUG : A1/B2/C2: Making directory 2022/03/24 06:43:48 DEBUG : A1/B1/C3: Making directory 2022/03/24 06:43:48 DEBUG : A3: Making directory 2022/03/24 06:43:48 DEBUG : A3/B3: Making directory 2022/03/24 06:43:48 DEBUG : A3/B3/C4: Making directory 2022/03/24 06:43:49 DEBUG : A1/two: md5 = 8f6d80f0eaafc6fc494369191375f2f1 OK fstest.go:251: Filtering empty directory "A2" fstest.go:251: Filtering empty directory "A1/B2" fstest.go:251: Filtering empty directory "A1/B2/C2" fstest.go:251: Filtering empty directory "A1/B1/C3" fstest.go:251: Filtering empty directory "A3" fstest.go:251: Filtering empty directory "A3/B3" fstest.go:251: Filtering empty directory "A3/B3/C4" 2022/03/24 06:43:49 DEBUG : Waiting for deletions to finish 2022/03/24 06:43:50 INFO : A1/B1/C1/one.bin: Deleted fstest.go:251: Filtering empty directory "A2" fstest.go:251: Filtering empty directory "A1/B2" fstest.go:251: Filtering empty directory "A1/B2/C2" fstest.go:251: Filtering empty directory "A3" fstest.go:251: Filtering empty directory "A3/B3" fstest.go:251: Filtering empty directory "A3/B3/C4" 2022/03/24 06:43:50 DEBUG : Waiting for deletions to finish 2022/03/24 06:43:51 INFO : A1/two.bin: Deleted 2022/03/24 06:43:51 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-huradaz8deqolef5boliroz1': Purge remote 2022/03/24 06:43:51 DEBUG : Waiting for deletions to finish --- PASS: TestPurge (6.59s) === RUN TestRmdirsNoLeaveRoot run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:52 DEBUG : A1/B1/C1/one: md5 = 165c75ca27fdeb159697ac8bc05a61ac OK 2022/03/24 06:43:52 DEBUG : A2: Making directory 2022/03/24 06:43:52 DEBUG : A1/B2: Making directory 2022/03/24 06:43:52 DEBUG : A1/B2/C2: Making directory 2022/03/24 06:43:52 DEBUG : A1/B1/C3: Making directory 2022/03/24 06:43:52 DEBUG : A3: Making directory 2022/03/24 06:43:52 DEBUG : A3/B3: Making directory 2022/03/24 06:43:52 DEBUG : A3/B3/C4: Making directory 2022/03/24 06:43:52 DEBUG : A1/two: md5 = dc759ae4b925d508687203d314a849be OK fstest.go:251: Filtering empty directory "A2" fstest.go:251: Filtering empty directory "A1/B2" fstest.go:251: Filtering empty directory "A1/B2/C2" fstest.go:251: Filtering empty directory "A1/B1/C3" fstest.go:251: Filtering empty directory "A3" fstest.go:251: Filtering empty directory "A3/B3" fstest.go:251: Filtering empty directory "A3/B3/C4" 2022/03/24 06:43:52 INFO : A3/B3/C4: Removing directory fstest.go:251: Filtering empty directory "A2" fstest.go:251: Filtering empty directory "A1/B2" fstest.go:251: Filtering empty directory "A1/B2/C2" fstest.go:251: Filtering empty directory "A1/B1/C3" fstest.go:251: Filtering empty directory "A3" fstest.go:251: Filtering empty directory "A3/B3" --- PASS: TestRmdirsNoLeaveRoot (4.21s) === RUN TestRmdirsLeaveRoot run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:55 DEBUG : A1: Making directory 2022/03/24 06:43:55 DEBUG : A1/B1: Making directory 2022/03/24 06:43:55 DEBUG : A1/B1/C1: Making directory fstest.go:251: Filtering empty directory "A1" fstest.go:251: Filtering empty directory "A1/B1" fstest.go:251: Filtering empty directory "A1/B1/C1" fstest.go:251: Filtering empty directory "A1" --- PASS: TestRmdirsLeaveRoot (0.43s) === RUN TestRmdirsWithFilter run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:55 DEBUG : A1: Making directory 2022/03/24 06:43:55 DEBUG : A1/B1: Making directory 2022/03/24 06:43:55 DEBUG : A1/B1/C1: Making directory fstest.go:251: Filtering empty directory "A1" fstest.go:251: Filtering empty directory "A1/B1" fstest.go:251: Filtering empty directory "A1/B1/C1" fstest.go:251: Filtering empty directory "A1" --- PASS: TestRmdirsWithFilter (0.62s) === RUN TestCopyURL run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:56 DEBUG : file1: md5 = 6e4099e2a462d32c1469e597f09e0d01 OK 2022/03/24 06:43:57 DEBUG : filename.txt: File name found in url 2022/03/24 06:43:57 DEBUG : filename.txt: md5 = ec1e9be1d781c81921ae8a9f435699b9 OK 2022/03/24 06:43:57 DEBUG : file2: md5 = e89171d19dd534748e7fa243be98dabe OK --- PASS: TestCopyURL (2.30s) === RUN TestCopyURLToWriter --- PASS: TestCopyURLToWriter (0.00s) === RUN TestMoveFile run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:43:58 DEBUG : file1: Need to transfer - File not found at Destination 2022/03/24 06:44:00 DEBUG : file1: md5 = 610faa01b6b98cc9ef17d3cbdf9a930d OK 2022/03/24 06:44:00 INFO : file1: Copied (new) to: sub/file2 2022/03/24 06:44:00 INFO : file1: Deleted 2022/03/24 06:44:00 DEBUG : file1: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:00 DEBUG : file1: Unchanged skipping 2022/03/24 06:44:00 INFO : file1: Deleted 2022/03/24 06:44:00 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': don't need to copy/move sub/file2, it is already at target location --- PASS: TestMoveFile (2.37s) === RUN TestMoveFileWithIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:01 DEBUG : file1: Need to transfer - File not found at Destination 2022/03/24 06:44:01 DEBUG : file1: md5 = 00a4be8173f284d74a6155c1f1540863 OK 2022/03/24 06:44:01 INFO : file1: Copied (new) 2022/03/24 06:44:01 INFO : file1: Deleted 2022/03/24 06:44:01 DEBUG : file1: Destination exists, skipping 2022/03/24 06:44:01 DEBUG : file1: Not removing source file as destination file exists and --ignore-existing is set --- PASS: TestMoveFileWithIgnoreExisting (3.17s) === RUN TestCaseInsensitiveMoveFile run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" --- PASS: TestCaseInsensitiveMoveFile (0.20s) === RUN TestMoveFileBackupDir run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:04 DEBUG : dst/file1: md5 = 868a71aac0f5788a54a4f02489740f04 OK 2022/03/24 06:44:05 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/backup" 2022/03/24 06:44:05 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/backup.bin" 2022/03/24 06:44:05 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/backup" 2022/03/24 06:44:06 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2022/03/24 06:44:06 INFO : dst/file1: Copied (server-side copy) 2022/03/24 06:44:06 INFO : dst/file1: Deleted 2022/03/24 06:44:06 DEBUG : dst/file1: md5 = b37831f5e77d8da0b5180e2ac0de7bf3 OK 2022/03/24 06:44:06 INFO : dst/file1: Copied (new) 2022/03/24 06:44:06 INFO : dst/file1: Deleted --- PASS: TestMoveFileBackupDir (3.29s) === RUN TestCopyFile run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:07 DEBUG : file1: Need to transfer - File not found at Destination 2022/03/24 06:44:08 DEBUG : file1: md5 = 4075ced169fe74d5706e4fb4a10320cf OK 2022/03/24 06:44:08 INFO : file1: Copied (new) to: sub/file2 2022/03/24 06:44:08 DEBUG : file1: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:08 DEBUG : file1: Unchanged skipping 2022/03/24 06:44:08 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': don't need to copy/move sub/file2, it is already at target location --- PASS: TestCopyFile (1.42s) === RUN TestCopyFileBackupDir run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:09 DEBUG : dst/file1: md5 = fd5186b44a2b8f838cd1bb68c3311f66 OK 2022/03/24 06:44:09 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/backup" 2022/03/24 06:44:09 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/backup.bin" 2022/03/24 06:44:10 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/backup" 2022/03/24 06:44:10 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2022/03/24 06:44:11 INFO : dst/file1: Copied (server-side copy) 2022/03/24 06:44:11 INFO : dst/file1: Deleted 2022/03/24 06:44:12 DEBUG : dst/file1: md5 = 0575fe3681daf6c370e532edc715dbda OK 2022/03/24 06:44:12 INFO : dst/file1: Copied (new) --- PASS: TestCopyFileBackupDir (3.37s) === RUN TestCopyFileCompareDest run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:12 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/dst" 2022/03/24 06:44:12 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/dst.bin" 2022/03/24 06:44:13 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/dst" 2022/03/24 06:44:13 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/CompareDest" 2022/03/24 06:44:13 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/CompareDest.bin" 2022/03/24 06:44:14 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/CompareDest" 2022/03/24 06:44:14 DEBUG : one: Need to transfer - File not found at Destination 2022/03/24 06:44:17 DEBUG : one: md5 = d39edecf14cf5d101065c68b5ea737e6 OK 2022/03/24 06:44:17 INFO : one: Copied (new) 2022/03/24 06:44:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/03/24 06:44:18 DEBUG : one: md5 = 91cdb1006542688569d30b5080830e6e OK 2022/03/24 06:44:18 INFO : one: Copied (replaced existing) 2022/03/24 06:44:18 DEBUG : dst/one: md5 = e7a28781edd81ac34bc3b2d6a8357b27 OK 2022/03/24 06:44:19 DEBUG : CompareDest/one: md5 = 2f7f6e5528ac37496ff82179a40353fb OK 2022/03/24 06:44:19 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:19 DEBUG : one: Destination found in --compare-dest, skipping 2022/03/24 06:44:21 DEBUG : CompareDest/two: md5 = 2f60b687086b41dfb880d797c0b4a875 OK 2022/03/24 06:44:21 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:21 DEBUG : two: Destination found in --compare-dest, skipping 2022/03/24 06:44:22 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:22 DEBUG : two: Destination found in --compare-dest, skipping 2022/03/24 06:44:22 DEBUG : two: Sizes differ (src 5 vs dst 3) 2022/03/24 06:44:22 DEBUG : two: Need to transfer - File not found at Destination 2022/03/24 06:44:23 DEBUG : two: md5 = 034e1ba31fb67a12893509a2c2297208 OK 2022/03/24 06:44:23 INFO : two: Copied (new) --- PASS: TestCopyFileCompareDest (13.63s) === RUN TestCopyFileCopyDest run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:26 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/dst" 2022/03/24 06:44:26 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/dst.bin" 2022/03/24 06:44:26 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/dst" 2022/03/24 06:44:27 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/CopyDest" 2022/03/24 06:44:27 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/CopyDest.bin" 2022/03/24 06:44:27 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/CopyDest" 2022/03/24 06:44:28 DEBUG : one: Need to transfer - File not found at Destination 2022/03/24 06:44:29 DEBUG : one: md5 = b829e9b0c09b81d22f230d8c34cd5306 OK 2022/03/24 06:44:29 INFO : one: Copied (new) 2022/03/24 06:44:29 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/03/24 06:44:29 DEBUG : one: md5 = 8e922f604f5920c0d866c13d142a0e79 OK 2022/03/24 06:44:29 INFO : one: Copied (replaced existing) 2022/03/24 06:44:30 DEBUG : dst/one: md5 = ffb3bf6fb006b36efffc2b60f456368d OK 2022/03/24 06:44:30 DEBUG : CopyDest/one: md5 = 1fa2f634857f8cbbb78f3c8a7cf6f53c OK 2022/03/24 06:44:30 DEBUG : Creating backend with remote "TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6/BackupDir" 2022/03/24 06:44:30 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/BackupDir.bin" 2022/03/24 06:44:31 DEBUG : Creating backend with remote "memstore:crypt/rclone-test-vazezeh1qafapeh9higefum6/BackupDir" 2022/03/24 06:44:31 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/03/24 06:44:32 INFO : one: Copied (server-side copy) 2022/03/24 06:44:32 INFO : one: Deleted 2022/03/24 06:44:32 INFO : one: Copied (server-side copy) 2022/03/24 06:44:32 DEBUG : one: Destination found in --copy-dest, using server-side copy 2022/03/24 06:44:35 DEBUG : CopyDest/two: md5 = 269f21c994869ee6b8960c84fd231c0a OK 2022/03/24 06:44:36 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:36 INFO : two: Copied (server-side copy) 2022/03/24 06:44:36 DEBUG : two: Destination found in --copy-dest, using server-side copy 2022/03/24 06:44:36 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:36 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns) 2022/03/24 06:44:36 DEBUG : two: Unchanged skipping 2022/03/24 06:44:37 DEBUG : CopyDest/three: md5 = d2952b04c83121f3ee55160a8082c6c3 OK 2022/03/24 06:44:37 DEBUG : three: Sizes differ (src 7 vs dst 5) 2022/03/24 06:44:37 DEBUG : three: Destination not found in --copy-dest 2022/03/24 06:44:37 DEBUG : three: Need to transfer - File not found at Destination 2022/03/24 06:44:38 DEBUG : three: md5 = 2281b5c614b05be9919ae768cd21df10 OK 2022/03/24 06:44:38 INFO : three: Copied (new) --- PASS: TestCopyFileCopyDest (13.53s) === RUN TestSameConfig --- PASS: TestSameConfig (0.00s) === RUN TestSame --- PASS: TestSame (0.00s) === RUN TestOverlapping --- PASS: TestOverlapping (0.00s) === RUN TestListFormat --- PASS: TestListFormat (0.00s) === RUN TestDirMove run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:40 DEBUG : A1/one: md5 = fd887ddc8790aa1faa714a95a5d25259 OK 2022/03/24 06:44:40 DEBUG : A1/two: md5 = bcd6bacaa394f534d3a434eb8606eda6 OK 2022/03/24 06:44:41 DEBUG : A1/B1/three: md5 = 351ff3adb292313c15d98909f16938c9 OK 2022/03/24 06:44:42 DEBUG : A1/B1/C1/four: md5 = bc1e7ca11196a658d5110803b61ef411 OK 2022/03/24 06:44:42 DEBUG : A1/B1/C2/five: md5 = a86894d31c9412782ea34feda7a6d52d OK 2022/03/24 06:44:42 DEBUG : A1/B2: Making directory 2022/03/24 06:44:42 DEBUG : A1/B1/C3: Making directory fstest.go:251: Filtering empty directory "A1/B2" fstest.go:251: Filtering empty directory "A1/B1/C3" 2022/03/24 06:44:43 INFO : A1/B1/C1/four: Copied (server-side copy) to: A2/B1/C1/four 2022/03/24 06:44:43 INFO : A1/one: Copied (server-side copy) to: A2/one 2022/03/24 06:44:43 INFO : A1/B1/C2/five: Copied (server-side copy) to: A2/B1/C2/five 2022/03/24 06:44:43 INFO : A1/B1/C1/four: Deleted 2022/03/24 06:44:43 INFO : A1/B1/C2/five: Deleted 2022/03/24 06:44:43 INFO : A1/B1/three: Copied (server-side copy) to: A2/B1/three 2022/03/24 06:44:43 INFO : A1/one: Deleted 2022/03/24 06:44:43 INFO : A1/B1/three: Deleted 2022/03/24 06:44:44 INFO : A1/two: Copied (server-side copy) to: A2/two 2022/03/24 06:44:44 INFO : A1/two: Deleted fstest.go:251: Filtering empty directory "A2/B2" fstest.go:251: Filtering empty directory "A2/B1/C3" 2022/03/24 06:44:45 INFO : A2/one: Copied (server-side copy) to: A3/one 2022/03/24 06:44:45 INFO : A2/B1/C1/four: Copied (server-side copy) to: A3/B1/C1/four 2022/03/24 06:44:45 INFO : A2/one: Deleted 2022/03/24 06:44:45 INFO : A2/B1/three: Copied (server-side copy) to: A3/B1/three 2022/03/24 06:44:45 INFO : A2/B1/three: Deleted 2022/03/24 06:44:45 INFO : A2/B1/C1/four: Deleted 2022/03/24 06:44:45 INFO : A2/B1/C2/five: Copied (server-side copy) to: A3/B1/C2/five 2022/03/24 06:44:45 INFO : A2/two: Copied (server-side copy) to: A3/two 2022/03/24 06:44:45 INFO : A2/B1/C2/five: Deleted 2022/03/24 06:44:45 INFO : A2/two: Deleted fstest.go:251: Filtering empty directory "A3/B2" fstest.go:251: Filtering empty directory "A3/B1/C3" --- PASS: TestDirMove (9.50s) === RUN TestGetFsInfo run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" --- PASS: TestGetFsInfo (0.08s) === RUN TestRcat === RUN TestRcat/withChecksum=false,ignoreChecksum=false === CONT TestRcat run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:49 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': File to upload is small (34 bytes), uploading instead of streaming 2022/03/24 06:44:49 DEBUG : no_checksum_small_file_from_pipe: md5 = f593c3575f5136b81f3e92a6d467be82 OK 2022/03/24 06:44:49 INFO : no_checksum_small_file_from_pipe: Copied (new) 2022/03/24 06:44:49 DEBUG : no_checksum_big_file_from_pipe.bin: Uploading segment file "rclone-test-vazezeh1qafapeh9higefum6/no_checksum_big_file_from_pipe.bin/1648104289.817370476/-1/00000000" into "crypt_segments" 2022/03/24 06:44:50 DEBUG : no_checksum_big_file_from_pipe.bin: Uploading segments into "crypt_segments" seems done (EOF) 2022/03/24 06:44:50 DEBUG : no_checksum_big_file_from_pipe.bin: Returning empty Md5sum for swift large object 2022/03/24 06:44:50 DEBUG : no_checksum_big_file_from_pipe: Size and modification time the same (differ by 0s, within tolerance 1ns) === RUN TestRcat/withChecksum=true,ignoreChecksum=false === CONT TestRcat run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:53 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': File to upload is small (34 bytes), uploading instead of streaming 2022/03/24 06:44:53 DEBUG : with_checksum_small_file_from_pipe: md5 = b0920604f5b9825215f1f2575c14c9c2 OK 2022/03/24 06:44:53 INFO : with_checksum_small_file_from_pipe: Copied (new) 2022/03/24 06:44:53 DEBUG : with_checksum_big_file_from_pipe.bin: Uploading segment file "rclone-test-vazezeh1qafapeh9higefum6/with_checksum_big_file_from_pipe.bin/1648104293.695041236/-1/00000000" into "crypt_segments" 2022/03/24 06:44:54 DEBUG : with_checksum_big_file_from_pipe.bin: Uploading segments into "crypt_segments" seems done (EOF) 2022/03/24 06:44:55 DEBUG : with_checksum_big_file_from_pipe.bin: Returning empty Md5sum for swift large object 2022/03/24 06:44:55 NOTICE: Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2022/03/24 06:44:55 DEBUG : with_checksum_big_file_from_pipe: Size of src and dst objects identical === RUN TestRcat/withChecksum=false,ignoreChecksum=true === CONT TestRcat run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:44:57 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': File to upload is small (34 bytes), uploading instead of streaming 2022/03/24 06:44:58 DEBUG : ignore_checksum_small_file_from_pipe: md5 = 6f80b2e9e5c50c4d35a20cce3b21cc79 OK 2022/03/24 06:44:58 INFO : ignore_checksum_small_file_from_pipe: Copied (new) 2022/03/24 06:44:59 DEBUG : ignore_checksum_big_file_from_pipe.bin: Uploading segment file "rclone-test-vazezeh1qafapeh9higefum6/ignore_checksum_big_file_from_pipe.bin/1648104299.040422331/-1/00000000" into "crypt_segments" 2022/03/24 06:44:59 DEBUG : ignore_checksum_big_file_from_pipe.bin: Uploading segments into "crypt_segments" seems done (EOF) 2022/03/24 06:45:00 DEBUG : ignore_checksum_big_file_from_pipe.bin: Returning empty Md5sum for swift large object 2022/03/24 06:45:00 DEBUG : ignore_checksum_big_file_from_pipe: Size and modification time the same (differ by 0s, within tolerance 1ns) === RUN TestRcat/withChecksum=true,ignoreChecksum=true === CONT TestRcat run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:45:01 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': File to upload is small (34 bytes), uploading instead of streaming 2022/03/24 06:45:02 DEBUG : ignore_checksum_small_file_from_pipe: md5 = c72e917c9ce66dd905bdd6ca95e3e68a OK 2022/03/24 06:45:02 INFO : ignore_checksum_small_file_from_pipe: Copied (new) 2022/03/24 06:45:02 DEBUG : ignore_checksum_big_file_from_pipe.bin: Uploading segment file "rclone-test-vazezeh1qafapeh9higefum6/ignore_checksum_big_file_from_pipe.bin/1648104302.550363834/-1/00000000" into "crypt_segments" 2022/03/24 06:45:02 DEBUG : ignore_checksum_big_file_from_pipe.bin: Uploading segments into "crypt_segments" seems done (EOF) 2022/03/24 06:45:03 DEBUG : ignore_checksum_big_file_from_pipe.bin: Returning empty Md5sum for swift large object 2022/03/24 06:45:03 DEBUG : ignore_checksum_big_file_from_pipe: Size of src and dst objects identical --- PASS: TestRcat (17.73s) --- PASS: TestRcat/withChecksum=false,ignoreChecksum=false (3.67s) --- PASS: TestRcat/withChecksum=true,ignoreChecksum=false (4.43s) --- PASS: TestRcat/withChecksum=false,ignoreChecksum=true (4.05s) --- PASS: TestRcat/withChecksum=true,ignoreChecksum=true (5.58s) === RUN TestRcatSize run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:45:08 DEBUG : potato1: md5 = 6d14b231d6df3f9a3d8b948bb12f013a OK 2022/03/24 06:45:08 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': File to upload is small (60 bytes), uploading instead of streaming 2022/03/24 06:45:08 DEBUG : potato2: md5 = 04febb53bcb798d470ab8a427825313a OK 2022/03/24 06:45:08 INFO : potato2: Copied (new) --- PASS: TestRcatSize (2.01s) === RUN TestCopyFileMaxTransfer run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:45:09 DEBUG : TestCopyFileMaxTransfer/file1: Need to transfer - File not found at Destination 2022/03/24 06:45:09 DEBUG : TestCopyFileMaxTransfer/file1: md5 = 349e10edf842dbae8298fc5257d11877 OK 2022/03/24 06:45:09 INFO : TestCopyFileMaxTransfer/file1: Copied (new) 2022/03/24 06:45:09 DEBUG : TestCopyFileMaxTransfer/file2: Need to transfer - File not found at Destination 2022/03/24 06:45:09 ERROR : TestCopyFileMaxTransfer/file2: Failed to copy: Put "https://csproxy5.memset.com/v1/AUTH_msnickcaa1_93fd688179b54bb5aa9604bf21f236be/crypt/rclone-test-vazezeh1qafapeh9higefum6/TestCopyFileMaxTransfer/file2.bin": Max transfer limit reached as set by --max-transfer 2022/03/24 06:45:10 DEBUG : TestCopyFileMaxTransfer/file3: Need to transfer - File not found at Destination 2022/03/24 06:45:10 DEBUG : TestCopyFileMaxTransfer/file4: Need to transfer - File not found at Destination 2022/03/24 06:45:10 DEBUG : TestCopyFileMaxTransfer/file4: md5 = 6e4b7f857d3c022d3075561da7286362 OK 2022/03/24 06:45:10 INFO : TestCopyFileMaxTransfer/file4: Copied (new) --- PASS: TestCopyFileMaxTransfer (2.29s) === RUN TestTouchDir run.go:181: Remote "Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6'", Local "Local file system at /tmp/rclone2624659225", Modify Window "1ns" 2022/03/24 06:45:11 DEBUG : potato2: md5 = f1929581a506c67bd926fbc3326ec498 OK 2022/03/24 06:45:11 DEBUG : empty space: md5 = 1ad08999b0ee337879bda9be54cf63de OK 2022/03/24 06:45:12 DEBUG : sub dir/potato3: md5 = 5db31d0e721494ef92427db73105ea53 OK 2022/03/24 06:45:13 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': Touching "empty space" 2022/03/24 06:45:13 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': Touching "potato2" 2022/03/24 06:45:13 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': Touching "sub dir/potato3" --- PASS: TestTouchDir (3.39s) === RUN TestRcAbout rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcAbout (0.00s) === RUN TestRcCleanup rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcCleanup (0.00s) === RUN TestRcCopyfile rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcCopyfile (0.00s) === RUN TestRcCopyurl rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcCopyurl (0.00s) === RUN TestRcDelete rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcDelete (0.00s) === RUN TestRcDeletefile rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcDeletefile (0.00s) === RUN TestRcList rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcList (0.00s) === RUN TestRcStat rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcStat (0.00s) === RUN TestRcMkdir rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcMkdir (0.00s) === RUN TestRcMovefile rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcMovefile (0.00s) === RUN TestRcPurge rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcPurge (0.00s) === RUN TestRcRmdir rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcRmdir (0.00s) === RUN TestRcRmdirs rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcRmdirs (0.00s) === RUN TestRcSize rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcSize (0.00s) === RUN TestRcPublicLink rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcPublicLink (0.00s) === RUN TestRcFsInfo rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcFsInfo (0.00s) === RUN TestUploadFile rc_test.go:25: Skipping test on non local remote --- SKIP: TestUploadFile (0.00s) === RUN TestRcCommand rc_test.go:25: Skipping test on non local remote --- SKIP: TestRcCommand (0.00s) PASS 2022/03/24 06:45:14 DEBUG : Encrypted drive 'TestCryptSwift:rclone-test-vazezeh1qafapeh9higefum6': Purge remote 2022/03/24 06:45:14 DEBUG : Waiting for deletions to finish "./operations.test -test.v -test.timeout 1h0m0s -remote TestCryptSwift: -verbose" - Finished OK in 2m42.09865474s (try 1/5)