Closed Bug 1950795 Opened 11 months ago Closed 8 months ago

Intermittent browser/components/profiles/tests/browser/browser_test_last_tab.js | single tracking bug

Categories

(Toolkit :: Startup and Profile System, defect, P5)

defect

Tracking

()

RESOLVED FIXED
140 Branch
Tracking Status
firefox-esr128 --- unaffected
firefox135 --- unaffected
firefox136 --- unaffected
firefox137 --- wontfix
firefox138 --- wontfix
firefox139 --- fixed
firefox140 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, test-verify-fail, Whiteboard: [stockwell disabled])

Attachments

(3 files)

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=496772167&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WN-9z47QQa-NA_yJ6ISS_w/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/WN-9z47QQa-NA_yJ6ISS_w/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2025-02-27T03:01:04.614Z] 03:01:04     INFO - TEST-START | browser/components/profiles/tests/browser/browser_test_last_tab.js
[task 2025-02-27T03:01:05.000Z] 03:01:05     INFO - TEST-INFO | started process screentopng
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - TEST-INFO | screentopng: exit 0
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Buffered messages logged at 03:01:04
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Entering setup bound 
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Leaving setup bound 
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Entering test bound test_browser_remains_open_after_closing_last_profiles_tab
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Buffered messages finished
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - TEST-UNEXPECTED-FAIL | browser/components/profiles/tests/browser/browser_test_last_tab.js | The current uri is 'about:newtab' and the browser didn't close - Got "about:editprofile", expected "about:newtab"
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Stack trace:
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:test_is:1654
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochitests/content/browser/browser/components/profiles/tests/browser/browser_test_last_tab.js:test_browser_remains_open_after_closing_last_profiles_tab:58
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:handleTask:1170
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1242
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1383
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1153
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Not taking screenshot here: see the one that was previously logged
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - TEST-UNEXPECTED-FAIL | browser/components/profiles/tests/browser/browser_test_last_tab.js | There is only 1 tab open - Got 2, expected 1
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - Stack trace:
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:test_is:1654
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochitests/content/browser/browser/components/profiles/tests/browser/browser_test_last_tab.js:test_browser_remains_open_after_closing_last_profiles_tab:63
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:handleTask:1170
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1242
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1383
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1153
[task 2025-02-27T03:01:05.205Z] 03:01:05     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2025-02-27T03:01:50.991Z] 03:01:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2025-02-27T03:01:50.992Z] 03:01:50     INFO - TEST-UNEXPECTED-FAIL | browser/components/profiles/tests/browser/browser_test_last_tab.js | Test timed out - 
[task 2025-02-27T03:01:50.993Z] 03:01:50     INFO - GECKO(1082) | Completed ShutdownLeaks collections in process 1082
[task 2025-02-27T03:01:50.993Z] 03:01:50     INFO - TEST-START | Shutdown
[task 2025-02-27T03:01:50.993Z] 03:01:50     INFO - Browser Chrome Test Summary
[task 2025-02-27T03:01:50.994Z] 03:01:50     INFO - Passed:  48
[task 2025-02-27T03:01:50.994Z] 03:01:50     INFO - Failed:  3
[task 2025-02-27T03:01:50.994Z] 03:01:50     INFO - Todo:    0
[task 2025-02-27T03:01:50.995Z] 03:01:50     INFO - Mode:    e10s
[task 2025-02-27T03:01:50.995Z] 03:01:50     INFO - *** End BrowserChrome Test Results ***
[task 2025-02-27T03:01:51.007Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.007Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.008Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.008Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.008Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.009Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.009Z] 03:01:51     INFO - GECKO(1082) | Exiting due to channel error.
[task 2025-02-27T03:01:51.043Z] 03:01:51     INFO - TEST-INFO | Main app process: exit 0
[task 2025-02-27T03:01:51.044Z] 03:01:51     INFO - TEST-UNEXPECTED-FAIL | browser/components/profiles/tests/browser/browser_test_last_tab.js | Application shut down (without crashing) in the middle of a test!
[task 2025-02-27T03:01:51.044Z] 03:01:51     INFO - TEST-INFO took 46393ms
[task 2025-02-27T03:01:51.044Z] 03:01:51     INFO - runtests.py | Application ran for: 0:01:03.204042
[task 2025-02-27T03:01:51.045Z] 03:01:51     INFO - zombiecheck | Reading PID log: /tmp/tmpphvd1r8dpidlog
[task 2025-02-27T03:01:51.045Z] 03:01:51     INFO - ==> process 1082 launched child process 1157
[task 2025-02-27T03:01:51.046Z] 03:01:51     INFO - zombiecheck | Checking for orphan process with PID: 1157
[task 2025-02-27T03:01:51.046Z] 03:01:51     INFO - Stopping web server
[task 2025-02-27T03:01:51.050Z] 03:01:51     INFO - Server shut down.
[task 2025-02-27T03:01:51.051Z] 03:01:51     INFO - Web server killed.
[task 2025-02-27T03:01:51.051Z] 03:01:51     INFO - Stopping web socket server
[task 2025-02-27T03:01:51.052Z] 03:01:51     INFO - Stopping ssltunnel
[task 2025-02-27T03:01:51.052Z] 03:01:51     INFO - Stopping gst for v4l2loopback
[task 2025-02-27T03:01:51.053Z] 03:01:51  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2025-02-27T03:01:51.053Z] 03:01:51     INFO - runtests.py | Running tests: end.
[task 2025-02-27T03:01:51.093Z] 03:01:51     INFO - Buffered messages finished
[task 2025-02-27T03:01:51.093Z] 03:01:51     INFO -  TEST-INFO | checking window state
[task 2025-02-27T03:01:51.094Z] 03:01:51     INFO -  Browser Chrome Test Summary
[task 2025-02-27T03:01:51.094Z] 03:01:51     INFO -  	Passed: 48
[task 2025-02-27T03:01:51.094Z] 03:01:51     INFO -  	Failed: 3
[task 2025-02-27T03:01:51.095Z] 03:01:51     INFO -  	Todo: 0
[task 2025-02-27T03:01:51.095Z] 03:01:51     INFO -  	Mode: e10s
[task 2025-02-27T03:01:51.095Z] 03:01:51     INFO -  *** End BrowserChrome Test Results ***
[task 2025-02-27T03:01:51.096Z] 03:01:51     INFO - Buffered messages finished
[task 2025-02-27T03:01:51.096Z] 03:01:51     INFO - SUITE-END | took 63s
[task 2025-02-27T03:01:51.097Z] 03:01:51     INFO - SUITE-START | Running 1 tests
[task 2025-02-27T03:01:51.098Z] 03:01:51     INFO - :::
[task 2025-02-27T03:01:51.098Z] 03:01:51     INFO - ::: Test verification summary for:
[task 2025-02-27T03:01:51.099Z] 03:01:51     INFO - :::
[task 2025-02-27T03:01:51.099Z] 03:01:51     INFO - ::: browser/components/profiles/tests/browser/browser_test_last_tab.js
[task 2025-02-27T03:01:51.099Z] 03:01:51     INFO - :::
[task 2025-02-27T03:01:51.100Z] 03:01:51     INFO - ::: 1. Run each test 10 times in one browser. : FAIL
[task 2025-02-27T03:01:51.101Z] 03:01:51     INFO - ::: 2. Run each test 5 times in a new browser each time. : not run / incomplete
[task 2025-02-27T03:01:51.101Z] 03:01:51     INFO - ::: 3. Run each test 10 times in one browser, in chaos mode. : not run / incomplete
[task 2025-02-27T03:01:51.101Z] 03:01:51     INFO - ::: 4. Run each test 5 times in a new browser each time, in chaos mode. : not run / incomplete
[task 2025-02-27T03:01:51.102Z] 03:01:51     INFO - :::
[task 2025-02-27T03:01:51.102Z] 03:01:51     INFO - ::: Test verification FAILED!
[task 2025-02-27T03:01:51.102Z] 03:01:51     INFO - :::
[task 2025-02-27T03:01:51.102Z] 03:01:51     INFO - Buffered messages finished
[task 2025-02-27T03:01:51.103Z] 03:01:51     INFO - SUITE-END | took 0s
[task 2025-02-27T03:01:51.126Z] 03:01:51     INFO - Return code: 0
[task 2025-02-27T03:01:51.126Z] 03:01:51  WARNING - Got 4 unexpected statuses
[task 2025-02-27T03:01:51.126Z] 03:01:51     INFO - TinderboxPrint: mochitest-mochitest-browser-chrome<br/>8/<em class="testfail">4</em>/0
[task 2025-02-27T03:01:51.126Z] 03:01:51  WARNING - setting return code to 1
[task 2025-02-27T03:01:51.126Z] 03:01:51  WARNING - TinderboxPrint: Per-test run of .../browser/browser_test_last_tab.js<br/>: WARNING
[task 2025-02-27T03:01:51.126Z] 03:01:51     INFO - Per-test suites: {}
[task 2025-02-27T03:01:51.126Z] 03:01:51     INFO - Per-test suites: {}
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running post-action listener: _package_coverage_data
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running post-action listener: _resource_record_post_action
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running post-action listener: process_java_coverage_data
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - [mozharness: 2025-02-27 03:01:51.127235Z] Finished run-tests step (success)
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - [mozharness: 2025-02-27 03:01:51.127286Z] Running uninstall step.
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running pre-action listener: _resource_record_pre_action
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running main action method: uninstall
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Skipping uninstall for non-MSIX test
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running post-action listener: _resource_record_post_action
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - [mozharness: 2025-02-27 03:01:51.127501Z] Finished uninstall step (success)
[task 2025-02-27T03:01:51.127Z] 03:01:51     INFO - Running post-run listener: _resource_record_post_run
[task 2025-02-27T03:01:51.199Z] 03:01:51     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2025-02-27T03:01:51.201Z] 03:01:51     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": ".overall", "extraOptions": ["e10s", "taskcluster-projects/887720501152/machineTypes/c2-standard-4"], "subtests": [{"name": "cpu_percent", "value": 21.10620567375885}, {"name": "io_write_bytes", "value": 481439744}, {"name": "io.read_bytes", "value": 0}, {"name": "io_write_time", "value": 399796}, {"name": "io_read_time", "value": 0}]}, {"name": ".start-pulseaudio", "subtests": [{"name": "time", "value": 0.0211561599999186}, {"name": "cpu_percent", "value": 0}]}, {"name": ".install", "subtests": [{"name": "time", "value": 5.720319052999912}, {"name": "cpu_percent", "value": 25.454910714285717}]}, {"name": ".stage-files", "subtests": [{"name": "time", "value": 0.0004614429999492131}, {"name": "cpu_percent", "value": 0}]}, {"name": ".run-tests", "subtests": [{"name": "time", "value": 64.82203475300003}, {"name": "cpu_percent", "value": 20.696406491499225}]}, {"name": ".uninstall", "subtests": [{"name": "time", "value": 0.0001386429999001848}, {"name": "cpu_percent", "value": 0}]}]}
[task 2025-02-27T03:01:51.201Z] 03:01:51     INFO - Total resource usage - Wall time: 71s; CPU: Can't collect data; Read bytes: 0; Write bytes: 481439744; Read time: 0; Write time: 399796
[task 2025-02-27T03:01:51.201Z] 03:01:51     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2025-02-27T03:01:51.201Z] 03:01:51     INFO - TinderboxPrint: I/O write bytes / time<br/>481,439,744 / 399,796
[task 2025-02-27T03:01:51.201Z] 03:01:51     INFO - TinderboxPrint: CPU idle<br/>218.1 (77.7%)
[task 2025-02-27T03:01:51.202Z] 03:01:51     INFO - TinderboxPrint: CPU iowait<br/>3.9 (1.4%)
[task 2025-02-27T03:01:51.202Z] 03:01:51     INFO - TinderboxPrint: CPU system<br/>4.2 (1.5%)
[task 2025-02-27T03:01:51.202Z] 03:01:51     INFO - TinderboxPrint: CPU user<br/>54.5 (19.4%)
[task 2025-02-27T03:01:51.202Z] 03:01:51     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2025-02-27T03:01:51.202Z] 03:01:51     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-02-27T03:01:51.202Z] 03:01:51     INFO - install - Wall time: 6s; CPU: 25%; Read bytes: 0; Write bytes: 16740352; Read time: 0; Write time: 2508
[task 2025-02-27T03:01:51.203Z] 03:01:51     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-02-27T03:01:51.206Z] 03:01:51     INFO - run-tests - Wall time: 65s; CPU: 21%; Read bytes: 0; Write bytes: 464699392; Read time: 0; Write time: 397288
[task 2025-02-27T03:01:51.207Z] 03:01:51     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-02-27T03:01:51.326Z] 03:01:51  WARNING - returning nonzero exit status 1

:niklas, since you are the author of the regressor, bug 1934942, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(nbaumgardner)
Summary: Intermittent TV browser/components/profiles/tests/browser/browser_test_last_tab.js | single tracking bug → Intermittent browser/components/profiles/tests/browser/browser_test_last_tab.js | single tracking bug

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

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

There have been 89 total failures in the last 7 days.
There are:

  • 2 failures on linux1804-64-asan-qr opt
  • 21 failures on linux1804-64-qr opt and debug
  • 5 failures on linux1804-64-shippable-qr opt
  • 6 failures on linux1804-64-tsan-qr opt
  • 10 failures on macosx1015-64-qr opt and debug
  • 2 failures on macosx1015-64-shippable-qr opt
  • 15 failures on macosx1100-aarch64-shippable-qr opt
  • 5 failures on windows11-32-24h2 debug
  • 23 failures on windows11-64-24h2 asan and deug

Recent failure log.

Niklas, as you are the regressor of this bug, can you please take a look? Soon this test will be disabled for frequent failures.
Thank you.

Flags: needinfo?(nbaumgardner)
Flags: needinfo?(nbaumgardner)
Keywords: leave-open
Pushed by smolnar@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/a113c12c1798 Disable browser_test_last_tab.js on linux/mac/win for frequent failures r=intermittent-reviewers,jmaher DONTBUILD
Whiteboard: [stockwell disabled]
Pushed by dtownsend@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ba94011531f4 Fix race conditions in browser_test_last_tab.js. r=profiles-reviewers,niklas
Status: NEW → RESOLVED
Closed: 8 months ago
Keywords: leave-open
Resolution: --- → FIXED
Assignee: nobody → amarc
Assignee: amarc → dtownsend
Flags: needinfo?(nbaumgardner)
Target Milestone: --- → 140 Branch

The patch landed in nightly and beta is affected.
:mossop, is this bug important enough to require an uplift?

For more information, please visit BugBot documentation.

Flags: needinfo?(dtownsend)
Attachment #9484989 - Flags: approval-mozilla-beta?

firefox-beta Uplift Approval Request

  • User impact if declined: None
  • Code covered by automated testing: yes
  • Fix verified in Nightly: yes
  • Needs manual QE test: no
  • Steps to reproduce for manual QE testing: N/A
  • Risk associated with taking this patch: None
  • Explanation of risk level: This is a test only fix
  • String changes made/needed: None
  • Is Android affected?: no
Flags: needinfo?(dtownsend)
Attachment #9484989 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: