Closed Bug 1835796 Opened 1 year ago Closed 1 year ago

Perma [tier 2] remote/shared/test/xpcshell/test_Navigate.js | Test timed out

Tracking

(firefox-esr102 unaffected, firefox113 unaffected, firefox114 unaffected, firefox115 fixed)

Status:

RESOLVED FIXED

Milestone:

115 Branch

Tracking Flags:

Tracking

Status

firefox-esr102

---

unaffected

firefox113

---

unaffected

firefox114

---

unaffected

firefox115

---

fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [webdriver:m7][webdriver:external])

Attachments

(1 obsolete file)

Bug 1835796 - [remote] Do not rely on navigation timeouts in test_Navigate for waitForInitialNavigation 1 year ago Julian Descottes [:jdescottes] 48 bytes, text/x-phabricator-request		Details \| Review

Treeherder Bug Filer

Reporter

Description

•

1 year ago

treeherder

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

[task 2023-05-30T10:38:58.506Z] 10:38:58     INFO -  TEST-START | remote/shared/test/xpcshell/test_Navigate.js
[task 2023-05-30T10:43:58.507Z] 10:43:58  WARNING -  TEST-UNEXPECTED-TIMEOUT | remote/shared/test/xpcshell/test_Navigate.js | Test timed out
[task 2023-05-30T10:43:58.509Z] 10:43:58     INFO -  TEST-INFO took 300000ms
[task 2023-05-30T10:43:58.513Z] 10:43:58     INFO -  >>>>>>>
[task 2023-05-30T10:43:58.513Z] 10:43:58     INFO -  PID 2605 | [CodeCoverage] Setting handlers for process 2605.
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  running event loop
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  remote/shared/test/xpcshell/test_Navigate.js | Starting test_waitForInitialNavigation_initialDocumentNoWindowGlobal
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentNoWindowGlobal pending (2)
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNoWindowGlobal - [test_waitForInitialNavigation_initialDocumentNoWindowGlobal : 156] Document is not loading - true == true
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  } pending (3)
[task 2023-05-30T10:43:58.514Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (3)
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNoWindowGlobal - [test_waitForInitialNavigation_initialDocumentNoWindowGlobal : 161] waitForInitialNavigationCompleted has not resolved yet - true == true
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  } pending (2)
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.515Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNoWindowGlobal - [test_waitForInitialNavigation_initialDocumentNoWindowGlobal : 169] Document is not loading - true == true
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNoWindowGlobal - [test_waitForInitialNavigation_initialDocumentNoWindowGlobal : 170] Is initial document - true == true
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNoWindowGlobal - [test_waitForInitialNavigation_initialDocumentNoWindowGlobal : 174] Expected current URI has been set - "about:blank" == "about:blank"
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNoWindowGlobal - [test_waitForInitialNavigation_initialDocumentNoWindowGlobal : 179] Expected target URI has been set - "about:blank" == "about:blank"
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentNoWindowGlobal finished (2)
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  remote/shared/test/xpcshell/test_Navigate.js | Starting test_waitForInitialNavigation_initialDocumentNotLoaded
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentNotLoaded pending (2)
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNotLoaded - [test_waitForInitialNavigation_initialDocumentNotLoaded : 188] Document is not loading - true == true
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.516Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  } pending (3)
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (3)
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNotLoaded - [test_waitForInitialNavigation_initialDocumentNotLoaded : 194] waitForInitialNavigationCompleted has not resolved yet - true == true
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  } pending (2)
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.517Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNotLoaded - [test_waitForInitialNavigation_initialDocumentNotLoaded : 202] Document is not loading - true == true
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNotLoaded - [test_waitForInitialNavigation_initialDocumentNotLoaded : 203] Is initial document - true == true
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNotLoaded - [test_waitForInitialNavigation_initialDocumentNotLoaded : 207] Expected current URI has been set - "about:blank" == "about:blank"
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentNotLoaded - [test_waitForInitialNavigation_initialDocumentNotLoaded : 212] Expected target URI has been set - "about:blank" == "about:blank"
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentNotLoaded finished (2)
[task 2023-05-30T10:43:58.518Z] 10:43:58     INFO -  remote/shared/test/xpcshell/test_Navigate.js | Starting test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad pending (2)
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -  } pending (3)
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (3)
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.519Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad : 222] Document is loading - true == true
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad : 226] waitForInitialNavigationCompleted has not resolved yet - true == true
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  } pending (2)
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.520Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad : 234] Document is not loading - true == true
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad : 235] Is initial document - true == true
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad : 239] Expected current URI has been set - "about:blank" == "about:blank"
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad : 244] Expected target URI has been set - "about:blank" == "about:blank"
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 3 pending (2)
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentLoadingAndNoAdditionalLoad finished (2)
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  remote/shared/test/xpcshell/test_Navigate.js | Starting test_waitForInitialNavigation_initialDocumentFinishedLoadingNoAdditionalLoad
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  (xpcshell/head.js) | test test_waitForInitialNavigation_initialDocumentFinishedLoadingNoAdditionalLoad pending (2)
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.521Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  } pending (3)
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  (xpcshell/head.js) | test run_next_test 3 finished (3)
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  } pending (2)
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  (xpcshell/head.js) | test function () {
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -      [native code]
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  } finished (2)
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentFinishedLoadingNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentFinishedLoadingNoAdditionalLoad : 256] Document is not loading - true == true
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  TEST-PASS | remote/shared/test/xpcshell/test_Navigate.js | test_waitForInitialNavigation_initialDocumentFinishedLoadingNoAdditionalLoad - [test_waitForInitialNavigation_initialDocumentFinishedLoadingNoAdditionalLoad : 260] waitForInitialNavigationCompleted has not resolved yet - true == true
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  <<<<<<<
[task 2023-05-30T10:43:58.522Z] 10:43:58     INFO -  xpcshell return code: None
[task 2023-05-30T10:43:58.523Z] 10:43:58     INFO -  remote/shared/test/xpcshell/test_Navigate.js | Process still running after test!
[task 2023-05-30T10:43:58.523Z] 10:43:58     INFO -  TEST-START | toolkit/crashreporter/test/unit_ipc/test_content_memory_list.js

BugBot [:suhaib / :marco/ :calixte]

Comment 1

•

1 year ago

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

:jdescottes, since you are the author of the regressor, bug 1816538, could you take a look?

For more information, please visit BugBot documentation.

status-firefox113: --- → unaffected

status-firefox114: --- → unaffected

status-firefox115: --- → affected

status-firefox-esr102: --- → unaffected

Flags: needinfo?(jdescottes)

Julian Descottes [:jdescottes]

Assignee

Comment 2

•

1 year ago

Thanks for the ping.

The xpcshell tests for waitForInitialNavigation actually only pass thanks to the "no navigation detected" timeout today (which is an overlook from the initial implementation I believe).

Since on ccov we get a x16 multiplier for the timeout, it means the test takes a really long time. My patch over at https://phabricator.services.mozilla.com/D178817 was rewriting the tests to stop relying on that I will port that here.

Assignee: nobody → jdescottes

Status: NEW → ASSIGNED

Flags: needinfo?(jdescottes)

Priority: P5 → P1

Whiteboard: [webdriver:m7]

Julian Descottes [:jdescottes]

Assignee

Comment 3

•

1 year ago

Attached file Bug 1835796 - [remote] Do not rely on navigation timeouts in test_Navigate for waitForInitialNavigation (obsolete) — Details

Phabricator Automation

Updated

•

1 year ago

Attachment #9336535 - Attachment is obsolete: true

Julian Descottes [:jdescottes]

Assignee

Comment 4

•

1 year ago

Fixed by backout: https://hg.mozilla.org/integration/autoland/rev/a68845330c9a36a1f86120058875cc34c29a274c

Status: ASSIGNED → RESOLVED

Closed: 1 year ago

Resolution: --- → FIXED

Ryan VanderMeulen [:RyanVM]

Updated

•

1 year ago

status-firefox115: affected → fixed

Target Milestone: --- → 115 Branch

Comment hidden (Intermittent Failures Robot)

Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)

Updated

•

3 months ago

Whiteboard: [webdriver:m7] → [webdriver:m7][webdriver:external]

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

Bugzilla

Quick Search

Perma [tier 2] remote/shared/test/xpcshell/test_Navigate.js | Test timed out

Categories

(Remote Protocol :: Agent, defect, P1)

Tracking

(firefox-esr102 unaffected, firefox113 unaffected, firefox114 unaffected, firefox115 fixed)

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [webdriver:m7][webdriver:external])

Crash Data

Security

(public)

User Story

Attachments

(1 obsolete file)

Description

Comment 1

Comment 2

Comment 3

Updated

Comment 4

Updated

Comment 5

Updated

Attachment

General

Description

File Name

Content Type