"./sync.test -test.v -test.timeout 1h0m0s -remote TestTardigrade: -verbose -test.run '^TestServerSideMoveWithFilter$'" - Starting (try 2/5)
2020/12/27 05:19:38 DEBUG : Creating backend with remote "TestTardigrade:rclone-test-takurim9raxapod9cakiwob7"
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: connecting...
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: connected: <nil>
2020/12/27 05:19:38 DEBUG : Creating backend with remote "/tmp/rclone364728564"
=== RUN   TestServerSideMoveWithFilter
    run.go:176: Remote "FS sj://rclone-test-takurim9raxapod9cakiwob7", Local "Local file system at /tmp/rclone364728564", Modify Window "1ns"
2020/12/27 05:19:38 DEBUG : Creating backend with remote "TestTardigrade:rclone-test-wobeput5mikiqur1ciyukaq1"
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: connecting...
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: connected: <nil>
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: mkdir -p ./
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: cp input ./potato2 # [] 60
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: cp input ./empty space # [] 1
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: cp input ./potato3 # [] 68
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: ls -R ./
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: OBJ ls -R ./ ("rclone-test-takurim9raxapod9cakiwob7", "")
    sync_test.go:1294: Server side move (if possible) FS sj://rclone-test-takurim9raxapod9cakiwob7 -> FS sj://rclone-test-wobeput5mikiqur1ciyukaq1
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: mkdir -p ./
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: cp input ./empty space # [] 1
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: cp input ./potato3 # [] 60
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: ls -R ./
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: OBJ ls -R ./ ("rclone-test-wobeput5mikiqur1ciyukaq1", "")
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: ls ./
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: OBJ ls ./ ("rclone-test-wobeput5mikiqur1ciyukaq1", "")
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: ls ./
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: OBJ ls ./ ("rclone-test-takurim9raxapod9cakiwob7", "")
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/12/27 05:19:38 DEBUG : empty space: Excluded
2020/12/27 05:19:38 DEBUG : empty space: Excluded
2020/12/27 05:19:38 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: Waiting for checks to finish
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: Waiting for transfers to finish
2020/12/27 05:19:38 DEBUG : potato2: cat sj://rclone-test-takurim9raxapod9cakiwob7/potato2 # [HashesOption([])]
2020/12/27 05:19:38 DEBUG : potato2: range 0 + -1
2020/12/27 05:19:38 DEBUG : potato3: cat sj://rclone-test-takurim9raxapod9cakiwob7/potato3 # [HashesOption([])]
2020/12/27 05:19:38 DEBUG : potato3: range 0 + -1
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: cp input ./potato2 # [HashesOption([])] 60
2020/12/27 05:19:38 DEBUG : potato3: cp input ./potato3 [HashesOption([])]
2020/12/27 05:19:38 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: cp input ./potato3 # [HashesOption([])] 68
2020/12/27 05:19:39 INFO  : potato2: Copied (new)
2020/12/27 05:19:39 DEBUG : potato2: rm sj://rclone-test-takurim9raxapod9cakiwob7/potato2
2020/12/27 05:19:39 INFO  : potato2: Deleted
2020/12/27 05:19:39 INFO  : potato3: Copied (replaced existing)
2020/12/27 05:19:39 DEBUG : potato3: rm sj://rclone-test-takurim9raxapod9cakiwob7/potato3
2020/12/27 05:19:39 INFO  : potato3: Deleted
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: OBJ ls -R ./ ("rclone-test-takurim9raxapod9cakiwob7", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: OBJ ls -R ./ ("rclone-test-wobeput5mikiqur1ciyukaq1", "")
2020/12/27 05:19:39 DEBUG : Creating backend with remote "TestTardigrade:rclone-test-kefibil1jifulun0duliviy5"
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: connecting...
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: connected: <nil>
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: ls ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: OBJ ls ./ ("rclone-test-kefibil1jifulun0duliviy5", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: ls ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: OBJ ls ./ ("rclone-test-wobeput5mikiqur1ciyukaq1", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/12/27 05:19:39 DEBUG : empty space: Excluded
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: Waiting for checks to finish
2020/12/27 05:19:39 DEBUG : potato3: cat sj://rclone-test-wobeput5mikiqur1ciyukaq1/potato3 # [HashesOption([])]
2020/12/27 05:19:39 DEBUG : potato3: range 0 + -1
2020/12/27 05:19:39 DEBUG : potato2: cat sj://rclone-test-wobeput5mikiqur1ciyukaq1/potato2 # [HashesOption([])]
2020/12/27 05:19:39 DEBUG : potato2: range 0 + -1
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: Waiting for transfers to finish
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: cp input ./potato2 # [HashesOption([])] 60
2020/12/27 05:19:39 ERROR : FS sj://rclone-test-kefibil1jifulun0duliviy5: cp input ./potato2 [HashesOption([])]: uplink: upload done: already committed
	storj.io/uplink.errwrapf:64
	storj.io/uplink.(*Upload).Abort:162
	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:468
	github.com/rclone/rclone/fs/operations.Move:593
	github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove:388
2020/12/27 05:19:39 DEBUG : potato2: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2020/12/27 05:19:39 DEBUG : potato2: cat sj://rclone-test-wobeput5mikiqur1ciyukaq1/potato2 # [HashesOption([])]
2020/12/27 05:19:39 DEBUG : potato2: range 0 + -1
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: cp input ./potato2 # [HashesOption([])] 60
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: cp input ./potato3 # [HashesOption([])] 68
2020/12/27 05:19:39 INFO  : potato2: Copied (new)
2020/12/27 05:19:39 DEBUG : potato2: rm sj://rclone-test-wobeput5mikiqur1ciyukaq1/potato2
2020/12/27 05:19:39 INFO  : potato3: Copied (new)
2020/12/27 05:19:39 DEBUG : potato3: rm sj://rclone-test-wobeput5mikiqur1ciyukaq1/potato3
2020/12/27 05:19:39 INFO  : potato3: Deleted
2020/12/27 05:19:39 INFO  : potato2: Deleted
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: OBJ ls -R ./ ("rclone-test-kefibil1jifulun0duliviy5", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: OBJ ls -R ./ ("rclone-test-wobeput5mikiqur1ciyukaq1", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: OBJ ls -R ./ ("rclone-test-kefibil1jifulun0duliviy5", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: Purge object "potato2"
2020/12/27 05:19:39 DEBUG : potato2: rm sj://rclone-test-kefibil1jifulun0duliviy5/potato2
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: Purge object "potato3"
2020/12/27 05:19:39 DEBUG : potato3: rm sj://rclone-test-kefibil1jifulun0duliviy5/potato3
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: Purge dir ""
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-kefibil1jifulun0duliviy5: rmdir ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: OBJ ls -R ./ ("rclone-test-wobeput5mikiqur1ciyukaq1", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: Purge object "empty space"
2020/12/27 05:19:39 DEBUG : empty space: rm sj://rclone-test-wobeput5mikiqur1ciyukaq1/empty space
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: Purge dir ""
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-wobeput5mikiqur1ciyukaq1: rmdir ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: OBJ ls -R ./ ("rclone-test-takurim9raxapod9cakiwob7", "")
2020/12/27 05:19:39 DEBUG : empty space: rm sj://rclone-test-takurim9raxapod9cakiwob7/empty space
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: OBJ ls -R ./ ("rclone-test-takurim9raxapod9cakiwob7", "")
--- PASS: TestServerSideMoveWithFilter (1.62s)
PASS
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: ls -R ./
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: OBJ ls -R ./ ("rclone-test-takurim9raxapod9cakiwob7", "")
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: Purge dir ""
2020/12/27 05:19:39 DEBUG : FS sj://rclone-test-takurim9raxapod9cakiwob7: rmdir ./
"./sync.test -test.v -test.timeout 1h0m0s -remote TestTardigrade: -verbose -test.run '^TestServerSideMoveWithFilter$'" - Finished OK in 1.683563319s (try 2/5)