"./operations.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^(TestDirMove|TestMkdirModTime|TestRemoveExisting|TestRmdirsLeaveRoot|TestRmdirsNoLeaveRoot|TestRmdirsWithFilter)$'" - Starting (try 2/5) 2024/11/20 01:18:33 DEBUG : Creating backend with remote "TestGoFile:rclone-test-zuxihax0zaga" 2024/11/20 01:18:33 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/11/20 01:18:35 DEBUG : Creating backend with remote "/tmp/rclone1747149550" === RUN TestRmdirsNoLeaveRoot run.go:180: Remote "gofile root 'rclone-test-zuxihax0zaga'", Local "Local file system at /tmp/rclone1747149550", Modify Window "1s" 2024/11/20 01:18:42 DEBUG : Upload server store4 (eu) responded in 125.346493ms 2024/11/20 01:18:42 DEBUG : Upload server store10 (eu) responded in 130.32557ms 2024/11/20 01:18:42 DEBUG : A1/B1/C1/one: Using upload server store4 (eu) 2024/11/20 01:18:43 DEBUG : A2: Making directory 2024/11/20 01:18:44 DEBUG : A1/B2: Making directory 2024/11/20 01:18:46 DEBUG : A1/B2/C2: Making directory 2024/11/20 01:18:47 DEBUG : A1/B1/C3: Making directory 2024/11/20 01:18:48 DEBUG : A3: Making directory 2024/11/20 01:18:49 DEBUG : A3/B3: Making directory 2024/11/20 01:18:49 DEBUG : A3/B3/C4: Making directory 2024/11/20 01:18:50 DEBUG : A1/two: Using upload server store4 (eu) 2024/11/20 01:18:53 DEBUG : removing 1 level 3 directories 2024/11/20 01:18:53 INFO : A3/B3/C4: Removing directory 2024/11/20 01:18:59 DEBUG : removing 2 level 3 directories 2024/11/20 01:18:59 INFO : A1/B2/C2: Removing directory 2024/11/20 01:18:59 INFO : A1/B1/C3: Removing directory 2024/11/20 01:19:00 DEBUG : removing 2 level 2 directories 2024/11/20 01:19:00 INFO : A3/B3: Removing directory 2024/11/20 01:19:00 INFO : A1/B2: Removing directory 2024/11/20 01:19:01 DEBUG : removing 2 level 1 directories 2024/11/20 01:19:01 INFO : A3: Removing directory 2024/11/20 01:19:01 INFO : A2: Removing directory 2024/11/20 01:19:07 DEBUG : removing 1 level 3 directories 2024/11/20 01:19:07 INFO : A1/B1/C1: Removing directory 2024/11/20 01:19:07 DEBUG : removing 1 level 2 directories 2024/11/20 01:19:07 INFO : A1/B1: Removing directory fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:730 Error: Not equal: expected: []string{} actual : []string{"A1"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=2) "A1" } Test: TestRmdirsNoLeaveRoot Messages: directories --- FAIL: TestRmdirsNoLeaveRoot (47.33s) === RUN TestRmdirsLeaveRoot run.go:180: Remote "gofile root 'rclone-test-zuxihax0zaga'", Local "Local file system at /tmp/rclone1747149550", Modify Window "1s" 2024/11/20 01:19:22 DEBUG : A1: Making directory 2024/11/20 01:19:23 DEBUG : A1/B1: Making directory 2024/11/20 01:19:24 DEBUG : A1/B1/C1: Making directory fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure 2024/11/20 01:19:34 DEBUG : removing 1 level 3 directories 2024/11/20 01:19:34 INFO : A1/B1/C1: Removing directory 2024/11/20 01:19:35 DEBUG : removing 1 level 2 directories 2024/11/20 01:19:35 INFO : A1/B1: Removing directory fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure --- PASS: TestRmdirsLeaveRoot (23.74s) === RUN TestRmdirsWithFilter run.go:180: Remote "gofile root 'rclone-test-zuxihax0zaga'", Local "Local file system at /tmp/rclone1747149550", Modify Window "1s" 2024/11/20 01:19:46 DEBUG : A1: Making directory 2024/11/20 01:19:47 DEBUG : A1/B1: Making directory 2024/11/20 01:19:48 DEBUG : A1/B1/C1: Making directory operations_test.go:787: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:787 Error: Received unexpected error: directory not found Test: TestRmdirsWithFilter run.go:125: removing dir "A1" failed - try 1/3: directory not empty --- FAIL: TestRmdirsWithFilter (6.94s) === RUN TestDirMove run.go:180: Remote "gofile root 'rclone-test-zuxihax0zaga'", Local "Local file system at /tmp/rclone1747149550", Modify Window "1s" 2024/11/20 01:19:55 DEBUG : Upload server store1 (eu) responded in 129.177863ms 2024/11/20 01:19:55 DEBUG : Upload server store10 (eu) responded in 133.216172ms 2024/11/20 01:19:55 DEBUG : A1/one: Using upload server store1 (eu) 2024/11/20 01:19:56 DEBUG : A1/two: Using upload server store10 (eu) 2024/11/20 01:19:58 DEBUG : A1/B1/three: Using upload server store1 (eu) 2024/11/20 01:19:59 DEBUG : A1/B1/C1/four: Using upload server store1 (eu) 2024/11/20 01:20:01 DEBUG : A1/B1/C2/five: Using upload server store10 (eu) 2024/11/20 01:20:01 DEBUG : Couldn't decode error response: invalid character 'e' looking for beginning of value 2024/11/20 01:20:01 DEBUG : pacer: low level retry 1/1 (error Error "500 Internal Server Error (500): error-query\n") 2024/11/20 01:20:01 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2024/11/20 01:20:01 DEBUG : gofile root 'rclone-test-zuxihax0zaga': Clearing upload servers run.go:281: Retry Put of "A1/B1/C2/five" to gofile root 'rclone-test-zuxihax0zaga': 1/10 (failed to upload file: Error "500 Internal Server Error (500): error-query\n") 2024/11/20 01:20:04 DEBUG : pacer: Reducing sleep to 10ms 2024/11/20 01:20:04 DEBUG : Upload server store1 (eu) responded in 37.832328ms 2024/11/20 01:20:04 DEBUG : Upload server store10 (eu) responded in 37.88194ms 2024/11/20 01:20:04 DEBUG : A1/B1/C2/five: Using upload server store1 (eu) 2024/11/20 01:20:04 DEBUG : Upload server store4 (eu) responded in 37.850151ms 2024/11/20 01:20:04 DEBUG : A1/B2: Making directory 2024/11/20 01:20:06 DEBUG : A1/B1/C3: Making directory 2024/11/20 01:20:23 DEBUG : Rate limited, sleep for 5s 2024/11/20 01:20:23 DEBUG : Rate limited, sleep for 5s 2024/11/20 01:20:23 INFO : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five 2024/11/20 01:20:23 INFO : A2/one: Moved (server-side) to: A3/one 2024/11/20 01:20:24 INFO : A2/two: Moved (server-side) to: A3/two 2024/11/20 01:20:28 DEBUG : pacer: low level retry 1/10 (error Error "error-rateLimit") 2024/11/20 01:20:28 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2024/11/20 01:20:28 DEBUG : pacer: low level retry 1/10 (error Error "error-rateLimit") 2024/11/20 01:20:28 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2024/11/20 01:20:28 DEBUG : Rate limited, sleep for 5s 2024/11/20 01:20:28 DEBUG : Rate limited, sleep for 5s 2024/11/20 01:20:33 DEBUG : pacer: low level retry 2/10 (error Error "error-rateLimit") 2024/11/20 01:20:33 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2024/11/20 01:20:33 DEBUG : pacer: low level retry 2/10 (error Error "error-rateLimit") 2024/11/20 01:20:33 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2024/11/20 01:20:33 DEBUG : Rate limited, sleep for 5s 2024/11/20 01:20:34 DEBUG : pacer: Reducing sleep to 80ms 2024/11/20 01:20:34 INFO : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four 2024/11/20 01:20:38 DEBUG : pacer: low level retry 3/10 (error Error "error-rateLimit") 2024/11/20 01:20:38 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2024/11/20 01:20:39 DEBUG : pacer: Reducing sleep to 80ms 2024/11/20 01:20:39 INFO : A2/B1/three: Moved (server-side) to: A3/B1/three 2024/11/20 01:20:39 DEBUG : pacer: Reducing sleep to 40ms 2024/11/20 01:20:39 DEBUG : pacer: Reducing sleep to 20ms 2024/11/20 01:20:40 DEBUG : pacer: Reducing sleep to 10ms 2024/11/20 01:20:45 INFO : gofile root 'rclone-test-zuxihax0zaga': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes operations_test.go:1433: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1433 Error: Received unexpected error: RenameDir mkdir: directory not found Test: TestDirMove fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Should be true Test: TestDirMove Messages: listing wrong, want A4/B1/C1/four (4), A4/B1/C2/five (4), A4/B1/three (5), A4/one (3), A4/two (3) got A3/B1/C1/four (4), A3/B1/C2/five (4), A3/B1/three (5), A3/one (3), A3/two (3) fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Should be true Test: TestDirMove Messages: Unexpected file "A3/B1/three" fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Should be true Test: TestDirMove Messages: Unexpected file "A3/B1/C2/five" fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Should be true Test: TestDirMove Messages: Unexpected file "A3/B1/C1/four" fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Should be true Test: TestDirMove Messages: Unexpected file "A3/two" fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Should be true Test: TestDirMove Messages: Unexpected file "A3/one" fstest.go:197: Not found "A4/one" fstest.go:197: Not found "A4/two" fstest.go:197: Not found "A4/B1/three" fstest.go:197: Not found "A4/B1/C1/four" fstest.go:197: Not found "A4/B1/C2/five" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Not equal: expected: 0 actual : 5 Test: TestDirMove Messages: 5 objects not found fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1439 Error: Not equal: expected: []string{"A4", "A4/B1", "A4/B1/C1", "A4/B1/C2", "A4/B1/C3", "A4/B2"} actual : []string{"A3", "A3/B1", "A3/B1/C1", "A3/B1/C2", "A3/B1/C3", "A3/B2", "A4"} Diff: --- Expected +++ Actual @@ -1,8 +1,9 @@ -([]string) (len=6) { - (string) (len=2) "A4", - (string) (len=5) "A4/B1", - (string) (len=8) "A4/B1/C1", - (string) (len=8) "A4/B1/C2", - (string) (len=8) "A4/B1/C3", - (string) (len=5) "A4/B2" +([]string) (len=7) { + (string) (len=2) "A3", + (string) (len=5) "A3/B1", + (string) (len=8) "A3/B1/C1", + (string) (len=8) "A3/B1/C2", + (string) (len=8) "A3/B1/C3", + (string) (len=5) "A3/B2", + (string) (len=2) "A4" } Test: TestDirMove Messages: directories --- FAIL: TestDirMove (81.95s) === RUN TestMkdirModTime run.go:180: Remote "gofile root 'rclone-test-zuxihax0zaga'", Local "Local file system at /tmp/rclone1747149550", Modify Window "1s" 2024/11/20 01:21:15 DEBUG : directory with modtime: Making directory 2024/11/20 01:21:16 INFO : directory with modtime: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure --- PASS: TestMkdirModTime (11.57s) === RUN TestRemoveExisting run.go:180: Remote "gofile root 'rclone-test-zuxihax0zaga'", Local "Local file system at /tmp/rclone1747149550", Modify Window "1s" 2024/11/20 01:21:28 DEBUG : Upload server store1 (eu) responded in 121.019171ms 2024/11/20 01:21:28 DEBUG : Upload server store4 (eu) responded in 125.594203ms 2024/11/20 01:21:28 DEBUG : sub dir/test remove existing: Using upload server store1 (eu) 2024/11/20 01:21:29 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: Using upload server store4 (eu) 2024/11/20 01:21:32 DEBUG : sub dir/test remove existing: TEST: renaming existing object to "sub dir/test remove existing.tiniteq9" before starting 2024/11/20 01:21:34 DEBUG : sub dir/test remove existing.tiniteq9: TEST: removing renamed existing file after operation 2024/11/20 01:21:35 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.leregay0" before starting 2024/11/20 01:21:37 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.leregay0: TEST: renaming existing back after failed operation 2024/11/20 01:21:39 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.simodoc9" before starting 2024/11/20 01:21:40 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.simodoc9: TEST: removing renamed existing file after operation fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure --- PASS: TestRemoveExisting (24.52s) FAIL 2024/11/20 01:21:51 DEBUG : gofile root 'rclone-test-zuxihax0zaga': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^(TestDirMove|TestMkdirModTime|TestRemoveExisting|TestRmdirsLeaveRoot|TestRmdirsNoLeaveRoot|TestRmdirsWithFilter)$'" - Finished ERROR in 3m17.894189675s (try 2/5): exit status 1: Failed [TestRmdirsNoLeaveRoot TestRmdirsWithFilter TestDirMove]