"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestSyncBackupDir|TestSyncBackupDirWithSuffixKeepExtension)$'" - Starting (try 3/5)
2026/01/14 05:03:40 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yoliqet6fixi"
2026/01/14 05:03:40 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/01/14 05:03:40 DEBUG : Starting OpenDrive session with ID: ace950a706c32eb14270e86e1ab76ce4be7188eadbee509505725c949edd559a
2026/01/14 05:03:41 DEBUG : Creating backend with remote "/tmp/rclone3791568982"
=== RUN   TestSyncBackupDir
    run.go:185: Remote "OpenDrive root 'rclone-test-yoliqet6fixi'", Local "Local file system at /tmp/rclone3791568982", Modify Window "1s"
2026/01/14 05:03:42 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2026/01/14 05:03:44 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2026/01/14 05:03:46 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2026/01/14 05:03:47 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yoliqet6fixi/dst"
2026/01/14 05:03:48 DEBUG : Starting OpenDrive session with ID: 4776befc814ee371baa006d2e2ead2ed7c09cb455c663b37718c975677d70bab
2026/01/14 05:03:48 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yoliqet6fixi/backup"
2026/01/14 05:03:48 DEBUG : Starting OpenDrive session with ID: c610da809366d07e89f2011dcd6bc97ca0001fb641e1d92266f958d9f436a09a
2026/01/14 05:03:49 DEBUG : one: size = 4 (Local file system at /tmp/rclone3791568982)
2026/01/14 05:03:49 DEBUG : one: size = 3 (OpenDrive root 'rclone-test-yoliqet6fixi/dst')
2026/01/14 05:03:49 DEBUG : one: Sizes differ
2026/01/14 05:03:49 DEBUG : two: size = 3 OK
2026/01/14 05:03:49 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2026/01/14 05:03:49 DEBUG : two: Unchanged skipping
2026/01/14 05:03:49 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for checks to finish
2026/01/14 05:03:50 INFO  : one: Moved (server-side)
2026/01/14 05:03:50 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for transfers to finish
2026/01/14 05:03:51 DEBUG : one: Uploading chunk 0, size=4, remain=0
2026/01/14 05:03:52 DEBUG : one: size = 4 OK
2026/01/14 05:03:52 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2026/01/14 05:03:52 INFO  : one: Copied (new)
2026/01/14 05:03:52 DEBUG : Waiting for deletions to finish
2026/01/14 05:03:53 INFO  : three.txt: Moved (server-side)
2026/01/14 05:03:53 INFO  : three.txt: Moved into backup dir
2026/01/14 05:03:54 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2026/01/14 05:03:55 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for checks to finish
2026/01/14 05:03:55 DEBUG : one: size = 5 (Local file system at /tmp/rclone3791568982)
2026/01/14 05:03:55 DEBUG : one: size = 4 (OpenDrive root 'rclone-test-yoliqet6fixi/dst')
2026/01/14 05:03:55 DEBUG : one: Sizes differ
2026/01/14 05:03:55 DEBUG : two: size = 3 OK
2026/01/14 05:03:55 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2026/01/14 05:03:55 DEBUG : two: Unchanged skipping
2026/01/14 05:03:56 INFO  : one: Deleted
2026/01/14 05:03:56 INFO  : one: Moved (server-side)
2026/01/14 05:03:56 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for transfers to finish
2026/01/14 05:03:57 DEBUG : one: Uploading chunk 0, size=5, remain=0
2026/01/14 05:03:58 DEBUG : one: size = 5 OK
2026/01/14 05:03:58 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2026/01/14 05:03:58 INFO  : one: Copied (new)
2026/01/14 05:03:58 DEBUG : Waiting for deletions to finish
2026/01/14 05:03:58 INFO  : three.txt: Deleted
2026/01/14 05:03:59 INFO  : three.txt: Moved (server-side)
2026/01/14 05:03:59 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDir (20.39s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:185: Remote "OpenDrive root 'rclone-test-yoliqet6fixi'", Local "Local file system at /tmp/rclone3791568982", Modify Window "1s"
2026/01/14 05:04:02 DEBUG : dst/one: Uploading chunk 0, size=3, remain=0
2026/01/14 05:04:04 DEBUG : dst/two: Uploading chunk 0, size=3, remain=0
2026/01/14 05:04:06 DEBUG : dst/three.txt: Uploading chunk 0, size=5, remain=0
2026/01/14 05:04:07 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yoliqet6fixi/dst"
2026/01/14 05:04:08 DEBUG : Starting OpenDrive session with ID: d59f4e966d94a7fad3068f25aa6820e68453c3160a071aaede9d938f1b5d6ad3
2026/01/14 05:04:08 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yoliqet6fixi/backup"
2026/01/14 05:04:08 DEBUG : Starting OpenDrive session with ID: 9ab1cec1b611f7ab4eb615ac63216e8f64bbfd44ff213b56920953780b481dc3
2026/01/14 05:04:09 DEBUG : one: size = 4 (Local file system at /tmp/rclone3791568982)
2026/01/14 05:04:09 DEBUG : one: size = 3 (OpenDrive root 'rclone-test-yoliqet6fixi/dst')
2026/01/14 05:04:09 DEBUG : one: Sizes differ
2026/01/14 05:04:09 DEBUG : two: size = 3 OK
2026/01/14 05:04:09 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2026/01/14 05:04:09 DEBUG : two: Unchanged skipping
2026/01/14 05:04:09 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for checks to finish
2026/01/14 05:04:10 INFO  : one: Moved (server-side) to: one-2019-01-01
2026/01/14 05:04:10 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for transfers to finish
2026/01/14 05:04:11 DEBUG : one: Uploading chunk 0, size=4, remain=0
2026/01/14 05:04:12 DEBUG : one: size = 4 OK
2026/01/14 05:04:12 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK
2026/01/14 05:04:12 INFO  : one: Copied (new)
2026/01/14 05:04:12 DEBUG : Waiting for deletions to finish
2026/01/14 05:04:13 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2026/01/14 05:04:13 INFO  : three.txt: Moved into backup dir
2026/01/14 05:04:14 DEBUG : dst/three.txt: Uploading chunk 0, size=6, remain=0
2026/01/14 05:04:15 DEBUG : one: size = 5 (Local file system at /tmp/rclone3791568982)
2026/01/14 05:04:15 DEBUG : one: size = 4 (OpenDrive root 'rclone-test-yoliqet6fixi/dst')
2026/01/14 05:04:15 DEBUG : one: Sizes differ
2026/01/14 05:04:15 DEBUG : two: size = 3 OK
2026/01/14 05:04:15 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2026/01/14 05:04:15 DEBUG : two: Unchanged skipping
2026/01/14 05:04:15 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for checks to finish
2026/01/14 05:04:16 INFO  : one-2019-01-01: Deleted
2026/01/14 05:04:16 INFO  : one: Moved (server-side) to: one-2019-01-01
2026/01/14 05:04:16 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi/dst': Waiting for transfers to finish
2026/01/14 05:04:17 DEBUG : one: Uploading chunk 0, size=5, remain=0
2026/01/14 05:04:18 DEBUG : one: size = 5 OK
2026/01/14 05:04:18 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK
2026/01/14 05:04:18 INFO  : one: Copied (new)
2026/01/14 05:04:18 DEBUG : Waiting for deletions to finish
2026/01/14 05:04:18 INFO  : three-2019-01-01.txt: Deleted
2026/01/14 05:04:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2026/01/14 05:04:19 INFO  : three.txt: Moved into backup dir
    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: TestSyncBackupDirWithSuffixKeepExtension (27.51s)
PASS
2026/01/14 05:04:28 DEBUG : OpenDrive root 'rclone-test-yoliqet6fixi': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestSyncBackupDir|TestSyncBackupDirWithSuffixKeepExtension)$'" - Finished OK in 49.172390367s (try 3/5)