"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestAllTag|TestBase64|TestConflicting|TestManualTransformFile|TestMove|TestNothingToTransferWithEmptyDirs|TestRunTwice|TestSyncSuffixKeepExtension|TestTransformFile)$'" - Starting (try 2/5) 2025/09/21 01:31:39 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-jovixox2xeca" 2025/09/21 01:31:39 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/09/21 01:31:40 DEBUG : Creating backend with remote "/tmp/rclone1166820364" === RUN TestSyncSuffixKeepExtension run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:31:49 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-jovixox2xeca/dst" 2025/09/21 01:31:49 DEBUG : Config file has changed externally - reloading 2025/09/21 01:31:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/09/21 01:31:51 INFO : one: Moved (server-side) to: one-2019-01-01 2025/09/21 01:31:53 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2025/09/21 01:31:53 INFO : one: Copied (new) 2025/09/21 01:31:53 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/09/21 01:31:53 DEBUG : two: Unchanged skipping 2025/09/21 01:31:53 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/09/21 01:31:54 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/09/21 01:31:54 DEBUG : three.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:31:54 INFO : three.txt: Copied (new) 2025/09/21 01:31:56 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/09/21 01:31:56 INFO : one-2019-01-01: Deleted 2025/09/21 01:31:57 INFO : one: Moved (server-side) to: one-2019-01-01 2025/09/21 01:31:57 DEBUG : one: Dst hash empty - aborting Src hash check 2025/09/21 01:31:57 INFO : one: Copied (new) 2025/09/21 01:31:57 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/09/21 01:31:57 DEBUG : two: Unchanged skipping 2025/09/21 01:31:58 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/09/21 01:31:58 INFO : three-2019-01-01.txt: Deleted 2025/09/21 01:31:58 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/09/21 01:31:59 DEBUG : three.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:31:59 INFO : three.txt: Copied (new) --- PASS: TestSyncSuffixKeepExtension (22.06s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:02 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:02 INFO : sub dir: Making directory 2025/09/21 01:32:03 INFO : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC 2025/09/21 01:32:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:13 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/09/21 01:32:13 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:22 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dirEmpty not empty`) 2025/09/21 01:32:22 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/21 01:32:22 DEBUG : pacer: Reducing sleep to 15ms 2025/09/21 01:32:23 DEBUG : pacer: Reducing sleep to 11.25ms 2025/09/21 01:32:23 DEBUG : pacer: Reducing sleep to 10ms 2025/09/21 01:32:23 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very/very/very/very not empty`) 2025/09/21 01:32:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/21 01:32:23 DEBUG : pacer: Reducing sleep to 15ms 2025/09/21 01:32:23 DEBUG : pacer: Reducing sleep to 11.25ms 2025/09/21 01:32:23 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very/very not empty`) 2025/09/21 01:32:23 DEBUG : pacer: Rate limited, increasing sleep to 22.5ms 2025/09/21 01:32:24 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very/very not empty`) 2025/09/21 01:32:24 DEBUG : pacer: Rate limited, increasing sleep to 45ms 2025/09/21 01:32:24 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very/very not empty`) 2025/09/21 01:32:24 DEBUG : pacer: Rate limited, increasing sleep to 90ms 2025/09/21 01:32:24 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very/very not empty`) 2025/09/21 01:32:24 DEBUG : pacer: Rate limited, increasing sleep to 180ms 2025/09/21 01:32:24 DEBUG : pacer: Reducing sleep to 135ms 2025/09/21 01:32:24 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very not empty`) 2025/09/21 01:32:24 DEBUG : pacer: Rate limited, increasing sleep to 270ms 2025/09/21 01:32:24 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/sub dir2/very not empty`) 2025/09/21 01:32:24 DEBUG : pacer: Rate limited, increasing sleep to 540ms 2025/09/21 01:32:25 DEBUG : pacer: Reducing sleep to 405ms 2025/09/21 01:32:25 DEBUG : pacer: Reducing sleep to 303.75ms 2025/09/21 01:32:26 DEBUG : pacer: Reducing sleep to 227.8125ms 2025/09/21 01:32:26 DEBUG : pacer: Reducing sleep to 170.859375ms 2025/09/21 01:32:26 DEBUG : pacer: Reducing sleep to 128.144531ms --- PASS: TestNothingToTransferWithEmptyDirs (23.64s) === RUN TestAllTag run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:26 DEBUG : empty_dir: Making directory with metadata 2025/09/21 01:32:26 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/09/21 01:32:26 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:26 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:26 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:26 DEBUG : pacer: Reducing sleep to 96.108398ms 2025/09/21 01:32:26 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:26 INFO : tictacempty_dir: Making directory 2025/09/21 01:32:26 DEBUG : pacer: Reducing sleep to 72.081298ms 2025/09/21 01:32:27 DEBUG : pacer: Reducing sleep to 54.060973ms 2025/09/21 01:32:27 INFO : tictacempty_dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC 2025/09/21 01:32:27 DEBUG : Added delayed dir = "tictacempty_dir", newDst= 2025/09/21 01:32:27 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:27 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:27 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:27 INFO : tictactoe: Making directory 2025/09/21 01:32:27 DEBUG : pacer: Reducing sleep to 40.545729ms 2025/09/21 01:32:27 DEBUG : pacer: Reducing sleep to 30.409296ms 2025/09/21 01:32:27 INFO : tictactoe: Made directory with modification time 2025-09-21 01:32:26.56131666 +0000 UTC 2025/09/21 01:32:27 DEBUG : Added delayed dir = "tictactoe", newDst= 2025/09/21 01:32:27 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:27 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:27 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:27 INFO : tictactoe/tictactoe: Making directory 2025/09/21 01:32:27 DEBUG : pacer: Reducing sleep to 22.806972ms 2025/09/21 01:32:27 DEBUG : pacer: Reducing sleep to 17.105229ms 2025/09/21 01:32:27 INFO : tictactoe/tictactoe: Made directory with modification time 2025-09-21 01:32:26.56131666 +0000 UTC 2025/09/21 01:32:27 DEBUG : Added delayed dir = "tictactoe/tictactoe", newDst= 2025/09/21 01:32:27 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:27 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/09/21 01:32:27 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:27 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/09/21 01:32:27 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:27 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:27 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:28 DEBUG : pacer: Reducing sleep to 12.828921ms 2025/09/21 01:32:28 DEBUG : pacer: Reducing sleep to 10ms 2025/09/21 01:32:28 DEBUG : tictactoe/tictactoe/tictactoe.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:32:28 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:28 DEBUG : Waiting for deletions to finish 2025/09/21 01:32:28 INFO : tictactoe/tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:28 INFO : tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:28 INFO : tictacempty_dir: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:29 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:29 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:29 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:29 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:29 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:29 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:29 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/09/21 01:32:29 DEBUG : tictactoe/tictactoe/tictactoe.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:32:29 DEBUG : tictactoe/tictactoe/tictactoe.txt: OK - could not check hash 2025/09/21 01:32:29 NOTICE: files root 'rclone-test-jovixox2xeca': 0 differences found 2025/09/21 01:32:29 NOTICE: files root 'rclone-test-jovixox2xeca': 1 hashes could not be checked 2025/09/21 01:32:29 NOTICE: files root 'rclone-test-jovixox2xeca': 1 matching files 2025/09/21 01:32:30 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/21 01:32:30 DEBUG : pacer: Reducing sleep to 15ms 2025/09/21 01:32:30 DEBUG : pacer: Reducing sleep to 11.25ms 2025/09/21 01:32:30 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestAllTag (4.48s) === RUN TestRunTwice run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:31 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:31 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:31 INFO : tictactoe: Making directory 2025/09/21 01:32:31 INFO : tictactoe: Made directory with modification time 2025-09-21 01:32:31.038327973 +0000 UTC 2025/09/21 01:32:31 DEBUG : Added delayed dir = "tictactoe", newDst= 2025/09/21 01:32:31 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:31 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:31 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:31 INFO : tictactoe/tictactoe: Making directory 2025/09/21 01:32:31 INFO : tictactoe/tictactoe: Made directory with modification time 2025-09-21 01:32:31.038327973 +0000 UTC 2025/09/21 01:32:31 DEBUG : Added delayed dir = "tictactoe/tictactoe", newDst= 2025/09/21 01:32:31 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:31 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/toe.txt 2025/09/21 01:32:31 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/09/21 01:32:31 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/toe.txt 2025/09/21 01:32:31 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:31 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:36 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/09/21 01:32:36 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/toe.txt 2025/09/21 01:32:36 DEBUG : Waiting for deletions to finish 2025/09/21 01:32:36 INFO : tictactoe/tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:36 INFO : tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:37 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:38 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:38 DEBUG : tictactoe: Directory modification time the same (differ by -38.327973ms, within tolerance 1s) 2025/09/21 01:32:38 DEBUG : Added delayed dir = "tictactoe", newDst=tictactoe 2025/09/21 01:32:38 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:38 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:38 DEBUG : tictactoe/tictactoe: Directory modification time the same (differ by -38.327973ms, within tolerance 1s) 2025/09/21 01:32:38 DEBUG : Added delayed dir = "tictactoe/tictactoe", newDst=tictactoe/tictactoe 2025/09/21 01:32:38 DEBUG : toe/toe/toe.txt: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/09/21 01:32:38 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:38 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/toe.txt 2025/09/21 01:32:38 DEBUG : toe/toe/toe.txt: Unchanged skipping 2025/09/21 01:32:38 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:38 DEBUG : Waiting for deletions to finish 2025/09/21 01:32:39 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:39 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/21 01:32:40 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:40 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/09/21 01:32:40 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:40 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/09/21 01:32:40 DEBUG : pacer: Reducing sleep to 60ms 2025/09/21 01:32:40 DEBUG : pacer: Reducing sleep to 45ms --- PASS: TestRunTwice (9.40s) === RUN TestConflicting run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:40 DEBUG : pacer: Reducing sleep to 33.75ms 2025/09/21 01:32:40 INFO : toe: Making directory 2025/09/21 01:32:40 DEBUG : pacer: Reducing sleep to 25.3125ms 2025/09/21 01:32:40 DEBUG : pacer: Reducing sleep to 18.984375ms 2025/09/21 01:32:40 INFO : toe: Made directory with modification time 2025-09-21 01:32:40.434351778 +0000 UTC 2025/09/21 01:32:40 DEBUG : Added delayed dir = "toe", newDst= 2025/09/21 01:32:40 INFO : toe/toe: Making directory 2025/09/21 01:32:41 DEBUG : pacer: Reducing sleep to 14.238281ms 2025/09/21 01:32:41 DEBUG : pacer: Reducing sleep to 10.67871ms 2025/09/21 01:32:41 INFO : toe/toe: Made directory with modification time 2025-09-21 01:32:40.434351778 +0000 UTC 2025/09/21 01:32:41 DEBUG : Added delayed dir = "toe/toe", newDst= 2025/09/21 01:32:41 DEBUG : toe/toe/toe: Need to transfer - File not found at Destination 2025/09/21 01:32:41 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:41 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:41 DEBUG : pacer: Reducing sleep to 10ms 2025/09/21 01:32:42 DEBUG : toe/toe/toe: Dst hash empty - aborting Src hash check 2025/09/21 01:32:42 INFO : toe/toe/toe: Copied (new) 2025/09/21 01:32:42 DEBUG : Waiting for deletions to finish 2025/09/21 01:32:42 INFO : toe/toe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:42 INFO : toe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:43 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/toe not empty`) 2025/09/21 01:32:43 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/21 01:32:43 DEBUG : pacer: Reducing sleep to 15ms 2025/09/21 01:32:43 DEBUG : pacer: Reducing sleep to 11.25ms --- PASS: TestConflicting (3.40s) === RUN TestMove run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:43 DEBUG : empty_dir: Making directory with metadata 2025/09/21 01:32:43 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/09/21 01:32:43 DEBUG : pacer: Reducing sleep to 10ms 2025/09/21 01:32:43 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:43 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:43 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:43 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:43 INFO : tictacempty_dir: Making directory 2025/09/21 01:32:44 INFO : tictacempty_dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC 2025/09/21 01:32:44 DEBUG : Added delayed dir = "tictacempty_dir", newDst= 2025/09/21 01:32:44 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:44 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:44 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:44 INFO : tictactoe: Making directory 2025/09/21 01:32:44 INFO : tictactoe: Made directory with modification time 2025-09-21 01:32:43.83736042 +0000 UTC 2025/09/21 01:32:44 DEBUG : Added delayed dir = "tictactoe", newDst= 2025/09/21 01:32:44 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:44 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:44 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:44 INFO : tictactoe/tictactoe: Making directory 2025/09/21 01:32:45 INFO : tictactoe/tictactoe: Made directory with modification time 2025-09-21 01:32:43.83736042 +0000 UTC 2025/09/21 01:32:45 DEBUG : Added delayed dir = "tictactoe/tictactoe", newDst= 2025/09/21 01:32:45 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:45 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/09/21 01:32:45 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:45 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/09/21 01:32:45 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:45 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:45 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:45 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:45 DEBUG : tictactoe/tictactoe/tictactoe.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:32:45 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:45 INFO : toe/toe/toe.txt: Deleted 2025/09/21 01:32:45 INFO : tictactoe/tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:46 INFO : tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:46 INFO : tictacempty_dir: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:46 INFO : toe/toe: Removing directory 2025/09/21 01:32:46 INFO : toe: Removing directory 2025/09/21 01:32:46 INFO : empty_dir: Removing directory 2025/09/21 01:32:46 DEBUG : Local file system at /tmp/rclone1166820364: deleted 3 directories --- PASS: TestMove (3.87s) === RUN TestTransformFile run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:47 DEBUG : empty_dir: Making directory with metadata 2025/09/21 01:32:47 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/09/21 01:32:47 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:47 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:47 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:47 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:47 INFO : tictacempty_dir: Making directory 2025/09/21 01:32:48 INFO : tictacempty_dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC 2025/09/21 01:32:48 DEBUG : Added delayed dir = "tictacempty_dir", newDst= 2025/09/21 01:32:48 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:48 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:48 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:48 INFO : tictactoe: Making directory 2025/09/21 01:32:48 INFO : tictactoe: Made directory with modification time 2025-09-21 01:32:47.703370251 +0000 UTC 2025/09/21 01:32:48 DEBUG : Added delayed dir = "tictactoe", newDst= 2025/09/21 01:32:48 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:48 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:48 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:48 INFO : tictactoe/tictactoe: Making directory 2025/09/21 01:32:48 INFO : tictactoe/tictactoe: Made directory with modification time 2025-09-21 01:32:47.703370251 +0000 UTC 2025/09/21 01:32:48 DEBUG : Added delayed dir = "tictactoe/tictactoe", newDst= 2025/09/21 01:32:48 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:48 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/09/21 01:32:48 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:48 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/09/21 01:32:48 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:48 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:48 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:48 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:49 DEBUG : tictactoe/tictactoe/tictactoe.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:32:49 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:49 INFO : toe/toe/toe.txt: Deleted 2025/09/21 01:32:49 INFO : tictactoe/tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:49 INFO : tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:49 ERROR : tictacempty_dir: Failed to update directory timestamp or metadata: Not Found - `Not Found. This may be related to your permissions.` 2025/09/21 01:32:49 ERROR : Local file system at /tmp/rclone1166820364: not deleting directories as there were IO errors sync_transform_test.go:427: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_transform_test.go:427 Error: Received unexpected error: not deleting directories as there were IO errors Test: TestTransformFile 2025/09/21 01:32:50 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/21 01:32:50 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:50 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/09/21 01:32:50 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:50 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/09/21 01:32:51 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-jovixox2xeca/tictactoe not empty`) 2025/09/21 01:32:51 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/09/21 01:32:51 DEBUG : pacer: Reducing sleep to 120ms 2025/09/21 01:32:51 DEBUG : pacer: Reducing sleep to 90ms --- FAIL: TestTransformFile (3.70s) === RUN TestManualTransformFile run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:51 DEBUG : Reset feature "Copy" 2025/09/21 01:32:51 DEBUG : Reset feature "Move" 2025/09/21 01:32:51 DEBUG : Reset feature "Copy" 2025/09/21 01:32:51 DEBUG : Reset feature "Move" 2025/09/21 01:32:51 DEBUG : empty_dir: Making directory with metadata 2025/09/21 01:32:51 INFO : empty_dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/09/21 01:32:51 DEBUG : pacer: Reducing sleep to 67.5ms 2025/09/21 01:32:51 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:51 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:51 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:51 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:51 INFO : tictacempty_dir: Making directory 2025/09/21 01:32:51 DEBUG : pacer: Reducing sleep to 50.625ms 2025/09/21 01:32:51 DEBUG : pacer: Reducing sleep to 37.96875ms 2025/09/21 01:32:51 INFO : tictacempty_dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC 2025/09/21 01:32:51 DEBUG : Added delayed dir = "tictacempty_dir", newDst= 2025/09/21 01:32:51 DEBUG : empty_dir: transformed to: tictacempty_dir 2025/09/21 01:32:51 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:51 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:51 INFO : tictactoe: Making directory 2025/09/21 01:32:52 DEBUG : pacer: Reducing sleep to 28.476562ms 2025/09/21 01:32:52 DEBUG : pacer: Reducing sleep to 21.357421ms 2025/09/21 01:32:52 INFO : tictactoe: Made directory with modification time 2025-09-21 01:32:51.406379681 +0000 UTC 2025/09/21 01:32:52 DEBUG : Added delayed dir = "tictactoe", newDst= 2025/09/21 01:32:52 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:52 DEBUG : toe: transformed to: tictactoe 2025/09/21 01:32:52 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:52 INFO : tictactoe/tictactoe: Making directory 2025/09/21 01:32:52 DEBUG : pacer: Reducing sleep to 16.018065ms 2025/09/21 01:32:52 DEBUG : pacer: Reducing sleep to 12.013548ms 2025/09/21 01:32:52 INFO : tictactoe/tictactoe: Made directory with modification time 2025-09-21 01:32:51.406379681 +0000 UTC 2025/09/21 01:32:52 DEBUG : Added delayed dir = "tictactoe/tictactoe", newDst= 2025/09/21 01:32:52 DEBUG : toe/toe: transformed to: tictactoe/tictactoe 2025/09/21 01:32:52 DEBUG : toe.txt: transformed to: tictactoe.txt 2025/09/21 01:32:52 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:52 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/09/21 01:32:52 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:52 DEBUG : toe/toe/toe.txt: transformed to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:52 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:52 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:53 DEBUG : pacer: Reducing sleep to 10ms 2025/09/21 01:32:53 DEBUG : tictactoe/tictactoe/tictactoe.txt: Dst hash empty - aborting Src hash check 2025/09/21 01:32:53 INFO : toe/toe/toe.txt: Copied (new) to: tictactoe/tictactoe/tictactoe.txt 2025/09/21 01:32:53 INFO : toe/toe/toe.txt: Deleted 2025/09/21 01:32:53 INFO : tictactoe/tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:53 INFO : tictactoe: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:53 INFO : tictacempty_dir: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:53 ERROR : Local file system at /tmp/rclone1166820364: not deleting directories as there were IO errors sync_transform_test.go:457: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_transform_test.go:457 Error: Received unexpected error: not deleting directories as there were IO errors Test: TestManualTransformFile --- FAIL: TestManualTransformFile (3.41s) === RUN TestBase64 run.go:180: Remote "files root 'rclone-test-jovixox2xeca'", Local "Local file system at /tmp/rclone1166820364", Modify Window "1s" 2025/09/21 01:32:54 DEBUG : toe: transformed to: dG9l 2025/09/21 01:32:54 DEBUG : toe: transformed to: dG9l 2025/09/21 01:32:54 INFO : dG9l: Making directory 2025/09/21 01:32:55 INFO : dG9l: Made directory with modification time 2025-09-21 01:32:54.815388373 +0000 UTC 2025/09/21 01:32:55 DEBUG : Added delayed dir = "dG9l", newDst= 2025/09/21 01:32:55 DEBUG : toe: transformed to: dG9l 2025/09/21 01:32:55 DEBUG : toe: transformed to: dG9l 2025/09/21 01:32:55 DEBUG : toe/toe: transformed to: dG9l/dG9l 2025/09/21 01:32:55 INFO : dG9l/dG9l: Making directory 2025/09/21 01:32:55 INFO : dG9l/dG9l: Made directory with modification time 2025-09-21 01:32:54.815388373 +0000 UTC 2025/09/21 01:32:55 DEBUG : Added delayed dir = "dG9l/dG9l", newDst= 2025/09/21 01:32:55 DEBUG : toe/toe: transformed to: dG9l/dG9l 2025/09/21 01:32:55 DEBUG : toe.txt: transformed to: dG9lLnR4dA== 2025/09/21 01:32:55 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA== 2025/09/21 01:32:55 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination 2025/09/21 01:32:55 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA== 2025/09/21 01:32:55 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for checks to finish 2025/09/21 01:32:55 DEBUG : files root 'rclone-test-jovixox2xeca': Waiting for transfers to finish 2025/09/21 01:32:56 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Dst hash empty - aborting Src hash check 2025/09/21 01:32:56 INFO : toe/toe/toe.txt: Copied (new) to: dG9l/dG9l/dG9lLnR4dA== 2025/09/21 01:32:56 ERROR : files root 'rclone-test-jovixox2xeca': not deleting files as there were IO errors 2025/09/21 01:32:56 INFO : dG9l/dG9l: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:56 INFO : dG9l: Set directory modification time (using DirSetModTime) 2025/09/21 01:32:56 ERROR : files root 'rclone-test-jovixox2xeca': not deleting directories as there were IO errors sync_transform_test.go:481: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_transform_test.go:481 Error: Received unexpected error: not deleting files as there were IO errors Test: TestBase64 --- FAIL: TestBase64 (2.84s) FAIL 2025/09/21 01:32:57 DEBUG : files root 'rclone-test-jovixox2xeca': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestAllTag|TestBase64|TestConflicting|TestManualTransformFile|TestMove|TestNothingToTransferWithEmptyDirs|TestRunTwice|TestSyncSuffixKeepExtension|TestTransformFile)$'" - Finished ERROR in 1m18.127243747s (try 2/5): exit status 1: Failed [TestTransformFile TestManualTransformFile TestBase64]