Closed Bug 1760094 Opened 3 years ago Closed 1 year ago

Intermittent toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | single tracking bug

Categories

(Toolkit :: Async Tooling, defect, P3)

defect

Tracking

()

RESOLVED FIXED
121 Branch
Tracking Status
firefox121 --- fixed

People

(Reporter: jmaher, Assigned: jstutte)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [stockwell unknown])

Attachments

(1 file)

No description provided.
Severity: -- → S4

Update

There have been 33 failures within the last 7 days:

  • 5 failures on OS X 10.15 WebRender opt
  • 8 failures on OS X 10.15 WebRender Shippable opt
  • 20 failures on S X 11 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=435010370&repo=autoland&lineNumber=9066

[task 2023-11-04T20:52:34.795Z] 20:52:34     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 116] Duration of phase 2:profile-change-teardown is not too long - 1 <= 5
[task 2023-11-04T20:52:34.795Z] 20:52:34  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 125] Duration of phase 2:profile-change-teardown is not too short - 1 >= 2
[task 2023-11-04T20:52:34.795Z] 20:52:34     INFO -  /opt/worker/tasks/task_169912671668231/build/tests/xpcshell/tests/toolkit/components/terminator/tests/xpcshell/test_terminator_record.js:test_record:125
[task 2023-11-04T20:52:34.795Z] 20:52:34     INFO -  /opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:_do_main:245
[task 2023-11-04T20:52:34.795Z] 20:52:34     INFO -  /opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:_execute_test:592
[task 2023-11-04T20:52:34.795Z] 20:52:34     INFO -  -e:null:1
[task 2023-11-04T20:52:34.795Z] 20:52:34     INFO -  exiting test
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  _abort_failed_test@/opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:865:20
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  do_report_result@/opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:977:5
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  Assert<@/opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:70:21
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  Assert.prototype.report@resource://testing-common/Assert.sys.mjs:244:10
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  compareNumbers@resource://testing-common/Assert.sys.mjs:561:10
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  greaterOrEqual@resource://testing-common/Assert.sys.mjs:601:18
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  test_record@/opt/worker/tasks/task_169912671668231/build/tests/xpcshell/tests/toolkit/components/terminator/tests/xpcshell/test_terminator_record.js:125:14
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  _do_main@/opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:245:6
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  _execute_test@/opt/worker/tasks/task_169912671668231/build/tests/xpcshell/head.js:592:5
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  @-e:1:1
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  exiting test
[task 2023-11-04T20:52:34.796Z] 20:52:34     INFO -  <<<<<<<

Gijs, can you help us forward this?
Thank you.

Flags: needinfo?(gijskruitbosch+bugs)
Whiteboard: [stockwell needswork:owner]

Jens, could you take a look?

Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(jstutte)

I knew sleeps on Mac are less reliable for their effective wall-clock duration than on other OS, but this seems pretty much random? Measurements on Mac seem to count always significantly less terminator heartbeats than expected, and we already adjusted the test for this to some extent. We might want to disable this test for Mac until we fixed bug 1768795 ?

Flags: needinfo?(jstutte) → needinfo?(gijskruitbosch+bugs)
Depends on: 1768795
Flags: needinfo?(gijskruitbosch+bugs)

(In reply to Jens Stutte [:jstutte] from comment #83)

I knew sleeps on Mac are less reliable for their effective wall-clock duration than on other OS, but this seems pretty much random? Measurements on Mac seem to count always significantly less terminator heartbeats than expected, and we already adjusted the test for this to some extent. We might want to disable this test for Mac until we fixed bug 1768795 ?

What is the non-test effect of this issue on macOS? That is, is this likely to impact anything "in the real world", or just the test?

Flags: needinfo?(jstutte)

(In reply to :Gijs (he/him) from comment #84)

(In reply to Jens Stutte [:jstutte] from comment #83)

I knew sleeps on Mac are less reliable for their effective wall-clock duration than on other OS, but this seems pretty much random? Measurements on Mac seem to count always significantly less terminator heartbeats than expected, and we already adjusted the test for this to some extent. We might want to disable this test for Mac until we fixed bug 1768795 ?

What is the non-test effect of this issue on macOS? That is, is this likely to impact anything "in the real world", or just the test?

I assume the real-world impact is pretty low, but we could see terminator crashes much later than we would expect them, so processes longer hang around during shutdown if they hang. But I am throwing together a patch for bug 1768795 that might help here and solve that impact, too.

Flags: needinfo?(jstutte)

(In reply to Jens Stutte [:jstutte] from comment #85)

(In reply to :Gijs (he/him) from comment #84)

(In reply to Jens Stutte [:jstutte] from comment #83)

I knew sleeps on Mac are less reliable for their effective wall-clock duration than on other OS, but this seems pretty much random? Measurements on Mac seem to count always significantly less terminator heartbeats than expected, and we already adjusted the test for this to some extent. We might want to disable this test for Mac until we fixed bug 1768795 ?

What is the non-test effect of this issue on macOS? That is, is this likely to impact anything "in the real world", or just the test?

I assume the real-world impact is pretty low, but we could see terminator crashes much later than we would expect them, so processes longer hang around during shutdown if they hang. But I am throwing together a patch for bug 1768795 that might help here and solve that impact, too.

Would it be possible to (easily) check if this is happening in crash stats?

(In reply to :Gijs (he/him) from comment #86)

Would it be possible to (easily) check if this is happening in crash stats?

IIRC not on crash-stats. We have shutdown_phase_duration_ticks_[phase] telemetry for each phase, but those are not distinguishing between hang and normal shutdown, so we could only look there for outliers where the effective sleeping time is consistently lower than the expected time, not higher as we see here.

Assignee: nobody → jstutte
Status: NEW → ASSIGNED
No longer depends on: 1768795
See Also: → 1768795
Pushed by jstutte@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/154d83c9af14 Use wall-clock and include IO overhead in measurements in test_terminator_record.js. r=xpcom-reviewers,nika
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 121 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: