Closed Bug 1662723 Opened 4 years ago Closed 4 years ago

Intermittent [fission] TEST-UNEXPECTED-TIMEOUT | dom/events/test/test_focus_blur_on_click_in_cross_origin_iframe.html | application timed out after 370 seconds with no output

Categories

(Core :: DOM: UI Events & Focus Handling, defect, P3)

Product:
Core
Component:
DOM: UI Events & Focus Handling
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
89 Branch
Project Flags:
Fission Milestone M7a
Tracking Flags:
Tracking Status
firefox89 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: edgar)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Bug 1662723 - Wait for APZ get stable in test_focus_blur_on_click_in_cross_origin_iframe.html;
(deleted), text/x-phabricator-request
Details

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

[task 2020-09-02T11:47:21.241Z] 11:47:21 INFO - TEST-START | dom/events/test/test_focus_blur_on_click_in_cross_origin_iframe.html
[task 2020-09-02T11:47:21.472Z] 11:47:21 INFO - GECKO(3370) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-09-02T11:47:21.472Z] 11:47:21 INFO - GECKO(3370) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-09-02T11:53:31.494Z] 11:53:31 INFO - Buffered messages logged at 11:47:21
[task 2020-09-02T11:53:31.495Z] 11:53:31 INFO - add_task | Entering test
[task 2020-09-02T11:53:31.496Z] 11:53:31 INFO - TEST-PASS | dom/events/test/test_focus_blur_on_click_in_cross_origin_iframe.html | undefined assertion name
[task 2020-09-02T11:53:31.497Z] 11:53:31 INFO - Buffered messages finished
[task 2020-09-02T11:53:31.497Z] 11:53:31 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/events/test/test_focus_blur_on_click_in_cross_origin_iframe.html | application timed out after 370 seconds with no output
[task 2020-09-02T11:53:31.498Z] 11:53:31 ERROR - Force-terminating active process(es).
[task 2020-09-02T11:53:31.498Z] 11:53:31 INFO - Determining child pids from psutil...
[task 2020-09-02T11:53:31.504Z] 11:53:31 INFO - [3647, 3722, 3435, 3469, 3781, 3545, 3564, 3752]
[task 2020-09-02T11:53:31.504Z] 11:53:31 INFO - ==> process 3370 launched child process 3397
[task 2020-09-02T11:53:31.505Z] 11:53:31 INFO - ==> process 3370 launched child process 3435
[task 2020-09-02T11:53:31.506Z] 11:53:31 INFO - ==> process 3370 launched child process 3469
[task 2020-09-02T11:53:31.506Z] 11:53:31 INFO - ==> process 3370 launched child process 3545
[task 2020-09-02T11:53:31.506Z] 11:53:31 INFO - ==> process 3370 launched child process 3564
[task 2020-09-02T11:53:31.506Z] 11:53:31 INFO - ==> process 3370 launched child process 3576
[task 2020-09-02T11:53:31.507Z] 11:53:31 INFO - ==> process 3370 launched child process 3617
[task 2020-09-02T11:53:31.507Z] 11:53:31 INFO - ==> process 3370 launched child process 3647
[task 2020-09-02T11:53:31.507Z] 11:53:31 INFO - ==> process 3370 launched child process 3722
[task 2020-09-02T11:53:31.508Z] 11:53:31 INFO - ==> process 3370 launched child process 3752
[task 2020-09-02T11:53:31.508Z] 11:53:31 INFO - ==> process 3370 launched child process 3781
[task 2020-09-02T11:53:31.508Z] 11:53:31 INFO - Found child pids: set([3617, 3781, 3397, 3752, 3722, 3435, 3564, 3469, 3576, 3545, 3647])
[task 2020-09-02T11:53:31.509Z] 11:53:31 INFO - Failed to get child procs
[task 2020-09-02T11:53:31.509Z] 11:53:31 INFO - Killing process: 3617

ahal hit this test failure when trying to to enable mochitest-plan in fission-xorigin mode on more platforms in bug 1694835.

https://treeherder.mozilla.org/jobs?repo=try&revision=a4813c46eff128482994870bf8a06677022cee24&selectedTaskRun=JGTMJjhBRCOOlMEd4wmgNw.0

Blocks: 1694835, fission-tests
Fission Milestone: --- → M7a
status-firefox89: --- → affected
Priority: P5 → P3
No longer blocks: 1694835

Jens, this intermittent test failure is failing more frequently over the last week, jumping from about 10 failures per week to over 30.

The Fission team also hit this test failure (just once) when trying to to enable mochitest-plan in fission-xorigin mode on more platforms in bug 1694835. But given how frequently this test is now failing for non-Fission, I don't think this bug is a Fission issue that needs to block Fission. CORRECTION: Looks like all these failures and the Intermittent Failures Robot's reports are with Fission.

https://treeherder.mozilla.org/jobs?repo=try&revision=a4813c46eff128482994870bf8a06677022cee24&selectedTaskRun=JGTMJjhBRCOOlMEd4wmgNw.0

No longer blocks: fission-tests, 1700781
Fission Milestone: M7a → ---
Flags: needinfo?(jstutte)
See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1700781

btw, intermittently-failing tests that fail more than 30 times per week are candidates for getting disabled by the Stockwell team.

(In reply to Intermittent Failures Robot from comment #35)

53 failures in 3125 pushes (0.017 failures/push) were associated with this bug in the last 7 days.

This is the #22 most frequent failure this week.
...
For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1662723&startday=2021-03-29&endday=2021-04-04&tree=all

Looks like all of these intermittent test failures over the last week are on Fission, so I am tentatively tracking this bug for the current Fission milestone, M7a.

Fission Milestone: --- → M7a

Hi Edgar, are you able to get to this?

Flags: needinfo?(jstutte) → needinfo?(echen)

Seems happen only on opt build, I could not reproduce locally or on pernosco.
I trigger a try push with adding some log to see if we could get some clue, https://treeherder.mozilla.org/#/jobs?repo=try&revision=922d5846c45bc68dda7010cd487544b66856e0ee.

Assignee: nobody → echen
Status: NEW → ASSIGNED
Flags: needinfo?(echen)

I found it seems pretty easy to reproduce a similar timeout on TV-fis on try. When intermittent happens, test does receive focus event, but doesn't receive any mouse event.

https://treeherder.mozilla.org/jobs?repo=try&group_state=expanded&revision=11c21bb35b9cc25d52f014aa307f17d913469921&selectedTaskRun=EOful_i8RSu2p4KO0098iQ.0

Okay, from the log, the mousedown and mouseup event isn't dispatched to the oop-iframe, but the top-level one.
This is usually because of the apz is not yet stable, test does do promiseApzFlushedRepaints, but it probably isn't enough, let's try waitUntilApzStable which will wait for the APZ in parent process to get stable as well.

Pushed by echen@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/2c22715fcef2 Wait for APZ get stable in test_focus_blur_on_click_in_cross_origin_iframe.html; r=hsivonen

https://hg.mozilla.org/mozilla-central/rev/2c22715fcef2

Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox89: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → 89 Branch

This is still occurring:

Failure log: https://treeherder.mozilla.org/logviewer?job_id=336321560&repo=autoland&lineNumber=2374

[task 2021-04-13T06:43:20.859Z] 06:43:20 INFO - TEST-PASS | dom/events/test/test_focus_blur_on_click_in_cross_origin_iframe.html | check initial state
[task 2021-04-13T06:43:20.859Z] 06:43:20 INFO - Buffered messages finished
[task 2021-04-13T06:43:20.859Z] 06:43:20 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/events/test/test_focus_blur_on_click_in_cross_origin_iframe.html | application timed out after 370 seconds with no output
[task 2021-04-13T06:43:20.859Z] 06:43:20 ERROR - Force-terminating active process(es).

Can we keep tracking the issue on this bug?
Thank you.

(In reply to Natalia Csoregi [:nataliaCs] from comment #49)

Can we keep tracking the issue on this bug?

Could you file a new bug for that?
That looks a bit strange, I saw the failure task has been retriggered multiple times, but all fail.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: