"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestServerSideCopyOverSelf|TestServerSideMoveOverSelf|TestSyncBackupDir|TestSyncBackupDirSuffixOnly|TestSyncBackupDirWithSuffix|TestSyncIgnoreTimes)$'" - Starting (try 2/5)
2024/12/15 01:14:14 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kodozut2vagi"
2024/12/15 01:14:14 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/12/15 01:14:14 DEBUG : Starting OpenDrive session with ID: dcc654cbe9d1bb4748f627f6b879ca7bd4b42fd95638d22dc0726ce1238b3cce
2024/12/15 01:14:15 DEBUG : Creating backend with remote "/tmp/rclone171650411"
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:16 DEBUG : sub dir/hello world: Uploading chunk 0, size=11, remain=0
2024/12/15 01:14:17 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-xijuhot8bana"
2024/12/15 01:14:18 DEBUG : Starting OpenDrive session with ID: 94249773a77a5aacb8bbf191cc04ec1904a3eb49ac318ca8958d799d706758ad
    sync_test.go:626: Server side copy (if possible) OpenDrive root 'rclone-test-kodozut2vagi' -> OpenDrive root 'rclone-test-xijuhot8bana'
2024/12/15 01:14:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/15 01:14:19 DEBUG : OpenDrive root 'rclone-test-xijuhot8bana': Waiting for checks to finish
2024/12/15 01:14:19 DEBUG : OpenDrive root 'rclone-test-xijuhot8bana': Waiting for transfers to finish
2024/12/15 01:14:20 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2024/12/15 01:14:20 INFO  : sub dir/hello world: Copied (server-side copy)
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:20 DEBUG : sub dir/hello world: Uploading chunk 0, size=17, remain=0
2024/12/15 01:14:22 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/15 01:14:22 DEBUG : OpenDrive root 'rclone-test-xijuhot8bana': Waiting for checks to finish
2024/12/15 01:14:22 DEBUG : OpenDrive root 'rclone-test-xijuhot8bana': Waiting for transfers to finish
2024/12/15 01:14:22 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2024/12/15 01:14:22 INFO  : sub dir/hello world: Copied (server-side copy)
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:23 DEBUG : OpenDrive root 'rclone-test-xijuhot8bana': Purge remote
--- PASS: TestServerSideCopyOverSelf (10.19s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:26 DEBUG : sub dir/hello world: Uploading chunk 0, size=11, remain=0
2024/12/15 01:14:27 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-wadakok7vino"
2024/12/15 01:14:28 DEBUG : Starting OpenDrive session with ID: 61fe4ef3e936d364b2df4b62e14f0af64babef52f8f6c57cc6cbc7515b219008
    sync_test.go:671: Server side copy (if possible) OpenDrive root 'rclone-test-kodozut2vagi' -> OpenDrive root 'rclone-test-wadakok7vino'
2024/12/15 01:14:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/15 01:14:28 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Waiting for checks to finish
2024/12/15 01:14:28 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Waiting for transfers to finish
2024/12/15 01:14:29 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2024/12/15 01:14:29 INFO  : sub dir/hello world: Copied (server-side copy)
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Flushing the directory cache
    fstest.go:286: Sleeping for 6s just to make sure
2024/12/15 01:14:38 DEBUG : sub dir/hello world: Uploading chunk 0, size=17, remain=0
2024/12/15 01:14:39 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Using server-side directory move
2024/12/15 01:14:39 INFO  : OpenDrive root 'rclone-test-wadakok7vino': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/15 01:14:39 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/15 01:14:39 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Waiting for checks to finish
2024/12/15 01:14:39 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Waiting for transfers to finish
2024/12/15 01:14:39 INFO  : sub dir/hello world: Deleted
2024/12/15 01:14:40 INFO  : sub dir/hello world: Moved (server-side)
2024/12/15 01:14:41 DEBUG : sub dir/hello world: Uploading chunk 0, size=24, remain=0
2024/12/15 01:14:43 DEBUG : testing file moves
2024/12/15 01:14:43 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/12/15 01:14:43 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Waiting for checks to finish
2024/12/15 01:14:43 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Waiting for transfers to finish
2024/12/15 01:14:43 INFO  : sub dir/hello world: Deleted
2024/12/15 01:14:43 INFO  : sub dir/hello world: Moved (server-side)
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:44 DEBUG : OpenDrive root 'rclone-test-wadakok7vino': Purge remote
--- PASS: TestServerSideMoveOverSelf (21.25s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:47 DEBUG : existing: Uploading chunk 0, size=6, remain=0
2024/12/15 01:14:48 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:14:48 DEBUG : existing: Unchanged skipping
2024/12/15 01:14:48 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi': Waiting for checks to finish
2024/12/15 01:14:48 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi': Waiting for transfers to finish
2024/12/15 01:14:48 DEBUG : Waiting for deletions to finish
2024/12/15 01:14:48 INFO  : There was nothing to transfer
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:48 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/12/15 01:14:48 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi': Waiting for checks to finish
2024/12/15 01:14:48 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi': Waiting for transfers to finish
2024/12/15 01:14:48 DEBUG : existing: Uploading chunk 0, size=6, remain=0
2024/12/15 01:14:49 DEBUG : existing: md5 = 8ee2027983915ec78acc45027d874316 OK
2024/12/15 01:14:49 INFO  : existing: Copied (replaced existing)
2024/12/15 01:14:49 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
--- PASS: TestSyncIgnoreTimes (4.63s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:14:52 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2024/12/15 01:14:53 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2024/12/15 01:14:55 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2024/12/15 01:14:56 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kodozut2vagi/dst"
2024/12/15 01:14:57 DEBUG : Starting OpenDrive session with ID: 2d988c1bb555512e374eb5e992af6fd0b8659b83ef49cdae4560169f35c306f0
2024/12/15 01:14:57 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kodozut2vagi/backup"
2024/12/15 01:14:58 DEBUG : Starting OpenDrive session with ID: 38ff94cbbb2fc7ae71684e8e9a19d7f5c2a0cd733a3c90f931280e386926066a
2024/12/15 01:14:59 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/15 01:14:59 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:14:59 DEBUG : two: Unchanged skipping
2024/12/15 01:14:59 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for checks to finish
2024/12/15 01:14:59 INFO  : one: Moved (server-side)
2024/12/15 01:14:59 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for transfers to finish
2024/12/15 01:15:00 DEBUG : one: Uploading chunk 0, size=4, remain=0
2024/12/15 01:15:01 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2024/12/15 01:15:01 INFO  : one: Copied (new)
2024/12/15 01:15:01 DEBUG : Waiting for deletions to finish
2024/12/15 01:15:02 INFO  : three.txt: Moved (server-side)
2024/12/15 01:15:02 INFO  : three.txt: Moved into backup dir
2024/12/15 01:15:03 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2024/12/15 01:15:05 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/15 01:15:05 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:15:05 DEBUG : two: Unchanged skipping
2024/12/15 01:15:05 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for checks to finish
2024/12/15 01:15:05 INFO  : one: Deleted
2024/12/15 01:15:05 INFO  : one: Moved (server-side)
2024/12/15 01:15:05 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for transfers to finish
2024/12/15 01:15:06 DEBUG : one: Uploading chunk 0, size=5, remain=0
2024/12/15 01:15:07 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2024/12/15 01:15:07 INFO  : one: Copied (new)
2024/12/15 01:15:07 DEBUG : Waiting for deletions to finish
2024/12/15 01:15:07 INFO  : three.txt: Deleted
2024/12/15 01:15:08 INFO  : three.txt: Moved (server-side)
2024/12/15 01:15:08 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDir (19.31s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:15:11 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2024/12/15 01:15:13 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2024/12/15 01:15:14 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2024/12/15 01:15:16 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kodozut2vagi/dst"
2024/12/15 01:15:16 DEBUG : Starting OpenDrive session with ID: 3f612e1398ee1d608933d68fad839f7147d1ef704fc03e5aba73e9ff81d0ef4e
2024/12/15 01:15:17 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kodozut2vagi/backup"
2024/12/15 01:15:17 DEBUG : Starting OpenDrive session with ID: e548d0f5e63020980f737fcbe85bf721036eea4fccd356cbe10f2fc53e3178db
2024/12/15 01:15:18 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/15 01:15:18 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:15:18 DEBUG : two: Unchanged skipping
2024/12/15 01:15:18 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for checks to finish
2024/12/15 01:15:19 INFO  : one: Moved (server-side) to: one.bak
2024/12/15 01:15:19 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for transfers to finish
2024/12/15 01:15:20 DEBUG : one: Uploading chunk 0, size=4, remain=0
2024/12/15 01:15:21 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2024/12/15 01:15:21 INFO  : one: Copied (new)
2024/12/15 01:15:21 DEBUG : Waiting for deletions to finish
2024/12/15 01:15:21 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/15 01:15:21 INFO  : three.txt: Moved into backup dir
2024/12/15 01:15:22 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2024/12/15 01:15:24 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/15 01:15:24 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:15:24 DEBUG : two: Unchanged skipping
2024/12/15 01:15:24 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for checks to finish
2024/12/15 01:15:24 INFO  : one.bak: Deleted
2024/12/15 01:15:25 INFO  : one: Moved (server-side) to: one.bak
2024/12/15 01:15:25 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for transfers to finish
2024/12/15 01:15:25 DEBUG : one: Uploading chunk 0, size=5, remain=0
2024/12/15 01:15:27 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2024/12/15 01:15:27 INFO  : one: Copied (new)
2024/12/15 01:15:27 DEBUG : Waiting for deletions to finish
2024/12/15 01:15:27 INFO  : three.txt.bak: Deleted
2024/12/15 01:15:27 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/15 01:15:27 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffix (19.49s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "OpenDrive root 'rclone-test-kodozut2vagi'", Local "Local file system at /tmp/rclone171650411", Modify Window "1s"
2024/12/15 01:15:31 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2024/12/15 01:15:32 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2024/12/15 01:15:34 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2024/12/15 01:15:35 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kodozut2vagi/dst"
2024/12/15 01:15:36 DEBUG : Starting OpenDrive session with ID: 10729c44d1d1f4172f7a4dc0f6417d765da65553272f9e4b135c4d5277ee80e6
2024/12/15 01:15:36 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/15 01:15:36 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:15:36 DEBUG : two: Unchanged skipping
2024/12/15 01:15:36 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for checks to finish
2024/12/15 01:15:37 DEBUG : one: same parent dir (ODFfNzgyOTE3Ml9jNzg2Sg) - using file/rename instead of move_copy for one.bak
2024/12/15 01:15:37 INFO  : one: Moved (server-side) to: one.bak
2024/12/15 01:15:37 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for transfers to finish
2024/12/15 01:15:38 DEBUG : one: Uploading chunk 0, size=4, remain=0
2024/12/15 01:15:39 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2024/12/15 01:15:39 INFO  : one: Copied (new)
2024/12/15 01:15:39 DEBUG : Waiting for deletions to finish
2024/12/15 01:15:39 DEBUG : three.txt: same parent dir (ODFfNzgyOTE3Ml9jNzg2Sg) - using file/rename instead of move_copy for three.txt.bak
2024/12/15 01:15:39 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/15 01:15:39 INFO  : three.txt: Moved into backup dir
2024/12/15 01:15:40 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2024/12/15 01:15:42 DEBUG : one.bak: Excluded (Path Filter)
2024/12/15 01:15:42 DEBUG : one.bak: Excluded
2024/12/15 01:15:42 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/12/15 01:15:42 DEBUG : three.txt.bak: Excluded
2024/12/15 01:15:42 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/15 01:15:42 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2024/12/15 01:15:42 DEBUG : two: Unchanged skipping
2024/12/15 01:15:42 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for checks to finish
2024/12/15 01:15:42 INFO  : one.bak: Deleted
2024/12/15 01:15:42 DEBUG : one: same parent dir (ODFfNzgyOTE3Ml9jNzg2Sg) - using file/rename instead of move_copy for one.bak
2024/12/15 01:15:43 INFO  : one: Moved (server-side) to: one.bak
2024/12/15 01:15:43 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi/dst': Waiting for transfers to finish
2024/12/15 01:15:43 DEBUG : one: Uploading chunk 0, size=5, remain=0
2024/12/15 01:15:44 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2024/12/15 01:15:44 INFO  : one: Copied (new)
2024/12/15 01:15:44 DEBUG : Waiting for deletions to finish
2024/12/15 01:15:45 INFO  : three.txt.bak: Deleted
2024/12/15 01:15:45 DEBUG : three.txt: same parent dir (ODFfNzgyOTE3Ml9jNzg2Sg) - using file/rename instead of move_copy for three.txt.bak
2024/12/15 01:15:45 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/15 01:15:45 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirSuffixOnly (17.37s)
PASS
2024/12/15 01:15:47 DEBUG : OpenDrive root 'rclone-test-kodozut2vagi': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestServerSideCopyOverSelf|TestServerSideMoveOverSelf|TestSyncBackupDir|TestSyncBackupDirSuffixOnly|TestSyncBackupDirWithSuffix|TestSyncIgnoreTimes)$'" - Finished OK in 1m33.586558073s (try 2/5)