Closed Bug 1681368 Opened 1 year ago Closed 8 months ago

Intermittent dom/events/test/test_focus_blur_on_click_in_deep_cross_origin_iframe.html | Test timed out.

Categories

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

defect

Tracking

()

RESOLVED FIXED
89 Branch
Fission Milestone M8
Tracking Status
firefox-esr78 --- unaffected
firefox83 --- unaffected
firefox84 --- unaffected
firefox85 --- wontfix
firefox87 --- wontfix
firefox88 --- wontfix
firefox89 --- fixed

People

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

References

(Regression)

Details

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

Attachments

(2 files)

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


[task 2020-12-08T18:08:53.380Z] 18:08:53     INFO - TEST-START | dom/events/test/test_focus_blur_on_click_in_deep_cross_origin_iframe.html
[task 2020-12-08T18:08:53.651Z] 18:08:53     INFO - GECKO(1521) | [Parent 1521, IPDL Background] WARNING: Cannot record shutdown step, mConnection is nullptr: file /builds/worker/checkouts/gecko/dom/localstorage/ActorsParent.cpp:8027
[task 2020-12-08T18:08:53.706Z] 18:08:53     INFO - GECKO(1521) | [Child 1774, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3360
[task 2020-12-08T18:08:53.727Z] 18:08:53     INFO - GECKO(1521) | [Child 1774, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4339
[task 2020-12-08T18:08:54.038Z] 18:08:54     INFO - GECKO(1521) | [Parent 1521, IPDL Background] WARNING: Cannot record shutdown step, mConnection is nullptr: file /builds/worker/checkouts/gecko/dom/localstorage/ActorsParent.cpp:8027
[task 2020-12-08T18:08:54.194Z] 18:08:54     INFO - GECKO(1521) | [Child 1872, Main Thread] WARNING: '!topWindow', file /builds/worker/checkouts/gecko/dom/html/HTMLIFrameElement.cpp:240
[task 2020-12-08T18:08:54.202Z] 18:08:54     INFO - GECKO(1521) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpv70MZC.mozrunner/runtests_leaks_tab_pid1952.log
[task 2020-12-08T18:08:54.203Z] 18:08:54     INFO - GECKO(1521) | [1952, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-12-08T18:08:54.263Z] 18:08:54     INFO - GECKO(1521) | [Child 1872, Main Thread] WARNING: NS_ENSURE_TRUE(currentInner) failed: file /builds/worker/checkouts/gecko/dom/base/WindowDestroyedEvent.cpp:108
[task 2020-12-08T18:08:54.384Z] 18:08:54     INFO - GECKO(1521) | [Parent 1521, IPDL Background] WARNING: Cannot record shutdown step, mConnection is nullptr: file /builds/worker/checkouts/gecko/dom/localstorage/ActorsParent.cpp:8027
[task 2020-12-08T18:08:54.480Z] 18:08:54     INFO - GECKO(1521) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpv70MZC.mozrunner/runtests_leaks_tab_pid1963.log
[task 2020-12-08T18:08:54.493Z] 18:08:54     INFO - GECKO(1521) | [1963, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-12-08T18:08:54.508Z] 18:08:54     INFO - GECKO(1521) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-12-08T18:08:54.509Z] 18:08:54     INFO - GECKO(1521) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-12-08T18:08:54.592Z] 18:08:54     INFO - GECKO(1521) | [Child 1952, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:629
[task 2020-12-08T18:08:54.643Z] 18:08:54     INFO - GECKO(1521) | [Child 1872, Main Thread] WARNING: NS_ENSURE_TRUE(!doc->IsResourceDoc() && ((!doc->IsLoadedAsData() && aOwner->IsInComposedDoc()) || doc->IsStaticDocument())) failed: file /builds/worker/checkouts/gecko/dom/base/nsFrameLoader.cpp:415
[task 2020-12-08T18:08:54.771Z] 18:08:54     INFO - GECKO(1521) | [Child 1963, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:629
[task 2020-12-08T18:14:02.395Z] 18:14:02     INFO - TEST-INFO | started process screentopng
[task 2020-12-08T18:14:02.564Z] 18:14:02     INFO - TEST-INFO | screentopng: exit 0
[task 2020-12-08T18:14:02.565Z] 18:14:02     INFO - Buffered messages logged at 18:08:53
[task 2020-12-08T18:14:02.565Z] 18:14:02     INFO - add_task | Entering test 
[task 2020-12-08T18:14:02.566Z] 18:14:02     INFO - Buffered messages finished
[task 2020-12-08T18:14:02.566Z] 18:14:02     INFO - TEST-UNEXPECTED-FAIL | dom/events/test/test_focus_blur_on_click_in_deep_cross_origin_iframe.html | Test timed out. 
[task 2020-12-08T18:14:02.567Z] 18:14:02     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-12-08T18:14:02.567Z] 18:14:02     INFO -     reportError@SimpleTest/TestRunner.js:143:22
[task 2020-12-08T18:14:02.567Z] 18:14:02     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-12-08T18:14:03.411Z] 18:14:03     INFO - GECKO(1521) | MEMORY STAT | vsize 2668MB | residentFast 181MB | heapAllocated 13MB
[task 2020-12-08T18:14:03.428Z] 18:14:03     INFO - TEST-OK | dom/events/test/test_focus_blur_on_click_in_deep_cross_origin_iframe.html | took 310047ms
[task 2020-12-08T18:14:03.451Z] 18:14:03     INFO - Not taking screenshot here: see the one that was previously logged```

Bug 1660805 either intermittently adding to the execution time of this test or making it not make progress seems very odd.

I'll take a look. (In any case, let's rather keep this intermittent and let's not back out bug 1660805.)

Flags: needinfo?(hsivonen)

Keeping Henri's NI as he's going to look into this.

Flags: needinfo?(hsivonen)

There have been 75 total failures in the last 7 days, recent failure log.

Affected platforms are:

  • macosx1014-64-shippable-qr / macosx1014-64-qr opt
  • linux1804-64-shippable-qr / linux1804-64-shippable / linux1804-64-qr opt / linux1804-64-asan

Henri, are there any updates on this issue?

Flags: needinfo?(hsivonen)
Flags: needinfo?(hsivonen)
Assignee: nobody → abutkovits
Status: NEW → ASSIGNED
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a6f20e7d67c5
disable test_focus_blur_on_click_in_deep_cross_origin_iframe.html on Windows&Mac_64 for frequent failures. r=intermittent-reviewers,aki DONTBUILD
Keywords: leave-open
Assignee: abutkovits → nobody
Status: ASSIGNED → NEW
Whiteboard: [stockwell disabled]

I suspect this is the same symptom as bug 1662723 comment 41 where mouse event isn't dispatched to the expecting process, let's try if adding waitUntilApzStable helps.

See Also: → 1688862
Pushed by echen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4fc1c5188d9f
Wait for APZ get stable in test_focus_blur_on_click_in_deep_cross_origin_iframe.html; r=hsivonen
Assignee: nobody → echen
Status: NEW → RESOLVED
Closed: 8 months ago
Keywords: leave-open
Resolution: --- → FIXED
Duplicate of this bug: 1688862
Flags: needinfo?(hsivonen)
Target Milestone: --- → 89 Branch
See Also: → 1704741
Fission Milestone: --- → M8

This is still happening: https://treeherder.mozilla.org/logviewer?job_id=336757034&repo=autoland&lineNumber=3692
Edgar, should we make a new bug or reopen this bug to keep track of it?

Flags: needinfo?(echen)

There is a new bug to track it, bug 1704741. Thanks!

Flags: needinfo?(echen)
See Also: → 1709517
You need to log in before you can comment on or make changes to this bug.