"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestBase64|TestFixCase|TestServerSideCopyOverSelf)$'" - Starting (try 2/5)
2025/11/29 02:19:27 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-bujuniv6wenu"
2025/11/29 02:19:27 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/11/29 02:19:28 DEBUG : Starting OpenDrive session with ID: 59192d4a6e1ff20115af9fb866e274801c3093958245bf1e96d18f3897cf8dce
2025/11/29 02:19:28 DEBUG : Creating backend with remote "/tmp/rclone4098793722"
=== RUN   TestServerSideCopyOverSelf
    run.go:185: Remote "OpenDrive root 'rclone-test-bujuniv6wenu'", Local "Local file system at /tmp/rclone4098793722", Modify Window "1s"
2025/11/29 02:19:30 DEBUG : sub dir/hello world: Uploading chunk 0, size=11, remain=0
2025/11/29 02:19:31 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-jakolim9wema"
2025/11/29 02:19:32 DEBUG : Starting OpenDrive session with ID: 1b99c2a0d9bc272e8e1fef5da555aa8cdaefdff97b5e8e4742b09f8f4b8cbf5c
    sync_test.go:656: Server side copy (if possible) OpenDrive root 'rclone-test-bujuniv6wenu' -> OpenDrive root 'rclone-test-jakolim9wema'
2025/11/29 02:19:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/11/29 02:19:32 DEBUG : OpenDrive root 'rclone-test-jakolim9wema': Waiting for checks to finish
2025/11/29 02:19:32 DEBUG : OpenDrive root 'rclone-test-jakolim9wema': Waiting for transfers to finish
2025/11/29 02:19:33 DEBUG : sub dir/hello world: size = 11 OK
2025/11/29 02:19:33 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/11/29 02:19:33 INFO  : sub dir/hello world: Copied (server-side copy)
2025/11/29 02:19:34 DEBUG : sub dir/hello world: Uploading chunk 0, size=17, remain=0
2025/11/29 02:19:36 DEBUG : OpenDrive root 'rclone-test-jakolim9wema': Waiting for checks to finish
2025/11/29 02:19:36 DEBUG : sub dir/hello world: size = 17 (OpenDrive root 'rclone-test-bujuniv6wenu')
2025/11/29 02:19:36 DEBUG : sub dir/hello world: size = 11 (OpenDrive root 'rclone-test-jakolim9wema')
2025/11/29 02:19:36 DEBUG : sub dir/hello world: Sizes differ
2025/11/29 02:19:36 DEBUG : OpenDrive root 'rclone-test-jakolim9wema': Waiting for transfers to finish
2025/11/29 02:19:37 DEBUG : sub dir/hello world: size = 17 OK
2025/11/29 02:19:37 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/11/29 02:19:37 INFO  : sub dir/hello world: Copied (server-side copy)
2025/11/29 02:19:37 DEBUG : OpenDrive root 'rclone-test-jakolim9wema': Purge remote
--- PASS: TestServerSideCopyOverSelf (10.83s)
=== RUN   TestFixCase
    run.go:185: Remote "OpenDrive root 'rclone-test-bujuniv6wenu'", Local "Local file system at /tmp/rclone4098793722", Modify Window "1s"
2025/11/29 02:19:40 DEBUG : EXISTING: Uploading chunk 0, size=6, remain=0
2025/11/29 02:19:42 DEBUG : EXISTINGBUTDIFFERENT: Uploading chunk 0, size=8, remain=0
2025/11/29 02:19:45 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: Uploading chunk 0, size=8, remain=0
2025/11/29 02:19:47 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Uploading chunk 0, size=8, remain=0
2025/11/29 02:19:50 DEBUG : EXISTING: size = 6 OK
2025/11/29 02:19:50 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/11/29 02:19:50 DEBUG : existing: Unchanged skipping
2025/11/29 02:19:50 DEBUG : existingbutdifferent: size = 5 (Local file system at /tmp/rclone4098793722)
2025/11/29 02:19:50 DEBUG : EXISTINGBUTDIFFERENT: size = 8 (OpenDrive root 'rclone-test-bujuniv6wenu')
2025/11/29 02:19:50 DEBUG : existingbutdifferent: Sizes differ
2025/11/29 02:19:50 DEBUG : subdira-rclone-move-yakunix1: same parent dir (ODFfOTYyNDQ1OF8zZGZNVg) - using folder/rename instead of move_copy
2025/11/29 02:19:50 DEBUG : EXISTING: moving to existing-rclone-move-dexiwup5
2025/11/29 02:19:50 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent-rclone-move-foxeted9
2025/11/29 02:19:51 DEBUG : subdira: same parent dir (ODFfOTYyNDQ1OF8zZGZNVg) - using folder/rename instead of move_copy
2025/11/29 02:19:51 DEBUG : EXISTINGBUTDIFFERENT: same parent dir (ODFfOTYyNDQ1OF8zZGZNVg) - using file/rename instead of move_copy for existingbutdifferent-rclone-move-foxeted9
2025/11/29 02:19:51 DEBUG : EXISTING: same parent dir (ODFfOTYyNDQ1OF8zZGZNVg) - using file/rename instead of move_copy for existing-rclone-move-dexiwup5
2025/11/29 02:19:51 INFO  : SUBDIRA: Fixed case by renaming to: subdira
2025/11/29 02:19:51 INFO  : EXISTING: Moved (server-side) to: existing-rclone-move-dexiwup5
2025/11/29 02:19:51 DEBUG : EXISTING: moving to existing
2025/11/29 02:19:51 INFO  : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent-rclone-move-foxeted9
2025/11/29 02:19:51 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent
2025/11/29 02:19:51 DEBUG : existingbutdifferent-rclone-move-foxeted9: same parent dir (ODFfOTYyNDQ1OF8zZGZNVg) - using file/rename instead of move_copy for existingbutdifferent
2025/11/29 02:19:51 INFO  : existingbutdifferent-rclone-move-foxeted9: Moved (server-side) to: existingbutdifferent
2025/11/29 02:19:51 INFO  : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent
2025/11/29 02:19:51 INFO  : EXISTINGBUTDIFFERENT: Fixed case by renaming to: existingbutdifferent
2025/11/29 02:19:51 DEBUG : existingbutdifferent: Uploading chunk 0, size=5, remain=0
2025/11/29 02:19:52 DEBUG : existing-rclone-move-dexiwup5: same parent dir (ODFfOTYyNDQ1OF8zZGZNVg) - using file/rename instead of move_copy for existing
2025/11/29 02:19:52 DEBUG : subdira/subdirb-rclone-move-nuqifok7: same parent dir (ODFfOTYyNDQ2Ml9STk5mSw) - using folder/rename instead of move_copy
2025/11/29 02:19:52 INFO  : existing-rclone-move-dexiwup5: Moved (server-side) to: existing
2025/11/29 02:19:52 INFO  : EXISTING: Moved (server-side) to: existing
2025/11/29 02:19:52 INFO  : EXISTING: Fixed case by renaming to: existing
2025/11/29 02:19:52 DEBUG : subdira/subdirb: same parent dir (ODFfOTYyNDQ2Ml9STk5mSw) - using folder/rename instead of move_copy
2025/11/29 02:19:52 INFO  : SUBDIRA/subdirb: Fixed case by renaming to: subdira/subdirb
2025/11/29 02:19:52 DEBUG : existingbutdifferent: size = 5 OK
2025/11/29 02:19:52 DEBUG : existingbutdifferent: md5 = 81bdd90fd4bc5a1c9b7b603014ff1388 OK
2025/11/29 02:19:52 INFO  : existingbutdifferent: Copied (replaced existing)
2025/11/29 02:19:53 DEBUG : subdira/subdirb/subdirc-rclone-move-gijulut1: same parent dir (ODFfOTYyNDQ2M19NRnIxbg) - using folder/rename instead of move_copy
2025/11/29 02:19:54 DEBUG : subdira/subdirb/subdirc: same parent dir (ODFfOTYyNDQ2M19NRnIxbg) - using folder/rename instead of move_copy
2025/11/29 02:19:54 INFO  : SUBDIRA/subdirb/SUBDIRC: Fixed case by renaming to: subdira/subdirb/subdirc
2025/11/29 02:19:54 DEBUG : subdira/subdirb/subdirc/hello: size = 5 (Local file system at /tmp/rclone4098793722)
2025/11/29 02:19:54 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: size = 8 (OpenDrive root 'rclone-test-bujuniv6wenu')
2025/11/29 02:19:54 DEBUG : subdira/subdirb/subdirc/hello: Sizes differ
2025/11/29 02:19:55 DEBUG : subdira/subdirb/subdirc/subdird-rclone-move-gasamew6: same parent dir (ODFfOTYyNDQ2NF9zakl0Tg) - using folder/rename instead of move_copy
2025/11/29 02:19:55 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello-rclone-move-beqexam8
2025/11/29 02:19:55 DEBUG : subdira/subdirb/subdirc/subdird: same parent dir (ODFfOTYyNDQ2NF9zakl0Tg) - using folder/rename instead of move_copy
2025/11/29 02:19:55 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: same parent dir (ODFfOTYyNDQ2NF9zakl0Tg) - using file/rename instead of move_copy for subdira/subdirb/subdirc/hello-rclone-move-beqexam8
2025/11/29 02:19:55 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird: Fixed case by renaming to: subdira/subdirb/subdirc/subdird
2025/11/29 02:19:56 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello-rclone-move-beqexam8
2025/11/29 02:19:56 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello
2025/11/29 02:19:56 DEBUG : subdira/subdirb/subdirc/hello-rclone-move-beqexam8: same parent dir (ODFfOTYyNDQ2NF9zakl0Tg) - using file/rename instead of move_copy for subdira/subdirb/subdirc/hello
2025/11/29 02:19:56 DEBUG : OpenDrive root 'rclone-test-bujuniv6wenu': Waiting for checks to finish
2025/11/29 02:19:56 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: size = 5 (Local file system at /tmp/rclone4098793722)
2025/11/29 02:19:56 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: size = 8 (OpenDrive root 'rclone-test-bujuniv6wenu')
2025/11/29 02:19:56 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Sizes differ
2025/11/29 02:19:56 INFO  : subdira/subdirb/subdirc/hello-rclone-move-beqexam8: Moved (server-side) to: subdira/subdirb/subdirc/hello
2025/11/29 02:19:56 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello
2025/11/29 02:19:56 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Fixed case by renaming to: subdira/subdirb/subdirc/hello
2025/11/29 02:19:56 DEBUG : subdira/subdirb/subdirc/hello: Uploading chunk 0, size=5, remain=0
2025/11/29 02:19:56 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-ciyadip5
2025/11/29 02:19:56 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: same parent dir (ODFfOTYyNDQ2NV9INjRPQw) - using file/rename instead of move_copy for subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-ciyadip5
2025/11/29 02:19:57 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-ciyadip5
2025/11/29 02:19:57 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/11/29 02:19:57 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-ciyadip5: same parent dir (ODFfOTYyNDQ2NV9INjRPQw) - using file/rename instead of move_copy for subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/11/29 02:19:57 INFO  : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-ciyadip5: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/11/29 02:19:57 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/11/29 02:19:57 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Fixed case by renaming to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/11/29 02:19:57 DEBUG : OpenDrive root 'rclone-test-bujuniv6wenu': Waiting for transfers to finish
2025/11/29 02:19:57 DEBUG : subdira/subdirb/subdirc/hello: size = 5 OK
2025/11/29 02:19:57 DEBUG : subdira/subdirb/subdirc/hello: md5 = 81bdd90fd4bc5a1c9b7b603014ff1388 OK
2025/11/29 02:19:57 INFO  : subdira/subdirb/subdirc/hello: Copied (replaced existing)
2025/11/29 02:19:57 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Uploading chunk 0, size=5, remain=0
2025/11/29 02:19:58 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: size = 5 OK
2025/11/29 02:19:58 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: md5 = 81bdd90fd4bc5a1c9b7b603014ff1388 OK
2025/11/29 02:19:58 INFO  : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Copied (replaced existing)
2025/11/29 02:19:58 DEBUG : Waiting for deletions to finish
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestFixCase (31.54s)
=== RUN   TestBase64
    run.go:185: Remote "OpenDrive root 'rclone-test-bujuniv6wenu'", Local "Local file system at /tmp/rclone4098793722", Modify Window "1s"
2025/11/29 02:20:10 DEBUG : toe: transformed to: dG9l
2025/11/29 02:20:11 DEBUG : toe: transformed to: dG9l
2025/11/29 02:20:11 INFO  : dG9l: Making directory
2025/11/29 02:20:11 DEBUG : toe: transformed to: dG9l
2025/11/29 02:20:11 DEBUG : toe: transformed to: dG9l
2025/11/29 02:20:11 DEBUG : toe/toe: transformed to: dG9l/dG9l
2025/11/29 02:20:11 INFO  : dG9l/dG9l: Making directory
2025/11/29 02:20:11 DEBUG : toe/toe: transformed to: dG9l/dG9l
2025/11/29 02:20:11 DEBUG : toe.txt: transformed to: dG9lLnR4dA==
2025/11/29 02:20:11 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA==
2025/11/29 02:20:11 DEBUG : toe/toe/toe.txt: Need to transfer - File not found at Destination
2025/11/29 02:20:11 DEBUG : toe/toe/toe.txt: transformed to: dG9l/dG9l/dG9lLnR4dA==
2025/11/29 02:20:11 DEBUG : OpenDrive root 'rclone-test-bujuniv6wenu': Waiting for checks to finish
2025/11/29 02:20:11 DEBUG : OpenDrive root 'rclone-test-bujuniv6wenu': Waiting for transfers to finish
2025/11/29 02:20:12 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Uploading chunk 0, size=11, remain=0
2025/11/29 02:20:13 DEBUG : dG9l/dG9l/dG9lLnR4dA==: size = 11 OK
2025/11/29 02:20:13 DEBUG : toe/toe/toe.txt: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2025/11/29 02:20:13 INFO  : toe/toe/toe.txt: Copied (new) to: dG9l/dG9l/dG9lLnR4dA==
2025/11/29 02:20:13 DEBUG : Waiting for deletions to finish
2025/11/29 02:20:14 DEBUG : dG9l: transformed to: toe
2025/11/29 02:20:14 DEBUG : dG9l: transformed to: toe
2025/11/29 02:20:14 DEBUG : toe: Directory modification time the same (differ by -92.999789ms, within tolerance 1s)
2025/11/29 02:20:14 DEBUG : Added delayed dir = "toe", newDst=toe
2025/11/29 02:20:14 DEBUG : dG9l: transformed to: toe
2025/11/29 02:20:14 DEBUG : dG9l/dG9l: transformed to: toe/toe
2025/11/29 02:20:14 INFO  : toe/toe: Set directory modification time (using SetModTime)
2025/11/29 02:20:14 DEBUG : Added delayed dir = "toe/toe", newDst=toe/toe
2025/11/29 02:20:15 DEBUG : dG9lLnR4dA==: transformed to: toe.txt
2025/11/29 02:20:15 DEBUG : toe/toe/toe.txt: size = 11 OK
2025/11/29 02:20:15 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Size and modification time the same (differ by 499.999999ms, within tolerance 1s)
2025/11/29 02:20:15 DEBUG : Local file system at /tmp/rclone4098793722: Waiting for checks to finish
2025/11/29 02:20:15 DEBUG : dG9l/dG9l/dG9lLnR4dA==: transformed to: toe/toe/toe.txt
2025/11/29 02:20:15 DEBUG : dG9l/dG9l/dG9lLnR4dA==: Unchanged skipping
2025/11/29 02:20:15 DEBUG : Local file system at /tmp/rclone4098793722: Waiting for transfers to finish
2025/11/29 02:20:15 DEBUG : Waiting for deletions to finish
--- PASS: TestBase64 (6.43s)
PASS
2025/11/29 02:20:17 DEBUG : OpenDrive root 'rclone-test-bujuniv6wenu': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestBase64|TestFixCase|TestServerSideCopyOverSelf)$'" - Finished OK in 50.236956306s (try 2/5)