1611360 - Intermittent widget/tests/test_bug1151186.html | Test timed out.

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2020-01-24T02:59:48.769Z] 02:59:48 INFO - TEST-START | widget/tests/test_bug1151186.html
[task 2020-01-24T03:05:17.527Z] 03:05:17 INFO - TEST-INFO | started process screentopng
[task 2020-01-24T03:05:17.683Z] 03:05:17 INFO - TEST-INFO | screentopng: exit 0
[task 2020-01-24T03:05:17.684Z] 03:05:17 INFO - TEST-UNEXPECTED-FAIL | widget/tests/test_bug1151186.html | Test timed out.
[task 2020-01-24T03:05:17.685Z] 03:05:17 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:277:18
[task 2020-01-24T03:05:17.685Z] 03:05:17 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
[task 2020-01-24T03:05:17.685Z] 03:05:17 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:18
[task 2020-01-24T03:05:17.686Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.686Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.686Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.686Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.686Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.686Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - TestRunner.runTests/<@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:388:20
[task 2020-01-24T03:05:17.687Z] 03:05:17 INFO - promise callbackTestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:375:50
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:201:14
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:180:12
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:273:12
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:50:13
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:61:28
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:57:3
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:253:20
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - linkAndHookup@chrome://mochikit/content/harness.xhtml:45:3
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:50:13
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:61:28
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:57:3
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:258:18
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - loadTests@chrome://mochikit/content/harness.xhtml:24:14
[task 2020-01-24T03:05:17.688Z] 03:05:17 INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xhtml:48:12
[task 2020-01-24T03:05:18.526Z] 03:05:18 INFO - GECKO(7337) | MEMORY STAT | vsize 3269MB | residentFast 397MB | heapAllocated 147MB
[task 2020-01-24T03:05:18.527Z] 03:05:18 INFO - TEST-OK | widget/tests/test_bug1151186.html | took 329759ms
[task 2020-01-24T03:05:18.859Z] 03:05:18 INFO - TEST-PASS | widget/tests/test_bug1151186.html | The div element should be focused
[task 2020-01-24T03:05:18.859Z] 03:05:18 INFO - TEST-PASS | widget/tests/test_bug1151186.html | IME should be enabled
[task 2020-01-24T03:05:18.859Z] 03:05:18 ERROR - [SimpleTest.finish()] this test already called finish!
[task 2020-01-24T03:05:18.860Z] 03:05:18 INFO - TEST-UNEXPECTED-ERROR | widget/tests/test_bug1151186.html | called finish() multiple times
[task 2020-01-24T03:05:18.860Z] 03:05:18 INFO - TEST-INFO

Comment 1

[Razvan Maries]

Edwin, could you take a look?

Comment 2

[Intermittent Failures Robot]

17 failures in 4004 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 16
• mozilla-central: 1

Platform breakdown:

• linux1804-64-shippable-qr: 12
• linux1804-64-shippable: 4
• linux1804-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1611360&startday=2020-01-20&endday=2020-01-26&tree=all

Comment 3

[Edwin Takahashi (:egao | infrequent contributor)]

I'm not sure what I could do here - this appears to be an intermittent failure of this test which should be addressed by the test owner.

Transferring ni to :hsinyi - could you please have someone take a look, thanks!

Comment 4

[Intermittent Failures Robot]

19 failures in 2190 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #32 most frequent failure this week.

Repository breakdown:

• mozilla-central: 6
• autoland: 10
• try: 3

Platform breakdown:

• linux1804-64-shippable-qr: 12
• linux1804-64-devedition: 1
• linux1804-64-qr: 4
• linux1804-64-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1611360&startday=2020-01-27&endday=2020-02-02&tree=all

Comment 5

[Intermittent Failures Robot]

25 failures in 3364 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

This is the #24 most frequent failure this week.

Repository breakdown:

• mozilla-central: 5
• autoland: 15
• try: 5

Platform breakdown:

• linux1804-64-qr: 1
• linux1804-64-shippable-qr: 20
• linux1804-64: 1
• linux1804-64-shippable: 2
• linux1804-64-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1611360&startday=2020-02-03&endday=2020-02-09&tree=all

Comment 6

[Andreea Pavel [:apavel]]

There are 21 total failures in the last 7 days on linux1804-64-shippable-qr opt

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=287334297&repo=autoland&lineNumber=7846

[task 2020-02-03T16:58:07.572Z] 16:58:07 INFO - TEST-START | widget/tests/test_bug1151186.html
[task 2020-02-03T17:03:36.331Z] 17:03:36 INFO - TEST-INFO | started process screentopng
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - TEST-INFO | screentopng: exit 0
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - TEST-UNEXPECTED-FAIL | widget/tests/test_bug1151186.html | Test timed out.
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:277:18
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:18
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:170:15
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - TestRunner.runTests/<@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:388:20
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - promise callbackTestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:375:50
[task 2020-02-03T17:03:36.481Z] 17:03:36 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:201:14
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:180:12
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:273:12
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:50:13
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:61:28
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:57:3
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:253:20
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - linkAndHookup@chrome://mochikit/content/harness.xhtml:45:3
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:50:13
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:61:28
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:57:3
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:258:18
[task 2020-02-03T17:03:36.482Z] 17:03:36 INFO - loadTests@chrome://mochikit/content/harness.xhtml:24:14
[task 2020-02-03T17:03:36.483Z] 17:03:36 INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xhtml:48:12
[task 2020-02-03T17:03:37.340Z] 17:03:37 INFO - GECKO(7463) | MEMORY STAT | vsize 3239MB | residentFast 392MB | heapAllocated 148MB
[task 2020-02-03T17:03:37.363Z] 17:03:37 INFO - TEST-OK | widget/tests/test_bug1151186.html | took 329768ms
[task 2020-02-03T17:03:37.625Z] 17:03:37 INFO - TEST-PASS | widget/tests/test_bug1151186.html | The div element should be focused
[task 2020-02-03T17:03:37.626Z] 17:03:37 INFO - TEST-PASS | widget/tests/test_bug1151186.html | IME should be enabled
[task 2020-02-03T17:03:37.627Z] 17:03:37 ERROR - [SimpleTest.finish()] this test already called finish!
[task 2020-02-03T17:03:37.636Z] 17:03:37 INFO - TEST-UNEXPECTED-ERROR | widget/tests/test_bug1151186.html | called finish() multiple times
[task 2020-02-03T17:03:37.636Z] 17:03:37 INFO - TEST-INFO

Comment 7

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Attachment: Bug 1611360 - part 1: Make sure that test_bug1151186.html set focus to its window forcibly when the document does not receive focus event r=smaug!

For testing the original symptom of bug 1151186, this test needs to set focus
to a contenteditable editor from focus event listener of the documen.
However, according to the oranges, focus event for the document is not fired
as expected only on Linux. The reason is, the document sometimes does not get
focus automatically. Therefore, this patch tries to listen focus event first
for keeping original path. But if the document is not activated automatically,
sets focus to its window when next macro task runs.

Comment 8

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Attachment: Bug 1611360 - part 2: Change `test_bug1151186.html` to mochitest-plain r=smaug!

Now, we have SpecialPowers to use DOMWindowUtils. Therefore,
test_bug1151186.html can be a mochitest-plain and it's better since the
test checks behavior on web apps.

Depends on D62396

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3f29fd0e278e
part 1: Make sure that test_bug1151186.html set focus to its window forcibly when the document does not receive focus event r=smaug
https://hg.mozilla.org/integration/autoland/rev/39fd9ff27ad8
part 2: Change `test_bug1151186.html` to mochitest-plain r=smaug

Comment 10

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/3f29fd0e278e
https://hg.mozilla.org/mozilla-central/rev/39fd9ff27ad8

Comment 11

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/ea2de9b140e6
https://hg.mozilla.org/releases/mozilla-beta/rev/c709cccd7290

Comment 12

[Intermittent Failures Robot]

6 failures in 4690 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• try: 1
• mozilla-central: 3
• mozilla-beta: 1

Platform breakdown:

• linux1804-64-shippable-qr: 4
• linux1804-64-shippable: 1
• linux1804-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1611360&startday=2020-02-10&endday=2020-02-16&tree=all

Comment 13

[Intermittent Failures Robot]

2 failures in 4289 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 2

Platform breakdown:

• linux1804-64: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1611360&startday=2020-07-27&endday=2020-08-02&tree=all