1825957 - On Windows, a file is sometimes locked and not removable despite downloads.onChanged reporting state "complete" (after downloads.download)

Status: NEW

(WebExtensions :: General, defect, P3)

Description

[Rob Wu [:robwu]]

(while this report refers to unit tests, the underlying issue is not specific to tests and can also affect extensions in the wild)

On Windows, some of our unit tests that test the downloads API fail because the file is locked when we try to remove it. This manifests in explicit errors (complaining about the file being locked) or test timeouts (when the test interrupts due to the unexpected rejection of the downloads.removeFile call). The tests typically do the following:

• Request download via downloads.download call
• Observe download completion, when downloads.onChanged listener receives a change to state "complete"
• Delete the downloaded file, e.g. with downloads.removeFile (extension API) or internal APIs such as file.remove().

This is a long-standing problem; I documented the issue before at https://bugzilla.mozilla.org/show_bug.cgi?id=1316394#c126, and filed bug 1654819 for the root cause.

While I am filing this issue specifically because of the many test failures, this is not necessarily a logical issue with the tests themselves. Ideally, the underlying DownloadsCore should only notify about the completion of the download when the file is fully ready. And if we cannot do that, then we should at least have the ability (e.g. (test-only?) pref) to disable the part of it that causes the file to be locked or re-created (e.g. bug 1654819).

List of bugs with log samples

bug 1695612 - mochitest/test_chrome_ext_downloads_saveAs.html
(no bug, but skip-if references the same bug) - mochitest/test_chrome_ext_downloads_uniquify.html

no recent log files due to disabled tests, but see bug 1316394 and bug 1695612

bug 1760117 - xpcshell/test_ext_downloads_download.js

TEST-UNEXPECTED-FAIL | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_downloads_download.js | test_download_http_details - [test_download_http_details : 48] Leftover file C:\\Users\\task_1676479925\\AppData\\Local\\Temp\\xpc-profile-l_nu4owi\\temp\\downloads\\test-404 in download directory - false == true

bug 1760118 - xpcshell/test_ext_downloads_cookieStoreId.js

NS_ERROR_FILE_DIR_NOT_EMPTY: Component returned failure code: 0x80520014 (NS_ERROR_FILE_DIR_NOT_EMPTY) [nsIFile.remove]
setup/<@C:/Users/task_167942923863796/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_downloads_cookieStoreId.js:438:17
...
Error: Found unexpected files in temporary directory: downloads at resource://testing-common/AddonTestUtils.jsm:339

bug 1781294 - xpcshell/test_ext_downloads_cookies.js

NS_ERROR_FILE_DIR_NOT_EMPTY: Component returned failure code: 0x80520014 (NS_ERROR_FILE_DIR_NOT_EMPTY) [nsIFile.remove]
setup/<@Z:/task_1676114458/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_downloads_cookies.js:109:17
...
Error: Found unexpected files in temporary directory: downloads at resource://testing-common/AddonTestUtils.jsm:339

bug 1825955 - xpcshell/test_ext_dnr_download.js

(part of log file from https://bugzilla.mozilla.org/show_bug.cgi?id=1825955#c2)
"Download completed, removing file..."
"CONSOLE_MESSAGE: (error) [JavaScript Error: "Win error 32 during operation remove on file C:\Users\task_168037122166137\AppData\Local\Temp\xpc-profile-2hwh7_r6\temp\downloadDirForDnrDownloadTest\example_from_other_ext.txt (The process cannot access the file because it is being used by another process.

Comment 1

[Beth Rennie [:beth] (she/her)]

If the deletion failes because the file has FILE_ATTRIBUTE_READONLY, IOUtils.remove() recently got a retryReadonly option which removes the readonly flag and then retries deletion.

Comment 2

[Rob Wu [:robwu]]

(In reply to Barret Rennie [:barret] (they/them) from comment #1)

If the deletion failes because the file has FILE_ATTRIBUTE_READONLY, IOUtils.remove() recently got a retryReadonly option which removes the readonly flag and then retries deletion.

Thanks for letting us know about this new flag!

Under normal circumstances, the file should not have that flag. If it does, I would be inclined to respect the flag.
The most likely cause for the observed errors is that the file is somehow locked, i.e. considered in use by a process.

Comment 3

[Beth Rennie [:beth] (she/her)]

I should note that this was the default behaviour of OS.File.remove, as mentioned in the linked bug. See here.