Open Bug 1694274 Opened 2 months ago Updated 2 days ago

Intermittent devtools/client/storage/test/browser_storage_indexeddb_navigation.js | Test timed out -

Categories

(DevTools :: Storage Inspector, defect, P5)

defect
Points:
8

Tracking

(Fission Milestone:M8, firefox-esr78 unaffected, firefox86 unaffected, firefox87 unaffected, firefox88 affected)

ASSIGNED
Fission Milestone M8
Tracking Status
firefox-esr78 --- unaffected
firefox86 --- unaffected
firefox87 --- unaffected
firefox88 --- affected

People

(Reporter: intermittent-bug-filer, Assigned: ladybenko, NeedInfo)

References

(Regression)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: dt-fission-m3-mvp [retriggered][stockwell disabled])

Attachments

(4 files)

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=330802662&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OW_WdJDhSD2Dn9iXrCNmmQ/runs/0/artifacts/public/logs/live_backing.log


[task 2021-02-22T21:37:21.466Z] 21:37:21     INFO - TEST-OK | devtools/client/storage/test/browser_storage_indexeddb_duplicate_names.js | took 1936ms
[task 2021-02-22T21:37:21.507Z] 21:37:21     INFO - checking window state
[task 2021-02-22T21:37:21.545Z] 21:37:21     INFO - TEST-START | devtools/client/storage/test/browser_storage_indexeddb_navigation.js
[task 2021-02-22T21:37:23.077Z] 21:37:23     INFO - GECKO(2699) | JavaScript error: resource://gre/modules/Sqlite.jsm, line 893: Error: Error(s) encountered during statement execution: no such table: database
[task 2021-02-22T21:37:25.181Z] 21:37:25     INFO - GECKO(2699) | JavaScript error: resource://gre/modules/Sqlite.jsm, line 91: Error: Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-22T21:38:51.590Z] 21:38:51     INFO - TEST-INFO | started process screentopng
[task 2021-02-22T21:38:51.758Z] 21:38:51     INFO - TEST-INFO | screentopng: exit 0
[task 2021-02-22T21:38:51.759Z] 21:38:51     INFO - Buffered messages logged at 21:37:21
[task 2021-02-22T21:38:51.760Z] 21:38:51     INFO - Entering test bound 
[task 2021-02-22T21:38:51.761Z] 21:38:51     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/storage/test/storage-indexeddb-simple.html
[task 2021-02-22T21:38:51.762Z] 21:38:51     INFO - Tab added and finished loading
[task 2021-02-22T21:38:51.763Z] 21:38:51     INFO - Found a window: complete
[task 2021-02-22T21:38:51.765Z] 21:38:51     INFO - Opening the storage inspector
[task 2021-02-22T21:38:51.765Z] 21:38:51     INFO - Opening the toolbox
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Buffered messages logged at 21:37:22
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Making sure that the toolbox's frame is focused
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - TEST-PASS | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | indexedDB > http://example.com is in the tree - 
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Selecting "indexedDB,http://example.com,db (default),store".
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - TEST-PASS | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | Table row has an entry for: lorem with value: {"key":"lorem","value":"ipsum"} - 
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Removing database…
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Load document "http://example.net/browser/devtools/client/storage/test/storage-indexeddb-simple-alt.html"
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Waiting for page to be loaded…
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Buffered messages logged at 21:37:23
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - → page loaded
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Waiting for target 'navigate' event…
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - → 'navigate' emitted
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Creating database in the second domain…
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Console message: [JavaScript Error: "Error: Error(s) encountered during statement execution: no such table: database" {file: "resource://gre/modules/Sqlite.jsm" line: 893}]
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Checking storage tree…
[task 2021-02-22T21:38:51.766Z] 21:38:51     INFO - Buffered messages logged at 21:37:25
[task 2021-02-22T21:38:51.767Z] 21:38:51     INFO - Console message: [JavaScript Error: "Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-22T21:38:51.767Z] 21:38:51     INFO - " {file: "resource://gre/modules/Sqlite.jsm" line: 75}]
[task 2021-02-22T21:38:51.767Z] 21:38:51     INFO - Console message: [JavaScript Error: "Error: Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-22T21:38:51.767Z] 21:38:51     INFO - " {file: "resource://gre/modules/Sqlite.jsm" line: 91}]
[task 2021-02-22T21:38:51.767Z] 21:38:51     INFO - Buffered messages finished
[task 2021-02-22T21:38:51.767Z] 21:38:51     INFO - TEST-UNEXPECTED-FAIL | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | Test timed out - 
[task 2021-02-22T21:38:51.786Z] 21:38:51     INFO - Removing tab.
[task 2021-02-22T21:38:51.787Z] 21:38:51     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-02-22T21:38:51.802Z] 21:38:51     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-02-22T21:38:51.822Z] 21:38:51     INFO - Tab removed and finished closing
[task 2021-02-22T21:38:52.280Z] 21:38:52     INFO - TEST-PASS | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2021-02-22T21:38:52.280Z] 21:38:52     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - TEST-UNEXPECTED-FAIL | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | A promise chain failed to handle a rejection: Error(s) encountered during statement execution: no such table: database - stack: handleCompletion@resource://gre/modules/Sqlite.jsm:893:25
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - Rejection date: Mon Feb 22 2021 21:37:23 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 282
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - Stack trace:
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:282
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - chrome://mochikit/content/browser-test.js:nextTest:631
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1222
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1162
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:949
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:1037
[task 2021-02-22T21:38:52.282Z] 21:38:52     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - TEST-UNEXPECTED-FAIL | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | A promise chain failed to handle a rejection: Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO -  - stack: logScriptError@resource://gre/modules/Sqlite.jsm:91:20
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - finalizationObserver@resource://gre/modules/Sqlite.jsm:154:19
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - Rejection date: Mon Feb 22 2021 21:37:25 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 282
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - Stack trace:
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:282
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - chrome://mochikit/content/browser-test.js:nextTest:631
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1222
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1162
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:949
[task 2021-02-22T21:38:52.284Z] 21:38:52     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:1037
[task 2021-02-22T21:38:52.292Z] 21:38:52     INFO - GECKO(2699) | MEMORY STAT | vsize 20975606MB | residentFast 1561MB
[task 2021-02-22T21:38:52.292Z] 21:38:52     INFO - TEST-OK | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | took 90745ms
[task 2021-02-22T21:38:52.328Z] 21:38:52     INFO - checking window state
[task 2021-02-22T21:38:52.366Z] 21:38:52     INFO - TEST-START | devtools/client/storage/test/browser_storage_indexeddb_overflow.js```
See Also: → 1687923

There are 53 total failures in the last 7 days on

  • linux1804-64 opt
  • linux1804-64-asan opt
  • windows10-64 asan and opt
  • windows10-64-shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=331407778&repo=autoland&lineNumber=3304

[task 2021-02-27T00:00:29.181Z] 00:00:29 INFO - TEST-START | devtools/client/storage/test/browser_storage_indexeddb_navigation.js
[task 2021-02-27T00:00:32.182Z] 00:00:32 INFO - GECKO(10156) | JavaScript error: resource://gre/modules/Sqlite.jsm, line 893: Error: Error(s) encountered during statement execution: no such table: database
[task 2021-02-27T00:00:32.931Z] 00:00:32 INFO - GECKO(10156) | JavaScript error: resource://gre/modules/Sqlite.jsm, line 91: Error: Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-27T00:01:14.231Z] 00:01:14 INFO - TEST-INFO | started process screenshot
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - TEST-INFO | screenshot: exit 0
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - Buffered messages logged at 00:00:29
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - Entering test bound
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/storage/test/storage-indexeddb-simple.html
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - Tab added and finished loading
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - Found a window: complete
[task 2021-02-27T00:01:14.301Z] 00:01:14 INFO - Opening the storage inspector
[task 2021-02-27T00:01:14.302Z] 00:01:14 INFO - Opening the toolbox
[task 2021-02-27T00:01:14.302Z] 00:01:14 INFO - Buffered messages logged at 00:00:30
[task 2021-02-27T00:01:14.302Z] 00:01:14 INFO - Making sure that the toolbox's frame is focused
[task 2021-02-27T00:01:14.302Z] 00:01:14 INFO - TEST-PASS | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | indexedDB > http://example.com is in the tree -
[task 2021-02-27T00:01:14.302Z] 00:01:14 INFO - Selecting "indexedDB,http://example.com,db (default),store".
[task 2021-02-27T00:01:14.302Z] 00:01:14 INFO - TEST-PASS | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | Table row has an entry for: lorem with value: {"key":"lorem","value":"ipsum"} -
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - Removing database…
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - Buffered messages logged at 00:00:32
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - Load document "http://example.net/browser/devtools/client/storage/test/storage-indexeddb-simple-alt.html"
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - Waiting for page to be loaded…
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - → page loaded
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - Waiting for target 'navigate' event…
[task 2021-02-27T00:01:14.303Z] 00:01:14 INFO - → 'navigate' emitted
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - Creating database in the second domain…
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - Console message: [JavaScript Error: "Error: Error(s) encountered during statement execution: no such table: database" {file: "resource://gre/modules/Sqlite.jsm" line: 893}]
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - Checking storage tree…
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - Console message: [JavaScript Error: "Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - " {file: "resource://gre/modules/Sqlite.jsm" line: 75}]
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - Console message: [JavaScript Error: "Error: Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - " {file: "resource://gre/modules/Sqlite.jsm" line: 91}]
[task 2021-02-27T00:01:14.304Z] 00:01:14 INFO - Buffered messages finished
[task 2021-02-27T00:01:14.305Z] 00:01:14 INFO - TEST-UNEXPECTED-FAIL | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | Test timed out -
[task 2021-02-27T00:01:14.344Z] 00:01:14 INFO - Removing tab.
[task 2021-02-27T00:01:14.344Z] 00:01:14 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-02-27T00:01:14.363Z] 00:01:14 INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-02-27T00:01:14.363Z] 00:01:14 INFO - Tab removed and finished closing
[task 2021-02-27T00:01:14.566Z] 00:01:14 INFO - TEST-PASS | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - TEST-UNEXPECTED-FAIL | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | A promise chain failed to handle a rejection: Error(s) encountered during statement execution: no such table: database - stack: handleCompletion@resource://gre/modules/Sqlite.jsm:893:25
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - Rejection date: Sat Feb 27 2021 00:00:32 GMT+0000 (Greenwich Mean Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 282
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - Stack trace:
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:282
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - chrome://mochikit/content/browser-test.js:nextTest:631
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1222
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - setTimeout handlerchrome://mochikit/content/browser-test.js:Tester_execTest:1162
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:949
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:1037
[task 2021-02-27T00:01:14.571Z] 00:01:14 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - TEST-UNEXPECTED-FAIL | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | A promise chain failed to handle a rejection: Warning: Sqlite connection '816800518dtbl-a.sqlite#0' was not properly closed. Auto-close triggered by garbage collection.
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - - stack: logScriptError@resource://gre/modules/Sqlite.jsm:91:20
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - finalizationObserver@resource://gre/modules/Sqlite.jsm:154:19
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - Rejection date: Sat Feb 27 2021 00:00:32 GMT+0000 (Greenwich Mean Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 282
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - Stack trace:
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:282
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - chrome://mochikit/content/browser-test.js:nextTest:631
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1222
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - setTimeout handler
chrome://mochikit/content/browser-test.js:Tester_execTest:1162
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:949
[task 2021-02-27T00:01:14.572Z] 00:01:14 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:1037
[task 2021-02-27T00:01:14.612Z] 00:01:14 INFO - GECKO(10156) | MEMORY STAT | vsize 2104242MB | vsizeMaxContiguous 66146864MB | residentFast 296MB | heapAllocated 94MB
[task 2021-02-27T00:01:14.612Z] 00:01:14 INFO - TEST-OK | devtools/client/storage/test/browser_storage_indexeddb_navigation.js | took 45432ms
[task 2021-02-27T00:01:14.630Z] 00:01:14 INFO - checking window state

Alexandre can you take a look?

Flags: needinfo?(poirot.alex)
Regressed by: 1685474
Whiteboard: [retriggered][stockwell needswork:owner]
See Also: 1687923

Please take a look at this frequent failure which is a regression from bug 1685474.

Flags: needinfo?(balbeza)
Assignee: nobody → nbeleuzu
Status: NEW → ASSIGNED
Assignee: nbeleuzu → nobody
Status: ASSIGNED → NEW
Assignee: nobody → nbeleuzu
Status: NEW → ASSIGNED
Assignee: nbeleuzu → nobody
Status: ASSIGNED → NEW
Assignee: nobody → balbeza
Flags: needinfo?(balbeza)
Whiteboard: [retriggered][stockwell disable-recommended] → dt-fission-m3-mvp [retriggered][stockwell disable-recommended]
Pushed by nbeleuzu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/48e48673b875
Disable browser_storage_indexeddb_navigation.js on Win10_64. r=intermittent-reviewers,jmaher
Status: NEW → ASSIGNED
Points: --- → 8
Status: ASSIGNED → RESOLVED
Closed: 2 months ago
Resolution: --- → FIXED
Target Milestone: --- → 88 Branch
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: 88 Branch → ---
Status: REOPENED → ASSIGNED
Fission Milestone: --- → ?
Attachment #9209426 - Attachment description: Bug 1694274 - disable 1694274 on Linux_64 for frequent failures. r=#intermittent-reviewers → Bug 1694274 - disable browser_storage_indexeddb_navigation.js on Linux_64 for frequent failures. r=#intermittent-reviewers
Keywords: leave-open
Whiteboard: dt-fission-m3-mvp [retriggered][stockwell disable-recommended] → dt-fission-m3-mvp [retriggered][stockwell disabled]
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/03a398c3c67c
disable browser_storage_indexeddb_navigation.js on Linux_64 for frequent failures. r=intermittent-reviewers,jmaher DONTBUILD
Fission Milestone: ? → M8

Fix intermittent indexedDB test (removing databases can take a while)

Pushed by balbeza@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/1aeb20ca63d0
[devtools] Request longer timeout for indexedDB navigation test r=nchevobbe

Before closing this bug, you should renable the test, which has been disabled in comment 15:
https://searchfox.org/mozilla-central/source/devtools/client/storage/test/browser.ini#83-86

Flags: needinfo?(poirot.alex) → needinfo?(balbeza)
You need to log in before you can comment on or make changes to this bug.