1751865 - Intermittent [TV] devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for dom-loading event is greater than will-navigate event (''x'' <= ''y'') -

Reporter

Description

•

3 years ago

treeherder

Filed by: ccozmuta [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=365325710&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ViCmupXLS4m9wpHrcRXKtw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ViCmupXLS4m9wpHrcRXKtw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2022-01-25T09:07:28.812Z] 09:07:28     INFO - TEST-START | devtools/shared/commands/resource/tests/browser_resources_document_events.js
[task 2022-01-25T09:07:29.879Z] 09:07:29     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:30.445Z] 09:07:30     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:30.885Z] 09:07:30     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:31.869Z] 09:07:31     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:31.870Z] 09:07:31     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:33.005Z] 09:07:33     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:34.091Z] 09:07:34     INFO - TEST-INFO | started process screencapture
[task 2022-01-25T09:07:34.215Z] 09:07:34     INFO - TEST-INFO | screencapture: exit 0
[task 2022-01-25T09:07:34.215Z] 09:07:34     INFO - <snipped 98 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
[task 2022-01-25T09:07:34.216Z] 09:07:34     INFO - Buffered messages logged at 09:07:31
[task 2022-01-25T09:07:34.216Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for loading event is correct (1643101650974) - 
[task 2022-01-25T09:07:34.217Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for interactive event is correct (1643101650985) - 
[task 2022-01-25T09:07:34.217Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for complete event is correct (1643101651163) - 
[task 2022-01-25T09:07:34.218Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for interactive event is greater than loading event (1643101650974 <= 1643101650985) - 
[task 2022-01-25T09:07:34.218Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for complete event is greater than interactive event (1643101650985 <= 1643101651163). - 
[task 2022-01-25T09:07:34.218Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | loading target is the expected one - 
[task 2022-01-25T09:07:34.219Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | interactive target is the expected one - 
[task 2022-01-25T09:07:34.219Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | complete target is the expected one - 
[task 2022-01-25T09:07:34.220Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | None of the tests (except the dedicated one) overload the console object - 
[task 2022-01-25T09:07:34.220Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | loading received in the exepected order - 
[task 2022-01-25T09:07:34.220Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | interactive received in the expected order - 
[task 2022-01-25T09:07:34.221Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | complete received last - 
[task 2022-01-25T09:07:34.221Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for loading event is correct (1643101650985) - 
[task 2022-01-25T09:07:34.222Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for interactive event is correct (1643101651161) - 
[task 2022-01-25T09:07:34.222Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for complete event is correct (1643101651163) - 
[task 2022-01-25T09:07:34.222Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for interactive event is greater than loading event (1643101650985 <= 1643101651161) - 
[task 2022-01-25T09:07:34.223Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for complete event is greater than interactive event (1643101651161 <= 1643101651163). - 
[task 2022-01-25T09:07:34.223Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | loading target is the expected one - 
[task 2022-01-25T09:07:34.223Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | interactive target is the expected one - 
[task 2022-01-25T09:07:34.224Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | complete target is the expected one - 
[task 2022-01-25T09:07:34.224Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | None of the tests (except the dedicated one) overload the console object - 
[task 2022-01-25T09:07:34.224Z] 09:07:34     INFO - Navigate the iframe to another process (if fission is enabled)
<...>
[task 2022-01-25T09:07:34.247Z] 09:07:34     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-01-25T09:07:34.247Z] 09:07:34     INFO - Test cross origin navigations for DOCUMENT_EVENT
[task 2022-01-25T09:07:34.248Z] 09:07:34     INFO - Adding a new tab with URL: https://example.com/document-builder.sjs?html=com
[task 2022-01-25T09:07:34.248Z] 09:07:34     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/document-builder.sjs?html=com" line: 0}]
[task 2022-01-25T09:07:34.249Z] 09:07:34     INFO - Tab added and finished loading
[task 2022-01-25T09:07:34.249Z] 09:07:34     INFO - Waiting 0.25 seconds.
[task 2022-01-25T09:07:34.249Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Existing document events are not fired - 
[task 2022-01-25T09:07:34.250Z] 09:07:34     INFO - Navigate to another process
[task 2022-01-25T09:07:34.250Z] 09:07:34     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.net/document-builder.sjs?html=%3Chead%3E%3Ctitle%3EtitleNet%3C/title%3E%3C/head%3Enet" line: 0}]
[task 2022-01-25T09:07:34.251Z] 09:07:34     INFO - Wait for will-navigate, dom-loading, dom-interactive and dom-complete events
[task 2022-01-25T09:07:34.251Z] 09:07:34     INFO - Buffered messages logged at 09:07:34
[task 2022-01-25T09:07:34.251Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Received the will-navigate - 
[task 2022-01-25T09:07:34.252Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | will-navigate newURI is set to the current tab new location - 
[task 2022-01-25T09:07:34.252Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | loading received in the exepected order - 
[task 2022-01-25T09:07:34.253Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | interactive received in the expected order - 
[task 2022-01-25T09:07:34.253Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | complete received last - 
[task 2022-01-25T09:07:34.253Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for will-navigate event is correct (1643101653705) - 
[task 2022-01-25T09:07:34.254Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for loading event is correct (1643101653704) - 
[task 2022-01-25T09:07:34.254Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for interactive event is correct (1643101653914) - 
[task 2022-01-25T09:07:34.254Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Type of time attribute for complete event is correct (1643101653920) - 
[task 2022-01-25T09:07:34.255Z] 09:07:34     INFO - Buffered messages finished
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - TEST-UNEXPECTED-FAIL | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for dom-loading event is greater than will-navigate event (1643101653705 <= 1643101653704) - 
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - Stack trace:
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochikit/content/browser-test.js:test_ok:1375
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochitests/content/browser/devtools/shared/commands/resource/tests/browser_resources_document_events.js:assertEvents:625
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochitests/content/browser/devtools/shared/commands/resource/tests/browser_resources_document_events.js:testCrossOriginNavigation:439
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochitests/content/browser/devtools/shared/commands/resource/tests/browser_resources_document_events.js:null:18
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1130
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1170
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:978
[task 2022-01-25T09:07:34.256Z] 09:07:34     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1041
[task 2022-01-25T09:07:34.257Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for interactive event is greater than loading event (1643101653704 <= 1643101653914) - 
[task 2022-01-25T09:07:34.257Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for complete event is greater than interactive event (1643101653914 <= 1643101653920). - 
[task 2022-01-25T09:07:34.257Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | will-navigate target was the one before the navigation - 
[task 2022-01-25T09:07:34.258Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | loading target is the expected one - 
[task 2022-01-25T09:07:34.258Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | interactive target is the expected one - 
[task 2022-01-25T09:07:34.258Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | complete target is the expected one - 
[task 2022-01-25T09:07:34.259Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | None of the tests (except the dedicated one) overload the console object - 
[task 2022-01-25T09:07:34.259Z] 09:07:34     INFO - Waiting 0.25 seconds.
[task 2022-01-25T09:07:34.365Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | There is no duplicated event and only the 4 expected DOCUMENT_EVENT states - 
[task 2022-01-25T09:07:34.365Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | The first DOCUMENT_EVENT is will-navigate - 
[task 2022-01-25T09:07:34.366Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | The second DOCUMENT_EVENT is dom-loading - 
[task 2022-01-25T09:07:34.367Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | The third DOCUMENT_EVENT is dom-interactive - 
[task 2022-01-25T09:07:34.367Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | The fourth DOCUMENT_EVENT is dom-complete - 
[task 2022-01-25T09:07:34.368Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | resource dom-loading has expected url after reloading - 
[task 2022-01-25T09:07:34.369Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | resource dom-loading does not have a title property after reloading - 
[task 2022-01-25T09:07:34.369Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | resource dom-interactive has expected url property after reloading - 
[task 2022-01-25T09:07:34.370Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | resource dom-interactive has expected title after reloading - 
[task 2022-01-25T09:07:34.370Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | resource dom-complete does not have a url property after reloading - 
[task 2022-01-25T09:07:34.371Z] 09:07:34     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_document_events.js | resource dom-complete does not have a title property after reloading - 
[task 2022-01-25T09:07:34.371Z] 09:07:34     INFO - Leaving test bound 
[task 2022-01-25T09:07:34.372Z] 09:07:34     INFO - GECKO(1817) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-25T09:07:34.372Z] 09:07:34     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-01-25T09:07:34.372Z] 09:07:34     INFO - Removing tab.

BugBot [:suhaib / :marco/ :calixte]

Updated

•

3 years ago

Has Regression Range: --- → yes

Andreea Pavel [:apavel]

Updated

•

3 years ago

Summary: Intermittent devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for dom-loading event is greater than will-navigate event (''x'' <= ''y'') - → Intermittent [TV] devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for dom-loading event is greater than will-navigate event (''x'' <= ''y'') -

Nicolas Chevobbe [:nchevobbe]

Comment 1

•

3 years ago

Looks like Bug 1715878 (the assertion message was updated in Bug 1685187)

BugBot [:suhaib / :marco/ :calixte]

Comment 2

•

3 years ago

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

status-firefox96: --- → unaffected

status-firefox97: --- → unaffected

status-firefox98: --- → affected

status-firefox-esr91: --- → unaffected

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

Comment 4

•

3 years ago

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

Status: NEW → RESOLVED

Closed: 3 years ago

Resolution: --- → INCOMPLETE

Treeherder Bug Filer

Reporter

Comment 5

•

3 years ago

treeherder

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

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

Joel Maher ( :jmaher ) (UTC -8)

Updated

•

3 years ago

Blocks: 1767768

Joel Maher ( :jmaher ) (UTC -8)

Updated

•

3 years ago

Status: REOPENED → RESOLVED

Closed: 3 years ago → 3 years ago

Resolution: --- → DUPLICATE

Bugzilla

Intermittent [TV] devtools/shared/commands/resource/tests/browser_resources_document_events.js | Timestamp for dom-loading event is greater than will-navigate event (''x'' <= ''y'') -

Categories

(DevTools :: General, defect, P5)

Tracking

(firefox-esr91 unaffected, firefox96 unaffected, firefox97 unaffected, firefox98 affected)

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Crash Data

Security

(public)

User Story

Description

Updated

Updated

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Updated

Updated