"./vfs.test -test.v -test.timeout 1h0m0s -remote TestWebdavInfiniteScale: -verbose -test.run '^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$|^TestWriteFileHandleMethods$'" - Starting (try 4/5)
2025/07/06 01:58:14 DEBUG : Creating backend with remote "TestWebdavInfiniteScale:rclone-test-rometuf0cezo"
2025/07/06 01:58:14 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/07/06 01:58:14 DEBUG : Setting type="webdav" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_TYPE
2025/07/06 01:58:14 DEBUG : Setting url="https://127.0.0.1:9200/dav/spaces/some-admin-user-id-0000-100000000000" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_URL
2025/07/06 01:58:14 DEBUG : Setting vendor="infinitescale" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_VENDOR
2025/07/06 01:58:14 DEBUG : Setting user="admin" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_USER
2025/07/06 01:58:14 DEBUG : Setting pass="ZtlWzwYf0nIXCCXnUqq8BcwgIN4r" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_PASS
2025/07/06 01:58:14 DEBUG : TestWebdavInfiniteScale: detected overridden config - adding "{UFdD8}" suffix to name
2025/07/06 01:58:14 DEBUG : Setting url="https://127.0.0.1:9200/dav/spaces/some-admin-user-id-0000-100000000000" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_URL
2025/07/06 01:58:14 DEBUG : Setting vendor="infinitescale" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_VENDOR
2025/07/06 01:58:14 DEBUG : Setting user="admin" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_USER
2025/07/06 01:58:14 DEBUG : Setting pass="ZtlWzwYf0nIXCCXnUqq8BcwgIN4r" for "TestWebdavInfiniteScale" from environment variable RCLONE_CONFIG_TESTWEBDAVINFINITESCALE_PASS
2025/07/06 01:58:14 DEBUG : found headers: 
2025/07/06 01:58:15 DEBUG : Creating backend with remote "/tmp/rclone1446488612"
2025/07/06 01:58:15 DEBUG : Config file has changed externally - reloading
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:180: Remote "webdav root 'rclone-test-rometuf0cezo'", Local "Local file system at /tmp/rclone1446488612", Modify Window "1s"
2025/07/06 01:58:15 INFO  : webdav root 'rclone-test-rometuf0cezo': poll-interval is not supported by this remote
2025/07/06 01:58:15 NOTICE: webdav root 'rclone-test-rometuf0cezo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2025/07/06 01:58:15 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:15 INFO  : dir/file1: Failed to read metadata: object not found
2025/07/06 01:58:15 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:15 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 14
2025/07/06 01:58:15 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:15 DEBUG : time_test: Update will use the tus protocol to upload
2025/07/06 01:58:15 INFO  : time_test: Failed to read metadata: object not found
2025/07/06 01:58:15 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:16 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 5
2025/07/06 01:58:16 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:16 DEBUG : Can set mod time: true
2025/07/06 01:58:16 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
    fstest.go:124: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:139
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:159
        	Error:      	Should be true
        	Test:       	TestFileSetModTime/cache=off,open=false,write=false
        	Messages:   	dir/file1: Modification time difference too big |95456h54m53.123456789s| > 1s (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2001-02-03 04:05:06 +0000 GMT) (precision 1s)
2025/07/06 01:58:16 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:16 DEBUG : dir: Looking for writers
2025/07/06 01:58:16 DEBUG : file1: reading active writers
2025/07/06 01:58:16 DEBUG : Looking for writers
2025/07/06 01:58:16 DEBUG : dir: reading active writers
2025/07/06 01:58:16 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=false
    run.go:180: Remote "webdav root 'rclone-test-rometuf0cezo'", Local "Local file system at /tmp/rclone1446488612", Modify Window "1s"
2025/07/06 01:58:17 INFO  : webdav root 'rclone-test-rometuf0cezo': poll-interval is not supported by this remote
2025/07/06 01:58:17 NOTICE: webdav root 'rclone-test-rometuf0cezo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2025/07/06 01:58:17 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:17 INFO  : dir/file1: Failed to read metadata: object not found
2025/07/06 01:58:17 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:17 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 14
2025/07/06 01:58:17 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:17 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2025/07/06 01:58:17 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2025/07/06 01:58:17 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:17 DEBUG : webdav root 'rclone-test-rometuf0cezo': File to upload is small (0 bytes), uploading instead of streaming
2025/07/06 01:58:17 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:17 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:17 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:18 DEBUG : dir/file1: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/07/06 01:58:18 DEBUG : dir/file1: Size and sha1 of src and dst objects identical
2025/07/06 01:58:18 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2025/07/06 01:58:18 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:18 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:18 DEBUG : dir: Looking for writers
2025/07/06 01:58:18 DEBUG : file1: reading active writers
2025/07/06 01:58:18 DEBUG : Looking for writers
2025/07/06 01:58:18 DEBUG : dir: reading active writers
2025/07/06 01:58:18 DEBUG : >WaitForWriters: 
    fstest.go:124: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:139
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:159
        	Error:      	Should be true
        	Test:       	TestFileSetModTime/cache=off,open=true,write=false
        	Messages:   	dir/file1: Modification time difference too big |-118596h58m17.876543211s| > 1s (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2025-07-06 01:58:17 +0000 GMT) (precision 1s)
2025/07/06 01:58:18 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:18 DEBUG : dir: Looking for writers
2025/07/06 01:58:18 DEBUG : file1: reading active writers
2025/07/06 01:58:18 DEBUG : Looking for writers
2025/07/06 01:58:18 DEBUG : dir: reading active writers
2025/07/06 01:58:18 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=true
    run.go:180: Remote "webdav root 'rclone-test-rometuf0cezo'", Local "Local file system at /tmp/rclone1446488612", Modify Window "1s"
2025/07/06 01:58:18 INFO  : webdav root 'rclone-test-rometuf0cezo': poll-interval is not supported by this remote
2025/07/06 01:58:18 NOTICE: webdav root 'rclone-test-rometuf0cezo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2025/07/06 01:58:18 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:18 INFO  : dir/file1: Failed to read metadata: object not found
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 14
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:19 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2025/07/06 01:58:19 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2025/07/06 01:58:19 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': File to upload is small (5 bytes), uploading instead of streaming
2025/07/06 01:58:19 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 5
2025/07/06 01:58:19 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:19 DEBUG : dir/file1: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK
2025/07/06 01:58:19 DEBUG : dir/file1: Size and sha1 of src and dst objects identical
2025/07/06 01:58:19 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2025/07/06 01:58:19 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:19 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:19 DEBUG : dir: Looking for writers
2025/07/06 01:58:19 DEBUG : file1: reading active writers
2025/07/06 01:58:19 DEBUG : Looking for writers
2025/07/06 01:58:19 DEBUG : dir: reading active writers
2025/07/06 01:58:19 DEBUG : >WaitForWriters: 
    fstest.go:124: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:139
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:159
        	Error:      	Should be true
        	Test:       	TestFileSetModTime/cache=off,open=true,write=true
        	Messages:   	dir/file1: Modification time difference too big |-118596h58m19.876543211s| > 1s (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2025-07-06 01:58:19 +0000 GMT) (precision 1s)
2025/07/06 01:58:20 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:20 DEBUG : dir: Looking for writers
2025/07/06 01:58:20 DEBUG : file1: reading active writers
2025/07/06 01:58:20 DEBUG : Looking for writers
2025/07/06 01:58:20 DEBUG : dir: reading active writers
2025/07/06 01:58:20 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=full,open=false,write=false
    run.go:180: Remote "webdav root 'rclone-test-rometuf0cezo'", Local "Local file system at /tmp/rclone1446488612", Modify Window "1s"
2025/07/06 01:58:20 INFO  : webdav root 'rclone-test-rometuf0cezo': poll-interval is not supported by this remote
2025/07/06 01:58:20 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: root is "/home/rclone/.cache/rclone"
2025/07/06 01:58:20 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:20 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:20 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:20 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2025/07/06 01:58:20 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:20 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:20 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2025/07/06 01:58:20 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:20 INFO  : webdav root 'rclone-test-rometuf0cezo': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2025/07/06 01:58:20 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:20 INFO  : dir/file1: Failed to read metadata: object not found
2025/07/06 01:58:20 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:20 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 14
2025/07/06 01:58:20 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:21 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
    fstest.go:124: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:139
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:159
        	Error:      	Should be true
        	Test:       	TestFileSetModTime/cache=full,open=false,write=false
        	Messages:   	dir/file1: Modification time difference too big |95456h54m53.123456789s| > 1s (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2001-02-03 04:05:06 +0000 GMT) (precision 1s)
2025/07/06 01:58:21 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:21 DEBUG : dir: Looking for writers
2025/07/06 01:58:21 DEBUG : file1: reading active writers
2025/07/06 01:58:21 DEBUG : Looking for writers
2025/07/06 01:58:21 DEBUG : dir: reading active writers
2025/07/06 01:58:21 DEBUG : >WaitForWriters: 
2025/07/06 01:58:21 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: cleaner exiting
=== RUN   TestFileSetModTime/cache=full,open=true,write=false
    run.go:180: Remote "webdav root 'rclone-test-rometuf0cezo'", Local "Local file system at /tmp/rclone1446488612", Modify Window "1s"
2025/07/06 01:58:22 INFO  : webdav root 'rclone-test-rometuf0cezo': poll-interval is not supported by this remote
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: root is "/home/rclone/.cache/rclone"
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:22 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:22 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2025/07/06 01:58:22 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:22 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:22 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2025/07/06 01:58:22 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestWebdavInfiniteScale{UFdD8}/rclone-test-rometuf0cezo"
2025/07/06 01:58:22 INFO  : webdav root 'rclone-test-rometuf0cezo': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2025/07/06 01:58:22 DEBUG : dir/file1: Update will use the tus protocol to upload
2025/07/06 01:58:22 INFO  : dir/file1: Failed to read metadata: object not found
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 14
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:22 DEBUG : dir/file1: Open: flags=O_WRONLY
2025/07/06 01:58:22 DEBUG : dir/file1: newRWFileHandle: 
2025/07/06 01:58:22 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2025/07/06 01:58:22 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2025/07/06 01:58:22 DEBUG : dir/file1(0xc000602740): close: 
2025/07/06 01:58:22 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2025/07/06 01:58:22 DEBUG : dir/file1(0xc000602740): >close: err=<nil>
2025/07/06 01:58:22 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:22 DEBUG : dir: Looking for writers
2025/07/06 01:58:22 DEBUG : file1: reading active writers
2025/07/06 01:58:22 DEBUG : Looking for writers
2025/07/06 01:58:22 DEBUG : dir: reading active writers
2025/07/06 01:58:22 DEBUG : >WaitForWriters: 
    fstest.go:124: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:124
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:129
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:148
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:347
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:139
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:159
        	Error:      	Should be true
        	Test:       	TestFileSetModTime/cache=full,open=true,write=false
        	Messages:   	dir/file1: Modification time difference too big |95456h54m53.123456789s| > 1s (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2001-02-03 04:05:06 +0000 GMT) (precision 1s)
2025/07/06 01:58:22 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:22 DEBUG : dir: Looking for writers
2025/07/06 01:58:22 DEBUG : file1: reading active writers
2025/07/06 01:58:22 DEBUG : Looking for writers
2025/07/06 01:58:22 DEBUG : dir: reading active writers
2025/07/06 01:58:22 DEBUG : >WaitForWriters: 
2025/07/06 01:58:22 DEBUG : webdav root 'rclone-test-rometuf0cezo': vfs cache: cleaner exiting
--- FAIL: TestFileSetModTime (8.39s)
    --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (2.03s)
    --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (1.75s)
    --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (1.75s)
    --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (1.43s)
    --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (1.42s)
=== RUN   TestWriteFileHandleMethods
    run.go:180: Remote "webdav root 'rclone-test-rometuf0cezo'", Local "Local file system at /tmp/rclone1446488612", Modify Window "1s"
2025/07/06 01:58:23 INFO  : webdav root 'rclone-test-rometuf0cezo': poll-interval is not supported by this remote
2025/07/06 01:58:23 NOTICE: webdav root 'rclone-test-rometuf0cezo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2025/07/06 01:58:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2025/07/06 01:58:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal
2025/07/06 01:58:23 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal
2025/07/06 01:58:23 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2025/07/06 01:58:23 DEBUG : webdav root 'rclone-test-rometuf0cezo': File to upload is small (5 bytes), uploading instead of streaming
2025/07/06 01:58:23 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:23 INFO  : file1: Failed to read metadata: object not found
2025/07/06 01:58:23 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:23 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 ok, range 0 -> 5
2025/07/06 01:58:23 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:23 DEBUG : file1: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK
2025/07/06 01:58:23 DEBUG : file1: Size and sha1 of src and dst objects identical
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2025/07/06 01:58:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2025/07/06 01:58:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes
2025/07/06 01:58:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2025/07/06 01:58:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2025/07/06 01:58:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:23 DEBUG : webdav root 'rclone-test-rometuf0cezo': File to upload is small (0 bytes), uploading instead of streaming
2025/07/06 01:58:23 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:24 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:24 DEBUG : webdav root 'rclone-test-rometuf0cezo': -- Uploaded finished
2025/07/06 01:58:24 DEBUG : file1: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/07/06 01:58:24 DEBUG : file1: Size and sha1 of src and dst objects identical
2025/07/06 01:58:24 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:24 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2025/07/06 01:58:24 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2025/07/06 01:58:24 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:24 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2025/07/06 01:58:24 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2025/07/06 01:58:24 DEBUG : Added virtual directory entry vAddFile: "file1"
2025/07/06 01:58:24 DEBUG : webdav root 'rclone-test-rometuf0cezo': File to upload is small (7 bytes), uploading instead of streaming
2025/07/06 01:58:24 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:24 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:24 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:24 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:24 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:24 DEBUG : file1: tus update failed.
2025/07/06 01:58:24 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 1/10
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:24 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:24 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:24 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:24 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:24 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:24 DEBUG : file1: tus update failed.
2025/07/06 01:58:24 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 2/10
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:24 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:24 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:24 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:24 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:24 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:24 DEBUG : file1: tus update failed.
2025/07/06 01:58:24 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 3/10
2025/07/06 01:58:24 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:24 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:25 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:25 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:25 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:25 DEBUG : file1: tus update failed.
2025/07/06 01:58:25 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 4/10
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:25 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:25 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:25 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:25 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:25 DEBUG : file1: tus update failed.
2025/07/06 01:58:25 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 5/10
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:25 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:25 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:25 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:25 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:25 DEBUG : file1: tus update failed.
2025/07/06 01:58:25 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 6/10
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:25 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:25 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:25 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:25 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:25 DEBUG : file1: tus update failed.
2025/07/06 01:58:25 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 7/10
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:25 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:25 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:26 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:26 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:26 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:26 DEBUG : file1: tus update failed.
2025/07/06 01:58:26 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 8/10
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:26 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:26 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:26 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:26 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:26 DEBUG : file1: tus update failed.
2025/07/06 01:58:26 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 9/10
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:26 DEBUG : file1: Update will use the tus protocol to upload
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 10ms
2025/07/06 01:58:26 DEBUG : webdav root 'rclone-test-rometuf0cezo': Uploaded starts
2025/07/06 01:58:26 DEBUG : pacer: low level retry 1/1 (error 500 Internal Server Error)
2025/07/06 01:58:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/06 01:58:26 ERROR : webdav root 'rclone-test-rometuf0cezo': Uploaded chunk no 1 failed: uploadChunk failed: 500 Internal Server Error
2025/07/06 01:58:26 DEBUG : file1: tus update failed.
2025/07/06 01:58:26 DEBUG : file1: Received error: tus update failed: uploadChunk failed: 500 Internal Server Error - low level retry 10/10
2025/07/06 01:58:26 ERROR : file1: WriteFileHandle.New Rcat failed: tus update failed: uploadChunk failed: 500 Internal Server Error
    write_test.go:190: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:190
        	Error:      	Received unexpected error:
        	            	tus update failed: uploadChunk failed: 500 Internal Server Error
        	Test:       	TestWriteFileHandleMethods
    dir_test.go:250: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:191
        	Error:      	Not equal: 
        	            	expected: []string{"file1,7,false"}
        	            	actual  : []string{"file1,0,false"}
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1,3 +1,3 @@
        	            	 ([]string) (len=1) {
        	            	- (string) (len=13) "file1,7,false"
        	            	+ (string) (len=13) "file1,0,false"
        	            	 }
        	Test:       	TestWriteFileHandleMethods
2025/07/06 01:58:26 DEBUG : WaitForWriters: timeout=30s
2025/07/06 01:58:26 DEBUG : Looking for writers
2025/07/06 01:58:26 DEBUG : file1: reading active writers
2025/07/06 01:58:26 DEBUG : >WaitForWriters: 
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 15ms
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/06 01:58:26 DEBUG : pacer: Reducing sleep to 10ms
--- FAIL: TestWriteFileHandleMethods (3.27s)
FAIL
2025/07/06 01:58:26 DEBUG : webdav root 'rclone-test-rometuf0cezo': Purge remote
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestWebdavInfiniteScale: -verbose -test.run '^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$|^TestWriteFileHandleMethods$'" - Finished ERROR in 12.314399952s (try 4/5): exit status 1: Failed [TestFileSetModTime/cache=off,open=false,write=false TestFileSetModTime/cache=off,open=true,write=false TestFileSetModTime/cache=off,open=true,write=true TestFileSetModTime/cache=full,open=false,write=false TestFileSetModTime/cache=full,open=true,write=false TestWriteFileHandleMethods]