Open Bug 1765445 Opened 3 years ago Updated 2 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | dom/workers/test/test_file.xhtml | application timed out after 370 seconds with no output

Categories

(Core :: DOM: Workers, defect)

Product:
Core
Component:
DOM: Workers
Type:
defect

Tracking

()

Status:
ASSIGNED
Tracking Flags:
Tracking Status
firefox-esr91 --- unaffected
firefox99 --- unaffected
firefox100 --- unaffected
firefox101 --- affected

People

(Reporter: intermittent-bug-filer, Assigned: farre, NeedInfo)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [retriggered][stockwell disabled])

Attachments

(1 file)

Bug 1765445 - disable test_file.xhtml on multiple platforms r?#intermittent-reviewers
(deleted), text/x-phabricator-request
Details

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

[task 2022-04-19T20:46:59.312Z] 20:46:59     INFO - TEST-PASS | dom/workers/test/test_file.xhtml | lastModified proproperty accessed from worker is incorrect. 
[task 2022-04-19T20:46:59.313Z] 20:46:59     INFO - Buffered messages finished
[task 2022-04-19T20:46:59.314Z] 20:46:59    ERROR - TEST-UNEXPECTED-TIMEOUT | dom/workers/test/test_file.xhtml | application timed out after 370 seconds with no output
[task 2022-04-19T20:46:59.315Z] 20:46:59    ERROR - Force-terminating active process(es).
[task 2022-04-19T20:46:59.316Z] 20:46:59     INFO - Determining child pids from psutil...
[task 2022-04-19T20:46:59.316Z] 20:46:59     INFO - []
[task 2022-04-19T20:46:59.317Z] 20:46:59     INFO - ==> process 6169 launched child process 6187
[task 2022-04-19T20:46:59.318Z] 20:46:59     INFO - Found child pids: {6187}
[task 2022-04-19T20:46:59.318Z] 20:46:59     INFO - Failed to get child procs
[task 2022-04-19T20:46:59.319Z] 20:46:59     INFO - Killing process: 6187
[task 2022-04-19T20:46:59.320Z] 20:46:59     INFO - TEST-INFO | started process screentopng
[task 2022-04-19T20:46:59.468Z] 20:46:59     INFO - TEST-INFO | screentopng: exit 0
[task 2022-04-19T20:46:59.468Z] 20:46:59     INFO - Can't trigger Breakpad, process no longer exists
[task 2022-04-19T20:46:59.469Z] 20:46:59     INFO - Killing process: 6169
[task 2022-04-19T20:46:59.470Z] 20:46:59     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-04-19T20:46:59.612Z] 20:46:59     INFO - psutil found pid 6169 dead
[task 2022-04-19T20:46:59.614Z] 20:46:59     INFO - TEST-INFO | Main app process: exit 0

It looks like I can't find the regression Bug for this, can somone please take a look? There are some retriggers and backfills. Thanks!

Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][triggered]
Whiteboard: [stockwell needswork:owner][triggered] → [stockwell needswork:owner][retriggered]

First fail so far is here.

Flags: needinfo?(jstutte)
Regressed by: 1764251
Flags: needinfo?(jstutte)
No longer regressed by: 1764251

There are 65 failures in the last 5 days.

  • 35 failures on linux1804-64-qr
  • 21 failures on windows10-32/64-2004-qr
  • 9 failures on macosx1015-64-qr

Andreas, I did some extra retriggs and the failure seem to have started from bug 1739450.

Log snippet:

[task 2022-04-22T06:45:05.482Z] 06:45:05     INFO - TEST-START | dom/workers/test/test_file.xhtml
[task 2022-04-22T06:45:05.487Z] 06:45:05     INFO - GECKO(6205) | [Parent 6205, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:180
[task 2022-04-22T06:45:05.489Z] 06:45:05     INFO - GECKO(6205) | [Parent 6205, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/security/nsCSPService.cpp:190
[task 2022-04-22T06:45:05.515Z] 06:45:05     INFO - GECKO(6205) | [Parent 6205, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:197
[task 2022-04-22T06:45:05.622Z] 06:45:05     INFO - GECKO(6205) | [Parent 6205, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:45
[task 2022-04-22T06:45:05.623Z] 06:45:05     INFO - GECKO(6205) | [Parent 6205, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:57
[task 2022-04-22T06:45:05.695Z] 06:45:05     INFO - GECKO(6205) | [Parent 6205, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:197
[task 2022-04-22T06:51:15.696Z] 06:51:15     INFO - Buffered messages finished
[task 2022-04-22T06:51:15.697Z] 06:51:15    ERROR - TEST-UNEXPECTED-TIMEOUT | dom/workers/test/test_file.xhtml | application timed out after 370 seconds with no output
[task 2022-04-22T06:51:15.701Z] 06:51:15    ERROR - Force-terminating active process(es).
[task 2022-04-22T06:51:15.702Z] 06:51:15     INFO - Determining child pids from psutil...
[task 2022-04-22T06:51:15.702Z] 06:51:15     INFO - []
[task 2022-04-22T06:51:15.703Z] 06:51:15     INFO - ==> process 6205 launched child process 6223
[task 2022-04-22T06:51:15.703Z] 06:51:15     INFO - Found child pids: {6223}
[task 2022-04-22T06:51:15.704Z] 06:51:15     INFO - Failed to get child procs
[task 2022-04-22T06:51:15.704Z] 06:51:15     INFO - Killing process: 6223
[task 2022-04-22T06:51:15.705Z] 06:51:15     INFO - TEST-INFO | started process screentopng
[task 2022-04-22T06:51:15.855Z] 06:51:15     INFO - TEST-INFO | screentopng: exit 0
Flags: needinfo?(afarre)
Has Regression Range: --- → yes
Regressed by: 1739450

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

status-firefox100: --- → unaffected
status-firefox101: --- → affected
status-firefox99: --- → unaffected
status-firefox-esr91: --- → unaffected
Assignee: nobody → afarre
Status: NEW → ASSIGNED
Flags: needinfo?(afarre)

Let's wait if things settle a bit here before disabling.

Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell needswork:owner]

Hi :farre, should we disable the test until you are able to get to this? It's still pretty frequent, it seems.

Flags: needinfo?(afarre)

@farre: this has 116 total failures in the last 7 days and 227 total failures in the last 30 days. We're disabling it to reduce noise in trees.
Please re-enable the test in your fix.
Thank you.

Keywords: leave-open
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell disabled]
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/71a9b7b599b5 disable test_file.xhtml on multiple platforms r=intermittent-reviewers,jmaher DONTBUILD
Summary: High frequency TEST-UNEXPECTED-TIMEOUT | dom/workers/test/test_file.xhtml | application timed out after 370 seconds with no output → Intermittent TEST-UNEXPECTED-TIMEOUT | dom/workers/test/test_file.xhtml | application timed out after 370 seconds with no output
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: