Closed Bug 1779133 Opened 4 years ago Closed 3 years ago

Intermittent condprof dom/quota/test/xpcshell/test_initTemporaryStorage.js | single tracking bug

Categories

(Core :: Storage: Quota Manager, defect, P5)

Product:
Core
Component:
Storage: Quota Manager
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, regression)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=384030749&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BmN3XyCZTxGfkxhRUmwpgw/runs/0/artifacts/public/logs/live_backing.log

[task 2022-07-12T00:12:18.221Z] 00:12:18     INFO -  TEST-START | dom/quota/test/xpcshell/test_initTemporaryStorage.js
[task 2022-07-12T00:12:20.913Z] 00:12:20  WARNING -  TEST-UNEXPECTED-FAIL | dom/quota/test/xpcshell/test_initTemporaryStorage.js | xpcshell return code: 0
[task 2022-07-12T00:12:20.924Z] 00:12:20     INFO -  TEST-INFO took 2692ms
[task 2022-07-12T00:12:20.924Z] 00:12:20     INFO -  >>>>>>>
[task 2022-07-12T00:12:20.924Z] 00:12:20     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2022-07-12T00:12:20.924Z] 00:12:20     INFO -  TEST-PASS | dom/quota/test/xpcshell/test_initTemporaryStorage.js | undefined assertion name - There should be a testSteps function - true == true
[task 2022-07-12T00:12:20.925Z] 00:12:20     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2022-07-12T00:12:20.925Z] 00:12:20     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2022-07-12T00:12:20.925Z] 00:12:20     INFO -  running event loop
[task 2022-07-12T00:12:20.925Z] 00:12:20     INFO -  dom/quota/test/xpcshell/test_initTemporaryStorage.js | Starting testSteps
[task 2022-07-12T00:12:20.925Z] 00:12:20     INFO -  (xpcshell/head.js) | test testSteps pending (2)
[task 2022-07-12T00:12:20.926Z] 00:12:20     INFO -  "Initializing"
[task 2022-07-12T00:12:20.926Z] 00:12:20     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2022-07-12T00:12:20.926Z] 00:12:20     INFO -  "Verifying initialization status"
[task 2022-07-12T00:12:20.926Z] 00:12:20     INFO -  TEST-PASS | dom/quota/test/xpcshell/test_initTemporaryStorage.js | testSteps - [testSteps : 1] Initialization status is consistent - true == true
[task 2022-07-12T00:12:20.926Z] 00:12:20     INFO -  TEST-PASS | dom/quota/test/xpcshell/test_initTemporaryStorage.js | testSteps - [testSteps : 1] Storage is initialized - true == true
[task 2022-07-12T00:12:20.927Z] 00:12:20     INFO -  TEST-PASS | dom/quota/test/xpcshell/test_initTemporaryStorage.js | testSteps - [testSteps : 1] Temporary storage is not initialized - true == true
[task 2022-07-12T00:12:20.927Z] 00:12:20     INFO -  "Creating an empty directory"
[task 2022-07-12T00:12:20.927Z] 00:12:20     INFO -  "Initializing the temporary storage"
[task 2022-07-12T00:12:20.927Z] 00:12:20     INFO -  "Verifying directory metadata was restored after calling initTemporaryStorage()"
[task 2022-07-12T00:12:20.929Z] 00:12:20  WARNING -  TEST-UNEXPECTED-FAIL | dom/quota/test/xpcshell/test_initTemporaryStorage.js | testSteps - [testSteps : 44] Directory metadata file does exist - false == true
[task 2022-07-12T00:12:20.929Z] 00:12:20     INFO -  Z:/task_165758038525394/build/tests/xpcshell/tests/dom/quota/test/xpcshell/test_initTemporaryStorage.js:testSteps:44
[task 2022-07-12T00:12:20.929Z] 00:12:20     INFO -  Z:\task_165758038525394\build\tests\xpcshell\head.js:_do_main:238
[task 2022-07-12T00:12:20.929Z] 00:12:20     INFO -  Z:\task_165758038525394\build\tests\xpcshell\head.js:_execute_test:595
[task 2022-07-12T00:12:20.929Z] 00:12:20     INFO -  -e:null:1
[task 2022-07-12T00:12:20.930Z] 00:12:20     INFO -  exiting test
[task 2022-07-12T00:12:20.930Z] 00:12:20     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2022-07-12T00:12:20.930Z] 00:12:20     INFO -  _abort_failed_test@Z:\task_165758038525394\build\tests\xpcshell\head.js:866:20
[task 2022-07-12T00:12:20.930Z] 00:12:20     INFO -  do_report_result@Z:\task_165758038525394\build\tests\xpcshell\head.js:967:5
[task 2022-07-12T00:12:20.930Z] 00:12:20     INFO -  Assert<@Z:\task_165758038525394\build\tests\xpcshell\head.js:73:21
[task 2022-07-12T00:12:20.930Z] 00:12:20     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2022-07-12T00:12:20.931Z] 00:12:20     INFO -  proto.ok@resource://testing-common/Assert.jsm:254:10
[task 2022-07-12T00:12:20.931Z] 00:12:20     INFO -  testSteps@Z:/task_165758038525394/build/tests/xpcshell/tests/dom/quota/test/xpcshell/test_initTemporaryStorage.js:44:5
[task 2022-07-12T00:12:20.931Z] 00:12:20     INFO -  _do_main@Z:\task_165758038525394\build\tests\xpcshell\head.js:238:6
[task 2022-07-12T00:12:20.931Z] 00:12:20     INFO -  _execute_test@Z:\task_165758038525394\build\tests\xpcshell\head.js:595:5
[task 2022-07-12T00:12:20.931Z] 00:12:20     INFO -  @-e:1:1
[task 2022-07-12T00:12:20.932Z] 00:12:20     INFO -  exiting test
[task 2022-07-12T00:12:20.932Z] 00:12:20     INFO -  <<<<<<<
[task 2022-07-12T00:12:41.776Z] 00:12:41     INFO -  INFO | Result summary:
[task 2022-07-12T00:12:41.780Z] 00:12:41     INFO -  INFO | Passed: 29
[task 2022-07-12T00:12:41.780Z] 00:12:41  WARNING -  INFO | Failed: 1
[task 2022-07-12T00:12:41.780Z] 00:12:41  WARNING -  One or more unittests failed.
[task 2022-07-12T00:12:41.780Z] 00:12:41     INFO -  INFO | Todo: 0
[task 2022-07-12T00:12:41.780Z] 00:12:41     INFO -  INFO | Retried: 1
[task 2022-07-12T00:12:41.780Z] 00:12:41     INFO -  SUITE-END | took 998s
[task 2022-07-12T00:12:41.781Z] 00:12:41     INFO -  Node moz-http2 server shutting down ...
[task 2022-07-12T00:12:41.782Z] 00:12:41     INFO -  http3Server server shutting down ...
[task 2022-07-12T00:12:41.966Z] 00:12:41    ERROR - Return code: 1
[task 2022-07-12T00:12:41.966Z] 00:12:41     INFO - TinderboxPrint: xpcshell-xpcshell<br/>29/<em class="testfail">1</em>/0
[task 2022-07-12T00:12:41.966Z] 00:12:41  WARNING - # TBPL FAILURE #
[task 2022-07-12T00:12:41.966Z] 00:12:41  WARNING - setting return code to 2
[task 2022-07-12T00:12:41.966Z] 00:12:41  WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE
Regressed by: 1667455

Hi Tooru. Please take a look.

Flags: needinfo?(arai.unmht)

The same test passes on autoland, immediately before the merge
https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=test-windows10-64-2004-shippable-qr%2Fopt-xpcshell-condprof&revision=0fa881dedc30efcf53f1419737a9f3d7d2fc5521

So there might be something special with either the merge, or with automation on m-c.

So far, I've triggered the same test on the bug 1667455's push on autoland (before the above push):
https://treeherder.mozilla.org/jobs?repo=autoland&revision=563470602734975ceb761dc38415bf0fd2bc1058&searchStr=windows%2Cship

and the merge, on try:
https://treeherder.mozilla.org/jobs?repo=try&revision=8cbc8024191bf729bd14f224f545d9ffd8fad26b

and backing out bug 1667455's patches after the merge, on try:
https://treeherder.mozilla.org/jobs?repo=try&revision=b29adf4a998d2e30e0f7d0ed3bce5c1aad3b20ac

waiting for the results.

the test doesn't fail with any of the above.

:jmaher, can you look into this? is this something special with condprof + m-c?

Flags: needinfo?(jmaher)

retriggered the tests to see if there's any change now

retriggered on m-c merge push, and it now passes

https://treeherder.mozilla.org/jobs?repo=mozilla-central&selectedTaskRun=SNb-BAqrQxezfb8jgsUq8A.0&group_state=expanded&revision=e0683c733cf9569c6fde4f57852efbb2befc8740&searchStr=windows%2Cship%2Ccondprof

also, I've checked if profile-win64-full-default.tgz artifact downloaded there affects the issue.
There are 2 runs for each, before/after the artifact gets updated.

both on autoland and try, the test passes with both profile artifacts.
on m-c, the test fails with previous profile artifact, but passes with the new artifact.

there may be some more things affecting.

[autoland, before merge]

https://treeherder.mozilla.org/jobs?repo=autoland&revision=563470602734975ceb761dc38415bf0fd2bc1058&searchStr=windows%2Cship

[try, merge]

https://firefoxci.taskcluster-artifacts.net/SsslFDxYSw-39NPu7bvnVA/0/public/condprof/profile-win64-full-default.tgz

[m-c, merge]

https://treeherder.mozilla.org/jobs?repo=mozilla-central&revision=e0683c733cf9569c6fde4f57852efbb2befc8740&searchStr=condprof&selectedTaskRun=Jz4ZMEqtTTqYCNaZHxolVQ.0

Flags: needinfo?(arai.unmht)

it sounds intermittent? One quirk with automation is that we generate a profile for every push on m-c which gets put into the index- all tests pull from the index (which makes it less deterministic). In this scenario, I wonder if the profile used for the failing tests was causing a problem.

When we generate the profile we download the old profile, launch a browser with it, then browser a bunch- it could be there is an edge case with the specific profile.

Flags: needinfo?(jmaher)

Yeah, I thought it comes from profile, but the same profile works on autoland and try.
maybe there's also some other file than profile-win64-full-default.tgz ?

anyway, this is not a regression from bug 1667455.

No longer regressed by: 1667455

please keep in mind that the profile could be changed an hour later. There are no differences in the tooling or artifacts used between autoland and central. Quite likely the only difference is that mozilla-central runs ALL the tests, where autoland runs the most relevant manifests per push (and then every XX pushes a backstop runs the full set)

Summary: Perma condprof dom/quota/test/xpcshell/test_initTemporaryStorage.js | single tracking bug → Intermittent condprof dom/quota/test/xpcshell/test_initTemporaryStorage.js | single tracking bug

No failures here since the 11th so let's close as incomplete for now: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2022-07-10&endday=2022-07-17&tree=trunk&bug=1779133

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE

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

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

Status: REOPENED → RESOLVED
Closed: 4 years ago → 4 years ago
Resolution: --- → INCOMPLETE

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

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

Status: REOPENED → RESOLVED
Closed: 4 years ago → 3 years ago
Resolution: --- → INCOMPLETE

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

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

Status: REOPENED → RESOLVED
Closed: 3 years ago → 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.