"./operations.test -test.v -test.timeout 2h0m0s -remote TestDrime: -verbose -test.run '^(TestApplyTransforms|TestCheckSumDownload|TestCopyFile|TestCopyFileCompareDest|TestCopyFileCopyDest|TestHashSums|TestListDirSortedFn|TestLsLong|TestMaxDelete|TestMaxDeleteSize|TestParseSumFile|TestRmdirsNoLeaveRoot|TestStatJSON)$|^TestListJSON$/^(Default|DirsOnly|Metadata|Recurse)$|^TestMultithreadCopy$/^(upload=false,size=10485759,streams=2|upload=true,size=10485759,streams=2|upload=true,size=10485760,streams=2|upload=true,size=10485761,streams=2)$'" - Starting (try 5/5)
2026/02/02 07:38:38 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu"
2026/02/02 07:38:38 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:38:40 DEBUG : Creating backend with remote "/tmp/rclone142847565"
=== RUN TestMultithreadCopy
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
=== RUN TestMultithreadCopy/upload=false,size=10485759,streams=2
fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
fstest.go:301: Flushing the directory cache
2026/02/02 07:38:49 ERROR : error listing: directory not found
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/multithread_test.go:191
Error: Should be true
Test: TestMultithreadCopy/upload=false,size=10485759,streams=2
Messages: listing wrong, want
test-multithread-copy-false-10485759-2 (10485759) got
fstest.go:203: Not found "test-multithread-copy-false-10485759-2"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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/multithread_test.go:191
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestMultithreadCopy/upload=false,size=10485759,streams=2
Messages: 1 objects not found
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: write buffer set to 131072
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10.000Mi
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: Starting multi-thread copy with 1 chunks of size 10.000Mi with 1 parallel streams
2026/02/02 07:38:57 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk 1/1 (0-10485759) size 10.000Mi starting
2026/02/02 07:38:59 DEBUG : test-multithread-copy-false-10485759-2: writing chunk 0
2026/02/02 07:38:59 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk 1/1 (0-10485759) size 10.000Mi finished
2026/02/02 07:38:59 DEBUG : test-multithread-copy-false-10485759-2: Finished multi-thread copy with 1 parts of size 10.000Mi
=== RUN TestMultithreadCopy/upload=true,size=10485759,streams=2
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/multithread_test.go:186
Error: Should be true
Test: TestMultithreadCopy/upload=true,size=10485759,streams=2
Messages: listing wrong, want
got
test-multithread-copy-false-10485759-2 (10485759)
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/multithread_test.go:186
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Should be true
Test: TestMultithreadCopy/upload=true,size=10485759,streams=2
Messages: Unexpected file "test-multithread-copy-false-10485759-2"
2026/02/02 07:39:11 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: disabling buffering because source is local disk
2026/02/02 07:39:13 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2026/02/02 07:39:13 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: number of streams 4 was bigger than number of chunks 2
2026/02/02 07:39:13 DEBUG : test-multithread-copy-true-10485759-2: Starting multi-thread copy with 2 chunks of size 5Mi with 2 parallel streams
2026/02/02 07:39:13 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 2/2 (5242880-10485759) size 5.000Mi starting
2026/02/02 07:39:13 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi starting
2026/02/02 07:39:14 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 2/2 (5242880-10485759) size 5.000Mi finished
2026/02/02 07:39:14 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi finished
2026/02/02 07:39:16 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
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/multithread_test.go:186
Error: Should be true
Test: TestMultithreadCopy/upload=true,size=10485760,streams=2
Messages: listing wrong, want
got
test-multithread-copy-true-10485759-2 (10485759)
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/multithread_test.go:186
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Should be true
Test: TestMultithreadCopy/upload=true,size=10485760,streams=2
Messages: Unexpected file "test-multithread-copy-true-10485759-2"
2026/02/02 07:39:28 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: disabling buffering because source is local disk
2026/02/02 07:39:30 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2026/02/02 07:39:30 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: number of streams 4 was bigger than number of chunks 2
2026/02/02 07:39:30 DEBUG : test-multithread-copy-true-10485760-2: Starting multi-thread copy with 2 chunks of size 5Mi with 2 parallel streams
2026/02/02 07:39:30 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 2/2 (5242880-10485760) size 5Mi starting
2026/02/02 07:39:30 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi starting
2026/02/02 07:39:31 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 2/2 (5242880-10485760) size 5Mi finished
2026/02/02 07:39:31 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi finished
2026/02/02 07:39:33 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
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/multithread_test.go:186
Error: Should be true
Test: TestMultithreadCopy/upload=true,size=10485761,streams=2
Messages: listing wrong, want
got
test-multithread-copy-true-10485760-2 (10485760)
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/multithread_test.go:186
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Should be true
Test: TestMultithreadCopy/upload=true,size=10485761,streams=2
Messages: Unexpected file "test-multithread-copy-true-10485760-2"
2026/02/02 07:39:46 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: disabling buffering because source is local disk
2026/02/02 07:39:47 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2026/02/02 07:39:47 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: number of streams 4 was bigger than number of chunks 3
2026/02/02 07:39:47 DEBUG : test-multithread-copy-true-10485761-2: Starting multi-thread copy with 3 chunks of size 5Mi with 3 parallel streams
2026/02/02 07:39:47 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 starting
2026/02/02 07:39:47 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi starting
2026/02/02 07:39:47 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi starting
2026/02/02 07:39:48 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 finished
2026/02/02 07:39:48 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi finished
2026/02/02 07:39:48 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi finished
2026/02/02 07:39:50 DEBUG : test-multithread-copy-true-10485761-2: Finished multi-thread copy with 3 parts of size 5Mi
2026/02/02 07:39:53 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:39:53 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 07:39:53 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:39:53 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 07:39:54 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 07:39:54 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 07:39:55 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:39:55 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 07:39:55 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:39:55 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:39:55 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/02/02 07:39:55 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:39:55 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/02/02 07:39:56 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 07:39:56 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/02/02 07:39:56 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:39:56 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/02/02 07:39:58 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:39:58 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/02/02 07:40:00 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
2026/02/02 07:40:00 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
=== NAME TestMultithreadCopy
run.go:130: removing file "test-multithread-copy-true-10485761-2" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 07:40:05 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:40:05 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 07:40:16 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:40:35 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 07:40:56 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:41:16 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 07:41:35 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:41:56 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 07:42:16 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:42:36 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:42:56 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "test-multithread-copy-true-10485761-2" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 07:43:15 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:43:36 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:43:55 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:43:55 DEBUG : pacer: low level retry 3/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:44:16 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:44:35 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:44:35 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:44:55 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:45:16 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 07:45:36 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:45:56 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:46:16 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "test-multithread-copy-true-10485761-2" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing file "test-multithread-copy-true-10485761-2" failed: failed to delete item: Error "Server Error"
2026/02/02 07:46:36 DEBUG : pacer: Reducing sleep to 10s
--- FAIL: TestMultithreadCopy (476.03s)
--- FAIL: TestMultithreadCopy/upload=false,size=10485759,streams=2 (17.52s)
--- FAIL: TestMultithreadCopy/upload=true,size=10485759,streams=2 (17.65s)
--- FAIL: TestMultithreadCopy/upload=true,size=10485760,streams=2 (17.13s)
--- FAIL: TestMultithreadCopy/upload=true,size=10485761,streams=2 (16.93s)
=== RUN TestParseSumFile
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 07:46:56 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 07:47:07 DEBUG : pacer: Reducing sleep to 2.5s
2026/02/02 07:47:11 DEBUG : pacer: Reducing sleep to 1.25s
2026/02/02 07:47:14 DEBUG : pacer: Reducing sleep to 625ms
2026/02/02 07:47:14 NOTICE: test.sum: improperly formatted checksum line 4
2026/02/02 07:47:14 NOTICE: test.sum: improperly formatted checksum line 5
2026/02/02 07:47:14 NOTICE: test.sum: improperly formatted checksum line 6
2026/02/02 07:47:14 NOTICE: test.sum: 2 warning(s) suppressed...
2026/02/02 07:47:15 DEBUG : pacer: Reducing sleep to 312.5ms
2026/02/02 07:47:16 DEBUG : pacer: Reducing sleep to 156.25ms
2026/02/02 07:47:16 DEBUG : test.sum: Removing old object on successful upload
2026/02/02 07:47:16 DEBUG : pacer: Reducing sleep to 78.125ms
2026/02/02 07:47:17 DEBUG : pacer: Reducing sleep to 39.0625ms
2026/02/02 07:47:18 DEBUG : pacer: Reducing sleep to 19.53125ms
2026/02/02 07:47:18 NOTICE: test.sum: improperly formatted checksum line 4
2026/02/02 07:47:18 NOTICE: test.sum: improperly formatted checksum line 5
2026/02/02 07:47:18 NOTICE: test.sum: improperly formatted checksum line 6
2026/02/02 07:47:18 NOTICE: test.sum: 2 warning(s) suppressed...
2026/02/02 07:47:18 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 07:47:19 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:47:19 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 07:47:19 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:47:19 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 07:47:20 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 07:47:20 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 07:47:20 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:47:20 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 07:47:20 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 07:47:20 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/02/02 07:47:21 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:47:21 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/02/02 07:47:22 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 07:47:22 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/02/02 07:47:22 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:47:22 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/02/02 07:47:24 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:47:24 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/02/02 07:47:26 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
2026/02/02 07:47:26 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
run.go:130: removing file "test.sum" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 07:47:31 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:47:31 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 07:47:41 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:48:02 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 07:48:21 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:48:42 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 07:49:02 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:49:21 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 07:49:42 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:50:01 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:50:22 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "test.sum" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 07:50:41 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:51:01 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:51:22 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 07:51:42 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:52:02 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 07:52:22 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:52:42 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 07:53:02 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:53:22 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:53:42 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "test.sum" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing file "test.sum" failed: failed to delete item: Error "Server Error"
2026/02/02 07:54:02 DEBUG : pacer: Reducing sleep to 10s
fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
fstest.go:301: Flushing the directory cache
2026/02/02 07:54:22 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 07:54:32 DEBUG : pacer: Reducing sleep to 2.5s
fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3
fstest.go:301: Flushing the directory cache
2026/02/02 07:54:37 DEBUG : pacer: Reducing sleep to 1.25s
2026/02/02 07:54:39 DEBUG : pacer: Reducing sleep to 625ms
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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Should be true
Test: TestParseSumFile
Messages: listing wrong, want
got
test.sum (90)
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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Should be true
Test: TestParseSumFile
Messages: Unexpected file "test.sum"
--- FAIL: TestParseSumFile (487.89s)
=== RUN TestCheckSumDownload
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 07:54:43 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/data"
2026/02/02 07:54:44 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:54:44 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:54:44 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 07:54:45 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:54:45 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:54:45 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 07:54:45 DEBUG : pacer: Reducing sleep to 20ms
2026/02/02 07:54:46 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 07:54:47 DEBUG : pacer: Reducing sleep to 312.5ms
2026/02/02 07:54:48 DEBUG : pacer: Reducing sleep to 156.25ms
2026/02/02 07:54:48 DEBUG : pacer: Reducing sleep to 78.125ms
2026/02/02 07:54:48 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:54:48 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:54:48 DEBUG : pacer: Rate limited, increasing sleep to 156.25ms
2026/02/02 07:54:49 DEBUG : pacer: Reducing sleep to 78.125ms
2026/02/02 07:54:50 DEBUG : pacer: Reducing sleep to 39.0625ms
2026/02/02 07:54:51 DEBUG : pacer: Reducing sleep to 19.53125ms
2026/02/02 07:54:52 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 07:54:52 DEBUG : test.sum: Removing old object on successful upload
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:292: Sleeping for 7s just to make sure
=== RUN TestCheckSumDownload/subtest1
2026/02/02 07:55:11 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:11 DEBUG : pacer: low level retry 1/1 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:11 DEBUG : pacer: Rate limited, increasing sleep to 20ms
=== NAME TestCheckSumDownload
run.go:286: Retry Put of "test.sum" to drime root 'rclone-test-veqakub4xibu': 1/10 (failed to upload file: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:14 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 07:55:16 DEBUG : test.sum: Removing old object on successful upload
2026/02/02 07:55:17 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:17 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:17 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 07:55:17 DEBUG : pacer: Reducing sleep to 10ms
fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
fstest.go:301: Flushing the directory cache
2026/02/02 07:55:18 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:18 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:18 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 07:55:19 DEBUG : pacer: Reducing sleep to 10ms
fstest.go:292: Sleeping for 6s just to make sure
=== RUN TestCheckSumDownload/subtest2
2026/02/02 07:55:31 DEBUG : test.sum: Removing old object on successful upload
=== NAME TestCheckSumDownload
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/subtest3
2026/02/02 07:55:45 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:45 DEBUG : pacer: low level retry 1/1 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:45 DEBUG : pacer: Rate limited, increasing sleep to 20ms
=== NAME TestCheckSumDownload
run.go:286: Retry Put of "test.sum" to drime root 'rclone-test-veqakub4xibu': 1/10 (failed to upload file: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:47 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 07:55:47 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:47 DEBUG : pacer: low level retry 1/1 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:47 DEBUG : pacer: Rate limited, increasing sleep to 20ms
run.go:286: Retry Put of "test.sum" to drime root 'rclone-test-veqakub4xibu': 2/10 (failed to upload file: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:49 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:49 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:49 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 07:55:50 DEBUG : pacer: Reducing sleep to 20ms
2026/02/02 07:55:51 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 07:55:51 DEBUG : test.sum: Removing old object on successful upload
=== RUN TestCheckSumDownload/subtest4
=== NAME TestCheckSumDownload
check_test.go:407:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:407
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428
Error: An error is expected but got nil.
Test: TestCheckSumDownload
Messages: no expected error in run 4
check_test.go:409:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:409
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428
Error: Not equal:
expected: 1
actual : 0
Test: TestCheckSumDownload
Messages: wrong error count in run 4
check_test.go:384:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:417
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428
Error: Not equal:
expected: []string{"", "* banana", "= potato"}
actual : []string{"", "= banana", "= potato"}
Diff:
--- Expected
+++ Actual
@@ -2,3 +2,3 @@
(string) "",
- (string) (len=8) "* banana",
+ (string) (len=8) "= banana",
(string) (len=8) "= potato"
Test: TestCheckSumDownload
Messages: wrong combined result in run 4
check_test.go:384:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:420
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428
Error: Not equal:
expected: []string{"", "potato"}
actual : []string{"", "banana", "potato"}
Diff:
--- Expected
+++ Actual
@@ -1,3 +1,4 @@
-([]string) (len=2) {
+([]string) (len=3) {
(string) "",
+ (string) (len=6) "banana",
(string) (len=6) "potato"
Test: TestCheckSumDownload
Messages: wrong match result in run 4
check_test.go:384:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:421
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428
Error: Not equal:
expected: []string{"", "banana"}
actual : []string{}
Diff:
--- Expected
+++ Actual
@@ -1,4 +1,2 @@
-([]string) (len=2) {
- (string) "",
- (string) (len=6) "banana"
+([]string) {
}
Test: TestCheckSumDownload
Messages: wrong differ result in run 4
2026/02/02 07:55:57 DEBUG : test.sum: Removing old object on successful upload
2026/02/02 07:55:57 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 07:55:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 07:55:58 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 07:55:58 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 07:55:58 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 07:55:58 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 07:55:59 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 07:55:59 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 07:55:59 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 07:55:59 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/02/02 07:55:59 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 07:55:59 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/02/02 07:55:59 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:55:59 DEBUG : pacer: low level retry 7/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:55:59 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/02/02 07:56:00 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 07:56:00 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/02/02 07:56:02 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 07:56:02 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/02/02 07:56:04 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 07:56:04 DEBUG : pacer: low level retry 10/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:56:04 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
run.go:286: Retry Put of "test.sum" to drime root 'rclone-test-veqakub4xibu': 1/10 (failed to delete existing object: failed to delete item: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 07:56:09 DEBUG : pacer: Reducing sleep to 5.12s
2026/02/02 07:56:20 DEBUG : pacer: Reducing sleep to 2.56s
2026/02/02 07:56:20 DEBUG : test.sum: Removing old object on successful upload
2026/02/02 07:56:25 DEBUG : pacer: Reducing sleep to 1.28s
2026/02/02 07:56:27 DEBUG : pacer: Reducing sleep to 640ms
2026/02/02 07:56:29 DEBUG : pacer: Reducing sleep to 320ms
fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
fstest.go:301: Flushing the directory cache
2026/02/02 07:56:30 DEBUG : pacer: Reducing sleep to 160ms
2026/02/02 07:56:31 DEBUG : pacer: Reducing sleep to 80ms
2026/02/02 07:56:31 DEBUG : pacer: Reducing sleep to 40ms
fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3
fstest.go:301: Flushing the directory cache
2026/02/02 07:56:33 DEBUG : pacer: Reducing sleep to 20ms
2026/02/02 07:56:34 DEBUG : pacer: Reducing sleep to 10ms
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/check_test.go:493
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Should be true
Test: TestCheckSumDownload
Messages: listing wrong, want
data/banana (13), data/potato (15), test.sum (123) got
data/banana (13), data/potato (15), test.sum (123), test.sum (82)
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/check_test.go:493
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
Error: Should be true
Test: TestCheckSumDownload
Messages: Unexpected file "test.sum"
=== RUN TestCheckSumDownload/subtest5
2026/02/02 07:56:42 DEBUG : test.sum: Removing old object on successful upload
=== NAME TestCheckSumDownload
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/check_test.go:508
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Should be true
Test: TestCheckSumDownload
Messages: listing wrong, want
data/banana (13), data/potato (15), test.sum (123) got
data/banana (13), data/potato (15), test.sum (123), test.sum (82)
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/check_test.go:508
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
Error: Should be true
Test: TestCheckSumDownload
Messages: Unexpected file "test.sum"
=== RUN TestCheckSumDownload/subtest6
2026/02/02 07:56:59 DEBUG : data/banana: Removing old object on successful upload
2026/02/02 07:57:01 DEBUG : data/potato: Removing old object on successful upload
2026/02/02 07:57:04 DEBUG : test.sum: Removing old object on successful upload
=== NAME TestCheckSumDownload
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/check_test.go:525
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Should be true
Test: TestCheckSumDownload
Messages: listing wrong, want
data/banana (13), data/potato (15), test.sum (82) got
data/banana (13), data/potato (15), test.sum (123), test.sum (82)
fstest.go:150:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:150
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195
/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/check_test.go:525
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
Error: Not equal:
expected: 82
actual : 123
Test: TestCheckSumDownload
Messages: test.sum: size incorrect file=82 vs obj=123
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/check_test.go:525
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:541
Error: Should be true
Test: TestCheckSumDownload
Messages: Unexpected file "test.sum"
=== RUN TestCheckSumDownload/subtest7
=== NAME TestCheckSumDownload
run.go:130: removing dir "data" failed - try 1/3: directory not empty
run.go:130: removing dir "data" failed - try 2/3: directory not empty
run.go:130: removing dir "data" failed - try 3/3: directory not empty
run.go:133: removing dir "data" failed: 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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Not equal:
expected: []string{}
actual : []string{"data"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,3 @@
-([]string) {
+([]string) (len=1) {
+ (string) (len=4) "data"
}
Test: TestCheckSumDownload
Messages: directories
--- FAIL: TestCheckSumDownload (171.45s)
--- PASS: TestCheckSumDownload/subtest1 (3.82s)
--- PASS: TestCheckSumDownload/subtest2 (2.86s)
--- PASS: TestCheckSumDownload/subtest3 (2.26s)
--- PASS: TestCheckSumDownload/subtest4 (2.21s)
--- PASS: TestCheckSumDownload/subtest5 (2.64s)
--- PASS: TestCheckSumDownload/subtest6 (2.78s)
--- PASS: TestCheckSumDownload/subtest7 (2.40s)
=== RUN TestApplyTransforms
2026/02/02 07:57:35 DEBUG : Creating backend with remote "TestDrime:rclone-test-ciroguv0gari"
2026/02/02 07:57:35 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:57:37 DEBUG : Creating backend with remote "/tmp/rclone3632760562"
run.go:185: Remote "drime root 'rclone-test-ciroguv0gari'", Local "Local file system at /tmp/rclone3632760562", Modify Window "876000h0m0s"
upper checkfile vs. lower remote (without normalization)
2026/02/02 07:57:41 ERROR : HELLO, WORLD!: file not in drime root 'rclone-test-ciroguv0gari'
2026/02/02 07:57:41 NOTICE: drime root 'rclone-test-ciroguv0gari': 1 files missing
2026/02/02 07:57:41 NOTICE: drime root 'rclone-test-ciroguv0gari': 0 differences found
2026/02/02 07:57:41 NOTICE: drime root 'rclone-test-ciroguv0gari': 1 errors while checking
upper checkfile vs. lower remote (with normalization)
2026/02/02 07:57:41 ERROR : hello, world!: file not in drime root 'rclone-test-ciroguv0gari'
2026/02/02 07:57:41 NOTICE: drime root 'rclone-test-ciroguv0gari': 1 files missing
2026/02/02 07:57:41 NOTICE: drime root 'rclone-test-ciroguv0gari': 0 differences found
2026/02/02 07:57:41 NOTICE: drime root 'rclone-test-ciroguv0gari': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:594
Error: Received unexpected error:
file not in drime root 'rclone-test-ciroguv0gari'
Test: TestApplyTransforms
Messages: unexpected error for upper checkfile vs. lower remote (with normalization) HELLO, WORLD! hello, world!
2026/02/02 07:57:41 DEBUG : Creating backend with remote "TestDrime:rclone-test-patodaf4jali"
2026/02/02 07:57:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:57:42 DEBUG : Creating backend with remote "/tmp/rclone3669860064"
run.go:185: Remote "drime root 'rclone-test-patodaf4jali'", Local "Local file system at /tmp/rclone3669860064", Modify Window "876000h0m0s"
lower checkfile vs. upper remote (without normalization)
2026/02/02 07:57:46 ERROR : hello, world!: file not in drime root 'rclone-test-patodaf4jali'
2026/02/02 07:57:46 NOTICE: drime root 'rclone-test-patodaf4jali': 1 files missing
2026/02/02 07:57:46 NOTICE: drime root 'rclone-test-patodaf4jali': 0 differences found
2026/02/02 07:57:46 NOTICE: drime root 'rclone-test-patodaf4jali': 1 errors while checking
lower checkfile vs. upper remote (with normalization)
2026/02/02 07:57:46 ERROR : hello, world!: file not in drime root 'rclone-test-patodaf4jali'
2026/02/02 07:57:46 NOTICE: drime root 'rclone-test-patodaf4jali': 1 files missing
2026/02/02 07:57:46 NOTICE: drime root 'rclone-test-patodaf4jali': 0 differences found
2026/02/02 07:57:46 NOTICE: drime root 'rclone-test-patodaf4jali': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:595
Error: Received unexpected error:
file not in drime root 'rclone-test-patodaf4jali'
Test: TestApplyTransforms
Messages: unexpected error for lower checkfile vs. upper remote (with normalization) hello, world! HELLO, WORLD!
2026/02/02 07:57:46 DEBUG : Creating backend with remote "TestDrime:rclone-test-xiguvec8mifo"
2026/02/02 07:57:46 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:57:47 DEBUG : Creating backend with remote "/tmp/rclone1250480996"
run.go:185: Remote "drime root 'rclone-test-xiguvec8mifo'", Local "Local file system at /tmp/rclone1250480996", Modify Window "876000h0m0s"
lower checkfile vs. upperlowermixed remote (without normalization)
2026/02/02 07:57:51 ERROR : hello, world!: file not in drime root 'rclone-test-xiguvec8mifo'
2026/02/02 07:57:51 NOTICE: drime root 'rclone-test-xiguvec8mifo': 1 files missing
2026/02/02 07:57:51 NOTICE: drime root 'rclone-test-xiguvec8mifo': 0 differences found
2026/02/02 07:57:51 NOTICE: drime root 'rclone-test-xiguvec8mifo': 1 errors while checking
lower checkfile vs. upperlowermixed remote (with normalization)
2026/02/02 07:57:52 ERROR : hello, world!: file not in drime root 'rclone-test-xiguvec8mifo'
2026/02/02 07:57:52 NOTICE: drime root 'rclone-test-xiguvec8mifo': 1 files missing
2026/02/02 07:57:52 NOTICE: drime root 'rclone-test-xiguvec8mifo': 0 differences found
2026/02/02 07:57:52 NOTICE: drime root 'rclone-test-xiguvec8mifo': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:596
Error: Received unexpected error:
file not in drime root 'rclone-test-xiguvec8mifo'
Test: TestApplyTransforms
Messages: unexpected error for lower checkfile vs. upperlowermixed remote (with normalization) hello, world! HeLlO, wOrLd!
2026/02/02 07:57:52 DEBUG : Creating backend with remote "TestDrime:rclone-test-kugiruy6wepo"
2026/02/02 07:57:52 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:57:52 DEBUG : Creating backend with remote "/tmp/rclone2314051318"
run.go:185: Remote "drime root 'rclone-test-kugiruy6wepo'", Local "Local file system at /tmp/rclone2314051318", Modify Window "876000h0m0s"
upperlowermixed checkfile vs. upper remote (without normalization)
2026/02/02 07:57:56 ERROR : HeLlO, wOrLd!: file not in drime root 'rclone-test-kugiruy6wepo'
2026/02/02 07:57:56 NOTICE: drime root 'rclone-test-kugiruy6wepo': 1 files missing
2026/02/02 07:57:56 NOTICE: drime root 'rclone-test-kugiruy6wepo': 0 differences found
2026/02/02 07:57:56 NOTICE: drime root 'rclone-test-kugiruy6wepo': 1 errors while checking
upperlowermixed checkfile vs. upper remote (with normalization)
2026/02/02 07:57:56 ERROR : hello, world!: file not in drime root 'rclone-test-kugiruy6wepo'
2026/02/02 07:57:56 NOTICE: drime root 'rclone-test-kugiruy6wepo': 1 files missing
2026/02/02 07:57:56 NOTICE: drime root 'rclone-test-kugiruy6wepo': 0 differences found
2026/02/02 07:57:56 NOTICE: drime root 'rclone-test-kugiruy6wepo': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:597
Error: Received unexpected error:
file not in drime root 'rclone-test-kugiruy6wepo'
Test: TestApplyTransforms
Messages: unexpected error for upperlowermixed checkfile vs. upper remote (with normalization) HeLlO, wOrLd! HELLO, WORLD!
2026/02/02 07:57:56 DEBUG : Creating backend with remote "TestDrime:rclone-test-cohoyeh9xite"
2026/02/02 07:57:56 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:57:57 DEBUG : Creating backend with remote "/tmp/rclone1682415426"
run.go:185: Remote "drime root 'rclone-test-cohoyeh9xite'", Local "Local file system at /tmp/rclone1682415426", Modify Window "876000h0m0s"
NFD checkfile vs. NFC remote (without normalization)
2026/02/02 07:57:59 ERROR : 測試_Русский___ě_áñ: file not in drime root 'rclone-test-cohoyeh9xite'
2026/02/02 07:57:59 NOTICE: drime root 'rclone-test-cohoyeh9xite': 1 files missing
2026/02/02 07:57:59 NOTICE: drime root 'rclone-test-cohoyeh9xite': 0 differences found
2026/02/02 07:57:59 NOTICE: drime root 'rclone-test-cohoyeh9xite': 1 errors while checking
NFD checkfile vs. NFC remote (with normalization)
2026/02/02 07:58:00 ERROR : 測試_русский___ě_áñ: file not in drime root 'rclone-test-cohoyeh9xite'
2026/02/02 07:58:00 NOTICE: drime root 'rclone-test-cohoyeh9xite': 1 files missing
2026/02/02 07:58:00 NOTICE: drime root 'rclone-test-cohoyeh9xite': 0 differences found
2026/02/02 07:58:00 NOTICE: drime root 'rclone-test-cohoyeh9xite': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:598
Error: Received unexpected error:
file not in drime root 'rclone-test-cohoyeh9xite'
Test: TestApplyTransforms
Messages: unexpected error for NFD checkfile vs. NFC remote (with normalization) 測試_Русский___ě_áñ 測試_Русский___ě_áñ
2026/02/02 07:58:00 DEBUG : Creating backend with remote "TestDrime:rclone-test-wilavuc6maca"
2026/02/02 07:58:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:58:01 DEBUG : Creating backend with remote "/tmp/rclone2115716597"
run.go:185: Remote "drime root 'rclone-test-wilavuc6maca'", Local "Local file system at /tmp/rclone2115716597", Modify Window "876000h0m0s"
NFC checkfile vs. NFD remote (without normalization)
2026/02/02 07:58:05 ERROR : 測試_Русский___ě_áñ: file not in drime root 'rclone-test-wilavuc6maca'
2026/02/02 07:58:05 NOTICE: drime root 'rclone-test-wilavuc6maca': 1 files missing
2026/02/02 07:58:05 NOTICE: drime root 'rclone-test-wilavuc6maca': 0 differences found
2026/02/02 07:58:05 NOTICE: drime root 'rclone-test-wilavuc6maca': 1 errors while checking
NFC checkfile vs. NFD remote (with normalization)
2026/02/02 07:58:05 ERROR : 測試_русский___ě_áñ: file not in drime root 'rclone-test-wilavuc6maca'
2026/02/02 07:58:05 NOTICE: drime root 'rclone-test-wilavuc6maca': 1 files missing
2026/02/02 07:58:05 NOTICE: drime root 'rclone-test-wilavuc6maca': 0 differences found
2026/02/02 07:58:05 NOTICE: drime root 'rclone-test-wilavuc6maca': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:599
Error: Received unexpected error:
file not in drime root 'rclone-test-wilavuc6maca'
Test: TestApplyTransforms
Messages: unexpected error for NFC checkfile vs. NFD remote (with normalization) 測試_Русский___ě_áñ 測試_Русский___ě_áñ
2026/02/02 07:58:05 DEBUG : Creating backend with remote "TestDrime:rclone-test-xelicug7vomu"
2026/02/02 07:58:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:58:07 DEBUG : Creating backend with remote "/tmp/rclone2944090587"
run.go:185: Remote "drime root 'rclone-test-xelicug7vomu'", Local "Local file system at /tmp/rclone2944090587", Modify Window "876000h0m0s"
NFDx2 checkfile vs. both remote (without normalization)
2026/02/02 07:58:11 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-xelicug7vomu'
2026/02/02 07:58:11 NOTICE: drime root 'rclone-test-xelicug7vomu': 1 files missing
2026/02/02 07:58:11 NOTICE: drime root 'rclone-test-xelicug7vomu': 0 differences found
2026/02/02 07:58:11 NOTICE: drime root 'rclone-test-xelicug7vomu': 1 errors while checking
NFDx2 checkfile vs. both remote (with normalization)
2026/02/02 07:58:11 ERROR : 測試_русский___ě_áñ測試_русский___ě_áñ: file not in drime root 'rclone-test-xelicug7vomu'
2026/02/02 07:58:11 NOTICE: drime root 'rclone-test-xelicug7vomu': 1 files missing
2026/02/02 07:58:11 NOTICE: drime root 'rclone-test-xelicug7vomu': 0 differences found
2026/02/02 07:58:11 NOTICE: drime root 'rclone-test-xelicug7vomu': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:600
Error: Received unexpected error:
file not in drime root 'rclone-test-xelicug7vomu'
Test: TestApplyTransforms
Messages: unexpected error for NFDx2 checkfile vs. both remote (with normalization) 測試_Русский___ě_áñ測試_Русский___ě_áñ 測試_Русский___ě_áñ測試_Русский___ě_áñ
2026/02/02 07:58:11 DEBUG : Creating backend with remote "TestDrime:rclone-test-dasuqat9dege"
2026/02/02 07:58:11 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:58:13 DEBUG : Creating backend with remote "/tmp/rclone974563839"
run.go:185: Remote "drime root 'rclone-test-dasuqat9dege'", Local "Local file system at /tmp/rclone974563839", Modify Window "876000h0m0s"
NFCx2 checkfile vs. both remote (without normalization)
2026/02/02 07:58:17 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-dasuqat9dege'
2026/02/02 07:58:17 NOTICE: drime root 'rclone-test-dasuqat9dege': 1 files missing
2026/02/02 07:58:17 NOTICE: drime root 'rclone-test-dasuqat9dege': 0 differences found
2026/02/02 07:58:17 NOTICE: drime root 'rclone-test-dasuqat9dege': 1 errors while checking
NFCx2 checkfile vs. both remote (with normalization)
2026/02/02 07:58:17 ERROR : 測試_русский___ě_áñ測試_русский___ě_áñ: file not in drime root 'rclone-test-dasuqat9dege'
2026/02/02 07:58:17 NOTICE: drime root 'rclone-test-dasuqat9dege': 1 files missing
2026/02/02 07:58:17 NOTICE: drime root 'rclone-test-dasuqat9dege': 0 differences found
2026/02/02 07:58:17 NOTICE: drime root 'rclone-test-dasuqat9dege': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:601
Error: Received unexpected error:
file not in drime root 'rclone-test-dasuqat9dege'
Test: TestApplyTransforms
Messages: unexpected error for NFCx2 checkfile vs. both remote (with normalization) 測試_Русский___ě_áñ測試_Русский___ě_áñ 測試_Русский___ě_áñ測試_Русский___ě_áñ
2026/02/02 07:58:17 DEBUG : Creating backend with remote "TestDrime:rclone-test-benohuk8vayu"
2026/02/02 07:58:17 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:58:18 DEBUG : Creating backend with remote "/tmp/rclone2214055635"
run.go:185: Remote "drime root 'rclone-test-benohuk8vayu'", Local "Local file system at /tmp/rclone2214055635", Modify Window "876000h0m0s"
both checkfile vs. NFDx2 remote (without normalization)
2026/02/02 07:58:23 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-benohuk8vayu'
2026/02/02 07:58:23 NOTICE: drime root 'rclone-test-benohuk8vayu': 1 files missing
2026/02/02 07:58:23 NOTICE: drime root 'rclone-test-benohuk8vayu': 0 differences found
2026/02/02 07:58:23 NOTICE: drime root 'rclone-test-benohuk8vayu': 1 errors while checking
both checkfile vs. NFDx2 remote (with normalization)
2026/02/02 07:58:23 ERROR : 測試_русский___ě_áñ測試_русский___ě_áñ: file not in drime root 'rclone-test-benohuk8vayu'
2026/02/02 07:58:23 NOTICE: drime root 'rclone-test-benohuk8vayu': 1 files missing
2026/02/02 07:58:23 NOTICE: drime root 'rclone-test-benohuk8vayu': 0 differences found
2026/02/02 07:58:23 NOTICE: drime root 'rclone-test-benohuk8vayu': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:602
Error: Received unexpected error:
file not in drime root 'rclone-test-benohuk8vayu'
Test: TestApplyTransforms
Messages: unexpected error for both checkfile vs. NFDx2 remote (with normalization) 測試_Русский___ě_áñ測試_Русский___ě_áñ 測試_Русский___ě_áñ測試_Русский___ě_áñ
2026/02/02 07:58:23 DEBUG : Creating backend with remote "TestDrime:rclone-test-denamib5dowe"
2026/02/02 07:58:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/02/02 07:58:24 DEBUG : Creating backend with remote "/tmp/rclone1036727474"
run.go:185: Remote "drime root 'rclone-test-denamib5dowe'", Local "Local file system at /tmp/rclone1036727474", Modify Window "876000h0m0s"
both checkfile vs. NFCx2 remote (without normalization)
2026/02/02 07:58:28 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in drime root 'rclone-test-denamib5dowe'
2026/02/02 07:58:28 NOTICE: drime root 'rclone-test-denamib5dowe': 1 files missing
2026/02/02 07:58:28 NOTICE: drime root 'rclone-test-denamib5dowe': 0 differences found
2026/02/02 07:58:28 NOTICE: drime root 'rclone-test-denamib5dowe': 1 errors while checking
both checkfile vs. NFCx2 remote (with normalization)
2026/02/02 07:58:29 ERROR : 測試_русский___ě_áñ測試_русский___ě_áñ: file not in drime root 'rclone-test-denamib5dowe'
2026/02/02 07:58:29 NOTICE: drime root 'rclone-test-denamib5dowe': 1 files missing
2026/02/02 07:58:29 NOTICE: drime root 'rclone-test-denamib5dowe': 0 differences found
2026/02/02 07:58:29 NOTICE: drime root 'rclone-test-denamib5dowe': 1 errors while checking
check_test.go:591:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:591
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:603
Error: Received unexpected error:
file not in drime root 'rclone-test-denamib5dowe'
Test: TestApplyTransforms
Messages: unexpected error for both checkfile vs. NFCx2 remote (with normalization) 測試_Русский___ě_áñ測試_Русский___ě_áñ 測試_Русский___ě_áñ測試_Русский___ě_áñ
2026/02/02 07:58:29 DEBUG : drime root 'rclone-test-denamib5dowe': Purge remote
2026/02/02 07:58:29 DEBUG : drime root 'rclone-test-benohuk8vayu': Purge remote
2026/02/02 07:58:30 DEBUG : drime root 'rclone-test-dasuqat9dege': Purge remote
2026/02/02 07:58:31 DEBUG : drime root 'rclone-test-xelicug7vomu': Purge remote
2026/02/02 07:58:31 DEBUG : drime root 'rclone-test-wilavuc6maca': Purge remote
2026/02/02 07:58:32 DEBUG : drime root 'rclone-test-cohoyeh9xite': Purge remote
2026/02/02 07:58:33 DEBUG : drime root 'rclone-test-kugiruy6wepo': Purge remote
2026/02/02 07:58:33 DEBUG : drime root 'rclone-test-xiguvec8mifo': Purge remote
2026/02/02 07:58:33 DEBUG : drime root 'rclone-test-patodaf4jali': Purge remote
2026/02/02 07:58:34 DEBUG : drime root 'rclone-test-ciroguv0gari': Purge remote
--- FAIL: TestApplyTransforms (59.34s)
=== RUN TestCopyFile
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 07:58:36 DEBUG : file1: Need to transfer - File not found at Destination
2026/02/02 07:58:38 DEBUG : sub/file2: size = 14 OK
2026/02/02 07:58:38 INFO : file1: Copied (new) to: sub/file2
2026/02/02 07:58:40 DEBUG : sub/file2: size = 14 OK
2026/02/02 07:58:40 DEBUG : file1: Sizes identical
2026/02/02 07:58:40 DEBUG : file1: Unchanged skipping
2026/02/02 07:58:40 DEBUG : drime root 'rclone-test-veqakub4xibu': don't need to copy/move sub/file2, it is already at target location
run.go:130: removing dir "sub" failed - try 1/3: directory not empty
run.go:130: removing dir "sub" failed - try 2/3: directory not empty
run.go:130: removing dir "sub" failed - try 3/3: directory not empty
run.go:133: removing dir "sub" failed: 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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Not equal:
expected: []string{}
actual : []string{"sub"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,3 @@
-([]string) {
+([]string) (len=1) {
+ (string) (len=3) "sub"
}
Test: TestCopyFile
Messages: directories
--- FAIL: TestCopyFile (23.20s)
=== RUN TestCopyFileCompareDest
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 07:58:57 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/dst"
2026/02/02 07:58:59 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/CompareDest"
2026/02/02 07:59:00 DEBUG : one: Need to transfer - File not found at Destination
2026/02/02 07:59:03 DEBUG : one: size = 3 OK
2026/02/02 07:59:03 INFO : one: Copied (new)
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:212
Error: Should be true
Test: TestCopyFileCompareDest
Messages: listing wrong, want
dst/one (3) got
fstest.go:203: Not found "dst/one"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:212
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCompareDest
Messages: 1 objects not found
2026/02/02 07:59:16 DEBUG : one: size = 5 (Local file system at /tmp/rclone142847565)
2026/02/02 07:59:16 DEBUG : one: size = 3 (drime root 'rclone-test-veqakub4xibu/dst')
2026/02/02 07:59:16 DEBUG : one: Sizes differ
2026/02/02 07:59:17 DEBUG : one: Removing old object on successful upload
2026/02/02 07:59:18 DEBUG : one: size = 5 OK
2026/02/02 07:59:18 INFO : one: Copied (replaced existing)
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:225
Error: Should be true
Test: TestCopyFileCompareDest
Messages: listing wrong, want
dst/one (5) got
dst/one (3)
fstest.go:150:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:150
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195
/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:225
Error: Not equal:
expected: 5
actual : 3
Test: TestCopyFileCompareDest
Messages: dst/one: size incorrect file=5 vs obj=3
2026/02/02 07:59:31 DEBUG : dst/one: Removing old object on successful upload
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:292: Sleeping for 7s just to make sure
2026/02/02 07:59:49 DEBUG : one: size = 5 (Local file system at /tmp/rclone142847565)
2026/02/02 07:59:49 DEBUG : one: size = 3 (drime root 'rclone-test-veqakub4xibu/dst')
2026/02/02 07:59:49 DEBUG : one: Sizes differ
2026/02/02 07:59:50 DEBUG : one: size = 5 OK
2026/02/02 07:59:50 DEBUG : one: Sizes identical
2026/02/02 07:59:50 DEBUG : one: Destination found in --compare-dest, 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:242
Error: Should be true
Test: TestCopyFileCompareDest
Messages: listing wrong, want
CompareDest/one (5), CompareDest/two (3), dst/one (3) got
CompareDest/one (5), dst/one (3)
fstest.go:203: Not found "CompareDest/two"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:242
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCompareDest
Messages: 1 objects not found
2026/02/02 08:00:03 DEBUG : two: Need to transfer - File not found at Destination
2026/02/02 08:00:04 DEBUG : two: size = 3 OK
2026/02/02 08:00:04 DEBUG : two: Sizes identical
2026/02/02 08:00:04 DEBUG : two: Destination found in --compare-dest, skipping
2026/02/02 08:00:06 DEBUG : two: Need to transfer - File not found at Destination
2026/02/02 08:00:06 DEBUG : two: size = 3 OK
2026/02/02 08:00:06 DEBUG : two: Sizes identical
2026/02/02 08:00:06 DEBUG : two: Destination found in --compare-dest, skipping
2026/02/02 08:00:08 DEBUG : two: Need to transfer - File not found at Destination
2026/02/02 08:00:09 DEBUG : two: size = 5 (Local file system at /tmp/rclone142847565)
2026/02/02 08:00:09 DEBUG : two: size = 3 (drime root 'rclone-test-veqakub4xibu/CompareDest')
2026/02/02 08:00:09 DEBUG : two: Sizes differ
2026/02/02 08:00:11 DEBUG : two: size = 5 OK
2026/02/02 08:00:11 INFO : two: Copied (new)
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:292: Sleeping for 7s just to make sure
run.go:130: removing dir "CompareDest" failed - try 1/3: directory not empty
run.go:130: removing dir "CompareDest" failed - try 2/3: directory not empty
run.go:130: removing dir "CompareDest" failed - try 3/3: directory not empty
run.go:133: removing dir "CompareDest" failed: 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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Not equal:
expected: []string{}
actual : []string{"CompareDest"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,3 @@
-([]string) {
+([]string) (len=1) {
+ (string) (len=11) "CompareDest"
}
Test: TestCopyFileCompareDest
Messages: directories
--- FAIL: TestCopyFileCompareDest (106.05s)
=== RUN TestCopyFileCopyDest
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 08:00:44 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/dst"
2026/02/02 08:00:46 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/CopyDest"
2026/02/02 08:00:48 DEBUG : one: Need to transfer - File not found at Destination
2026/02/02 08:00:51 DEBUG : one: size = 3 OK
2026/02/02 08:00:51 INFO : one: Copied (new)
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:292: Sleeping for 7s just to make sure
2026/02/02 08:01:05 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:01:05 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:01:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:01:05 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:01:05 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:01:05 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:01:05 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:01:05 DEBUG : pacer: low level retry 3/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:01:05 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 08:01:05 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:01:05 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:01:05 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 08:01:06 DEBUG : pacer: Reducing sleep to 80ms
2026/02/02 08:01:06 DEBUG : one: size = 5 (Local file system at /tmp/rclone142847565)
2026/02/02 08:01:06 DEBUG : one: size = 3 (drime root 'rclone-test-veqakub4xibu/dst')
2026/02/02 08:01:06 DEBUG : one: Sizes differ
2026/02/02 08:01:08 DEBUG : pacer: Reducing sleep to 40ms
2026/02/02 08:01:08 DEBUG : one: Removing old object on successful upload
2026/02/02 08:01:08 DEBUG : pacer: Reducing sleep to 20ms
2026/02/02 08:01:08 DEBUG : one: size = 5 OK
2026/02/02 08:01:08 INFO : one: Copied (replaced existing)
2026/02/02 08:01:12 DEBUG : dst/one: Removing old object on successful upload
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:292: Sleeping for 7s just to make sure
2026/02/02 08:01:30 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 08:01:30 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/BackupDir"
2026/02/02 08:01:31 DEBUG : one: size = 5 (Local file system at /tmp/rclone142847565)
2026/02/02 08:01:31 DEBUG : one: size = 3 (drime root 'rclone-test-veqakub4xibu/dst')
2026/02/02 08:01:31 DEBUG : one: Sizes differ
2026/02/02 08:01:32 DEBUG : one: size = 5 OK
2026/02/02 08:01:32 DEBUG : one: Sizes identical
2026/02/02 08:01:32 DEBUG : one: size = 5 (Local file system at /tmp/rclone142847565)
2026/02/02 08:01:32 DEBUG : one: size = 3 (drime root 'rclone-test-veqakub4xibu/dst')
2026/02/02 08:01:32 DEBUG : one: Sizes differ
2026/02/02 08:01:34 INFO : one: Moved (server-side)
2026/02/02 08:01:35 DEBUG : one: size = 5 OK
2026/02/02 08:01:35 INFO : one: Copied (server-side copy)
2026/02/02 08:01:35 DEBUG : one: Destination found in --copy-dest, using server-side copy
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:327
Error: Should be true
Test: TestCopyFileCopyDest
Messages: listing wrong, want
BackupDir/one (3), CopyDest/one (5), dst/one (5) got
BackupDir/one (3), CopyDest/one (5)
fstest.go:203: Not found "dst/one"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:327
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCopyDest
Messages: 1 objects not found
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:333
Error: Should be true
Test: TestCopyFileCopyDest
Messages: listing wrong, want
BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5) got
BackupDir/one (3), CopyDest/one (5), dst/one (5)
fstest.go:203: Not found "CopyDest/two"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:333
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCopyDest
Messages: 1 objects not found
2026/02/02 08:02:01 DEBUG : two: Need to transfer - File not found at Destination
2026/02/02 08:02:01 DEBUG : two: size = 3 OK
2026/02/02 08:02:01 DEBUG : two: Sizes identical
2026/02/02 08:02:03 DEBUG : two: size = 3 OK
2026/02/02 08:02:03 INFO : two: Copied (server-side copy)
2026/02/02 08:02:03 DEBUG : two: Destination found in --copy-dest, using server-side copy
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:342
Error: Should be true
Test: TestCopyFileCopyDest
Messages: listing wrong, want
BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5), dst/two (3) got
BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5)
fstest.go:203: Not found "dst/two"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:342
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCopyDest
Messages: 1 objects not found
2026/02/02 08:02:15 DEBUG : two: size = 3 OK
2026/02/02 08:02:15 DEBUG : two: Sizes identical
2026/02/02 08:02:15 DEBUG : two: 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:353
Error: Should be true
Test: TestCopyFileCopyDest
Messages: listing wrong, want
BackupDir/one (3), CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/two (3) got
BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5), dst/two (3)
fstest.go:203: Not found "CopyDest/three"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:353
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCopyDest
Messages: 1 objects not found
2026/02/02 08:02:30 DEBUG : three: Need to transfer - File not found at Destination
2026/02/02 08:02:30 DEBUG : three: size = 7 (Local file system at /tmp/rclone142847565)
2026/02/02 08:02:30 DEBUG : three: size = 5 (drime root 'rclone-test-veqakub4xibu/CopyDest')
2026/02/02 08:02:30 DEBUG : three: Sizes differ
2026/02/02 08:02:30 DEBUG : three: Destination not found in --copy-dest
2026/02/02 08:02:32 DEBUG : three: size = 7 OK
2026/02/02 08:02:32 INFO : three: Copied (new)
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:362
Error: Should be true
Test: TestCopyFileCopyDest
Messages: listing wrong, want
BackupDir/one (3), CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/three (7), dst/two (3) got
BackupDir/one (3), CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/two (3)
fstest.go:203: Not found "dst/three"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:362
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestCopyFileCopyDest
Messages: 1 objects not found
run.go:130: removing dir "dst" failed - try 1/3: directory not empty
run.go:130: removing dir "dst" failed - try 2/3: directory not empty
run.go:130: removing dir "dst" failed - try 3/3: directory not empty
run.go:133: removing dir "dst" failed: directory not empty
run.go:130: removing dir "CopyDest" failed - try 1/3: directory not empty
run.go:130: removing dir "CopyDest" failed - try 2/3: directory not empty
run.go:130: removing dir "CopyDest" failed - try 3/3: directory not empty
run.go:133: removing dir "CopyDest" failed: 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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Not equal:
expected: []string{}
actual : []string{"CopyDest", "dst"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,4 @@
-([]string) {
+([]string) (len=2) {
+ (string) (len=8) "CopyDest",
+ (string) (len=3) "dst"
}
Test: TestCopyFileCopyDest
Messages: directories
--- FAIL: TestCopyFileCopyDest (142.71s)
=== RUN TestListDirSortedFn
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", 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:292: Sleeping for 7s just to make sure
listdirsorted_test.go:57:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/listdirsorted_test.go:57
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/listdirsorted_test.go:125
Error: "[CopyDest a.txt dst sub dir zend.txt]" should have 3 item(s), but has 5
Test: TestListDirSortedFn
run.go:130: removing dir "sub dir/sub sub dir" failed - try 1/3: directory not empty
run.go:130: removing dir "sub dir/sub sub dir" failed - try 2/3: directory not empty
run.go:130: removing dir "sub dir/sub sub dir" failed - try 3/3: directory not empty
run.go:133: removing dir "sub dir/sub sub dir" failed: directory not empty
run.go:130: removing dir "sub dir/ignore dir" failed - try 1/3: directory not empty
run.go:130: removing dir "sub dir/ignore dir" failed - try 2/3: directory not empty
run.go:130: removing dir "sub dir/ignore dir" failed - try 3/3: directory not empty
run.go:133: removing dir "sub dir/ignore dir" failed: directory not empty
run.go:130: removing dir "sub dir" failed - try 1/3: directory not empty
run.go:130: removing dir "sub dir" failed - try 2/3: directory not empty
run.go:130: removing dir "sub dir" failed - try 3/3: directory not empty
run.go:133: removing dir "sub dir" failed: 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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
/usr/local/go/src/runtime/panic.go:636
/usr/local/go/src/testing/testing.go:1041
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/listdirsorted_test.go:57
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/listdirsorted_test.go:125
Error: Not equal:
expected: []string{}
actual : []string{"sub dir", "sub dir/ignore dir", "sub dir/sub sub dir"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,5 @@
-([]string) {
+([]string) (len=3) {
+ (string) (len=7) "sub dir",
+ (string) (len=18) "sub dir/ignore dir",
+ (string) (len=19) "sub dir/sub sub dir"
}
Test: TestListDirSortedFn
Messages: directories
--- FAIL: TestListDirSortedFn (60.98s)
=== RUN TestListJSON
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", 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:292: Sleeping for 7s just to make sure
=== RUN TestListJSON/Default
lsjson_test.go:202:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/lsjson_test.go:202
Error: Not equal:
expected: 2
actual : 3
Test: TestListJSON/Default
Messages: Wrong number of results
=== RUN TestListJSON/DirsOnly
lsjson_test.go:202:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/lsjson_test.go:202
Error: Not equal:
expected: 1
actual : 2
Test: TestListJSON/DirsOnly
Messages: Wrong number of results
=== RUN TestListJSON/Recurse
lsjson_test.go:202:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/lsjson_test.go:202
Error: Not equal:
expected: 3
actual : 6
Test: TestListJSON/Recurse
Messages: Wrong number of results
=== RUN TestListJSON/Metadata
lsjson_test.go:202:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/lsjson_test.go:202
Error: Not equal:
expected: 2
actual : 3
Test: TestListJSON/Metadata
Messages: Wrong number of results
2026/02/02 08:04:31 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:04:31 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:04:31 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:04:32 DEBUG : pacer: Reducing sleep to 10ms
=== NAME TestListJSON
run.go:130: removing dir "sub dir" failed - try 1/3: directory not empty
run.go:130: removing dir "sub dir" failed - try 2/3: directory not empty
run.go:130: removing dir "sub dir" failed - try 3/3: directory not empty
run.go:133: removing dir "sub dir" failed: directory not empty
2026/02/02 08:04:39 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:04:39 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:04:39 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:04:39 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:04:39 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:04:39 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:04:40 DEBUG : pacer: Reducing sleep to 20ms
run.go:130: removing dir "sub" failed - try 1/3: directory not empty
2026/02/02 08:04:41 DEBUG : pacer: Reducing sleep to 10ms
run.go:130: removing dir "sub" failed - try 2/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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Not equal:
expected: []string{}
actual : []string{"sub dir"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,3 @@
-([]string) {
+([]string) (len=1) {
+ (string) (len=7) "sub dir"
}
Test: TestListJSON
Messages: directories
--- FAIL: TestListJSON (46.93s)
--- FAIL: TestListJSON/Default (0.65s)
--- FAIL: TestListJSON/DirsOnly (0.58s)
--- FAIL: TestListJSON/Recurse (1.13s)
--- FAIL: TestListJSON/Metadata (0.41s)
=== RUN TestStatJSON
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 08:04:57 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:04:57 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:04:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:04:57 DEBUG : pacer: Reducing sleep to 10ms
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:292: Sleeping for 7s just to make sure
=== 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/02/02 08:05:18 DEBUG : Creating backend with remote "TestDrime:rclone-test-veqakub4xibu/notfound"
2026/02/02 08:05:19 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:05:19 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:05:19 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:05:20 DEBUG : pacer: Reducing sleep to 10ms
=== NAME TestStatJSON
run.go:130: removing dir "sub" failed - try 1/3: directory not empty
run.go:130: removing dir "sub" failed - try 2/3: directory not empty
run.go:130: removing dir "sub" failed - try 3/3: directory not empty
run.go:133: removing dir "sub" failed: directory not empty
2026/02/02 08:05:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:05:27 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:05:27 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:05:28 DEBUG : pacer: Reducing sleep to 10ms
fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
fstest.go:301: Flushing the directory cache
2026/02/02 08:05:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:05:30 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:05:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:05:31 DEBUG : pacer: Reducing sleep to 10ms
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:327:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
/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:1211
/usr/local/go/src/testing/testing.go:1445
/usr/local/go/src/testing/testing.go:1786
Error: Not equal:
expected: []string{}
actual : []string{"sub"}
Diff:
--- Expected
+++ Actual
@@ -1,2 +1,3 @@
-([]string) {
+([]string) (len=1) {
+ (string) (len=3) "sub"
}
Test: TestStatJSON
Messages: directories
--- FAIL: TestStatJSON (45.10s)
--- PASS: TestStatJSON/Root (0.56s)
--- PASS: TestStatJSON/RootFilesOnly (0.00s)
--- PASS: TestStatJSON/RootDirsOnly (0.37s)
--- PASS: TestStatJSON/Dir (0.99s)
--- PASS: TestStatJSON/DirWithTrailingSlash (0.31s)
--- PASS: TestStatJSON/File (0.52s)
--- PASS: TestStatJSON/NotFound (0.93s)
--- PASS: TestStatJSON/DirFilesOnly (0.36s)
--- PASS: TestStatJSON/FileFilesOnly (0.32s)
--- PASS: TestStatJSON/NotFoundFilesOnly (0.37s)
--- PASS: TestStatJSON/DirDirsOnly (0.57s)
--- PASS: TestStatJSON/FileDirsOnly (0.28s)
--- PASS: TestStatJSON/NotFoundDirsOnly (0.30s)
--- PASS: TestStatJSON/RootNotFound (1.97s)
=== RUN TestLsLong
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", 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
2026/02/02 08:05:51 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:05:51 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:05:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:05:52 DEBUG : pacer: Reducing sleep to 10ms
fstest.go:292: Sleeping for 7s just to make sure
--- PASS: TestLsLong (24.96s)
=== RUN TestHashSums
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 08:06:08 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:08 DEBUG : pacer: low level retry 1/1 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms
run.go:286: Retry Put of "empty space" to drime root 'rclone-test-veqakub4xibu': 1/10 (failed to upload file: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:10 DEBUG : pacer: Reducing sleep to 10ms
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:292: Sleeping for 7s just to make sure
2026/02/02 08:06:25 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:25 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:06:25 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:25 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:25 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:06:25 DEBUG : pacer: Reducing sleep to 20ms
2026/02/02 08:06:26 DEBUG : pacer: Reducing sleep to 10ms
fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
fstest.go:301: Flushing the directory cache
2026/02/02 08:06:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:27 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:27 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:06:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:27 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:27 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:06:28 DEBUG : pacer: Reducing sleep to 20ms
fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestHashSums (29.55s)
=== RUN TestMaxDelete
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 08:06:34 DEBUG : pacer: Reducing sleep to 10ms
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:447
Error: Should be true
Test: TestMaxDelete
Messages: listing wrong, want
large (100), medium (60), small (10) got
medium (60), small (10)
fstest.go:203: Not found "large"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/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:447
/usr/local/go/src/runtime/asm_amd64.s:1700
Error: Not equal:
expected: 0
actual : 1
Test: TestMaxDelete
Messages: 1 objects not found
2026/02/02 08:06:50 DEBUG : Waiting for deletions to finish
2026/02/02 08:06:51 ERROR : small: Got fatal error on delete: --max-delete threshold reached
2026/02/02 08:06:51 INFO : large: Deleted
2026/02/02 08:06:51 INFO : medium: Deleted
2026/02/02 08:06:51 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:51 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:06:52 DEBUG : pacer: Reducing sleep to 10ms
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
2026/02/02 08:06:52 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:06:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:06:53 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:06:53 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:06:53 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:06:53 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 08:06:53 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:53 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:53 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 08:06:53 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:53 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:53 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/02/02 08:06:54 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:06:54 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/02/02 08:06:54 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:06:54 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/02/02 08:06:55 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:06:55 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/02/02 08:06:56 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:06:56 DEBUG : pacer: low level retry 9/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:06:56 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/02/02 08:06:59 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
2026/02/02 08:06:59 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
run.go:130: removing file "large" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 08:07:04 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:07:04 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:07:14 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:07:34 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:07:55 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:08:14 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:08:14 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:08:34 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:08:54 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:09:14 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:09:34 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:09:54 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "large" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 08:10:14 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:10:35 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:10:54 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:11:14 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:11:34 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:11:55 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:12:14 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:12:35 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:12:54 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:12:54 DEBUG : pacer: low level retry 9/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:13:14 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "large" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing file "large" failed: failed to delete item: Error "Server Error"
2026/02/02 08:13:34 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:13:54 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:14:14 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:14:34 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:14:54 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:15:14 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:15:34 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:15:54 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:16:14 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:16:34 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "medium" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 08:16:55 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:17:14 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:17:14 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:17:34 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:17:54 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:18:14 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:18:34 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:18:54 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:19:14 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:19:34 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:19:54 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "medium" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 08:20:14 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:20:34 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:20:54 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:21:14 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:21:35 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:21:55 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:22:14 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:22:34 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:22:54 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:22:54 DEBUG : pacer: low level retry 9/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:23:14 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:23:14 DEBUG : pacer: low level retry 10/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
run.go:130: removing file "medium" failed - try 3/3: failed to delete item: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n"
run.go:133: removing file "medium" failed: failed to delete item: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n"
2026/02/02 08:23:34 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:23:34 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:23:54 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:23:54 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:24:14 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 08:24:34 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 08:24:44 DEBUG : pacer: Reducing sleep to 2.5s
2026/02/02 08:24:49 DEBUG : pacer: Reducing sleep to 1.25s
--- FAIL: TestMaxDelete (1095.52s)
=== RUN TestMaxDeleteSize
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 08:24:52 DEBUG : pacer: Reducing sleep to 625ms
2026/02/02 08:24:54 DEBUG : pacer: Reducing sleep to 312.5ms
2026/02/02 08:24:54 DEBUG : pacer: Reducing sleep to 156.25ms
2026/02/02 08:24:55 DEBUG : pacer: Reducing sleep to 78.125ms
2026/02/02 08:24:56 DEBUG : pacer: Reducing sleep to 39.0625ms
2026/02/02 08:24:57 DEBUG : pacer: Reducing sleep to 19.53125ms
2026/02/02 08:24:58 DEBUG : pacer: Reducing sleep to 10ms
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/02/02 08:25:05 DEBUG : Waiting for deletions to finish
2026/02/02 08:25:06 ERROR : small: Got fatal error on delete: --max-delete-size threshold reached
2026/02/02 08:25:06 INFO : medium: Deleted
2026/02/02 08:25:06 INFO : large: Deleted
2026/02/02 08:25:06 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:25:06 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:25:06 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:25:07 DEBUG : pacer: Reducing sleep to 10ms
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
2026/02/02 08:25:08 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:25:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:25:08 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:25:08 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:25:09 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:25:09 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 08:25:09 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:25:09 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 08:25:10 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:25:10 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/02/02 08:25:10 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:25:10 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/02/02 08:25:11 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:25:11 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/02/02 08:25:11 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:25:11 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/02/02 08:25:13 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:25:13 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/02/02 08:25:15 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
2026/02/02 08:25:15 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
run.go:130: removing file "large" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 08:25:20 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:25:20 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:25:30 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:25:51 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:26:11 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:26:31 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:26:51 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:27:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:27:10 DEBUG : pacer: low level retry 7/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:27:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:27:30 DEBUG : pacer: low level retry 8/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:27:51 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:28:10 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "large" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 08:28:30 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:28:50 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:29:10 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:29:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:29:30 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:29:50 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:30:10 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:30:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:30:30 DEBUG : pacer: low level retry 7/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:30:50 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:31:11 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:31:31 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "large" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing file "large" failed: failed to delete item: Error "Server Error"
2026/02/02 08:31:51 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:32:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:32:10 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:32:31 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:32:56 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:32:56 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:33:11 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:33:30 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:33:51 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:34:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:34:10 DEBUG : pacer: low level retry 8/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:34:31 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:34:51 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "medium" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 08:35:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:35:10 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:35:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:35:30 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:35:50 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:36:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:36:10 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:36:31 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:36:50 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:37:11 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:37:31 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:37:51 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:38:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:38:10 DEBUG : pacer: low level retry 10/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
run.go:130: removing file "medium" failed - try 2/3: failed to delete item: Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n"
2026/02/02 08:38:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:38:30 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:38:51 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:39:11 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:39:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:39:30 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:39:50 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:39:50 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:40:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:40:10 DEBUG : pacer: low level retry 6/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:40:31 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:40:50 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:41:11 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:41:30 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing file "medium" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing file "medium" failed: failed to delete item: Error "Server Error"
2026/02/02 08:41:51 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 08:42:11 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 08:42:21 DEBUG : pacer: Reducing sleep to 2.5s
2026/02/02 08:42:25 DEBUG : pacer: Reducing sleep to 1.25s
--- FAIL: TestMaxDeleteSize (1056.22s)
=== RUN TestRmdirsNoLeaveRoot
run.go:185: Remote "drime root 'rclone-test-veqakub4xibu'", Local "Local file system at /tmp/rclone142847565", Modify Window "876000h0m0s"
2026/02/02 08:42:28 DEBUG : pacer: Reducing sleep to 625ms
2026/02/02 08:42:29 DEBUG : pacer: Reducing sleep to 312.5ms
2026/02/02 08:42:30 DEBUG : pacer: Reducing sleep to 156.25ms
2026/02/02 08:42:30 DEBUG : pacer: Reducing sleep to 78.125ms
2026/02/02 08:42:31 DEBUG : pacer: Reducing sleep to 39.0625ms
2026/02/02 08:42:31 DEBUG : pacer: Reducing sleep to 19.53125ms
2026/02/02 08:42:32 DEBUG : pacer: Reducing sleep to 10ms
2026/02/02 08:42:34 INFO : A2: Making directory
2026/02/02 08:42:35 INFO : A1/B2: Making directory
2026/02/02 08:42:35 INFO : A1/B2/C2: Making directory
2026/02/02 08:42:36 INFO : A1/B1/C3: Making directory
2026/02/02 08:42:37 INFO : A3: Making directory
2026/02/02 08:42:37 INFO : A3/B3: Making directory
2026/02/02 08:42:38 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: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/fs/operations/operations_test.go:662
Error: Should be true
Test: TestRmdirsNoLeaveRoot
Messages: listing wrong, want
A1/B1/C1/one (3), A1/two (3) got
A1/B1/C1/one (3)
fstest.go:203: Not found "A1/two"
fstest.go:206:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310
/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338
/home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:662
Error: Not equal:
expected: 0
actual : 1
Test: TestRmdirsNoLeaveRoot
Messages: 1 objects not found
2026/02/02 08:42:54 DEBUG : removing 1 level 3 directories
2026/02/02 08:42:54 INFO : A3/B3/C4: Removing directory
2026/02/02 08:42:58 DEBUG : removing 2 level 3 directories
2026/02/02 08:42:58 INFO : A1/B2/C2: Removing directory
2026/02/02 08:42:58 INFO : A1/B1/C3: Removing directory
2026/02/02 08:42:59 DEBUG : removing 2 level 2 directories
2026/02/02 08:42:59 INFO : A3/B3: Removing directory
2026/02/02 08:42:59 INFO : A1/B2: Removing directory
2026/02/02 08:42:59 ERROR : A1/B2: Failed to rmdir: directory not empty
2026/02/02 08:42:59 DEBUG : removing 2 level 1 directories
2026/02/02 08:42:59 INFO : A3: Removing directory
2026/02/02 08:42:59 INFO : A2: Removing directory
2026/02/02 08:42:59 ERROR : A3: Failed to rmdir: directory not empty
operations_test.go:705:
Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:705
Error: Received unexpected error:
failed to remove directories: 2 errors: last error: directory not empty
Test: TestRmdirsNoLeaveRoot
2026/02/02 08:43:03 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:43:03 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/02/02 08:43:03 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:43:03 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/02/02 08:43:04 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:43:04 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/02/02 08:43:04 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:43:04 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/02/02 08:43:04 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:43:04 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/02/02 08:43:04 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:43:04 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/02/02 08:43:05 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:43:05 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/02/02 08:43:05 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:43:05 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/02/02 08:43:07 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:43:07 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/02/02 08:43:09 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
2026/02/02 08:43:09 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
run.go:130: removing dir "A3/B3" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 08:43:14 DEBUG : pacer: Reducing sleep to 5.12s
2026/02/02 08:43:25 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:43:25 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2026/02/02 08:43:29 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 08:43:29 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 08:43:29 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:43:40 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:44:00 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:44:20 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:44:40 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:45:00 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:45:20 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:45:40 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:46:00 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A3/B3" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 08:46:20 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 08:46:40 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:46:40 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:46:50 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:47:10 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:47:30 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:47:50 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:48:10 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:48:30 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:48:50 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:49:10 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:49:30 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A3/B3" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing dir "A3/B3" failed: failed to delete item: Error "Server Error"
2026/02/02 08:49:50 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 08:50:10 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 08:50:20 DEBUG : pacer: Reducing sleep to 2.5s
2026/02/02 08:50:25 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:50:25 DEBUG : pacer: Rate limited, increasing sleep to 5s
2026/02/02 08:50:28 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:50:28 DEBUG : pacer: Rate limited, increasing sleep to 10s
2026/02/02 08:50:33 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:50:33 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:50:43 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:51:03 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:51:22 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:51:43 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:52:03 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:52:23 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:52:42 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A2" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 08:53:03 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 08:53:23 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:53:23 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:53:33 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:53:52 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:54:13 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:54:33 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:54:53 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:55:13 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:55:33 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:55:53 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:56:13 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A2" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 08:56:33 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 08:56:53 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 08:56:53 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 08:57:03 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 08:57:23 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 08:57:43 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 08:58:03 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 08:58:23 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 08:58:43 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 08:59:03 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 08:59:23 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 08:59:43 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A2" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing dir "A2" failed: failed to delete item: Error "Server Error"
2026/02/02 09:00:03 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:00:23 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 09:00:23 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:00:33 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 09:00:53 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 09:01:12 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:01:12 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:01:33 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 09:01:52 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:01:52 DEBUG : pacer: low level retry 6/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:02:13 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 09:02:33 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 09:02:53 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 09:03:13 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A1/B2/C2" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 09:03:32 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:03:32 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:03:52 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:03:52 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:04:13 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:04:32 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:04:32 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:04:32 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:04:43 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 09:05:03 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 09:05:22 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:05:22 DEBUG : pacer: low level retry 4/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:05:43 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 09:06:03 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 09:06:23 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 09:06:43 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 09:07:02 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 09:07:23 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A1/B2/C2" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 09:07:43 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:08:02 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:08:02 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:08:02 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:08:12 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 09:08:33 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 09:08:53 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 09:09:13 DEBUG : pacer: low level retry 5/10 (error Error "Server Error")
2026/02/02 09:09:33 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 09:09:52 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:09:52 DEBUG : pacer: low level retry 7/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:10:12 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 09:10:33 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 09:10:53 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A1/B2/C2" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing dir "A1/B2/C2" failed: failed to delete item: Error "Server Error"
2026/02/02 09:11:13 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:11:33 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 09:11:43 DEBUG : pacer: Reducing sleep to 2.5s
2026/02/02 09:11:47 DEBUG : pacer: low level retry 1/10 (error Error "Server Error")
2026/02/02 09:11:47 DEBUG : pacer: Rate limited, increasing sleep to 5s
2026/02/02 09:11:50 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:11:50 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:11:50 DEBUG : pacer: Rate limited, increasing sleep to 10s
2026/02/02 09:11:55 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 09:11:55 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:12:05 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 09:12:25 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:12:25 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:12:45 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 09:13:05 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:13:05 DEBUG : pacer: low level retry 7/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:13:25 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 09:13:45 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 09:14:05 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A1/B1/C3" failed - try 1/3: failed to delete item: Error "Server Error"
2026/02/02 09:14:25 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:14:45 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:14:45 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:14:45 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:14:55 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 09:15:15 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:15:15 DEBUG : pacer: low level retry 3/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:15:35 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 09:15:55 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:15:55 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:16:15 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 09:16:35 DEBUG : pacer: low level retry 7/10 (error Error "Server Error")
2026/02/02 09:16:55 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 09:17:15 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 09:17:35 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A1/B1/C3" failed - try 2/3: failed to delete item: Error "Server Error"
2026/02/02 09:17:55 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:18:15 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:18:15 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:18:15 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:18:25 DEBUG : pacer: low level retry 2/10 (error Error "Server Error")
2026/02/02 09:18:45 DEBUG : pacer: low level retry 3/10 (error Error "Server Error")
2026/02/02 09:19:05 DEBUG : pacer: low level retry 4/10 (error Error "Server Error")
2026/02/02 09:19:25 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:19:25 DEBUG : pacer: low level retry 5/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:19:45 DEBUG : pacer: low level retry 6/10 (error Error "Server Error")
2026/02/02 09:20:05 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:20:05 DEBUG : pacer: low level retry 7/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:20:25 DEBUG : pacer: low level retry 8/10 (error Error "Server Error")
2026/02/02 09:20:45 DEBUG : pacer: low level retry 9/10 (error Error "Server Error")
2026/02/02 09:21:06 DEBUG : pacer: low level retry 10/10 (error Error "Server Error")
run.go:130: removing dir "A1/B1/C3" failed - try 3/3: failed to delete item: Error "Server Error"
run.go:133: removing dir "A1/B1/C3" failed: failed to delete item: Error "Server Error"
2026/02/02 09:21:25 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:21:45 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 09:21:55 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:21:55 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:21:55 DEBUG : pacer: Rate limited, increasing sleep to 10s
2026/02/02 09:22:00 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:22:00 DEBUG : pacer: low level retry 2/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:22:00 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/02/02 09:22:10 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:22:10 DEBUG : pacer: low level retry 3/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:22:30 DEBUG : pacer: Reducing sleep to 10s
2026/02/02 09:22:50 DEBUG : pacer: Reducing sleep to 5s
2026/02/02 09:23:01 DEBUG : pacer: Reducing sleep to 2.5s
2026/02/02 09:23:05 DEBUG : pacer: Reducing sleep to 1.25s
2026/02/02 09:23:08 DEBUG : pacer: Reducing sleep to 625ms
--- FAIL: TestRmdirsNoLeaveRoot (2442.24s)
FAIL
2026/02/02 09:23:08 DEBUG : drime root 'rclone-test-veqakub4xibu': Purge remote
2026/02/02 09:23:09 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/02/02 09:23:09 DEBUG : pacer: low level retry 1/10 (error Error "500 Internal Server Error (500): \r\n500 Internal Server Error\r\n\r\n500 Internal Server Error
\r\n
nginx\r\n\r\n\r\n")
2026/02/02 09:23:09 DEBUG : pacer: Rate limited, increasing sleep to 1.25s
2026/02/02 09:23:10 DEBUG : pacer: Reducing sleep to 625ms
"./operations.test -test.v -test.timeout 2h0m0s -remote TestDrime: -verbose -test.run '^(TestApplyTransforms|TestCheckSumDownload|TestCopyFile|TestCopyFileCompareDest|TestCopyFileCopyDest|TestHashSums|TestListDirSortedFn|TestLsLong|TestMaxDelete|TestMaxDeleteSize|TestParseSumFile|TestRmdirsNoLeaveRoot|TestStatJSON)$|^TestListJSON$/^(Default|DirsOnly|Metadata|Recurse)$|^TestMultithreadCopy$/^(upload=false,size=10485759,streams=2|upload=true,size=10485759,streams=2|upload=true,size=10485760,streams=2|upload=true,size=10485761,streams=2)$'" - Finished ERROR in 1h44m31.518584445s (try 5/5): exit status 1: Failed [TestMultithreadCopy/upload=false,size=10485759,streams=2 TestMultithreadCopy/upload=true,size=10485759,streams=2 TestMultithreadCopy/upload=true,size=10485760,streams=2 TestMultithreadCopy/upload=true,size=10485761,streams=2 TestParseSumFile TestCheckSumDownload TestApplyTransforms TestCopyFile TestCopyFileCompareDest TestCopyFileCopyDest TestListDirSortedFn TestListJSON/Default TestListJSON/DirsOnly TestListJSON/Recurse TestListJSON/Metadata TestStatJSON TestMaxDelete TestMaxDeleteSize TestRmdirsNoLeaveRoot]