"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestSyncConcurrentDelete|TestSyncReplaceDirModTime)$'" - Starting (try 2/5)
2025/03/31 01:33:52 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qewenif9zeke"
2025/03/31 01:33:52 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/31 01:33:52 DEBUG : Starting OpenDrive session with ID: 4adf292ca9a4c950f49cf0e479895350d164a81b1b8b22a82a4c90cb447f6da6
2025/03/31 01:33:53 DEBUG : Creating backend with remote "/tmp/rclone2910104374"
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "OpenDrive root 'rclone-test-qewenif9zeke'", Local "Local file system at /tmp/rclone2910104374", Modify Window "1s"
2025/03/31 01:33:54 DEBUG : both0: Uploading chunk 0, size=6, remain=0
2025/03/31 01:33:55 DEBUG : only0: Uploading chunk 0, size=6, remain=0
2025/03/31 01:33:57 DEBUG : both1: Uploading chunk 0, size=6, remain=0
2025/03/31 01:33:59 DEBUG : only1: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:00 DEBUG : both2: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:02 DEBUG : only2: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:04 DEBUG : both3: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:05 DEBUG : only3: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:07 DEBUG : both4: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:09 DEBUG : only4: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:11 DEBUG : both5: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:13 DEBUG : only5: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:15 DEBUG : both6: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:16 DEBUG : only6: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:18 DEBUG : both7: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:20 DEBUG : only7: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:21 DEBUG : both8: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:23 DEBUG : only8: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:25 DEBUG : both9: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:26 DEBUG : only9: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:28 DEBUG : both10: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:30 DEBUG : only10: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:32 DEBUG : both11: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:33 DEBUG : only11: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:35 DEBUG : both12: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:37 DEBUG : only12: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:38 DEBUG : both13: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:40 DEBUG : only13: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:42 DEBUG : both14: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:43 DEBUG : only14: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:45 DEBUG : both15: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:47 DEBUG : only15: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:49 DEBUG : both16: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:50 DEBUG : only16: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:52 DEBUG : both17: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:54 DEBUG : only17: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:56 DEBUG : both18: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:57 DEBUG : only18: Uploading chunk 0, size=6, remain=0
2025/03/31 01:34:59 DEBUG : both19: Uploading chunk 0, size=6, remain=0
2025/03/31 01:35:01 DEBUG : only19: Uploading chunk 0, size=6, remain=0
2025/03/31 01:35:02 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both0: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : OpenDrive root 'rclone-test-qewenif9zeke': Waiting for checks to finish
2025/03/31 01:35:02 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both1: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both13: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both11: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both15: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both16: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both17: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both18: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both19: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both2: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both3: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both4: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both5: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both6: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both7: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both8: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/03/31 01:35:02 DEBUG : both9: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both12: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both10: Unchanged skipping
2025/03/31 01:35:02 DEBUG : both14: Unchanged skipping
2025/03/31 01:35:02 DEBUG : OpenDrive root 'rclone-test-qewenif9zeke': Waiting for transfers to finish
2025/03/31 01:35:02 DEBUG : Waiting for deletions to finish
2025/03/31 01:35:03 INFO  : only8: Deleted
2025/03/31 01:35:03 INFO  : only0: Deleted
2025/03/31 01:35:03 INFO  : only10: Deleted
2025/03/31 01:35:03 INFO  : only11: Deleted
2025/03/31 01:35:03 INFO  : only12: Deleted
2025/03/31 01:35:03 INFO  : only13: Deleted
2025/03/31 01:35:03 INFO  : only15: Deleted
2025/03/31 01:35:03 INFO  : only17: Deleted
2025/03/31 01:35:03 INFO  : only9: Deleted
2025/03/31 01:35:03 INFO  : only16: Deleted
2025/03/31 01:35:03 INFO  : only18: Deleted
2025/03/31 01:35:03 INFO  : only19: Deleted
2025/03/31 01:35:03 INFO  : only2: Deleted
2025/03/31 01:35:03 INFO  : only4: Deleted
2025/03/31 01:35:03 INFO  : only14: Deleted
2025/03/31 01:35:03 INFO  : only3: Deleted
2025/03/31 01:35:03 INFO  : only5: Deleted
2025/03/31 01:35:03 INFO  : only1: Deleted
2025/03/31 01:35:03 INFO  : only6: Deleted
2025/03/31 01:35:04 INFO  : only7: Deleted
2025/03/31 01:35:04 INFO  : There was nothing to transfer
    run.go:180: Remote "OpenDrive root 'rclone-test-qewenif9zeke'", Local "Local file system at /tmp/rclone2910104374", Modify Window "1s"
--- PASS: TestSyncConcurrentDelete (75.14s)
=== RUN   TestSyncReplaceDirModTime
    run.go:180: Remote "OpenDrive root 'rclone-test-qewenif9zeke'", Local "Local file system at /tmp/rclone2910104374", Modify Window "1s"
2025/03/31 01:35:08 DEBUG : empty_dir: Making directory with metadata
2025/03/31 01:35:08 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/31 01:35:08 DEBUG : empty_on_remote: Making directory with metadata
2025/03/31 01:35:08 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/31 01:35:08 INFO  : empty_on_remote: Making directory
2025/03/31 01:35:08 INFO  : empty_on_remote: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
    run.go:180: Remote "OpenDrive root 'rclone-test-qewenif9zeke'", Local "Local file system at /tmp/rclone2910104374", Modify Window "1s"
2025/03/31 01:35:13 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/03/31 01:35:13 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/03/31 01:35:13 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/03/31 01:35:13 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "OpenDrive root 'rclone-test-qewenif9zeke'", Local "Local file system at /tmp/rclone2910104374", 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: TestSyncReplaceDirModTime (16.71s)
PASS
2025/03/31 01:35:25 DEBUG : OpenDrive root 'rclone-test-qewenif9zeke': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestSyncConcurrentDelete|TestSyncReplaceDirModTime)$'" - Finished OK in 1m33.155715501s (try 2/5)