Closed Bug 1767695 Opened 3 years ago Closed 3 months ago

Intermittent devtools/client/aboutdebugging/test/browser/browser_aboutdebugging_addons_debug_storage.js | single tracking bug

Categories

(DevTools :: about:debugging, defect, P3)

Product:
DevTools
Component:
about:debugging
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: jmaher, Assigned: jdescottes)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

Attachments

(1 file, 1 obsolete file)

Bug 1767695 - [devtools] Wait for storage table in browser_aboutdebugging_addons_debug_storage.js
48 bytes, text/x-phabricator-request
Details | Review
No description provided.

Filter on devtools-intermittent-singletrackingbug-triage

Severity: -- → S4
Component: Storage Inspector → about:debugging
Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
Pushed by jdescottes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/c94d2513c1ba [devtools] Wait for storage table in browser_aboutdebugging_addons_debug_storage.js r=nchevobbe

https://hg.mozilla.org/mozilla-central/rev/c94d2513c1ba

Status: ASSIGNED → RESOLVED
Closed: 3 years ago
status-firefox105: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 105 Branch
See Also: → 1782708

This is still happening: https://treeherder.mozilla.org/logviewer?job_id=387857292&repo=mozilla-central&lineNumber=3126

Status: RESOLVED → REOPENED
status-firefox105: fixed → ---
Resolution: FIXED → ---
Target Milestone: 105 Branch → ---

We have 2 issues mixed here. The old/existing intermittent is still happening rarely, but the recent spike in about two issues:

For the first one, I am not sure if there could be any leftover animation. The storage inspector is using a few animations, but we are closing the tab hosting the toolbox before the end of the test.

For the second one, no clue so far.

Attachment #9381443 - Attachment is obsolete: true

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: REOPENED → RESOLVED
Closed: 3 years ago → 1 year ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=507861033&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Hi Marco,

This intermittent started spiking 8 days ago, around June 10, only on linux opt.
When trying to open the storage panel for a toolbox debugging a webextension, we get the following errors:

[task 2025-06-15T18:34:02.210+00:00] 18:34:02 INFO - Select the storage panel
[task 2025-06-15T18:34:02.210+00:00] 18:34:02 INFO - Buffered messages logged at 18:33:24
[task 2025-06-15T18:34:02.211+00:00] 18:34:02 INFO - Console message: [JavaScript Error: "Warning: Sqlite connection '3489115804TeessatbDaat.sqlite#11' was not properly closed. Auto-close triggered by garbage collection.
[task 2025-06-15T18:34:02.212+00:00] 18:34:02 INFO - " {file: "resource://gre/modules/Sqlite.sys.mjs" line: 95}]
[task 2025-06-15T18:34:02.214+00:00] 18:34:02 INFO - Console message: [JavaScript Error: "Error: Warning: Sqlite connection '3489115804TeessatbDaat.sqlite#11' was not properly closed. Auto-close triggered by garbage collection.
[task 2025-06-15T18:34:02.214+00:00] 18:34:02 INFO - " {file: "resource://gre/modules/Sqlite.sys.mjs" line: 110}]

Also some earlier errors in the logs:

[task 2025-06-15T18:33:18.907+00:00] 18:33:18 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.018+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.120+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.232+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.334+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.435+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.536+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.638+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.740+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.854+00:00] 18:33:19 INFO - GECKO(1040) | console.error: "Content process 1156 isn't responsive while sending "DevToolsProcessParent:addOrSetSessionDataEntry" request. DevTools will ignore this process for now."
[task 2025-06-15T18:33:19.855+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:19.960+00:00] 18:33:19 INFO - GECKO(1040) | console.error: SQLite JSM (ConnectionOpener): "Could not open connection to /tmp/tmpb3e04nqk.mozrunner/storage/default/moz-extension+++ce7e8bbe-b491-44bd-a43b-80f9f3445640/idb/3489115804TeessatbDaat.sqlite: 2153971713"
[task 2025-06-15T18:33:20.114+00:00] 18:33:20 INFO - GECKO(1040) | console.error: "Error while calling actor 'watcher's method 'watchResources'" "Error(s) encountered during statement execution: no such table: database"
[task 2025-06-15T18:33:20.115+00:00] 18:33:20 INFO - GECKO(1040) | console.error: (new Error("Error(s) encountered during statement execution: no such table: database", "resource://gre/modules/Sqlite.sys.mjs", 1093))
[task 2025-06-15T18:33:20.115+00:00] 18:33:20 INFO - GECKO(1040) | console.error: (new Error("Protocol error (Error): Error(s) encountered during statement execution: no such table: database from: server0.conn1.watcher16 (resource://gre/modules/Sqlite.sys.mjs:1093:25)", "resource://devtools/shared/protocol/Front.js", 404))
[task 2025-06-15T18:33:23.276+00:00] 18:33:23 INFO - GECKO(1040) | console.error: "Content process 1156 is responsive again. DevTools resumes operations against it."

Any idea if there was a recent change which could be linked to this?

Flags: needinfo?(mak)

It seems the spike is gone now, no idea if some regression was fixed or some bug was backed out...

(In reply to Julian Descottes [:jdescottes] from comment #124)

Any idea if there was a recent change which could be linked to this?

Sorry for the delay, I was not aware of any changes specific to SQLite or Storage. I'm not following the DOM Storage side, thus I'd not be able to answer question regarding it, :jstutte may be a better pick on that side.
From what I can tell some shutdown code here is either racing or not running, and it's no properly closing a database connection.
I'd probably suggest to investigate the code and ensure .close is always invoked, for example here https://searchfox.org/mozilla-central/rev/53acdf9ea724c7fc85cfc259e0acf7663f4d34b8/devtools/server/actors/resources/storage/indexed-db.js#790 if we hit the early return the connection won't be closed... Similarly if the executeCached throws (and maybe it's what is causing the Error(s) encountered during statement execution: no such table: database error visible here) it also won't be closed...
that call to .close() should probably be in a try/finally()

Now, I think this was already discussed related to another intermittent, and that code in getNameFromDatabaseFile is just not robust enough, opening the database may not be a sufficient condition to read most recent data from it, maybe the while loop should be larger.

Flags: needinfo?(mak)

Thanks, and yes we already mentioned this issue with the while loop, let me file a quick bug to fix it.

Depends on: 1975004

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: REOPENED → RESOLVED
Closed: 1 year ago → 3 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: