Intermittent toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | single tracking bug
Categories
(WebExtensions :: General, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=497346095&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/flBPv4FBSyydHm3HJRBdaA/runs/0/artifacts/public/logs/live_backing.log
[task 2025-03-03T20:06:43.439Z] 20:06:43 INFO - TEST-START | toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js
[task 2025-03-03T20:09:26.918Z] 20:09:26 WARNING - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | xpcshell return code: 0
[task 2025-03-03T20:09:26.918Z] 20:09:26 INFO - TEST-INFO took 163478ms
[task 2025-03-03T20:09:26.918Z] 20:09:26 INFO - >>>>>>>
[task 2025-03-03T20:09:26.918Z] 20:09:26 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2025-03-03T20:09:26.918Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2025-03-03T20:09:26.919Z] 20:09:26 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2025-03-03T20:09:26.919Z] 20:09:26 INFO - running event loop
[task 2025-03-03T20:09:26.919Z] 20:09:26 INFO - toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | Starting setup check_remote
[task 2025-03-03T20:09:26.919Z] 20:09:26 INFO - (xpcshell/head.js) | test check_remote pending (2)
[task 2025-03-03T20:09:26.920Z] 20:09:26 INFO - TEST-PASS | toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - false == false
[task 2025-03-03T20:09:26.920Z] 20:09:26 INFO - TEST-PASS | toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | check_remote - [check_remote : 1] testing from extension process - true == true
[task 2025-03-03T20:09:26.920Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2025-03-03T20:09:26.920Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2025-03-03T20:09:26.920Z] 20:09:26 INFO - (xpcshell/head.js) | test check_remote finished (2)
[task 2025-03-03T20:09:26.921Z] 20:09:26 INFO - toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | Starting setup setup
[task 2025-03-03T20:09:26.921Z] 20:09:26 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2025-03-03T20:09:26.921Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2025-03-03T20:09:26.921Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2025-03-03T20:09:26.921Z] 20:09:26 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2025-03-03T20:09:26.921Z] 20:09:26 INFO - toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | Starting setup
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 3 pending (2)
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - (xpcshell/head.js) | test setup finished (2)
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | Starting test_round_trip_perf
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - (xpcshell/head.js) | test test_round_trip_perf pending (2)
[task 2025-03-03T20:09:26.922Z] 20:09:26 INFO - "Extension attached"
[task 2025-03-03T20:09:26.923Z] 20:09:26 INFO - (xpcshell/head.js) | test run_next_test 3 finished (2)
[task 2025-03-03T20:09:26.923Z] 20:09:26 WARNING - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js | test_round_trip_perf - [test_round_trip_perf : 126] Expected round trip time (32.29ms) to be less than 30ms - 32.29 <= 30
[task 2025-03-03T20:09:26.923Z] 20:09:26 INFO - /opt/worker/tasks/task_174103142889060/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js:test_round_trip_perf:126
[task 2025-03-03T20:09:26.923Z] 20:09:26 INFO - exiting test
[task 2025-03-03T20:09:26.923Z] 20:09:26 INFO - Unexpected exception NS_ERROR_ABORT:
[task 2025-03-03T20:09:26.924Z] 20:09:26 INFO - _abort_failed_test@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:869:20
[task 2025-03-03T20:09:26.924Z] 20:09:26 INFO - do_report_result@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:981:5
[task 2025-03-03T20:09:26.924Z] 20:09:26 INFO - Assert<@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:70:21
[task 2025-03-03T20:09:26.924Z] 20:09:26 INFO - Assert.prototype.report@resource://testing-common/Assert.sys.mjs:251:10
[task 2025-03-03T20:09:26.925Z] 20:09:26 INFO - compareNumbers@resource://testing-common/Assert.sys.mjs:568:10
[task 2025-03-03T20:09:26.925Z] 20:09:26 INFO - lessOrEqual@resource://testing-common/Assert.sys.mjs:652:18
[task 2025-03-03T20:09:26.925Z] 20:09:26 INFO - test_round_trip_perf@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js:126:10
[task 2025-03-03T20:09:26.925Z] 20:09:26 INFO - async*_run_next_test/<@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:1759:22
[task 2025-03-03T20:09:26.926Z] 20:09:26 INFO - _run_next_test@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:1759:38
[task 2025-03-03T20:09:26.926Z] 20:09:26 INFO - run@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:808:9
[task 2025-03-03T20:09:26.926Z] 20:09:26 INFO - _do_main@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:245:6
[task 2025-03-03T20:09:26.927Z] 20:09:26 INFO - _execute_test@/opt/worker/tasks/task_174103142889060/build/tests/xpcshell/head.js:596:5
[task 2025-03-03T20:09:26.927Z] 20:09:26 INFO - @-e:1:1
[task 2025-03-03T20:09:26.927Z] 20:09:26 INFO - exiting test
[task 2025-03-03T20:09:26.927Z] 20:09:26 INFO - <<<<<<<
[task 2025-03-03T20:09:26.932Z] 20:09:26 INFO - TEST-START | xpcshell-remote.toml:toolkit/components/extensions/test/xpcshell/test_ext_background_early_shutdown.js
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 31•5 months ago
|
||
I was looking at this test as part of auditing for non-deterministic uses of Date.now() following bug 1991910, and found this test, specifically https://searchfox.org/firefox-main/rev/21d3e8ab8b61715ddd39ac04c62a846fa79deddd/toolkit/components/extensions/test/xpcshell/test_ext_native_messaging_perf.js#81-132
Unfortunately, it is not easy to come up with a deterministic way for the test to pass. It tests the interaction between:
- Extension process
- Firefox parent process
- Subprocess worker (from Subprocess.sys.mjs)
- External application, a Python script in this case.
and tries to confirm whether it all finished in a reasonable amount of time. If the system was particularly busy, the time thresholds may not apply. Note that the original report here mentions a threshold of 30ms (60ms on debug), but the test is currently accepting 90ms following the changes in bug 1945470 (7 months ago). Sadly, the intermittent failures history does not keep that much history, so I cannot tell what the impact was of increasing the threshold to 90ms. In any case, this test is inherently prone to time-sensitive test failures, so ideally we'd fix it.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 40•2 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Description
•