"./sync.test -test.v -test.timeout 1h0m0s -remote TestStorj: -verbose -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Starting (try 2/5)
2024/11/18 01:22:55 DEBUG : Creating backend with remote "TestStorj:rclone-test-remazec6gexa"
2024/11/18 01:22:55 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/18 01:22:55 DEBUG : FS sj://rclone-test-remazec6gexa: connecting...
2024/11/18 01:22:55 DEBUG : FS sj://rclone-test-remazec6gexa: connected: <nil>
2024/11/18 01:22:55 DEBUG : Creating backend with remote "/tmp/rclone2442196624"
=== RUN   TestServerSideMove
    run.go:180: Remote "FS sj://rclone-test-remazec6gexa", Local "Local file system at /tmp/rclone2442196624", Modify Window "1ns"
2024/11/18 01:22:55 DEBUG : Creating backend with remote "TestStorj:rclone-test-mepipaq0cago"
2024/11/18 01:22:55 DEBUG : FS sj://rclone-test-mepipaq0cago: connecting...
2024/11/18 01:22:55 DEBUG : FS sj://rclone-test-mepipaq0cago: connected: <nil>
2024/11/18 01:22:55 DEBUG : FS sj://rclone-test-remazec6gexa: mkdir -p ./
2024/11/18 01:22:56 DEBUG : FS sj://rclone-test-remazec6gexa: cp input ./potato2 # [] 60
2024/11/18 01:22:56 DEBUG : FS sj://rclone-test-remazec6gexa: cp input ./empty space # [] 1
2024/11/18 01:22:56 DEBUG : FS sj://rclone-test-remazec6gexa: cp input ./potato3 # [] 68
2024/11/18 01:22:56 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:22:56 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
    sync_test.go:1705: Server side move (if possible) FS sj://rclone-test-remazec6gexa -> FS sj://rclone-test-mepipaq0cago
2024/11/18 01:22:56 DEBUG : FS sj://rclone-test-mepipaq0cago: mkdir -p ./
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: cp input ./empty space # [] 1
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: cp input ./potato3 # [] 60
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: ls -R ./
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: OBJ ls -R ./ ("rclone-test-mepipaq0cago", "")
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: ls ./
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: OBJ ls ./ ("rclone-test-mepipaq0cago", "")
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-remazec6gexa: ls ./
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-remazec6gexa: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:22:57 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/18 01:22:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2024/11/18 01:22:57 DEBUG : empty space: Unchanged skipping
2024/11/18 01:22:57 DEBUG : empty space: rm sj://rclone-test-remazec6gexa/empty space
2024/11/18 01:22:57 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/18 01:22:57 DEBUG : potato3: rm sj://rclone-test-mepipaq0cago/potato3
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: Waiting for checks to finish
2024/11/18 01:22:57 INFO  : empty space: Deleted
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: Waiting for transfers to finish
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: stat ./potato2
2024/11/18 01:22:57 INFO  : potato3: Deleted
2024/11/18 01:22:57 INFO  : potato2: Moved (server-side)
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-mepipaq0cago: stat ./potato3
2024/11/18 01:22:57 INFO  : potato3: Moved (server-side)
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:22:57 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-mepipaq0cago: ls -R ./
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-mepipaq0cago: OBJ ls -R ./ ("rclone-test-mepipaq0cago", "")
2024/11/18 01:22:58 DEBUG : Creating backend with remote "TestStorj:rclone-test-hisubeg7xoqa"
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: connecting...
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: connected: <nil>
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: ls ./
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: OBJ ls ./ ("rclone-test-hisubeg7xoqa", "")
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-mepipaq0cago: ls ./
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-mepipaq0cago: OBJ ls ./ ("rclone-test-mepipaq0cago", "")
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-mepipaq0cago: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:22:58 DEBUG : empty space: Need to transfer - File not found at Destination
2024/11/18 01:22:58 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/18 01:22:58 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: Waiting for checks to finish
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: Waiting for transfers to finish
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: stat ./potato3
2024/11/18 01:22:58 INFO  : potato3: Moved (server-side)
2024/11/18 01:22:58 DEBUG : FS sj://rclone-test-hisubeg7xoqa: stat ./potato2
2024/11/18 01:22:58 INFO  : potato2: Moved (server-side)
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-hisubeg7xoqa: stat ./empty space
2024/11/18 01:22:59 INFO  : empty space: Moved (server-side)
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-hisubeg7xoqa: ls -R ./
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-hisubeg7xoqa: OBJ ls -R ./ ("rclone-test-hisubeg7xoqa", "")
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-mepipaq0cago: ls -R ./
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-mepipaq0cago: OBJ ls -R ./ ("rclone-test-mepipaq0cago", "")
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-hisubeg7xoqa: Purge remote
2024/11/18 01:22:59 DEBUG : FS sj://rclone-test-mepipaq0cago: Purge remote
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
--- PASS: TestServerSideMove (5.27s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "FS sj://rclone-test-remazec6gexa", Local "Local file system at /tmp/rclone2442196624", Modify Window "1ns"
2024/11/18 01:23:00 DEBUG : Creating backend with remote "TestStorj:rclone-test-pohoxud4mipu"
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-pohoxud4mipu: connecting...
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-pohoxud4mipu: connected: <nil>
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: cp input ./potato2 # [] 60
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: cp input ./empty space # [] 1
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: cp input ./potato3 # [] 68
2024/11/18 01:23:00 DEBUG : tomatoDir: Making directory
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: mkdir -p ./tomatoDir
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
    sync_test.go:1705: Server side move (if possible) FS sj://rclone-test-remazec6gexa -> FS sj://rclone-test-pohoxud4mipu
2024/11/18 01:23:00 DEBUG : FS sj://rclone-test-pohoxud4mipu: mkdir -p ./
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: cp input ./empty space # [] 1
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: cp input ./potato3 # [] 60
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: ls -R ./
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: OBJ ls -R ./ ("rclone-test-pohoxud4mipu", "")
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: ls ./
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: OBJ ls ./ ("rclone-test-pohoxud4mipu", "")
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-remazec6gexa: ls ./
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-remazec6gexa: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:23:01 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/18 01:23:01 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2024/11/18 01:23:01 DEBUG : empty space: Unchanged skipping
2024/11/18 01:23:01 DEBUG : empty space: rm sj://rclone-test-remazec6gexa/empty space
2024/11/18 01:23:01 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/18 01:23:01 DEBUG : potato3: rm sj://rclone-test-pohoxud4mipu/potato3
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: Waiting for checks to finish
2024/11/18 01:23:01 INFO  : empty space: Deleted
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: Waiting for transfers to finish
2024/11/18 01:23:01 DEBUG : FS sj://rclone-test-pohoxud4mipu: stat ./potato2
2024/11/18 01:23:02 INFO  : potato3: Deleted
2024/11/18 01:23:02 INFO  : potato2: Moved (server-side)
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: stat ./potato3
2024/11/18 01:23:02 INFO  : potato3: Moved (server-side)
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: ls -R ./
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: OBJ ls -R ./ ("rclone-test-pohoxud4mipu", "")
2024/11/18 01:23:02 DEBUG : Creating backend with remote "TestStorj:rclone-test-yeyizem4retu"
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: connecting...
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: connected: <nil>
2024/11/18 01:23:02 DEBUG : tomatoDir: Making directory
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: mkdir -p ./tomatoDir
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: ls ./
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: OBJ ls ./ ("rclone-test-yeyizem4retu", "")
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: ls ./
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: OBJ ls ./ ("rclone-test-pohoxud4mipu", "")
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-pohoxud4mipu: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2024/11/18 01:23:02 DEBUG : empty space: Need to transfer - File not found at Destination
2024/11/18 01:23:02 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/18 01:23:02 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: Waiting for checks to finish
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: Waiting for transfers to finish
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: stat ./potato3
2024/11/18 01:23:02 DEBUG : FS sj://rclone-test-yeyizem4retu: stat ./potato2
2024/11/18 01:23:02 INFO  : potato3: Moved (server-side)
2024/11/18 01:23:02 INFO  : potato2: Moved (server-side)
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-yeyizem4retu: stat ./empty space
2024/11/18 01:23:03 INFO  : empty space: Moved (server-side)
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-yeyizem4retu: ls -R ./
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-yeyizem4retu: OBJ ls -R ./ ("rclone-test-yeyizem4retu", "")
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-pohoxud4mipu: ls -R ./
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-pohoxud4mipu: OBJ ls -R ./ ("rclone-test-pohoxud4mipu", "")
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-pohoxud4mipu: ls -R ./
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-pohoxud4mipu: OBJ ls -R ./ ("rclone-test-pohoxud4mipu", "")
2024/11/18 01:23:03 DEBUG : FS sj://rclone-test-yeyizem4retu: Purge remote
2024/11/18 01:23:04 DEBUG : FS sj://rclone-test-pohoxud4mipu: Purge remote
2024/11/18 01:23:04 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:04 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
2024/11/18 01:23:04 DEBUG : FS sj://rclone-test-remazec6gexa: ls -R ./
2024/11/18 01:23:04 DEBUG : FS sj://rclone-test-remazec6gexa: OBJ ls -R ./ ("rclone-test-remazec6gexa", "")
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (4.23s)
PASS
2024/11/18 01:23:04 DEBUG : FS sj://rclone-test-remazec6gexa: Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestStorj: -verbose -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Finished OK in 10.057945261s (try 2/5)