Closed Bug 1904154 Opened 3 months ago Closed 3 months ago

High frequency TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_persist.js | First page message disappeared - Got 1, expected +0

Categories

(DevTools :: Console, defect, P5)

defect

Tracking

(firefox-esr115 unaffected, firefox-esr128 unaffected, firefox127 unaffected, firefox128 unaffected, firefox129 fixed)

RESOLVED FIXED
129 Branch
Tracking Status
firefox-esr115 --- unaffected
firefox-esr128 --- unaffected
firefox127 --- unaffected
firefox128 --- unaffected
firefox129 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jdescottes)

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [retriggered])

Attachments

(1 file)

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


[task 2024-06-21T20:30:24.091Z] 20:30:24     INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_persist.js | The second page is really a bfcache navigation, keeping the same WindowGlobal - 
[task 2024-06-21T20:30:24.092Z] 20:30:24     INFO - Buffered messages finished
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_persist.js | First page message disappeared - Got 1, expected +0
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - Stack trace:
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochikit/content/browser-test.js:test_is:1625
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_persist.js:null:170
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochikit/content/browser-test.js:handleTask:1145
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1217
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1358
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1134
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2024-06-21T20:30:24.093Z] 20:30:24     INFO - Leaving test bound 
[task 2024-06-21T20:30:24.094Z] 20:30:24     INFO - Entering test bound 
[task 2024-06-21T20:30:24.094Z] 20:30:24     INFO - Testing that messages persist on a refresh if logs are persisted
[task 2024-06-21T20:30:24.094Z] 20:30:24     INFO - Adding a new tab with URL: https://example.com/browser/devtools/client/webconsole/test/browser/test-console.html
[task 2024-06-21T20:30:24.129Z] 20:30:24     INFO - GECKO(2049) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2024-06-21T20:30:24.129Z] 20:30:24     INFO - GECKO(2049) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2024-06-21T20:30:24.130Z] 20:30:24     INFO - GECKO(2049) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2024-06-21T20:30:24.130Z] 20:30:24     INFO - GECKO(2049) | JavaScript error: , line 0: NotFoundError: No such JSProcessActor 'DevToolsProcess'
[task 2024-06-21T20:30:24.135Z] 20:30:24     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2024-06-21T20:30:24.136Z] 20:30:24     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2024-06-21T20:30:24.136Z] 20:30:24     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2024-06-21T20:30:24.136Z] 20:30:24     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSProcessActor 'DevToolsProcess'"]
[task 2024-06-21T20:30:24.141Z] 20:30:24     INFO - GECKO(2049) | JavaScript error: chrome://browser/content/places/browserPlacesViews.js, line 120: Error: No DOM node set for aPlacesNode.
[task 2024-06-21T20:30:24.141Z] 20:30:24     INFO - GECKO(2049) | node.type: 0. node.parent: [xpconnect wrapped nsINavHistoryResultNode]
[task 2024-06-21T20:30:24.142Z] 20:30:24     INFO - Console message: [JavaScript Error: "Error: No DOM node set for aPlacesNode.
[task 2024-06-21T20:30:24.142Z] 20:30:24     INFO - node.type: 0. node.parent: [xpconnect wrapped nsINavHistoryResultNode]" {file: "chrome://browser/content/places/browserPlacesViews.js" line: 120}]
[task 2024-06-21T20:30:24.142Z] 20:30:24     INFO - _getDOMNodeForPlacesNode@chrome://browser/content/places/browserPlacesViews.js:120:13
[task 2024-06-21T20:30:24.142Z] 20:30:24     INFO - nodeMoved@chrome://browser/content/places/browserPlacesViews.js:587:20
[task 2024-06-21T20:30:24.142Z] 20:30:24     INFO - 
[task 2024-06-21T20:30:24.458Z] 20:30:24     INFO - Tab added and finished loading
[task 2024-06-21T20:30:24.458Z] 20:30:24     INFO - Opening the toolbox
[task 2024-06-21T20:30:24.568Z] 20:30:24     INFO - Console message: [JavaScript Error: "Content-Security-Policy: The page’s settings blocked an inline style (style-src-attr) from being applied because it violates the following directive: “default-src chrome: resource:”" {file: "chrome://global/content/customElements.js" line: 499 column: 25 source: "display: none !important"}]
[task 2024-06-21T20:30:24.576Z] 20:30:24     INFO - Console message: [JavaScript Error: "Content-Security-Policy: The page’s settings blocked an inline style (style-src-attr) from being applied because it violates the following directive: “default-src chrome: resource:”" {file: "chrome://global/content/customElements.js" line: 499}]
[task 2024-06-21T20:30:24.577Z] 20:30:24     INFO - Console message: [JavaScript Error: "Content-Security-Policy: The page’s settings blocked an inline style (style-src-attr) from being applied because it violates the following directive: “default-src chrome: resource:”" {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2024-06-21T20:30:24.645Z] 20:30:24     INFO - Console message: [JavaScript Error: "Content-Security-Policy: The page’s settings blocked an inline style (style-src-attr) from being applied because it violates the following directive: “default-src chrome: resource:”" {file: "chrome://global/content/customElements.js" line: 499 column: 25 source: "display: none !important"}]
[task 2024-06-21T20:30:24.646Z] 20:30:24     INFO - Console message: [JavaScript Error: "Content-Security-Policy: The page’s settings blocked an inline style (style-src-attr) from being applied because it violates the following directive: “default-src chrome: resource:”" {file: "chrome://global/content/customElements.js" line: 499}]
[task 2024-06-21T20:30:24.647Z] 20:30:24     INFO - Console message: [JavaScript Error: "Content-Security-Policy: The page’s settings blocked an inline style (style-src-attr) from being applied because it violates the following directive: “default-src chrome: resource:”" {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2024-06-21T20:30:24.665Z] 20:30:24     INFO - Toolbox opened and focused
[task 2024-06-21T20:30:24.892Z] 20:30:24     INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_persist.js | Messages showed up initially - 

Hi Alexandre! Can you please take a look at this? This is very frequent, mostly on OSX.
To get a better overview of the failure rate please check Bug 1772009 in the see also section.
Thank you!

retriggers and backfills

Flags: needinfo?(poirot.alex)
Keywords: regression
Regressed by: 1824726
See Also: → 1772009
Summary: High frequency devtools/client/webconsole/test/browser/browser_webconsole_persist.js | single tracking bug → High frequency TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_persist.js | First page message disappeared - Got 1, expected +0
Whiteboard: [retriggered]

Set release status flags based on info from the regressing bug 1824726

I investigated this a bit, and the issue is that sometimes we fail to clear the message cache on navigate, with the following exception + stack trace

Exception in clearMessagesCache" (new Error("Connection closed, pending request to server0.conn0.process4//consoleActor44, type clearMessagesCacheAsync failed

Request stack:
request@resource://devtools/shared/protocol/Front.js:299:14
generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:47:19
clearMessagesCache@resource://devtools/client/webconsole/webconsole-ui.js:240:36
asyncmessagesCacheClearingEnhancer@resource://devtools/client/webconsole/enhancers/message-cache-clearing.js:25:22
batchingReducer@resource://devtools/client/webconsole/enhancers/batching.js:21:18
dispatch@resource://devtools/client/shared/vendor/redux.js:256:22
eventTelemetryMiddleware/</<@resource://devtools/client/webconsole/middleware/event-telemetry.js:25:21
historyPersistenceMiddleware/</<@resource://devtools/client/webconsole/middleware/history-persistence.js:41:21
thunk/</</<@resource://devtools/client/shared/redux/middleware/thunk.js:18:11
ignore/</<@resource://devtools/client/shared/redux/middleware/ignore.js:31:12
createPerformanceMarkerMiddleware/</</<@resource://devtools/client/shared/redux/middleware/performance-marker.js:47:28
dispatchMessagesClear@resource://devtools/client/webconsole/webconsole-wrapper.js:219:20
dispatchTabWillNavigate@resource://devtools/client/webconsole/webconsole-wrapper.js:334:12
handleWillNavigate@resource://devtools/client/webconsole/webconsole-ui.js:452:18
handleDocumentEvent@resource://devtools/client/webconsole/webconsole-ui.js:417:12
_onResourceAvailable@resource://devtools/client/webconsole/webconsole-ui.js:478:14
_notifyWatchers@resource://devtools/shared/commands/resource/resource-command.js:905:24
_onResourceAvailable@resource://devtools/shared/commands/resource/resource-command.js:743:12
async
_emit@resource://devtools/shared/event-emitter.js:242:32
emit@resource://devtools/shared/event-emitter.js:186:18
emit@resource://devtools/shared/event-emitter.js:330:18
onPacket@resource://devtools/shared/protocol/Front.js:348:13
onPacket@resource://devtools/client/devtools-client.js:458:13
send/<@resource://devtools/shared/transport/local-transport.js:67:25
exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:103:22
DevToolsUtils.executeSoon*exports.executeSoon@resource://devtools/shared/DevToolsUtils.js:70:21
send@resource://devtools/shared/transport/local-transport.js:55:21
send@resource://devtools/server/devtools-server-connection.js:88:20
_sendEvent@resource://devtools/shared/protocol/Actor.js:73:15
Actor/<@resource://devtools/shared/protocol/Actor.js:47:16
_emit@resource://devtools/shared/event-emitter.js:242:32
emit@resource://devtools/shared/event-emitter.js:186:18
emit@resource://devtools/shared/event-emitter.js:330:18
notifyResources@resource://devtools/server/actors/watcher.js:480:10
onStateChange@resource://devtools/server/actors/resources/parent-process-document-event.js:137:12

When this happens we will get more messages than expected when doing bfcache navigations, and with the new throttling mechanism the last message might be throttled and be delayed until another navigation has been done ... and fails the test.

I have a test patch to workaround the issue, but we should probably see if we can make the clearMessagesCacheAsync call more reliable.

Flags: needinfo?(poirot.alex)
Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
Attachment #9409816 - Attachment description: Bug 1904154 - [devtools]Update webconsole persist test to handle scenarios where cache clear failed → Bug 1904154 - [devtools] Update webconsole persist test to handle scenarios where cache clear failed
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/eab53782a1a9
[devtools] Update webconsole persist test to handle scenarios where cache clear failed r=nchevobbe,devtools-reviewers
Status: ASSIGNED → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → 129 Branch

Set release status flags based on info from the regressing bug 1824726

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: