"./sync.test -test.v -test.timeout 1h0m0s -remote TestStorj: -verbose -test.run '^TestServerSideMoveDeleteEmptySourceDirs$'" - Starting (try 2/5)
2022/03/02 05:10:35 DEBUG : Creating backend with remote "TestStorj:rclone-test-jaleges4wosovey2pocupob9"
2022/03/02 05:10:35 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/03/02 05:10:35 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: connecting...
2022/03/02 05:10:35 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: connected: <nil>
2022/03/02 05:10:35 DEBUG : Creating backend with remote "/tmp/rclone675123163"
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:181: Remote "FS sj://rclone-test-jaleges4wosovey2pocupob9", Local "Local file system at /tmp/rclone675123163", Modify Window "1ns"
2022/03/02 05:10:35 DEBUG : Creating backend with remote "TestStorj:rclone-test-riqajuq1torahav4vosifol8"
2022/03/02 05:10:35 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: connecting...
2022/03/02 05:10:35 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: connected: <nil>
2022/03/02 05:10:35 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: mkdir -p ./
2022/03/02 05:10:35 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: cp input ./potato2 # [] 60
2022/03/02 05:10:36 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: cp input ./empty space # [] 1
2022/03/02 05:10:36 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: cp input ./potato3 # [] 68
2022/03/02 05:10:36 DEBUG : tomatoDir: Making directory
2022/03/02 05:10:36 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: mkdir -p ./tomatoDir
2022/03/02 05:10:37 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls -R ./
2022/03/02 05:10:37 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls -R ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
    sync_test.go:1215: Server side move (if possible) FS sj://rclone-test-jaleges4wosovey2pocupob9 -> FS sj://rclone-test-riqajuq1torahav4vosifol8
2022/03/02 05:10:37 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: mkdir -p ./
2022/03/02 05:10:37 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: cp input ./empty space # [] 1
2022/03/02 05:10:37 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: cp input ./potato3 # [] 60
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls -R ./
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls -R ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls ./
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls ./
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2022/03/02 05:10:38 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2022/03/02 05:10:38 DEBUG : empty space: Unchanged skipping
2022/03/02 05:10:38 DEBUG : empty space: rm sj://rclone-test-jaleges4wosovey2pocupob9/empty space
2022/03/02 05:10:38 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: Waiting for checks to finish
2022/03/02 05:10:38 DEBUG : potato3: cat sj://rclone-test-jaleges4wosovey2pocupob9/potato3 # [HashesOption([])]
2022/03/02 05:10:38 DEBUG : potato3: range 0 + -1
2022/03/02 05:10:38 DEBUG : potato2: cat sj://rclone-test-jaleges4wosovey2pocupob9/potato2 # [HashesOption([])]
2022/03/02 05:10:38 DEBUG : potato2: range 0 + -1
2022/03/02 05:10:38 INFO  : empty space: Deleted
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: Waiting for transfers to finish
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: cp input ./potato2 # [HashesOption([])] 60
2022/03/02 05:10:38 DEBUG : potato3: cp input ./potato3 [HashesOption([])]
2022/03/02 05:10:38 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: cp input ./potato3 # [HashesOption([])] 68
2022/03/02 05:10:38 INFO  : potato2: Copied (new)
2022/03/02 05:10:38 DEBUG : potato2: rm sj://rclone-test-jaleges4wosovey2pocupob9/potato2
2022/03/02 05:10:38 INFO  : potato2: Deleted
2022/03/02 05:10:38 INFO  : potato3: Copied (replaced existing)
2022/03/02 05:10:38 DEBUG : potato3: rm sj://rclone-test-jaleges4wosovey2pocupob9/potato3
2022/03/02 05:10:39 INFO  : potato3: Deleted
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls -R ./
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls -R ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls -R ./
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls -R ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls -R ./
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls -R ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:39 DEBUG : Creating backend with remote "TestStorj:rclone-test-begenaq3yatopad8nabinus1"
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: connecting...
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: connected: <nil>
2022/03/02 05:10:39 DEBUG : tomatoDir: Making directory
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: mkdir -p ./tomatoDir
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: ls ./
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls ./
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: OBJ ls ./ ("rclone-test-begenaq3yatopad8nabinus1", "")
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2022/03/02 05:10:39 DEBUG : empty space: cat sj://rclone-test-riqajuq1torahav4vosifol8/empty space # [HashesOption([])]
2022/03/02 05:10:39 DEBUG : empty space: range 0 + -1
2022/03/02 05:10:39 DEBUG : potato2: cat sj://rclone-test-riqajuq1torahav4vosifol8/potato2 # [HashesOption([])]
2022/03/02 05:10:39 DEBUG : potato2: range 0 + -1
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: Waiting for checks to finish
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: Waiting for transfers to finish
2022/03/02 05:10:39 DEBUG : potato3: cat sj://rclone-test-riqajuq1torahav4vosifol8/potato3 # [HashesOption([])]
2022/03/02 05:10:39 DEBUG : potato3: range 0 + -1
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: cp input ./empty space # [HashesOption([])] 1
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: cp input ./potato2 # [HashesOption([])] 60
2022/03/02 05:10:39 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: cp input ./potato3 # [HashesOption([])] 68
2022/03/02 05:10:40 ERROR : FS sj://rclone-test-begenaq3yatopad8nabinus1: cp input ./empty space [HashesOption([])]: uplink: upload done: already committed
	storj.io/uplink.errwrapf:82
	storj.io/uplink.(*Upload).Abort:161
	github.com/rclone/rclone/backend/storj.(*Fs).Put.func1:545
	github.com/rclone/rclone/backend/storj.(*Fs).Put:578
	github.com/rclone/rclone/fs/operations.Copy:472
	github.com/rclone/rclone/fs/operations.Move:625
	github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove:400
2022/03/02 05:10:40 DEBUG : empty space: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2022/03/02 05:10:40 DEBUG : empty space: cat sj://rclone-test-riqajuq1torahav4vosifol8/empty space # [HashesOption([])]
2022/03/02 05:10:40 DEBUG : empty space: range 0 + -1
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: cp input ./empty space # [HashesOption([])] 1
2022/03/02 05:10:40 INFO  : potato3: Copied (new)
2022/03/02 05:10:40 DEBUG : potato3: rm sj://rclone-test-riqajuq1torahav4vosifol8/potato3
2022/03/02 05:10:40 INFO  : potato2: Copied (new)
2022/03/02 05:10:40 DEBUG : potato2: rm sj://rclone-test-riqajuq1torahav4vosifol8/potato2
2022/03/02 05:10:40 INFO  : empty space: Copied (new)
2022/03/02 05:10:40 DEBUG : empty space: rm sj://rclone-test-riqajuq1torahav4vosifol8/empty space
2022/03/02 05:10:40 INFO  : potato2: Deleted
2022/03/02 05:10:40 INFO  : potato3: Deleted
2022/03/02 05:10:40 INFO  : empty space: Deleted
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: ls -R ./
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: OBJ ls -R ./ ("rclone-test-begenaq3yatopad8nabinus1", "")
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls -R ./
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls -R ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls -R ./
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls -R ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: ls -R ./
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: OBJ ls -R ./ ("rclone-test-begenaq3yatopad8nabinus1", "")
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: Purge object "potato2"
2022/03/02 05:10:40 DEBUG : potato2: rm sj://rclone-test-begenaq3yatopad8nabinus1/potato2
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: Purge object "empty space"
2022/03/02 05:10:40 DEBUG : empty space: rm sj://rclone-test-begenaq3yatopad8nabinus1/empty space
2022/03/02 05:10:40 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: Purge object "potato3"
2022/03/02 05:10:40 DEBUG : potato3: rm sj://rclone-test-begenaq3yatopad8nabinus1/potato3
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: Purge dir ""
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-begenaq3yatopad8nabinus1: rmdir ./
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: ls -R ./
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: OBJ ls -R ./ ("rclone-test-riqajuq1torahav4vosifol8", "")
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: Purge dir ""
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-riqajuq1torahav4vosifol8: rmdir ./
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls -R ./
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls -R ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls -R ./
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls -R ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (6.38s)
PASS
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: ls -R ./
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: OBJ ls -R ./ ("rclone-test-jaleges4wosovey2pocupob9", "")
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: Purge dir ""
2022/03/02 05:10:41 DEBUG : FS sj://rclone-test-jaleges4wosovey2pocupob9: rmdir ./
"./sync.test -test.v -test.timeout 1h0m0s -remote TestStorj: -verbose -test.run '^TestServerSideMoveDeleteEmptySourceDirs$'" - Finished OK in 6.726727706s (try 2/5)