"./operations.test -test.v -test.timeout 2h0m0s -remote TestDrime: -verbose" - Starting (try 1/5) 2026/04/21 01:08:14 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese" 2026/04/21 01:08:14 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:08:15 DEBUG : Creating backend with remote "/tmp/rclone4177392965" === 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:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" === RUN TestMultithreadCopy/upload=false,size=10485759,streams=2 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: write buffer set to 131072 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10.000Mi 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: Starting multi-thread copy with 1 chunks of size 10.000Mi with 1 parallel streams 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk 1/1 (0-10485759) size 10.000Mi starting 2026/04/21 01:08:19 DEBUG : test-multithread-copy-false-10485759-2: writing chunk 0 2026/04/21 01:08:20 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk 1/1 (0-10485759) size 10.000Mi finished 2026/04/21 01:08:20 DEBUG : test-multithread-copy-false-10485759-2: Finished multi-thread copy with 1 parts of size 10.000Mi === RUN TestMultithreadCopy/upload=false,size=10485760,streams=2 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: write buffer set to 131072 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10Mi 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: Starting multi-thread copy with 1 chunks of size 10Mi with 1 parallel streams 2026/04/21 01:08:23 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: chunk 1/1 (0-10485760) size 10Mi starting 2026/04/21 01:08:24 DEBUG : test-multithread-copy-false-10485760-2: writing chunk 0 2026/04/21 01:08:24 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: chunk 1/1 (0-10485760) size 10Mi finished 2026/04/21 01:08:24 DEBUG : test-multithread-copy-false-10485760-2: Finished multi-thread copy with 1 parts of size 10Mi === RUN TestMultithreadCopy/upload=false,size=10485761,streams=2 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: write buffer set to 131072 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10.000Mi 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: Starting multi-thread copy with 1 chunks of size 10.000Mi with 1 parallel streams 2026/04/21 01:08:27 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: chunk 1/1 (0-10485761) size 10.000Mi starting 2026/04/21 01:08:28 DEBUG : test-multithread-copy-false-10485761-2: writing chunk 0 2026/04/21 01:08:28 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: chunk 1/1 (0-10485761) size 10.000Mi finished 2026/04/21 01:08:28 DEBUG : test-multithread-copy-false-10485761-2: Finished multi-thread copy with 1 parts of size 10.000Mi === RUN TestMultithreadCopy/upload=true,size=10485759,streams=2 2026/04/21 01:08:30 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: disabling buffering because source is local disk 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: number of streams 4 was bigger than number of chunks 2 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: Starting multi-thread copy with 2 chunks of size 5Mi with 2 parallel streams 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 2/2 (5242880-10485759) size 5.000Mi starting 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi starting 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 2/2 (5242880-10485759) size 5.000Mi finished 2026/04/21 01:08:31 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi finished 2026/04/21 01:08:33 DEBUG : test-multithread-copy-true-10485759-2: Finished multi-thread copy with 2 parts of size 5Mi === RUN TestMultithreadCopy/upload=true,size=10485760,streams=2 2026/04/21 01:08:34 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: disabling buffering because source is local disk 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: number of streams 4 was bigger than number of chunks 2 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: Starting multi-thread copy with 2 chunks of size 5Mi with 2 parallel streams 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 2/2 (5242880-10485760) size 5Mi starting 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi starting 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 2/2 (5242880-10485760) size 5Mi finished 2026/04/21 01:08:35 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi finished 2026/04/21 01:08:36 DEBUG : test-multithread-copy-true-10485760-2: Finished multi-thread copy with 2 parts of size 5Mi === RUN TestMultithreadCopy/upload=true,size=10485761,streams=2 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: disabling buffering because source is local disk 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: number of streams 4 was bigger than number of chunks 3 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: Starting multi-thread copy with 3 chunks of size 5Mi with 3 parallel streams 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 starting 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi starting 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi starting 2026/04/21 01:08:38 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 finished 2026/04/21 01:08:39 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi finished 2026/04/21 01:08:39 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi finished 2026/04/21 01:08:40 DEBUG : test-multithread-copy-true-10485761-2: Finished multi-thread copy with 3 parts of size 5Mi --- PASS: TestMultithreadCopy (26.37s) --- PASS: TestMultithreadCopy/upload=false,size=10485759,streams=2 (4.70s) --- PASS: TestMultithreadCopy/upload=false,size=10485760,streams=2 (4.55s) --- PASS: TestMultithreadCopy/upload=false,size=10485761,streams=2 (4.23s) --- PASS: TestMultithreadCopy/upload=true,size=10485759,streams=2 (3.92s) --- PASS: TestMultithreadCopy/upload=true,size=10485760,streams=2 (3.51s) --- PASS: TestMultithreadCopy/upload=true,size=10485761,streams=2 (3.84s) === RUN TestMultithreadCopyAbort run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/04/21 01:08:51 DEBUG : test-multithread-abort: multi-thread copy: disabling buffering because source is local disk 2026/04/21 01:08:51 DEBUG : test-multithread-abort: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 1 2026/04/21 01:08:51 DEBUG : test-multithread-abort: multi-thread copy: number of streams 4 was bigger than number of chunks 3 2026/04/21 01:08:51 DEBUG : test-multithread-abort: Starting multi-thread copy with 3 chunks of size 5Mi with 3 parallel streams 2026/04/21 01:08:51 DEBUG : test-multithread-abort: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 starting 2026/04/21 01:08:51 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:51 DEBUG : test-multithread-abort: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi starting 2026/04/21 01:08:51 DEBUG : Open with options = [RangeOption(0,5242879)] 2026/04/21 01:08:51 DEBUG : test-multithread-abort: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi starting 2026/04/21 01:08:51 DEBUG : Open with options = [RangeOption(5242880,10485759)] 2026/04/21 01:08:52 DEBUG : test-multithread-abort: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi finished 2026/04/21 01:08:52 DEBUG : test-multithread-abort: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi finished 2026/04/21 01:08:52 DEBUG : Returning error reader 2026/04/21 01:08:52 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:52 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 0/10: BOOM: simulated read failure 2026/04/21 01:08:52 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:53 DEBUG : Returning error reader 2026/04/21 01:08:53 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:53 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 1/10: BOOM: simulated read failure 2026/04/21 01:08:53 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:54 DEBUG : Returning error reader 2026/04/21 01:08:54 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:54 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 2/10: BOOM: simulated read failure 2026/04/21 01:08:54 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:55 DEBUG : Returning error reader 2026/04/21 01:08:55 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:55 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 3/10: BOOM: simulated read failure 2026/04/21 01:08:55 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:56 DEBUG : Returning error reader 2026/04/21 01:08:56 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:56 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 4/10: BOOM: simulated read failure 2026/04/21 01:08:56 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:57 DEBUG : Returning error reader 2026/04/21 01:08:57 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:57 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 5/10: BOOM: simulated read failure 2026/04/21 01:08:57 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:58 DEBUG : Returning error reader 2026/04/21 01:08:58 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:58 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 6/10: BOOM: simulated read failure 2026/04/21 01:08:58 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:08:59 DEBUG : Returning error reader 2026/04/21 01:08:59 DEBUG : BOOM: simulated read failure 2026/04/21 01:08:59 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 7/10: BOOM: simulated read failure 2026/04/21 01:08:59 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:09:00 DEBUG : Returning error reader 2026/04/21 01:09:00 DEBUG : BOOM: simulated read failure 2026/04/21 01:09:00 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 8/10: BOOM: simulated read failure 2026/04/21 01:09:00 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:09:01 DEBUG : Returning error reader 2026/04/21 01:09:01 DEBUG : BOOM: simulated read failure 2026/04/21 01:09:01 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 9/10: BOOM: simulated read failure 2026/04/21 01:09:01 DEBUG : Open with options = [RangeOption(10485760,10485760)] 2026/04/21 01:09:02 DEBUG : Returning error reader 2026/04/21 01:09:02 DEBUG : BOOM: simulated read failure 2026/04/21 01:09:02 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 10/10: BOOM: simulated read failure 2026/04/21 01:09:02 DEBUG : test-multithread-abort: Reopen failed after offset 0 bytes read: failed to reopen: too many retries 2026/04/21 01:09:02 DEBUG : test-multithread-abort: multi-thread copy: chunk 3/3 failed: multi-thread copy: failed to write chunk: failed to upload part 3: Put "https://18b804eaa6bc9759e2278f8d5367f42f.r2.cloudflarestorage.com/drimestorage/uploads/d4543e2d-c124-46a9-a966-3db1a90f510b/d4543e2d-c124-46a9-a966-3db1a90f510b?uploadId=AIuy4q02CRxwEOC1_qFAYa9HuZXLh8I3SM29Dh5A4c6O1OEI1c6wUMist1VgsEBPgNqcYJqyb5mXabmdX5aG1SJRaxVrH19-yqsv2piRFDoGY549GR1d5pJRVUmRmpZgL0osDOfHA6qJWiOZmgN1EExpzPtpatwhvzvhS1EYzJCtxHMkdUVowi__ehsqhFPMALnELy-o8D31BBw54YESsC1Oh787zd-lnJmSp7_UZ3TF_FRB0sHVImXNpxRMW21zjqVDj7JIzOgVC1JLLjP6k1rTnens3PhSrhlSFiXnYHRMBDW3FR1lgAajEeDXr4IJWScZQro1e8Poa-FWecuLAYo&partNumber=3&X-Amz-Content-Sha256=UNSIGNED-PAYLOAD&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=6a6ba1504e777c9aad0cd55f765be59c%2F20260421%2Fauto%2Fs3%2Faws4_request&X-Amz-Date=20260421T010852Z&X-Amz-SignedHeaders=host&X-Amz-Expires=86400&X-Amz-Signature=bc06082408b9b1a3611cceeb214269670bf29f1564bc0e10cb2f09b01b702faa": BOOM: simulated read failure 2026/04/21 01:09:02 DEBUG : test-multithread-abort: multi-thread copy: cancelling transfer on exit run.go:130: removing file "test-multithread-abort" failed - try 1/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "test-multithread-abort" failed - try 2/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "test-multithread-abort" failed - try 3/3: failed to delete item: Error "The selected entry ids is invalid." run.go:133: removing file "test-multithread-abort" failed: failed to delete item: Error "The selected entry ids is invalid." --- PASS: TestMultithreadCopyAbort (26.12s) === RUN TestSizeDiffers 2026/04/21 01:09:07 DEBUG : a: size = 0 OK 2026/04/21 01:09:07 DEBUG : a: size = 1 (memory) 2026/04/21 01:09:07 DEBUG : a: size = 2 (memory) --- PASS: TestSizeDiffers (0.00s) === RUN TestReOpen === RUN TestReOpen/Normal === RUN TestReOpen/Normal/Basics 2026/04/21 01:09:07 DEBUG : potato: Seek from 10 to 0 === RUN TestReOpen/Normal/ErrorAtStart === RUN TestReOpen/Normal/WithErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/Normal/TooManyErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/Normal/ReadAt 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 1 === RUN TestReOpen/Normal/Seek 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 2 === RUN TestReOpen/Normal/AccountRead === RUN TestReOpen/Normal/AccountReadDelay 2026/04/21 01:09:07 DEBUG : potato: Seek from 10 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 10 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 10 to 0 === RUN TestReOpen/Normal/AccountReadError === RUN TestReOpen/WithRangeOption === RUN TestReOpen/WithRangeOption/Basics 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 0 === RUN TestReOpen/WithRangeOption/ErrorAtStart === RUN TestReOpen/WithRangeOption/WithErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/WithRangeOption/TooManyErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/WithRangeOption/ReadAt 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 1 === RUN TestReOpen/WithRangeOption/Seek 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 2 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 4 === RUN TestReOpen/WithRangeOption/AccountRead === RUN TestReOpen/WithRangeOption/AccountReadDelay 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 0 === RUN TestReOpen/WithRangeOption/AccountReadError === RUN TestReOpen/WithSeekOption === RUN TestReOpen/WithSeekOption/Basics 2026/04/21 01:09:07 DEBUG : potato: Seek from 8 to 0 === RUN TestReOpen/WithSeekOption/ErrorAtStart === RUN TestReOpen/WithSeekOption/WithErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/WithSeekOption/TooManyErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/WithSeekOption/ReadAt 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 1 === RUN TestReOpen/WithSeekOption/Seek 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 2 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 5 === RUN TestReOpen/WithSeekOption/AccountRead === RUN TestReOpen/WithSeekOption/AccountReadDelay 2026/04/21 01:09:07 DEBUG : potato: Seek from 8 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 8 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 8 to 0 === RUN TestReOpen/WithSeekOption/AccountReadError === RUN TestReOpen/UnknownSize === RUN TestReOpen/UnknownSize/Basics 2026/04/21 01:09:07 DEBUG : potato: Seek from 9 to 0 === RUN TestReOpen/UnknownSize/ErrorAtStart === RUN TestReOpen/UnknownSize/WithErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error === RUN TestReOpen/UnknownSize/TooManyErrors 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error 2026/04/21 01:09:07 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries === RUN TestReOpen/UnknownSize/ReadAt 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 1 === RUN TestReOpen/UnknownSize/Seek 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error 2026/04/21 01:09:07 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error 2026/04/21 01:09:07 DEBUG : potato: Seek from 5 to 2 2026/04/21 01:09:07 DEBUG : potato: Seek from 7 to 6 === RUN TestReOpen/UnknownSize/AccountRead === RUN TestReOpen/UnknownSize/AccountReadDelay 2026/04/21 01:09:07 DEBUG : potato: Seek from 9 to 0 2026/04/21 01:09:07 DEBUG : potato: Seek from 9 to 0 2026/04/21 01:09:07 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/ReadAt (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/ReadAt (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/ReadAt (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/ReadAt (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:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure === RUN TestCheck/1 === RUN TestCheck/2 === RUN TestCheck/3 === RUN TestCheck/4 === RUN TestCheck/5 === RUN TestCheck/6 === RUN TestCheck/7 --- PASS: TestCheck (14.06s) --- PASS: TestCheck/1 (0.22s) --- PASS: TestCheck/2 (0.19s) --- PASS: TestCheck/3 (0.20s) --- PASS: TestCheck/4 (0.19s) --- PASS: TestCheck/5 (0.20s) --- PASS: TestCheck/6 (0.26s) --- PASS: TestCheck/7 (0.20s) === RUN TestCheckFsError 2026/04/21 01:09:21 DEBUG : Creating backend with remote "nonexistent" 2026/04/21 01:09:21 DEBUG : Creating backend with remote "nonexistent" 2026/04/21 01:09:21 DEBUG : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: Waiting for checks to finish 2026/04/21 01:09:21 ERROR : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: error reading source root directory: directory not found 2026/04/21 01:09:21 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: 0 differences found 2026/04/21 01:09:21 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:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 === NAME TestCheckDownload fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure === RUN TestCheckDownload/3 === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 === NAME TestCheckDownload fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 --- PASS: TestCheckDownload (31.78s) --- PASS: TestCheckDownload/1 (0.58s) --- PASS: TestCheckDownload/2 (0.53s) --- PASS: TestCheckDownload/3 (0.55s) --- PASS: TestCheckDownload/4 (0.62s) --- PASS: TestCheckDownload/5 (0.58s) --- PASS: TestCheckDownload/6 (0.63s) --- PASS: TestCheckDownload/7 (0.58s) === RUN TestCheckSizeOnly run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 === RUN TestCheckSizeOnly/3 === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (14.31s) --- PASS: TestCheckSizeOnly/1 (0.23s) --- PASS: TestCheckSizeOnly/2 (0.21s) --- PASS: TestCheckSizeOnly/3 (0.26s) --- PASS: TestCheckSizeOnly/4 (0.19s) --- PASS: TestCheckSizeOnly/5 (0.21s) --- PASS: TestCheckSizeOnly/6 (0.20s) --- PASS: TestCheckSizeOnly/7 (0.19s) === RUN TestCheckEqualReaders --- PASS: TestCheckEqualReaders (0.00s) === RUN TestParseSumFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:542: Sleeping for 1s for findObject eventual consistency: 1/3 (object not found) 2026/04/21 01:10:10 NOTICE: test.sum: improperly formatted checksum line 4 2026/04/21 01:10:10 NOTICE: test.sum: improperly formatted checksum line 5 2026/04/21 01:10:10 NOTICE: test.sum: improperly formatted checksum line 6 2026/04/21 01:10:10 NOTICE: test.sum: 2 warning(s) suppressed... 2026/04/21 01:10:11 DEBUG : test.sum: Removing old object on successful upload run.go:290: Failed to put "test.sum" to "drime root 'rclone-test-yojoqaj4hese'": failed to delete existing object: failed to delete item: Error "The selected entry ids is invalid." fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- FAIL: TestParseSumFile (11.59s) === RUN TestCheckSum run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:10:19 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/data" check_test.go:350: drime root 'rclone-test-yojoqaj4hese/data' lacks md5, skipping --- SKIP: TestCheckSum (1.51s) === RUN TestCheckSumDownload run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:10:21 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/data" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure === RUN TestCheckSumDownload/subtest1 2026/04/21 01:10:35 DEBUG : test.sum: Removing old object on successful upload === NAME TestCheckSumDownload run.go:290: Failed to put "test.sum" to "drime root 'rclone-test-yojoqaj4hese'": failed to delete existing object: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "test.sum" failed - try 1/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "test.sum" failed - try 2/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "test.sum" failed - try 3/3: failed to delete item: Error "The selected entry ids is invalid." run.go:133: removing file "test.sum" failed: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing dir "data" failed - try 1/3: directory not empty fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:178 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:393 /usr/local/go/src/testing/testing.go:1317 /usr/local/go/src/testing/testing.go:1667 /usr/local/go/src/testing/testing.go:2030 /usr/local/go/src/runtime/panic.go:694 /usr/local/go/src/testing/testing.go:1022 /usr/local/go/src/testing/testing.go:1228 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:290 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:297 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:368 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:447 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541 Error: Should be true Test: TestCheckSumDownload Messages: listing wrong, want got test.sum (41) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:178 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:393 /usr/local/go/src/testing/testing.go:1317 /usr/local/go/src/testing/testing.go:1667 /usr/local/go/src/testing/testing.go:2030 /usr/local/go/src/runtime/panic.go:694 /usr/local/go/src/testing/testing.go:1022 /usr/local/go/src/testing/testing.go:1228 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:290 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:297 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:368 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:447 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestCheckSumDownload Messages: Unexpected file "test.sum" --- FAIL: TestCheckSumDownload (28.61s) --- PASS: TestCheckSumDownload/subtest1 (1.46s) === RUN TestApplyTransforms 2026/04/21 01:10:49 DEBUG : Creating backend with remote "TestDrime:rclone-test-raqocun0rudu" 2026/04/21 01:10:49 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:10:50 DEBUG : Creating backend with remote "/tmp/rclone1288846584" run.go:185: Remote "drime root 'rclone-test-raqocun0rudu'", Local "Local file system at /tmp/rclone1288846584", Modify Window "876000h0m0s" upper checkfile vs. lower remote (without normalization) 2026/04/21 01:10:51 ERROR : HELLO, WORLD!: file not in drime root 'rclone-test-raqocun0rudu' 2026/04/21 01:10:51 NOTICE: drime root 'rclone-test-raqocun0rudu': 1 files missing 2026/04/21 01:10:51 NOTICE: drime root 'rclone-test-raqocun0rudu': 0 differences found 2026/04/21 01:10:51 NOTICE: drime root 'rclone-test-raqocun0rudu': 1 errors while checking upper checkfile vs. lower remote (with normalization) 2026/04/21 01:10:52 DEBUG : hello, world!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:10:52 NOTICE: drime root 'rclone-test-raqocun0rudu': 0 differences found 2026/04/21 01:10:52 NOTICE: drime root 'rclone-test-raqocun0rudu': 1 matching files 2026/04/21 01:10:52 DEBUG : Creating backend with remote "TestDrime:rclone-test-tixuvaj8xako" 2026/04/21 01:10:52 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:10:53 DEBUG : Creating backend with remote "/tmp/rclone3615728792" run.go:185: Remote "drime root 'rclone-test-tixuvaj8xako'", Local "Local file system at /tmp/rclone3615728792", Modify Window "876000h0m0s" lower checkfile vs. upper remote (without normalization) 2026/04/21 01:10:54 ERROR : hello, world!: file not in drime root 'rclone-test-tixuvaj8xako' 2026/04/21 01:10:54 NOTICE: drime root 'rclone-test-tixuvaj8xako': 1 files missing 2026/04/21 01:10:54 NOTICE: drime root 'rclone-test-tixuvaj8xako': 0 differences found 2026/04/21 01:10:54 NOTICE: drime root 'rclone-test-tixuvaj8xako': 1 errors while checking lower checkfile vs. upper remote (with normalization) 2026/04/21 01:10:55 DEBUG : HELLO, WORLD!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:10:55 NOTICE: drime root 'rclone-test-tixuvaj8xako': 0 differences found 2026/04/21 01:10:55 NOTICE: drime root 'rclone-test-tixuvaj8xako': 1 matching files 2026/04/21 01:10:55 DEBUG : Creating backend with remote "TestDrime:rclone-test-wumaney6zale" 2026/04/21 01:10:55 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:10:55 DEBUG : Creating backend with remote "/tmp/rclone2997560565" run.go:185: Remote "drime root 'rclone-test-wumaney6zale'", Local "Local file system at /tmp/rclone2997560565", Modify Window "876000h0m0s" lower checkfile vs. upperlowermixed remote (without normalization) 2026/04/21 01:10:57 ERROR : hello, world!: file not in drime root 'rclone-test-wumaney6zale' 2026/04/21 01:10:57 NOTICE: drime root 'rclone-test-wumaney6zale': 1 files missing 2026/04/21 01:10:57 NOTICE: drime root 'rclone-test-wumaney6zale': 0 differences found 2026/04/21 01:10:57 NOTICE: drime root 'rclone-test-wumaney6zale': 1 errors while checking lower checkfile vs. upperlowermixed remote (with normalization) 2026/04/21 01:10:58 DEBUG : HeLlO, wOrLd!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:10:58 NOTICE: drime root 'rclone-test-wumaney6zale': 0 differences found 2026/04/21 01:10:58 NOTICE: drime root 'rclone-test-wumaney6zale': 1 matching files 2026/04/21 01:10:58 DEBUG : Creating backend with remote "TestDrime:rclone-test-vayudes7tini" 2026/04/21 01:10:58 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:10:58 DEBUG : Creating backend with remote "/tmp/rclone786892757" run.go:185: Remote "drime root 'rclone-test-vayudes7tini'", Local "Local file system at /tmp/rclone786892757", Modify Window "876000h0m0s" upperlowermixed checkfile vs. upper remote (without normalization) 2026/04/21 01:11:00 ERROR : HeLlO, wOrLd!: file not in drime root 'rclone-test-vayudes7tini' 2026/04/21 01:11:00 NOTICE: drime root 'rclone-test-vayudes7tini': 1 files missing 2026/04/21 01:11:00 NOTICE: drime root 'rclone-test-vayudes7tini': 0 differences found 2026/04/21 01:11:00 NOTICE: drime root 'rclone-test-vayudes7tini': 1 errors while checking upperlowermixed checkfile vs. upper remote (with normalization) 2026/04/21 01:11:00 DEBUG : HELLO, WORLD!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:00 NOTICE: drime root 'rclone-test-vayudes7tini': 0 differences found 2026/04/21 01:11:00 NOTICE: drime root 'rclone-test-vayudes7tini': 1 matching files 2026/04/21 01:11:00 DEBUG : Creating backend with remote "TestDrime:rclone-test-tuqoqil8lunu" 2026/04/21 01:11:00 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:11:01 DEBUG : Creating backend with remote "/tmp/rclone1625950706" run.go:185: Remote "drime root 'rclone-test-tuqoqil8lunu'", Local "Local file system at /tmp/rclone1625950706", Modify Window "876000h0m0s" NFD checkfile vs. NFC remote (without normalization) 2026/04/21 01:11:03 ERROR : 測試_Русский___ě_áñ: file not in drime root 'rclone-test-tuqoqil8lunu' 2026/04/21 01:11:03 NOTICE: drime root 'rclone-test-tuqoqil8lunu': 1 files missing 2026/04/21 01:11:03 NOTICE: drime root 'rclone-test-tuqoqil8lunu': 0 differences found 2026/04/21 01:11:03 NOTICE: drime root 'rclone-test-tuqoqil8lunu': 1 errors while checking NFD checkfile vs. NFC remote (with normalization) 2026/04/21 01:11:03 DEBUG : 測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:03 NOTICE: drime root 'rclone-test-tuqoqil8lunu': 0 differences found 2026/04/21 01:11:03 NOTICE: drime root 'rclone-test-tuqoqil8lunu': 1 matching files 2026/04/21 01:11:03 DEBUG : Creating backend with remote "TestDrime:rclone-test-rumuzek7zeka" 2026/04/21 01:11:03 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:11:04 DEBUG : Creating backend with remote "/tmp/rclone1526915554" run.go:185: Remote "drime root 'rclone-test-rumuzek7zeka'", Local "Local file system at /tmp/rclone1526915554", Modify Window "876000h0m0s" NFC checkfile vs. NFD remote (without normalization) 2026/04/21 01:11:06 ERROR : 測試_Русский___ě_áñ: file not in drime root 'rclone-test-rumuzek7zeka' 2026/04/21 01:11:06 NOTICE: drime root 'rclone-test-rumuzek7zeka': 1 files missing 2026/04/21 01:11:06 NOTICE: drime root 'rclone-test-rumuzek7zeka': 0 differences found 2026/04/21 01:11:06 NOTICE: drime root 'rclone-test-rumuzek7zeka': 1 errors while checking NFC checkfile vs. NFD remote (with normalization) 2026/04/21 01:11:06 DEBUG : 測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:06 NOTICE: drime root 'rclone-test-rumuzek7zeka': 0 differences found 2026/04/21 01:11:06 NOTICE: drime root 'rclone-test-rumuzek7zeka': 1 matching files 2026/04/21 01:11:06 DEBUG : Creating backend with remote "TestDrime:rclone-test-bapoqay2wagi" 2026/04/21 01:11:06 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:11:07 DEBUG : Creating backend with remote "/tmp/rclone3017947205" run.go:185: Remote "drime root 'rclone-test-bapoqay2wagi'", Local "Local file system at /tmp/rclone3017947205", Modify Window "876000h0m0s" NFDx2 checkfile vs. both remote (without normalization) 2026/04/21 01:11:08 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-bapoqay2wagi' 2026/04/21 01:11:08 NOTICE: drime root 'rclone-test-bapoqay2wagi': 1 files missing 2026/04/21 01:11:08 NOTICE: drime root 'rclone-test-bapoqay2wagi': 0 differences found 2026/04/21 01:11:08 NOTICE: drime root 'rclone-test-bapoqay2wagi': 1 errors while checking NFDx2 checkfile vs. both remote (with normalization) 2026/04/21 01:11:09 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:09 NOTICE: drime root 'rclone-test-bapoqay2wagi': 0 differences found 2026/04/21 01:11:09 NOTICE: drime root 'rclone-test-bapoqay2wagi': 1 matching files 2026/04/21 01:11:09 DEBUG : Creating backend with remote "TestDrime:rclone-test-ciwajog8beho" 2026/04/21 01:11:09 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:11:10 DEBUG : Creating backend with remote "/tmp/rclone3626292776" run.go:185: Remote "drime root 'rclone-test-ciwajog8beho'", Local "Local file system at /tmp/rclone3626292776", Modify Window "876000h0m0s" NFCx2 checkfile vs. both remote (without normalization) 2026/04/21 01:11:11 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-ciwajog8beho' 2026/04/21 01:11:11 NOTICE: drime root 'rclone-test-ciwajog8beho': 1 files missing 2026/04/21 01:11:11 NOTICE: drime root 'rclone-test-ciwajog8beho': 0 differences found 2026/04/21 01:11:11 NOTICE: drime root 'rclone-test-ciwajog8beho': 1 errors while checking NFCx2 checkfile vs. both remote (with normalization) 2026/04/21 01:11:12 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:12 NOTICE: drime root 'rclone-test-ciwajog8beho': 0 differences found 2026/04/21 01:11:12 NOTICE: drime root 'rclone-test-ciwajog8beho': 1 matching files 2026/04/21 01:11:12 DEBUG : Creating backend with remote "TestDrime:rclone-test-jijalof4heyi" 2026/04/21 01:11:12 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:11:12 DEBUG : Creating backend with remote "/tmp/rclone3595186919" run.go:185: Remote "drime root 'rclone-test-jijalof4heyi'", Local "Local file system at /tmp/rclone3595186919", Modify Window "876000h0m0s" both checkfile vs. NFDx2 remote (without normalization) 2026/04/21 01:11:14 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-jijalof4heyi' 2026/04/21 01:11:14 NOTICE: drime root 'rclone-test-jijalof4heyi': 1 files missing 2026/04/21 01:11:14 NOTICE: drime root 'rclone-test-jijalof4heyi': 0 differences found 2026/04/21 01:11:14 NOTICE: drime root 'rclone-test-jijalof4heyi': 1 errors while checking both checkfile vs. NFDx2 remote (with normalization) 2026/04/21 01:11:15 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:15 NOTICE: drime root 'rclone-test-jijalof4heyi': 0 differences found 2026/04/21 01:11:15 NOTICE: drime root 'rclone-test-jijalof4heyi': 1 matching files 2026/04/21 01:11:15 DEBUG : Creating backend with remote "TestDrime:rclone-test-havowos9munu" 2026/04/21 01:11:15 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:11:15 DEBUG : Creating backend with remote "/tmp/rclone2385168099" run.go:185: Remote "drime root 'rclone-test-havowos9munu'", Local "Local file system at /tmp/rclone2385168099", Modify Window "876000h0m0s" both checkfile vs. NFCx2 remote (without normalization) 2026/04/21 01:11:17 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-havowos9munu' 2026/04/21 01:11:17 NOTICE: drime root 'rclone-test-havowos9munu': 1 files missing 2026/04/21 01:11:17 NOTICE: drime root 'rclone-test-havowos9munu': 0 differences found 2026/04/21 01:11:17 NOTICE: drime root 'rclone-test-havowos9munu': 1 errors while checking both checkfile vs. NFCx2 remote (with normalization) 2026/04/21 01:11:18 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK 2026/04/21 01:11:18 NOTICE: drime root 'rclone-test-havowos9munu': 0 differences found 2026/04/21 01:11:18 NOTICE: drime root 'rclone-test-havowos9munu': 1 matching files 2026/04/21 01:11:18 DEBUG : drime root 'rclone-test-havowos9munu': Purge remote 2026/04/21 01:11:18 DEBUG : drime root 'rclone-test-jijalof4heyi': Purge remote 2026/04/21 01:11:18 DEBUG : drime root 'rclone-test-ciwajog8beho': Purge remote 2026/04/21 01:11:18 DEBUG : drime root 'rclone-test-bapoqay2wagi': Purge remote 2026/04/21 01:11:18 DEBUG : drime root 'rclone-test-rumuzek7zeka': Purge remote 2026/04/21 01:11:19 DEBUG : drime root 'rclone-test-tuqoqil8lunu': Purge remote 2026/04/21 01:11:19 DEBUG : drime root 'rclone-test-vayudes7tini': Purge remote 2026/04/21 01:11:19 DEBUG : drime root 'rclone-test-wumaney6zale': Purge remote 2026/04/21 01:11:19 DEBUG : drime root 'rclone-test-tixuvaj8xako': Purge remote 2026/04/21 01:11:20 DEBUG : drime root 'rclone-test-raqocun0rudu': Purge remote --- PASS: TestApplyTransforms (30.62s) === RUN TestTruncateString --- PASS: TestTruncateString (0.00s) === RUN TestCopyFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:11:20 DEBUG : file1: Need to transfer - File not found at Destination 2026/04/21 01:11:21 DEBUG : sub/file2: size = 14 OK 2026/04/21 01:11:21 INFO : file1: Copied (new) to: sub/file2 fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:116 Error: Should be true Test: TestCopyFile Messages: listing wrong, want sub/file2 (14) got sub/file2 (14), test.sum (41) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:116 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestCopyFile Messages: Unexpected file "test.sum" 2026/04/21 01:11:31 DEBUG : sub/file2: size = 14 OK 2026/04/21 01:11:31 DEBUG : file1: Sizes identical 2026/04/21 01:11:31 DEBUG : file1: Unchanged skipping fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:121 Error: Should be true Test: TestCopyFile Messages: listing wrong, want sub/file2 (14) got sub/file2 (14), test.sum (41) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:121 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestCopyFile Messages: Unexpected file "test.sum" 2026/04/21 01:11:40 DEBUG : drime root 'rclone-test-yojoqaj4hese': don't need to copy/move sub/file2, it is already at target location fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:126 Error: Should be true Test: TestCopyFile Messages: listing wrong, want sub/file2 (14) got sub/file2 (14), test.sum (41) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:126 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestCopyFile Messages: Unexpected file "test.sum" run.go:130: removing dir "sub" failed - try 1/3: directory not empty --- FAIL: TestCopyFile (32.08s) === RUN TestCopyLongFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" copy_test.go:154: Test only runs on local --- SKIP: TestCopyLongFile (0.39s) === RUN TestCopyFileBackupDir run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:11:54 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/backup" 2026/04/21 01:11:55 DEBUG : dst/file1: size = 14 (Local file system at /tmp/rclone4177392965) 2026/04/21 01:11:55 DEBUG : dst/file1: size = 18 (drime root 'rclone-test-yojoqaj4hese') 2026/04/21 01:11:55 DEBUG : dst/file1: Sizes differ 2026/04/21 01:11:57 INFO : dst/file1: Moved (server-side) 2026/04/21 01:11:58 DEBUG : dst/file1: size = 14 OK 2026/04/21 01:11:58 INFO : dst/file1: Copied (new) fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure run.go:130: removing dir "dst" failed - try 1/3: directory not empty --- PASS: TestCopyFileBackupDir (18.06s) === RUN TestCopyFileCompareDest run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:12:10 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/dst" 2026/04/21 01:12:11 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/CompareDest" 2026/04/21 01:12:12 DEBUG : one: Need to transfer - File not found at Destination 2026/04/21 01:12:14 DEBUG : one: size = 3 OK 2026/04/21 01:12:14 INFO : one: Copied (new) 2026/04/21 01:12:15 DEBUG : one: size = 5 (Local file system at /tmp/rclone4177392965) 2026/04/21 01:12:15 DEBUG : one: size = 3 (drime root 'rclone-test-yojoqaj4hese/dst') 2026/04/21 01:12:15 DEBUG : one: Sizes differ 2026/04/21 01:12:16 DEBUG : one: Removing old object on successful upload 2026/04/21 01:12:16 ERROR : one: Failed to copy: failed to delete existing object: failed to delete item: Error "The selected entry ids is invalid." copy_test.go:220: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:220 Error: Received unexpected error: failed to delete existing object: failed to delete item: Error "The selected entry ids is invalid." Test: TestCopyFileCompareDest run.go:130: removing dir "dst" failed - try 1/3: directory not empty --- FAIL: TestCopyFileCompareDest (8.01s) === RUN TestCopyFileCopyDest run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:12:18 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/dst" 2026/04/21 01:12:19 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/CopyDest" 2026/04/21 01:12:20 DEBUG : one: Need to transfer - File not found at Destination 2026/04/21 01:12:22 DEBUG : one: size = 3 OK 2026/04/21 01:12:22 INFO : one: Copied (new) 2026/04/21 01:12:23 DEBUG : one: size = 5 (Local file system at /tmp/rclone4177392965) 2026/04/21 01:12:23 DEBUG : one: size = 3 (drime root 'rclone-test-yojoqaj4hese/dst') 2026/04/21 01:12:23 DEBUG : one: Sizes differ 2026/04/21 01:12:24 DEBUG : one: Removing old object on successful upload 2026/04/21 01:12:24 ERROR : one: Failed to copy: failed to delete existing object: failed to delete item: Error "The selected entry ids is invalid." copy_test.go:303: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:303 Error: Received unexpected error: failed to delete existing object: failed to delete item: Error "The selected entry ids is invalid." Test: TestCopyFileCopyDest run.go:130: removing dir "dst" failed - try 1/3: directory not empty --- FAIL: TestCopyFileCopyDest (7.99s) === RUN TestCopyInplace run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" copy_test.go:371: Partial uploads not supported --- SKIP: TestCopyInplace (0.48s) === RUN TestCopyLongFileName run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" copy_test.go:404: Partial uploads not supported --- SKIP: TestCopyLongFileName (0.47s) === RUN TestCopyLongFileNameCollision run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" copy_test.go:437: Partial uploads not supported --- SKIP: TestCopyLongFileNameCollision (0.44s) === RUN TestCopyFileMaxTransfer run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:12:28 DEBUG : TestCopyFileMaxTransfer/file1: Need to transfer - File not found at Destination 2026/04/21 01:12:29 DEBUG : TestCopyFileMaxTransfer/file1: size = 14 OK 2026/04/21 01:12:29 INFO : TestCopyFileMaxTransfer/file1: Copied (new) 2026/04/21 01:12:30 DEBUG : TestCopyFileMaxTransfer/file2: Need to transfer - File not found at Destination 2026/04/21 01:12:30 ERROR : TestCopyFileMaxTransfer/file2: Failed to copy: failed to upload file: Post "https://app.drime.cloud/api/v1/uploads": failed to copy data: max transfer limit reached as set by --max-transfer 2026/04/21 01:12:30 DEBUG : TestCopyFileMaxTransfer/file3: Need to transfer - File not found at Destination 2026/04/21 01:12:31 DEBUG : TestCopyFileMaxTransfer/file4: Need to transfer - File not found at Destination 2026/04/21 01:12:32 DEBUG : TestCopyFileMaxTransfer/file4: size = 2062 OK 2026/04/21 01:12:32 INFO : TestCopyFileMaxTransfer/file4: Copied (new) --- PASS: TestCopyFileMaxTransfer (6.21s) === RUN TestDeduplicateInteractive run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateInteractive (0.41s) === RUN TestDeduplicateSkip run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateSkip (0.39s) === RUN TestDeduplicateSizeOnly run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateSizeOnly (0.40s) === RUN TestDeduplicateFirst run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateFirst (0.42s) === RUN TestDeduplicateNewest run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateNewest (0.38s) === RUN TestDeduplicateNewestByHash run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:36: Can't run this test without a hash --- SKIP: TestDeduplicateNewestByHash (0.39s) === RUN TestDeduplicateOldest run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateOldest (0.39s) === RUN TestDeduplicateLargest run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateLargest (0.42s) === RUN TestDeduplicateSmallest run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateSmallest (0.40s) === RUN TestDeduplicateRename run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:24: Can't test deduplicate - no duplicate files possible --- SKIP: TestDeduplicateRename (0.43s) === RUN TestMergeDirs run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" dedupe_test.go:256: Can't merge directories --- SKIP: TestMergeDirs (0.39s) === RUN TestListDirSorted run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:12:47 DEBUG : a.txt: Excluded (Size Filter) 2026/04/21 01:12:47 DEBUG : a.txt: Excluded 2026/04/21 01:12:47 DEBUG : sub dir/hello world2: Excluded (Size Filter) 2026/04/21 01:12:47 DEBUG : sub dir/hello world2: Excluded 2026/04/21 01:12:47 DEBUG : sub dir/hello world: Excluded (Size Filter) 2026/04/21 01:12:47 DEBUG : sub dir/hello world: Excluded 2026/04/21 01:12:48 DEBUG : sub dir/ignore dir: Excluded 2026/04/21 01:12:48 DEBUG : sub dir/hello world2: Excluded (Size Filter) 2026/04/21 01:12:48 DEBUG : sub dir/hello world2: Excluded 2026/04/21 01:12:48 DEBUG : sub dir/hello world: Excluded (Size Filter) 2026/04/21 01:12:48 DEBUG : sub dir/hello world: Excluded 2026/04/21 01:12:48 DEBUG : sub dir/ignore dir: Excluded run.go:130: removing dir "sub dir/sub sub dir" failed - try 1/3: directory not empty --- PASS: TestListDirSorted (14.88s) === RUN TestListDirSortedFn run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:13:01 DEBUG : a.txt: Excluded (Size Filter) 2026/04/21 01:13:01 DEBUG : a.txt: Excluded 2026/04/21 01:13:01 DEBUG : sub dir/hello world: Excluded (Size Filter) 2026/04/21 01:13:01 DEBUG : sub dir/hello world: Excluded 2026/04/21 01:13:01 DEBUG : sub dir/hello world2: Excluded (Size Filter) 2026/04/21 01:13:01 DEBUG : sub dir/hello world2: Excluded 2026/04/21 01:13:02 DEBUG : sub dir/ignore dir: Excluded 2026/04/21 01:13:02 DEBUG : sub dir/hello world: Excluded (Size Filter) 2026/04/21 01:13:02 DEBUG : sub dir/hello world: Excluded 2026/04/21 01:13:02 DEBUG : sub dir/hello world2: Excluded (Size Filter) 2026/04/21 01:13:02 DEBUG : sub dir/hello world2: Excluded 2026/04/21 01:13:02 DEBUG : sub dir/ignore dir: Excluded run.go:130: removing dir "sub dir/sub sub dir" failed - try 1/3: directory not empty --- PASS: TestListDirSortedFn (14.49s) === RUN TestListJSON run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" === 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 2026/04/21 01:13:12 ERROR : file1: Failed to read hash: hash type not supported === RUN TestListJSON/Metadata === NAME TestListJSON run.go:130: removing dir "sub" failed - try 1/3: directory not empty --- PASS: TestListJSON (7.43s) --- PASS: TestListJSON/Default (0.19s) --- PASS: TestListJSON/FilesOnly (0.20s) --- PASS: TestListJSON/DirsOnly (0.20s) --- PASS: TestListJSON/Recurse (0.47s) --- PASS: TestListJSON/SubDir (0.19s) --- PASS: TestListJSON/NoModTime (0.20s) --- PASS: TestListJSON/NoMimeType (0.20s) --- PASS: TestListJSON/ShowHash (0.25s) --- PASS: TestListJSON/HashTypes (0.21s) --- PASS: TestListJSON/Metadata (0.25s) === RUN TestStatJSON run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" === 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 2026/04/21 01:13:20 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/notfound" 2026/04/21 01:13:20 DEBUG : Config file has changed externally - reloading === NAME TestStatJSON run.go:130: removing dir "sub" failed - try 1/3: directory not empty --- PASS: TestStatJSON (9.11s) --- PASS: TestStatJSON/Root (0.20s) --- PASS: TestStatJSON/RootFilesOnly (0.00s) --- PASS: TestStatJSON/RootDirsOnly (0.19s) --- PASS: TestStatJSON/Dir (0.45s) --- PASS: TestStatJSON/DirWithTrailingSlash (0.20s) --- PASS: TestStatJSON/File (0.21s) --- PASS: TestStatJSON/NotFound (0.40s) --- PASS: TestStatJSON/DirFilesOnly (0.24s) --- PASS: TestStatJSON/FileFilesOnly (0.20s) --- PASS: TestStatJSON/NotFoundFilesOnly (0.21s) --- PASS: TestStatJSON/DirDirsOnly (0.19s) --- PASS: TestStatJSON/FileDirsOnly (0.19s) --- PASS: TestStatJSON/NotFoundDirsOnly (0.21s) --- PASS: TestStatJSON/RootNotFound (1.19s) === RUN TestMkdir run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:13:24 INFO : drime root 'rclone-test-yojoqaj4hese': Making directory 2026/04/21 01:13:24 INFO : drime root 'rclone-test-yojoqaj4hese': Making directory --- PASS: TestMkdir (0.61s) === RUN TestLsd run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" --- PASS: TestLsd (3.07s) === RUN TestLs run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" --- PASS: TestLs (2.63s) === RUN TestLsWithFilesFrom run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:13:32 DEBUG : empty space: Excluded (FilesFrom Filter) 2026/04/21 01:13:32 DEBUG : empty space: Excluded --- PASS: TestLsWithFilesFrom (3.01s) === RUN TestLsLong run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" --- PASS: TestLsLong (2.65s) === RUN TestHashSums run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestHashSums (9.98s) === RUN TestHashSumsWithErrors 2026/04/21 01:13:46 DEBUG : Creating backend with remote ":memory:" 2026/04/21 01:13:46 ERROR : file1: hash unsupported: hash type not supported --- PASS: TestHashSumsWithErrors (0.00s) === RUN TestHashStream 2026/04/21 01:13:46 DEBUG : Creating md5 hash of 0 bytes read from input stream 2026/04/21 01:13:46 DEBUG : Creating md5 hash of 0 bytes read from input stream 2026/04/21 01:13:46 DEBUG : Creating sha1 hash of 0 bytes read from input stream 2026/04/21 01:13:46 DEBUG : Creating sha1 hash of 0 bytes read from input stream 2026/04/21 01:13:46 DEBUG : Creating md5 hash of 12 bytes read from input stream 2026/04/21 01:13:46 DEBUG : Creating md5 hash of 12 bytes read from input stream 2026/04/21 01:13:46 DEBUG : Creating sha1 hash of 12 bytes read from input stream 2026/04/21 01:13:46 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:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" run.go:130: removing dir "sub dir" failed - try 1/3: directory not empty --- PASS: TestCount (6.34s) === RUN TestDelete run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:13:55 DEBUG : Waiting for deletions to finish 2026/04/21 01:13:55 DEBUG : large: Excluded (Size Filter) 2026/04/21 01:13:55 DEBUG : large: Excluded 2026/04/21 01:13:55 INFO : medium: Deleted 2026/04/21 01:13:55 INFO : small: Deleted fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestDelete (18.75s) === RUN TestMaxDelete run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/04/21 01:14:21 DEBUG : Waiting for deletions to finish 2026/04/21 01:14:21 ERROR : small: Got fatal error on delete: --max-delete threshold reached 2026/04/21 01:14:22 INFO : large: Deleted 2026/04/21 01:14:22 INFO : medium: Deleted operations_test.go:453: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:453 Error: Not equal: expected: 1 actual : 3 Test: TestMaxDelete run.go:130: removing file "large" failed - try 1/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "large" failed - try 2/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "large" failed - try 3/3: failed to delete item: Error "The selected entry ids is invalid." run.go:133: removing file "large" failed: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "medium" failed - try 1/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "medium" failed - try 2/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "medium" failed - try 3/3: failed to delete item: Error "The selected entry ids is invalid." run.go:133: removing file "medium" failed: failed to delete item: Error "The selected entry ids is invalid." --- FAIL: TestMaxDelete (19.04s) === RUN TestMaxDeleteSizeLargeFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:14:33 DEBUG : Waiting for deletions to finish 2026/04/21 01:14:33 ERROR : large: Got fatal error on delete: --max-delete-size threshold reached 2026/04/21 01:14:33 INFO : medium: Deleted 2026/04/21 01:14:33 INFO : small: Deleted fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestMaxDeleteSizeLargeFile (19.17s) === RUN TestMaxDeleteSize run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:14:52 DEBUG : Waiting for deletions to finish 2026/04/21 01:14:52 ERROR : large: Got fatal error on delete: --max-delete-size threshold reached 2026/04/21 01:14:52 INFO : small: Deleted 2026/04/21 01:14:52 INFO : medium: Deleted operations_test.go:492: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:492 Error: Not equal: expected: 1 actual : 3 Test: TestMaxDeleteSize run.go:130: removing file "medium" failed - try 1/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "medium" failed - try 2/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "medium" failed - try 3/3: failed to delete item: Error "The selected entry ids is invalid." run.go:133: removing file "medium" failed: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "small" failed - try 1/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "small" failed - try 2/3: failed to delete item: Error "The selected entry ids is invalid." run.go:130: removing file "small" failed - try 3/3: failed to delete item: Error "The selected entry ids is invalid." run.go:133: removing file "small" failed: failed to delete item: Error "The selected entry ids is invalid." --- FAIL: TestMaxDeleteSize (11.35s) === RUN TestReadFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" --- PASS: TestReadFile (2.73s) === RUN TestRetry 2026/04/21 01:15:04 DEBUG : Received error: Wrapped EOF is retriable: EOF - low level retry 1/5 2026/04/21 01:15:04 DEBUG : Received error: Wrapped EOF is retriable: EOF - low level retry 2/5 2026/04/21 01:15:04 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms 2026/04/21 01:15:04 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms 2026/04/21 01:15:04 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms 2026/04/21 01:15:04 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms 2026/04/21 01:15:04 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms --- PASS: TestRetry (0.05s) === RUN TestCat run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestCat (14.23s) === RUN TestPurge 2026/04/21 01:15:18 DEBUG : Creating backend with remote "TestDrime:rclone-test-wuhoxoc9ruzu" 2026/04/21 01:15:18 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/21 01:15:18 DEBUG : Creating backend with remote "/tmp/rclone15689568" run.go:185: Remote "drime root 'rclone-test-wuhoxoc9ruzu'", Local "Local file system at /tmp/rclone15689568", Modify Window "876000h0m0s" 2026/04/21 01:15:21 INFO : A2: Making directory 2026/04/21 01:15:22 INFO : A1/B2: Making directory 2026/04/21 01:15:22 INFO : A1/B2/C2: Making directory 2026/04/21 01:15:23 INFO : A1/B1/C3: Making directory 2026/04/21 01:15:23 INFO : A3: Making directory 2026/04/21 01:15:24 INFO : A3/B3: Making directory 2026/04/21 01:15:24 INFO : A3/B3/C4: Making directory 2026/04/21 01:15:28 ERROR : error listing: directory not found 2026/04/21 01:15:28 DEBUG : drime root 'rclone-test-wuhoxoc9ruzu': Purge remote 2026/04/21 01:15:28 NOTICE: purge failed: directory not found --- PASS: TestPurge (10.67s) === RUN TestRmdirsNoLeaveRoot run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:15:31 INFO : A2: Making directory 2026/04/21 01:15:31 INFO : A1/B2: Making directory 2026/04/21 01:15:32 INFO : A1/B2/C2: Making directory 2026/04/21 01:15:32 INFO : A1/B1/C3: Making directory 2026/04/21 01:15:33 INFO : A3: Making directory 2026/04/21 01:15:33 INFO : A3/B3: Making directory 2026/04/21 01:15:34 INFO : A3/B3/C4: Making directory fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/04/21 01:15:45 DEBUG : removing 1 level 3 directories 2026/04/21 01:15:45 INFO : A3/B3/C4: Removing directory 2026/04/21 01:15:47 DEBUG : removing 2 level 3 directories 2026/04/21 01:15:47 INFO : A1/B2/C2: Removing directory 2026/04/21 01:15:47 INFO : A1/B1/C3: Removing directory 2026/04/21 01:15:48 DEBUG : removing 2 level 2 directories 2026/04/21 01:15:48 INFO : A3/B3: Removing directory 2026/04/21 01:15:48 INFO : A1/B2: Removing directory 2026/04/21 01:15:48 DEBUG : removing 2 level 1 directories 2026/04/21 01:15:48 INFO : A3: Removing directory 2026/04/21 01:15:48 INFO : A2: Removing directory 2026/04/21 01:15:51 DEBUG : removing 1 level 3 directories 2026/04/21 01:15:51 INFO : A1/B1/C1: Removing directory 2026/04/21 01:15:52 DEBUG : removing 1 level 2 directories 2026/04/21 01:15:52 INFO : A1/B1: Removing directory 2026/04/21 01:15:52 ERROR : A1/B1: Failed to rmdir: directory not empty operations_test.go:728: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:728 Error: Received unexpected error: failed to remove directories: directory not empty Test: TestRmdirsNoLeaveRoot run.go:130: removing dir "A1" failed - try 1/3: directory not empty --- FAIL: TestRmdirsNoLeaveRoot (26.34s) === RUN TestRmdirsLeaveRoot run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:15:55 INFO : A1: Making directory 2026/04/21 01:15:55 INFO : A1/B1: Making directory 2026/04/21 01:15:56 INFO : A1/B1/C1: Making directory 2026/04/21 01:15:58 DEBUG : removing 1 level 3 directories 2026/04/21 01:15:58 INFO : A1/B1/C1: Removing directory 2026/04/21 01:15:58 DEBUG : removing 1 level 2 directories 2026/04/21 01:15:58 INFO : A1/B1: Removing directory --- PASS: TestRmdirsLeaveRoot (5.28s) === RUN TestRmdirsWithFilter run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:16:00 INFO : A1: Making directory 2026/04/21 01:16:01 INFO : A1/B1: Making directory 2026/04/21 01:16:01 INFO : A1/B1/C1: Making directory 2026/04/21 01:16:03 DEBUG : removing 1 level 3 directories 2026/04/21 01:16:03 INFO : A1/B1/C1: Removing directory 2026/04/21 01:16:04 DEBUG : removing 1 level 2 directories 2026/04/21 01:16:04 INFO : A1/B1: Removing directory fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestRmdirsWithFilter (13.35s) === RUN TestCopyURL run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/04/21 01:16:22 DEBUG : filename.txt: File name found in url 2026/04/21 01:16:23 DEBUG : headerfilename.txt: filename found in Content-Disposition header. fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestCopyURL (19.98s) === RUN TestCopyURLDownloadHeaders run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:178 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:393 /usr/local/go/src/testing/testing.go:1317 /usr/local/go/src/testing/testing.go:1667 /usr/local/go/src/testing/testing.go:2030 Error: Should be true Test: TestCopyURLDownloadHeaders Messages: listing wrong, want got file1 (14) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:178 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:393 /usr/local/go/src/testing/testing.go:1317 /usr/local/go/src/testing/testing.go:1667 /usr/local/go/src/testing/testing.go:2030 Error: Should be true Test: TestCopyURLDownloadHeaders Messages: Unexpected file "file1" --- FAIL: TestCopyURLDownloadHeaders (9.22s) === RUN TestCopyURLToWriter --- PASS: TestCopyURLToWriter (0.00s) === RUN TestMoveFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:16:43 DEBUG : file1: Need to transfer - File not found at Destination 2026/04/21 01:16:45 DEBUG : sub/file2: size = 14 OK 2026/04/21 01:16:45 INFO : file1: Copied (new) to: sub/file2 2026/04/21 01:16:45 INFO : file1: Deleted fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:965 Error: Should be true Test: TestMoveFile Messages: listing wrong, want sub/file2 (14) got file1 (14), sub/file2 (14) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:965 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestMoveFile Messages: Unexpected file "file1" 2026/04/21 01:16:54 DEBUG : sub/file2: size = 14 OK 2026/04/21 01:16:54 DEBUG : file1: Sizes identical 2026/04/21 01:16:54 DEBUG : file1: Unchanged skipping 2026/04/21 01:16:54 INFO : file1: Deleted fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:973 Error: Should be true Test: TestMoveFile Messages: listing wrong, want sub/file2 (14) got file1 (14), sub/file2 (14) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:973 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestMoveFile Messages: Unexpected file "file1" 2026/04/21 01:17:03 DEBUG : drime root 'rclone-test-yojoqaj4hese': don't need to copy/move sub/file2, it is already at target location fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:978 Error: Should be true Test: TestMoveFile Messages: listing wrong, want sub/file2 (14) got file1 (14), sub/file2 (14) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:978 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestMoveFile Messages: Unexpected file "file1" run.go:130: removing dir "sub" failed - try 1/3: directory not empty --- FAIL: TestMoveFile (32.51s) === RUN TestMoveFileWithIgnoreExisting run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:17:15 DEBUG : file1: Need to transfer - File not found at Destination 2026/04/21 01:17:16 DEBUG : file1: size = 14 OK 2026/04/21 01:17:16 INFO : file1: Copied (new) 2026/04/21 01:17:16 INFO : file1: Deleted 2026/04/21 01:17:17 DEBUG : file1: Destination exists, skipping 2026/04/21 01:17:17 DEBUG : file1: Not removing source file as destination file exists and --ignore-existing is set --- PASS: TestMoveFileWithIgnoreExisting (2.25s) === RUN TestCaseInsensitiveMoveFile run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" --- PASS: TestCaseInsensitiveMoveFile (0.39s) === RUN TestCaseInsensitiveMoveFileDryRun run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" --- PASS: TestCaseInsensitiveMoveFileDryRun (0.39s) === RUN TestMoveFileBackupDir run.go:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:17:20 DEBUG : Creating backend with remote "TestDrime:rclone-test-yojoqaj4hese/backup" 2026/04/21 01:17:21 DEBUG : dst/file1: size = 14 (Local file system at /tmp/rclone4177392965) 2026/04/21 01:17:21 DEBUG : dst/file1: size = 18 (drime root 'rclone-test-yojoqaj4hese') 2026/04/21 01:17:21 DEBUG : dst/file1: Sizes differ 2026/04/21 01:17:23 INFO : dst/file1: Moved (server-side) 2026/04/21 01:17:23 DEBUG : dst/file1: size = 14 OK 2026/04/21 01:17:23 INFO : dst/file1: Copied (new) 2026/04/21 01:17:23 INFO : dst/file1: Deleted fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure run.go:130: removing dir "dst" failed - try 1/3: directory not empty --- PASS: TestMoveFileBackupDir (17.80s) === 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:185: Remote "drime root 'rclone-test-yojoqaj4hese'", Local "Local file system at /tmp/rclone4177392965", Modify Window "876000h0m0s" 2026/04/21 01:17:42 INFO : A1/B2: Making directory 2026/04/21 01:17:42 INFO : A1/B1/C3: Making directory 2026/04/21 01:17:44 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value operations_test.go:1411: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1411 Error: Received unexpected error: Move rename leaf: failed to patch item "name" to A2: Error "520 (520): \n\n\n\n \n
\n\nThere is an unknown connection issue between Cloudflare and the origin web server. As a result, the web page can not be displayed.
\nPlease try again in a few minutes.
\n\nThere is an issue between Cloudflare's cache and your origin web server. Cloudflare monitors for these errors and automatically investigates the cause. To help support the investigation, you can pull the corresponding error log from your web server and submit it our support team. Please include the Ray ID (which is at the bottom of this error page). Additional troubleshooting resources.
\nThere is an unknown connection issue between Cloudflare and the origin web server. As a result, the web page can not be displayed.
\\nPlease try again in a few minutes.
\\n\\nThere is an issue between Cloudflare's cache and your origin web server. Cloudflare monitors for these errors and automatically investigates the cause. To help support the investigation, you can pull the corresponding error log from your web server and submit it our support team. Please include the Ray ID (which is at the bottom of this error page). Additional troubleshooting resources.
\\n