Open Bug 1674325 Opened 4 years ago Updated 1 month ago

When the site usage is near its quota, IDBObjectStore.delete() sometimes fails with NS_ERROR_FILE_NO_DEVICE_SPACE

Categories

(Core :: Storage: Quota Manager, defect, P3)

Firefox 82
defect

Tracking

()

People

(Reporter: cpnspam+git, Unassigned)

References

Details

(Whiteboard: dom-lws-bugdash-triage)

Attachments

(1 file)

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36

Steps to reproduce:

I don't know if a service worker is necessary, but my code is doing the following actions in a service worker.
It stores a few MB of data to an object store in indexedDB and a couple of GB of data (for testing purposes) to a cache. (Non-persistent storage is used for this test since persistent storage always reports 0 usage.)
When a cache write fails with NS_ERROR_FILE_NO_DEVICE_SPACE, it uses IDBObjectStore.delete() to delete a key from the object store to try to free up some space.

Actual results:

About 10-20% of the time (probably depending on the exact usage), the IDBRequest object's 'success' event is triggered, but the StorageEstimate usage remains unchanged, and an IDBObjectStore.get() shows that the key remains in the object store.

Expected results:

The key should be deleted from the object store, and the usage should decrease accordingly. (This happens 80-90% of the time.)

After checking the formal indexedDB spec, I noticed that some errors can be reported on the transaction instead of the request. After adding the appropriate instrumentation, I see now that the transaction fails with NS_ERROR_FILE_NO_DEVICE_SPACE. I have updated the bug title accordingly. This is slightly better than failing silently, so but I would still argue that delete should never fail due to a quota error.

Also of interest, I notice that overwriting a key succeeds much more often that deleting a key when the usage is near the quota.

I have seen some hints that the quota problems are timing dependent, e.g. that waiting a bit before attempting to delete a key is more likely to succeed. I will investigate further.

Summary: When the site usage is near its quota, IDBObjectStore.delete() claims to succeed but doesn't delete the record → When the site usage is near its quota, IDBObjectStore.delete() sometimes fails with NS_ERROR_FILE_NO_DEVICE_SPACE

I confirmed that in many (all?) cases when IDBObjectStore.delete() fails with a quota error, trying again 5 seconds later succeeds. The later delete() attempt uses the same DB connection but is in a new transaction.

Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:82.0) Gecko/20100101 Firefox/82.0

Hi,

I will move this over to a component so developers can take a look over it. If this is not the correct component please feel free to change it to an appropriate one.

Thanks for the report.

Component: Untriaged → Storage: Quota Manager
Product: Firefox → Core
See Also: → 1674326

Hi, thanks again for the report!

To allow us to better understand where the error is generated, could you run a debug build and share the debug output?

You can find debug builds of 82.0.2 at https://treeherder.mozilla.org/jobs?repo=mozilla-release&searchStr=build%2Cdebug&revision=690c4477e78a86bf10b1d3e4cf5d9b9cf65ddb4d.
Please check the "Artifacts" tab in the panel below, there is "target.zip".
Please download the zip file, unzip it and then run the firefox inside. Then redo the steps that triggered the problem.

Flags: needinfo?(cpnspam+git)
Attached file firefox-dbg.log

capture of STDOUT/STDERR from a debug build of Firefox 82.0.2

Flags: needinfo?(cpnspam+git)

I've attached a capture of STDOUT/STDERR from the debug build of Firefox, although it seems rather sparse. If there's another log file I should look for, let me know.

It does include these lines, which may be relevant:

[Parent 12148, IndexedDB #9] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/indexedDB/ActorsParent.cpp, line 7104
[Parent 12148, IndexedDB #9] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/indexedDB/ActorsParent.cpp, line 7192
[Parent 12148, IndexedDB #9] WARNING: Commit failed!: 'NS_SUCCEEDED(mResultCode)', file /builds/worker/checkouts/gecko/dom/indexedDB/ActorsParent.cpp, line 18776
[Parent 12148, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/generic/nsFrameSelection.cpp, line 1598

FYI, my current Javascript application requires a bit of user fiddling to trigger the quota bug. In general, a user interaction causes it to allocate a large entry in indexedDB, then cache a bunch of files, and then (when the cache reaches the quota limit), it attempts to delete the large entry from indexedDB and then some of the cached files. In this case, I repeated the process 2 to 4 times. On the last attempt, the delete of the key from indexedDB failed with NS_ERROR_FILE_NO_DEVICE_SPACE. The script then waited one second before trying again, upon which the delete succeeded. I then manually killed Firefox.

Thanks a lot for providing the information!

Hm, so this means that the quota check that fails happens when committing the transaction, probably then originating from https://searchfox.org/mozilla-release/rev/32d0e24d914a59d7e86de1e1de06b57400642022/storage/TelemetryVFS.cpp#251 (TelemetryVFS isn't instrumented to output warnings at the moment).

I would have rather expected that quota might have been exceeded before committing because the journal file size increased.

Assuming this transaction is actually (only) deleting entries, i.e. only a ObjectStoreDeleteRequestOp ran, it's depending on implementation details of SQLite if this only temporarily increases the size of some file.

Would we need additional information from increasing the IndexedDB log level here to be sure what's happening?

Flags: needinfo?(jvarga)
Severity: -- → S3
Priority: -- → P3

(In reply to Simon Giesecke [:sg] [he/him] from comment #7)

Would we need additional information from increasing the IndexedDB log level here to be sure what's happening?

I think the provided log from running a debug build is enough. We created a special cleanup transaction for handling cases like this in bug 1182987. The reported edge case is currently not handled by that obviously.

Flags: needinfo?(jvarga)
Status: UNCONFIRMED → NEW
Ever confirmed: true
Whiteboard: dom-lws-bugdash-triage
You need to log in before you can comment on or make changes to this bug.