"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestBase64|TestConflicting|TestManualTransformFile|TestMove|TestSyncOverlapWithFilter|TestTransformFile)$'" - Starting (try 3/5) 2025/07/19 03:32:26 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-nupotag3jevu" 2025/07/19 03:32:26 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/07/19 03:32:27 DEBUG : Starting OpenDrive session with ID: b7b70741dc0daff443bafa37186a096e1635d931cb1374ce8d7a20fe5b76329a 2025/07/19 03:32:27 DEBUG : Creating backend with remote "/tmp/rclone526832348" === RUN TestSyncOverlapWithFilter run.go:180: Remote "OpenDrive root 'rclone-test-nupotag3jevu'", Local "Local file system at /tmp/rclone526832348", Modify Window "1s" 2025/07/19 03:32:27 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-nupotag3jevu/rclone-sync-test" 2025/07/19 03:32:27 DEBUG : Starting OpenDrive session with ID: b75b13bb4eec6453d9b8283a5a72f272af23acdd8c8c4f46ae8d771f78f0874b 2025/07/19 03:32:29 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-nupotag3jevu/rclone-sync-test-include/layer2" 2025/07/19 03:32:30 DEBUG : Starting OpenDrive session with ID: 57514abb4cc58c489b7d1148b24b0cb1ff87bb445fc83b2feac90d0cd5c9eb15 2025/07/19 03:32:31 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-nupotag3jevu/rclone-sync-test-ignore-file" 2025/07/19 03:32:32 DEBUG : Starting OpenDrive session with ID: c34fe344af00f7eb8b62d2644609a7f84c8bfea75e9a6a63ef381c5a74b338d5 2025/07/19 03:32:34 DEBUG : rclone-sync-test-ignore-file/.ignore: Uploading chunk 0, size=1, remain=0 2025/07/19 03:32:36 DEBUG : rclone-sync-test: Excluded 2025/07/19 03:32:36 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/07/19 03:32:36 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/07/19 03:32:36 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu/rclone-sync-test': Waiting for checks to finish 2025/07/19 03:32:36 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu/rclone-sync-test': Waiting for transfers to finish 2025/07/19 03:32:36 DEBUG : Waiting for deletions to finish 2025/07/19 03:32:36 INFO : There was nothing to transfer 2025/07/19 03:32:37 DEBUG : rclone-sync-test: Excluded 2025/07/19 03:32:37 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/07/19 03:32:38 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/07/19 03:32:38 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:32:38 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:32:38 DEBUG : Waiting for deletions to finish 2025/07/19 03:32:38 INFO : rclone-sync-test-include: Removing directory 2025/07/19 03:32:38 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': deleted 1 directories 2025/07/19 03:32:38 INFO : There was nothing to transfer 2025/07/19 03:32:39 DEBUG : rclone-sync-test: Excluded 2025/07/19 03:32:39 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/07/19 03:32:39 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/07/19 03:32:39 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/07/19 03:32:39 DEBUG : Waiting for deletions to finish 2025/07/19 03:32:39 INFO : There was nothing to transfer 2025/07/19 03:32:40 DEBUG : rclone-sync-test: Excluded 2025/07/19 03:32:40 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/07/19 03:32:40 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:32:40 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:32:40 DEBUG : Waiting for deletions to finish 2025/07/19 03:32:40 INFO : There was nothing to transfer 2025/07/19 03:32:40 DEBUG : Excluded 2025/07/19 03:32:40 DEBUG : rclone-sync-test: Excluded 2025/07/19 03:32:40 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/07/19 03:32:40 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/07/19 03:32:40 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/07/19 03:32:40 DEBUG : Waiting for deletions to finish 2025/07/19 03:32:40 INFO : There was nothing to transfer --- PASS: TestSyncOverlapWithFilter (15.05s) === RUN TestConflicting run.go:180: Remote "OpenDrive root 'rclone-test-nupotag3jevu'", Local "Local file system at /tmp/rclone526832348", Modify Window "1s" 2025/07/19 03:32:42 INFO : toe: Making directory 2025/07/19 03:32:42 INFO : toe/toe: Making directory 2025/07/19 03:32:43 DEBUG : toe/toe/toe: Need to transfer - File not found at Destination 2025/07/19 03:32:43 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:32:43 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:32:44 DEBUG : toe/toe/toe: Uploading chunk 0, size=11, remain=0 2025/07/19 03:32:45 DEBUG : toe/toe/toe: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/07/19 03:32:45 INFO : toe/toe/toe: Copied (new) 2025/07/19 03:32:45 DEBUG : Waiting for deletions to finish fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:289: Sleeping for 6s just to make sure --- PASS: TestConflicting (12.24s) === RUN TestMove run.go:180: Remote "OpenDrive root 'rclone-test-nupotag3jevu'", Local "Local file system at /tmp/rclone526832348", Modify Window "1s" 2025/07/19 03:32:54 DEBUG : empty_dir: Making directory with metadata 2025/07/19 03:32:54 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/07/19 03:32:54 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:32:54 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:32:54 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:32:54 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:32:54 INFO : tictacempty_dir: Making directory 2025/07/19 03:32:55 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:32:55 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:32:55 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:32:55 INFO : tictactoe: Making directory 2025/07/19 03:32:55 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:32:55 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:32:55 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/07/19 03:32:55 INFO : tictactoe/tictactoe: Making directory 2025/07/19 03:32:55 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/07/19 03:32:55 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/07/19 03:32:55 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:32:55 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/07/19 03:32:55 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:32:55 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:32:55 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:32:55 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:32:56 DEBUG : tictactoe/tictactoe/tictactoe.txt: Uploading chunk 0, size=11, remain=0 2025/07/19 03:32:57 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/07/19 03:32:57 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:32:57 INFO : toe/toe/toe.txt: Deleted 2025/07/19 03:32:57 INFO : toe/toe: Removing directory 2025/07/19 03:32:57 INFO : toe: Removing directory 2025/07/19 03:32:57 INFO : empty_dir: Removing directory 2025/07/19 03:32:57 DEBUG : Local file system at /tmp/rclone526832348: deleted 3 directories --- PASS: TestMove (5.49s) === RUN TestTransformFile run.go:180: Remote "OpenDrive root 'rclone-test-nupotag3jevu'", Local "Local file system at /tmp/rclone526832348", Modify Window "1s" 2025/07/19 03:33:00 DEBUG : empty_dir: Making directory with metadata 2025/07/19 03:33:00 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/07/19 03:33:00 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:00 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:00 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:00 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:00 INFO : tictacempty_dir: Making directory 2025/07/19 03:33:00 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:00 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:00 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:00 INFO : tictactoe: Making directory 2025/07/19 03:33:00 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:00 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:00 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/07/19 03:33:00 INFO : tictactoe/tictactoe: Making directory 2025/07/19 03:33:01 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/07/19 03:33:01 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/07/19 03:33:01 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:01 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/07/19 03:33:01 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:01 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:01 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:33:01 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:33:02 DEBUG : tictactoe/tictactoe/tictactoe.txt: Uploading chunk 0, size=11, remain=0 2025/07/19 03:33:02 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/07/19 03:33:02 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:02 INFO : toe/toe/toe.txt: Deleted 2025/07/19 03:33:02 INFO : toe/toe: Removing directory 2025/07/19 03:33:02 INFO : toe: Removing directory 2025/07/19 03:33:02 INFO : empty_dir: Removing directory 2025/07/19 03:33:02 DEBUG : Local file system at /tmp/rclone526832348: deleted 3 directories 2025/07/19 03:33:03 DEBUG : tictactoe/tictactoe/tictactoe.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2025/07/19 03:33:03 DEBUG : tictactoe/tictactoe/tictactoe.txt: transformed to: toe/toe/toe.txt 2025/07/19 03:33:03 DEBUG : tictactoe/tictactoe/tictactoe.txt: transformed to: toe/toe/toe.txt 2025/07/19 03:33:03 DEBUG : tictactoe/tictactoe/tictactoe.txt: transformed to: toe/toe/toe.txt 2025/07/19 03:33:04 INFO : tictactoe/tictactoe/tictactoe.txt: Moved (server-side) to: toe/toe/toe.txt --- PASS: TestTransformFile (7.92s) === RUN TestManualTransformFile run.go:180: Remote "OpenDrive root 'rclone-test-nupotag3jevu'", Local "Local file system at /tmp/rclone526832348", Modify Window "1s" 2025/07/19 03:33:08 DEBUG : Reset feature "Copy" 2025/07/19 03:33:08 DEBUG : Reset feature "Move" 2025/07/19 03:33:08 DEBUG : Reset feature "Copy" 2025/07/19 03:33:08 DEBUG : Reset feature "Move" 2025/07/19 03:33:08 DEBUG : empty_dir: Making directory with metadata 2025/07/19 03:33:08 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/07/19 03:33:08 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:08 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:08 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:08 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:08 INFO : tictacempty_dir: Making directory 2025/07/19 03:33:08 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/07/19 03:33:08 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:08 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:08 INFO : tictactoe: Making directory 2025/07/19 03:33:08 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:08 DEBUG : toe: transformed to: tictactoe 2025/07/19 03:33:08 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/07/19 03:33:08 INFO : tictactoe/tictactoe: Making directory 2025/07/19 03:33:09 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/07/19 03:33:09 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/07/19 03:33:09 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:09 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/07/19 03:33:09 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:09 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:33:09 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:33:09 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:10 DEBUG : tictactoe/tictactoe/tictactoe.txt: Uploading chunk 0, size=11, remain=0 2025/07/19 03:33:11 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/07/19 03:33:11 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/07/19 03:33:11 INFO : toe/toe/toe.txt: Deleted 2025/07/19 03:33:11 INFO : toe/toe: Removing directory 2025/07/19 03:33:11 INFO : toe: Removing directory 2025/07/19 03:33:11 INFO : empty_dir: Removing directory 2025/07/19 03:33:11 DEBUG : Local file system at /tmp/rclone526832348: deleted 3 directories 2025/07/19 03:33:11 DEBUG : tictactoe/tictactoe/tictactoe.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2025/07/19 03:33:11 DEBUG : tictactoe/tictactoe/tictactoe.txt: transformed to: toe/toe/toe.txt 2025/07/19 03:33:11 DEBUG : tictactoe/tictactoe/tictactoe.txt: transformed to: toe/toe/toe.txt 2025/07/19 03:33:11 DEBUG : tictactoe/tictactoe/tictactoe.txt: transformed to: toe/toe/toe.txt 2025/07/19 03:33:13 DEBUG : toe/toe/toe.txt: Uploading chunk 0, size=11, remain=0 2025/07/19 03:33:14 DEBUG : tictactoe/tictactoe/tictactoe.txt: Src hash empty - aborting Dst hash check 2025/07/19 03:33:14 INFO : tictactoe/tictactoe/tictactoe.txt: Copied (new) to: toe/toe/toe.txt 2025/07/19 03:33:14 INFO : tictactoe/tictactoe/tictactoe.txt: Deleted --- PASS: TestManualTransformFile (9.84s) === RUN TestBase64 run.go:180: Remote "OpenDrive root 'rclone-test-nupotag3jevu'", Local "Local file system at /tmp/rclone526832348", Modify Window "1s" 2025/07/19 03:33:17 DEBUG : toe: transformed to: dG9l 2025/07/19 03:33:18 DEBUG : toe: transformed to: dG9l 2025/07/19 03:33:18 INFO : dG9l: Making directory 2025/07/19 03:33:18 DEBUG : toe: transformed to: dG9l 2025/07/19 03:33:18 DEBUG : toe: transformed to: dG9l 2025/07/19 03:33:18 DEBUG : toe/toe: transformed to: dG9l/dG9l 2025/07/19 03:33:18 INFO : dG9l/dG9l: Making directory 2025/07/19 03:33:18 DEBUG : toe/toe: transformed to: dG9l/dG9l 2025/07/19 03:33:18 DEBUG : toe.txt: transformed to: dG9lLnR4dA== 2025/07/19 03:33:18 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA== 2025/07/19 03:33:18 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/07/19 03:33:18 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA== 2025/07/19 03:33:18 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for checks to finish 2025/07/19 03:33:18 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Waiting for transfers to finish 2025/07/19 03:33:19 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Uploading chunk 0, size=11, remain=0 2025/07/19 03:33:20 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/07/19 03:33:20 INFO : toe/toe/toe.txt: Copied (new) to: dG9l/dG9l/dG9lLnR4dA== 2025/07/19 03:33:20 DEBUG : Waiting for deletions to finish 2025/07/19 03:33:21 DEBUG : dG9l: transformed to: toe 2025/07/19 03:33:21 DEBUG : dG9l: transformed to: toe 2025/07/19 03:33:21 DEBUG : toe: Directory modification time the same (differ by -98.079497ms, within tolerance 1s) 2025/07/19 03:33:21 DEBUG : Added delayed dir = "toe", newDst=toe 2025/07/19 03:33:21 DEBUG : dG9l: transformed to: toe 2025/07/19 03:33:21 DEBUG : dG9l/dG9l: transformed to: toe/toe 2025/07/19 03:33:21 INFO : toe/toe: Set directory modification time (using SetModTime) 2025/07/19 03:33:21 DEBUG : Added delayed dir = "toe/toe", newDst=toe/toe 2025/07/19 03:33:21 DEBUG : dG9lLnR4dA==: transformed to: toe.txt 2025/07/19 03:33:21 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Size and modification time the same (differ by 499.999999ms, within tolerance 1s) 2025/07/19 03:33:21 DEBUG : dG9l/dG9l/dG9lLnR4dA==: transformed to: toe/toe/toe.txt 2025/07/19 03:33:21 DEBUG : Local file system at /tmp/rclone526832348: Waiting for checks to finish 2025/07/19 03:33:21 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Unchanged skipping 2025/07/19 03:33:21 DEBUG : Local file system at /tmp/rclone526832348: Waiting for transfers to finish 2025/07/19 03:33:21 DEBUG : Waiting for deletions to finish --- PASS: TestBase64 (5.76s) PASS 2025/07/19 03:33:23 DEBUG : OpenDrive root 'rclone-test-nupotag3jevu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestBase64|TestConflicting|TestManualTransformFile|TestMove|TestSyncOverlapWithFilter|TestTransformFile)$'" - Finished OK in 57.731417898s (try 3/5)