Open Bug 1760099 Opened 2 years ago Updated 8 days ago

Intermittent toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js | single tracking bug

Categories

(Toolkit :: Application Update, defect, P3)

Product:
Toolkit
Component:
Application Update
Type:
defect

Tracking

()

Status:
REOPENED

People

(Reporter: jmaher, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

Attachments

(1 obsolete file)

No description provided.
Severity: -- → S3

Update:

There have been 40 failures within the last 7 days:

  • 18 failures on Windows 7 WebRender opt
  • 22 failures on Windows 7 WebRender Shippable opt

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

[task 2023-01-21T06:15:22.389Z] 06:15:22     INFO -  TEST-START | toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js
[task 2023-01-21T06:15:22.566Z] 06:15:22     INFO -  Failed to remove directory: C:\Users\task_1674279689\AppData\Local\Temp\xpc-other-8m2tmoej. Waiting.
[task 2023-01-21T06:15:22.789Z] 06:15:22  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js | xpcshell return code: 0
[task 2023-01-21T06:15:22.789Z] 06:15:22     INFO -  TEST-INFO took 399ms
[task 2023-01-21T06:15:22.789Z] 06:15:22     INFO -  >>>>>>>
[task 2023-01-21T06:15:22.790Z] 06:15:22     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2023-01-21T06:15:22.790Z] 06:15:22     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2023-01-21T06:15:22.790Z] 06:15:22     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2023-01-21T06:15:22.791Z] 06:15:22     INFO -  running event loop
[task 2023-01-21T06:15:22.791Z] 06:15:22     INFO -  toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js | Starting test_default_profile_does_not_exist
[task 2023-01-21T06:15:22.791Z] 06:15:22     INFO -  (xpcshell/head.js) | test test_default_profile_does_not_exist pending (2)
[task 2023-01-21T06:15:22.792Z] 06:15:22     INFO -  TEST-PASS | toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js | test_default_profile_does_not_exist - [test_default_profile_does_not_exist : 52] resource://testing-common is not substituted - true == true
[task 2023-01-21T06:15:22.792Z] 06:15:22     INFO -  PID 5776 | console.info: "launching background task" ({command:"Z:\\\\task_1674279689\\\\build\\\\application\\\\firefox\\\\firefox.exe", args:["--backgroundtask", "backgroundupdate"], extraEnv:{MOZ_BACKGROUNDTASKS_NO_DEFAULT_PROFILE:"1", XPCSHELL_TESTING_MODULES_URI:"file:///Z:/task_1674279689/build/tests/modules/"}})
[task 2023-01-21T06:15:22.793Z] 06:15:22     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2023-01-21T06:15:22.793Z] 06:15:22     INFO -  PID 5776 | 4648> *** You are running in background task mode. ***
[task 2023-01-21T06:15:22.793Z] 06:15:22     INFO -  PID 5776 | 4648> *** You are running in headless mode.
[task 2023-01-21T06:15:22.794Z] 06:15:22     INFO -  PID 5776 | 4648> console.error: BackgroundTasksManager:
[task 2023-01-21T06:15:22.794Z] 06:15:22     INFO -  PID 5776 | 4648>   Substitution set: resource://testing-common aliases file:///Z:/task_1674279689/build/tests/modules/
[task 2023-01-21T06:15:22.794Z] 06:15:22     INFO -  PID 5776 | 4648> console.error: BackgroundUpdate:
[task 2023-01-21T06:15:22.795Z] 06:15:22     INFO -  PID 5776 | 4648>   runBackgroundTask: backgroundupdate
[task 2023-01-21T06:15:22.795Z] 06:15:22     INFO -  PID 5776 | 4648> console.error: BackgroundUpdate:
[task 2023-01-21T06:15:22.795Z] 06:15:22     INFO -  PID 5776 | 4648>   runBackgroundTask: another instance is running
[task 2023-01-21T06:15:22.796Z] 06:15:22  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js | test_default_profile_does_not_exist - [test_default_profile_does_not_exist : 34] 11 == 21
[task 2023-01-21T06:15:22.796Z] 06:15:22     INFO -  Z:/task_1674279689/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js:test_default_profile_does_not_exist:34
[task 2023-01-21T06:15:22.797Z] 06:15:22     INFO -  Z:\task_1674279689\build\tests\xpcshell\head.js:_do_main:238
[task 2023-01-21T06:15:22.797Z] 06:15:22     INFO -  Z:\task_1674279689\build\tests\xpcshell\head.js:_execute_test:585
[task 2023-01-21T06:15:22.797Z] 06:15:22     INFO -  -e:null:1
[task 2023-01-21T06:15:22.797Z] 06:15:22     INFO -  exiting test
[task 2023-01-21T06:15:22.798Z] 06:15:22     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2023-01-21T06:15:22.798Z] 06:15:22     INFO -  _abort_failed_test@Z:\task_1674279689\build\tests\xpcshell\head.js:863:20
[task 2023-01-21T06:15:22.798Z] 06:15:22     INFO -  do_report_result@Z:\task_1674279689\build\tests\xpcshell\head.js:964:5
[task 2023-01-21T06:15:22.799Z] 06:15:22     INFO -  Assert<@Z:\task_1674279689\build\tests\xpcshell\head.js:71:21
[task 2023-01-21T06:15:22.799Z] 06:15:22     INFO -  Assert.prototype.report@resource://testing-common/Assert.sys.mjs:240:10
[task 2023-01-21T06:15:22.799Z] 06:15:22     INFO -  equal@resource://testing-common/Assert.sys.mjs:282:8
[task 2023-01-21T06:15:22.800Z] 06:15:22     INFO -  test_default_profile_does_not_exist@Z:/task_1674279689/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/unit_background_update/test_backgroundupdate_exitcodes.js:34:10
[task 2023-01-21T06:15:22.800Z] 06:15:22     INFO -  _do_main@Z:\task_1674279689\build\tests\xpcshell\head.js:238:6
[task 2023-01-21T06:15:22.801Z] 06:15:22     INFO -  _execute_test@Z:\task_1674279689\build\tests\xpcshell\head.js:585:5
[task 2023-01-21T06:15:22.801Z] 06:15:22     INFO -  @-e:1:1
[task 2023-01-21T06:15:22.801Z] 06:15:22     INFO -  exiting test

Nick, as the owner of this component, can you help us assign the bug to someone?
Thank you.

Flags: needinfo?(nrishel)
test_default_profile_does_not_exist - [test_default_profile_does_not_exist : 34] 11 == 21

BackgroundUpdate.EXIT_CODE = {
...
  // Another instance is running.
  OTHER_INSTANCE: 21,
};

:nalexander looks like a preceding test overrunning into this one causing this one to fail?

Flags: needinfo?(nrishel) → needinfo?(nalexander)

(In reply to Nick Rishel [:nrishel] from comment #16)

test_default_profile_does_not_exist - [test_default_profile_does_not_exist : 34] 11 == 21

BackgroundUpdate.EXIT_CODE = {
...
  // Another instance is running.
  OTHER_INSTANCE: 21,
};

:nalexander looks like a preceding test overrunning into this one causing this one to fail?

Yes, exactly. The issue is that xpcshell instances take the multi-process mutex, which causes the firefox --backgroundtask backgroundupdate invocation to bail. Inspecting a few of these failure runs, I see crash reporter tests timing out and evidence that those test processes remain:

[task 2023-01-23T21:44:40.138Z] 21:44:40     INFO -  rmtree() failed for "('\\\\?\\C:\\Users\\task_1674508474\\AppData\\Local\\Temp\\xpc-other-twkxpgoy',)". Reason: The process cannot access the file because it is being used by another process (13). Retrying...

So when the backgroundupdate task comes along, it fails because the lock is (legitimately) taken. We could avoid that by changing the background update lock behaviour while under test, but I'm loathe to do that: it makes it harder to reason about and test the behaviour we actually ship.

I notice that these test failures are mostly on Windows 7. Is it possible we just need to give the crash reporter tests longer timeouts on what might be older hardware? I don't know if we have data which would give us descriptive statistics on the runtime of the crash reporter tests on different hardware. Maybe jmaher could help us understand that question?

Ultimately, I strongly believe that this is another test failing and that test and the test harness not cleaning up correctly, and not the background update test itself.

Flags: needinfo?(nalexander) → needinfo?(jmaher)

win7 is a different beast- we are the only browser that supports win7, and we are looking to reduce our test coverage on win7.

can we run these tests sequentially, and not in parallel? It might be as easy as doing that, it is done for a lot of tests already:
https://searchfox.org/mozilla-central/search?q=run-sequentially&path=&case=false&regexp=false

It is very possible that we have bleedthrough from another test - parallel runs only add to that; we should have profile separation, but I am not sure about system wide events, etc.

Flags: needinfo?(jmaher)

(In reply to Joel Maher ( :jmaher ) (UTC -8) from comment #18)

win7 is a different beast- we are the only browser that supports win7, and we are looking to reduce our test coverage on win7.

can we run these tests sequentially, and not in parallel? It might be as easy as doing that, it is done for a lot of tests already:
https://searchfox.org/mozilla-central/search?q=run-sequentially&path=&case=false&regexp=false

Yes, and this test is labeled run-sequentially (which doesn't seem to be working), but it doesn't prevent the "bleedthrough" you suggest below.

It is very possible that we have bleedthrough from another test - parallel runs only add to that; we should have profile separation, but I am not sure about system wide events, etc.

Hence investigating timeouts...

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

Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE

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

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

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

Status: REOPENED → RESOLVED
Closed: 1 year ago → 10 months ago
Resolution: --- → INCOMPLETE

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

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Attachment #9384507 - Attachment is obsolete: true

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

Status: REOPENED → RESOLVED
Closed: 10 months ago → 3 months ago
Resolution: --- → INCOMPLETE

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

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

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

Status: REOPENED → RESOLVED
Closed: 3 months ago → 1 month ago
Resolution: --- → INCOMPLETE

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

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

Attachment

General

Creator:
Created:
Updated:
Size: