1695447 - Intermittent toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 122] Duration is reasonable - false == true

Status: RESOLVED DUPLICATE of bug 1760094

(Toolkit :: Async Tooling, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-02-27T15:22:00.895Z] 15:22:00     INFO -  TEST-START | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js
[task 2021-02-27T15:22:03.526Z] 15:22:03  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | xpcshell return code: 0
[task 2021-02-27T15:22:03.527Z] 15:22:03     INFO -  TEST-INFO took 2632ms
[task 2021-02-27T15:22:03.528Z] 15:22:03     INFO -  >>>>>>>
[task 2021-02-27T15:22:03.528Z] 15:22:03     INFO -  PID 8292 | *** You are running in chaos test mode. See ChaosMode.h. ***
[task 2021-02-27T15:22:03.529Z] 15:22:03     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2021-02-27T15:22:03.529Z] 15:22:03     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2021-02-27T15:22:03.529Z] 15:22:03     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2021-02-27T15:22:03.530Z] 15:22:03     INFO -  running event loop
[task 2021-02-27T15:22:03.530Z] 15:22:03     INFO -  toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | Starting init
[task 2021-02-27T15:22:03.531Z] 15:22:03     INFO -  (xpcshell/head.js) | test init pending (2)
[task 2021-02-27T15:22:03.532Z] 15:22:03     INFO -  "Initializing the Terminator"
[task 2021-02-27T15:22:03.533Z] 15:22:03     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2021-02-27T15:22:03.534Z] 15:22:03     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2021-02-27T15:22:03.534Z] 15:22:03     INFO -  (xpcshell/head.js) | test init finished (2)
[task 2021-02-27T15:22:03.534Z] 15:22:03     INFO -  toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | Starting test_record
[task 2021-02-27T15:22:03.535Z] 15:22:03     INFO -  (xpcshell/head.js) | test test_record pending (2)
[task 2021-02-27T15:22:03.535Z] 15:22:03     INFO -  "Starting shutdown"
[task 2021-02-27T15:22:03.535Z] 15:22:03     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2021-02-27T15:22:03.536Z] 15:22:03     INFO -  "Moving to next phase"
[task 2021-02-27T15:22:03.536Z] 15:22:03     INFO -  "Waiting for file creation: /tmp/xpc-profile-59N_g9/ShutdownDuration.json"
[task 2021-02-27T15:22:03.538Z] 15:22:03     INFO -  "The file has been created"
[task 2021-02-27T15:22:03.538Z] 15:22:03     INFO -  "{"profile-change-teardown": 2, "profile-before-change": 0}"
[task 2021-02-27T15:22:03.539Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 78] The file contains the expected key - true == true
[task 2021-02-27T15:22:03.539Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 80] "number" == "number"
[task 2021-02-27T15:22:03.539Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 81] Duration is a non-negative number - true == true
[task 2021-02-27T15:22:03.539Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 82] Duration is reasonable - true == true
[task 2021-02-27T15:22:03.540Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 87] Data does not contain other durations - 2 == 2
[task 2021-02-27T15:22:03.540Z] 15:22:03     INFO -  "Cleaning up and moving to next phase"
[task 2021-02-27T15:22:03.540Z] 15:22:03     INFO -  "Waiting at least one tick"
[task 2021-02-27T15:22:03.540Z] 15:22:03     INFO -  "Waiting for file creation: /tmp/xpc-profile-59N_g9/ShutdownDuration.json"
[task 2021-02-27T15:22:03.540Z] 15:22:03     INFO -  "The file has been created"
[task 2021-02-27T15:22:03.541Z] 15:22:03     INFO -  "{"profile-change-teardown": 2, "profile-before-change": 23, "profile-before-change-qm": 0}"
[task 2021-02-27T15:22:03.541Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 106] The file contains the expected keys - "profile-before-change, profile-before-change-qm, profile-change-teardown" == "profile-before-change, profile-before-change-qm, profile-change-teardown"
[task 2021-02-27T15:22:03.541Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 113] Duration of phase 0 hasn't changed - 2 == 2
[task 2021-02-27T15:22:03.541Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 115] "number" == "number"
[task 2021-02-27T15:22:03.542Z] 15:22:03     INFO -  TEST-PASS | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 118] We have waited at least 10 ticks - true == true
[task 2021-02-27T15:22:03.542Z] 15:22:03  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/terminator/tests/xpcshell/test_terminator_record.js | test_record - [test_record : 122] Duration is reasonable - false == true```

Comment 1

[Intermittent Failures Robot]

1 failures in 4327 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1695447&startday=2021-02-22&endday=2021-02-28&tree=all

Comment 2

[Jens Stutte [:jstutte]]

OK, test_terminator_record.js is still very much assuming that ticks can be converted into wall-clock quite accurately. We probably need to relax that test.

Comment 3

[Intermittent Failures Robot]

1 failures in 3683 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1014-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1695447&startday=2021-03-01&endday=2021-03-07&tree=all

Comment 4

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 5

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=363943848&repo=autoland

Comment 6

[Intermittent Failures Robot]

1 failures in 3060 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1695447&startday=2022-01-10&endday=2022-01-16&tree=all

Comment 7

[Intermittent Failures Robot]

1 failures in 3444 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows7-32-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1695447&startday=2022-01-17&endday=2022-01-23&tree=all

Comment 8

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 9

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=370086842&repo=mozilla-central

Comment 10

[Intermittent Failures Robot]

1 failures in 3063 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows7-32-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1695447&startday=2022-02-28&endday=2022-03-06&tree=all

Comment 11

[Intermittent Failures Robot]

1 failures in 3304 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• windows7-32-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1695447&startday=2022-03-14&endday=2022-03-20&tree=all