Closed Bug 1830043 Opened 2 years ago Closed 2 years ago

Intermittent TV netwerk/test/unit/test_trr_telemetry.js | xpcshell return code: 0 | The histogram TRR_SKIP_REASON_TRR_FIRST2 must contain (other)_2 - false == true

Categories

(Core :: Networking, defect, P2)

defect

Tracking

()

RESOLVED FIXED
116 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox112 --- unaffected
firefox113 --- unaffected
firefox114 --- wontfix
firefox115 --- wontfix
firefox116 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, test-verify-fail, Whiteboard: [necko-triaged])

Attachments

(1 file)

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


[task 2023-04-26T10:18:04.390Z] 10:18:04     INFO -  TEST-START | netwerk/test/unit/test_trr_telemetry.js
[task 2023-04-26T10:18:04.758Z] 10:18:04  WARNING -  TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_trr_telemetry.js | xpcshell return code: 0
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  TEST-INFO took 366ms
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  >>>>>>>
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  PID 4264 | *** You are running in chaos test mode. See ChaosMode.h. ***
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  PID 4264 | start!
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  TEST-PASS | netwerk/test/unit/test_trr_telemetry.js | setup - [setup : 10] "35422" != null
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  TEST-PASS | netwerk/test/unit/test_trr_telemetry.js | setup - [setup : 10] "35422" != ""
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2023-04-26T10:18:04.759Z] 10:18:04     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2023-04-26T10:18:04.760Z] 10:18:04     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2023-04-26T10:18:04.760Z] 10:18:04     INFO -  running event loop
[task 2023-04-26T10:18:04.760Z] 10:18:04     INFO -  netwerk/test/unit/test_trr_telemetry.js | Starting test_trr_lookup_mode_2
[task 2023-04-26T10:18:04.760Z] 10:18:04     INFO -  (xpcshell/head.js) | test test_trr_lookup_mode_2 pending (2)
[task 2023-04-26T10:18:04.761Z] 10:18:04     INFO -  TEST-PASS | netwerk/test/unit/test_trr_telemetry.js | test_trr_lookup_mode_2 - [test_trr_lookup_mode_2 : 35] asyncResolve ok - true == true
[task 2023-04-26T10:18:04.761Z] 10:18:04     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2023-04-26T10:18:04.761Z] 10:18:04     INFO -  "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2023-04-26T10:18:04.762Z] 10:18:04     INFO -  TEST-PASS | netwerk/test/unit/test_trr_telemetry.js | test_trr_lookup_mode_2 - [test_trr_lookup_mode_2 : 1] Checking that this is the correct callback - true == true
[task 2023-04-26T10:18:04.764Z] 10:18:04     INFO -  TEST-PASS | netwerk/test/unit/test_trr_telemetry.js | test_trr_lookup_mode_2 - [test_trr_lookup_mode_2 : 1] Checking status - 0 == 0
[task 2023-04-26T10:18:04.764Z] 10:18:04     INFO -  TEST-PASS | netwerk/test/unit/test_trr_telemetry.js | test_trr_lookup_mode_2 - [test_trr_lookup_mode_2 : 1] Checking result for test.example.com - "2.2.2.2" == "2.2.2.2"
[task 2023-04-26T10:18:04.765Z] 10:18:04  WARNING -  TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_trr_telemetry.js | test_trr_lookup_mode_2 - [test_trr_lookup_mode_2 : 409] The histogram TRR_SKIP_REASON_TRR_FIRST2 must contain (other)_2 - false == true
[task 2023-04-26T10:18:04.765Z] 10:18:04     INFO -  resource://testing-common/TelemetryTestUtils.sys.mjs:assertKeyedHistogramValue:409
[task 2023-04-26T10:18:04.766Z] 10:18:04     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_trr_telemetry.js:trrLookup:40
[task 2023-04-26T10:18:04.766Z] 10:18:04     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:238
[task 2023-04-26T10:18:04.766Z] 10:18:04     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:585
[task 2023-04-26T10:18:04.767Z] 10:18:04     INFO -  -e:null:1
[task 2023-04-26T10:18:04.767Z] 10:18:04     INFO -  exiting test
[task 2023-04-26T10:18:04.767Z] 10:18:04     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2023-04-26T10:18:04.767Z] 10:18:04     INFO -  _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:868:20
[task 2023-04-26T10:18:04.768Z] 10:18:04     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:977:5
[task 2023-04-26T10:18:04.768Z] 10:18:04     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:71:21
[task 2023-04-26T10:18:04.768Z] 10:18:04     INFO -  Assert.prototype.report@resource://testing-common/Assert.sys.mjs:240:10
[task 2023-04-26T10:18:04.768Z] 10:18:04     INFO -  Assert.prototype.ok@resource://testing-common/Assert.sys.mjs:266:10
[task 2023-04-26T10:18:04.769Z] 10:18:04     INFO -  assertKeyedHistogramValue@resource://testing-common/TelemetryTestUtils.sys.mjs:409:14
[task 2023-04-26T10:18:04.769Z] 10:18:04     INFO -  trrLookup@/builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_trr_telemetry.js:40:22
[task 2023-04-26T10:18:04.769Z] 10:18:04     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:238:6
[task 2023-04-26T10:18:04.770Z] 10:18:04     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:585:5
[task 2023-04-26T10:18:04.770Z] 10:18:04     INFO -  @-e:1:1
[task 2023-04-26T10:18:04.770Z] 10:18:04     INFO -  exiting test
[task 2023-04-26T10:18:04.770Z] 10:18:04     INFO -  "Force a GC"
[task 2023-04-26T10:18:04.771Z] 10:18:04     INFO -  <<<<<<<

:kershaw, since you are the author of the regressor, bug 1828944, could you take a look?

For more information, please visit auto_nag documentation.

Flags: needinfo?(kershaw)

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

Priority: P5 → P2
Whiteboard: [necko-triaged]

Maybe we can print the histogram values/keys so we can identify what's happening?

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

This hasn't failed since 2023-04-27. Maybe this is fixed, or maybe it hasn't been running so much.

Looks like it's only failed in verify mode.
I'll try to create a patch to fix this.

Flags: needinfo?(kershaw)
Assignee: nobody → kershaw
Status: NEW → ASSIGNED
Pushed by kjang@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/5192875817d6 Use TestUtils.waitForCondition to check if the histogram is available, r=necko-reviewers,jesup
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 116 Branch

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

  • If yes, please nominate the patch for beta approval.
  • If no, please set status-firefox115 to wontfix.

For more information, please visit BugBot documentation.

Flags: needinfo?(kershaw)
Flags: needinfo?(kershaw)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: