"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCopyFileCompareDest|TestIndexChanged)$'" - Starting (try 3/5)
2026/10/06 06:49:39 DEBUG : Creating backend with remote "TestDropbox:rclone-test-cerowug4nexi"
2026/10/06 06:49:39 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/10/06 06:49:39 DEBUG : Creating backend with remote "/tmp/rclone3799338709"
=== RUN   TestCopyFileCompareDest
    run.go:198: Remote "Dropbox root 'rclone-test-cerowug4nexi'", Local "Local file system at /tmp/rclone3799338709", Modify Window "1s"
2026/10/06 06:49:39 DEBUG : Creating backend with remote "TestDropbox:rclone-test-cerowug4nexi/dst"
2026/10/06 06:49:40 DEBUG : Creating backend with remote "TestDropbox:rclone-test-cerowug4nexi/CompareDest"
2026/10/06 06:49:40 DEBUG : one: Need to transfer - File not found at Destination
2026/10/06 06:49:41 DEBUG : one: Uploading chunk 1/1
2026/10/06 06:49:42 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Adding "one" to batch
2026/10/06 06:49:42 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Batch idle for 500ms so committing
2026/10/06 06:49:42 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Committing sync batch length 1 starting with: one
2026/10/06 06:49:43 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Committed sync batch length 1 starting with: one
2026/10/06 06:49:43 DEBUG : one: size = 3 OK
2026/10/06 06:49:43 DEBUG : one: dropbox = fe8d7a873dc48961a6af334c996b2cb3ce37149d5ce9c9253952a54c6a92c1ad OK
2026/10/06 06:49:43 INFO  : one: Copied (new)
2026/10/06 06:49:44 DEBUG : one: size = 5 (Local file system at /tmp/rclone3799338709)
2026/10/06 06:49:44 DEBUG : one: size = 3 (Dropbox root 'rclone-test-cerowug4nexi/dst')
2026/10/06 06:49:44 DEBUG : one: Sizes differ
2026/10/06 06:49:45 DEBUG : one: Uploading chunk 1/1
2026/10/06 06:49:46 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Adding "one" to batch
2026/10/06 06:49:46 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Batch idle for 500ms so committing
2026/10/06 06:49:46 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Committing sync batch length 1 starting with: one
2026/10/06 06:49:47 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Committed sync batch length 1 starting with: one
2026/10/06 06:49:47 DEBUG : one: size = 5 OK
2026/10/06 06:49:47 DEBUG : one: dropbox = 7da8d117f9fb226817d81adc15c72720c9879c8b7fb821d27f217d198bd79d0d OK
2026/10/06 06:49:47 INFO  : one: Copied (replaced existing)
2026/10/06 06:49:49 DEBUG : dst/one: Uploading chunk 1/1
2026/10/06 06:49:49 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "dst/one" to batch
2026/10/06 06:49:50 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:49:50 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: dst/one
2026/10/06 06:49:51 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: dst/one
2026/10/06 06:49:51 DEBUG : CompareDest/one: Uploading chunk 1/1
2026/10/06 06:49:52 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "CompareDest/one" to batch
2026/10/06 06:49:52 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:49:52 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: CompareDest/one
2026/10/06 06:49:53 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: CompareDest/one
2026/10/06 06:49:54 DEBUG : one: size = 5 (Local file system at /tmp/rclone3799338709)
2026/10/06 06:49:54 DEBUG : one: size = 3 (Dropbox root 'rclone-test-cerowug4nexi/dst')
2026/10/06 06:49:54 DEBUG : one: Sizes differ
2026/10/06 06:49:54 DEBUG : one: size = 5 OK
2026/10/06 06:49:54 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2026/10/06 06:49:54 DEBUG : one: Destination found in --compare-dest, skipping
2026/10/06 06:49:56 DEBUG : CompareDest/two: Uploading chunk 1/1
2026/10/06 06:49:56 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "CompareDest/two" to batch
2026/10/06 06:49:57 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:49:57 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: CompareDest/two
2026/10/06 06:49:58 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: CompareDest/two
2026/10/06 06:49:59 DEBUG : two: Need to transfer - File not found at Destination
2026/10/06 06:49:59 DEBUG : two: size = 3 OK
2026/10/06 06:49:59 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2026/10/06 06:49:59 DEBUG : two: Destination found in --compare-dest, skipping
2026/10/06 06:50:00 DEBUG : two: Need to transfer - File not found at Destination
2026/10/06 06:50:00 DEBUG : two: size = 3 OK
2026/10/06 06:50:00 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2026/10/06 06:50:00 DEBUG : two: Destination found in --compare-dest, skipping
2026/10/06 06:50:01 DEBUG : two: Need to transfer - File not found at Destination
2026/10/06 06:50:02 DEBUG : two: size = 5 (Local file system at /tmp/rclone3799338709)
2026/10/06 06:50:02 DEBUG : two: size = 3 (Dropbox root 'rclone-test-cerowug4nexi/CompareDest')
2026/10/06 06:50:02 DEBUG : two: Sizes differ
2026/10/06 06:50:02 DEBUG : two: Uploading chunk 1/1
2026/10/06 06:50:03 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Adding "two" to batch
2026/10/06 06:50:03 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Batch idle for 500ms so committing
2026/10/06 06:50:03 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Committing sync batch length 1 starting with: two
2026/10/06 06:50:04 DEBUG : Dropbox root 'rclone-test-cerowug4nexi/dst': Committed sync batch length 1 starting with: two
2026/10/06 06:50:04 DEBUG : two: size = 5 OK
2026/10/06 06:50:04 DEBUG : two: dropbox = 25e70b9a05696acbcc5bd6fa74ba6fa580c9a58960a02390ae1d2f71d21c0378 OK
2026/10/06 06:50:04 INFO  : two: Copied (new)
2026/10/06 06:50:10 INFO  : Dropbox root 'rclone-test-cerowug4nexi/CompareDest': Committing uploads - please wait...
--- PASS: TestCopyFileCompareDest (30.38s)
=== RUN   TestIndexChanged
    run.go:198: Remote "Dropbox root 'rclone-test-cerowug4nexi'", Local "Local file system at /tmp/rclone3799338709", Modify Window "1s"
2026/10/06 06:50:10 DEBUG : file1.txt: Uploading chunk 1/1
2026/10/06 06:50:11 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "file1.txt" to batch
2026/10/06 06:50:11 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:11 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: file1.txt
2026/10/06 06:50:12 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: file1.txt
2026/10/06 06:50:13 DEBUG : sub/file2.txt: Uploading chunk 1/1
2026/10/06 06:50:14 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "sub/file2.txt" to batch
2026/10/06 06:50:14 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:14 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: sub/file2.txt
2026/10/06 06:50:15 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: sub/file2.txt
2026/10/06 06:50:15 DEBUG : sub/deep/file3.txt: Uploading chunk 1/1
2026/10/06 06:50:16 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "sub/deep/file3.txt" to batch
2026/10/06 06:50:17 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:17 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: sub/deep/file3.txt
2026/10/06 06:50:17 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: sub/deep/file3.txt
2026/10/06 06:50:18 DEBUG : other/notes.md: Uploading chunk 1/1
2026/10/06 06:50:18 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "other/notes.md" to batch
2026/10/06 06:50:19 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:19 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: other/notes.md
2026/10/06 06:50:20 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: other/notes.md
2026/10/06 06:50:21 DEBUG : sub/index.html: Uploading chunk 1/1
2026/10/06 06:50:21 DEBUG : index.html: Uploading chunk 1/1
2026/10/06 06:50:21 DEBUG : sub/deep/index.html: Uploading chunk 1/1
2026/10/06 06:50:21 DEBUG : other/index.html: Uploading chunk 1/1
2026/10/06 06:50:22 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "sub/index.html" to batch
2026/10/06 06:50:22 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "sub/deep/index.html" to batch
2026/10/06 06:50:22 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "other/index.html" to batch
2026/10/06 06:50:22 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "index.html" to batch
2026/10/06 06:50:22 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 4 starting with: sub/index.html
2026/10/06 06:50:23 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 4 starting with: sub/index.html
2026/10/06 06:50:23 DEBUG : index.html: size = 12399 OK
2026/10/06 06:50:23 DEBUG : other/index.html: size = 12058 OK
2026/10/06 06:50:23 DEBUG : sub/deep/index.html: size = 12087 OK
2026/10/06 06:50:23 DEBUG : index.html: dropbox = ca2f84ca2766b1aed6bb481ae7cab49b9025fb858141d5a13842e1c41f6b7d03 OK
2026/10/06 06:50:23 INFO  : index.html: Copied (new)
2026/10/06 06:50:23 DEBUG : other/index.html: dropbox = 1ae2146ba858aa1424e8aeb6f00209524ac75389d5e7a1fdbf59822428a12e96 OK
2026/10/06 06:50:23 INFO  : other/index.html: Copied (new)
2026/10/06 06:50:23 DEBUG : sub/deep/index.html: dropbox = 0ee72e3df4e9bb9fd491368d80a36324b5b0ffcc1e5ea68cd6bba3a5971b6b88 OK
2026/10/06 06:50:23 INFO  : sub/deep/index.html: Copied (new)
2026/10/06 06:50:23 DEBUG : sub/index.html: size = 12306 OK
2026/10/06 06:50:23 DEBUG : sub/index.html: dropbox = 024fd48ca7491f057385871eaf715a7ffcc2b1afc78d53c598b4294cc1dca003 OK
2026/10/06 06:50:23 INFO  : sub/index.html: Copied (new)
2026/10/06 06:50:23 DEBUG : sub/deep/file4.txt: Uploading chunk 1/1
2026/10/06 06:50:24 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "sub/deep/file4.txt" to batch
2026/10/06 06:50:25 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:25 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: sub/deep/file4.txt
2026/10/06 06:50:25 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: sub/deep/file4.txt
2026/10/06 06:50:26 DEBUG : other/undeclared.txt: Uploading chunk 1/1
2026/10/06 06:50:26 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "other/undeclared.txt" to batch
2026/10/06 06:50:27 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:27 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: other/undeclared.txt
2026/10/06 06:50:28 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committed sync batch length 1 starting with: other/undeclared.txt
2026/10/06 06:50:28 INFO  : Dropbox root 'rclone-test-cerowug4nexi': Partial index: listing 3 directories and walking 0 changed directories
2026/10/06 06:50:29 DEBUG : index.html: dropbox = ca2f84ca2766b1aed6bb481ae7cab49b9025fb858141d5a13842e1c41f6b7d03 OK
2026/10/06 06:50:29 DEBUG : index.html: Unchanged skipping
2026/10/06 06:50:29 DEBUG : sub/index.html: dropbox = 024fd48ca7491f057385871eaf715a7ffcc2b1afc78d53c598b4294cc1dca003 OK
2026/10/06 06:50:29 DEBUG : sub/index.html: Unchanged skipping
2026/10/06 06:50:29 DEBUG : sub/deep/index.html: Uploading chunk 1/1
2026/10/06 06:50:30 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Adding "sub/deep/index.html" to batch
2026/10/06 06:50:30 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Batch idle for 500ms so committing
2026/10/06 06:50:30 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Committing sync batch length 1 starting with: sub/deep/index.html
2026/10/06 06:50:32 ERROR : Dropbox root 'rclone-test-cerowug4nexi': sync batch commit: failed to commit batch length 1: batch had 1 errors: last error: upload failed: too_many_write_operations
2026/10/06 06:50:32 ERROR : sub/deep/index.html: Failed to copy: upload failed: batch upload failed: upload failed: too_many_write_operations
2026/10/06 06:50:32 ERROR : sub/deep/index.html: Failed to write listing: upload failed: batch upload failed: upload failed: too_many_write_operations
    index_test.go:55: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/index_test.go:55
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/operations/index_test.go:401
        	Error:      	Received unexpected error:
        	            	index: upload failed: batch upload failed: upload failed: too_many_write_operations
        	Test:       	TestIndexChanged
2026/10/06 06:50:35 NOTICE: Error too_many_requests/... Too many requests or write operations. Trying again in 10 seconds.
2026/10/06 06:50:35 DEBUG : pacer: low level retry 1/10 (error too_many_requests/..: trying again in 10s)
2026/10/06 06:50:35 DEBUG : pacer: Rate limited, increasing sleep to 10s
2026/10/06 06:50:36 NOTICE: Error too_many_requests/... Too many requests or write operations. Trying again in 10 seconds.
2026/10/06 06:50:36 DEBUG : pacer: low level retry 2/10 (error too_many_requests/..: trying again in 10s)
2026/10/06 06:50:46 DEBUG : pacer: Reducing sleep to 7.5s
2026/10/06 06:50:56 DEBUG : pacer: Reducing sleep to 5.625s
2026/10/06 06:51:04 DEBUG : pacer: Reducing sleep to 4.21875s
2026/10/06 06:51:09 DEBUG : pacer: Reducing sleep to 3.1640625s
2026/10/06 06:51:13 DEBUG : pacer: Reducing sleep to 2.373046875s
2026/10/06 06:51:16 DEBUG : pacer: Reducing sleep to 1.779785156s
2026/10/06 06:51:19 DEBUG : pacer: Reducing sleep to 1.334838867s
2026/10/06 06:51:20 DEBUG : pacer: Reducing sleep to 1.00112915s
2026/10/06 06:51:22 DEBUG : pacer: Reducing sleep to 750.846862ms
2026/10/06 06:51:23 DEBUG : pacer: Reducing sleep to 563.135146ms
2026/10/06 06:51:24 DEBUG : pacer: Reducing sleep to 422.351359ms
2026/10/06 06:51:24 DEBUG : pacer: Reducing sleep to 316.763519ms
2026/10/06 06:51:25 DEBUG : pacer: Reducing sleep to 237.572639ms
2026/10/06 06:51:25 DEBUG : pacer: Reducing sleep to 178.179479ms
--- FAIL: TestIndexChanged (75.34s)
FAIL
2026/10/06 06:51:25 DEBUG : Dropbox root 'rclone-test-cerowug4nexi': Purge remote
2026/10/06 06:51:26 DEBUG : pacer: Reducing sleep to 133.634609ms
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCopyFileCompareDest|TestIndexChanged)$'" - Finished ERROR in 1m46.633750796s (try 3/5): exit status 1: Failed [TestIndexChanged]