Open Bug 1438998 Opened 7 years ago Updated 2 years ago

7,500 instances of "NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001" emitted from storage/mozStorage(Connection|Service).cpp during linux64 debug testing

Categories

(Toolkit :: Storage, defect, P3)

defect

Tracking

()

People

(Reporter: erahm, Unassigned)

References

(Depends on 2 open bugs, Blocks 1 open bug)

Details

Attachments

(1 file)

> 3738 WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001: file storage/mozStorageConnection.cpp, line 759 This warning [1] shows up in the following test suites: > 799 - test-linux64/debug-web-platform-tests-e10s-12 wpt12 > 235 - test-linux64/debug-mochitest-e10s-5 5 > 227 - test-linux64/debug-mochitest-plain-headless-e10s-5 h5 > 208 - test-linux64/debug-web-platform-tests-wdspec-e10s Wd > 143 - test-linux64/debug-web-platform-tests-e10s-9 wpt9 > 136 - test-linux64/debug-web-platform-tests-e10s-6 wpt6 > 131 - test-linux64/debug-web-platform-tests-e10s-10 wpt10 > 120 - test-linux64/debug-web-platform-tests-e10s-11 wpt11 > 119 - test-linux64/debug-web-platform-tests-e10s-3 wpt3 > 112 - test-linux64/debug-web-platform-tests-e10s-1 wpt1 > 109 - test-linux64/debug-web-platform-tests-e10s-7 wpt7 > 100 - test-linux64/debug-web-platform-tests-e10s-2 wpt2 > 98 - test-linux64/debug-web-platform-tests-e10s-5 wpt5 > 96 - test-linux64/debug-web-platform-tests-e10s-8 wpt8 > 95 - test-linux64/debug-web-platform-tests-e10s-4 wpt4 > 74 - test-linux64/debug-web-platform-tests-reftests-e10s-1 Wr1 > 62 - test-linux64/debug-mochitest-devtools-chrome-e10s-7 dt7 > 61 - test-linux64/debug-web-platform-tests-reftests-e10s-5 Wr5 > 53 - test-linux64/debug-web-platform-tests-reftests-e10s-4 Wr4 > 47 - test-linux64/debug-web-platform-tests-reftests-e10s-6 Wr6 > 46 - test-linux64/debug-mochitest-clipboard-e10s cl > 39 - test-linux64/debug-web-platform-tests-reftests-e10s-2 Wr2 > 36 - test-linux64/debug-mochitest-chrome-2 c2 > 29 - test-linux64/debug-mochitest-chrome-3 c3 > 29 - test-linux64/debug-marionette-e10s Mn > 26 - test-linux64/debug-marionette-headless-e10s MnH > 25 - test-linux64/debug-mochitest-e10s-16 16 > 17 - test-linux64/debug-mochitest-browser-chrome-e10s-10 bc10 > 16 - test-linux64/debug-mochitest-chrome-1 c1 > 15 - test-linux64/debug-firefox-ui-functional-local-e10s en-US > 13 - test-linux64/debug-mochitest-browser-chrome-e10s-8 bc8 > 13 - test-linux64/debug-mochitest-plain-headless-e10s-15 h15 > 12 - test-linux64/debug-mochitest-browser-chrome-e10s-3 bc3 > 12 - test-linux64/debug-mochitest-e10s-7 7 > 12 - test-linux64/debug-mochitest-browser-chrome-e10s-4 bc4 > 11 - test-linux64/debug-mochitest-browser-chrome-e10s-5 bc5 > 11 - test-linux64/debug-mochitest-browser-chrome-e10s-7 bc7 > 11 - test-linux64/debug-mochitest-browser-chrome-e10s-1 bc1 > 11 - test-linux64/debug-mochitest-browser-chrome-e10s-6 bc6 > 11 - test-linux64/debug-mochitest-e10s-15 15 > 10 - test-linux64/debug-mochitest-browser-chrome-e10s-2 bc2 > 10 - test-linux64/debug-mochitest-e10s-4 4 > 10 - test-linux64/debug-mochitest-browser-chrome-e10s-9 bc9 > 10 - test-linux64/debug-mochitest-gpu-e10s gpu > 9 - test-linux64/debug-mochitest-e10s-11 11 > 9 - test-linux64/debug-mochitest-plain-headless-e10s-11 h11 > 9 - test-linux64/debug-mochitest-plain-headless-e10s-4 h4 > 9 - test-linux64/debug-mochitest-e10s-10 10 > 8 - test-linux64/debug-mochitest-e10s-12 12 > 8 - test-linux64/debug-mochitest-e10s-14 14 > 8 - test-linux64/debug-mochitest-plain-headless-e10s-13 h13 > 8 - test-linux64/debug-mochitest-plain-headless-e10s-7 h7 > 8 - test-linux64/debug-mochitest-plain-headless-e10s-12 h12 > 7 - test-linux64/debug-mochitest-e10s-6 6 > 7 - test-linux64/debug-mochitest-e10s-9 9 > 7 - test-linux64/debug-mochitest-e10s-3 3 > 7 - test-linux64/debug-mochitest-plain-headless-e10s-9 h9 > 7 - test-linux64/debug-mochitest-plain-headless-e10s-8 h8 > 7 - test-linux64/debug-mochitest-plain-headless-e10s-10 h10 > 7 - test-linux64/debug-mochitest-e10s-13 13 > 7 - test-linux64/debug-mochitest-devtools-chrome-e10s-6 dt6 > 6 - test-linux64/debug-reftest-e10s-7 R7 > 6 - test-linux64/debug-mochitest-e10s-8 8 > 6 - test-linux64/debug-mochitest-plain-headless-e10s-16 h16 > 6 - test-linux64/debug-mochitest-devtools-chrome-e10s-2 dt2 > 6 - test-linux64/debug-mochitest-plain-headless-e10s-6 h6 > 6 - test-linux64/debug-mochitest-plain-headless-e10s-1 h1 > 5 - test-linux64/debug-mochitest-plain-headless-e10s-3 h3 > 5 - test-linux64/debug-reftest-no-accel-e10s-4 Ru4 > 4 - test-linux64/debug-mochitest-e10s-2 2 > 4 - test-linux64/debug-mochitest-devtools-chrome-e10s-3 dt3 > 4 - test-linux64/debug-crashtest-e10s C > 4 - test-linux64/debug-mochitest-devtools-chrome-e10s-4 dt4 > 4 - test-linux64/debug-mochitest-devtools-chrome-e10s-5 dt5 > 4 - test-linux64/debug-firefox-ui-functional-remote-e10s en-US > 4 - test-linux64/debug-mochitest-e10s-1 1 > 4 - test-linux64/debug-reftest-e10s-4 R4 > 3 - test-linux64/debug-reftest-stylo-e10s-1 Rs1 > 3 - test-linux64/debug-mochitest-browser-chrome-e10s-16 bc16 > 3 - test-linux64/debug-reftest-no-accel-e10s-8 Ru8 > 3 - test-linux64/debug-mochitest-plain-headless-e10s-2 h2 > 3 - test-linux64/debug-mochitest-devtools-chrome-e10s-1 dt1 > 3 - test-linux64/debug-reftest-stylo-e10s-4 Rs4 > 3 - test-linux64/debug-jsreftest-e10s-2 J2 > 3 - test-linux64/debug-reftest-stylo-e10s-3 Rs3 > 3 - test-linux64/debug-reftest-no-accel-e10s-6 Ru6 > 3 - test-linux64/debug-mochitest-plain-headless-e10s-14 h14 > 2 - test-linux64/debug-reftest-no-accel-e10s-1 Ru1 > 2 - test-linux64/debug-reftest-e10s-2 R2 > 2 - test-linux64/debug-reftest-no-accel-e10s-2 Ru2 > 2 - test-linux64/debug-jsreftest-e10s-1 J1 > 2 - test-linux64/debug-reftest-no-accel-e10s-5 Ru5 > 2 - test-linux64/debug-mochitest-media-e10s-3 mda3 > 2 - test-linux64/debug-reftest-e10s-3 R3 > 2 - test-linux64/debug-reftest-no-accel-e10s-7 Ru7 > 2 - test-linux64/debug-reftest-stylo-e10s-2 Rs2 > 2 - test-linux64/debug-mochitest-media-e10s-2 mda2 > 2 - test-linux64/debug-reftest-e10s-1 R1 > 1 - test-linux64/debug-reftest-e10s-8 R8 > 1 - test-linux64/debug-reftest-e10s-5 R5 > 1 - test-linux64/debug-jsreftest-e10s-3 J3 > 1 - test-linux64/debug-reftest-stylo-e10s-8 Rs8 > 1 - test-linux64/debug-mochitest-devtools-chrome-e10s-8 dt8 > 1 - test-linux64/debug-reftest-e10s-6 R6 > 1 - test-linux64/debug-reftest-stylo-e10s-5 Rs5 > 1 - test-linux64/debug-mochitest-a11y a11y > 1 - test-linux64/debug-mochitest-browser-chrome-e10s-15 bc15 > 1 - test-linux64/debug-mochitest-browser-chrome-e10s-13 bc13 > 1 - test-linux64/debug-mochitest-webgl-e10s-3 gl3 > 1 - test-linux64/debug-mochitest-browser-chrome-e10s-12 bc12 > 1 - test-linux64/debug-reftest-stylo-e10s-6 Rs6 > 1 - test-linux64/debug-mochitest-webgl-e10s-1 gl1 > 1 - test-linux64/debug-reftest-no-accel-e10s-3 Ru3 > 1 - test-linux64/debug-mochitest-media-e10s-1 mda1 It shows up in 1561 tests. A few of the most prevalent: > 387 - [e10s] Shutdown > 77 - Shutdown > 36 - [e10s] /webdriver/tests/sessions/new_session/create_firstMatch.py > 30 - [e10s] /webdriver/tests/sessions/new_session/create_alwaysMatch.py > 20 - [e10s] /IndexedDB/key-conversion-exceptions.htm > 18 - [e10s] /IndexedDB/idbobjectstore-rename-store.html > 15 - [e10s] /IndexedDB/key_valid.html > 15 - [e10s] dom/indexedDB/test/test_rename_objectStore.html > 14 - [e10s] /IndexedDB/idbindex-rename.html > 14 - [e10s] /IndexedDB/idb-binary-key-roundtrip.htm [1] https://hg.mozilla.org/mozilla-central/annotate/928f0f09172f/storage/mozStorageConnection.cpp#l759
Summary: 3,700 instances of "NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001" emitted from storage/mozStorageConnection.cpp during linux64 debug testing → 7,500 instances of "NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001" emitted from storage/mozStorage(Connection|Service).cpp during linux64 debug testing
uhm, this is rv = initializeInternal(); not very positive. Do we have a better pseudo stack? Maybe it's tests without a profile. The warning looks correct, the caller likely doesn't check if it can run in that context.
ah this comes from openDatabaseWithFileURL that is indexedDB indeed. Let's see what Jan thinks.
Flags: needinfo?(jvarga)
Priority: -- → P2

7,500 instances of "NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80630001" emitted from storage/mozStorage(Connection|Service).cpp during linux64 debug testing

Hi, I would like to work on this. Please check the submitted patch.

Flags: needinfo?(erahm)

The fix here doesn't just consist into removing the warning, you should run one (or more) of the above test get a stack of where and why initializeInternal() is returning an error, probably one of the executeSql calls inside it return a native SQLITE error, it would be useful to know which one. It would also be useful to know what's the url passed to openDatabaseWithFileURL

At that point we should be able to evaluate whether this warning is correct and the consumers should be fixed, or wrong, and then we could mute it.

Flags: needinfo?(erahm)

To inspect this locally you'll want to have a debug build, you can enable this by adding the following to your .mozconfig build file:

ac_add_options --enable-debug

One of the tests where this reproduces is the wpt idbobjectstore-rename-store.html test, you can run that locally with:

./mach test testing/web-platform/tests/IndexedDB/idbobjectstore-rename-store.html

Marco would like to know which line is returning a failure in initializeInternal [1]. You can either inspect with a debugger or more simply just add a printf indicating which line is returning. Additionally it would be useful to log error that comes back from sqlite. You'll also want to confirm that we still see this warning

[1] https://searchfox.org/mozilla-central/rev/44a212460990ffffecf50a8e972d3cbde2e7216b/storage/mozStorageConnection.cpp#703

Flags: needinfo?(jvarga)

Per https://www.oxymoronical.com/nsresult/:

Results for 0x80630001
    NS_ERROR_STORAGE_BUSY
    SQLite database connection is busy

This likely indicates that an IndexedDB test is attempting to open a database that's currently being checkpointed on another thread. I believe bug 1541550 most specifically covers this, but bug 1541548 could also be involved. Fixing those bugs is likely to be the best way to eliminate this spam.

In general, a connection being busy does indicate a scheduling/coordination problem, so the spam is arguably good, except for how long it's taken to address it. It could make sense to have some kind of open flag that indicates that a busy-wait is expected/possible and the specific error shouldn't be warned. When a bug is filed to fix the underlying issue (as has been done for IDB), the open requests related to that bug could then be marked as expecting the busy-wait to suppress the spam.

Context

The general issue is that there are potentially 3 threads involved in IDB database work:

  1. The PBackground thread where IndexedDB coordinates access to databases and decides what thread should handle an IDB requests.
  2. The QuotaManager I/O thread where IDB open requests are serviced. This thread will initially open a database to do a version check, and then subsequently close the database so it can be re-opened on the next thread. That's bug 1541548.
  3. The IDB connection thread where all of the database transactions are serviced. When the database is closed, write-ahead-log checkpointing may occur which does blocking IO. Bug 1541550 is about IDB doing a better job of tracking/coordinating this closure so QM I/O opens don't get run while this is still happening.
Depends on: 1541548, 1541550
Severity: normal → S3
Severity: S3 → N/A
Priority: P2 → P3
Severity: N/A → S4
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: