"./sync.test -test.v -test.timeout 1h0m0s -remote TestTardigrade: -verbose -fast-list -test.run '^TestServerSideMoveWithFilter$'" - Starting (try 2/5)
2021/03/04 05:31:36 DEBUG : Creating backend with remote "TestTardigrade:rclone-test-lehijof7dudubuj1susoreg8"
2021/03/04 05:31:36 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: connecting...
2021/03/04 05:31:36 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: connected: <nil>
2021/03/04 05:31:36 DEBUG : Creating backend with remote "/tmp/rclone100795388"
=== RUN   TestServerSideMoveWithFilter
    run.go:176: Remote "FS sj://rclone-test-lehijof7dudubuj1susoreg8", Local "Local file system at /tmp/rclone100795388", Modify Window "1ns"
2021/03/04 05:31:36 DEBUG : Creating backend with remote "TestTardigrade:rclone-test-wusamox8zaridef6bidihov5"
2021/03/04 05:31:36 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: connecting...
2021/03/04 05:31:36 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: connected: <nil>
2021/03/04 05:31:36 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: mkdir -p ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: cp input ./potato2 # [] 60
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: cp input ./empty space # [] 1
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: cp input ./potato3 # [] 68
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: OBJ ls -R ./ ("rclone-test-lehijof7dudubuj1susoreg8", "")
    sync_test.go:1294: Server side move (if possible) FS sj://rclone-test-lehijof7dudubuj1susoreg8 -> FS sj://rclone-test-wusamox8zaridef6bidihov5
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: mkdir -p ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: cp input ./empty space # [] 1
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: cp input ./potato3 # [] 60
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: OBJ ls -R ./ ("rclone-test-wusamox8zaridef6bidihov5", "")
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: OBJ ls -R ./ ("rclone-test-wusamox8zaridef6bidihov5", "")
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: OBJ ls -R ./ ("rclone-test-lehijof7dudubuj1susoreg8", "")
2021/03/04 05:31:37 DEBUG : empty space: Excluded from sync (and deletion)
2021/03/04 05:31:37 DEBUG : empty space: Excluded from sync (and deletion)
2021/03/04 05:31:37 DEBUG : potato2: cat sj://rclone-test-lehijof7dudubuj1susoreg8/potato2 # [HashesOption([])]
2021/03/04 05:31:37 DEBUG : potato2: range 0 + -1
2021/03/04 05:31:37 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2021/03/04 05:31:37 DEBUG : potato3: cat sj://rclone-test-lehijof7dudubuj1susoreg8/potato3 # [HashesOption([])]
2021/03/04 05:31:37 DEBUG : potato3: range 0 + -1
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: Waiting for checks to finish
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: Waiting for transfers to finish
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: cp input ./potato2 # [HashesOption([])] 60
2021/03/04 05:31:37 DEBUG : potato3: cp input ./potato3 [HashesOption([])]
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: cp input ./potato3 # [HashesOption([])] 68
2021/03/04 05:31:37 INFO  : potato3: Copied (replaced existing)
2021/03/04 05:31:37 DEBUG : potato3: rm sj://rclone-test-lehijof7dudubuj1susoreg8/potato3
2021/03/04 05:31:37 INFO  : potato3: Deleted
2021/03/04 05:31:37 INFO  : potato2: Copied (new)
2021/03/04 05:31:37 DEBUG : potato2: rm sj://rclone-test-lehijof7dudubuj1susoreg8/potato2
2021/03/04 05:31:37 INFO  : potato2: Deleted
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: OBJ ls -R ./ ("rclone-test-lehijof7dudubuj1susoreg8", "")
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: OBJ ls -R ./ ("rclone-test-wusamox8zaridef6bidihov5", "")
2021/03/04 05:31:37 DEBUG : Creating backend with remote "TestTardigrade:rclone-test-yukofet6zuxided1fowedom4"
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: connecting...
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: connected: <nil>
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: OBJ ls -R ./ ("rclone-test-yukofet6zuxided1fowedom4", "")
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: ls -R ./
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: OBJ ls -R ./ ("rclone-test-wusamox8zaridef6bidihov5", "")
2021/03/04 05:31:37 DEBUG : empty space: Excluded from sync (and deletion)
2021/03/04 05:31:37 DEBUG : potato2: cat sj://rclone-test-wusamox8zaridef6bidihov5/potato2 # [HashesOption([])]
2021/03/04 05:31:37 DEBUG : potato2: range 0 + -1
2021/03/04 05:31:37 DEBUG : potato3: cat sj://rclone-test-wusamox8zaridef6bidihov5/potato3 # [HashesOption([])]
2021/03/04 05:31:37 DEBUG : potato3: range 0 + -1
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: Waiting for checks to finish
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: Waiting for transfers to finish
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: cp input ./potato2 # [HashesOption([])] 60
2021/03/04 05:31:37 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: cp input ./potato3 # [HashesOption([])] 68
2021/03/04 05:31:38 ERROR : FS sj://rclone-test-yukofet6zuxided1fowedom4: cp input ./potato3 [HashesOption([])]: uplink: upload done: already committed
	storj.io/uplink.errwrapf:74
	storj.io/uplink.(*Upload).Abort:160
	github.com/rclone/rclone/backend/tardigrade.(*Fs).Put.func1:548
	github.com/rclone/rclone/backend/tardigrade.(*Fs).Put:581
	github.com/rclone/rclone/fs/operations.Copy:472
	github.com/rclone/rclone/fs/operations.Move:617
	github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove:393
2021/03/04 05:31:38 DEBUG : potato3: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2021/03/04 05:31:38 DEBUG : potato3: cat sj://rclone-test-wusamox8zaridef6bidihov5/potato3 # [HashesOption([])]
2021/03/04 05:31:38 DEBUG : potato3: range 0 + -1
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: cp input ./potato3 # [HashesOption([])] 68
2021/03/04 05:31:38 ERROR : FS sj://rclone-test-yukofet6zuxided1fowedom4: cp input ./potato2 [HashesOption([])]: uplink: upload done: already committed
	storj.io/uplink.errwrapf:74
	storj.io/uplink.(*Upload).Abort:160
	github.com/rclone/rclone/backend/tardigrade.(*Fs).Put.func1:548
	github.com/rclone/rclone/backend/tardigrade.(*Fs).Put:581
	github.com/rclone/rclone/fs/operations.Copy:472
	github.com/rclone/rclone/fs/operations.Move:617
	github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove:393
2021/03/04 05:31:38 DEBUG : potato2: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2021/03/04 05:31:38 DEBUG : potato2: cat sj://rclone-test-wusamox8zaridef6bidihov5/potato2 # [HashesOption([])]
2021/03/04 05:31:38 DEBUG : potato2: range 0 + -1
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: cp input ./potato2 # [HashesOption([])] 60
2021/03/04 05:31:38 INFO  : potato3: Copied (new)
2021/03/04 05:31:38 DEBUG : potato3: rm sj://rclone-test-wusamox8zaridef6bidihov5/potato3
2021/03/04 05:31:38 INFO  : potato3: Deleted
2021/03/04 05:31:38 INFO  : potato2: Copied (new)
2021/03/04 05:31:38 DEBUG : potato2: rm sj://rclone-test-wusamox8zaridef6bidihov5/potato2
2021/03/04 05:31:38 INFO  : potato2: Deleted
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: ls -R ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: OBJ ls -R ./ ("rclone-test-yukofet6zuxided1fowedom4", "")
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: ls -R ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: OBJ ls -R ./ ("rclone-test-wusamox8zaridef6bidihov5", "")
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: ls -R ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: OBJ ls -R ./ ("rclone-test-yukofet6zuxided1fowedom4", "")
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: Purge object "potato3"
2021/03/04 05:31:38 DEBUG : potato3: rm sj://rclone-test-yukofet6zuxided1fowedom4/potato3
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: Purge object "potato2"
2021/03/04 05:31:38 DEBUG : potato2: rm sj://rclone-test-yukofet6zuxided1fowedom4/potato2
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: Purge dir ""
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-yukofet6zuxided1fowedom4: rmdir ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: ls -R ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: OBJ ls -R ./ ("rclone-test-wusamox8zaridef6bidihov5", "")
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: Purge object "empty space"
2021/03/04 05:31:38 DEBUG : empty space: rm sj://rclone-test-wusamox8zaridef6bidihov5/empty space
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: Purge dir ""
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-wusamox8zaridef6bidihov5: rmdir ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: ls -R ./
2021/03/04 05:31:38 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: OBJ ls -R ./ ("rclone-test-lehijof7dudubuj1susoreg8", "")
2021/03/04 05:31:38 DEBUG : empty space: rm sj://rclone-test-lehijof7dudubuj1susoreg8/empty space
2021/03/04 05:31:39 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: ls -R ./
2021/03/04 05:31:39 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: OBJ ls -R ./ ("rclone-test-lehijof7dudubuj1susoreg8", "")
--- PASS: TestServerSideMoveWithFilter (2.05s)
PASS
2021/03/04 05:31:39 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: ls -R ./
2021/03/04 05:31:39 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: OBJ ls -R ./ ("rclone-test-lehijof7dudubuj1susoreg8", "")
2021/03/04 05:31:39 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: Purge dir ""
2021/03/04 05:31:39 DEBUG : FS sj://rclone-test-lehijof7dudubuj1susoreg8: rmdir ./
"./sync.test -test.v -test.timeout 1h0m0s -remote TestTardigrade: -verbose -fast-list -test.run '^TestServerSideMoveWithFilter$'" - Finished OK in 2.296467317s (try 2/5)