"./vfs.test -test.v -test.timeout 1h0m0s -remote TestFileLu: -verbose -test.run '^TestZipManySubDirs$'" - Starting (try 2/5)
2025/12/15 01:32:32 DEBUG : Creating backend with remote "TestFileLu:rclone-test-mahexak6teco"
2025/12/15 01:32:32 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/12/15 01:32:32 DEBUG : Creating backend with remote "/tmp/rclone1647235213"
=== RUN   TestZipManySubDirs
    run.go:185: Remote "FileLu root 'rclone-test-mahexak6teco'", Local "Local file system at /tmp/rclone1647235213", Modify Window "876000h0m0s"
2025/12/15 01:32:32 INFO  : FileLu root 'rclone-test-mahexak6teco': poll-interval is not supported by this remote
2025/12/15 01:32:32 NOTICE: FileLu root 'rclone-test-mahexak6teco': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2025/12/15 01:32:33 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully created folder "rclone-test-mahexak6teco" with ID 1891066
2025/12/15 01:32:34 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully created folder "rclone-test-mahexak6teco/a" with ID 1891067
2025/12/15 01:32:36 INFO  : FileLu root 'rclone-test-mahexak6teco': Put: Successfully uploaded new file "a/top.txt"
2025/12/15 01:32:37 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully created folder "rclone-test-mahexak6teco/a/b" with ID 1891068
2025/12/15 01:32:38 INFO  : FileLu root 'rclone-test-mahexak6teco': Put: Successfully uploaded new file "a/b/mid.txt"
2025/12/15 01:32:39 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully created folder "rclone-test-mahexak6teco/a/b/c" with ID 1891069
2025/12/15 01:32:42 INFO  : FileLu root 'rclone-test-mahexak6teco': Put: Successfully uploaded new file "a/b/c/deep.txt"
2025/12/15 01:32:43 DEBUG : a/b/c/deep.txt: Open: flags=O_RDONLY
2025/12/15 01:32:43 DEBUG : a/b/c/deep.txt: >Open: fd=a/b/c/deep.txt (r), err=<nil>
2025/12/15 01:32:43 DEBUG : a/b/c/deep.txt: Set virtual modtime to 2025-12-15 01:32:43.881025804 +0000 UTC m=+10.947320028
2025/12/15 01:32:43 DEBUG : a/b/c/deep.txt: ChunkedReader.openRange at 0 length 134217728
2025/12/15 01:32:45 DEBUG : a/b/c/deep.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2025/12/15 01:32:45 DEBUG : a/b/mid.txt: Open: flags=O_RDONLY
2025/12/15 01:32:45 DEBUG : a/b/mid.txt: >Open: fd=a/b/mid.txt (r), err=<nil>
2025/12/15 01:32:45 DEBUG : a/b/mid.txt: Set virtual modtime to 2025-12-15 01:32:43.33583688 +0000 UTC m=+10.402131143
2025/12/15 01:32:45 DEBUG : a/b/mid.txt: ChunkedReader.openRange at 0 length 134217728
2025/12/15 01:32:46 DEBUG : a/b/mid.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2025/12/15 01:32:46 DEBUG : a/top.txt: Open: flags=O_RDONLY
2025/12/15 01:32:46 DEBUG : a/top.txt: >Open: fd=a/top.txt (r), err=<nil>
2025/12/15 01:32:46 DEBUG : a/top.txt: Set virtual modtime to 2025-12-15 01:32:42.89805645 +0000 UTC m=+9.964350703
2025/12/15 01:32:46 DEBUG : a/top.txt: ChunkedReader.openRange at 0 length 134217728
2025/12/15 01:32:47 DEBUG : a/top.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2025/12/15 01:32:47 DEBUG : WaitForWriters: timeout=30s
2025/12/15 01:32:47 DEBUG : a/b/c: Looking for writers
2025/12/15 01:32:47 DEBUG : deep.txt: reading active writers
2025/12/15 01:32:47 DEBUG : a/b: Looking for writers
2025/12/15 01:32:47 DEBUG : c: reading active writers
2025/12/15 01:32:47 DEBUG : mid.txt: reading active writers
2025/12/15 01:32:47 DEBUG : a: Looking for writers
2025/12/15 01:32:47 DEBUG : b: reading active writers
2025/12/15 01:32:47 DEBUG : top.txt: reading active writers
2025/12/15 01:32:47 DEBUG : Looking for writers
2025/12/15 01:32:47 DEBUG : a: reading active writers
2025/12/15 01:32:47 DEBUG : >WaitForWriters: 
2025/12/15 01:32:49 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully deleted file: /rclone-test-mahexak6teco/a/top.txt
2025/12/15 01:32:50 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully deleted file: /rclone-test-mahexak6teco/a/b/mid.txt
2025/12/15 01:33:01 INFO  : FileLu root 'rclone-test-mahexak6teco': Successfully deleted file: /rclone-test-mahexak6teco/a/b/c/deep.txt
2025/12/15 01:33:08 INFO  : FileLu root 'rclone-test-mahexak6teco': Rmdir: successfully deleted "/rclone-test-mahexak6teco/a/b/c"
2025/12/15 01:33:15 INFO  : FileLu root 'rclone-test-mahexak6teco': Rmdir: successfully deleted "/rclone-test-mahexak6teco/a/b"
2025/12/15 01:33:20 INFO  : FileLu root 'rclone-test-mahexak6teco': Rmdir: successfully deleted "/rclone-test-mahexak6teco/a"
--- PASS: TestZipManySubDirs (47.70s)
PASS
2025/12/15 01:33:20 DEBUG : FileLu root 'rclone-test-mahexak6teco': Purge remote
2025/12/15 01:33:21 INFO  : FileLu root 'rclone-test-mahexak6teco': Rmdir: successfully deleted "/rclone-test-mahexak6teco"
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestFileLu: -verbose -test.run '^TestZipManySubDirs$'" - Finished OK in 48.329914918s (try 2/5)