"./sync.test -test.v -test.timeout 1h0m0s -remote TestTardigrade: -verbose" - Starting (try 1/5)
2020/05/15 06:15:51 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: connecting...
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: connected: <nil>
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.06s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
--- SKIP: TestRcCopy (0.00s)
    rc_test.go:16: Skipping test on non local remote
=== RUN   TestRcMove
--- SKIP: TestRcMove (0.00s)
    rc_test.go:16: Skipping test on non local remote
=== RUN   TestRcSync
--- SKIP: TestRcSync (0.00s)
    rc_test.go:16: Skipping test on non local remote
=== RUN   TestCopyWithDryRun
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 NOTICE: sub dir/hello world: Not copying as --dry-run
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyWithDryRun (0.08s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopy
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:52 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopy (0.13s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyMissingDirectory
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 ERROR : : error reading source directory: directory not found
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyMissingDirectory (0.04s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyNoTraverse
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: stat ./sub dir/hello world
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: err: uplink: object not found ("sub dir/hello world")
	github.com/rclone/rclone/vendor/storj.io/uplink.errwrapf:55
	github.com/rclone/rclone/vendor/storj.io/uplink.(*Project).StatObject:91
	github.com/rclone/rclone/backend/tardigrade.(*Fs).NewObject:506
	github.com/rclone/rclone/fs/march.(*March).processJob:415
	github.com/rclone/rclone/fs/march.(*March).Run.func1:154
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyNoTraverse (0.16s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncNoTraverse
2020/05/15 06:15:52 ERROR : Ignoring --no-traverse with sync
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:52 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:52 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncNoTraverse (0.15s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyWithDepth
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./hello world2 # [HashesOption([])] 12
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 INFO  : hello world2: Copied (new)
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : hello world2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/hello world2
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyWithDepth (0.10s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyWithFilesFrom
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 DEBUG : hello world2: Excluded
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [HashesOption([])] 11
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 INFO  : potato2: Copied (new)
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyWithFilesFrom (0.10s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyWithFilesFromAndNoTraverse
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: stat ./potato2
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: err: uplink: object not found ("potato2")
	github.com/rclone/rclone/vendor/storj.io/uplink.errwrapf:55
	github.com/rclone/rclone/vendor/storj.io/uplink.(*Project).StatObject:91
	github.com/rclone/rclone/backend/tardigrade.(*Fs).NewObject:506
	github.com/rclone/rclone/fs/march.(*March).processJob:415
	github.com/rclone/rclone/fs/march.(*March).Run.func1:154
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [HashesOption([])] 11
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 INFO  : potato2: Copied (new)
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyWithFilesFromAndNoTraverse (0.10s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyEmptyDirectories
2020/05/15 06:15:52 DEBUG : sub dir2: Making directory
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:52 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:52 DEBUG : sub dir2: Making directory
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./sub dir2
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: copied 1 directories
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:52 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyEmptyDirectories (0.14s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    fstest.go:247: Filtering empty directory "sub dir2"
=== RUN   TestMoveEmptyDirectories
2020/05/15 06:15:53 DEBUG : sub dir2: Making directory
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:53 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:53 INFO  : sub dir/hello world: Deleted
2020/05/15 06:15:53 DEBUG : sub dir2: Making directory
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./sub dir2
2020/05/15 06:15:53 DEBUG : sub dir: Making directory
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: copied 2 directories
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestMoveEmptyDirectories (0.17s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    fstest.go:247: Filtering empty directory "sub dir2"
=== RUN   TestSyncEmptyDirectories
2020/05/15 06:15:53 DEBUG : sub dir2: Making directory
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:53 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:53 DEBUG : sub dir2: Making directory
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./sub dir2
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: copied 1 directories
2020/05/15 06:15:53 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncEmptyDirectories (0.14s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    fstest.go:247: Filtering empty directory "sub dir2"
=== RUN   TestServerSideCopy
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [] 11
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: connecting...
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: connected: <nil>
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: ls ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: OBJ ls ./ ("rclone-test-qorazol6rofitif1dutisan0", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./sub dir ("rclone-test-hulowef9rayuwij9miruvoq9", "sub dir")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:sub dir/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : sub dir/hello world: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world # [HashesOption([])]
2020/05/15 06:15:53 DEBUG : sub dir/hello world: range 0 + -1
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: Waiting for checks to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: Waiting for transfers to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:53 DEBUG : sub dir/hello world: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2020/05/15 06:15:53 DEBUG : sub dir/hello world: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world # [HashesOption([])]
2020/05/15 06:15:53 DEBUG : sub dir/hello world: range 0 + -1
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:53 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: OBJ ls -R ./ ("rclone-test-qorazol6rofitif1dutisan0", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: OBJ ls -R ./ ("rclone-test-qorazol6rofitif1dutisan0", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: Purge object "sub dir/hello world"
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-qorazol6rofitif1dutisan0/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: Purge dir "sub dir"
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: rmdir ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: Purge dir ""
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-qorazol6rofitif1dutisan0: rmdir ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestServerSideCopy (0.35s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:258: Server side copy (if possible) FS sj://rclone-test-hulowef9rayuwij9miruvoq9 -> FS sj://rclone-test-qorazol6rofitif1dutisan0
=== RUN   TestCopyAfterDelete
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [] 11
2020/05/15 06:15:53 ERROR : : error listing: directory not found
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : Local file system at /tmp/rclone884505443: Making directory
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyAfterDelete (0.13s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyRedownload
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [] 11
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./sub dir
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./sub dir ("rclone-test-hulowef9rayuwij9miruvoq9", "sub dir")
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:sub dir/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:53 DEBUG : Local file system at /tmp/rclone884505443: Waiting for checks to finish
2020/05/15 06:15:53 DEBUG : Local file system at /tmp/rclone884505443: Waiting for transfers to finish
2020/05/15 06:15:53 DEBUG : sub dir/hello world: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world # [HashesOption([])]
2020/05/15 06:15:53 DEBUG : sub dir/hello world: range 0 + -1
2020/05/15 06:15:53 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:53 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:53 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyRedownload (0.16s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncBasedOnCheckSum
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./check sum # [HashesOption([])] 1
2020/05/15 06:15:54 INFO  : check sum: Copied (new)
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 NOTICE: FS sj://rclone-test-hulowef9rayuwij9miruvoq9: --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2020/05/15 06:15:54 DEBUG : check sum: Size of src and dst objects identical
2020/05/15 06:15:54 DEBUG : check sum: Unchanged skipping
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 INFO  : There was nothing to transfer
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : check sum: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/check sum
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncBasedOnCheckSum (0.13s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncSizeOnly
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sizeonly # [HashesOption([])] 6
2020/05/15 06:15:54 INFO  : sizeonly: Copied (new)
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : sizeonly: Sizes identical
2020/05/15 06:15:54 DEBUG : sizeonly: Unchanged skipping
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 INFO  : There was nothing to transfer
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : sizeonly: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sizeonly
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncSizeOnly (0.14s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncIgnoreSize
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./ignore-size # [HashesOption([])] 8
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 INFO  : ignore-size: Copied (new)
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : ignore-size: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:54 DEBUG : ignore-size: Unchanged skipping
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 INFO  : There was nothing to transfer
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : ignore-size: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/ignore-size
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncIgnoreSize (0.13s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncIgnoreTimes
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./existing # [] 6
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : existing: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:54 DEBUG : existing: Unchanged skipping
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 INFO  : There was nothing to transfer
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : existing: cp input ./existing [HashesOption([])]
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./existing # [HashesOption([])] 6
2020/05/15 06:15:54 INFO  : existing: Copied (replaced existing)
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : existing: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/existing
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncIgnoreTimes (0.16s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncIgnoreExisting
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./existing # [HashesOption([])] 6
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 INFO  : existing: Copied (new)
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : existing: Destination exists, skipping
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 INFO  : There was nothing to transfer
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : existing: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/existing
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncIgnoreExisting (0.12s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncIgnoreErrors
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./b/potato # [] 21
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./c/non empty space # [] 5
2020/05/15 06:15:54 DEBUG : d: Making directory
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./d
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./c
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./b
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./b ("rclone-test-hulowef9rayuwij9miruvoq9", "b")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:b/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./c ("rclone-test-hulowef9rayuwij9miruvoq9", "c")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:c/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./a/potato2 # [HashesOption([])] 60
2020/05/15 06:15:54 DEBUG : c/non empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:54 DEBUG : c/non empty space: Unchanged skipping
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:54 INFO  : a/potato2: Copied (new)
2020/05/15 06:15:54 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:54 DEBUG : b/potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/b/potato
2020/05/15 06:15:54 INFO  : b/potato: Deleted
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:54 DEBUG : a/potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/a/potato2
2020/05/15 06:15:54 DEBUG : c/non empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/c/non empty space
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./c
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./a
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:54 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncIgnoreErrors (0.31s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    fstest.go:247: Filtering empty directory "d"
=== RUN   TestSyncAfterChangingModtimeOnly
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : empty space: Modification times differ by -95456h54m52.62345679s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499999999 +0000 UTC
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 NOTICE: empty space: Not copying as --dry-run
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : empty space: Modification times differ by -95456h54m52.62345679s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499999999 +0000 UTC
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 DEBUG : empty space: cp input ./empty space [HashesOption([])]
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [HashesOption([])] 1
2020/05/15 06:15:55 INFO  : empty space: Copied (replaced existing)
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterChangingModtimeOnly (0.17s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.03s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:559: Can't check this if no hashes supported
=== RUN   TestSyncDoesntUpdateModtime
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./foo # [] 3
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : foo: Modification times differ by -95456h54m52.62345679s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499999999 +0000 UTC
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 DEBUG : foo: cp input ./foo [HashesOption([])]
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./foo # [HashesOption([])] 3
2020/05/15 06:15:55 INFO  : foo: Copied (replaced existing)
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : foo: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/foo
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncDoesntUpdateModtime (0.14s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterAddingAFile
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [HashesOption([])] 60
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:55 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 INFO  : potato: Copied (new)
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:55 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterAddingAFile (0.16s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterChangingFilesSizeOnly
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 60
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2020/05/15 06:15:55 DEBUG : potato: cp input ./potato [HashesOption([])]
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [HashesOption([])] 21
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 INFO  : potato: Copied (replaced existing)
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterChangingFilesSizeOnly (0.14s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterChangingContentsOnly
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 21
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 DEBUG : potato: cp input ./potato [HashesOption([])]
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [HashesOption([])] 21
2020/05/15 06:15:55 INFO  : potato: Copied (replaced existing)
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterChangingContentsOnly (0.15s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 21
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:55 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:55 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:55 NOTICE: potato2: Not copying as --dry-run
2020/05/15 06:15:55 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:55 NOTICE: potato: Not deleting as --dry-run
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:55 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:55 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (0.15s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 21
2020/05/15 06:15:55 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:15:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:56 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:56 INFO  : potato2: Copied (new)
2020/05/15 06:15:56 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:56 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:56 INFO  : potato: Deleted
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:56 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (0.22s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./b/potato # [] 21
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./c/non empty space # [] 5
2020/05/15 06:15:56 DEBUG : d: Making directory
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./d
2020/05/15 06:15:56 DEBUG : d/e: Making directory
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./d/e
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./b
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./b ("rclone-test-hulowef9rayuwij9miruvoq9", "b")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:b/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./c
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./c ("rclone-test-hulowef9rayuwij9miruvoq9", "c")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:c/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./a/potato2 # [HashesOption([])] 60
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:56 DEBUG : c/non empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:56 DEBUG : c/non empty space: Unchanged skipping
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:56 INFO  : a/potato2: Copied (new)
2020/05/15 06:15:56 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:56 DEBUG : b/potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/b/potato
2020/05/15 06:15:56 INFO  : b/potato: Deleted
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : a/potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/a/potato2
2020/05/15 06:15:56 DEBUG : c/non empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/c/non empty space
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./c
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./a
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (0.33s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    fstest.go:247: Filtering empty directory "d"
    fstest.go:247: Filtering empty directory "d/e"
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./b/potato # [] 21
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./c/non empty space # [] 5
2020/05/15 06:15:56 DEBUG : d: Making directory
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./d
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./c
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./c ("rclone-test-hulowef9rayuwij9miruvoq9", "c")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:c/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./b
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./b ("rclone-test-hulowef9rayuwij9miruvoq9", "b")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix:b/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./a/potato2 # [HashesOption([])] 60
2020/05/15 06:15:56 DEBUG : c/non empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:56 DEBUG : c/non empty space: Unchanged skipping
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:56 INFO  : a/potato2: Copied (new)
2020/05/15 06:15:56 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: not deleting files as there were IO errors
2020/05/15 06:15:56 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: not deleting directories as there were IO errors
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : b/potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/b/potato
2020/05/15 06:15:56 DEBUG : a/potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/a/potato2
2020/05/15 06:15:56 DEBUG : c/non empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/c/non empty space
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./c
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./b
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./a
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (0.30s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    fstest.go:247: Filtering empty directory "d"
    fstest.go:247: Filtering empty directory "d"
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 21
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:15:56 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:56 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:56 INFO  : potato: Deleted
2020/05/15 06:15:56 INFO  : potato2: Copied (new)
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:56 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:56 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:56 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncDeleteDuring (0.20s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncDeleteBefore
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 21
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:57 INFO  : potato: Deleted
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:57 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:57 INFO  : potato2: Copied (new)
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:57 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncDeleteBefore (0.22s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestCopyDeleteBefore
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [] 21
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [HashesOption([])] 19
2020/05/15 06:15:57 INFO  : potato2: Copied (new)
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:57 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestCopyDeleteBefore (0.17s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncWithExclude
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [] 60
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : potato2: Excluded
2020/05/15 06:15:57 DEBUG : enormous: Excluded
2020/05/15 06:15:57 DEBUG : potato2: Excluded
2020/05/15 06:15:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:57 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:57 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:57 INFO  : There was nothing to transfer
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : potato2: Excluded
2020/05/15 06:15:57 DEBUG : enormous: Excluded
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : potato2: Excluded
2020/05/15 06:15:57 DEBUG : Local file system at /tmp/rclone884505443: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:57 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:57 DEBUG : Local file system at /tmp/rclone884505443: Waiting for transfers to finish
2020/05/15 06:15:57 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:57 INFO  : There was nothing to transfer
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:57 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncWithExclude (0.18s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncWithExcludeAndDeleteExcluded
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [] 60
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./enormous # [] 100
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : potato2: Excluded
2020/05/15 06:15:57 DEBUG : enormous: Excluded
2020/05/15 06:15:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:57 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:57 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:57 DEBUG : enormous: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/enormous
2020/05/15 06:15:57 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:15:57 INFO  : potato2: Deleted
2020/05/15 06:15:57 INFO  : enormous: Deleted
2020/05/15 06:15:57 INFO  : There was nothing to transfer
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:57 DEBUG : empty space: Unchanged skipping
2020/05/15 06:15:57 DEBUG : Local file system at /tmp/rclone884505443: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : Local file system at /tmp/rclone884505443: Waiting for transfers to finish
2020/05/15 06:15:57 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:57 INFO  : enormous: Deleted
2020/05/15 06:15:57 INFO  : potato2: Deleted
2020/05/15 06:15:57 INFO  : There was nothing to transfer
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncWithExcludeAndDeleteExcluded (0.21s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncWithUpdateOlder
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./one # [] 3
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./two # [] 3
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./three # [] 5
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./four # [] 8
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./five # [HashesOption([])] 4
2020/05/15 06:15:57 DEBUG : four: Sizes differ (src 4 vs dst 8)
2020/05/15 06:15:57 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:57 DEBUG : two: cp input ./two [HashesOption([])]
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./two # [HashesOption([])] 3
2020/05/15 06:15:57 DEBUG : three: Sizes identical
2020/05/15 06:15:57 DEBUG : one: Destination is newer than source, skipping
2020/05/15 06:15:57 DEBUG : four: cp input ./four [HashesOption([])]
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./four # [HashesOption([])] 4
2020/05/15 06:15:57 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:57 INFO  : five: Copied (new)
2020/05/15 06:15:57 INFO  : four: Copied (replaced existing)
2020/05/15 06:15:57 INFO  : two: Copied (replaced existing)
2020/05/15 06:15:57 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:57 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:57 DEBUG : four: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/four
2020/05/15 06:15:58 DEBUG : five: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/five
2020/05/15 06:15:58 DEBUG : one: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/one
2020/05/15 06:15:58 DEBUG : three: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/three
2020/05/15 06:15:58 DEBUG : two: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/two
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncWithUpdateOlder (0.31s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:981: Skip test with --checksum as no hashes supported
=== RUN   TestSyncWithMaxDuration
--- SKIP: TestSyncWithMaxDuration (0.00s)
    sync_test.go:997: Skipping test on non local remote
=== RUN   TestSyncWithTrackRenames
2020/05/15 06:15:58 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Ignoring --track-renames as the destination does not support server-side move or copy
2020/05/15 06:15:58 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Ignoring --track-renames as the source and destination do not have a common hash
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [HashesOption([])] 14
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./yam # [HashesOption([])] 11
2020/05/15 06:15:58 INFO  : yam: Copied (new)
2020/05/15 06:15:58 INFO  : potato: Copied (new)
2020/05/15 06:15:58 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Ignoring --track-renames as the destination does not support server-side move or copy
2020/05/15 06:15:58 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Ignoring --track-renames as the source and destination do not have a common hash
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./yaml # [HashesOption([])] 11
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:58 DEBUG : potato: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:58 DEBUG : potato: Unchanged skipping
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:58 INFO  : yaml: Copied (new)
2020/05/15 06:15:58 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:58 DEBUG : yam: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/yam
2020/05/15 06:15:58 INFO  : yam: Deleted
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:58 DEBUG : yaml: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/yaml
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncWithTrackRenames (0.19s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1051: Can track renames: false
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
2020/05/15 06:15:58 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Ignoring --track-renames as the destination does not support server-side move or copy
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato # [HashesOption([])] 14
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./yam # [HashesOption([])] 11
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:58 INFO  : yam: Copied (new)
2020/05/15 06:15:58 INFO  : potato: Copied (new)
2020/05/15 06:15:58 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Ignoring --track-renames as the destination does not support server-side move or copy
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./yaml # [HashesOption([])] 11
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:58 DEBUG : potato: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:15:58 DEBUG : potato: Unchanged skipping
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:58 INFO  : yaml: Copied (new)
2020/05/15 06:15:58 DEBUG : Waiting for deletions to finish
2020/05/15 06:15:58 DEBUG : yam: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/yam
2020/05/15 06:15:58 INFO  : yam: Deleted
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : potato: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato
2020/05/15 06:15:58 DEBUG : yaml: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/yaml
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncWithTrackRenamesStrategyModtime (0.19s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1122: Can track renames: false
=== RUN   TestMoveWithDeleteEmptySrcDirs
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./nested/sub dir/file # [HashesOption([])] 6
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:58 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:58 INFO  : sub dir/hello world: Deleted
2020/05/15 06:15:58 INFO  : nested/sub dir/file: Copied (new)
2020/05/15 06:15:58 INFO  : nested/sub dir/file: Deleted
2020/05/15 06:15:58 DEBUG : sub dir: Removing directory
2020/05/15 06:15:58 DEBUG : nested/sub dir: Removing directory
2020/05/15 06:15:58 DEBUG : nested: Removing directory
2020/05/15 06:15:58 DEBUG : Local file system at /tmp/rclone884505443: deleted 3 directories
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:58 DEBUG : nested/sub dir/file: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/nested/sub dir/file
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./nested/sub dir
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./nested
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestMoveWithDeleteEmptySrcDirs (0.18s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./sub dir/hello world # [HashesOption([])] 11
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./nested/sub dir/file # [HashesOption([])] 6
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:15:58 INFO  : sub dir/hello world: Copied (new)
2020/05/15 06:15:58 INFO  : nested/sub dir/file: Copied (new)
2020/05/15 06:15:58 INFO  : nested/sub dir/file: Deleted
2020/05/15 06:15:58 INFO  : sub dir/hello world: Deleted
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : sub dir/hello world: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/sub dir/hello world
2020/05/15 06:15:58 DEBUG : nested/sub dir/file: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/nested/sub dir/file
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./sub dir
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./nested/sub dir
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./nested
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (0.18s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestServerSideMove
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: connecting...
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: connected: <nil>
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [] 60
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato3 # [] 68
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:15:58 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: mkdir -p ./
2020/05/15 06:15:59 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: cp input ./empty space # [] 1
2020/05/15 06:15:59 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: cp input ./potato3 # [] 60
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: ls -R ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: OBJ ls -R ./ ("rclone-test-lupesap1guwuvik4soyukis8", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: ls ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: OBJ ls ./ ("rclone-test-lupesap1guwuvik4soyukis8", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:00 DEBUG : potato2: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2 # [HashesOption([])]
2020/05/15 06:16:00 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: Waiting for checks to finish
2020/05/15 06:16:00 DEBUG : potato2: range 0 + -1
2020/05/15 06:16:00 DEBUG : potato3: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/potato3 # [HashesOption([])]
2020/05/15 06:16:00 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:00 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:00 DEBUG : empty space: Unchanged skipping
2020/05/15 06:16:00 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:16:00 DEBUG : potato3: cp input ./potato3 [HashesOption([])]
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:16:00 INFO  : empty space: Deleted
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: Waiting for transfers to finish
2020/05/15 06:16:00 INFO  : potato3: Copied (replaced existing)
2020/05/15 06:16:00 DEBUG : potato3: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato3
2020/05/15 06:16:00 INFO  : potato3: Deleted
2020/05/15 06:16:00 INFO  : potato2: Copied (new)
2020/05/15 06:16:00 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:16:00 INFO  : potato2: Deleted
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: ls -R ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: OBJ ls -R ./ ("rclone-test-lupesap1guwuvik4soyukis8", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: connecting...
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: connected: <nil>
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: ls ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: OBJ ls ./ ("rclone-test-bohoseb0janedat5pugumic2", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: ls ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: OBJ ls ./ ("rclone-test-lupesap1guwuvik4soyukis8", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:00 DEBUG : empty space: cat sj://rclone-test-lupesap1guwuvik4soyukis8/empty space # [HashesOption([])]
2020/05/15 06:16:00 DEBUG : empty space: range 0 + -1
2020/05/15 06:16:00 DEBUG : potato2: cat sj://rclone-test-lupesap1guwuvik4soyukis8/potato2 # [HashesOption([])]
2020/05/15 06:16:00 DEBUG : potato2: range 0 + -1
2020/05/15 06:16:00 DEBUG : potato3: cat sj://rclone-test-lupesap1guwuvik4soyukis8/potato3 # [HashesOption([])]
2020/05/15 06:16:00 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: Waiting for checks to finish
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: Waiting for transfers to finish
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: cp input ./empty space # [HashesOption([])] 1
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:00 DEBUG : empty space: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2020/05/15 06:16:00 DEBUG : empty space: cat sj://rclone-test-lupesap1guwuvik4soyukis8/empty space # [HashesOption([])]
2020/05/15 06:16:00 DEBUG : empty space: range 0 + -1
2020/05/15 06:16:00 ERROR : potato3: Failed to copy: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:00 ERROR : potato3: Not deleting source as copy failed: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:00 ERROR : potato2: Failed to copy: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:00 ERROR : potato2: Not deleting source as copy failed: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: cp input ./empty space # [HashesOption([])] 1
2020/05/15 06:16:00 INFO  : empty space: Copied (new)
2020/05/15 06:16:00 DEBUG : empty space: rm sj://rclone-test-lupesap1guwuvik4soyukis8/empty space
2020/05/15 06:16:00 INFO  : empty space: Deleted
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: ls -R ./
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: OBJ ls -R ./ ("rclone-test-bohoseb0janedat5pugumic2", "")
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: Purge object "empty space"
2020/05/15 06:16:00 DEBUG : empty space: rm sj://rclone-test-bohoseb0janedat5pugumic2/empty space
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: Purge dir ""
2020/05/15 06:16:00 DEBUG : FS sj://rclone-test-bohoseb0janedat5pugumic2: rmdir ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: ls -R ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: OBJ ls -R ./ ("rclone-test-lupesap1guwuvik4soyukis8", "")
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: Purge object "potato3"
2020/05/15 06:16:01 DEBUG : potato3: rm sj://rclone-test-lupesap1guwuvik4soyukis8/potato3
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: Purge object "potato2"
2020/05/15 06:16:01 DEBUG : potato2: rm sj://rclone-test-lupesap1guwuvik4soyukis8/potato2
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: Purge dir ""
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-lupesap1guwuvik4soyukis8: rmdir ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- FAIL: TestServerSideMove (2.74s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1174: Server side move (if possible) FS sj://rclone-test-hulowef9rayuwij9miruvoq9 -> FS sj://rclone-test-lupesap1guwuvik4soyukis8
    sync_test.go:1211: 
        	Error Trace:	sync_test.go:1211
        	            				sync_test.go:1276
        	Error:      	Received unexpected error:
        	            	uplink: bucket: metainfo error: unable to create bucket
        	Test:       	TestServerSideMove
=== RUN   TestServerSideMoveWithFilter
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: connecting...
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: connected: <nil>
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [] 60
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato3 # [] 68
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: mkdir -p ./
2020/05/15 06:16:01 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: cp input ./empty space # [] 1
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: cp input ./potato3 # [] 60
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: ls -R ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: OBJ ls -R ./ ("rclone-test-luvoked3kixivas7rabenog4", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: ls ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: OBJ ls ./ ("rclone-test-luvoked3kixivas7rabenog4", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:02 DEBUG : empty space: Excluded
2020/05/15 06:16:02 DEBUG : empty space: Excluded
2020/05/15 06:16:02 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/05/15 06:16:02 DEBUG : potato2: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2 # [HashesOption([])]
2020/05/15 06:16:02 DEBUG : potato2: range 0 + -1
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: Waiting for checks to finish
2020/05/15 06:16:02 DEBUG : potato3: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/potato3 # [HashesOption([])]
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: Waiting for transfers to finish
2020/05/15 06:16:02 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:16:02 DEBUG : potato3: cp input ./potato3 [HashesOption([])]
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:02 INFO  : potato2: Copied (new)
2020/05/15 06:16:02 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:16:02 INFO  : potato2: Deleted
2020/05/15 06:16:02 INFO  : potato3: Copied (replaced existing)
2020/05/15 06:16:02 DEBUG : potato3: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato3
2020/05/15 06:16:02 INFO  : potato3: Deleted
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: ls -R ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: OBJ ls -R ./ ("rclone-test-luvoked3kixivas7rabenog4", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: connecting...
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: connected: <nil>
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: ls ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: OBJ ls ./ ("rclone-test-deborif7jafoyut9kalamem3", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: ls ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: OBJ ls ./ ("rclone-test-luvoked3kixivas7rabenog4", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:02 DEBUG : empty space: Excluded
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: Waiting for checks to finish
2020/05/15 06:16:02 DEBUG : potato2: cat sj://rclone-test-luvoked3kixivas7rabenog4/potato2 # [HashesOption([])]
2020/05/15 06:16:02 DEBUG : potato2: range 0 + -1
2020/05/15 06:16:02 DEBUG : potato3: cat sj://rclone-test-luvoked3kixivas7rabenog4/potato3 # [HashesOption([])]
2020/05/15 06:16:02 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: Waiting for transfers to finish
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:16:02 DEBUG : potato3: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2020/05/15 06:16:02 DEBUG : potato3: cat sj://rclone-test-luvoked3kixivas7rabenog4/potato3 # [HashesOption([])]
2020/05/15 06:16:02 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:02 ERROR : potato2: Failed to copy: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:02 ERROR : potato2: Not deleting source as copy failed: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:02 INFO  : potato3: Copied (new)
2020/05/15 06:16:02 DEBUG : potato3: rm sj://rclone-test-luvoked3kixivas7rabenog4/potato3
2020/05/15 06:16:02 INFO  : potato3: Deleted
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: ls -R ./
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: OBJ ls -R ./ ("rclone-test-deborif7jafoyut9kalamem3", "")
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: Purge object "potato3"
2020/05/15 06:16:02 DEBUG : potato3: rm sj://rclone-test-deborif7jafoyut9kalamem3/potato3
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: Purge dir ""
2020/05/15 06:16:02 DEBUG : FS sj://rclone-test-deborif7jafoyut9kalamem3: rmdir ./
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: ls -R ./
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: OBJ ls -R ./ ("rclone-test-luvoked3kixivas7rabenog4", "")
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: Purge object "empty space"
2020/05/15 06:16:03 DEBUG : empty space: rm sj://rclone-test-luvoked3kixivas7rabenog4/empty space
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: Purge object "potato2"
2020/05/15 06:16:03 DEBUG : potato2: rm sj://rclone-test-luvoked3kixivas7rabenog4/potato2
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: Purge dir ""
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-luvoked3kixivas7rabenog4: rmdir ./
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:03 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- FAIL: TestServerSideMoveWithFilter (2.34s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1174: Server side move (if possible) FS sj://rclone-test-hulowef9rayuwij9miruvoq9 -> FS sj://rclone-test-luvoked3kixivas7rabenog4
    sync_test.go:1211: 
        	Error Trace:	sync_test.go:1211
        	            				sync_test.go:1289
        	Error:      	Received unexpected error:
        	            	uplink: bucket: metainfo error: unable to create bucket
        	Test:       	TestServerSideMoveWithFilter
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: connecting...
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: connected: <nil>
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [] 60
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./empty space # [] 1
2020/05/15 06:16:03 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato3 # [] 68
2020/05/15 06:16:04 DEBUG : tomatoDir: Making directory
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: mkdir -p ./tomatoDir
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: mkdir -p ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: cp input ./empty space # [] 1
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: cp input ./potato3 # [] 60
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: ls -R ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: OBJ ls -R ./ ("rclone-test-pokeson7pejitov9reseyov1", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: ls ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: OBJ ls ./ ("rclone-test-pokeson7pejitov9reseyov1", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:04 DEBUG : potato2: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2 # [HashesOption([])]
2020/05/15 06:16:04 DEBUG : potato2: range 0 + -1
2020/05/15 06:16:04 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:04 DEBUG : empty space: Unchanged skipping
2020/05/15 06:16:04 DEBUG : empty space: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/empty space
2020/05/15 06:16:04 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/05/15 06:16:04 DEBUG : potato3: cat sj://rclone-test-hulowef9rayuwij9miruvoq9/potato3 # [HashesOption([])]
2020/05/15 06:16:04 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: Waiting for checks to finish
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:16:04 DEBUG : potato3: cp input ./potato3 [HashesOption([])]
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:04 INFO  : empty space: Deleted
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: Waiting for transfers to finish
2020/05/15 06:16:04 INFO  : potato3: Copied (replaced existing)
2020/05/15 06:16:04 DEBUG : potato3: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato3
2020/05/15 06:16:04 INFO  : potato3: Deleted
2020/05/15 06:16:04 INFO  : potato2: Copied (new)
2020/05/15 06:16:04 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:16:04 INFO  : potato2: Deleted
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: ls -R ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: OBJ ls -R ./ ("rclone-test-pokeson7pejitov9reseyov1", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: connecting...
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: connected: <nil>
2020/05/15 06:16:04 DEBUG : tomatoDir: Making directory
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: mkdir -p ./tomatoDir
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: ls ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: OBJ ls ./ ("rclone-test-tivuzem9wifuram5negomeb8", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: ls ./
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: OBJ ls ./ ("rclone-test-pokeson7pejitov9reseyov1", "")
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:04 DEBUG : empty space: cat sj://rclone-test-pokeson7pejitov9reseyov1/empty space # [HashesOption([])]
2020/05/15 06:16:04 DEBUG : empty space: range 0 + -1
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: Waiting for checks to finish
2020/05/15 06:16:04 DEBUG : potato2: cat sj://rclone-test-pokeson7pejitov9reseyov1/potato2 # [HashesOption([])]
2020/05/15 06:16:04 DEBUG : potato2: range 0 + -1
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: Waiting for transfers to finish
2020/05/15 06:16:04 DEBUG : potato3: cat sj://rclone-test-pokeson7pejitov9reseyov1/potato3 # [HashesOption([])]
2020/05/15 06:16:04 DEBUG : potato3: range 0 + -1
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: cp input ./empty space # [HashesOption([])] 1
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: cp input ./potato2 # [HashesOption([])] 60
2020/05/15 06:16:04 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: cp input ./potato3 # [HashesOption([])] 68
2020/05/15 06:16:05 DEBUG : empty space: Received error: bucket was not available, now created, the upload must be retried - low level retry 1/10
2020/05/15 06:16:05 DEBUG : empty space: cat sj://rclone-test-pokeson7pejitov9reseyov1/empty space # [HashesOption([])]
2020/05/15 06:16:05 DEBUG : empty space: range 0 + -1
2020/05/15 06:16:05 ERROR : potato2: Failed to copy: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:05 ERROR : potato2: Not deleting source as copy failed: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:05 ERROR : potato3: Failed to copy: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:05 ERROR : potato3: Not deleting source as copy failed: uplink: bucket: metainfo error: unable to create bucket
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: cp input ./empty space # [HashesOption([])] 1
2020/05/15 06:16:05 INFO  : empty space: Copied (new)
2020/05/15 06:16:05 DEBUG : empty space: rm sj://rclone-test-pokeson7pejitov9reseyov1/empty space
2020/05/15 06:16:05 INFO  : empty space: Deleted
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: ls -R ./
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: OBJ ls -R ./ ("rclone-test-tivuzem9wifuram5negomeb8", "")
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: Purge object "empty space"
2020/05/15 06:16:05 DEBUG : empty space: rm sj://rclone-test-tivuzem9wifuram5negomeb8/empty space
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: Purge dir ""
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-tivuzem9wifuram5negomeb8: rmdir ./
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: ls -R ./
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: OBJ ls -R ./ ("rclone-test-pokeson7pejitov9reseyov1", "")
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: Purge object "potato3"
2020/05/15 06:16:05 DEBUG : potato3: rm sj://rclone-test-pokeson7pejitov9reseyov1/potato3
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: Purge object "potato2"
2020/05/15 06:16:05 DEBUG : potato2: rm sj://rclone-test-pokeson7pejitov9reseyov1/potato2
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: Purge dir ""
2020/05/15 06:16:05 DEBUG : FS sj://rclone-test-pokeson7pejitov9reseyov1: rmdir ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- FAIL: TestServerSideMoveDeleteEmptySourceDirs (2.29s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1174: Server side move (if possible) FS sj://rclone-test-hulowef9rayuwij9miruvoq9 -> FS sj://rclone-test-pokeson7pejitov9reseyov1
    sync_test.go:1211: 
        	Error Trace:	sync_test.go:1211
        	            				sync_test.go:1296
        	Error:      	Received unexpected error:
        	            	uplink: bucket: metainfo error: unable to create bucket
        	Test:       	TestServerSideMoveDeleteEmptySourceDirs
=== RUN   TestServerSideMoveOverlap
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/rclone-move-test: connecting...
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/rclone-move-test: connected: <nil>
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./potato2 # [] 60
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : potato2: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/potato2
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestServerSideMoveOverlap (0.14s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncOverlap
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/rclone-sync-test: connecting...
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/rclone-sync-test: connected: <nil>
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncOverlap (0.07s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncCompareDest
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: connecting...
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: connected: <nil>
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: connecting...
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: connected: <nil>
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: ls ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "dst")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: opts &{Prefix:dst/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./one
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: err: uplink: object not found ("CompareDest/one")
	github.com/rclone/rclone/vendor/storj.io/uplink.errwrapf:55
	github.com/rclone/rclone/vendor/storj.io/uplink.(*Project).StatObject:91
	github.com/rclone/rclone/backend/tardigrade.(*Fs).NewObject:506
	github.com/rclone/rclone/fs/operations.compareDest:1509
	github.com/rclone/rclone/fs/operations.CompareOrCopyDest:1593
	github.com/rclone/rclone/fs/sync.(*syncCopyMove).SrcOnly:917
	github.com/rclone/rclone/fs/march.(*March).processJob:429
	github.com/rclone/rclone/fs/march.(*March).Run.func1:154
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for checks to finish
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for transfers to finish
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: cp input ./one # [HashesOption([])] 3
2020/05/15 06:16:06 INFO  : one: Copied (new)
2020/05/15 06:16:06 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: ls ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "dst")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: opts &{Prefix:dst/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for checks to finish
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./one
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: err: uplink: object not found ("CompareDest/one")
	github.com/rclone/rclone/vendor/storj.io/uplink.errwrapf:55
	github.com/rclone/rclone/vendor/storj.io/uplink.(*Project).StatObject:91
	github.com/rclone/rclone/backend/tardigrade.(*Fs).NewObject:506
	github.com/rclone/rclone/fs/operations.compareDest:1509
	github.com/rclone/rclone/fs/operations.CompareOrCopyDest:1593
	github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairChecker:283
2020/05/15 06:16:06 DEBUG : one: Sizes differ (src 5 vs dst 3)
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for transfers to finish
2020/05/15 06:16:06 DEBUG : one: cp input ./one [HashesOption([])]
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: cp input ./one # [HashesOption([])] 5
2020/05/15 06:16:06 INFO  : one: Copied (replaced existing)
2020/05/15 06:16:06 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./dst/one # [] 3
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./CompareDest/one # [] 5
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: ls ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "dst")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: opts &{Prefix:dst/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./one
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for checks to finish
2020/05/15 06:16:06 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:06 DEBUG : one: Destination found in --compare-dest, skipping
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for transfers to finish
2020/05/15 06:16:06 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:06 INFO  : There was nothing to transfer
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./CompareDest/two # [] 3
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: ls ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "dst")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: opts &{Prefix:dst/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./two
2020/05/15 06:16:06 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:06 DEBUG : two: Destination found in --compare-dest, skipping
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./one
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for checks to finish
2020/05/15 06:16:06 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:06 DEBUG : one: Destination found in --compare-dest, skipping
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for transfers to finish
2020/05/15 06:16:06 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:06 INFO  : There was nothing to transfer
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: ls ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "dst")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: opts &{Prefix:dst/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./two
2020/05/15 06:16:06 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:06 DEBUG : two: Destination found in --compare-dest, skipping
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./one
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for checks to finish
2020/05/15 06:16:06 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:06 DEBUG : one: Destination found in --compare-dest, skipping
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for transfers to finish
2020/05/15 06:16:06 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:06 INFO  : There was nothing to transfer
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: ls ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "dst")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: opts &{Prefix:dst/ Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./two
2020/05/15 06:16:06 DEBUG : two: Sizes differ (src 5 vs dst 3)
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest: stat ./one
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: cp input ./two # [HashesOption([])] 5
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for checks to finish
2020/05/15 06:16:06 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:06 DEBUG : one: Destination found in --compare-dest, skipping
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9/dst: Waiting for transfers to finish
2020/05/15 06:16:06 INFO  : two: Copied (new)
2020/05/15 06:16:06 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:06 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:06 DEBUG : CompareDest/two: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest/two
2020/05/15 06:16:07 DEBUG : CompareDest/one: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/CompareDest/one
2020/05/15 06:16:07 DEBUG : dst/two: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/dst/two
2020/05/15 06:16:07 DEBUG : dst/one: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/dst/one
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./dst
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./CompareDest
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncCompareDest (0.72s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncCopyDest
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestSyncCopyDest (0.02s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1442: Skipping test as remote does not support server side copy
=== RUN   TestSyncBackupDir
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestSyncBackupDir (0.02s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1545: Skipping test as remote does not support server side move
=== RUN   TestSyncBackupDirWithSuffix
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestSyncBackupDirWithSuffix (0.02s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1545: Skipping test as remote does not support server side move
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestSyncBackupDirWithSuffixKeepExtension (0.02s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1545: Skipping test as remote does not support server side move
=== RUN   TestSyncSuffix
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestSyncSuffix (0.02s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1626: Skipping test as remote does not support server side move
=== RUN   TestSyncSuffixKeepExtension
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestSyncSuffixKeepExtension (0.02s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1626: Skipping test as remote does not support server side move
=== RUN   TestSyncUTFNorm
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./Testêé # [] 18
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:16:07 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:16:07 DEBUG : Testêé: cp input ./Testêé [HashesOption([])]
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./Testêé # [HashesOption([])] 14
2020/05/15 06:16:07 INFO  : Testêé: Copied (replaced existing)
2020/05/15 06:16:07 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : Testêé: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/Testêé
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncUTFNorm (0.15s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncImmutable
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./existing # [HashesOption([])] 6
2020/05/15 06:16:07 INFO  : existing: Copied (new)
2020/05/15 06:16:07 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:16:07 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2020/05/15 06:16:07 ERROR : existing: Source and destination exist but do not match: immutable file modified
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:16:07 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: not deleting files as there were IO errors
2020/05/15 06:16:07 ERROR : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: not deleting directories as there were IO errors
2020/05/15 06:16:07 INFO  : There was nothing to transfer
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : existing: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/existing
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncImmutable (0.15s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestSyncIgnoreCase
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: cp input ./EXISTING # [] 6
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: opts &{Prefix: Cursor: Recursive:false System:true Custom:true}
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for checks to finish
2020/05/15 06:16:07 DEBUG : existing: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/05/15 06:16:07 DEBUG : existing: Unchanged skipping
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Waiting for transfers to finish
2020/05/15 06:16:07 DEBUG : Waiting for deletions to finish
2020/05/15 06:16:07 INFO  : There was nothing to transfer
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : EXISTING: rm sj://rclone-test-hulowef9rayuwij9miruvoq9/EXISTING
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- PASS: TestSyncIgnoreCase (0.11s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
=== RUN   TestAbort
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
--- SKIP: TestAbort (0.03s)
    run.go:176: Remote "FS sj://rclone-test-hulowef9rayuwij9miruvoq9", Local "Local file system at /tmp/rclone884505443", Modify Window "1ns"
    sync_test.go:1807: This test only runs on local
FAIL
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: ls -R ./
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: OBJ ls -R ./ ("rclone-test-hulowef9rayuwij9miruvoq9", "")
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: Purge dir ""
2020/05/15 06:16:07 DEBUG : FS sj://rclone-test-hulowef9rayuwij9miruvoq9: rmdir ./
"./sync.test -test.v -test.timeout 1h0m0s -remote TestTardigrade: -verbose" - Finished ERROR in 16.283791316s (try 1/5): exit status 1: Failed [TestServerSideMove TestServerSideMoveWithFilter TestServerSideMoveDeleteEmptySourceDirs]