"./vfs.test -test.v -test.timeout 1h0m0s -remote TestProtonDrive: -verbose -test.run '^(TestCaseSensitivity|TestDirCreate|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestRWCacheUpdate|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Starting (try 2/5) 2024/04/25 04:58:28 DEBUG : Creating backend with remote "TestProtonDrive:rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:58:28 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/04/25 04:58:28 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': Has cached credentials 2024/04/25 04:58:29 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': Used cached credential to initialize the ProtonDrive API 2024/04/25 04:58:30 DEBUG : Creating backend with remote "/tmp/rclone1448066485" === RUN TestDirHandleMethods run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:30 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:30 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:32.531734 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:32.531772 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:32 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:32 DEBUG : : Looking for writers 2024/04/25 04:58:32 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleMethods (3.84s) === RUN TestDirHandleReaddir run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:34 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:34 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:35.387853 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:35.387886 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:35 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:35 DEBUG : : Looking for writers 2024/04/25 04:58:35 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (2.85s) === RUN TestDirHandleReaddirnames run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:36 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:36 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:38.352188 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:38.352213 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:38 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:38 DEBUG : : Looking for writers 2024/04/25 04:58:38 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddirnames (2.94s) === RUN TestDirMethods run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:39 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:39 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:41.171743 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:41.171780 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:41 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:41 DEBUG : : Looking for writers 2024/04/25 04:58:41 DEBUG : >WaitForWriters: --- FAIL: TestDirMethods (2.71s) === RUN TestDirForgetAll run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:42 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:42 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:43.942650 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:43.942680 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:43 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:43 DEBUG : : Looking for writers 2024/04/25 04:58:43 DEBUG : >WaitForWriters: --- FAIL: TestDirForgetAll (2.85s) === RUN TestDirForgetPath run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:45 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:45 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:46.738876 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:46.738899 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:46 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:46 DEBUG : : Looking for writers 2024/04/25 04:58:46 DEBUG : >WaitForWriters: --- FAIL: TestDirForgetPath (2.77s) === RUN TestDirWalk run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:48 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:48 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:49.466230 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:49.466276 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:49 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:49 DEBUG : : Looking for writers 2024/04/25 04:58:49 DEBUG : >WaitForWriters: --- FAIL: TestDirWalk (2.98s) === RUN TestDirSetModTime run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:51 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:51 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:52.603672 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:52.603710 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:52 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:52 DEBUG : : Looking for writers 2024/04/25 04:58:52 DEBUG : >WaitForWriters: --- FAIL: TestDirSetModTime (2.80s) === RUN TestDirStat run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:53 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:53 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:55.391698 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:55.391728 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:55 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:55 DEBUG : : Looking for writers 2024/04/25 04:58:55 DEBUG : >WaitForWriters: --- FAIL: TestDirStat (2.81s) === RUN TestDirReadDirAll run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:56 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:56 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:58:58.115085 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:58:58.115114 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:58:58 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:58:58 DEBUG : : Looking for writers 2024/04/25 04:58:58 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (3.09s) === RUN TestDirOpen run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:58:59 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:58:59 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:01.066598 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:01.066630 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:01 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:01 DEBUG : : Looking for writers 2024/04/25 04:59:01 DEBUG : >WaitForWriters: --- FAIL: TestDirOpen (2.65s) === RUN TestDirCreate run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:02 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:02 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:03.786695 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:03.786724 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:03 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:03 DEBUG : : Looking for writers 2024/04/25 04:59:03 DEBUG : >WaitForWriters: --- FAIL: TestDirCreate (2.72s) === RUN TestDirMkdir run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:05 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:05 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:06.613777 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:06.613805 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:06 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:06 DEBUG : : Looking for writers 2024/04/25 04:59:06 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdir (3.22s) === RUN TestDirMkdirSub run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:08 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:08 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:10.374129 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:10.374150 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:10 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:10 DEBUG : : Looking for writers 2024/04/25 04:59:10 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdirSub (3.69s) === RUN TestDirRemove run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:12 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:12 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:13.668807 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:13.668829 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:13 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:13 DEBUG : : Looking for writers 2024/04/25 04:59:13 DEBUG : >WaitForWriters: --- FAIL: TestDirRemove (3.31s) === RUN TestDirRemoveAll run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:15 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:15 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:16.878381 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:16.878414 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:16 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:16 DEBUG : : Looking for writers 2024/04/25 04:59:16 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveAll (2.97s) === RUN TestDirRemoveName run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:18 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:18 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:19.779925 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:19.779956 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:19 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:19 DEBUG : : Looking for writers 2024/04/25 04:59:19 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveName (3.61s) === RUN TestDirRename run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:21 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:21 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:23.314140 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:23.314172 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:23 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:23 DEBUG : : Looking for writers 2024/04/25 04:59:23 DEBUG : >WaitForWriters: --- FAIL: TestDirRename (2.98s) === RUN TestFileMethods run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:24 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:24 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:26.324563 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:26.324596 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:26 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:26 DEBUG : : Looking for writers 2024/04/25 04:59:26 DEBUG : >WaitForWriters: --- FAIL: TestFileMethods (2.78s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:27 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:27 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:29.066679 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:29.066719 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:29 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:29 DEBUG : : Looking for writers 2024/04/25 04:59:29 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:30 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:30 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:31.941149 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:31.941172 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:31 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:31 DEBUG : : Looking for writers 2024/04/25 04:59:31 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:33 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:33 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:34.734584 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:34.734629 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:34 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:34 DEBUG : : Looking for writers 2024/04/25 04:59:34 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:36 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:36 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 04:59:36 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:36 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:36 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:36 DEBUG : Config file has changed externally - reloading 2024/04/25 04:59:36 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:36 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 04:59:37.604690 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:37.604714 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:37 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:37 DEBUG : : Looking for writers 2024/04/25 04:59:37 DEBUG : >WaitForWriters: 2024/04/25 04:59:37 DEBUG : vfs cache: cleaner exiting === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:39 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:39 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 04:59:39 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:39 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:39 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:39 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:39 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 04:59:40.502313 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:40.502349 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:40 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:40 DEBUG : : Looking for writers 2024/04/25 04:59:40 DEBUG : >WaitForWriters: 2024/04/25 04:59:40 DEBUG : vfs cache: cleaner exiting === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:41 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:41 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 04:59:41 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:41 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:41 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:41 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 04:59:41 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 04:59:43.294457 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:43.294523 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:43 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:43 DEBUG : : Looking for writers 2024/04/25 04:59:43 DEBUG : >WaitForWriters: 2024/04/25 04:59:43 DEBUG : vfs cache: cleaner exiting --- FAIL: TestFileSetModTime (16.96s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (2.84s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (2.82s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (2.78s) --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (2.91s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (2.86s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (2.75s) === RUN TestFileOpenRead run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:44 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:44 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:46.060527 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:46.060563 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:46 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:46 DEBUG : : Looking for writers 2024/04/25 04:59:46 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenRead (2.83s) === RUN TestFileOpenWrite run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:47 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:47 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:48.849632 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:48.849664 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:48 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:48 DEBUG : : Looking for writers 2024/04/25 04:59:48 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenWrite (2.73s) === RUN TestFileRemove run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:50 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:50 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:51.605322 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:51.605390 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:51 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:51 DEBUG : : Looking for writers 2024/04/25 04:59:51 DEBUG : >WaitForWriters: --- FAIL: TestFileRemove (2.74s) === RUN TestFileRemoveAll run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:52 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:52 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:54.393765 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:54.393811 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:54 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:54 DEBUG : : Looking for writers 2024/04/25 04:59:54 DEBUG : >WaitForWriters: --- FAIL: TestFileRemoveAll (2.91s) === RUN TestFileOpen run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:55 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:55 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 04:59:57.396054 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 04:59:57.396085 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 04:59:57 DEBUG : WaitForWriters: timeout=30s 2024/04/25 04:59:57 DEBUG : : Looking for writers 2024/04/25 04:59:57 DEBUG : >WaitForWriters: --- FAIL: TestFileOpen (3.02s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 04:59:58 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 04:59:58 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:00.324826 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:00.324856 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:00 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:00 DEBUG : : Looking for writers 2024/04/25 05:00:00 DEBUG : >WaitForWriters: === RUN TestFileRename/minimal,forceCache=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:01 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:01 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:01 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:01 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:01 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:01 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:01 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:01 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:03.179162 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:03.179205 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:03 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:03 DEBUG : : Looking for writers 2024/04/25 05:00:03 DEBUG : >WaitForWriters: 2024/04/25 05:00:03 DEBUG : vfs cache: cleaner exiting === RUN TestFileRename/minimal,forceCache=true run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:04 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:04 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:04 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:04 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:04 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:04 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:04 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:04 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:06.140503 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:06.140528 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:06 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:06 DEBUG : : Looking for writers 2024/04/25 05:00:06 DEBUG : >WaitForWriters: 2024/04/25 05:00:06 DEBUG : vfs cache: cleaner exiting === RUN TestFileRename/writes,forceCache=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:07 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:07 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:07 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:07 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:07 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:07 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:07 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:09.042924 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:09.042973 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:09 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:09 DEBUG : : Looking for writers 2024/04/25 05:00:09 DEBUG : >WaitForWriters: 2024/04/25 05:00:09 DEBUG : vfs cache: cleaner exiting === RUN TestFileRename/writes,forceCache=true run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:10 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:10 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:10 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:10 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:10 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:10 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:10 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:12.023403 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:12.023440 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:12 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:12 DEBUG : : Looking for writers 2024/04/25 05:00:12 DEBUG : >WaitForWriters: 2024/04/25 05:00:12 DEBUG : vfs cache: cleaner exiting === RUN TestFileRename/full,forceCache=false run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:13 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:13 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:13 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:13 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:13 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:13 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:13 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:14.756610 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:14.756637 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:14 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:14 DEBUG : : Looking for writers 2024/04/25 05:00:14 DEBUG : >WaitForWriters: 2024/04/25 05:00:14 DEBUG : vfs cache: cleaner exiting --- FAIL: TestFileRename (17.28s) --- FAIL: TestFileRename/off,forceCache=false (2.88s) --- FAIL: TestFileRename/minimal,forceCache=false (2.90s) --- FAIL: TestFileRename/minimal,forceCache=true (3.00s) --- FAIL: TestFileRename/writes,forceCache=false (2.89s) --- FAIL: TestFileRename/writes,forceCache=true (2.88s) --- FAIL: TestFileRename/full,forceCache=false (2.73s) === RUN TestReadFileHandleMethods run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:16 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:16 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:17.569840 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:17.569868 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:17 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:17 DEBUG : : Looking for writers 2024/04/25 05:00:17 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleMethods (2.82s) === RUN TestReadFileHandleSeek run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:19 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:19 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:20.345814 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:20.345850 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:20 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:20 DEBUG : : Looking for writers 2024/04/25 05:00:20 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleSeek (2.85s) === RUN TestReadFileHandleReadAt run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:21 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:21 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:23.241253 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:23.241282 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:23 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:23 DEBUG : : Looking for writers 2024/04/25 05:00:23 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleReadAt (2.80s) === RUN TestReadFileHandleFlush run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:24 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:24 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:26.039388 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:26.039423 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:26 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:26 DEBUG : : Looking for writers 2024/04/25 05:00:26 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleFlush (3.54s) === RUN TestReadFileHandleRelease run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:28 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:28 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:00:29.592665 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:29.592703 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:29 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:29 DEBUG : : Looking for writers 2024/04/25 05:00:29 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleRelease (2.83s) === RUN TestRWFileHandleMethodsRead run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:31 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:31 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:31 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:31 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:31 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:31 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:32.405724 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:32.405750 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:32 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:32 DEBUG : : Looking for writers 2024/04/25 05:00:32 DEBUG : >WaitForWriters: 2024/04/25 05:00:32 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleMethodsRead (2.85s) === RUN TestRWFileHandleSeek run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:33 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:33 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:33 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:33 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:33 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:33 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:33 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:35.143188 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:35.143210 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:35 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:35 DEBUG : : Looking for writers 2024/04/25 05:00:35 DEBUG : >WaitForWriters: 2024/04/25 05:00:35 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleSeek (2.75s) === RUN TestRWFileHandleReadAt run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:36 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:36 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:36 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:36 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:36 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:36 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:36 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:38.128740 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:38.128773 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:38 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:38 DEBUG : : Looking for writers 2024/04/25 05:00:38 DEBUG : >WaitForWriters: 2024/04/25 05:00:38 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleReadAt (3.03s) === RUN TestRWFileHandleFlushRead run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:39 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:39 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:39 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:39 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:39 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:39 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:39 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:41.060988 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:41.061024 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:41 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:41 DEBUG : : Looking for writers 2024/04/25 05:00:41 DEBUG : >WaitForWriters: 2024/04/25 05:00:41 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleFlushRead (2.81s) === RUN TestRWFileHandleReleaseRead run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:42 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:42 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:42 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:42 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:42 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:42 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:42 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:43.893967 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:43.893999 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:43 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:43 DEBUG : : Looking for writers 2024/04/25 05:00:43 DEBUG : >WaitForWriters: 2024/04/25 05:00:43 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleReleaseRead (2.86s) === RUN TestRWFileHandleMethodsWrite run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:00:45 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:00:45 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:00:45 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:45 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:45 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:45 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:00:45 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:00:45 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:00:45 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:00:45 DEBUG : file1: newRWFileHandle: 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): openPending: 2024/04/25 05:00:45 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2024/04/25 05:00:45 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): >openPending: err= 2024/04/25 05:00:45 DEBUG : file1: >newRWFileHandle: err= 2024/04/25 05:00:45 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:00:45 DEBUG : file1: >Open: fd=file1 (rw), err= 2024/04/25 05:00:45 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): _writeAt: size=5, off=0 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): >_writeAt: n=5, err= 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): _writeAt: size=7, off=5 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): >_writeAt: n=7, err= 2024/04/25 05:00:45 DEBUG : file1: vfs cache: truncate to size=11 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): close: 2024/04/25 05:00:45 DEBUG : file1: vfs cache: setting modification time to 2024-04-25 05:00:45.672123108 +0000 UTC m=+136.901683816 2024/04/25 05:00:45 INFO : file1: vfs cache: queuing for upload in 100ms 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): >close: err= 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): close: 2024/04/25 05:00:45 DEBUG : file1(0xc00099f3c0): >close: err=file already closed 2024/04/25 05:00:45 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:00:45 DEBUG : : Looking for writers 2024/04/25 05:00:45 DEBUG : file1: reading active writers 2024/04/25 05:00:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2024/04/25 05:00:45 DEBUG : : Looking for writers 2024/04/25 05:00:45 DEBUG : file1: reading active writers 2024/04/25 05:00:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2024/04/25 05:00:45 DEBUG : : Looking for writers 2024/04/25 05:00:45 DEBUG : file1: reading active writers 2024/04/25 05:00:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2024/04/25 05:00:45 DEBUG : : Looking for writers 2024/04/25 05:00:45 DEBUG : file1: reading active writers 2024/04/25 05:00:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2024/04/25 05:00:45 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:00:45 DEBUG : : Looking for writers 2024/04/25 05:00:45 DEBUG : file1: reading active writers 2024/04/25 05:00:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2024/04/25 05:00:45 DEBUG : : Looking for writers 2024/04/25 05:00:45 DEBUG : file1: reading active writers 2024/04/25 05:00:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2024/04/25 05:00:46 DEBUG : : Looking for writers 2024/04/25 05:00:46 DEBUG : file1: reading active writers 2024/04/25 05:00:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2024/04/25 05:00:46.317069 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:00:46.317098 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:46 ERROR : file1: Failed to copy: 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:46 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:00:46 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:00:46 DEBUG : : Looking for writers 2024/04/25 05:00:46 DEBUG : file1: reading active writers 2024/04/25 05:00:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:47.297224 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:00:47.297269 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:00:47 DEBUG : : Looking for writers 2024/04/25 05:00:47 DEBUG : file1: reading active writers 2024/04/25 05:00:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:48 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:48 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:48 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:00:48 DEBUG : : Looking for writers 2024/04/25 05:00:48 DEBUG : file1: reading active writers 2024/04/25 05:00:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:49.439001 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:00:49.439045 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:00:49 DEBUG : : Looking for writers 2024/04/25 05:00:49 DEBUG : file1: reading active writers 2024/04/25 05:00:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:50 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:50 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:50 DEBUG : : Looking for writers 2024/04/25 05:00:50 DEBUG : file1: reading active writers 2024/04/25 05:00:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:51 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:00:51 DEBUG : : Looking for writers 2024/04/25 05:00:51 DEBUG : file1: reading active writers 2024/04/25 05:00:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:52.090894 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:00:52.090918 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:00:52 DEBUG : : Looking for writers 2024/04/25 05:00:52 DEBUG : file1: reading active writers 2024/04/25 05:00:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:53 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:53 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:53 DEBUG : : Looking for writers 2024/04/25 05:00:53 DEBUG : file1: reading active writers 2024/04/25 05:00:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:54 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:00:54 DEBUG : : Looking for writers 2024/04/25 05:00:54 DEBUG : file1: reading active writers 2024/04/25 05:00:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:55.391152 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:00:55.391202 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:00:55 DEBUG : : Looking for writers 2024/04/25 05:00:55 DEBUG : file1: reading active writers 2024/04/25 05:00:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:56 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:56 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:00:56 DEBUG : : Looking for writers 2024/04/25 05:00:56 DEBUG : file1: reading active writers 2024/04/25 05:00:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:57 DEBUG : : Looking for writers 2024/04/25 05:00:57 DEBUG : file1: reading active writers 2024/04/25 05:00:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:58 DEBUG : : Looking for writers 2024/04/25 05:00:58 DEBUG : file1: reading active writers 2024/04/25 05:00:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:00:59 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:00:59 DEBUG : : Looking for writers 2024/04/25 05:00:59 DEBUG : file1: reading active writers 2024/04/25 05:00:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:00.420597 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:01:00.420628 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:01:00 DEBUG : : Looking for writers 2024/04/25 05:01:00 DEBUG : file1: reading active writers 2024/04/25 05:01:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:01 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:01:01 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:01:01 DEBUG : : Looking for writers 2024/04/25 05:01:01 DEBUG : file1: reading active writers 2024/04/25 05:01:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:02 DEBUG : : Looking for writers 2024/04/25 05:01:02 DEBUG : file1: reading active writers 2024/04/25 05:01:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:03 DEBUG : : Looking for writers 2024/04/25 05:01:03 DEBUG : file1: reading active writers 2024/04/25 05:01:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:04 DEBUG : : Looking for writers 2024/04/25 05:01:04 DEBUG : file1: reading active writers 2024/04/25 05:01:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:05 DEBUG : : Looking for writers 2024/04/25 05:01:05 DEBUG : file1: reading active writers 2024/04/25 05:01:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:06 DEBUG : : Looking for writers 2024/04/25 05:01:06 DEBUG : file1: reading active writers 2024/04/25 05:01:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:07 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:01:07 DEBUG : : Looking for writers 2024/04/25 05:01:07 DEBUG : file1: reading active writers 2024/04/25 05:01:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:08.525539 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:01:08.525565 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:01:08 DEBUG : : Looking for writers 2024/04/25 05:01:08 DEBUG : file1: reading active writers 2024/04/25 05:01:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:09 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:01:09 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:01:09 DEBUG : : Looking for writers 2024/04/25 05:01:09 DEBUG : file1: reading active writers 2024/04/25 05:01:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:10 DEBUG : : Looking for writers 2024/04/25 05:01:10 DEBUG : file1: reading active writers 2024/04/25 05:01:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:11 DEBUG : : Looking for writers 2024/04/25 05:01:11 DEBUG : file1: reading active writers 2024/04/25 05:01:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:12 DEBUG : : Looking for writers 2024/04/25 05:01:12 DEBUG : file1: reading active writers 2024/04/25 05:01:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:13 DEBUG : : Looking for writers 2024/04/25 05:01:13 DEBUG : file1: reading active writers 2024/04/25 05:01:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:14 DEBUG : : Looking for writers 2024/04/25 05:01:14 DEBUG : file1: reading active writers 2024/04/25 05:01:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:15 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000022870 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc000c5cc08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824646683712} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13943873145121261796 ext:136901683816 loc:0x3a135e0} ATime:{wall:13943873145121278016 ext:136901700036 loc:0x3a135e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2024/04/25 05:01:15 DEBUG : >WaitForWriters: fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/04/25 05:01:22 DEBUG : file1: vfs cache: starting upload fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 2024/04/25 05:01:31.837459 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:01:31.837489 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:01:32 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:01:32 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft fstest.go:295: Flushing the directory cache 2024/04/25 05:01:45 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2024/04/25 05:01:45 INFO : vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:337 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: listing wrong, want file1 (11) got fstest.go:197: Not found "file1" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:337 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleMethodsWrite Messages: 1 objects not found 2024/04/25 05:01:51 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:01:51 DEBUG : : Looking for writers 2024/04/25 05:01:51 DEBUG : file1: reading active writers 2024/04/25 05:01:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2024/04/25 05:01:51 DEBUG : : Looking for writers 2024/04/25 05:01:51 DEBUG : file1: reading active writers 2024/04/25 05:01:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2024/04/25 05:01:51 DEBUG : : Looking for writers 2024/04/25 05:01:51 DEBUG : file1: reading active writers 2024/04/25 05:01:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2024/04/25 05:01:51 DEBUG : : Looking for writers 2024/04/25 05:01:51 DEBUG : file1: reading active writers 2024/04/25 05:01:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2024/04/25 05:01:51 DEBUG : : Looking for writers 2024/04/25 05:01:51 DEBUG : file1: reading active writers 2024/04/25 05:01:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2024/04/25 05:01:51 DEBUG : : Looking for writers 2024/04/25 05:01:51 DEBUG : file1: reading active writers 2024/04/25 05:01:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2024/04/25 05:01:52 DEBUG : : Looking for writers 2024/04/25 05:01:52 DEBUG : file1: reading active writers 2024/04/25 05:01:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2024/04/25 05:01:52 DEBUG : : Looking for writers 2024/04/25 05:01:52 DEBUG : file1: reading active writers 2024/04/25 05:01:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:53 DEBUG : : Looking for writers 2024/04/25 05:01:53 DEBUG : file1: reading active writers 2024/04/25 05:01:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:54 DEBUG : : Looking for writers 2024/04/25 05:01:54 DEBUG : file1: reading active writers 2024/04/25 05:01:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:55 DEBUG : : Looking for writers 2024/04/25 05:01:55 DEBUG : file1: reading active writers 2024/04/25 05:01:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:56 DEBUG : : Looking for writers 2024/04/25 05:01:56 DEBUG : file1: reading active writers 2024/04/25 05:01:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:57 DEBUG : : Looking for writers 2024/04/25 05:01:57 DEBUG : file1: reading active writers 2024/04/25 05:01:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:58 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:01:58 DEBUG : : Looking for writers 2024/04/25 05:01:58 DEBUG : file1: reading active writers 2024/04/25 05:01:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:01:59 DEBUG : : Looking for writers 2024/04/25 05:01:59 DEBUG : file1: reading active writers 2024/04/25 05:01:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:00 DEBUG : : Looking for writers 2024/04/25 05:02:00 DEBUG : file1: reading active writers 2024/04/25 05:02:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:01 DEBUG : : Looking for writers 2024/04/25 05:02:01 DEBUG : file1: reading active writers 2024/04/25 05:02:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:02 DEBUG : : Looking for writers 2024/04/25 05:02:02 DEBUG : file1: reading active writers 2024/04/25 05:02:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:03 DEBUG : : Looking for writers 2024/04/25 05:02:03 DEBUG : file1: reading active writers 2024/04/25 05:02:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:04 DEBUG : : Looking for writers 2024/04/25 05:02:04 DEBUG : file1: reading active writers 2024/04/25 05:02:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:05 DEBUG : : Looking for writers 2024/04/25 05:02:05 DEBUG : file1: reading active writers 2024/04/25 05:02:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:06 DEBUG : : Looking for writers 2024/04/25 05:02:06 DEBUG : file1: reading active writers 2024/04/25 05:02:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:07 DEBUG : : Looking for writers 2024/04/25 05:02:07 DEBUG : file1: reading active writers 2024/04/25 05:02:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:08 DEBUG : : Looking for writers 2024/04/25 05:02:08 DEBUG : file1: reading active writers 2024/04/25 05:02:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:09 DEBUG : : Looking for writers 2024/04/25 05:02:09 DEBUG : file1: reading active writers 2024/04/25 05:02:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:10 DEBUG : : Looking for writers 2024/04/25 05:02:10 DEBUG : file1: reading active writers 2024/04/25 05:02:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:11 DEBUG : : Looking for writers 2024/04/25 05:02:11 DEBUG : file1: reading active writers 2024/04/25 05:02:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:12 DEBUG : : Looking for writers 2024/04/25 05:02:12 DEBUG : file1: reading active writers 2024/04/25 05:02:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:13.073259 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:13.073286 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:13 DEBUG : : Looking for writers 2024/04/25 05:02:13 DEBUG : file1: reading active writers 2024/04/25 05:02:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:14 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:14 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:14 DEBUG : : Looking for writers 2024/04/25 05:02:14 DEBUG : file1: reading active writers 2024/04/25 05:02:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:15 DEBUG : : Looking for writers 2024/04/25 05:02:15 DEBUG : file1: reading active writers 2024/04/25 05:02:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:16 DEBUG : : Looking for writers 2024/04/25 05:02:16 DEBUG : file1: reading active writers 2024/04/25 05:02:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:17 DEBUG : : Looking for writers 2024/04/25 05:02:17 DEBUG : file1: reading active writers 2024/04/25 05:02:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:18 DEBUG : : Looking for writers 2024/04/25 05:02:18 DEBUG : file1: reading active writers 2024/04/25 05:02:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:19 DEBUG : : Looking for writers 2024/04/25 05:02:19 DEBUG : file1: reading active writers 2024/04/25 05:02:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:20 DEBUG : : Looking for writers 2024/04/25 05:02:20 DEBUG : file1: reading active writers 2024/04/25 05:02:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:21 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000022870 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc000c5cc08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824646683712} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13943873145121261796 ext:136901683816 loc:0x3a135e0} ATime:{wall:13943873145121278016 ext:136901700036 loc:0x3a135e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2024/04/25 05:02:21 DEBUG : >WaitForWriters: 2024/04/25 05:02:21 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleMethodsWrite (96.89s) === RUN TestRWFileHandleWriteAt run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:02:22 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:02:22 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:02:22 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:02:22 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:02:22 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:02:22 DEBUG : Config file has changed externally - reloading 2024/04/25 05:02:22 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:02:22 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:02:22 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:02:22 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:02:22 DEBUG : file1: newRWFileHandle: 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): openPending: 2024/04/25 05:02:22 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2024/04/25 05:02:22 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): >openPending: err= 2024/04/25 05:02:22 DEBUG : file1: >newRWFileHandle: err= 2024/04/25 05:02:22 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:02:22 DEBUG : file1: >Open: fd=file1 (rw), err= 2024/04/25 05:02:22 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): _writeAt: size=7, off=0 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): >_writeAt: n=7, err= 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): _writeAt: size=6, off=5 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): >_writeAt: n=6, err= 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): close: 2024/04/25 05:02:22 DEBUG : file1: vfs cache: setting modification time to 2024-04-25 05:02:22.491668634 +0000 UTC m=+233.721229342 2024/04/25 05:02:22 INFO : file1: vfs cache: queuing for upload in 100ms 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): >close: err= 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): _writeAt: size=5, off=0 2024/04/25 05:02:22 DEBUG : file1(0xc000725b80): >_writeAt: n=0, err=file already closed 2024/04/25 05:02:22 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:02:22 DEBUG : : Looking for writers 2024/04/25 05:02:22 DEBUG : file1: reading active writers 2024/04/25 05:02:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2024/04/25 05:02:22 DEBUG : : Looking for writers 2024/04/25 05:02:22 DEBUG : file1: reading active writers 2024/04/25 05:02:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2024/04/25 05:02:22 DEBUG : : Looking for writers 2024/04/25 05:02:22 DEBUG : file1: reading active writers 2024/04/25 05:02:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2024/04/25 05:02:22 DEBUG : : Looking for writers 2024/04/25 05:02:22 DEBUG : file1: reading active writers 2024/04/25 05:02:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2024/04/25 05:02:22 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:22 DEBUG : : Looking for writers 2024/04/25 05:02:22 DEBUG : file1: reading active writers 2024/04/25 05:02:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2024/04/25 05:02:22 DEBUG : : Looking for writers 2024/04/25 05:02:22 DEBUG : file1: reading active writers 2024/04/25 05:02:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2024/04/25 05:02:23 DEBUG : : Looking for writers 2024/04/25 05:02:23 DEBUG : file1: reading active writers 2024/04/25 05:02:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2024/04/25 05:02:23.269666 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:23.269688 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:23 DEBUG : : Looking for writers 2024/04/25 05:02:23 DEBUG : file1: reading active writers 2024/04/25 05:02:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:24 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:24 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:24 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:24 DEBUG : : Looking for writers 2024/04/25 05:02:24 DEBUG : file1: reading active writers 2024/04/25 05:02:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:25.226367 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:25.226409 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:25 DEBUG : : Looking for writers 2024/04/25 05:02:25 DEBUG : file1: reading active writers 2024/04/25 05:02:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:26 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:26 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:26 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:26 DEBUG : : Looking for writers 2024/04/25 05:02:26 DEBUG : file1: reading active writers 2024/04/25 05:02:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:27.434262 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:27.434303 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:27 DEBUG : : Looking for writers 2024/04/25 05:02:27 DEBUG : file1: reading active writers 2024/04/25 05:02:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:28 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:28 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:28 DEBUG : : Looking for writers 2024/04/25 05:02:28 DEBUG : file1: reading active writers 2024/04/25 05:02:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:29 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:29 DEBUG : : Looking for writers 2024/04/25 05:02:29 DEBUG : file1: reading active writers 2024/04/25 05:02:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:29.948401 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:29.948430 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:30 DEBUG : : Looking for writers 2024/04/25 05:02:30 DEBUG : file1: reading active writers 2024/04/25 05:02:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:31 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:31 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:31 DEBUG : : Looking for writers 2024/04/25 05:02:31 DEBUG : file1: reading active writers 2024/04/25 05:02:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:32 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:32 DEBUG : : Looking for writers 2024/04/25 05:02:32 DEBUG : file1: reading active writers 2024/04/25 05:02:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:33.361508 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:33.361539 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:33 DEBUG : : Looking for writers 2024/04/25 05:02:33 DEBUG : file1: reading active writers 2024/04/25 05:02:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:34 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:34 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:34 DEBUG : : Looking for writers 2024/04/25 05:02:34 DEBUG : file1: reading active writers 2024/04/25 05:02:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:35 DEBUG : : Looking for writers 2024/04/25 05:02:35 DEBUG : file1: reading active writers 2024/04/25 05:02:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:36 DEBUG : : Looking for writers 2024/04/25 05:02:36 DEBUG : file1: reading active writers 2024/04/25 05:02:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:37 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:37 DEBUG : : Looking for writers 2024/04/25 05:02:37 DEBUG : file1: reading active writers 2024/04/25 05:02:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:38.466945 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:38.466985 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:38 DEBUG : : Looking for writers 2024/04/25 05:02:38 DEBUG : file1: reading active writers 2024/04/25 05:02:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:39 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:39 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:39 DEBUG : : Looking for writers 2024/04/25 05:02:39 DEBUG : file1: reading active writers 2024/04/25 05:02:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:40 DEBUG : : Looking for writers 2024/04/25 05:02:40 DEBUG : file1: reading active writers 2024/04/25 05:02:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:41 DEBUG : : Looking for writers 2024/04/25 05:02:41 DEBUG : file1: reading active writers 2024/04/25 05:02:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:42 DEBUG : : Looking for writers 2024/04/25 05:02:42 DEBUG : file1: reading active writers 2024/04/25 05:02:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:43 DEBUG : : Looking for writers 2024/04/25 05:02:43 DEBUG : file1: reading active writers 2024/04/25 05:02:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:44 DEBUG : : Looking for writers 2024/04/25 05:02:44 DEBUG : file1: reading active writers 2024/04/25 05:02:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:45 DEBUG : : Looking for writers 2024/04/25 05:02:45 DEBUG : file1: reading active writers 2024/04/25 05:02:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:45 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:02:46.675856 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:02:46.675890 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:02:46 DEBUG : : Looking for writers 2024/04/25 05:02:46 DEBUG : file1: reading active writers 2024/04/25 05:02:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:47 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:47 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:02:47 DEBUG : : Looking for writers 2024/04/25 05:02:47 DEBUG : file1: reading active writers 2024/04/25 05:02:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:48 DEBUG : : Looking for writers 2024/04/25 05:02:48 DEBUG : file1: reading active writers 2024/04/25 05:02:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:49 DEBUG : : Looking for writers 2024/04/25 05:02:49 DEBUG : file1: reading active writers 2024/04/25 05:02:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:50 DEBUG : : Looking for writers 2024/04/25 05:02:50 DEBUG : file1: reading active writers 2024/04/25 05:02:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:51 DEBUG : : Looking for writers 2024/04/25 05:02:51 DEBUG : file1: reading active writers 2024/04/25 05:02:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:02:52 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc002192000 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc00218c308 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824668898112} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13943873249093764250 ext:233721229342 loc:0x3a135e0} ATime:{wall:13943873249093801550 ext:233721266652 loc:0x3a135e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2024/04/25 05:02:52 DEBUG : >WaitForWriters: fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/04/25 05:03:00 DEBUG : file1: vfs cache: starting upload fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 2024/04/25 05:03:08.767460 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:03:08.767503 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:03:09 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:03:09 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft fstest.go:295: Flushing the directory cache 2024/04/25 05:03:22 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2024/04/25 05:03:22 INFO : vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:387 Error: Should be true Test: TestRWFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:197: Not found "file1" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:387 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleWriteAt Messages: 1 objects not found 2024/04/25 05:03:28 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:03:28 DEBUG : : Looking for writers 2024/04/25 05:03:28 DEBUG : file1: reading active writers 2024/04/25 05:03:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2024/04/25 05:03:28 DEBUG : : Looking for writers 2024/04/25 05:03:28 DEBUG : file1: reading active writers 2024/04/25 05:03:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2024/04/25 05:03:28 DEBUG : : Looking for writers 2024/04/25 05:03:28 DEBUG : file1: reading active writers 2024/04/25 05:03:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2024/04/25 05:03:28 DEBUG : : Looking for writers 2024/04/25 05:03:28 DEBUG : file1: reading active writers 2024/04/25 05:03:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2024/04/25 05:03:28 DEBUG : : Looking for writers 2024/04/25 05:03:28 DEBUG : file1: reading active writers 2024/04/25 05:03:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2024/04/25 05:03:29 DEBUG : : Looking for writers 2024/04/25 05:03:29 DEBUG : file1: reading active writers 2024/04/25 05:03:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2024/04/25 05:03:29 DEBUG : : Looking for writers 2024/04/25 05:03:29 DEBUG : file1: reading active writers 2024/04/25 05:03:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2024/04/25 05:03:30 DEBUG : : Looking for writers 2024/04/25 05:03:30 DEBUG : file1: reading active writers 2024/04/25 05:03:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:31 DEBUG : : Looking for writers 2024/04/25 05:03:31 DEBUG : file1: reading active writers 2024/04/25 05:03:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:32 DEBUG : : Looking for writers 2024/04/25 05:03:32 DEBUG : file1: reading active writers 2024/04/25 05:03:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:33 DEBUG : : Looking for writers 2024/04/25 05:03:33 DEBUG : file1: reading active writers 2024/04/25 05:03:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:34 DEBUG : : Looking for writers 2024/04/25 05:03:34 DEBUG : file1: reading active writers 2024/04/25 05:03:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:35 DEBUG : : Looking for writers 2024/04/25 05:03:35 DEBUG : file1: reading active writers 2024/04/25 05:03:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:35 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:03:36 DEBUG : : Looking for writers 2024/04/25 05:03:36 DEBUG : file1: reading active writers 2024/04/25 05:03:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:37 DEBUG : : Looking for writers 2024/04/25 05:03:37 DEBUG : file1: reading active writers 2024/04/25 05:03:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:38 DEBUG : : Looking for writers 2024/04/25 05:03:38 DEBUG : file1: reading active writers 2024/04/25 05:03:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:39 DEBUG : : Looking for writers 2024/04/25 05:03:39 DEBUG : file1: reading active writers 2024/04/25 05:03:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:40 DEBUG : : Looking for writers 2024/04/25 05:03:40 DEBUG : file1: reading active writers 2024/04/25 05:03:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:41 DEBUG : : Looking for writers 2024/04/25 05:03:41 DEBUG : file1: reading active writers 2024/04/25 05:03:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:42 DEBUG : : Looking for writers 2024/04/25 05:03:42 DEBUG : file1: reading active writers 2024/04/25 05:03:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:43 DEBUG : : Looking for writers 2024/04/25 05:03:43 DEBUG : file1: reading active writers 2024/04/25 05:03:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:44 DEBUG : : Looking for writers 2024/04/25 05:03:44 DEBUG : file1: reading active writers 2024/04/25 05:03:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:45 DEBUG : : Looking for writers 2024/04/25 05:03:45 DEBUG : file1: reading active writers 2024/04/25 05:03:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:46 DEBUG : : Looking for writers 2024/04/25 05:03:46 DEBUG : file1: reading active writers 2024/04/25 05:03:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:47 DEBUG : : Looking for writers 2024/04/25 05:03:47 DEBUG : file1: reading active writers 2024/04/25 05:03:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:48 DEBUG : : Looking for writers 2024/04/25 05:03:48 DEBUG : file1: reading active writers 2024/04/25 05:03:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:49 DEBUG : : Looking for writers 2024/04/25 05:03:49 DEBUG : file1: reading active writers 2024/04/25 05:03:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:50 DEBUG : : Looking for writers 2024/04/25 05:03:50 DEBUG : file1: reading active writers 2024/04/25 05:03:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:50.157756 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:03:50.157793 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:03:51 DEBUG : : Looking for writers 2024/04/25 05:03:51 DEBUG : file1: reading active writers 2024/04/25 05:03:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:51 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:03:51 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:03:52 DEBUG : : Looking for writers 2024/04/25 05:03:52 DEBUG : file1: reading active writers 2024/04/25 05:03:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:53 DEBUG : : Looking for writers 2024/04/25 05:03:53 DEBUG : file1: reading active writers 2024/04/25 05:03:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:54 DEBUG : : Looking for writers 2024/04/25 05:03:54 DEBUG : file1: reading active writers 2024/04/25 05:03:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:55 DEBUG : : Looking for writers 2024/04/25 05:03:55 DEBUG : file1: reading active writers 2024/04/25 05:03:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:56 DEBUG : : Looking for writers 2024/04/25 05:03:56 DEBUG : file1: reading active writers 2024/04/25 05:03:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:57 DEBUG : : Looking for writers 2024/04/25 05:03:57 DEBUG : file1: reading active writers 2024/04/25 05:03:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:58 DEBUG : : Looking for writers 2024/04/25 05:03:58 DEBUG : file1: reading active writers 2024/04/25 05:03:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:03:58 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc002192000 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc00218c308 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824668898112} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13943873249093764250 ext:233721229342 loc:0x3a135e0} ATime:{wall:13943873249093801550 ext:233721266652 loc:0x3a135e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2024/04/25 05:03:58 DEBUG : >WaitForWriters: 2024/04/25 05:03:58 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleWriteAt (97.27s) === RUN TestRWFileHandleWriteNoWrite run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:03:59 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:03:59 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:03:59 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:03:59 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:03:59 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:03:59 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:03:59 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:03:59 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:03:59 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:03:59 DEBUG : file1: newRWFileHandle: 2024/04/25 05:03:59 DEBUG : file1(0xc00055e540): openPending: 2024/04/25 05:03:59 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2024/04/25 05:03:59 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:03:59 DEBUG : file1(0xc00055e540): >openPending: err= 2024/04/25 05:03:59 DEBUG : file1: >newRWFileHandle: err= 2024/04/25 05:03:59 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:03:59 DEBUG : file1: >Open: fd=file1 (rw), err= 2024/04/25 05:03:59 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2024/04/25 05:03:59 DEBUG : file1(0xc00055e540): close: 2024/04/25 05:03:59 DEBUG : file1: vfs cache: setting modification time to 2024-04-25 05:03:59.78901345 +0000 UTC m=+331.018574168 2024/04/25 05:03:59 INFO : file1: vfs cache: queuing for upload in 100ms 2024/04/25 05:03:59 DEBUG : file1(0xc00055e540): >close: err= 2024/04/25 05:03:59 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2024/04/25 05:03:59 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2024/04/25 05:03:59 DEBUG : file2: newRWFileHandle: 2024/04/25 05:03:59 DEBUG : file2(0xc00055e640): openPending: 2024/04/25 05:03:59 DEBUG : file2: vfs cache: truncate to size=0 (not needed as size correct) 2024/04/25 05:03:59 DEBUG : : Added virtual directory entry vAddFile: "file2" 2024/04/25 05:03:59 DEBUG : file2(0xc00055e640): >openPending: err= 2024/04/25 05:03:59 DEBUG : file2: >newRWFileHandle: err= 2024/04/25 05:03:59 DEBUG : : Added virtual directory entry vAddFile: "file2" 2024/04/25 05:03:59 DEBUG : file2: >Open: fd=file2 (rw), err= 2024/04/25 05:03:59 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2024/04/25 05:03:59 DEBUG : file2(0xc00055e640): RWFileHandle.Flush 2024/04/25 05:03:59 DEBUG : file2(0xc00055e640): RWFileHandle.Release 2024/04/25 05:03:59 DEBUG : file2(0xc00055e640): close: 2024/04/25 05:03:59 DEBUG : file2: vfs cache: setting modification time to 2024-04-25 05:03:59.790238608 +0000 UTC m=+331.019799316 2024/04/25 05:03:59 INFO : file2: vfs cache: queuing for upload in 100ms 2024/04/25 05:03:59 DEBUG : file2(0xc00055e640): >close: err= 2024/04/25 05:03:59 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:03:59 DEBUG : : Looking for writers 2024/04/25 05:03:59 DEBUG : file1: reading active writers 2024/04/25 05:03:59 DEBUG : file2: reading active writers 2024/04/25 05:03:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2024/04/25 05:03:59 DEBUG : : Looking for writers 2024/04/25 05:03:59 DEBUG : file1: reading active writers 2024/04/25 05:03:59 DEBUG : file2: reading active writers 2024/04/25 05:03:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2024/04/25 05:03:59 DEBUG : : Looking for writers 2024/04/25 05:03:59 DEBUG : file1: reading active writers 2024/04/25 05:03:59 DEBUG : file2: reading active writers 2024/04/25 05:03:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2024/04/25 05:03:59 DEBUG : : Looking for writers 2024/04/25 05:03:59 DEBUG : file1: reading active writers 2024/04/25 05:03:59 DEBUG : file2: reading active writers 2024/04/25 05:03:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2024/04/25 05:03:59 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:03:59 DEBUG : file2: vfs cache: starting upload 2024/04/25 05:03:59 DEBUG : : Looking for writers 2024/04/25 05:03:59 DEBUG : file2: reading active writers 2024/04/25 05:03:59 DEBUG : file1: reading active writers 2024/04/25 05:03:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2024/04/25 05:04:00 DEBUG : : Looking for writers 2024/04/25 05:04:00 DEBUG : file1: reading active writers 2024/04/25 05:04:00 DEBUG : file2: reading active writers 2024/04/25 05:04:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2024/04/25 05:04:00 DEBUG : : Looking for writers 2024/04/25 05:04:00 DEBUG : file2: reading active writers 2024/04/25 05:04:00 DEBUG : file1: reading active writers 2024/04/25 05:04:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2024/04/25 05:04:00.549391 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:00.549415 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:00 DEBUG : file2: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/04/25 05:04:00 INFO : file2: Copied (new) 2024/04/25 05:04:00 DEBUG : file2: vfs cache: fingerprint now "0,2024-04-25 05:03:59.790238608 +0000 UTC,da39a3ee5e6b4b0d3255bfef95601890afd80709" 2024/04/25 05:04:00 DEBUG : file2: vfs cache: writeback object to VFS layer 2024/04/25 05:04:00 DEBUG : : Added virtual directory entry vAddFile: "file2" 2024/04/25 05:04:00 INFO : file2: vfs cache: upload succeeded try #1 2024/04/25 05:04:01 DEBUG : : Looking for writers 2024/04/25 05:04:01 DEBUG : file1: reading active writers 2024/04/25 05:04:01 DEBUG : file2: reading active writers 2024/04/25 05:04:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:01 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:01 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:01 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:02 DEBUG : : Looking for writers 2024/04/25 05:04:02 DEBUG : file2: reading active writers 2024/04/25 05:04:02 DEBUG : file1: reading active writers 2024/04/25 05:04:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:02.462017 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:02.462050 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:03 DEBUG : : Looking for writers 2024/04/25 05:04:03 DEBUG : file1: reading active writers 2024/04/25 05:04:03 DEBUG : file2: reading active writers 2024/04/25 05:04:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:03 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:03 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:03 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:04 DEBUG : : Looking for writers 2024/04/25 05:04:04 DEBUG : file1: reading active writers 2024/04/25 05:04:04 DEBUG : file2: reading active writers 2024/04/25 05:04:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:04.876793 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:04.876831 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:05 DEBUG : : Looking for writers 2024/04/25 05:04:05 DEBUG : file1: reading active writers 2024/04/25 05:04:05 DEBUG : file2: reading active writers 2024/04/25 05:04:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:06 DEBUG : : Looking for writers 2024/04/25 05:04:06 DEBUG : file1: reading active writers 2024/04/25 05:04:06 DEBUG : file2: reading active writers 2024/04/25 05:04:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:06 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:06 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:06 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:07 DEBUG : : Looking for writers 2024/04/25 05:04:07 DEBUG : file1: reading active writers 2024/04/25 05:04:07 DEBUG : file2: reading active writers 2024/04/25 05:04:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:07.949186 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:07.949209 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:08 DEBUG : : Looking for writers 2024/04/25 05:04:08 DEBUG : file1: reading active writers 2024/04/25 05:04:08 DEBUG : file2: reading active writers 2024/04/25 05:04:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:09 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:09 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:09 DEBUG : : Looking for writers 2024/04/25 05:04:09 DEBUG : file1: reading active writers 2024/04/25 05:04:09 DEBUG : file2: reading active writers 2024/04/25 05:04:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:10 DEBUG : : Looking for writers 2024/04/25 05:04:10 DEBUG : file1: reading active writers 2024/04/25 05:04:10 DEBUG : file2: reading active writers 2024/04/25 05:04:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:10 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:11 DEBUG : : Looking for writers 2024/04/25 05:04:11 DEBUG : file1: reading active writers 2024/04/25 05:04:11 DEBUG : file2: reading active writers 2024/04/25 05:04:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:11.354781 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:11.354812 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:12 DEBUG : : Looking for writers 2024/04/25 05:04:12 DEBUG : file1: reading active writers 2024/04/25 05:04:12 DEBUG : file2: reading active writers 2024/04/25 05:04:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:12 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:12 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:13 DEBUG : : Looking for writers 2024/04/25 05:04:13 DEBUG : file1: reading active writers 2024/04/25 05:04:13 DEBUG : file2: reading active writers 2024/04/25 05:04:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:14 DEBUG : : Looking for writers 2024/04/25 05:04:14 DEBUG : file1: reading active writers 2024/04/25 05:04:14 DEBUG : file2: reading active writers 2024/04/25 05:04:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:15 DEBUG : : Looking for writers 2024/04/25 05:04:15 DEBUG : file1: reading active writers 2024/04/25 05:04:15 DEBUG : file2: reading active writers 2024/04/25 05:04:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:15 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:16 DEBUG : : Looking for writers 2024/04/25 05:04:16 DEBUG : file1: reading active writers 2024/04/25 05:04:16 DEBUG : file2: reading active writers 2024/04/25 05:04:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:16.379054 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:16.379086 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:17 DEBUG : : Looking for writers 2024/04/25 05:04:17 DEBUG : file1: reading active writers 2024/04/25 05:04:17 DEBUG : file2: reading active writers 2024/04/25 05:04:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:17 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:17 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:18 DEBUG : : Looking for writers 2024/04/25 05:04:18 DEBUG : file1: reading active writers 2024/04/25 05:04:18 DEBUG : file2: reading active writers 2024/04/25 05:04:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:19 DEBUG : : Looking for writers 2024/04/25 05:04:19 DEBUG : file1: reading active writers 2024/04/25 05:04:19 DEBUG : file2: reading active writers 2024/04/25 05:04:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:20 DEBUG : : Looking for writers 2024/04/25 05:04:20 DEBUG : file1: reading active writers 2024/04/25 05:04:20 DEBUG : file2: reading active writers 2024/04/25 05:04:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:21 DEBUG : : Looking for writers 2024/04/25 05:04:21 DEBUG : file1: reading active writers 2024/04/25 05:04:21 DEBUG : file2: reading active writers 2024/04/25 05:04:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:22 DEBUG : : Looking for writers 2024/04/25 05:04:22 DEBUG : file1: reading active writers 2024/04/25 05:04:22 DEBUG : file2: reading active writers 2024/04/25 05:04:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:23 DEBUG : : Looking for writers 2024/04/25 05:04:23 DEBUG : file1: reading active writers 2024/04/25 05:04:23 DEBUG : file2: reading active writers 2024/04/25 05:04:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:23 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:24 DEBUG : : Looking for writers 2024/04/25 05:04:24 DEBUG : file1: reading active writers 2024/04/25 05:04:24 DEBUG : file2: reading active writers 2024/04/25 05:04:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:24.494463 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:24.494498 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:04:25 DEBUG : : Looking for writers 2024/04/25 05:04:25 DEBUG : file1: reading active writers 2024/04/25 05:04:25 DEBUG : file2: reading active writers 2024/04/25 05:04:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:25 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:25 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:26 DEBUG : : Looking for writers 2024/04/25 05:04:26 DEBUG : file1: reading active writers 2024/04/25 05:04:26 DEBUG : file2: reading active writers 2024/04/25 05:04:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:27 DEBUG : : Looking for writers 2024/04/25 05:04:27 DEBUG : file2: reading active writers 2024/04/25 05:04:27 DEBUG : file1: reading active writers 2024/04/25 05:04:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:28 DEBUG : : Looking for writers 2024/04/25 05:04:28 DEBUG : file1: reading active writers 2024/04/25 05:04:28 DEBUG : file2: reading active writers 2024/04/25 05:04:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:29 DEBUG : : Looking for writers 2024/04/25 05:04:29 DEBUG : file1: reading active writers 2024/04/25 05:04:29 DEBUG : file2: reading active writers 2024/04/25 05:04:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:04:29 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc0021920f0 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc0001d9508 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824635659584} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13943873353544065994 ext:331018574168 loc:0x3a135e0} ATime:{wall:13943873353544286067 ext:331018794231 loc:0x3a135e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, "file2": &{c:0xc0021920f0 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc0001d9608 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824635659840} name:file2 opens:0 downloaders: o:0xc000c281e0 fd: info:{ModTime:{wall:13943873353545291152 ext:331019799316 loc:0x3a135e0} ATime:{wall:13943873353545534457 ext:331020042632 loc:0x3a135e0} Size:0 Rs:[] Fingerprint:0,2024-04-25 05:03:59.790238608 +0000 UTC,da39a3ee5e6b4b0d3255bfef95601890afd80709 Dirty:false} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, } 2024/04/25 05:04:29 DEBUG : >WaitForWriters: fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/04/25 05:04:38 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:04:46.391709 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:04:46.391736 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 2024/04/25 05:04:47 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:04:47 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft fstest.go:295: Flushing the directory cache 2024/04/25 05:04:59 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2024/04/25 05:04:59 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file2 not removed, freed 0 bytes 2024/04/25 05:04:59 INFO : vfs cache: cleaned: objects 2 (was 2) in use 1, to upload 1, uploading 0, total size 0 (was 0) fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:420 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: listing wrong, want file1 (0), file2 (0) got file2 (0) fstest.go:197: Not found "file1" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:420 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleWriteNoWrite Messages: 1 objects not found 2024/04/25 05:05:07 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2024/04/25 05:05:07 DEBUG : : Looking for writers 2024/04/25 05:05:07 DEBUG : file1: reading active writers 2024/04/25 05:05:07 DEBUG : file2: reading active writers 2024/04/25 05:05:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2024/04/25 05:05:08 DEBUG : : Looking for writers 2024/04/25 05:05:08 DEBUG : file1: reading active writers 2024/04/25 05:05:08 DEBUG : file2: reading active writers 2024/04/25 05:05:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:09 DEBUG : : Looking for writers 2024/04/25 05:05:09 DEBUG : file1: reading active writers 2024/04/25 05:05:09 DEBUG : file2: reading active writers 2024/04/25 05:05:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:10 DEBUG : : Looking for writers 2024/04/25 05:05:10 DEBUG : file1: reading active writers 2024/04/25 05:05:10 DEBUG : file2: reading active writers 2024/04/25 05:05:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:11 DEBUG : : Looking for writers 2024/04/25 05:05:11 DEBUG : file1: reading active writers 2024/04/25 05:05:11 DEBUG : file2: reading active writers 2024/04/25 05:05:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:12 DEBUG : : Looking for writers 2024/04/25 05:05:12 DEBUG : file2: reading active writers 2024/04/25 05:05:12 DEBUG : file1: reading active writers 2024/04/25 05:05:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:13 DEBUG : file1: vfs cache: starting upload 2024/04/25 05:05:13 DEBUG : : Looking for writers 2024/04/25 05:05:13 DEBUG : file2: reading active writers 2024/04/25 05:05:13 DEBUG : file1: reading active writers 2024/04/25 05:05:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:14 DEBUG : : Looking for writers 2024/04/25 05:05:14 DEBUG : file1: reading active writers 2024/04/25 05:05:14 DEBUG : file2: reading active writers 2024/04/25 05:05:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:15 DEBUG : : Looking for writers 2024/04/25 05:05:15 DEBUG : file1: reading active writers 2024/04/25 05:05:15 DEBUG : file2: reading active writers 2024/04/25 05:05:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:16 DEBUG : : Looking for writers 2024/04/25 05:05:16 DEBUG : file1: reading active writers 2024/04/25 05:05:16 DEBUG : file2: reading active writers 2024/04/25 05:05:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:17 DEBUG : : Looking for writers 2024/04/25 05:05:17 DEBUG : file1: reading active writers 2024/04/25 05:05:17 DEBUG : file2: reading active writers 2024/04/25 05:05:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:18 DEBUG : : Looking for writers 2024/04/25 05:05:18 DEBUG : file1: reading active writers 2024/04/25 05:05:18 DEBUG : file2: reading active writers 2024/04/25 05:05:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:19 DEBUG : : Looking for writers 2024/04/25 05:05:19 DEBUG : file1: reading active writers 2024/04/25 05:05:19 DEBUG : file2: reading active writers 2024/04/25 05:05:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:20 DEBUG : : Looking for writers 2024/04/25 05:05:20 DEBUG : file1: reading active writers 2024/04/25 05:05:20 DEBUG : file2: reading active writers 2024/04/25 05:05:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:21 DEBUG : : Looking for writers 2024/04/25 05:05:21 DEBUG : file1: reading active writers 2024/04/25 05:05:21 DEBUG : file2: reading active writers 2024/04/25 05:05:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:22 DEBUG : : Looking for writers 2024/04/25 05:05:22 DEBUG : file1: reading active writers 2024/04/25 05:05:22 DEBUG : file2: reading active writers 2024/04/25 05:05:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:23 DEBUG : : Looking for writers 2024/04/25 05:05:23 DEBUG : file2: reading active writers 2024/04/25 05:05:23 DEBUG : file1: reading active writers 2024/04/25 05:05:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:24 DEBUG : : Looking for writers 2024/04/25 05:05:24 DEBUG : file1: reading active writers 2024/04/25 05:05:24 DEBUG : file2: reading active writers 2024/04/25 05:05:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:25 DEBUG : : Looking for writers 2024/04/25 05:05:25 DEBUG : file1: reading active writers 2024/04/25 05:05:25 DEBUG : file2: reading active writers 2024/04/25 05:05:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:26 DEBUG : : Looking for writers 2024/04/25 05:05:26 DEBUG : file1: reading active writers 2024/04/25 05:05:26 DEBUG : file2: reading active writers 2024/04/25 05:05:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:27 DEBUG : : Looking for writers 2024/04/25 05:05:27 DEBUG : file1: reading active writers 2024/04/25 05:05:27 DEBUG : file2: reading active writers 2024/04/25 05:05:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:27.659975 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:05:27.660004 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:05:28 DEBUG : : Looking for writers 2024/04/25 05:05:28 DEBUG : file1: reading active writers 2024/04/25 05:05:28 DEBUG : file2: reading active writers 2024/04/25 05:05:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:28 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:05:28 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:05:29 DEBUG : : Looking for writers 2024/04/25 05:05:29 DEBUG : file1: reading active writers 2024/04/25 05:05:29 DEBUG : file2: reading active writers 2024/04/25 05:05:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:30 DEBUG : : Looking for writers 2024/04/25 05:05:30 DEBUG : file1: reading active writers 2024/04/25 05:05:30 DEBUG : file2: reading active writers 2024/04/25 05:05:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:31 DEBUG : : Looking for writers 2024/04/25 05:05:31 DEBUG : file1: reading active writers 2024/04/25 05:05:31 DEBUG : file2: reading active writers 2024/04/25 05:05:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:32 DEBUG : : Looking for writers 2024/04/25 05:05:32 DEBUG : file1: reading active writers 2024/04/25 05:05:32 DEBUG : file2: reading active writers 2024/04/25 05:05:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:33 DEBUG : : Looking for writers 2024/04/25 05:05:33 DEBUG : file1: reading active writers 2024/04/25 05:05:33 DEBUG : file2: reading active writers 2024/04/25 05:05:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:34 DEBUG : : Looking for writers 2024/04/25 05:05:34 DEBUG : file1: reading active writers 2024/04/25 05:05:34 DEBUG : file2: reading active writers 2024/04/25 05:05:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:35 DEBUG : : Looking for writers 2024/04/25 05:05:35 DEBUG : file1: reading active writers 2024/04/25 05:05:35 DEBUG : file2: reading active writers 2024/04/25 05:05:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:36 DEBUG : : Looking for writers 2024/04/25 05:05:36 DEBUG : file1: reading active writers 2024/04/25 05:05:36 DEBUG : file2: reading active writers 2024/04/25 05:05:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:37 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file2": &{c:0xc0021920f0 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc0001d9608 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824635659840} name:file2 opens:0 downloaders: o:0xc000c281e0 fd: info:{ModTime:{wall:13943873353545291152 ext:331019799316 loc:0x3a135e0} ATime:{wall:13943873353545534457 ext:331020042632 loc:0x3a135e0} Size:0 Rs:[] Fingerprint:0,2024-04-25 05:03:59.790238608 +0000 UTC,da39a3ee5e6b4b0d3255bfef95601890afd80709 Dirty:false} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, "file1": &{c:0xc0021920f0 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc0001d9508 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824635659584} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13943873353544065994 ext:331018574168 loc:0x3a135e0} ATime:{wall:13943873353544286067 ext:331018794231 loc:0x3a135e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2024/04/25 05:05:37 DEBUG : >WaitForWriters: 2024/04/25 05:05:37 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleWriteNoWrite (99.58s) === RUN TestRWFileHandleSizeTruncateExisting run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:05:39 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:05:39 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:05:39 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:39 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:39 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:39 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:39 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:05:40.497339 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:05:40.497396 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:05:40 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:05:40 DEBUG : : Looking for writers 2024/04/25 05:05:40 DEBUG : >WaitForWriters: 2024/04/25 05:05:40 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleSizeTruncateExisting (2.99s) === RUN TestRWFileHandleSizeCreateExisting run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:05:42 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:05:42 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:05:42 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:42 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:42 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:42 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:42 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:05:43.500701 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:05:43.500745 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:05:43 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:05:43 DEBUG : : Looking for writers 2024/04/25 05:05:43 DEBUG : >WaitForWriters: 2024/04/25 05:05:43 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileHandleSizeCreateExisting (2.89s) === RUN TestRWFileModTimeWithOpenWriters run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:05:44 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:05:44 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:05:44 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:44 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:44 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:44 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:05:44 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:05:44 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:05:45 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:05:45 DEBUG : file1: newRWFileHandle: 2024/04/25 05:05:45 DEBUG : file1(0xc00055e580): openPending: 2024/04/25 05:05:45 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2024/04/25 05:05:45 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:05:45 DEBUG : file1(0xc00055e580): >openPending: err= 2024/04/25 05:05:45 DEBUG : file1: >newRWFileHandle: err= 2024/04/25 05:05:45 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:05:45 DEBUG : file1: >Open: fd=file1 (rw), err= 2024/04/25 05:05:45 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2024/04/25 05:05:45.931995 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:05:45.932025 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "time_test" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:05:45 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:05:45 DEBUG : : Looking for writers 2024/04/25 05:05:45 DEBUG : file1: reading active writers 2024/04/25 05:05:45 DEBUG : file1: active writers 1 2024/04/25 05:05:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms 2024/04/25 05:05:45 DEBUG : : Looking for writers 2024/04/25 05:05:45 DEBUG : file1: reading active writers 2024/04/25 05:05:45 DEBUG : file1: active writers 1 2024/04/25 05:05:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms 2024/04/25 05:05:45 DEBUG : : Looking for writers 2024/04/25 05:05:45 DEBUG : file1: reading active writers 2024/04/25 05:05:45 DEBUG : file1: active writers 1 2024/04/25 05:05:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms 2024/04/25 05:05:46 DEBUG : : Looking for writers 2024/04/25 05:05:46 DEBUG : file1: reading active writers 2024/04/25 05:05:46 DEBUG : file1: active writers 1 2024/04/25 05:05:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms 2024/04/25 05:05:46 DEBUG : : Looking for writers 2024/04/25 05:05:46 DEBUG : file1: reading active writers 2024/04/25 05:05:46 DEBUG : file1: active writers 1 2024/04/25 05:05:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms 2024/04/25 05:05:46 DEBUG : : Looking for writers 2024/04/25 05:05:46 DEBUG : file1: reading active writers 2024/04/25 05:05:46 DEBUG : file1: active writers 1 2024/04/25 05:05:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms 2024/04/25 05:05:46 DEBUG : : Looking for writers 2024/04/25 05:05:46 DEBUG : file1: reading active writers 2024/04/25 05:05:46 DEBUG : file1: active writers 1 2024/04/25 05:05:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms 2024/04/25 05:05:47 DEBUG : : Looking for writers 2024/04/25 05:05:47 DEBUG : file1: reading active writers 2024/04/25 05:05:47 DEBUG : file1: active writers 1 2024/04/25 05:05:47 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:48 DEBUG : : Looking for writers 2024/04/25 05:05:48 DEBUG : file1: reading active writers 2024/04/25 05:05:48 DEBUG : file1: active writers 1 2024/04/25 05:05:48 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:49 DEBUG : : Looking for writers 2024/04/25 05:05:49 DEBUG : file1: reading active writers 2024/04/25 05:05:49 DEBUG : file1: active writers 1 2024/04/25 05:05:49 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:50 DEBUG : : Looking for writers 2024/04/25 05:05:50 DEBUG : file1: reading active writers 2024/04/25 05:05:50 DEBUG : file1: active writers 1 2024/04/25 05:05:50 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:51 DEBUG : : Looking for writers 2024/04/25 05:05:51 DEBUG : file1: reading active writers 2024/04/25 05:05:51 DEBUG : file1: active writers 1 2024/04/25 05:05:51 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:52 DEBUG : : Looking for writers 2024/04/25 05:05:52 DEBUG : file1: reading active writers 2024/04/25 05:05:52 DEBUG : file1: active writers 1 2024/04/25 05:05:52 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:53 DEBUG : : Looking for writers 2024/04/25 05:05:53 DEBUG : file1: reading active writers 2024/04/25 05:05:53 DEBUG : file1: active writers 1 2024/04/25 05:05:53 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:54 DEBUG : : Looking for writers 2024/04/25 05:05:54 DEBUG : file1: reading active writers 2024/04/25 05:05:54 DEBUG : file1: active writers 1 2024/04/25 05:05:54 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:55 DEBUG : : Looking for writers 2024/04/25 05:05:55 DEBUG : file1: reading active writers 2024/04/25 05:05:55 DEBUG : file1: active writers 1 2024/04/25 05:05:55 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:56 DEBUG : : Looking for writers 2024/04/25 05:05:56 DEBUG : file1: reading active writers 2024/04/25 05:05:56 DEBUG : file1: active writers 1 2024/04/25 05:05:56 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:57 DEBUG : : Looking for writers 2024/04/25 05:05:57 DEBUG : file1: reading active writers 2024/04/25 05:05:57 DEBUG : file1: active writers 1 2024/04/25 05:05:57 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:58 DEBUG : : Looking for writers 2024/04/25 05:05:58 DEBUG : file1: reading active writers 2024/04/25 05:05:58 DEBUG : file1: active writers 1 2024/04/25 05:05:58 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:05:59 DEBUG : : Looking for writers 2024/04/25 05:05:59 DEBUG : file1: reading active writers 2024/04/25 05:05:59 DEBUG : file1: active writers 1 2024/04/25 05:05:59 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:00 DEBUG : : Looking for writers 2024/04/25 05:06:00 DEBUG : file1: reading active writers 2024/04/25 05:06:00 DEBUG : file1: active writers 1 2024/04/25 05:06:00 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:01 DEBUG : : Looking for writers 2024/04/25 05:06:01 DEBUG : file1: reading active writers 2024/04/25 05:06:01 DEBUG : file1: active writers 1 2024/04/25 05:06:01 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:02 DEBUG : : Looking for writers 2024/04/25 05:06:02 DEBUG : file1: reading active writers 2024/04/25 05:06:02 DEBUG : file1: active writers 1 2024/04/25 05:06:02 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:03 DEBUG : : Looking for writers 2024/04/25 05:06:03 DEBUG : file1: reading active writers 2024/04/25 05:06:03 DEBUG : file1: active writers 1 2024/04/25 05:06:03 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:04 DEBUG : : Looking for writers 2024/04/25 05:06:04 DEBUG : file1: reading active writers 2024/04/25 05:06:04 DEBUG : file1: active writers 1 2024/04/25 05:06:04 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:05 DEBUG : : Looking for writers 2024/04/25 05:06:05 DEBUG : file1: reading active writers 2024/04/25 05:06:05 DEBUG : file1: active writers 1 2024/04/25 05:06:05 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:06 DEBUG : : Looking for writers 2024/04/25 05:06:06 DEBUG : file1: reading active writers 2024/04/25 05:06:06 DEBUG : file1: active writers 1 2024/04/25 05:06:06 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:07 DEBUG : : Looking for writers 2024/04/25 05:06:07 DEBUG : file1: reading active writers 2024/04/25 05:06:07 DEBUG : file1: active writers 1 2024/04/25 05:06:07 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:08 DEBUG : : Looking for writers 2024/04/25 05:06:08 DEBUG : file1: reading active writers 2024/04/25 05:06:08 DEBUG : file1: active writers 1 2024/04/25 05:06:08 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:09 DEBUG : : Looking for writers 2024/04/25 05:06:09 DEBUG : file1: reading active writers 2024/04/25 05:06:09 DEBUG : file1: active writers 1 2024/04/25 05:06:09 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:10 DEBUG : : Looking for writers 2024/04/25 05:06:10 DEBUG : file1: reading active writers 2024/04/25 05:06:10 DEBUG : file1: active writers 1 2024/04/25 05:06:10 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:11 DEBUG : : Looking for writers 2024/04/25 05:06:11 DEBUG : file1: reading active writers 2024/04/25 05:06:11 DEBUG : file1: active writers 1 2024/04/25 05:06:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:12 DEBUG : : Looking for writers 2024/04/25 05:06:12 DEBUG : file1: reading active writers 2024/04/25 05:06:12 DEBUG : file1: active writers 1 2024/04/25 05:06:12 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:13 DEBUG : : Looking for writers 2024/04/25 05:06:13 DEBUG : file1: reading active writers 2024/04/25 05:06:13 DEBUG : file1: active writers 1 2024/04/25 05:06:13 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:14 DEBUG : : Looking for writers 2024/04/25 05:06:14 DEBUG : file1: reading active writers 2024/04/25 05:06:14 DEBUG : file1: active writers 1 2024/04/25 05:06:14 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:15 DEBUG : : Looking for writers 2024/04/25 05:06:15 DEBUG : file1: reading active writers 2024/04/25 05:06:15 DEBUG : file1: active writers 1 2024/04/25 05:06:15 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2024/04/25 05:06:15 ERROR : Exiting even though 1 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc00094e960 mu:{state:0 sema:0} cond:{noCopy:{} L:0xc000c5d408 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824646685760} name:file1 opens:1 downloaders: o: fd:0xc0005621f0 info:{ModTime:{wall:13943873466850403012 ext:436508277801 loc:0x3a135e0} ATime:{wall:13943873466850403012 ext:436508277801 loc:0x3a135e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:0 pendingAccesses:0 modified:true beingReset:false}, } 2024/04/25 05:06:15 DEBUG : >WaitForWriters: 2024/04/25 05:06:15 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWFileModTimeWithOpenWriters (31.62s) === RUN TestRWCacheUpdate run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:16 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:06:16 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2024/04/25 05:06:16 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:06:16 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:06:16 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:06:16 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestProtonDrive/rclone-test-yuxacep5mucufuv5fabafim6" 2024/04/25 05:06:16 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2024/04/25 05:06:16 DEBUG : : forgetting directory cache 2024/04/25 05:06:17.262342 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:06:17.262381 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "TestRWCacheUpdate" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:06:17 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:06:17 DEBUG : : Looking for writers 2024/04/25 05:06:17 DEBUG : >WaitForWriters: 2024/04/25 05:06:17 DEBUG : vfs cache: cleaner exiting --- FAIL: TestRWCacheUpdate (1.30s) === RUN TestCaseSensitivity run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:18.465219 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:06:18.465250 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "FiLeA" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) --- FAIL: TestCaseSensitivity (1.28s) === RUN TestUnicodeNormalization run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:19.724781 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:06:19.724813 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "normal name with no special characters.txt" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) --- FAIL: TestUnicodeNormalization (1.27s) === RUN TestVFSStat run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:20 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:06:20 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:06:21.095992 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:06:21.096165 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) run.go:285: Failed to put "file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:06:22 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:06:22 DEBUG : : Looking for writers 2024/04/25 05:06:22 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (2.51s) === RUN TestVFSStatParent run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:22 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:06:22 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:06:23.616123 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:06:23.616158 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) run.go:285: Failed to put "file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:06:24 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:06:24 DEBUG : : Looking for writers 2024/04/25 05:06:24 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (2.29s) === RUN TestVFSOpenFile run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:25 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:06:25 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:06:25.959447 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:06:25.959468 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) run.go:285: Failed to put "file1" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:06:27 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:06:27 DEBUG : : Looking for writers 2024/04/25 05:06:27 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (2.43s) === RUN TestVFSRename run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:27 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:06:27 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:06:29.090100 WARN RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400), Attempt 1 2024/04/25 05:06:29.090132 ERROR RESTY 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) run.go:285: Failed to put "dir/file2" to "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'": 400 POST https://mail.proton.me/api/drive/blocks: You are using an outdated version of the app. Please update to upload this file’ (Code=2000, Status=400) 2024/04/25 05:06:29 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:06:29 DEBUG : : Looking for writers 2024/04/25 05:06:29 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (3.09s) === RUN TestWriteFileHandleMethods run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:06:30 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:06:30 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:06:30 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:06:31 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:06:31 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:06:31 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:06:31 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:06:31 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:06:31 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2024/04/25 05:06:31 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2024/04/25 05:06:31 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2024/04/25 05:06:31 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (5 bytes), uploading instead of streaming 2024/04/25 05:06:31.795533 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:06:31.795560 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:06:32 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:06:32 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:06:32 DEBUG : file1: Remove: 2024/04/25 05:06:32 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:06:32 DEBUG : file1: >Remove: err= write_test.go:144: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:144 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestWriteFileHandleMethods dir_test.go:247: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:247 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:153 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:157 Error: Should be true Test: TestWriteFileHandleMethods Messages: listing wrong, want file1 (5) got fstest.go:197: Not found "file1" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:157 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleMethods Messages: 1 objects not found 2024/04/25 05:07:09 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:07:09 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:07:09 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:07:09 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:07:09 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:07:09 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:07:09 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (0 bytes), uploading instead of streaming 2024/04/25 05:07:23.946597 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:07:23.946630 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:07:24 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:07:24 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:07:24 DEBUG : file1: Remove: 2024/04/25 05:07:24 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:07:24 DEBUG : file1: >Remove: err= write_test.go:163: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:163 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestWriteFileHandleMethods dir_test.go:247: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:247 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:164 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods 2024/04/25 05:07:24 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:07:24 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:07:24 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:07:24 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:07:24 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:07:24 DEBUG : : Added virtual directory entry vAddFile: "file1" write_test.go:171: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:171 Error: Not equal: expected: *errors.errorString(&errors.errorString{s:"permission denied"}) actual : () Test: TestWriteFileHandleMethods 2024/04/25 05:07:24 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:07:24 DEBUG : : Looking for writers 2024/04/25 05:07:24 DEBUG : file1: reading active writers 2024/04/25 05:07:24 DEBUG : file1: active writers 1 2024/04/25 05:07:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2024/04/25 05:07:24 DEBUG : : Looking for writers 2024/04/25 05:07:24 DEBUG : file1: reading active writers 2024/04/25 05:07:24 DEBUG : file1: active writers 1 2024/04/25 05:07:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2024/04/25 05:07:24 DEBUG : : Looking for writers 2024/04/25 05:07:24 DEBUG : file1: reading active writers 2024/04/25 05:07:24 DEBUG : file1: active writers 1 2024/04/25 05:07:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2024/04/25 05:07:25 DEBUG : : Looking for writers 2024/04/25 05:07:25 DEBUG : file1: reading active writers 2024/04/25 05:07:25 DEBUG : file1: active writers 1 2024/04/25 05:07:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2024/04/25 05:07:25 DEBUG : : Looking for writers 2024/04/25 05:07:25 DEBUG : file1: reading active writers 2024/04/25 05:07:25 DEBUG : file1: active writers 1 2024/04/25 05:07:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2024/04/25 05:07:25 DEBUG : : Looking for writers 2024/04/25 05:07:25 DEBUG : file1: reading active writers 2024/04/25 05:07:25 DEBUG : file1: active writers 1 2024/04/25 05:07:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2024/04/25 05:07:25 DEBUG : : Looking for writers 2024/04/25 05:07:25 DEBUG : file1: reading active writers 2024/04/25 05:07:25 DEBUG : file1: active writers 1 2024/04/25 05:07:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2024/04/25 05:07:26 DEBUG : : Looking for writers 2024/04/25 05:07:26 DEBUG : file1: reading active writers 2024/04/25 05:07:26 DEBUG : file1: active writers 1 2024/04/25 05:07:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:27 DEBUG : : Looking for writers 2024/04/25 05:07:27 DEBUG : file1: reading active writers 2024/04/25 05:07:27 DEBUG : file1: active writers 1 2024/04/25 05:07:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:28 DEBUG : : Looking for writers 2024/04/25 05:07:28 DEBUG : file1: reading active writers 2024/04/25 05:07:28 DEBUG : file1: active writers 1 2024/04/25 05:07:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:29 DEBUG : : Looking for writers 2024/04/25 05:07:29 DEBUG : file1: reading active writers 2024/04/25 05:07:29 DEBUG : file1: active writers 1 2024/04/25 05:07:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:30 DEBUG : : Looking for writers 2024/04/25 05:07:30 DEBUG : file1: reading active writers 2024/04/25 05:07:30 DEBUG : file1: active writers 1 2024/04/25 05:07:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:31 DEBUG : : Looking for writers 2024/04/25 05:07:31 DEBUG : file1: reading active writers 2024/04/25 05:07:31 DEBUG : file1: active writers 1 2024/04/25 05:07:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:32 DEBUG : : Looking for writers 2024/04/25 05:07:32 DEBUG : file1: reading active writers 2024/04/25 05:07:32 DEBUG : file1: active writers 1 2024/04/25 05:07:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:33 DEBUG : : Looking for writers 2024/04/25 05:07:33 DEBUG : file1: reading active writers 2024/04/25 05:07:33 DEBUG : file1: active writers 1 2024/04/25 05:07:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:34 DEBUG : : Looking for writers 2024/04/25 05:07:34 DEBUG : file1: reading active writers 2024/04/25 05:07:34 DEBUG : file1: active writers 1 2024/04/25 05:07:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:35 DEBUG : : Looking for writers 2024/04/25 05:07:35 DEBUG : file1: reading active writers 2024/04/25 05:07:35 DEBUG : file1: active writers 1 2024/04/25 05:07:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:36 DEBUG : : Looking for writers 2024/04/25 05:07:36 DEBUG : file1: reading active writers 2024/04/25 05:07:36 DEBUG : file1: active writers 1 2024/04/25 05:07:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:37 DEBUG : : Looking for writers 2024/04/25 05:07:37 DEBUG : file1: reading active writers 2024/04/25 05:07:37 DEBUG : file1: active writers 1 2024/04/25 05:07:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:38 DEBUG : : Looking for writers 2024/04/25 05:07:38 DEBUG : file1: reading active writers 2024/04/25 05:07:38 DEBUG : file1: active writers 1 2024/04/25 05:07:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:39 DEBUG : : Looking for writers 2024/04/25 05:07:39 DEBUG : file1: reading active writers 2024/04/25 05:07:39 DEBUG : file1: active writers 1 2024/04/25 05:07:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:40 DEBUG : : Looking for writers 2024/04/25 05:07:40 DEBUG : file1: reading active writers 2024/04/25 05:07:40 DEBUG : file1: active writers 1 2024/04/25 05:07:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:41 DEBUG : : Looking for writers 2024/04/25 05:07:41 DEBUG : file1: reading active writers 2024/04/25 05:07:41 DEBUG : file1: active writers 1 2024/04/25 05:07:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:42 DEBUG : : Looking for writers 2024/04/25 05:07:42 DEBUG : file1: reading active writers 2024/04/25 05:07:42 DEBUG : file1: active writers 1 2024/04/25 05:07:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:43 DEBUG : : Looking for writers 2024/04/25 05:07:43 DEBUG : file1: reading active writers 2024/04/25 05:07:43 DEBUG : file1: active writers 1 2024/04/25 05:07:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:44 DEBUG : : Looking for writers 2024/04/25 05:07:44 DEBUG : file1: reading active writers 2024/04/25 05:07:44 DEBUG : file1: active writers 1 2024/04/25 05:07:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:45 DEBUG : : Looking for writers 2024/04/25 05:07:45 DEBUG : file1: reading active writers 2024/04/25 05:07:45 DEBUG : file1: active writers 1 2024/04/25 05:07:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:46 DEBUG : : Looking for writers 2024/04/25 05:07:46 DEBUG : file1: reading active writers 2024/04/25 05:07:46 DEBUG : file1: active writers 1 2024/04/25 05:07:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:47 DEBUG : : Looking for writers 2024/04/25 05:07:47 DEBUG : file1: reading active writers 2024/04/25 05:07:47 DEBUG : file1: active writers 1 2024/04/25 05:07:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:48 DEBUG : : Looking for writers 2024/04/25 05:07:48 DEBUG : file1: reading active writers 2024/04/25 05:07:48 DEBUG : file1: active writers 1 2024/04/25 05:07:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:49 DEBUG : : Looking for writers 2024/04/25 05:07:49 DEBUG : file1: reading active writers 2024/04/25 05:07:49 DEBUG : file1: active writers 1 2024/04/25 05:07:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:50 DEBUG : : Looking for writers 2024/04/25 05:07:50 DEBUG : file1: reading active writers 2024/04/25 05:07:50 DEBUG : file1: active writers 1 2024/04/25 05:07:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:51 DEBUG : : Looking for writers 2024/04/25 05:07:51 DEBUG : file1: reading active writers 2024/04/25 05:07:51 DEBUG : file1: active writers 1 2024/04/25 05:07:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:52 DEBUG : : Looking for writers 2024/04/25 05:07:52 DEBUG : file1: reading active writers 2024/04/25 05:07:52 DEBUG : file1: active writers 1 2024/04/25 05:07:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:53 DEBUG : : Looking for writers 2024/04/25 05:07:53 DEBUG : file1: reading active writers 2024/04/25 05:07:53 DEBUG : file1: active writers 1 2024/04/25 05:07:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:54 DEBUG : : Looking for writers 2024/04/25 05:07:54 DEBUG : file1: reading active writers 2024/04/25 05:07:54 DEBUG : file1: active writers 1 2024/04/25 05:07:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2024/04/25 05:07:54 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s Cache: 2024/04/25 05:07:54 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (84.92s) === RUN TestWriteFileHandleWriteAt run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:07:55 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:07:55 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:07:55 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:07:56 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:07:56 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:07:56 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:07:56 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:07:56 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:07:56 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2024/04/25 05:07:57 DEBUG : file1: aborting in-sequence write wait, off=100 2024/04/25 05:07:57 DEBUG : file1: failed to wait for in-sequence write to 100 2024/04/25 05:07:57 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2024/04/25 05:07:57 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (11 bytes), uploading instead of streaming 2024/04/25 05:07:57.707102 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:07:57.707138 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:07:58 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:07:58 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:07:58 DEBUG : file1: Remove: 2024/04/25 05:07:58 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:07:58 DEBUG : file1: >Remove: err= write_test.go:221: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:221 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestWriteFileHandleWriteAt 2024/04/25 05:07:58 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor dir_test.go:247: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:247 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:231 Error: Not equal: expected: []string{"file1,11,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=14) "file1,11,false" -} +([]string) Test: TestWriteFileHandleWriteAt fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache 2024/04/25 05:08:30 DEBUG : : forgetting directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 2024/04/25 05:08:34 DEBUG : : forgetting directory cache fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:235 Error: Should be true Test: TestWriteFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:197: Not found "file1" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:235 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleWriteAt Messages: 1 objects not found 2024/04/25 05:08:34 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:08:34 DEBUG : : Looking for writers 2024/04/25 05:08:34 DEBUG : >WaitForWriters: 2024/04/25 05:08:36 DEBUG : : forgetting directory cache 2024/04/25 05:08:39 DEBUG : : forgetting directory cache 2024/04/25 05:08:42 DEBUG : : forgetting directory cache 2024/04/25 05:08:45 DEBUG : : forgetting directory cache 2024/04/25 05:08:48 DEBUG : : forgetting directory cache --- FAIL: TestWriteFileHandleWriteAt (54.79s) === RUN TestWriteFileHandleFlush run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:08:50 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:08:50 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:08:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:08:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:08:50 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:08:50 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:08:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:08:50 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2024/04/25 05:08:50 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:08:50 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (5 bytes), uploading instead of streaming 2024/04/25 05:08:51 DEBUG : : forgetting directory cache 2024/04/25 05:08:51.982191 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:08:51.982223 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:08:53 DEBUG : : forgetting directory cache 2024/04/25 05:08:53 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:08:53 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:08:53 DEBUG : file1: Remove: 2024/04/25 05:08:53 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:08:53 DEBUG : file1: >Remove: err= 2024/04/25 05:08:53 ERROR : file1: WriteFileHandle.Flush error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft write_test.go:256: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:256 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestWriteFileHandleFlush 2024/04/25 05:08:53 DEBUG : file1: WriteFileHandle.Flush nothing to do dir_test.go:247: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:247 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:267 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleFlush 2024/04/25 05:08:53 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:08:53 DEBUG : : Looking for writers 2024/04/25 05:08:53 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (4.16s) === RUN TestWriteFileHandleRelease run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:08:54 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:08:54 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:08:54 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:08:54 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:08:54 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:08:54 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:08:54 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:08:54 DEBUG : file1: WriteFileHandle.Release closing 2024/04/25 05:08:54 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:08:54 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (0 bytes), uploading instead of streaming 2024/04/25 05:08:55.695323 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:08:55.695359 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:08:56 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:08:56 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:08:56 DEBUG : file1: Remove: 2024/04/25 05:08:56 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:08:56 DEBUG : file1: >Remove: err= 2024/04/25 05:08:56 ERROR : file1: WriteFileHandle.Release error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft write_test.go:279: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:279 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestWriteFileHandleRelease 2024/04/25 05:08:56 DEBUG : file1: WriteFileHandle.Release nothing to do 2024/04/25 05:08:56 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:08:56 DEBUG : : Looking for writers 2024/04/25 05:08:56 DEBUG : >WaitForWriters: 2024/04/25 05:08:56 DEBUG : : forgetting directory cache --- FAIL: TestWriteFileHandleRelease (3.02s) === RUN TestWriteFileModTimeWithOpenWriters run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:08:57 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:08:57 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:08:57 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:08:57 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:08:57 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:08:57 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:08:57 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:08:57 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:08:57 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (2 bytes), uploading instead of streaming 2024/04/25 05:08:58.671914 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:08:58.671959 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:08:59 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:08:59 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:08:59 DEBUG : file1: Remove: 2024/04/25 05:08:59 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:08:59 DEBUG : file1: >Remove: err= write_test.go:333: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:333 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestWriteFileModTimeWithOpenWriters 2024/04/25 05:08:59 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:08:59 DEBUG : : Looking for writers 2024/04/25 05:08:59 DEBUG : >WaitForWriters: 2024/04/25 05:08:59 DEBUG : : forgetting directory cache --- FAIL: TestWriteFileModTimeWithOpenWriters (3.01s) === RUN TestFileReadAtZeroLength run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:09:00 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:09:00 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:09:00 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:09:00 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:09:00 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:09:00 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:09:00 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:09:00 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:09:00 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (0 bytes), uploading instead of streaming 2024/04/25 05:09:01.630611 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:09:01.630638 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:09:02 DEBUG : : forgetting directory cache 2024/04/25 05:09:02 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:09:02 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:09:02 DEBUG : file1: Remove: 2024/04/25 05:09:02 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:09:02 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:380 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestFileReadAtZeroLength 2024/04/25 05:09:02 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2024/04/25 05:09:02 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:380 Error: Received unexpected error: file does not exist Test: TestFileReadAtZeroLength 2024/04/25 05:09:02 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:09:02 DEBUG : : Looking for writers 2024/04/25 05:09:02 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtZeroLength (2.93s) === RUN TestFileReadAtNonZeroLength run.go:180: Remote "proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6'", Local "Local file system at /tmp/rclone1448066485", Modify Window "1s" 2024/04/25 05:09:03 INFO : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': poll-interval is not supported by this remote 2024/04/25 05:09:03 NOTICE: proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2024/04/25 05:09:03 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2024/04/25 05:09:04 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2024/04/25 05:09:04 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:09:04 DEBUG : file1: >Open: fd=file1 (w), err= 2024/04/25 05:09:04 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2024/04/25 05:09:04 DEBUG : : Added virtual directory entry vAddFile: "file1" 2024/04/25 05:09:04 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': File to upload is small (100 bytes), uploading instead of streaming 2024/04/25 05:09:05 DEBUG : : forgetting directory cache 2024/04/25 05:09:05.641488 WARN RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422), Attempt 1 2024/04/25 05:09:05.641513 ERROR RESTY 422 POST https://mail.proton.me/api/drive/shares/gYxulUP2_XOrbAxegpHKiBy09cfvss6mjykkd2Z3ZDpMFCmoWX4bC2TTm-Gl2UwrjReC8te_lFsQyeXT74Vgfw==/files: A file or folder with that name already exists (Code=2500, Status=422) 2024/04/25 05:09:07 ERROR : file1: Failed to copy: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:09:07 ERROR : file1: WriteFileHandle.New Rcat failed: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft 2024/04/25 05:09:07 DEBUG : file1: Remove: 2024/04/25 05:09:07 DEBUG : : Added virtual directory entry vDel: "file1" 2024/04/25 05:09:07 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: a draft exist - usually this means a file is being uploaded at another client, or, there was a failed upload attempt. Can use --protondrive-replace-existing-draft=true to temporarily override the existing draft Test: TestFileReadAtNonZeroLength 2024/04/25 05:09:07 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2024/04/25 05:09:07 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: file does not exist Test: TestFileReadAtNonZeroLength 2024/04/25 05:09:07 DEBUG : WaitForWriters: timeout=30s 2024/04/25 05:09:07 DEBUG : : Looking for writers 2024/04/25 05:09:07 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (4.68s) FAIL 2024/04/25 05:09:08 DEBUG : proton drive root link ID 'rclone-test-yuxacep5mucufuv5fabafim6': Purge remote 2024/04/25 05:09:08 DEBUG : : forgetting directory cache "./vfs.test -test.v -test.timeout 1h0m0s -remote TestProtonDrive: -verbose -test.run '^(TestCaseSensitivity|TestDirCreate|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestRWCacheUpdate|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Finished ERROR in 10m39.962676102s (try 2/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestFileMethods 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 TestFileSetModTime/cache=full,open=true,write=true TestFileOpenRead TestFileOpenWrite TestFileRemove TestFileRemoveAll TestFileOpen TestFileRename/off,forceCache=false TestFileRename/minimal,forceCache=false TestFileRename/minimal,forceCache=true TestFileRename/writes,forceCache=false TestFileRename/writes,forceCache=true TestFileRename/full,forceCache=false TestReadFileHandleMethods TestReadFileHandleSeek TestReadFileHandleReadAt TestReadFileHandleFlush TestReadFileHandleRelease TestRWFileHandleMethodsRead TestRWFileHandleSeek TestRWFileHandleReadAt TestRWFileHandleFlushRead TestRWFileHandleReleaseRead TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestRWFileHandleSizeTruncateExisting TestRWFileHandleSizeCreateExisting TestRWFileModTimeWithOpenWriters TestRWCacheUpdate TestCaseSensitivity TestUnicodeNormalization TestVFSStat TestVFSStatParent TestVFSOpenFile TestVFSRename TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush TestWriteFileHandleRelease TestWriteFileModTimeWithOpenWriters TestFileReadAtZeroLength TestFileReadAtNonZeroLength]