"./sync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^(TestServerSideCopyOverSelf|TestSyncBackupDirWithSuffixKeepExtension|TestSyncCopyDest)$'" - Starting (try 4/5)
2024/11/03 04:51:15 DEBUG : Creating backend with remote "TestGoFile:rclone-test-rejahew1zuli"
2024/11/03 04:51:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/03 04:51:16 DEBUG : Creating backend with remote "/tmp/rclone2596263587"
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "gofile root 'rclone-test-rejahew1zuli'", Local "Local file system at /tmp/rclone2596263587", Modify Window "1s"
2024/11/03 04:51:17 DEBUG : Upload server store5 (eu) responded in 125.476605ms
2024/11/03 04:51:17 DEBUG : Upload server store4 (eu) responded in 133.645686ms
2024/11/03 04:51:17 DEBUG : sub dir/hello world: Using upload server store5 (eu)
2024/11/03 04:51:18 DEBUG : Creating backend with remote "TestGoFile:rclone-test-loyebeb7hibi"
    sync_test.go:626: Server side copy (if possible) gofile root 'rclone-test-rejahew1zuli' -> gofile root 'rclone-test-loyebeb7hibi'
2024/11/03 04:51:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/03 04:51:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/03 04:51:18 DEBUG : gofile root 'rclone-test-loyebeb7hibi': Waiting for checks to finish
2024/11/03 04:51:18 DEBUG : gofile root 'rclone-test-loyebeb7hibi': Waiting for transfers to finish
2024/11/03 04:51:19 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2024/11/03 04:51:19 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/03 04:51:20 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "gofile root 'rclone-test-rejahew1zuli'", Local "Local file system at /tmp/rclone2596263587", Modify Window "1s"
2024/11/03 04:51:20 DEBUG : sub dir/hello world: Using upload server store5 (eu)
2024/11/03 04:51:20 DEBUG : sub dir/hello world: Removing old object on successful upload
2024/11/03 04:51:21 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/03 04:51:21 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/03 04:51:21 DEBUG : gofile root 'rclone-test-loyebeb7hibi': Waiting for checks to finish
2024/11/03 04:51:21 DEBUG : gofile root 'rclone-test-loyebeb7hibi': Waiting for transfers to finish
2024/11/03 04:51:21 DEBUG : sub dir/hello world: md5 = 00321a507bdb420dbbd4f53c733b1505 OK
2024/11/03 04:51:21 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/03 04:51:22 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "gofile root 'rclone-test-rejahew1zuli'", Local "Local file system at /tmp/rclone2596263587", Modify Window "1s"
    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/fstest/fstest.go:350
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:641
        	Error:      	Should be true
        	Test:       	TestServerSideCopyOverSelf
        	Messages:   	listing wrong, want
        	            	  sub dir/hello world (17) got
        	            	  sub dir/hello world (11), sub dir/hello world (17)
    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/fstest/fstest.go:350
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:641
        	Error:      	Should be true
        	Test:       	TestServerSideCopyOverSelf
        	Messages:   	Unexpected file "sub dir/hello world"
2024/11/03 04:51:30 DEBUG : gofile root 'rclone-test-loyebeb7hibi': Purge remote
--- FAIL: TestServerSideCopyOverSelf (15.27s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "gofile root 'rclone-test-rejahew1zuli'", Local "Local file system at /tmp/rclone2596263587", Modify Window "1s"
2024/11/03 04:51:32 DEBUG : Creating backend with remote "TestGoFile:rclone-test-rejahew1zuli/dst"
2024/11/03 04:51:32 DEBUG : Creating backend with remote "TestGoFile:rclone-test-rejahew1zuli/CopyDest"
2024/11/03 04:51:33 DEBUG : one: Need to transfer - File not found at Destination
2024/11/03 04:51:33 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for checks to finish
2024/11/03 04:51:33 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for transfers to finish
2024/11/03 04:51:33 DEBUG : Upload server store6 (eu) responded in 126.227156ms
2024/11/03 04:51:33 DEBUG : Upload server store10 (eu) responded in 132.645616ms
2024/11/03 04:51:33 DEBUG : one: Using upload server store10 (eu)
2024/11/03 04:51:34 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2024/11/03 04:51:34 INFO  : one: Copied (new)
2024/11/03 04:51:34 DEBUG : Waiting for deletions to finish
2024/11/03 04:51:34 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/03 04:51:34 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for checks to finish
2024/11/03 04:51:34 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for transfers to finish
2024/11/03 04:51:34 DEBUG : one: Using upload server store6 (eu)
2024/11/03 04:51:34 DEBUG : one: Removing old object on successful upload
2024/11/03 04:51:34 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK
2024/11/03 04:51:34 INFO  : one: Copied (replaced existing)
2024/11/03 04:51:34 DEBUG : Waiting for deletions to finish
2024/11/03 04:51:35 DEBUG : dst/one: Using upload server store5 (eu)
2024/11/03 04:51:35 DEBUG : dst/one: Removing old object on successful upload
2024/11/03 04:51:35 DEBUG : CopyDest/one: Using upload server store5 (eu)
2024/11/03 04:51:36 DEBUG : Creating backend with remote "TestGoFile:rclone-test-rejahew1zuli/BackupDir"
2024/11/03 04:51:36 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/03 04:51:36 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for checks to finish
2024/11/03 04:51:36 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2024/11/03 04:51:36 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/03 04:51:37 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:51:42 DEBUG : pacer: low level retry 1/10 (error Error "error-rateLimit")
2024/11/03 04:51:42 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/11/03 04:51:42 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:51:47 DEBUG : pacer: low level retry 2/10 (error Error "error-rateLimit")
2024/11/03 04:51:47 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/11/03 04:51:47 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:51:52 DEBUG : pacer: low level retry 3/10 (error Error "error-rateLimit")
2024/11/03 04:51:52 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2024/11/03 04:51:52 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:51:57 DEBUG : pacer: low level retry 4/10 (error Error "error-rateLimit")
2024/11/03 04:51:57 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2024/11/03 04:51:57 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:02 DEBUG : pacer: low level retry 5/10 (error Error "error-rateLimit")
2024/11/03 04:52:02 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2024/11/03 04:52:02 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:07 DEBUG : pacer: low level retry 6/10 (error Error "error-rateLimit")
2024/11/03 04:52:07 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2024/11/03 04:52:07 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:12 DEBUG : pacer: low level retry 7/10 (error Error "error-rateLimit")
2024/11/03 04:52:12 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2024/11/03 04:52:12 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:17 DEBUG : pacer: low level retry 8/10 (error Error "error-rateLimit")
2024/11/03 04:52:17 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2024/11/03 04:52:17 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:22 DEBUG : pacer: low level retry 9/10 (error Error "error-rateLimit")
2024/11/03 04:52:22 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2024/11/03 04:52:22 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:27 DEBUG : pacer: low level retry 10/10 (error Error "error-rateLimit")
2024/11/03 04:52:27 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2024/11/03 04:52:27 ERROR : one: Couldn't move: failed to move item: Error "error-rateLimit"
2024/11/03 04:52:27 DEBUG : pacer: Reducing sleep to 5.12s
2024/11/03 04:52:38 DEBUG : pacer: Reducing sleep to 2.56s
2024/11/03 04:52:38 INFO  : one: Moved (server-side)
2024/11/03 04:52:38 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for transfers to finish
2024/11/03 04:52:38 DEBUG : Upload server store4 (eu) responded in 124.040146ms
2024/11/03 04:52:38 DEBUG : Upload server store6 (eu) responded in 130.270002ms
2024/11/03 04:52:38 DEBUG : one: Using upload server store6 (eu)
2024/11/03 04:52:38 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK
2024/11/03 04:52:38 INFO  : one: Copied (new)
2024/11/03 04:52:38 ERROR : gofile root 'rclone-test-rejahew1zuli/dst': not deleting files as there were IO errors
2024/11/03 04:52:38 ERROR : gofile root 'rclone-test-rejahew1zuli/dst': not deleting directories as there were IO errors
    sync_test.go:2288: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2288
        	Error:      	Received unexpected error:
        	            	moving to --backup-dir failed: failed to move item: Error "error-rateLimit"
        	Test:       	TestSyncCopyDest
--- FAIL: TestSyncCopyDest (68.86s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "gofile root 'rclone-test-rejahew1zuli'", Local "Local file system at /tmp/rclone2596263587", Modify Window "1s"
2024/11/03 04:52:41 DEBUG : Upload server store6 (eu) responded in 125.745593ms
2024/11/03 04:52:41 DEBUG : Upload server store5 (eu) responded in 128.544225ms
2024/11/03 04:52:41 DEBUG : dst/one: Using upload server store6 (eu)
2024/11/03 04:52:41 DEBUG : dst/two: Using upload server store6 (eu)
2024/11/03 04:52:42 DEBUG : dst/three.txt: Using upload server store5 (eu)
2024/11/03 04:52:42 DEBUG : Creating backend with remote "TestGoFile:rclone-test-rejahew1zuli/dst"
2024/11/03 04:52:43 DEBUG : Creating backend with remote "TestGoFile:rclone-test-rejahew1zuli/backup"
2024/11/03 04:52:44 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/03 04:52:44 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for checks to finish
2024/11/03 04:52:44 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/11/03 04:52:44 DEBUG : two: Unchanged skipping
2024/11/03 04:52:44 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:49 DEBUG : pacer: low level retry 1/10 (error Error "error-rateLimit")
2024/11/03 04:52:49 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/11/03 04:52:49 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:54 DEBUG : pacer: low level retry 2/10 (error Error "error-rateLimit")
2024/11/03 04:52:54 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/11/03 04:52:54 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:52:59 DEBUG : pacer: low level retry 3/10 (error Error "error-rateLimit")
2024/11/03 04:52:59 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2024/11/03 04:52:59 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:04 DEBUG : pacer: low level retry 4/10 (error Error "error-rateLimit")
2024/11/03 04:53:04 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2024/11/03 04:53:04 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:09 DEBUG : pacer: low level retry 5/10 (error Error "error-rateLimit")
2024/11/03 04:53:09 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2024/11/03 04:53:09 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:14 DEBUG : pacer: low level retry 6/10 (error Error "error-rateLimit")
2024/11/03 04:53:14 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2024/11/03 04:53:14 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:19 DEBUG : pacer: low level retry 7/10 (error Error "error-rateLimit")
2024/11/03 04:53:19 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2024/11/03 04:53:19 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:24 DEBUG : pacer: low level retry 8/10 (error Error "error-rateLimit")
2024/11/03 04:53:24 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2024/11/03 04:53:24 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:29 DEBUG : pacer: low level retry 9/10 (error Error "error-rateLimit")
2024/11/03 04:53:29 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2024/11/03 04:53:29 DEBUG : Rate limited, sleep for 5s
2024/11/03 04:53:34 DEBUG : pacer: low level retry 10/10 (error Error "error-rateLimit")
2024/11/03 04:53:34 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2024/11/03 04:53:34 ERROR : one: Couldn't move: failed to move item: Error "error-rateLimit"
2024/11/03 04:53:34 DEBUG : gofile root 'rclone-test-rejahew1zuli/dst': Waiting for transfers to finish
2024/11/03 04:53:34 ERROR : gofile root 'rclone-test-rejahew1zuli/dst': not deleting files as there were IO errors
2024/11/03 04:53:34 ERROR : gofile root 'rclone-test-rejahew1zuli/dst': not deleting directories as there were IO errors
    sync_test.go:2385: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2385
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Received unexpected error:
        	            	failed to move item: Error "error-rateLimit"
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
--- FAIL: TestSyncBackupDirWithSuffixKeepExtension (55.32s)
FAIL
2024/11/03 04:53:36 DEBUG : gofile root 'rclone-test-rejahew1zuli': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^(TestServerSideCopyOverSelf|TestSyncBackupDirWithSuffixKeepExtension|TestSyncCopyDest)$'" - Finished ERROR in 2m20.614566772s (try 4/5): exit status 1: Failed [TestServerSideCopyOverSelf TestSyncCopyDest TestSyncBackupDirWithSuffixKeepExtension]