"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveOverSelf|TestSyncBackupDir|TestSyncBackupDirWithSuffix|TestSyncSuffix)$'" - Starting (try 3/5)
2025/09/23 15:49:44 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kokoher5jupa"
2025/09/23 15:49:44 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/09/23 15:49:44 DEBUG : Starting OpenDrive session with ID: 1ff319b8edffa2b63fe0cd2bff3a7f4f080ec231e4028089f47aefd30cb1230d
2025/09/23 15:49:45 DEBUG : Creating backend with remote "/tmp/rclone458858447"
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "OpenDrive root 'rclone-test-kokoher5jupa'", Local "Local file system at /tmp/rclone458858447", Modify Window "1s"
2025/09/23 15:49:46 DEBUG : sub dir/hello world: Uploading chunk 0, size=11, remain=0
2025/09/23 15:49:48 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-macodub9fuke"
2025/09/23 15:49:48 DEBUG : Starting OpenDrive session with ID: 9dfcaa8f0a1b5aa55fa302254ba6affc0807782025e0a07a92f49229837cf394
    sync_test.go:701: Server side copy (if possible) OpenDrive root 'rclone-test-kokoher5jupa' -> OpenDrive root 'rclone-test-macodub9fuke'
2025/09/23 15:49:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/09/23 15:49:49 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Waiting for checks to finish
2025/09/23 15:49:49 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Waiting for transfers to finish
2025/09/23 15:49:50 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/09/23 15:49:50 INFO  : sub dir/hello world: Copied (server-side copy)
2025/09/23 15:49:51 DEBUG : sub dir/hello world: Uploading chunk 0, size=17, remain=0
2025/09/23 15:49:53 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Using server-side directory move
2025/09/23 15:49:53 INFO  : OpenDrive root 'rclone-test-macodub9fuke': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/09/23 15:49:53 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Waiting for checks to finish
2025/09/23 15:49:53 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/09/23 15:49:53 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Waiting for transfers to finish
2025/09/23 15:49:53 INFO  : sub dir/hello world: Deleted
2025/09/23 15:49:54 INFO  : sub dir/hello world: Moved (server-side)
2025/09/23 15:49:56 DEBUG : sub dir/hello world: Uploading chunk 0, size=24, remain=0
2025/09/23 15:49:57 DEBUG : testing file moves
2025/09/23 15:49:57 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/09/23 15:49:57 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Waiting for checks to finish
2025/09/23 15:49:57 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Waiting for transfers to finish
2025/09/23 15:49:58 INFO  : sub dir/hello world: Deleted
2025/09/23 15:49:58 INFO  : sub dir/hello world: Moved (server-side)
2025/09/23 15:49:59 DEBUG : OpenDrive root 'rclone-test-macodub9fuke': Purge remote
--- PASS: TestServerSideMoveOverSelf (16.06s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "OpenDrive root 'rclone-test-kokoher5jupa'", Local "Local file system at /tmp/rclone458858447", Modify Window "1s"
2025/09/23 15:50:01 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-cumarug0vora"
2025/09/23 15:50:01 DEBUG : Starting OpenDrive session with ID: 739fedfa05d6dcb78f9f6c0029905fa40e7a86be32a16d46426ed7cf15e3bbee
2025/09/23 15:50:02 DEBUG : potato2: Uploading chunk 0, size=60, remain=0
2025/09/23 15:50:04 DEBUG : empty space: Uploading chunk 0, size=1, remain=0
2025/09/23 15:50:07 DEBUG : potato3: Uploading chunk 0, size=68, remain=0
2025/09/23 15:50:08 INFO  : tomatoDir: Making directory
    sync_test.go:1735: Server side move (if possible) OpenDrive root 'rclone-test-kokoher5jupa' -> OpenDrive root 'rclone-test-cumarug0vora'
2025/09/23 15:50:10 DEBUG : empty space: Uploading chunk 0, size=1, remain=0
2025/09/23 15:50:12 DEBUG : potato3: Uploading chunk 0, size=60, remain=0
2025/09/23 15:50:13 DEBUG : OpenDrive root 'rclone-test-cumarug0vora': Using server-side directory move
2025/09/23 15:50:13 INFO  : OpenDrive root 'rclone-test-cumarug0vora': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/09/23 15:50:13 DEBUG : potato2: Need to transfer - File not found at Destination
2025/09/23 15:50:13 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2025/09/23 15:50:13 DEBUG : empty space: Unchanged skipping
2025/09/23 15:50:13 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/09/23 15:50:14 INFO  : potato3: Deleted
2025/09/23 15:50:14 DEBUG : OpenDrive root 'rclone-test-cumarug0vora': Waiting for checks to finish
2025/09/23 15:50:14 INFO  : empty space: Deleted
2025/09/23 15:50:14 DEBUG : OpenDrive root 'rclone-test-cumarug0vora': Waiting for transfers to finish
2025/09/23 15:50:14 INFO  : potato2: Moved (server-side)
2025/09/23 15:50:14 INFO  : potato3: Moved (server-side)
2025/09/23 15:50:14 INFO  : tomatoDir: Removing directory
2025/09/23 15:50:15 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa': deleted 1 directories
2025/09/23 15:50:15 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-varumiy6qato"
2025/09/23 15:50:15 DEBUG : Config file has changed externally - reloading
2025/09/23 15:50:16 DEBUG : Starting OpenDrive session with ID: d994d228b6faa440fe065336313e66a1aaafcccaf47131843defccb2f23e72c9
2025/09/23 15:50:16 INFO  : tomatoDir: Making directory
2025/09/23 15:50:17 DEBUG : OpenDrive root 'rclone-test-varumiy6qato': Using server-side directory move
2025/09/23 15:50:17 DEBUG : same parent dir (0) - using folder/rename instead of move_copy
2025/09/23 15:50:17 INFO  : OpenDrive root 'rclone-test-varumiy6qato': Server side directory move succeeded
2025/09/23 15:50:18 ERROR : error listing: directory not found
2025/09/23 15:50:18 ERROR : error listing: directory not found
2025/09/23 15:50:18 DEBUG : OpenDrive root 'rclone-test-varumiy6qato': Purge remote
2025/09/23 15:50:18 DEBUG : OpenDrive root 'rclone-test-cumarug0vora': Purge remote
2025/09/23 15:50:19 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.30s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "OpenDrive root 'rclone-test-kokoher5jupa'", Local "Local file system at /tmp/rclone458858447", Modify Window "1s"
2025/09/23 15:50:20 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2025/09/23 15:50:22 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2025/09/23 15:50:24 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2025/09/23 15:50:26 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kokoher5jupa/dst"
2025/09/23 15:50:26 DEBUG : Starting OpenDrive session with ID: 99a13dc969ff53c466091072e264754d06abbf6bb9bcc77d6344a2808efe2faf
2025/09/23 15:50:27 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kokoher5jupa/backup"
2025/09/23 15:50:27 DEBUG : Starting OpenDrive session with ID: 3b2c0b6b7a375c71a7e71f5a463b6938ebc3657e3d7c8ce9bc463c8f81532c26
2025/09/23 15:50:28 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/09/23 15:50:28 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/09/23 15:50:28 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for checks to finish
2025/09/23 15:50:28 DEBUG : two: Unchanged skipping
2025/09/23 15:50:29 INFO  : one: Moved (server-side)
2025/09/23 15:50:29 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for transfers to finish
2025/09/23 15:50:30 DEBUG : one: Uploading chunk 0, size=4, remain=0
2025/09/23 15:50:31 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2025/09/23 15:50:31 INFO  : one: Copied (new)
2025/09/23 15:50:31 DEBUG : Waiting for deletions to finish
2025/09/23 15:50:32 INFO  : three.txt: Moved (server-side)
2025/09/23 15:50:32 INFO  : three.txt: Moved into backup dir
2025/09/23 15:50:33 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2025/09/23 15:50:35 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/09/23 15:50:35 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for checks to finish
2025/09/23 15:50:35 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/09/23 15:50:35 DEBUG : two: Unchanged skipping
2025/09/23 15:50:35 INFO  : one: Deleted
2025/09/23 15:50:36 INFO  : one: Moved (server-side)
2025/09/23 15:50:36 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for transfers to finish
2025/09/23 15:50:36 DEBUG : one: Uploading chunk 0, size=5, remain=0
2025/09/23 15:50:37 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2025/09/23 15:50:37 INFO  : one: Copied (new)
2025/09/23 15:50:37 DEBUG : Waiting for deletions to finish
2025/09/23 15:50:38 INFO  : three.txt: Deleted
2025/09/23 15:50:38 INFO  : three.txt: Moved (server-side)
2025/09/23 15:50:38 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDir (21.74s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "OpenDrive root 'rclone-test-kokoher5jupa'", Local "Local file system at /tmp/rclone458858447", Modify Window "1s"
2025/09/23 15:50:42 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2025/09/23 15:50:44 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2025/09/23 15:50:46 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2025/09/23 15:50:47 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kokoher5jupa/dst"
2025/09/23 15:50:48 DEBUG : Starting OpenDrive session with ID: 2251cee05dcbd513adfba5ac15978faee7e74df4608a299f2aba43d0abedf98a
2025/09/23 15:50:48 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kokoher5jupa/backup"
2025/09/23 15:50:49 DEBUG : Starting OpenDrive session with ID: d9f892aa43ac5092524d4ca781515adee7698b2204c5ccce855d2041d3fbad6a
2025/09/23 15:50:50 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/09/23 15:50:50 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/09/23 15:50:50 DEBUG : two: Unchanged skipping
2025/09/23 15:50:50 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for checks to finish
2025/09/23 15:50:51 INFO  : one: Moved (server-side) to: one.bak
2025/09/23 15:50:51 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for transfers to finish
2025/09/23 15:50:52 DEBUG : one: Uploading chunk 0, size=4, remain=0
2025/09/23 15:50:53 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2025/09/23 15:50:53 INFO  : one: Copied (new)
2025/09/23 15:50:53 DEBUG : Waiting for deletions to finish
2025/09/23 15:50:53 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/09/23 15:50:53 INFO  : three.txt: Moved into backup dir
2025/09/23 15:50:55 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2025/09/23 15:50:56 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/09/23 15:50:56 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/09/23 15:50:56 DEBUG : two: Unchanged skipping
2025/09/23 15:50:56 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for checks to finish
2025/09/23 15:50:57 INFO  : one.bak: Deleted
2025/09/23 15:50:57 INFO  : one: Moved (server-side) to: one.bak
2025/09/23 15:50:57 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa/dst': Waiting for transfers to finish
2025/09/23 15:50:58 DEBUG : one: Uploading chunk 0, size=5, remain=0
2025/09/23 15:50:59 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2025/09/23 15:50:59 INFO  : one: Copied (new)
2025/09/23 15:50:59 DEBUG : Waiting for deletions to finish
2025/09/23 15:50:59 INFO  : three.txt.bak: Deleted
2025/09/23 15:51:00 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/09/23 15:51:00 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffix (21.69s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "OpenDrive root 'rclone-test-kokoher5jupa'", Local "Local file system at /tmp/rclone458858447", Modify Window "1s"
2025/09/23 15:51:04 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2025/09/23 15:51:06 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2025/09/23 15:51:07 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2025/09/23 15:51:09 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-kokoher5jupa/dst"
2025/09/23 15:51:09 DEBUG : Starting OpenDrive session with ID: 3a3a9a9f269f5f3370b8f09faacd2e08f2cfc111d76d07c5077ce1f4169daa78
2025/09/23 15:51:10 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/09/23 15:51:10 DEBUG : one: same parent dir (ODFfOTQ2MDMyN195ZXpXTg) - using file/rename instead of move_copy for one.bak
2025/09/23 15:51:10 INFO  : one: Moved (server-side) to: one.bak
2025/09/23 15:51:11 DEBUG : one: Uploading chunk 0, size=4, remain=0
2025/09/23 15:51:13 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2025/09/23 15:51:13 INFO  : one: Copied (new)
2025/09/23 15:51:13 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/09/23 15:51:13 DEBUG : two: Unchanged skipping
2025/09/23 15:51:13 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/09/23 15:51:13 DEBUG : three.txt: same parent dir (ODFfOTQ2MDMyN195ZXpXTg) - using file/rename instead of move_copy for three.txt.bak
2025/09/23 15:51:14 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/09/23 15:51:14 DEBUG : three.txt: Uploading chunk 0, size=6, remain=0
2025/09/23 15:51:16 DEBUG : three.txt: md5 = 91341eed84691a83caea73aa785736d5 OK
2025/09/23 15:51:16 INFO  : three.txt: Copied (new)
2025/09/23 15:51:16 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/09/23 15:51:17 INFO  : one.bak: Deleted
2025/09/23 15:51:17 DEBUG : one: same parent dir (ODFfOTQ2MDMyN195ZXpXTg) - using file/rename instead of move_copy for one.bak
2025/09/23 15:51:17 INFO  : one: Moved (server-side) to: one.bak
2025/09/23 15:51:18 DEBUG : one: Uploading chunk 0, size=5, remain=0
2025/09/23 15:51:19 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2025/09/23 15:51:19 INFO  : one: Copied (new)
2025/09/23 15:51:19 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/09/23 15:51:19 DEBUG : two: Unchanged skipping
2025/09/23 15:51:20 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/09/23 15:51:20 INFO  : three.txt.bak: Deleted
2025/09/23 15:51:20 DEBUG : three.txt: same parent dir (ODFfOTQ2MDMyN195ZXpXTg) - using file/rename instead of move_copy for three.txt.bak
2025/09/23 15:51:20 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/09/23 15:51:21 DEBUG : three.txt: Uploading chunk 0, size=19, remain=0
2025/09/23 15:51:22 DEBUG : three.txt: md5 = 423e01c5e84a30d129b97aedb6e219a9 OK
2025/09/23 15:51:22 INFO  : three.txt: Copied (new)
--- PASS: TestSyncSuffix (22.30s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "OpenDrive root 'rclone-test-kokoher5jupa'", Local "Local file system at /tmp/rclone458858447", Modify Window "1s"
2025/09/23 15:51:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/09/23 15:51:25 INFO  : sub dir: Making directory
2025/09/23 15:51:25 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
--- PASS: TestNothingToTransferWithEmptyDirs (17.13s)
PASS
2025/09/23 15:51:42 DEBUG : OpenDrive root 'rclone-test-kokoher5jupa': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveOverSelf|TestSyncBackupDir|TestSyncBackupDirWithSuffix|TestSyncSuffix)$'" - Finished OK in 1m58.78934499s (try 3/5)