"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideMoveOverSelf|TestSyncCopyDest|TestSyncSuffix)$'" - Starting (try 2/5) 2025/04/07 03:00:35 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-cecibuy2lude" 2025/04/07 03:00:35 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/07 03:00:35 DEBUG : Starting OpenDrive session with ID: 00c487642ad453470e513bf1b758801cb8c9645b6d6359a44542b8204d660e14 2025/04/07 03:00:36 DEBUG : Creating backend with remote "/tmp/rclone3295788445" === RUN TestServerSideMoveOverSelf run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", Modify Window "1s" 2025/04/07 03:00:37 DEBUG : sub dir/hello world: Uploading chunk 0, size=11, remain=0 2025/04/07 03:00:38 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-nubosol0wale" 2025/04/07 03:00:39 DEBUG : Starting OpenDrive session with ID: beba048a924a99774dd46ac40751e15203b13c0f0bbc7909698417bd09e558b7 sync_test.go:671: Server side copy (if possible) OpenDrive root 'rclone-test-cecibuy2lude' -> OpenDrive root 'rclone-test-nubosol0wale' 2025/04/07 03:00:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/07 03:00:39 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Waiting for checks to finish 2025/04/07 03:00:39 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Waiting for transfers to finish 2025/04/07 03:00:40 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check 2025/04/07 03:00:40 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", Modify Window "1s" 2025/04/07 03:00:41 DEBUG : sub dir/hello world: Uploading chunk 0, size=17, remain=0 2025/04/07 03:00:42 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Using server-side directory move 2025/04/07 03:00:42 INFO : OpenDrive root 'rclone-test-nubosol0wale': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/07 03:00:43 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/07 03:00:43 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Waiting for checks to finish 2025/04/07 03:00:43 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Waiting for transfers to finish 2025/04/07 03:00:43 INFO : sub dir/hello world: Deleted 2025/04/07 03:00:43 INFO : sub dir/hello world: Moved (server-side) 2025/04/07 03:00:45 DEBUG : sub dir/hello world: Uploading chunk 0, size=24, remain=0 2025/04/07 03:00:46 DEBUG : testing file moves 2025/04/07 03:00:47 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Waiting for checks to finish 2025/04/07 03:00:47 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/07 03:00:47 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Waiting for transfers to finish 2025/04/07 03:00:47 INFO : sub dir/hello world: Deleted 2025/04/07 03:00:47 INFO : sub dir/hello world: Moved (server-side) run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", Modify Window "1s" 2025/04/07 03:00:48 DEBUG : OpenDrive root 'rclone-test-nubosol0wale': Purge remote --- PASS: TestServerSideMoveOverSelf (14.56s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", Modify Window "1s" 2025/04/07 03:00:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/07 03:00:50 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/07 03:00:50 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude': Waiting for checks to finish 2025/04/07 03:00:50 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude': Waiting for transfers to finish 2025/04/07 03:00:52 DEBUG : sub dir/hello world: Uploading chunk 0, size=11, remain=0 2025/04/07 03:00:53 DEBUG : nested/sub dir/file: Uploading chunk 0, size=6, remain=0 2025/04/07 03:00:53 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/04/07 03:00:53 INFO : sub dir/hello world: Copied (new) 2025/04/07 03:00:53 INFO : sub dir/hello world: Deleted 2025/04/07 03:00:54 DEBUG : nested/sub dir/file: md5 = 83d3784ea62518eafc60e98d84f877ad OK 2025/04/07 03:00:54 INFO : nested/sub dir/file: Copied (new) 2025/04/07 03:00:54 INFO : nested/sub dir/file: Deleted 2025/04/07 03:00:54 INFO : sub dir: Removing directory 2025/04/07 03:00:54 INFO : nested/sub dir: Removing directory 2025/04/07 03:00:54 INFO : nested: Removing directory 2025/04/07 03:00:54 DEBUG : Local file system at /tmp/rclone3295788445: deleted 3 directories run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", 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 --- PASS: TestMoveWithDeleteEmptySrcDirs (13.92s) === RUN TestSyncCopyDest run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", Modify Window "1s" 2025/04/07 03:01:04 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-cecibuy2lude/dst" 2025/04/07 03:01:05 DEBUG : Starting OpenDrive session with ID: 8e3d64e6a72d684853cf282018b01ed7e3cf420433f2c9061ae8424f864d0d09 2025/04/07 03:01:05 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-cecibuy2lude/CopyDest" 2025/04/07 03:01:06 DEBUG : Starting OpenDrive session with ID: 6cfd5cc0789287b91473803614f65e67525b6de8a51e7ac9e5590a94ada35db8 2025/04/07 03:01:07 DEBUG : one: Need to transfer - File not found at Destination 2025/04/07 03:01:07 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for checks to finish 2025/04/07 03:01:07 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for transfers to finish 2025/04/07 03:01:08 DEBUG : one: Uploading chunk 0, size=3, remain=0 2025/04/07 03:01:09 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK 2025/04/07 03:01:09 INFO : one: Copied (new) 2025/04/07 03:01:09 DEBUG : Waiting for deletions to finish 2025/04/07 03:01:10 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for checks to finish 2025/04/07 03:01:10 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/07 03:01:10 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for transfers to finish 2025/04/07 03:01:10 DEBUG : one: Uploading chunk 0, size=5, remain=0 2025/04/07 03:01:11 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK 2025/04/07 03:01:11 INFO : one: Copied (replaced existing) 2025/04/07 03:01:11 DEBUG : Waiting for deletions to finish 2025/04/07 03:01:12 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0 2025/04/07 03:01:14 DEBUG : CopyDest/one: Uploading chunk 0, size=5, remain=0 2025/04/07 03:01:15 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-cecibuy2lude/BackupDir" 2025/04/07 03:01:16 DEBUG : Starting OpenDrive session with ID: 4c3c1ffe4ba473d326d5c7b99c1730573a016c838a78259512fbe84f6c85207f 2025/04/07 03:01:17 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for checks to finish 2025/04/07 03:01:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/07 03:01:17 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/07 03:01:18 INFO : one: Moved (server-side) 2025/04/07 03:01:18 DEBUG : one: Dst hash empty - aborting Src hash check 2025/04/07 03:01:18 INFO : one: Copied (server-side copy) 2025/04/07 03:01:18 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/07 03:01:18 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for transfers to finish 2025/04/07 03:01:18 DEBUG : Waiting for deletions to finish 2025/04/07 03:01:19 DEBUG : CopyDest/two: Uploading chunk 0, size=3, remain=0 2025/04/07 03:01:21 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:21 DEBUG : two: Dst hash empty - aborting Src hash check 2025/04/07 03:01:21 INFO : two: Copied (server-side copy) 2025/04/07 03:01:21 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/07 03:01:21 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for checks to finish 2025/04/07 03:01:21 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:21 DEBUG : one: Unchanged skipping 2025/04/07 03:01:21 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for transfers to finish 2025/04/07 03:01:21 DEBUG : Waiting for deletions to finish 2025/04/07 03:01:22 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:22 DEBUG : one: Unchanged skipping 2025/04/07 03:01:22 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:22 DEBUG : two: Unchanged skipping 2025/04/07 03:01:22 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for checks to finish 2025/04/07 03:01:22 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for transfers to finish 2025/04/07 03:01:22 DEBUG : Waiting for deletions to finish 2025/04/07 03:01:22 INFO : There was nothing to transfer 2025/04/07 03:01:23 DEBUG : CopyDest/three: Uploading chunk 0, size=5, remain=0 2025/04/07 03:01:25 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/07 03:01:25 DEBUG : three: Destination not found in --copy-dest 2025/04/07 03:01:25 DEBUG : three: Need to transfer - File not found at Destination 2025/04/07 03:01:25 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:25 DEBUG : one: Unchanged skipping 2025/04/07 03:01:25 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/04/07 03:01:25 DEBUG : two: Unchanged skipping 2025/04/07 03:01:25 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for checks to finish 2025/04/07 03:01:25 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude/dst': Waiting for transfers to finish 2025/04/07 03:01:26 DEBUG : three: Uploading chunk 0, size=7, remain=0 2025/04/07 03:01:27 DEBUG : three: md5 = 1bccb9dccb3e9f6a3f9d2a8bdb54b7f5 OK 2025/04/07 03:01:27 INFO : three: Copied (new) 2025/04/07 03:01:27 DEBUG : Waiting for deletions to finish 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 --- PASS: TestSyncCopyDest (33.36s) === RUN TestSyncSuffix run.go:180: Remote "OpenDrive root 'rclone-test-cecibuy2lude'", Local "Local file system at /tmp/rclone3295788445", Modify Window "1s" 2025/04/07 03:01:38 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0 2025/04/07 03:01:40 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0 2025/04/07 03:01:42 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0 2025/04/07 03:01:43 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-cecibuy2lude/dst" 2025/04/07 03:01:44 DEBUG : Starting OpenDrive session with ID: 578d17359f2f19f406d405bfa1ae06980e77d3e2e143e00dffccd84309110515 2025/04/07 03:01:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/07 03:01:44 DEBUG : one: same parent dir (ODFfODIwNzE4NF8zOWhlOQ) - using file/rename instead of move_copy for one.bak 2025/04/07 03:01:45 INFO : one: Moved (server-side) to: one.bak 2025/04/07 03:01:45 DEBUG : one: Uploading chunk 0, size=4, remain=0 2025/04/07 03:01:46 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/04/07 03:01:46 INFO : one: Copied (new) 2025/04/07 03:01:47 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/07 03:01:47 DEBUG : two: Unchanged skipping 2025/04/07 03:01:47 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/07 03:01:47 DEBUG : three.txt: same parent dir (ODFfODIwNzE4NF8zOWhlOQ) - using file/rename instead of move_copy for three.txt.bak 2025/04/07 03:01:47 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/07 03:01:48 DEBUG : three.txt: Uploading chunk 0, size=6, remain=0 2025/04/07 03:01:49 DEBUG : three.txt: md5 = 91341eed84691a83caea73aa785736d5 OK 2025/04/07 03:01:49 INFO : three.txt: Copied (new) 2025/04/07 03:01:50 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/07 03:01:50 INFO : one.bak: Deleted 2025/04/07 03:01:50 DEBUG : one: same parent dir (ODFfODIwNzE4NF8zOWhlOQ) - using file/rename instead of move_copy for one.bak 2025/04/07 03:01:50 INFO : one: Moved (server-side) to: one.bak 2025/04/07 03:01:51 DEBUG : one: Uploading chunk 0, size=5, remain=0 2025/04/07 03:01:52 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2025/04/07 03:01:52 INFO : one: Copied (new) 2025/04/07 03:01:52 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/07 03:01:52 DEBUG : two: Unchanged skipping 2025/04/07 03:01:52 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/07 03:01:53 INFO : three.txt.bak: Deleted 2025/04/07 03:01:53 DEBUG : three.txt: same parent dir (ODFfODIwNzE4NF8zOWhlOQ) - using file/rename instead of move_copy for three.txt.bak 2025/04/07 03:01:53 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/07 03:01:54 DEBUG : three.txt: Uploading chunk 0, size=19, remain=0 2025/04/07 03:01:55 DEBUG : three.txt: md5 = 423e01c5e84a30d129b97aedb6e219a9 OK 2025/04/07 03:01:55 INFO : three.txt: Copied (new) run.go:125: removing dir "dst" failed - try 1/3: folder not empty --- PASS: TestSyncSuffix (20.61s) PASS 2025/04/07 03:01:58 DEBUG : OpenDrive root 'rclone-test-cecibuy2lude': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideMoveOverSelf|TestSyncCopyDest|TestSyncSuffix)$'" - Finished OK in 1m23.744172585s (try 2/5)