"./operations.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/01/30 04:08:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe" 2025/01/30 04:08:40 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:08:40 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0" 2025/01/30 04:08:41 DEBUG : Creating backend with remote "/tmp/rclone259371107" === RUN TestDoMultiThreadCopy --- PASS: TestDoMultiThreadCopy (0.00s) === RUN TestMultithreadCalculateNumChunks === RUN TestMultithreadCalculateNumChunks/{size:1_chunkSize:65536_wantNumChunks:1} === RUN TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:1_wantNumChunks:1048576} === RUN TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:2_wantNumChunks:524288} === RUN TestMultithreadCalculateNumChunks/{size:1048577_chunkSize:2_wantNumChunks:524289} === RUN TestMultithreadCalculateNumChunks/{size:1048575_chunkSize:2_wantNumChunks:524288} --- PASS: TestMultithreadCalculateNumChunks (0.00s) --- PASS: TestMultithreadCalculateNumChunks/{size:1_chunkSize:65536_wantNumChunks:1} (0.00s) --- PASS: TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:1_wantNumChunks:1048576} (0.00s) --- PASS: TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:2_wantNumChunks:524288} (0.00s) --- PASS: TestMultithreadCalculateNumChunks/{size:1048577_chunkSize:2_wantNumChunks:524289} (0.00s) --- PASS: TestMultithreadCalculateNumChunks/{size:1048575_chunkSize:2_wantNumChunks:524288} (0.00s) === RUN TestMultithreadCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" multithread_test.go:121: multithread writing not supported --- SKIP: TestMultithreadCopy (0.23s) === RUN TestMultithreadCopyAbort run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" multithread_test.go:121: multithread writing not supported --- SKIP: TestMultithreadCopyAbort (0.23s) === RUN TestSizeDiffers --- PASS: TestSizeDiffers (0.00s) === RUN TestReOpen === RUN TestReOpen/Normal === RUN TestReOpen/Normal/Basics 2025/01/30 04:08:41 DEBUG : potato: Seek from 10 to 0 === RUN TestReOpen/Normal/ErrorAtStart === RUN TestReOpen/Normal/WithErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/Normal/TooManyErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/Normal/Seek 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Seek from 5 to 2 === RUN TestReOpen/Normal/AccountRead === RUN TestReOpen/Normal/AccountReadDelay 2025/01/30 04:08:41 DEBUG : potato: Seek from 10 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 10 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 10 to 0 === RUN TestReOpen/Normal/AccountReadError === RUN TestReOpen/WithRangeOption === RUN TestReOpen/WithRangeOption/Basics 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 0 === RUN TestReOpen/WithRangeOption/ErrorAtStart === RUN TestReOpen/WithRangeOption/WithErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/WithRangeOption/TooManyErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/WithRangeOption/Seek 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Seek from 5 to 2 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 4 === RUN TestReOpen/WithRangeOption/AccountRead === RUN TestReOpen/WithRangeOption/AccountReadDelay 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 0 === RUN TestReOpen/WithRangeOption/AccountReadError === RUN TestReOpen/WithSeekOption === RUN TestReOpen/WithSeekOption/Basics 2025/01/30 04:08:41 DEBUG : potato: Seek from 8 to 0 === RUN TestReOpen/WithSeekOption/ErrorAtStart === RUN TestReOpen/WithSeekOption/WithErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/WithSeekOption/TooManyErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/WithSeekOption/Seek 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Seek from 5 to 2 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 5 === RUN TestReOpen/WithSeekOption/AccountRead === RUN TestReOpen/WithSeekOption/AccountReadDelay 2025/01/30 04:08:41 DEBUG : potato: Seek from 8 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 8 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 8 to 0 === RUN TestReOpen/WithSeekOption/AccountReadError === RUN TestReOpen/UnknownSize === RUN TestReOpen/UnknownSize/Basics 2025/01/30 04:08:41 DEBUG : potato: Seek from 9 to 0 === RUN TestReOpen/UnknownSize/ErrorAtStart === RUN TestReOpen/UnknownSize/WithErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/UnknownSize/TooManyErrors 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2025/01/30 04:08:41 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/UnknownSize/Seek 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2025/01/30 04:08:41 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2025/01/30 04:08:41 DEBUG : potato: Seek from 5 to 2 2025/01/30 04:08:41 DEBUG : potato: Seek from 7 to 6 === RUN TestReOpen/UnknownSize/AccountRead === RUN TestReOpen/UnknownSize/AccountReadDelay 2025/01/30 04:08:41 DEBUG : potato: Seek from 9 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 9 to 0 2025/01/30 04:08:41 DEBUG : potato: Seek from 9 to 0 === RUN TestReOpen/UnknownSize/AccountReadError --- PASS: TestReOpen (0.00s) --- PASS: TestReOpen/Normal (0.00s) --- PASS: TestReOpen/Normal/Basics (0.00s) --- PASS: TestReOpen/Normal/ErrorAtStart (0.00s) --- PASS: TestReOpen/Normal/WithErrors (0.00s) --- PASS: TestReOpen/Normal/TooManyErrors (0.00s) --- PASS: TestReOpen/Normal/Seek (0.00s) --- PASS: TestReOpen/Normal/AccountRead (0.00s) --- PASS: TestReOpen/Normal/AccountReadDelay (0.00s) --- PASS: TestReOpen/Normal/AccountReadError (0.00s) --- PASS: TestReOpen/WithRangeOption (0.00s) --- PASS: TestReOpen/WithRangeOption/Basics (0.00s) --- PASS: TestReOpen/WithRangeOption/ErrorAtStart (0.00s) --- PASS: TestReOpen/WithRangeOption/WithErrors (0.00s) --- PASS: TestReOpen/WithRangeOption/TooManyErrors (0.00s) --- PASS: TestReOpen/WithRangeOption/Seek (0.00s) --- PASS: TestReOpen/WithRangeOption/AccountRead (0.00s) --- PASS: TestReOpen/WithRangeOption/AccountReadDelay (0.00s) --- PASS: TestReOpen/WithRangeOption/AccountReadError (0.00s) --- PASS: TestReOpen/WithSeekOption (0.00s) --- PASS: TestReOpen/WithSeekOption/Basics (0.00s) --- PASS: TestReOpen/WithSeekOption/ErrorAtStart (0.00s) --- PASS: TestReOpen/WithSeekOption/WithErrors (0.00s) --- PASS: TestReOpen/WithSeekOption/TooManyErrors (0.00s) --- PASS: TestReOpen/WithSeekOption/Seek (0.00s) --- PASS: TestReOpen/WithSeekOption/AccountRead (0.00s) --- PASS: TestReOpen/WithSeekOption/AccountReadDelay (0.00s) --- PASS: TestReOpen/WithSeekOption/AccountReadError (0.00s) --- PASS: TestReOpen/UnknownSize (0.00s) --- PASS: TestReOpen/UnknownSize/Basics (0.00s) --- PASS: TestReOpen/UnknownSize/ErrorAtStart (0.00s) --- PASS: TestReOpen/UnknownSize/WithErrors (0.00s) --- PASS: TestReOpen/UnknownSize/TooManyErrors (0.00s) --- PASS: TestReOpen/UnknownSize/Seek (0.00s) --- PASS: TestReOpen/UnknownSize/AccountRead (0.00s) --- PASS: TestReOpen/UnknownSize/AccountReadDelay (0.00s) --- PASS: TestReOpen/UnknownSize/AccountReadError (0.00s) === RUN TestCheck run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:08:44 DEBUG : rutabaga: md5 = cd5a4a094c68d6e2ba6ffff8b558566d OK === RUN TestCheck/1 === RUN TestCheck/2 2025/01/30 04:08:47 DEBUG : empty space: md5 = f6d1ba5ea90532307a23b98a0d898652 OK === RUN TestCheck/3 2025/01/30 04:08:49 DEBUG : potato2: md5 = b1c148491d74c28c202a9e1f3bb58667 OK === RUN TestCheck/4 === RUN TestCheck/5 2025/01/30 04:08:52 DEBUG : remotepotato: md5 = 7ec702b22d879918e9910088555846ec OK === RUN TestCheck/6 === RUN TestCheck/7 --- PASS: TestCheck (13.94s) --- PASS: TestCheck/1 (0.27s) --- PASS: TestCheck/2 (0.24s) --- PASS: TestCheck/3 (0.25s) --- PASS: TestCheck/4 (0.25s) --- PASS: TestCheck/5 (0.24s) --- PASS: TestCheck/6 (0.27s) --- PASS: TestCheck/7 (0.24s) === RUN TestCheckFsError 2025/01/30 04:08:55 DEBUG : Creating backend with remote "nonexistent" 2025/01/30 04:08:55 DEBUG : Creating backend with remote "nonexistent" 2025/01/30 04:08:55 DEBUG : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: Waiting for checks to finish 2025/01/30 04:08:55 ERROR : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: error reading source root directory: directory not found 2025/01/30 04:08:55 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: 2 differences found 2025/01/30 04:08:55 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: 2 errors while checking --- PASS: TestCheckFsError (0.00s) === RUN TestCheckDownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:08:57 DEBUG : rutabaga: md5 = cba5303df8d9ee62d8cc3f99eaaf4c0c OK === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 2025/01/30 04:09:01 DEBUG : empty space: md5 = 6eb297388c9d52ee9555cf80e4ebf88c OK === RUN TestCheckDownload/3 2025/01/30 04:09:04 DEBUG : potato2: md5 = 8aa5ab18a2c4acdd86bbf71bb90de4f6 OK === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 2025/01/30 04:09:09 DEBUG : remotepotato: md5 = 6f7a8a37838316f0855d79cdcf81109f OK === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 --- PASS: TestCheckDownload (18.29s) --- PASS: TestCheckDownload/1 (1.06s) --- PASS: TestCheckDownload/2 (0.83s) --- PASS: TestCheckDownload/3 (1.17s) --- PASS: TestCheckDownload/4 (1.07s) --- PASS: TestCheckDownload/5 (1.75s) --- PASS: TestCheckDownload/6 (1.05s) --- PASS: TestCheckDownload/7 (0.92s) === RUN TestCheckSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:09:15 DEBUG : rutabaga: md5 = 397e60fcc406d8707f2ab40bab30a940 OK === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 2025/01/30 04:09:18 DEBUG : empty space: md5 = 47ca8307f05e11741360e17926fc6e10 OK === RUN TestCheckSizeOnly/3 2025/01/30 04:09:20 DEBUG : potato2: md5 = 23d08eb47a64c0b9036f9756ce3f7603 OK === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2025/01/30 04:09:23 DEBUG : remotepotato: md5 = cf77b6a3b8226717bd9a6ef70f7cc4e1 OK === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (12.51s) --- PASS: TestCheckSizeOnly/1 (0.24s) --- PASS: TestCheckSizeOnly/2 (0.24s) --- PASS: TestCheckSizeOnly/3 (0.25s) --- PASS: TestCheckSizeOnly/4 (0.27s) --- PASS: TestCheckSizeOnly/5 (0.26s) --- PASS: TestCheckSizeOnly/6 (0.23s) --- PASS: TestCheckSizeOnly/7 (0.26s) === RUN TestCheckEqualReaders --- PASS: TestCheckEqualReaders (0.00s) === RUN TestParseSumFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:09:29 DEBUG : test.sum: md5 = f14d299a4c111c5d3e622c6f088cb03c OK 2025/01/30 04:09:30 NOTICE: test.sum: improperly formatted checksum line 4 2025/01/30 04:09:30 NOTICE: test.sum: improperly formatted checksum line 5 2025/01/30 04:09:30 NOTICE: test.sum: improperly formatted checksum line 6 2025/01/30 04:09:30 NOTICE: test.sum: 2 warning(s) suppressed... 2025/01/30 04:09:32 DEBUG : test.sum: md5 = 7110e6c2228716636b4d04a1098ab786 OK 2025/01/30 04:09:33 NOTICE: test.sum: improperly formatted checksum line 4 2025/01/30 04:09:33 NOTICE: test.sum: improperly formatted checksum line 5 2025/01/30 04:09:33 NOTICE: test.sum: improperly formatted checksum line 6 2025/01/30 04:09:33 NOTICE: test.sum: 2 warning(s) suppressed... --- PASS: TestParseSumFile (7.99s) === RUN TestCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:09:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/data" 2025/01/30 04:09:34 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/vjrnln8ratgmqakfosrqe8espk" check_test.go:353: Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe/data' lacks md5, skipping --- SKIP: TestCheckSum (1.93s) === RUN TestCheckSumDownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:09:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/data" 2025/01/30 04:09:36 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/vjrnln8ratgmqakfosrqe8espk" 2025/01/30 04:09:40 DEBUG : data/banana: md5 = c6ac2d2c9208f4f400c2ea376a40c280 OK 2025/01/30 04:09:42 DEBUG : test.sum: md5 = e739e832a91453729312b1172e32ea78 OK === RUN TestCheckSumDownload/subtest1 2025/01/30 04:09:47 DEBUG : data/potato: md5 = b2ff5e0566e49381acb41d3943de9fe9 OK 2025/01/30 04:09:48 DEBUG : test.sum: md5 = 533cd1f911291750bfbdf7c13c38768d OK === RUN TestCheckSumDownload/subtest2 2025/01/30 04:09:52 DEBUG : test.sum: md5 = e01c636bf65f638ceec0c9e545ad7451 OK === RUN TestCheckSumDownload/subtest3 2025/01/30 04:09:57 DEBUG : test.sum: md5 = 1d5c34dfddc4517f0e1bfde51b5c62df OK === RUN TestCheckSumDownload/subtest4 2025/01/30 04:10:01 DEBUG : test.sum: md5 = 2d028e63e3e6da104649aed21d831d99 OK === RUN TestCheckSumDownload/subtest5 2025/01/30 04:10:05 DEBUG : test.sum: md5 = 283d2736448157a6249898101ecf3352 OK === RUN TestCheckSumDownload/subtest6 2025/01/30 04:10:09 DEBUG : data/banana: md5 = 083b567f561c93e2564fdf85ac0f0cfb OK 2025/01/30 04:10:11 DEBUG : data/potato: md5 = 7ef74b80ba2a7f4b3d3a23587b56ee9d OK 2025/01/30 04:10:13 DEBUG : test.sum: md5 = e0cdc4b5f8615ee6d60df2d2b780c6ec OK === RUN TestCheckSumDownload/subtest7 2025/01/30 04:10:18 DEBUG : vjrnln8ratgmqakfosrqe8espk: Rmdir: contains trashed file: "igjr4utqjj43i7bn8okrqetjm0" 2025/01/30 04:10:18 DEBUG : vjrnln8ratgmqakfosrqe8espk: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" --- PASS: TestCheckSumDownload (42.58s) --- PASS: TestCheckSumDownload/subtest1 (2.49s) --- PASS: TestCheckSumDownload/subtest2 (2.04s) --- PASS: TestCheckSumDownload/subtest3 (2.25s) --- PASS: TestCheckSumDownload/subtest4 (2.19s) --- PASS: TestCheckSumDownload/subtest5 (1.95s) --- PASS: TestCheckSumDownload/subtest6 (1.98s) --- PASS: TestCheckSumDownload/subtest7 (2.24s) === RUN TestApplyTransforms 2025/01/30 04:10:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fekejab0yepe" 2025/01/30 04:10:19 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:19 DEBUG : Creating backend with remote "TestDrive:crypt/kp8rhkue7uvv9i2495bm5buvcigjb384158ugakghr3617mih8ag" 2025/01/30 04:10:20 DEBUG : Creating backend with remote "/tmp/rclone1744842751" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe'", Local "Local file system at /tmp/rclone1744842751", Modify Window "1ms" 2025/01/30 04:10:23 DEBUG : hello, world!: md5 = a638f24b0a8418f42ca46ecf151990b8 OK upper checkfile vs. lower remote (without normalization) 2025/01/30 04:10:23 ERROR : hello, world!: sum not found 2025/01/30 04:10:23 ERROR : HELLO, WORLD!: file not in Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe' 2025/01/30 04:10:23 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe': 1 files missing 2025/01/30 04:10:23 NOTICE: 1 hashes missing 2025/01/30 04:10:23 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe': 2 differences found 2025/01/30 04:10:23 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe': 2 errors while checking upper checkfile vs. lower remote (with normalization) 2025/01/30 04:10:24 DEBUG : hello, world!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:24 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe': 0 differences found 2025/01/30 04:10:24 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe': 1 matching files 2025/01/30 04:10:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hapexun3suka" 2025/01/30 04:10:24 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:24 DEBUG : Creating backend with remote "TestDrive:crypt/8bf8ljk6ncjlb3jtnt5k5nouuec61jrcs8grmlo7in8v6t4gsnm0" 2025/01/30 04:10:25 DEBUG : Creating backend with remote "/tmp/rclone2919772088" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka'", Local "Local file system at /tmp/rclone2919772088", Modify Window "1ms" 2025/01/30 04:10:28 DEBUG : HELLO, WORLD!: md5 = 6d20a27e4fda23129f63cb6cfcb76910 OK lower checkfile vs. upper remote (without normalization) 2025/01/30 04:10:28 ERROR : HELLO, WORLD!: sum not found 2025/01/30 04:10:28 ERROR : hello, world!: file not in Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka' 2025/01/30 04:10:28 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka': 1 files missing 2025/01/30 04:10:28 NOTICE: 1 hashes missing 2025/01/30 04:10:28 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka': 2 differences found 2025/01/30 04:10:28 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka': 2 errors while checking lower checkfile vs. upper remote (with normalization) 2025/01/30 04:10:29 DEBUG : HELLO, WORLD!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:29 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka': 0 differences found 2025/01/30 04:10:29 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka': 1 matching files 2025/01/30 04:10:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vuyejon1bere" 2025/01/30 04:10:29 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:29 DEBUG : Creating backend with remote "TestDrive:crypt/d4vkd6jsdhrhoqlqonpo1ec43vvttfdrbt2cb0igkeuvqsr7tncg" 2025/01/30 04:10:30 DEBUG : Creating backend with remote "/tmp/rclone1250726745" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere'", Local "Local file system at /tmp/rclone1250726745", Modify Window "1ms" 2025/01/30 04:10:33 DEBUG : HeLlO, wOrLd!: md5 = aeb7880b78facaa4ed08ad0d642e5df4 OK lower checkfile vs. upperlowermixed remote (without normalization) 2025/01/30 04:10:33 ERROR : HeLlO, wOrLd!: sum not found 2025/01/30 04:10:33 ERROR : hello, world!: file not in Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere' 2025/01/30 04:10:33 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere': 1 files missing 2025/01/30 04:10:33 NOTICE: 1 hashes missing 2025/01/30 04:10:33 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere': 2 differences found 2025/01/30 04:10:33 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere': 2 errors while checking lower checkfile vs. upperlowermixed remote (with normalization) 2025/01/30 04:10:34 DEBUG : HeLlO, wOrLd!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:34 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere': 0 differences found 2025/01/30 04:10:34 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere': 1 matching files 2025/01/30 04:10:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qodetif1hofa" 2025/01/30 04:10:34 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:35 DEBUG : Creating backend with remote "TestDrive:crypt/f6kcvfe6bihvftuedffgcv1sjlkcoa75h1pjajtk6tf532hvpefg" 2025/01/30 04:10:35 DEBUG : Creating backend with remote "/tmp/rclone3361823661" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa'", Local "Local file system at /tmp/rclone3361823661", Modify Window "1ms" 2025/01/30 04:10:38 DEBUG : HELLO, WORLD!: md5 = bbc853b2dae4cac1603afb5c2fb4e3a2 OK upperlowermixed checkfile vs. upper remote (without normalization) 2025/01/30 04:10:39 ERROR : HELLO, WORLD!: sum not found 2025/01/30 04:10:39 ERROR : HeLlO, wOrLd!: file not in Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa' 2025/01/30 04:10:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa': 1 files missing 2025/01/30 04:10:39 NOTICE: 1 hashes missing 2025/01/30 04:10:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa': 2 differences found 2025/01/30 04:10:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa': 2 errors while checking upperlowermixed checkfile vs. upper remote (with normalization) 2025/01/30 04:10:40 DEBUG : HELLO, WORLD!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:40 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa': 0 differences found 2025/01/30 04:10:40 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa': 1 matching files 2025/01/30 04:10:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-debotix2pele" 2025/01/30 04:10:40 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:40 DEBUG : Creating backend with remote "TestDrive:crypt/fa209s5loe84d5a97mie6cviph3j9dlglmu2c18r0sot5sv335lg" 2025/01/30 04:10:41 DEBUG : Creating backend with remote "/tmp/rclone3987841051" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele'", Local "Local file system at /tmp/rclone3987841051", Modify Window "1ms" 2025/01/30 04:10:44 DEBUG : 測試_Русский___ě_áñ: md5 = 92f6bef18e05b51efb777c372598b315 OK NFD checkfile vs. NFC remote (without normalization) 2025/01/30 04:10:44 ERROR : 測試_Русский___ě_áñ: sum not found 2025/01/30 04:10:44 ERROR : 測試_Русский___ě_áñ: file not in Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele' 2025/01/30 04:10:44 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele': 1 files missing 2025/01/30 04:10:44 NOTICE: 1 hashes missing 2025/01/30 04:10:44 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele': 2 differences found 2025/01/30 04:10:44 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele': 2 errors while checking NFD checkfile vs. NFC remote (with normalization) 2025/01/30 04:10:46 DEBUG : 測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:46 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele': 0 differences found 2025/01/30 04:10:46 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele': 1 matching files 2025/01/30 04:10:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pikovuq5qabe" 2025/01/30 04:10:46 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:46 DEBUG : Creating backend with remote "TestDrive:crypt/pkdci0han34cjaff0ksje9d66ul9ho34rbjlsjmdcotubme2flv0" 2025/01/30 04:10:47 DEBUG : Creating backend with remote "/tmp/rclone3876854964" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe'", Local "Local file system at /tmp/rclone3876854964", Modify Window "1ms" 2025/01/30 04:10:49 DEBUG : 測試_Русский___ě_áñ: md5 = 3af01c982ef951c7adc228a539885e7c OK NFC checkfile vs. NFD remote (without normalization) 2025/01/30 04:10:50 ERROR : 測試_Русский___ě_áñ: sum not found 2025/01/30 04:10:50 ERROR : 測試_Русский___ě_áñ: file not in Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe' 2025/01/30 04:10:50 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe': 1 files missing 2025/01/30 04:10:50 NOTICE: 1 hashes missing 2025/01/30 04:10:50 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe': 2 differences found 2025/01/30 04:10:50 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe': 2 errors while checking NFC checkfile vs. NFD remote (with normalization) 2025/01/30 04:10:51 DEBUG : 測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:51 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe': 0 differences found 2025/01/30 04:10:51 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe': 1 matching files 2025/01/30 04:10:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sawacur4wuwo" 2025/01/30 04:10:51 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:51 DEBUG : Creating backend with remote "TestDrive:crypt/4btul83fup807nu8q2sfv821h76tre38i9hvj34u2ns4i5bbdltg" 2025/01/30 04:10:52 DEBUG : Creating backend with remote "/tmp/rclone399383621" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo'", Local "Local file system at /tmp/rclone399383621", Modify Window "1ms" 2025/01/30 04:10:55 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 3ec66b268daf33cb5d29ce6d9fcffc00 OK NFDx2 checkfile vs. both remote (without normalization) 2025/01/30 04:10:55 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found 2025/01/30 04:10:55 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo' 2025/01/30 04:10:55 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo': 1 files missing 2025/01/30 04:10:55 NOTICE: 1 hashes missing 2025/01/30 04:10:55 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo': 2 differences found 2025/01/30 04:10:55 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo': 2 errors while checking NFDx2 checkfile vs. both remote (with normalization) 2025/01/30 04:10:56 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:10:56 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo': 0 differences found 2025/01/30 04:10:56 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo': 1 matching files 2025/01/30 04:10:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zocazaj5kica" 2025/01/30 04:10:56 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:10:56 DEBUG : Creating backend with remote "TestDrive:crypt/o0ruttdiojpoevmtq8s9uqasf92q1v1buia7ljh4dk4uas9jc3fg" 2025/01/30 04:10:58 DEBUG : Creating backend with remote "/tmp/rclone246659898" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica'", Local "Local file system at /tmp/rclone246659898", Modify Window "1ms" 2025/01/30 04:11:00 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = e70c9691d42d5cc26f86f6fe6e5720cc OK NFCx2 checkfile vs. both remote (without normalization) 2025/01/30 04:11:01 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found 2025/01/30 04:11:01 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica' 2025/01/30 04:11:01 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica': 1 files missing 2025/01/30 04:11:01 NOTICE: 1 hashes missing 2025/01/30 04:11:01 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica': 2 differences found 2025/01/30 04:11:01 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica': 2 errors while checking NFCx2 checkfile vs. both remote (with normalization) 2025/01/30 04:11:02 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:11:02 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica': 0 differences found 2025/01/30 04:11:02 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica': 1 matching files 2025/01/30 04:11:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jukabip4midi" 2025/01/30 04:11:02 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:11:02 DEBUG : Creating backend with remote "TestDrive:crypt/vf8krfnp02bopmv93370eq95h4v1jnm09sg2p4vttid6p5s2bqn0" 2025/01/30 04:11:03 DEBUG : Creating backend with remote "/tmp/rclone3460585559" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi'", Local "Local file system at /tmp/rclone3460585559", Modify Window "1ms" 2025/01/30 04:11:05 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 2d7af77d1f6312679b4a05c4b739ba60 OK both checkfile vs. NFDx2 remote (without normalization) 2025/01/30 04:11:06 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found 2025/01/30 04:11:06 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi' 2025/01/30 04:11:06 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi': 1 files missing 2025/01/30 04:11:06 NOTICE: 1 hashes missing 2025/01/30 04:11:06 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi': 2 differences found 2025/01/30 04:11:06 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi': 2 errors while checking both checkfile vs. NFDx2 remote (with normalization) 2025/01/30 04:11:07 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:11:07 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi': 0 differences found 2025/01/30 04:11:07 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi': 1 matching files 2025/01/30 04:11:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyiwuf4cudo" 2025/01/30 04:11:07 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:11:07 DEBUG : Creating backend with remote "TestDrive:crypt/1tcknpnm4ab8e2d4skdackmffsc02sc6u1qpdql0l7qbini4oev0" 2025/01/30 04:11:08 DEBUG : Creating backend with remote "/tmp/rclone4145098782" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo'", Local "Local file system at /tmp/rclone4145098782", Modify Window "1ms" 2025/01/30 04:11:11 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = f515b4127ecbae79e826ec14d3562671 OK both checkfile vs. NFCx2 remote (without normalization) 2025/01/30 04:11:11 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found 2025/01/30 04:11:11 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo' 2025/01/30 04:11:11 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo': 1 files missing 2025/01/30 04:11:11 NOTICE: 1 hashes missing 2025/01/30 04:11:11 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo': 2 differences found 2025/01/30 04:11:11 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo': 2 errors while checking both checkfile vs. NFCx2 remote (with normalization) 2025/01/30 04:11:13 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2025/01/30 04:11:13 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo': 0 differences found 2025/01/30 04:11:13 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo': 1 matching files 2025/01/30 04:11:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyiwuf4cudo': Purge remote 2025/01/30 04:11:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jukabip4midi': Purge remote 2025/01/30 04:11:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zocazaj5kica': Purge remote 2025/01/30 04:11:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sawacur4wuwo': Purge remote 2025/01/30 04:11:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pikovuq5qabe': Purge remote 2025/01/30 04:11:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-debotix2pele': Purge remote 2025/01/30 04:11:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qodetif1hofa': Purge remote 2025/01/30 04:11:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuyejon1bere': Purge remote 2025/01/30 04:11:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hapexun3suka': Purge remote 2025/01/30 04:11:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fekejab0yepe': Purge remote --- PASS: TestApplyTransforms (60.69s) === RUN TestTruncateString --- PASS: TestTruncateString (0.00s) === RUN TestCopyFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:11:20 DEBUG : file1: Need to transfer - File not found at Destination 2025/01/30 04:11:23 DEBUG : sub/file2: md5 = 9ee431dc01125031926b886cc4f88109 OK 2025/01/30 04:11:23 INFO : file1: Copied (new) to: sub/file2 2025/01/30 04:11:23 DEBUG : file1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/30 04:11:23 DEBUG : file1: Unchanged skipping 2025/01/30 04:11:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': don't need to copy/move sub/file2, it is already at target location 2025/01/30 04:11:26 DEBUG : 150fuo3cn4j1uenq6r4g4qk6t4: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestCopyFile (7.22s) === RUN TestCopyLongFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" copy_test.go:153: Test only runs on local --- SKIP: TestCopyLongFile (0.44s) === RUN TestCopyFileBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:11:30 DEBUG : dst/file1: md5 = 3d095ef1c8d95ead1783318148075d7f OK 2025/01/30 04:11:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/backup" 2025/01/30 04:11:31 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/1nrff024r7pq65ecp72fc28jb0" 2025/01/30 04:11:32 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2025/01/30 04:11:35 INFO : dst/file1: Moved (server-side) 2025/01/30 04:11:37 DEBUG : dst/file1: md5 = f695f4fefffc0361650afab06d89cb3e OK 2025/01/30 04:11:37 INFO : dst/file1: Copied (new) 2025/01/30 04:11:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:11:41 DEBUG : 1nrff024r7pq65ecp72fc28jb0/31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:11:41 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "31u3jie661vd5p8j7rtc3hgbh0" --- PASS: TestCopyFileBackupDir (15.36s) === RUN TestCopyFileCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:11:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/dst" 2025/01/30 04:11:42 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/30 04:11:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/CompareDest" 2025/01/30 04:11:44 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/gveqi14airsml4bgu7krj116o8" 2025/01/30 04:11:46 DEBUG : one: Need to transfer - File not found at Destination 2025/01/30 04:11:48 DEBUG : one: md5 = 683ca92a4b793a244b76ed247e2b3d3f OK 2025/01/30 04:11:48 INFO : one: Copied (new) 2025/01/30 04:11:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/30 04:11:51 DEBUG : one: md5 = 6f38e9ef9225afb2bb2ed978413a6bc4 OK 2025/01/30 04:11:51 INFO : one: Copied (replaced existing) 2025/01/30 04:11:54 DEBUG : dst/one: md5 = 5a0ecd04f2e741aeae8dd964e90faea1 OK 2025/01/30 04:11:56 DEBUG : CompareDest/one: md5 = e369a8b8130662966f7d3c9547bcc2fc OK 2025/01/30 04:11:57 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/30 04:11:57 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/30 04:11:57 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/30 04:12:00 DEBUG : CompareDest/two: md5 = 8bd9b160abb937e9790dfd257d851f2c OK 2025/01/30 04:12:00 DEBUG : two: Need to transfer - File not found at Destination 2025/01/30 04:12:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/30 04:12:01 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/30 04:12:01 DEBUG : two: Need to transfer - File not found at Destination 2025/01/30 04:12:02 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/30 04:12:02 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/30 04:12:03 DEBUG : two: Need to transfer - File not found at Destination 2025/01/30 04:12:03 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/01/30 04:12:05 DEBUG : two: md5 = 40f39fb6304ae44966b0994d310d1e2b OK 2025/01/30 04:12:05 INFO : two: Copied (new) 2025/01/30 04:12:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/30 04:12:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:12:09 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:12:09 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestCopyFileCompareDest (27.78s) === RUN TestCopyFileCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:12:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/dst" 2025/01/30 04:12:10 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/30 04:12:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/CopyDest" 2025/01/30 04:12:12 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/01/30 04:12:13 DEBUG : one: Need to transfer - File not found at Destination 2025/01/30 04:12:16 DEBUG : one: md5 = a41d21736c743cf4cf721151708b02dc OK 2025/01/30 04:12:16 INFO : one: Copied (new) 2025/01/30 04:12:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/30 04:12:19 DEBUG : one: md5 = 23f231a9e9cca2f13bf965b86320b845 OK 2025/01/30 04:12:19 INFO : one: Copied (replaced existing) 2025/01/30 04:12:21 DEBUG : dst/one: md5 = 0fdc9c8dfeca476283bfb29a91294282 OK 2025/01/30 04:12:24 DEBUG : CopyDest/one: md5 = bd899f9c61c23cf4296e8306a7c74918 OK 2025/01/30 04:12:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/BackupDir" 2025/01/30 04:12:25 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/01/30 04:12:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/30 04:12:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/30 04:12:27 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/30 04:12:29 INFO : one: Moved (server-side) 2025/01/30 04:12:30 INFO : one: Copied (server-side copy) 2025/01/30 04:12:30 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/01/30 04:12:32 DEBUG : CopyDest/two: md5 = 552431136c7f234aabfa6ce3fc310aaa OK 2025/01/30 04:12:33 DEBUG : two: Need to transfer - File not found at Destination 2025/01/30 04:12:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/30 04:12:35 INFO : two: Copied (server-side copy) 2025/01/30 04:12:35 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/01/30 04:12:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/30 04:12:35 DEBUG : two: Unchanged skipping 2025/01/30 04:12:38 DEBUG : CopyDest/three: md5 = d3c893ab50a100f559a3c3860e9f9db3 OK 2025/01/30 04:12:39 DEBUG : three: Need to transfer - File not found at Destination 2025/01/30 04:12:39 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/01/30 04:12:39 DEBUG : three: Destination not found in --copy-dest 2025/01/30 04:12:40 DEBUG : three: md5 = 816ff9ab78df5e8e6925c7207e498542 OK 2025/01/30 04:12:40 INFO : three: Copied (new) 2025/01/30 04:12:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/30 04:12:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:12:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/30 04:12:48 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:12:48 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/30 04:12:48 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/30 04:12:49 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestCopyFileCopyDest (39.66s) === RUN TestCopyInplace run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" copy_test.go:370: Partial uploads not supported --- SKIP: TestCopyInplace (0.47s) === RUN TestCopyLongFileName run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" copy_test.go:403: Partial uploads not supported --- SKIP: TestCopyLongFileName (0.44s) === RUN TestCopyFileMaxTransfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:12:51 DEBUG : TestCopyFileMaxTransfer/file1: Need to transfer - File not found at Destination 2025/01/30 04:12:54 DEBUG : TestCopyFileMaxTransfer/file1: md5 = 15a0ffa3b9b4d1937434e67ee5d568db OK 2025/01/30 04:12:54 INFO : TestCopyFileMaxTransfer/file1: Copied (new) 2025/01/30 04:12:54 DEBUG : TestCopyFileMaxTransfer/file2: Need to transfer - File not found at Destination 2025/01/30 04:12:55 ERROR : TestCopyFileMaxTransfer/file2: Failed to copy: Post "https://www.googleapis.com/upload/drive/v3/files?alt=json&fields=id%2Cname%2Csize%2Cmd5Checksum%2Csha1Checksum%2Csha256Checksum%2Ctrashed%2CexplicitlyTrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails%2CexportLinks%2CresourceKey&keepRevisionForever=false&prettyPrint=false&supportsAllDrives=true&uploadType=multipart": googleapi: Copy failed: max transfer limit reached as set by --max-transfer copy_test.go:473: Expecting error to contain accounting.ErrorMaxTransferLimitReachedFatal 2025/01/30 04:12:55 DEBUG : TestCopyFileMaxTransfer/file3: Need to transfer - File not found at Destination 2025/01/30 04:12:56 DEBUG : TestCopyFileMaxTransfer/file4: Need to transfer - File not found at Destination 2025/01/30 04:12:58 DEBUG : TestCopyFileMaxTransfer/file4: md5 = d1272e63d13e2a94012323b51220ccfe OK 2025/01/30 04:12:58 INFO : TestCopyFileMaxTransfer/file4: Copied (new) 2025/01/30 04:13:01 DEBUG : bl9cnu966tarhhpg22ft7c4qm1863k22qdncucii8kn8c3k4aut0: Rmdir: contains trashed file: "amq3bkuqh8mg4ohnbs2i3185uk" 2025/01/30 04:13:01 DEBUG : bl9cnu966tarhhpg22ft7c4qm1863k22qdncucii8kn8c3k4aut0: Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" --- PASS: TestCopyFileMaxTransfer (10.75s) === RUN TestDeduplicateInteractive run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" dedupe_test.go:36: Can't run this test without a hash --- SKIP: TestDeduplicateInteractive (0.43s) === RUN TestDeduplicateSkip run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using skip mode. 2025/01/30 04:13:06 NOTICE: one: Found 2 files with duplicate names 2025/01/30 04:13:06 NOTICE: one: Skipping 2 files with duplicate names --- PASS: TestDeduplicateSkip (5.73s) === RUN TestDeduplicateSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:12 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using skip mode. 2025/01/30 04:13:13 NOTICE: one: Found 3 files with duplicate names 2025/01/30 04:13:13 NOTICE: one: Deleting 1/2 identical duplicates (size 11) 2025/01/30 04:13:13 INFO : one: Deleted 2025/01/30 04:13:13 NOTICE: one: Skipping 2 files with duplicate names --- PASS: TestDeduplicateSizeOnly (7.40s) === RUN TestDeduplicateFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using first mode. 2025/01/30 04:13:20 NOTICE: one: Found 3 files with duplicate names 2025/01/30 04:13:21 INFO : one: Deleted 2025/01/30 04:13:22 INFO : one: Deleted 2025/01/30 04:13:22 NOTICE: one: Deleted 2 extra copies --- PASS: TestDeduplicateFirst (8.00s) === RUN TestDeduplicateNewest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using newest mode. 2025/01/30 04:13:28 NOTICE: one: Found 3 files with duplicate names 2025/01/30 04:13:29 INFO : one: Deleted 2025/01/30 04:13:30 INFO : one: Deleted 2025/01/30 04:13:30 NOTICE: one: Deleted 2 extra copies --- PASS: TestDeduplicateNewest (7.80s) === RUN TestDeduplicateNewestByHash run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" dedupe_test.go:36: Can't run this test without a hash --- SKIP: TestDeduplicateNewestByHash (0.43s) === RUN TestDeduplicateOldest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using oldest mode. 2025/01/30 04:13:36 NOTICE: one: Found 3 files with duplicate names 2025/01/30 04:13:37 INFO : one: Deleted 2025/01/30 04:13:37 INFO : one: Deleted 2025/01/30 04:13:37 NOTICE: one: Deleted 2 extra copies --- PASS: TestDeduplicateOldest (7.54s) === RUN TestDeduplicateLargest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using largest mode. 2025/01/30 04:13:44 NOTICE: one: Found 3 files with duplicate names 2025/01/30 04:13:45 INFO : one: Deleted 2025/01/30 04:13:45 INFO : one: Deleted 2025/01/30 04:13:45 NOTICE: one: Deleted 2 extra copies --- PASS: TestDeduplicateLargest (7.73s) === RUN TestDeduplicateSmallest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:13:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using smallest mode. 2025/01/30 04:13:51 NOTICE: one: Found 3 files with duplicate names 2025/01/30 04:13:52 INFO : one: Deleted 2025/01/30 04:13:53 INFO : one: Deleted 2025/01/30 04:13:53 NOTICE: one: Deleted 2 extra copies --- PASS: TestDeduplicateSmallest (7.38s) === RUN TestDeduplicateRename run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:14:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Looking for duplicate names using rename mode. 2025/01/30 04:14:01 NOTICE: one.txt: Found 3 files with duplicate names 2025/01/30 04:14:02 INFO : one-2.txt: renamed from: one.txt 2025/01/30 04:14:03 INFO : one-3.txt: renamed from: one.txt 2025/01/30 04:14:05 INFO : one-4.txt: renamed from: one.txt --- PASS: TestDeduplicateRename (14.08s) === RUN TestMergeDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:14:11 DEBUG : dupe1/one.txt: md5 = 0b1ee9d742b7be67b208571612ed360f OK 2025/01/30 04:14:13 DEBUG : dupe2/two.txt: md5 = 566af5031cb74f426f7dae6cd5896e88 OK 2025/01/30 04:14:16 DEBUG : dupe3/three.txt: md5 = 01f5815c29a81556578878ac7aaf9eee OK 2025/01/30 04:14:17 INFO : urj8gsducqbtvekeq181ntd2u8: merging "sfrom47189m9qr3mt4qonu281c" 2025/01/30 04:14:17 INFO : urj8gsducqbtvekeq181ntd2u8: removing empty directory 2025/01/30 04:14:18 INFO : 1u1r4ei7c628fnjg9blqt3j60o: merging "tr2hj63d80ftlmvm6a952snjcc" 2025/01/30 04:14:19 INFO : 1u1r4ei7c628fnjg9blqt3j60o: removing empty directory 2025/01/30 04:14:23 DEBUG : 6kqidisnml4ml642h4iorebdng: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/30 04:14:23 DEBUG : 6kqidisnml4ml642h4iorebdng: Rmdir: contains trashed file: "sfrom47189m9qr3mt4qonu281c" 2025/01/30 04:14:23 DEBUG : 6kqidisnml4ml642h4iorebdng: Rmdir: contains trashed file: "o9f79a47tdo934l5lfe4jpsms8" --- PASS: TestMergeDirs (16.27s) === RUN TestListDirSorted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:14:26 DEBUG : a.txt: md5 = 7fb0c81efbf41018394431f6d699a97c OK 2025/01/30 04:14:28 DEBUG : zend.txt: md5 = 7ba87b59107819318c17e871c4112604 OK 2025/01/30 04:14:30 DEBUG : sub dir/hello world: md5 = cd8a6c07b86378d88809d99f96226c9e OK 2025/01/30 04:14:32 DEBUG : sub dir/hello world2: md5 = 435ff8bfcdd7d12f2f9c70ad8f467ebc OK 2025/01/30 04:14:35 DEBUG : sub dir/ignore dir/.ignore: md5 = 3b7333be662231fcf37853a033ea6ed1 OK 2025/01/30 04:14:37 DEBUG : sub dir/ignore dir/should be ignored: md5 = 98e04fe5abf0cb60f71e0529b38407c2 OK 2025/01/30 04:14:39 DEBUG : sub dir/sub sub dir/hello world3: md5 = d5754e413bfdfde4858c5f937872d237 OK 2025/01/30 04:14:41 DEBUG : a.txt: Excluded (Size Filter) 2025/01/30 04:14:41 DEBUG : a.txt: Excluded 2025/01/30 04:14:41 DEBUG : sub dir/hello world2: Excluded (Size Filter) 2025/01/30 04:14:41 DEBUG : sub dir/hello world2: Excluded 2025/01/30 04:14:41 DEBUG : sub dir/hello world: Excluded (Size Filter) 2025/01/30 04:14:41 DEBUG : sub dir/hello world: Excluded 2025/01/30 04:14:42 DEBUG : sub dir/ignore dir: Excluded 2025/01/30 04:14:42 DEBUG : sub dir/hello world2: Excluded (Size Filter) 2025/01/30 04:14:42 DEBUG : sub dir/hello world2: Excluded 2025/01/30 04:14:42 DEBUG : sub dir/hello world: Excluded (Size Filter) 2025/01/30 04:14:42 DEBUG : sub dir/hello world: Excluded 2025/01/30 04:14:42 DEBUG : sub dir/ignore dir: Excluded 2025/01/30 04:14:49 DEBUG : 14begaa36ih249fgrnfk6nulg0/u72nb76vlceqmgie4q57rr656s: Rmdir: contains trashed file: "o5airla31uiui01blt74of9ves" 2025/01/30 04:14:49 DEBUG : 14begaa36ih249fgrnfk6nulg0/3fslb0r9seuggqgrrqv2gjhfj8: Rmdir: contains trashed file: "8qak2o3rl7h348s0lh02ghr71aajis56gocdjjbjfkc2j4vakju0" 2025/01/30 04:14:49 DEBUG : 14begaa36ih249fgrnfk6nulg0/3fslb0r9seuggqgrrqv2gjhfj8: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" 2025/01/30 04:14:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "u72nb76vlceqmgie4q57rr656s" 2025/01/30 04:14:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "3fslb0r9seuggqgrrqv2gjhfj8" 2025/01/30 04:14:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "mp1g12tj43cv7goud5b95fgju8" 2025/01/30 04:14:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestListDirSorted (27.00s) === RUN TestListJSON run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:14:53 DEBUG : file1: md5 = 50550c4532efd828644eff73e93178cd OK 2025/01/30 04:14:55 DEBUG : sub/file2: md5 = eff54f480cd5e7b03783b5630f09b827 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 2025/01/30 04:14:59 ERROR : file1: Failed to read hash: hash type not supported === RUN TestListJSON/Metadata 2025/01/30 04:14:59 DEBUG : eer8kka55qnghc34cq76ca668g: Fetching metadata 2025/01/30 04:14:59 DEBUG : 150fuo3cn4j1uenq6r4g4qk6t4: Fetching metadata 2025/01/30 04:15:01 DEBUG : 150fuo3cn4j1uenq6r4g4qk6t4: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestListJSON (10.84s) --- PASS: TestListJSON/Default (0.26s) --- PASS: TestListJSON/FilesOnly (0.27s) --- PASS: TestListJSON/DirsOnly (0.23s) --- PASS: TestListJSON/Recurse (0.55s) --- PASS: TestListJSON/SubDir (0.22s) --- PASS: TestListJSON/NoModTime (0.23s) --- PASS: TestListJSON/NoMimeType (0.23s) --- PASS: TestListJSON/ShowHash (0.22s) --- PASS: TestListJSON/HashTypes (0.25s) --- PASS: TestListJSON/Metadata (0.66s) === RUN TestStatJSON run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:04 DEBUG : file1: md5 = 4a1ea2c7e288f8f375110bd3e639f84c OK 2025/01/30 04:15:07 DEBUG : sub/file2: md5 = e2419727833cfa7b37600dcf41134ef1 OK === RUN TestStatJSON/Root === RUN TestStatJSON/RootFilesOnly === RUN TestStatJSON/RootDirsOnly === RUN TestStatJSON/Dir === RUN TestStatJSON/DirWithTrailingSlash === 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 2025/01/30 04:15:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/notfound" 2025/01/30 04:15:11 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/qe0i31qdkoejk60elps0ni5sqk" 2025/01/30 04:15:14 DEBUG : 150fuo3cn4j1uenq6r4g4qk6t4: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestStatJSON (13.09s) --- PASS: TestStatJSON/Root (0.25s) --- PASS: TestStatJSON/RootFilesOnly (0.00s) --- PASS: TestStatJSON/RootDirsOnly (0.25s) --- PASS: TestStatJSON/Dir (0.47s) --- PASS: TestStatJSON/DirWithTrailingSlash (0.24s) --- PASS: TestStatJSON/File (0.24s) --- PASS: TestStatJSON/NotFound (0.48s) --- PASS: TestStatJSON/DirFilesOnly (0.22s) --- PASS: TestStatJSON/FileFilesOnly (0.23s) --- PASS: TestStatJSON/NotFoundFilesOnly (0.21s) --- PASS: TestStatJSON/DirDirsOnly (0.26s) --- PASS: TestStatJSON/FileDirsOnly (0.26s) --- PASS: TestStatJSON/NotFoundDirsOnly (0.25s) --- PASS: TestStatJSON/RootNotFound (1.77s) === RUN TestMkdir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Making directory 2025/01/30 04:15:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Making directory --- PASS: TestMkdir (0.69s) === RUN TestLsd run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:19 DEBUG : sub dir/hello world: md5 = c83a200c638cc717a1782c0b04831128 OK 2025/01/30 04:15:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestLsd (5.62s) === RUN TestLs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:23 DEBUG : potato2: md5 = b6c8eb4152101d7c2065e9f4da143ce9 OK 2025/01/30 04:15:25 DEBUG : empty space: md5 = 94b0ea0f1ddc8ed5d425bf91d7ff4e6a OK --- PASS: TestLs (5.66s) === RUN TestLsWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:29 DEBUG : potato2: md5 = 4c98cad3d4aa1de375738232492992d5 OK 2025/01/30 04:15:30 DEBUG : empty space: md5 = b510bd5c67443e7bff57af0333cb2ff0 OK 2025/01/30 04:15:31 DEBUG : empty space: Excluded (FilesFrom Filter) --- PASS: TestLsWithFilesFrom (7.34s) === RUN TestLsLong run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:36 DEBUG : potato2: md5 = 4fd9a5acfc9df711bc1b4c103fdf972a OK 2025/01/30 04:15:38 DEBUG : empty space: md5 = 2291f40f3cf427dfc07ee35a4720474b OK --- PASS: TestLsLong (5.50s) === RUN TestHashSums run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:42 DEBUG : potato2: md5 = be1e7550831a32b13aa5e61c8418001a OK 2025/01/30 04:15:44 DEBUG : empty space: md5 = 901578df0b3cdcc9c6f379de766e35ff OK --- PASS: TestHashSums (5.32s) === RUN TestHashSumsWithErrors 2025/01/30 04:15:45 DEBUG : Creating backend with remote ":memory:" 2025/01/30 04:15:45 ERROR : file1: hash unsupported: hash type not supported --- PASS: TestHashSumsWithErrors (0.00s) === RUN TestHashStream 2025/01/30 04:15:45 DEBUG : Creating md5 hash of 0 bytes read from input stream 2025/01/30 04:15:45 DEBUG : Creating md5 hash of 0 bytes read from input stream 2025/01/30 04:15:45 DEBUG : Creating sha1 hash of 0 bytes read from input stream 2025/01/30 04:15:45 DEBUG : Creating sha1 hash of 0 bytes read from input stream 2025/01/30 04:15:45 DEBUG : Creating md5 hash of 12 bytes read from input stream 2025/01/30 04:15:45 DEBUG : Creating md5 hash of 12 bytes read from input stream 2025/01/30 04:15:45 DEBUG : Creating sha1 hash of 12 bytes read from input stream 2025/01/30 04:15:45 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:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:47 DEBUG : potato2: md5 = 5de1813892477ddde4b71bc7b998ae63 OK 2025/01/30 04:15:49 DEBUG : empty space: md5 = 637a3422088f2a92d6d7dd46fee6ef7a OK 2025/01/30 04:15:51 DEBUG : sub dir/potato3: md5 = d393ab6512a293b4a7072ba5bc210f36 OK 2025/01/30 04:15:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "9atai6og4mljg3r5gjeh27k0q8" --- PASS: TestCount (10.09s) === RUN TestDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:15:57 DEBUG : small: md5 = 3412c44d6e58cab12d54f4865223fbeb OK 2025/01/30 04:15:59 DEBUG : medium: md5 = 2e831b24128f15a1fa0196e2b64883b9 OK 2025/01/30 04:16:01 DEBUG : large: md5 = 59b28c7c2358adc2df3a2d1ee4341ff2 OK 2025/01/30 04:16:01 DEBUG : Waiting for deletions to finish 2025/01/30 04:16:01 DEBUG : large: Excluded (Size Filter) 2025/01/30 04:16:02 INFO : medium: Deleted 2025/01/30 04:16:02 INFO : small: Deleted --- PASS: TestDelete (7.55s) === RUN TestMaxDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:16:05 DEBUG : small: md5 = 4b4b748657353657058b152e705c4354 OK 2025/01/30 04:16:06 DEBUG : medium: md5 = 5cf3b15e9bf96b43ff1f166def7b9e42 OK 2025/01/30 04:16:08 DEBUG : large: md5 = 293356bc3d067502c7a0fca06c8928f6 OK 2025/01/30 04:16:08 DEBUG : Waiting for deletions to finish 2025/01/30 04:16:08 ERROR : large: Got fatal error on delete: --max-delete threshold reached 2025/01/30 04:16:09 INFO : medium: Deleted 2025/01/30 04:16:09 INFO : small: Deleted --- PASS: TestMaxDelete (7.97s) === RUN TestMaxDeleteSizeLargeFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:16:13 DEBUG : small: md5 = b268135d6a49e1297c38427a58449f36 OK 2025/01/30 04:16:15 DEBUG : medium: md5 = 8918aa9056efe4694d1e16954b6c6b38 OK 2025/01/30 04:16:17 DEBUG : large: md5 = d49e3c1cbb10a3185e026a6a828e8af9 OK 2025/01/30 04:16:17 DEBUG : Waiting for deletions to finish 2025/01/30 04:16:17 ERROR : large: Got fatal error on delete: --max-delete-size threshold reached 2025/01/30 04:16:18 INFO : medium: Deleted 2025/01/30 04:16:18 INFO : small: Deleted --- PASS: TestMaxDeleteSizeLargeFile (8.27s) === RUN TestMaxDeleteSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:16:21 DEBUG : small: md5 = 0e98e88e5f8538b87a70e33ab34a04dc OK 2025/01/30 04:16:22 DEBUG : medium: md5 = f94e53d278704c9c6883da7f0f5d012c OK 2025/01/30 04:16:24 DEBUG : large: md5 = 3e111ad34dea422c25dd11b127d36c19 OK 2025/01/30 04:16:25 DEBUG : Waiting for deletions to finish 2025/01/30 04:16:25 ERROR : large: Got fatal error on delete: --max-delete-size threshold reached 2025/01/30 04:16:25 INFO : small: Deleted 2025/01/30 04:16:26 INFO : medium: Deleted --- PASS: TestMaxDeleteSize (8.22s) === RUN TestReadFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:16:29 DEBUG : ReadFile: md5 = 88bfe5b3ec2d233bb31a35541e246680 OK --- PASS: TestReadFile (4.68s) === RUN TestRetry 2025/01/30 04:16:32 DEBUG : Received error: Wrapped EOF is retriable: EOF - low level retry 1/5 2025/01/30 04:16:32 DEBUG : Received error: Wrapped EOF is retriable: EOF - low level retry 2/5 2025/01/30 04:16:32 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG 2025/01/30 04:16:32 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG 2025/01/30 04:16:32 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG 2025/01/30 04:16:32 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG 2025/01/30 04:16:32 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG --- PASS: TestRetry (0.05s) === RUN TestCat run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:16:34 DEBUG : file1: md5 = bb24d0583eb4653b73b7b7866d70b77a OK 2025/01/30 04:16:35 DEBUG : file2: md5 = 4e0baafbf423b59172050bec33d3dedc OK --- PASS: TestCat (17.21s) === RUN TestPurge 2025/01/30 04:16:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lahoyux7gugu" 2025/01/30 04:16:49 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/30 04:16:49 DEBUG : Creating backend with remote "TestDrive:crypt/k3fj6baive4u7dap7r7o3lip1699r8nnp1n7uq2umokhcu7e1ilg" 2025/01/30 04:16:50 DEBUG : Creating backend with remote "/tmp/rclone600428456" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lahoyux7gugu'", Local "Local file system at /tmp/rclone600428456", Modify Window "1ms" 2025/01/30 04:16:57 DEBUG : A1/B1/C1/one: md5 = 51a5743638624eccdb76bb81e6ed1ca4 OK 2025/01/30 04:16:57 INFO : A2: Making directory 2025/01/30 04:16:57 INFO : A1/B2: Making directory 2025/01/30 04:16:58 INFO : A1/B2/C2: Making directory 2025/01/30 04:16:59 INFO : A1/B1/C3: Making directory 2025/01/30 04:17:00 INFO : A3: Making directory 2025/01/30 04:17:01 INFO : A3/B3: Making directory 2025/01/30 04:17:02 INFO : A3/B3/C4: Making directory 2025/01/30 04:17:05 DEBUG : A1/two: md5 = 0d04455d705834ba9ee2ab5775fa8299 OK 2025/01/30 04:17:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lahoyux7gugu': Purge remote 2025/01/30 04:17:09 NOTICE: purge failed: directory not found --- PASS: TestPurge (19.14s) === RUN TestRmdirsNoLeaveRoot run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:17:13 DEBUG : A1/B1/C1/one: md5 = 86d42ff4f8cb073f02853a87870465e9 OK 2025/01/30 04:17:13 INFO : A2: Making directory 2025/01/30 04:17:14 INFO : A1/B2: Making directory 2025/01/30 04:17:15 INFO : A1/B2/C2: Making directory 2025/01/30 04:17:16 INFO : A1/B1/C3: Making directory 2025/01/30 04:17:17 INFO : A3: Making directory 2025/01/30 04:17:18 INFO : A3/B3: Making directory 2025/01/30 04:17:19 INFO : A3/B3/C4: Making directory 2025/01/30 04:17:22 DEBUG : A1/two: md5 = 1e0fa7fc174f9e63720ce6c9a8f29178 OK 2025/01/30 04:17:23 DEBUG : removing 1 level 3 directories 2025/01/30 04:17:23 INFO : A3/B3/C4: Removing directory 2025/01/30 04:17:26 DEBUG : removing 2 level 3 directories 2025/01/30 04:17:26 INFO : A1/B2/C2: Removing directory 2025/01/30 04:17:26 INFO : A1/B1/C3: Removing directory 2025/01/30 04:17:27 DEBUG : removing 2 level 2 directories 2025/01/30 04:17:27 INFO : A3/B3: Removing directory 2025/01/30 04:17:27 INFO : A1/B2: Removing directory 2025/01/30 04:17:27 DEBUG : h0fgn6vkka25jj9fhu5roml6pg/avn2ljdtrs3fgdela1haatj3go: Rmdir: contains trashed file: "k43jqb5391s8afh9eje7baui0g" 2025/01/30 04:17:27 DEBUG : fppqbfrji50odnh2br069japlo/8j6vge4hggs2biai52vpe0kpik: Rmdir: contains trashed file: "ope427f0bb0h1ebd1s1fm4022k" 2025/01/30 04:17:27 DEBUG : removing 2 level 1 directories 2025/01/30 04:17:27 INFO : A3: Removing directory 2025/01/30 04:17:27 INFO : A2: Removing directory 2025/01/30 04:17:28 DEBUG : fppqbfrji50odnh2br069japlo: Rmdir: contains trashed file: "8j6vge4hggs2biai52vpe0kpik" 2025/01/30 04:17:32 DEBUG : removing 1 level 3 directories 2025/01/30 04:17:32 INFO : A1/B1/C1: Removing directory 2025/01/30 04:17:32 DEBUG : h0fgn6vkka25jj9fhu5roml6pg/rv5l12j0nanu5af9ivc97ofdk8/gtu1leijh9rlm05pcjtusqop2g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:33 DEBUG : removing 1 level 2 directories 2025/01/30 04:17:33 INFO : A1/B1: Removing directory 2025/01/30 04:17:33 DEBUG : h0fgn6vkka25jj9fhu5roml6pg/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "ui2vk9n52l82tdno99vhkfi87g" 2025/01/30 04:17:33 DEBUG : h0fgn6vkka25jj9fhu5roml6pg/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "gtu1leijh9rlm05pcjtusqop2g" 2025/01/30 04:17:34 DEBUG : removing 1 level 1 directories 2025/01/30 04:17:34 INFO : A1: Removing directory 2025/01/30 04:17:34 DEBUG : h0fgn6vkka25jj9fhu5roml6pg: Rmdir: contains trashed file: "avn2ljdtrs3fgdela1haatj3go" 2025/01/30 04:17:34 DEBUG : h0fgn6vkka25jj9fhu5roml6pg: Rmdir: contains trashed file: "rv5l12j0nanu5af9ivc97ofdk8" 2025/01/30 04:17:34 DEBUG : h0fgn6vkka25jj9fhu5roml6pg: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/30 04:17:35 DEBUG : removing 1 level 0 directories 2025/01/30 04:17:35 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Removing directory 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "fppqbfrji50odnh2br069japlo" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "c3k31g9ua29pvlul21td3bpldo" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "h0fgn6vkka25jj9fhu5roml6pg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "150fuo3cn4j1uenq6r4g4qk6t4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "150fuo3cn4j1uenq6r4g4qk6t4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1u1r4ei7c628fnjg9blqt3j60o" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "urj8gsducqbtvekeq181ntd2u8" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "6kqidisnml4ml642h4iorebdng" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "bl9cnu966tarhhpg22ft7c4qm1863k22qdncucii8kn8c3k4aut0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "d09o6po3f7bm6ce32vdgs8h9ls" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "31u3jie661vd5p8j7rtc3hgbh0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "gveqi14airsml4bgu7krj116o8" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "31u3jie661vd5p8j7rtc3hgbh0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1nrff024r7pq65ecp72fc28jb0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "31u3jie661vd5p8j7rtc3hgbh0" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "150fuo3cn4j1uenq6r4g4qk6t4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "vjrnln8ratgmqakfosrqe8espk" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "c4shrkuhic7ob3njfv3g2s2vik" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "to8qa1vn2r6dftei4e0knjo6o4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "to8qa1vn2r6dftei4e0knjo6o4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "to8qa1vn2r6dftei4e0knjo6o4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "tg4p894oov5pg84onakp5iir70" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "tg4p894oov5pg84onakp5iir70" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "tg4p894oov5pg84onakp5iir70" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "tg4p894oov5pg84onakp5iir70" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1atl8vl4e0t9vhahglkub15g9k" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "bdfh2jnp94io268p9p6mr133n4" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "q5ep28d6fiuvnifhronkrc1h8c" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "q5ep28d6fiuvnifhronkrc1h8c" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "q5ep28d6fiuvnifhronkrc1h8c" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1hetg8lme4rcdmnfbr0koj9m74" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "09ptdmd3vn9ng72gtig19k3tqg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "160p8jokk6e0sqr9khoaqluoic" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "09ptdmd3vn9ng72gtig19k3tqg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "2a4ubhneaj47tjcufnjilco248" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "09ptdmd3vn9ng72gtig19k3tqg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "160p8jokk6e0sqr9khoaqluoic" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "09ptdmd3vn9ng72gtig19k3tqg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "e9p3gp5bt94lpg91gpij093918" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "4u4fjlma3lemqjvkevbirqdmms" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "q75kr6k6e4u4qcpfacnefr56vg" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "160p8jokk6e0sqr9khoaqluoic" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "1hetg8lme4rcdmnfbr0koj9m74" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "160p8jokk6e0sqr9khoaqluoic" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "m5t7ukfh84vcomkjqcneu2d7uo" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:17:35 DEBUG : : Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestRmdirsNoLeaveRoot (27.66s) === RUN TestRmdirsLeaveRoot run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:17:37 INFO : A1: Making directory 2025/01/30 04:17:38 INFO : A1/B1: Making directory 2025/01/30 04:17:39 INFO : A1/B1/C1: Making directory 2025/01/30 04:17:42 DEBUG : removing 1 level 3 directories 2025/01/30 04:17:42 INFO : A1/B1/C1: Removing directory 2025/01/30 04:17:43 DEBUG : removing 1 level 2 directories 2025/01/30 04:17:43 INFO : A1/B1: Removing directory 2025/01/30 04:17:43 DEBUG : h0fgn6vkka25jj9fhu5roml6pg/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "gtu1leijh9rlm05pcjtusqop2g" 2025/01/30 04:17:45 DEBUG : h0fgn6vkka25jj9fhu5roml6pg: Rmdir: contains trashed file: "rv5l12j0nanu5af9ivc97ofdk8" --- PASS: TestRmdirsLeaveRoot (9.67s) === RUN TestRmdirsWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:17:46 INFO : A1: Making directory 2025/01/30 04:17:47 INFO : A1/B1: Making directory 2025/01/30 04:17:48 INFO : A1/B1/C1: Making directory 2025/01/30 04:17:51 DEBUG : removing 1 level 3 directories 2025/01/30 04:17:51 INFO : A1/B1/C1: Removing directory 2025/01/30 04:17:52 DEBUG : removing 1 level 2 directories 2025/01/30 04:17:52 INFO : A1/B1: Removing directory 2025/01/30 04:17:52 DEBUG : h0fgn6vkka25jj9fhu5roml6pg/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "gtu1leijh9rlm05pcjtusqop2g" 2025/01/30 04:17:54 DEBUG : h0fgn6vkka25jj9fhu5roml6pg: Rmdir: contains trashed file: "rv5l12j0nanu5af9ivc97ofdk8" --- PASS: TestRmdirsWithFilter (8.76s) === RUN TestCopyURL run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:17:57 DEBUG : file1: md5 = 516d87d02566ffd66d6c84511a8dcf57 OK 2025/01/30 04:17:57 DEBUG : filename.txt: File name found in url 2025/01/30 04:17:59 DEBUG : filename.txt: md5 = 4091c1c1d863c602c5bf7b2da25f4b87 OK 2025/01/30 04:17:59 DEBUG : headerfilename.txt: filename found in Content-Disposition header. 2025/01/30 04:18:00 DEBUG : headerfilename.txt: md5 = 31710f5e258a77c41d20539736f2f233 OK 2025/01/30 04:18:02 DEBUG : file2: md5 = f1c15aa199d9c95bd0d665b987f3c0ba OK --- PASS: TestCopyURL (10.82s) === RUN TestCopyURLToWriter --- PASS: TestCopyURLToWriter (0.00s) === RUN TestMoveFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:18:06 DEBUG : file1: Need to transfer - File not found at Destination 2025/01/30 04:18:08 DEBUG : sub/file2: md5 = 65de8bad2889b29eab10cf06e1458268 OK 2025/01/30 04:18:08 INFO : file1: Copied (new) to: sub/file2 2025/01/30 04:18:08 INFO : file1: Deleted 2025/01/30 04:18:09 DEBUG : file1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/30 04:18:09 DEBUG : file1: Unchanged skipping 2025/01/30 04:18:09 INFO : file1: Deleted 2025/01/30 04:18:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': don't need to copy/move sub/file2, it is already at target location 2025/01/30 04:18:11 DEBUG : 150fuo3cn4j1uenq6r4g4qk6t4: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestMoveFile (6.81s) === RUN TestMoveFileWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:18:13 DEBUG : file1: Need to transfer - File not found at Destination 2025/01/30 04:18:14 DEBUG : file1: md5 = 30aa924514294606826a06dbe4d8e5d0 OK 2025/01/30 04:18:14 INFO : file1: Copied (new) 2025/01/30 04:18:14 INFO : file1: Deleted 2025/01/30 04:18:15 DEBUG : file1: Destination exists, skipping 2025/01/30 04:18:15 DEBUG : file1: Not removing source file as destination file exists and --ignore-existing is set --- PASS: TestMoveFileWithIgnoreExisting (4.06s) === RUN TestCaseInsensitiveMoveFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" --- PASS: TestCaseInsensitiveMoveFile (0.42s) === RUN TestCaseInsensitiveMoveFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" --- PASS: TestCaseInsensitiveMoveFileDryRun (0.46s) === RUN TestMoveFileBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:18:20 DEBUG : dst/file1: md5 = cd207b2c0ebad5d7699fa406c46dc40f OK 2025/01/30 04:18:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wozacuf0poqe/backup" 2025/01/30 04:18:21 DEBUG : Creating backend with remote "TestDrive:crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0/1nrff024r7pq65ecp72fc28jb0" 2025/01/30 04:18:22 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2025/01/30 04:18:25 INFO : dst/file1: Moved (server-side) 2025/01/30 04:18:27 DEBUG : dst/file1: md5 = 8f58c1b11acdd1bf621e971411d87692 OK 2025/01/30 04:18:27 INFO : dst/file1: Copied (new) 2025/01/30 04:18:27 INFO : dst/file1: Deleted 2025/01/30 04:18:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:18:30 DEBUG : 1nrff024r7pq65ecp72fc28jb0/31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "eer8kka55qnghc34cq76ca668g" 2025/01/30 04:18:31 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "31u3jie661vd5p8j7rtc3hgbh0" --- PASS: TestMoveFileBackupDir (14.98s) === RUN TestSameConfig --- PASS: TestSameConfig (0.00s) === RUN TestSame --- PASS: TestSame (0.00s) === RUN TestOverlappingFilterCheckWithoutFilter --- PASS: TestOverlappingFilterCheckWithoutFilter (0.00s) === RUN TestOverlappingFilterCheckWithFilter --- PASS: TestOverlappingFilterCheckWithFilter (0.00s) === RUN TestListFormat --- PASS: TestListFormat (0.00s) === RUN TestDirMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:18:35 DEBUG : A1/one: md5 = d620e8b6a0fb5dbefd9338b71af49d3b OK 2025/01/30 04:18:37 DEBUG : A1/two: md5 = 964654b8305f08b05ab13f0f9e614ccc OK 2025/01/30 04:18:39 DEBUG : A1/B1/three: md5 = 7d8be259693ef9f38ea9384ab270b0da OK 2025/01/30 04:18:42 DEBUG : A1/B1/C1/four: md5 = 1c9a923ad784e715e21c37ab44b173a0 OK 2025/01/30 04:18:45 DEBUG : A1/B1/C2/five: md5 = a73e6bc7fd7e87b3a2268f8100edf008 OK 2025/01/30 04:18:45 INFO : A1/B2: Making directory 2025/01/30 04:18:46 INFO : A1/B1/C3: Making directory 2025/01/30 04:18:58 INFO : A2/B1/three: Moved (server-side) to: A3/B1/three 2025/01/30 04:18:58 INFO : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five 2025/01/30 04:18:58 INFO : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four 2025/01/30 04:18:58 INFO : A2/two: Moved (server-side) to: A3/two 2025/01/30 04:18:58 INFO : A2/one: Moved (server-side) to: A3/one 2025/01/30 04:19:02 DEBUG : c3k31g9ua29pvlul21td3bpldo/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "ui2vk9n52l82tdno99vhkfi87g" 2025/01/30 04:19:02 DEBUG : c3k31g9ua29pvlul21td3bpldo/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "k43jqb5391s8afh9eje7baui0g" 2025/01/30 04:19:02 DEBUG : c3k31g9ua29pvlul21td3bpldo/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "gtu1leijh9rlm05pcjtusqop2g" 2025/01/30 04:19:03 DEBUG : c3k31g9ua29pvlul21td3bpldo: Rmdir: contains trashed file: "avn2ljdtrs3fgdela1haatj3go" 2025/01/30 04:19:03 DEBUG : c3k31g9ua29pvlul21td3bpldo: Rmdir: contains trashed file: "rv5l12j0nanu5af9ivc97ofdk8" 2025/01/30 04:19:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes 2025/01/30 04:19:12 INFO : A3/B1/three: Moved (server-side) to: A4/B1/three 2025/01/30 04:19:12 INFO : A3/two: Moved (server-side) to: A4/two 2025/01/30 04:19:13 INFO : A3/B1/C2/five: Moved (server-side) to: A4/B1/C2/five 2025/01/30 04:19:13 INFO : A3/B1/C1/four: Moved (server-side) to: A4/B1/C1/four 2025/01/30 04:19:13 INFO : A3/one: Moved (server-side) to: A4/one 2025/01/30 04:19:16 DEBUG : fppqbfrji50odnh2br069japlo/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "ui2vk9n52l82tdno99vhkfi87g" 2025/01/30 04:19:16 DEBUG : fppqbfrji50odnh2br069japlo/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "k43jqb5391s8afh9eje7baui0g" 2025/01/30 04:19:16 DEBUG : fppqbfrji50odnh2br069japlo/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "gtu1leijh9rlm05pcjtusqop2g" 2025/01/30 04:19:17 DEBUG : fppqbfrji50odnh2br069japlo: Rmdir: contains trashed file: "avn2ljdtrs3fgdela1haatj3go" 2025/01/30 04:19:17 DEBUG : fppqbfrji50odnh2br069japlo: Rmdir: contains trashed file: "rv5l12j0nanu5af9ivc97ofdk8" 2025/01/30 04:19:25 DEBUG : kafked7s86nmf4k5e2iil1i668/rv5l12j0nanu5af9ivc97ofdk8/k43jqb5391s8afh9eje7baui0g: Rmdir: contains trashed file: "67t67jgahg44dflpavut88pang" 2025/01/30 04:19:26 DEBUG : kafked7s86nmf4k5e2iil1i668/rv5l12j0nanu5af9ivc97ofdk8/gtu1leijh9rlm05pcjtusqop2g: Rmdir: contains trashed file: "r2oabfeuilgbi5ic6kevi8chd0" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "ui2vk9n52l82tdno99vhkfi87g" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "k43jqb5391s8afh9eje7baui0g" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "gtu1leijh9rlm05pcjtusqop2g" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668/rv5l12j0nanu5af9ivc97ofdk8: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668: Rmdir: contains trashed file: "avn2ljdtrs3fgdela1haatj3go" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668: Rmdir: contains trashed file: "rv5l12j0nanu5af9ivc97ofdk8" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/30 04:19:27 DEBUG : kafked7s86nmf4k5e2iil1i668: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestDirMove (56.25s) === RUN TestGetFsInfo run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" --- PASS: TestGetFsInfo (0.44s) === RUN TestRcat === RUN TestRcat/withChecksum=false,ignoreChecksum=false run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:19:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (34 bytes), uploading instead of streaming 2025/01/30 04:19:31 DEBUG : no_checksum_small_file_from_pipe: md5 = f3816b7186defaf1f3029df7b98739c5 OK 2025/01/30 04:19:31 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/01/30 04:19:31 DEBUG : no_checksum_small_file_from_pipe: Size of src and dst objects identical 2025/01/30 04:19:31 DEBUG : qc9k4uauqa9ls6a2r6lo8jf4b1m7r0510pkurois1cc70egbs4h0: Sending chunk 0 length 102465 2025/01/30 04:19:33 DEBUG : no_checksum_big_file_from_pipe: md5 = 5dff391cc1635fad7e52875091ea2da3 OK 2025/01/30 04:19:33 DEBUG : no_checksum_big_file_from_pipe: Size of src and dst objects identical === RUN TestRcat/withChecksum=true,ignoreChecksum=false run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:19:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (34 bytes), uploading instead of streaming 2025/01/30 04:19:37 DEBUG : with_checksum_small_file_from_pipe: md5 = a83b0aa29ceb3a922ca334b9f8d9f4f8 OK 2025/01/30 04:19:37 DEBUG : with_checksum_small_file_from_pipe: Size of src and dst objects identical 2025/01/30 04:19:37 DEBUG : e74jo8a7lr1aimg2u78fct67gnuetc1qujiofaci0c8fnq7rjt1d4i296pcklqhgdihs03etvgdi4: Sending chunk 0 length 102465 2025/01/30 04:19:38 DEBUG : with_checksum_big_file_from_pipe: md5 = 909244e050c76ce97ed6d51692e6342d OK 2025/01/30 04:19:38 DEBUG : with_checksum_big_file_from_pipe: Size of src and dst objects identical === RUN TestRcat/withChecksum=false,ignoreChecksum=true run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (34 bytes), uploading instead of streaming 2025/01/30 04:19:43 DEBUG : ignore_checksum_small_file_from_pipe: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/30 04:19:43 DEBUG : 1963rn6olajfbjn4nbqi9nacu7bk879vpf0d2bg8r0ndcqqsfntob0urt056p0qujf574rqnb5f62: Sending chunk 0 length 102465 2025/01/30 04:19:44 DEBUG : ignore_checksum_big_file_from_pipe: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) === RUN TestRcat/withChecksum=true,ignoreChecksum=true run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:19:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (34 bytes), uploading instead of streaming 2025/01/30 04:19:48 DEBUG : ignore_checksum_small_file_from_pipe: Size of src and dst objects identical 2025/01/30 04:19:49 DEBUG : 1963rn6olajfbjn4nbqi9nacu7bk879vpf0d2bg8r0ndcqqsfntob0urt056p0qujf574rqnb5f62: Sending chunk 0 length 102465 2025/01/30 04:19:50 DEBUG : ignore_checksum_big_file_from_pipe: Size of src and dst objects identical --- PASS: TestRcat (23.09s) --- PASS: TestRcat/withChecksum=false,ignoreChecksum=false (5.75s) --- PASS: TestRcat/withChecksum=true,ignoreChecksum=false (5.84s) --- PASS: TestRcat/withChecksum=false,ignoreChecksum=true (5.84s) --- PASS: TestRcat/withChecksum=true,ignoreChecksum=true (5.66s) === RUN TestRcatMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" === RUN TestRcatMetadata/Normal 2025/01/30 04:19:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (48 bytes), uploading instead of streaming 2025/01/30 04:19:54 DEBUG : rcat_metadata: md5 = 4dc9d9b1d86ae1c3a70f64719ec70609 OK 2025/01/30 04:19:54 DEBUG : rcat_metadata: Size of src and dst objects identical === RUN TestRcatMetadata/ViaDisk 2025/01/30 04:19:56 DEBUG : rijssoobhbn85c5p1imhg55m6frank1nlplla6hkdjlqmqb2471g: Sending chunk 0 length 111 2025/01/30 04:19:57 DEBUG : rcat_metadata_uploadcutoff0: md5 = 28337f33937378dc4457d3a7a96ec306 OK 2025/01/30 04:19:57 DEBUG : rcat_metadata_uploadcutoff0: Size of src and dst objects identical --- PASS: TestRcatMetadata (6.60s) --- PASS: TestRcatMetadata/Normal (2.90s) --- PASS: TestRcatMetadata/ViaDisk (3.26s) === RUN TestRcatSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:00 DEBUG : potato1: md5 = 4254cc23e6ba066beec40558fb02cefe OK 2025/01/30 04:20:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (60 bytes), uploading instead of streaming 2025/01/30 04:20:02 DEBUG : potato2: md5 = 3f4cf81d3cd8cfc35579ced12b2f48cc OK 2025/01/30 04:20:02 DEBUG : potato2: Size of src and dst objects identical --- PASS: TestRcatSize (5.54s) === RUN TestRcatSizeMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:06 DEBUG : potato1: md5 = 81901b87c28907390b7d5f57f0db0a0d OK 2025/01/30 04:20:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': File to upload is small (60 bytes), uploading instead of streaming 2025/01/30 04:20:08 DEBUG : potato2: md5 = 08186f9ba77c55fde59a8a34f598fa25 OK 2025/01/30 04:20:08 DEBUG : potato2: Size of src and dst objects identical --- PASS: TestRcatSizeMetadata (6.37s) === RUN TestTouchDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:12 DEBUG : potato2: md5 = 86cc70976d28194faad90c2941351fe6 OK 2025/01/30 04:20:14 DEBUG : empty space: md5 = 4ee418ef9089cc35a76852eadb609b1e OK 2025/01/30 04:20:16 DEBUG : sub dir/potato3: md5 = 75e1f0a1cbcd9e7e493131939c8470f0 OK 2025/01/30 04:20:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Touching "empty space" 2025/01/30 04:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Touching "potato2" 2025/01/30 04:20:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Touching "sub dir/potato3" 2025/01/30 04:20:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "9atai6og4mljg3r5gjeh27k0q8" --- PASS: TestTouchDir (12.90s) === RUN TestMkdirMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:23 DEBUG : dir with metadata: Making directory with metadata 2025/01/30 04:20:24 INFO : dir with metadata: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) --- PASS: TestMkdirMetadata (2.75s) === RUN TestMkdirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:26 DEBUG : directory with modtime: Making directory with metadata 2025/01/30 04:20:27 INFO : directory with modtime: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) --- PASS: TestMkdirModTime (2.88s) === RUN TestCopyDirMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:29 DEBUG : dir with metadata to be copied: Making directory with metadata 2025/01/30 04:20:29 INFO : dir with metadata to be copied: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/30 04:20:29 DEBUG : Google drive root 'crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0': Skipping btime metadata as can't update it on an existing file: 2025-01-30T04:20:29.521146113Z 2025/01/30 04:20:30 INFO : non existent directory: Updated directory metadata 2025/01/30 04:20:33 DEBUG : Google drive root 'crypt/rh08k1qjmhan854qg542rnr32gcgstn8iintaoaapd6t2vo9e7a0': Skipping btime metadata as can't update it on an existing file: 2025-01-30T04:20:29.521146113Z 2025/01/30 04:20:33 INFO : existing directory: Updated directory metadata --- PASS: TestCopyDirMetadata (6.18s) === RUN TestSetDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:35 DEBUG : set modtime on non existent directory: Skipping set directory modification time as --no-update-dir-modtime is set 2025/01/30 04:20:37 INFO : set modtime on existing directory: Set directory modification time (using SetModTime) 2025/01/30 04:20:39 INFO : set modtime on existing directory: Set directory modification time (using DirSetModTime) --- PASS: TestSetDirModTime (5.01s) === RUN TestDirsEqual run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:40 DEBUG : dir with metadata to be copied: Making directory with metadata 2025/01/30 04:20:40 INFO : dir with metadata to be copied: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/30 04:20:40 DEBUG : dst: Making directory with metadata 2025/01/30 04:20:41 INFO : dst: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/30 04:20:41 DEBUG : dst: Directory modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/30 04:20:42 INFO : dst: Set directory modification time (using SetModTime) 2025/01/30 04:20:43 INFO : dst: Set directory modification time (using SetModTime) 2025/01/30 04:20:43 DEBUG : dst: Directory modification time the same (differ by 1ns, within tolerance 1ms) 2025/01/30 04:20:43 INFO : dst: Set directory modification time (using SetModTime) 2025/01/30 04:20:43 DEBUG : dst: Destination directory is newer than source, skipping --- PASS: TestDirsEqual (4.53s) === RUN TestRemoveExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe'", Local "Local file system at /tmp/rclone259371107", Modify Window "1ms" 2025/01/30 04:20:47 DEBUG : sub dir/test remove existing: md5 = 37effecdae814af9837b140d3689d3db OK 2025/01/30 04:20:49 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: md5 = ce87e6dcb68a1a463692c51ea9a20115 OK 2025/01/30 04:20:51 DEBUG : sub dir/test remove existing: TEST: renaming existing object to "sub dir/test remove existing.tedemix1" before starting 2025/01/30 04:20:52 DEBUG : sub dir/test remove existing.tedemix1: TEST: removing renamed existing file after operation 2025/01/30 04:20:54 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.miximav4" before starting 2025/01/30 04:20:55 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.miximav4: TEST: renaming existing back after failed operation 2025/01/30 04:20:56 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.peliror9" before starting 2025/01/30 04:20:57 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.peliror9: TEST: removing renamed existing file after operation 2025/01/30 04:20:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "bv2s7u9d7optk4ilioigerq0124ndch8obaj1pf55aja8rp23c4g" 2025/01/30 04:20:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "24pu2gokmg18s8635fdbpp5th2m3el7df741p1ckl4e2klt2tsoerl6nqmtcekq3negq5qpe75a6j24aloovvi6rnhbhs7rkdq52s3bmfli263fhr925nfbkk960nacukdokcqpums5j5hb2rj8ap9sghdliftsj6kjuq6132bie4nisfiog" --- PASS: TestRemoveExisting (15.32s) === RUN TestRcAbout rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcAbout (0.00s) === RUN TestRcCleanup rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcCleanup (0.00s) === RUN TestRcCopyfile rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcCopyfile (0.00s) === RUN TestRcCopyurl rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcCopyurl (0.00s) === RUN TestRcDelete rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcDelete (0.00s) === RUN TestRcDeletefile rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcDeletefile (0.00s) === RUN TestRcList rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcList (0.00s) === RUN TestRcStat rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcStat (0.00s) === RUN TestRcSetTier rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcSetTier (0.00s) === RUN TestRcSetTierFile rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcSetTierFile (0.00s) === RUN TestRcMkdir rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcMkdir (0.00s) === RUN TestRcMovefile rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcMovefile (0.00s) === RUN TestRcPurge rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcPurge (0.00s) === RUN TestRcRmdir rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcRmdir (0.00s) === RUN TestRcRmdirs rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcRmdirs (0.00s) === RUN TestRcSize rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcSize (0.00s) === RUN TestRcPublicLink rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcPublicLink (0.00s) === RUN TestRcFsInfo rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcFsInfo (0.00s) === RUN TestUploadFile rc_test.go:30: Skipping test on non local remote --- SKIP: TestUploadFile (0.00s) === RUN TestRcCommand rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcCommand (0.00s) === RUN TestRcDu rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcDu (0.00s) === RUN TestRcCheck rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcCheck (0.00s) === RUN TestRcHashsum rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcHashsum (0.00s) === RUN TestRcHashsumFile rc_test.go:30: Skipping test on non local remote --- SKIP: TestRcHashsumFile (0.00s) PASS 2025/01/30 04:21:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wozacuf0poqe': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 12m21.083382565s (try 1/5)