Closed Bug 1838981 Opened 1 year ago Closed 1 year ago

Intermittent TV TinderboxPrint: Per-test run of .../browser_privatebrowsing_about_default_promo.js<br/>: FAILURE

Categories

(Firefox :: Messaging System, defect)

Product:
Firefox
Component:
Messaging System
Type:
defect

Tracking

()

Status:
RESOLVED WORKSFORME
Tracking Flags:
Tracking Status
firefox-esr102 --- unaffected
firefox114 --- unaffected
firefox115 --- unaffected
firefox116 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, test-verify-fail)

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

[task 2023-06-16T22:31:10.128Z] 22:31:10     INFO - TEST-START | browser/components/privatebrowsing/test/browser/browser_privatebrowsing_about_default_promo.js
[task 2023-06-16T22:31:12.429Z] 22:31:12     INFO - GECKO(2632) | 1686954672427	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-06-16T22:31:13.219Z] 22:31:13     INFO - GECKO(2632) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-06-16T22:31:17.614Z] 22:31:17     INFO - GECKO(2632) | 1686954677612	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-06-16T22:31:19.366Z] 22:31:19     INFO - GECKO(2632) | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 324))
[task 2023-06-16T22:31:21.265Z] 22:31:21     INFO - GECKO(2632) | 1686954681264	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-06-16T22:31:24.657Z] 22:31:24     INFO - GECKO(2632) | 1686954684656	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-06-16T22:31:27.825Z] 22:31:27     INFO - GECKO(2632) | 1686954687824	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-06-16T22:31:32.243Z] 22:31:32     INFO - GECKO(2632) | 1686954692241	Marionette	TRACE	Received observer notification browser-delayed-startup-finished
[task 2023-06-16T22:31:36.747Z] 22:31:36     INFO - GECKO(2632) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2023-06-16T22:31:36.747Z] 22:31:36     INFO - GECKO(2632) | MEMORY STAT heapAllocated not supported in this build configuration.
[task 2023-06-16T22:31:36.748Z] 22:31:36     INFO - GECKO(2632) | MEMORY STAT | vsize 130560454MB | residentFast 1366MB
<...>
[task 2023-06-16T22:34:54.203Z] 22:34:54     INFO -  socket.timeout: Timed out waiting for connection on 127.0.0.1:2828!
[task 2023-06-16T22:34:54.204Z] 22:34:54    ERROR - Automation Error: Received unexpected exception while running application
[task 2023-06-16T22:34:54.204Z] 22:34:54    ERROR - 
[task 2023-06-16T22:34:54.205Z] 22:34:54     INFO - Stopping web server
[task 2023-06-16T22:34:54.253Z] 22:34:54     INFO - Server shut down.
[task 2023-06-16T22:34:54.273Z] 22:34:54     INFO - Web server killed.
[task 2023-06-16T22:34:54.274Z] 22:34:54     INFO - Stopping web socket server
[task 2023-06-16T22:34:54.293Z] 22:34:54     INFO - Stopping ssltunnel
[task 2023-06-16T22:34:54.314Z] 22:34:54     INFO - Stopping gst for v4l2loopback
[task 2023-06-16T22:34:54.314Z] 22:34:54     INFO - runtests.py | Running tests: end.
[task 2023-06-16T22:34:54.343Z] 22:34:54     INFO - Buffered messages finished
[task 2023-06-16T22:34:54.344Z] 22:34:54     INFO -  TEST-INFO | checking window state
[task 2023-06-16T22:34:54.345Z] 22:34:54     INFO -  Browser Chrome Test Summary
[task 2023-06-16T22:34:54.346Z] 22:34:54     INFO -  	Passed: 324
[task 2023-06-16T22:34:54.348Z] 22:34:54     INFO -  	Failed: 0
[task 2023-06-16T22:34:54.350Z] 22:34:54     INFO -  	Todo: 0
[task 2023-06-16T22:34:54.350Z] 22:34:54     INFO -  	Mode: e10s
[task 2023-06-16T22:34:54.351Z] 22:34:54     INFO -  *** End BrowserChrome Test Results ***
[task 2023-06-16T22:34:54.351Z] 22:34:54     INFO - Buffered messages finished
[task 2023-06-16T22:34:54.351Z] 22:34:54     INFO - SUITE-END | took 181s
[task 2023-06-16T22:34:54.351Z] 22:34:54     INFO - SUITE-START | Running 1 tests
[task 2023-06-16T22:34:54.351Z] 22:34:54     INFO - :::
[task 2023-06-16T22:34:54.351Z] 22:34:54     INFO - ::: Test verification summary for:
[task 2023-06-16T22:34:54.352Z] 22:34:54     INFO - :::
[task 2023-06-16T22:34:54.352Z] 22:34:54     INFO - ::: browser/components/privatebrowsing/test/browser/browser_privatebrowsing_about_default_promo.js
[task 2023-06-16T22:34:54.352Z] 22:34:54     INFO - :::
[task 2023-06-16T22:34:54.353Z] 22:34:54     INFO - ::: 1. Run each test 10 times in one browser. : Pass
[task 2023-06-16T22:34:54.354Z] 22:34:54     INFO - ::: 2. Run each test 5 times in a new browser each time. : FAIL
[task 2023-06-16T22:34:54.354Z] 22:34:54     INFO - ::: 3. Run each test 10 times in one browser, in chaos mode. : not run / incomplete
[task 2023-06-16T22:34:54.355Z] 22:34:54     INFO - ::: 4. Run each test 5 times in a new browser each time, in chaos mode. : not run / incomplete
[task 2023-06-16T22:34:54.356Z] 22:34:54     INFO - :::
[task 2023-06-16T22:34:54.356Z] 22:34:54     INFO - ::: Test verification FAILED!
[task 2023-06-16T22:34:54.357Z] 22:34:54     INFO - :::
[task 2023-06-16T22:34:54.358Z] 22:34:54     INFO - Buffered messages finished
[task 2023-06-16T22:34:54.358Z] 22:34:54     INFO - SUITE-END | took 0s
[task 2023-06-16T22:34:54.419Z] 22:34:54     INFO - Return code: 0
[task 2023-06-16T22:34:54.421Z] 22:34:54     INFO - TinderboxPrint: mochitest-mochitest-browser-chrome<br/>12/0/0
[task 2023-06-16T22:34:54.422Z] 22:34:54  WARNING - setting return code to 2
[task 2023-06-16T22:34:54.424Z] 22:34:54    ERROR - TinderboxPrint: Per-test run of .../browser_privatebrowsing_about_default_promo.js<br/>: FAILURE
[task 2023-06-16T22:34:54.425Z] 22:34:54     INFO - Per-test suites: {}
[task 2023-06-16T22:34:54.426Z] 22:34:54     INFO - Per-test suites: {}
[task 2023-06-16T22:34:54.427Z] 22:34:54     INFO - Running post-action listener: _package_coverage_data
[task 2023-06-16T22:34:54.428Z] 22:34:54     INFO - Running post-action listener: _resource_record_post_action
[task 2023-06-16T22:34:54.430Z] 22:34:54     INFO - Running post-action listener: process_java_coverage_data
[task 2023-06-16T22:34:54.431Z] 22:34:54     INFO - [mozharness: 2023-06-16 22:34:54.422178Z] Finished run-tests step (success)
[task 2023-06-16T22:34:54.432Z] 22:34:54     INFO - [mozharness: 2023-06-16 22:34:54.422243Z] Running uninstall step.
[task 2023-06-16T22:34:54.433Z] 22:34:54     INFO - Running pre-action listener: _resource_record_pre_action
[task 2023-06-16T22:34:54.434Z] 22:34:54     INFO - Running main action method: uninstall
[task 2023-06-16T22:34:54.435Z] 22:34:54     INFO - Skipping uninstall for non-MSIX test
[task 2023-06-16T22:34:54.436Z] 22:34:54     INFO - Running post-action listener: _resource_record_post_action
[task 2023-06-16T22:34:54.437Z] 22:34:54     INFO - [mozharness: 2023-06-16 22:34:54.422530Z] Finished uninstall step (success)
[task 2023-06-16T22:34:54.439Z] 22:34:54     INFO - Running post-run listener: _resource_record_post_run
[task 2023-06-16T22:34:54.557Z] 22:34:54     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2023-06-16T22:34:54.560Z] 22:34:54     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": ".overall", "extraOptions": ["e10s", "taskcluster-projects/887720501152/machineTypes/n2-standard-2"], "subtests": [{"name": "cpu_percent", "value": 55.68783403656822}, {"name": "io_write_bytes", "value": 2866802688}, {"name": "io.read_bytes", "value": 65159168}, {"name": "io_write_time", "value": 1119708}, {"name": "io_read_time", "value": 1336}]}, {"name": ".start-pulseaudio", "subtests": [{"name": "time", "value": 0.0254209041595459}, {"name": "cpu_percent", "value": 0}]}, {"name": ".install", "subtests": [{"name": "time", "value": 48.43215203285217}, {"name": "cpu_percent", "value": 50.774468085106385}]}, {"name": ".stage-files", "subtests": [{"name": "time", "value": 0.0027039051055908203}, {"name": "cpu_percent", "value": 0}]}, {"name": ".run-tests", "subtests": [{"name": "time", "value": 664.3610837459564}, {"name": "cpu_percent", "value": 56.04093655589126}]}, {"name": ".uninstall", "subtests": [{"name": "time", "value": 0.00019407272338867188}, {"name": "cpu_percent", "value": 0}]}]}
[task 2023-06-16T22:34:54.562Z] 22:34:54     INFO - Total resource usage - Wall time: 712s; CPU: Can't collect data; Read bytes: 65159168; Write bytes: 2866802688; Read time: 1336; Write time: 1119708
[task 2023-06-16T22:34:54.564Z] 22:34:54     INFO - TinderboxPrint: I/O read bytes / time<br/>65,159,168 / 1,336
[task 2023-06-16T22:34:54.565Z] 22:34:54     INFO - TinderboxPrint: I/O write bytes / time<br/>2,866,802,688 / 1,119,708
[task 2023-06-16T22:34:54.566Z] 22:34:54     INFO - TinderboxPrint: CPU idle<br/>627.2 (44.2%)
[task 2023-06-16T22:34:54.567Z] 22:34:54     INFO - TinderboxPrint: CPU system<br/>59.0 (4.2%)
[task 2023-06-16T22:34:54.568Z] 22:34:54     INFO - TinderboxPrint: CPU user<br/>730.9 (51.5%)
[task 2023-06-16T22:34:54.569Z] 22:34:54     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2023-06-16T22:34:54.570Z] 22:34:54     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-16T22:34:54.571Z] 22:34:54     INFO - install - Wall time: 48s; CPU: 51%; Read bytes: 212992; Write bytes: 1774628864; Read time: 0; Write time: 866840
[task 2023-06-16T22:34:54.572Z] 22:34:54     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-16T22:34:54.573Z] 22:34:54     INFO - run-tests - Wall time: 664s; CPU: 56%; Read bytes: 64593920; Write bytes: 1092145152; Read time: 1312; Write time: 252656
[task 2023-06-16T22:34:54.574Z] 22:34:54     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-16T22:34:54.641Z] 22:34:54  WARNING - returning nonzero exit status 2
[task 2023-06-16T22:34:54.698Z] cleanup

:aminomancer, since you are the author of the regressor, bug 1775956, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(shughes)

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

status-firefox114: --- → unaffected
status-firefox115: --- → unaffected
status-firefox116: --- → affected
status-firefox-esr102: --- → unaffected

The failures have not repeated.

Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → WORKSFORME
status-firefox116: affected → wontfix
Flags: needinfo?(shughes)
You need to log in before you can comment on or make changes to this bug.