1771945 - Intermittent org.mozilla.geckoview.test.PromptDelegateTest#selectTestDismiss | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms

Status: RESOLVED FIXED

(GeckoView :: General, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-05-31T15:55:20.692Z] 15:55:20     INFO -  TEST-START | org.mozilla.geckoview.test.PromptDelegateTest#selectTestDismiss
[task 2022-05-31T15:55:50.944Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=921
[task 2022-05-31T15:55:50.944Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-05-31T15:55:50.944Z] 15:55:50     INFO -  org.mozilla.geckoview.test | Error in selectTestDismiss(org.mozilla.geckoview.test.PromptDelegateTest):
[task 2022-05-31T15:55:50.945Z] 15:55:50     INFO -  org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-05-31T15:55:50.945Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-05-31T15:55:50.945Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-05-31T15:55:50.945Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-05-31T15:55:50.946Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-05-31T15:55:50.946Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForResult(UiThreadUtils.java:79)
[task 2022-05-31T15:55:50.946Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2661)
[task 2022-05-31T15:55:50.947Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PromptDelegateTest.selectTestDismiss(PromptDelegateTest.kt:458)
[task 2022-05-31T15:55:50.947Z] 15:55:50     INFO -  org.mozilla.geckoview.test |
[task 2022-05-31T15:55:50.947Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-05-31T15:55:50.947Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=selectTestDismiss
[task 2022-05-31T15:55:50.948Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-05-31T15:55:50.948Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-05-31T15:55:50.948Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-05-31T15:55:50.949Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-05-31T15:55:50.949Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-05-31T15:55:50.949Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-05-31T15:55:50.950Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForResult(UiThreadUtils.java:79)
[task 2022-05-31T15:55:50.950Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2661)
[task 2022-05-31T15:55:50.950Z] 15:55:50     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PromptDelegateTest.selectTestDismiss(PromptDelegateTest.kt:458)
[task 2022-05-31T15:55:50.951Z] 15:55:50     INFO -  org.mozilla.geckoview.test |
[task 2022-05-31T15:55:50.951Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=502
[task 2022-05-31T15:55:50.951Z] 15:55:50     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2022-05-31T15:55:50.951Z] 15:55:50     INFO -  Printing logcat for test:
[task 2022-05-31T15:55:51.017Z] 15:55:51     INFO -  05-31 15:55:20.724 E/GeckoSessionTestRule( 3432): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec selectTestDismiss(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-05-31T15:55:51.017Z] 15:55:51     INFO -  05-31 15:55:20.724 E/GeckoSessionTestRule( 3432): before prepareStatement selectTestDismiss(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-05-31T15:55:51.017Z] 15:55:51     INFO -  05-31 15:55:20.724 D/GeckoViewModule( 3432): unregisterListener
[task 2022-05-31T15:55:51.017Z] 15:55:51     INFO -  05-31 15:55:20.724 D/GeckoViewMediaControl( 3432): onDisable
[task 2022-05-31T15:55:51.018Z] 15:55:51     INFO -  05-31 15:55:20.725 D/GeckoViewModule( 3432): unregisterListener
<...>
[task 2022-05-31T15:55:51.042Z] 15:55:51     INFO -  05-31 15:55:50.970 E/GeckoSessionTestRule( 3432): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-05-31T15:55:51.042Z] 15:55:51     INFO -  05-31 15:55:50.972 D/EGL_emulation( 6241): eglMakeCurrent: 0x7fae9167bae0: ver 3 0 (tinfo 0x7fae916b44e0)
[task 2022-05-31T15:55:51.042Z] 15:55:51     INFO -  05-31 15:55:50.975 D/GeckoViewContent( 3432): handleEvent: DOMWindowClose
[task 2022-05-31T15:55:51.042Z] 15:55:51     INFO -  05-31 15:55:50.977 D/GeckoViewConsole( 3432): onEvent GeckoView:WebExtension:List null
[task 2022-05-31T15:55:51.042Z] 15:55:51     INFO -  05-31 15:55:50.980 I/Gecko   ( 3432): nsWindow[0x7fae481b9100]::Show 0
[task 2022-05-31T15:55:51.042Z] 15:55:51     INFO -  05-31 15:55:50.980 E/GeckoSessionTestRule( 3432): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 selectTestDismiss(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-05-31T15:55:51.042Z] 15:55:51  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PromptDelegateTest#selectTestDismiss | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  TEST-INFO took 30324ms
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=921
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=alertTest
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=503
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2022-05-31T15:55:51.043Z] 15:55:51     INFO -  TEST-START | org.mozilla.geckoview.test.PromptDelegateTest#alertTest

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

:m_kato, since you are the author of the regressor, bug 1715572, could you take a look?
For more information, please visit auto_nag documentation.

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 3

[Intermittent Failures Robot]

16 failures in 2917 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 10
• mozilla-central: 6

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 7
  • debug-isolated-process: 3
  • opt: 1
  • debug: 3
• android-em-7-0-x86_64-lite-qr: 5
  • debug: 4
  • opt: 1
• android-em-7-0-x86_64-shippable-qr: 2
  • opt: 2
• android-em-7-0-x86_64-shippable-lite-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1771945&startday=2022-05-30&endday=2022-06-05&tree=all

Comment 4

[Intermittent Failures Robot]

21 failures in 3336 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 11
• mozilla-central: 9
• try: 1

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 9
  • debug: 6
  • debug-isolated-process: 2
  • opt: 1
• android-em-7-0-x86_64-lite-qr: 9
  • debug: 7
  • opt: 2
• android-em-7-0-x86_64-shippable-lite-qr: 2
  • opt: 2
• android-em-7-0-x86_64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1771945&startday=2022-06-06&endday=2022-06-12&tree=all

Comment 5

[Intermittent Failures Robot]

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

This is the #45 most frequent failure this week.

Repository breakdown:

• autoland: 19
• mozilla-central: 8

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 17
  • debug-isolated-process: 8
  • opt: 4
  • debug: 5
• android-em-7-0-x86_64-lite-qr: 6
  • debug: 4
  • opt: 2
• android-em-7-0-x86_64-shippable-qr: 3
  • opt: 3
• android-em-7-0-x86_64-shippable-lite-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1771945&startday=2022-06-13&endday=2022-06-19&tree=all

Comment 6

[Intermittent Failures Robot]

15 failures in 534 pushes (0.028 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 14
• mozilla-central: 1

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 8
  • debug-isolated-process: 1
  • opt: 1
  • debug: 6
• android-em-7-0-x86_64-lite-qr: 5
  • opt: 2
  • debug: 3
• android-em-7-0-x86_64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1771945&startday=2022-06-24&endday=2022-06-24&tree=all

Comment 7

[Marian-Vasile Laza]

There have been 41 total failures in the last 7 days, recent failure log.
Affected platforms are:

• android-em-7-0-x86_64-lite-qr
• android-em-7-0-x86_64-qr
• android-em-7-0-x86_64-shippable-lite-qr
• android-em-7-0-x86_64-shippable-qr

[task 2022-06-26T10:19:38.868Z] 10:19:38     INFO -  TEST-START | org.mozilla.geckoview.test.PromptDelegateTest#selectTestDismiss
[task 2022-06-26T10:20:09.165Z] 10:20:09     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=928
[task 2022-06-26T10:20:09.165Z] 10:20:09     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-06-26T10:20:09.165Z] 10:20:09     INFO -  org.mozilla.geckoview.test | Error in selectTestDismiss(org.mozilla.geckoview.test.PromptDelegateTest):
[task 2022-06-26T10:20:09.166Z] 10:20:09     INFO -  org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
...
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.583 E/GeckoSessionTestRule( 3410): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.583 E/GeckoSessionTestRule( 3410): 	at android.os.Looper.loop(Looper.java:154)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.583 E/GeckoSessionTestRule( 3410): 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.583 E/GeckoSessionTestRule( 3410): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.583 E/GeckoSessionTestRule( 3410): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.583 E/GeckoSessionTestRule( 3410): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.584 D/EGL_emulation( 6336): eglMakeCurrent: 0x78771367e420: ver 3 0 (tinfo 0x7877136b45a0)
[task 2022-06-26T10:20:09.239Z] 10:20:09     INFO -  06-26 10:20:08.612 D/GeckoViewContent( 3410): handleEvent: DOMWindowClose
[task 2022-06-26T10:20:09.240Z] 10:20:09     INFO -  06-26 10:20:08.615 D/GeckoViewConsole( 3410): onEvent GeckoView:WebExtension:List null
[task 2022-06-26T10:20:09.240Z] 10:20:09     INFO -  06-26 10:20:08.620 E/GeckoSessionTestRule( 3410): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 selectTestDismiss(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-06-26T10:20:09.240Z] 10:20:09  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PromptDelegateTest#selectTestDismiss | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-06-26T10:20:09.240Z] 10:20:09     INFO -  TEST-INFO took 30348ms

Comment 8

[Makoto Kato [:m_kato]]

Attachment: Bug 1771945 - Don't use setTimeout for <select> dismiss test.

We shouldn't use setTimeout like dateTestDismiss() to avoid intermittent failure.

Comment 9

[Intermittent Failures Robot]

42 failures in 3075 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #28 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• try: 1
• autoland: 36
• mozilla-central: 5

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-lite-qr: 4
  • opt: 4
• android-em-7-0-x86_64-qr: 20
  • opt: 5
  • debug: 10
  • debug-isolated-process: 5
• android-em-7-0-x86_64-lite-qr: 16
  • debug: 11
  • opt: 5
• android-em-7-0-x86_64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1771945&startday=2022-06-20&endday=2022-06-26&tree=all

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/73ac6eea9084
Don't use setTimeout for <select> dismiss test. r=geckoview-reviewers,owlish

Comment 11

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/73ac6eea9084

Comment 12

[BugBot [:suhaib / :marco/ :calixte]]

The patch landed in nightly and beta is affected.
:m_kato, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
• If no, please set status-firefox103 to wontfix.

For more information, please visit auto_nag documentation.

Comment 13

[Makoto Kato [:m_kato]]

Comment on attachment 9282982 [details]
Bug 1771945 - Don't use setTimeout for <select> dismiss test.

Beta/Release Uplift Approval Request

• User impact if declined: Nothing. This is test fix.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): This is test only fix.
• String changes made/needed:
• Is Android affected?: Yes

Comment 14

[Donal Meehan [:dmeehan]]

Comment on attachment 9282982 [details]
Bug 1771945 - Don't use setTimeout for <select> dismiss test.

Approved for 103.0b4, thanks.

Comment 15

[Donal Meehan [:dmeehan]]

https://hg.mozilla.org/releases/mozilla-beta/rev/0b11163185dd

Comment 16

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 3
• autoland: 9

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 3
  • debug-isolated-process: 1
  • debug: 1
  • opt: 1
• android-em-7-0-x86_64-lite-qr: 4
  • debug: 4
• android-em-7-0-x86_64-shippable-lite-qr: 1
  • opt: 1
• android-em-7-0-x86_64-shippable-qr: 4
  • opt: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1771945&startday=2022-06-27&endday=2022-07-03&tree=all