Closed
Bug 1766110
Opened 2 years ago
Closed 2 years ago
High frequency org.mozilla.geckoview.test.PromptDelegateTest#dateTest | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
Categories
(GeckoView :: General, defect, P5)
Tracking
(firefox-esr91 unaffected, firefox99 unaffected, firefox100 unaffected, firefox101 fixed)
RESOLVED
FIXED
101 Branch
| Tracking | Status | |
|---|---|---|
| firefox-esr91 | --- | unaffected |
| firefox99 | --- | unaffected |
| firefox100 | --- | unaffected |
| firefox101 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: emilio)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disable-recommended])
Attachments
(1 file)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=375547459&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WMwSYs7_QFWG5vDuV2gHaQ/runs/0/artifacts/public/logs/live_backing.log
[task 2022-04-23T11:38:36.894Z] 11:38:36 INFO - TEST-START | org.mozilla.geckoview.test.PromptDelegateTest#dateTest
[task 2022-04-23T11:38:37.351Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=887
[task 2022-04-23T11:38:37.351Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-04-23T11:38:37.351Z] 11:38:37 INFO - org.mozilla.geckoview.test | Error in dateTest(org.mozilla.geckoview.test.PromptDelegateTest):
[task 2022-04-23T11:38:37.352Z] 11:38:37 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-23T11:38:37.352Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2190)
[task 2022-04-23T11:38:37.352Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2143)
[task 2022-04-23T11:38:37.352Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2309)
[task 2022-04-23T11:38:37.352Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:221)
[task 2022-04-23T11:38:37.353Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PromptDelegateTest.dateTest(PromptDelegateTest.kt:506)
[task 2022-04-23T11:38:37.353Z] 11:38:37 INFO - org.mozilla.geckoview.test |
[task 2022-04-23T11:38:37.353Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-23T11:38:37.353Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=dateTest
[task 2022-04-23T11:38:37.353Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-04-23T11:38:37.354Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-23T11:38:37.354Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2190)
[task 2022-04-23T11:38:37.354Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2143)
[task 2022-04-23T11:38:37.354Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2309)
[task 2022-04-23T11:38:37.355Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:221)
[task 2022-04-23T11:38:37.355Z] 11:38:37 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PromptDelegateTest.dateTest(PromptDelegateTest.kt:506)
[task 2022-04-23T11:38:37.355Z] 11:38:37 INFO - org.mozilla.geckoview.test |
[task 2022-04-23T11:38:37.355Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=497
[task 2022-04-23T11:38:37.355Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2[task 2022-04-23T11:38:37.355Z] 11:38:37 INFO - Printing logcat for test:
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.477 E/GeckoSessionTestRule( 3472): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec dateTest(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.477 E/GeckoSessionTestRule( 3472): before prepareStatement dateTest(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.479 E/eglCodecCommon( 6762): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.486 D/GeckoViewStartup( 3472): onEvent GeckoView:StorageDelegate:Attached
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.493 E/Web Content( 9396): [JavaScript Error: "TypeError: can't access dead object"]
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.493 E/Web Content( 9396): [JavaScript Error: "TypeError: NetworkError when attempting to fetch resource."]
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.502 D/GeckoViewNavigation( 3472): sessionContextId=null
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.509 E/eglCodecCommon( 6762): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.522 E/eglCodecCommon( 6762): glUtilsParamSize: unknow param 0x00008741
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.527 D/GeckoViewModule( 3472): registerListener ["GeckoViewContent:ExitFullScreen","GeckoView:ClearMatches","GeckoView:DisplayMatches","GeckoView:FindInPage","GeckoView:RestoreState","GeckoView:ScrollBy","GeckoView:ScrollTo","GeckoView:SetActive","GeckoView:SetFocused","GeckoView:UpdateInitData","GeckoView:ZoomToInput"]
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.528 D/GeckoViewNavigation( 3472): onInit
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.528 D/GeckoViewModule( 3472): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.528 D/GeckoViewNavigation( 3472): onEnable
[task 2022-04-23T11:38:37.426Z] 11:38:37 INFO - 04-23 11:38:36.529 D/GeckoViewProcessHangMonitor( 3472): onInit
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.529 D/GeckoViewProcessHangMonitor( 3472): onEnable
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.529 D/GeckoViewModule( 3472): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.529 D/GeckoViewProgress( 3472): onEnable
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.530 D/GeckoViewModule( 3472): registerListener GeckoView:FlushSessionState
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.531 D/GeckoViewSettings( 3472): onInit
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.531 D/GeckoViewModule( 3472): registerListener ["GeckoView:GetUserAgent"]
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.531 D/GeckoViewSettings( 3472): onSettingsUpdate: {"chromeUri":null,"screenId":0,"userAgentOverride":null,"allowJavascript":true,"userAgentMode":0,"viewportMode":0,"useTrackingProtection":false,"suspendMediaWhenInactive":false,"usePrivateMode":false,"unsafeSessionContextId":null,"displayMode":0,"sessionContextId":null,"fullAccessibilityTree":false,"isPopup":false}
[task 2022-04-23T11:38:37.427Z] 11:38:37 INFO - 04-23 11:38:36.531 D/GeckoViewModule( 3472): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2022-04-23T11:38:37.428Z] 11:38:37 INFO - 04-23 11:38:36.532 D/GeckoViewModule( 3472): registerListener ["ContentBlocking:RequestLog"]
[task 2022-04-23T11:38:37.428Z] 11:38:37 INFO - 04-23 11:38:36.532 D/GeckoViewMediaControl( 3472): onEnable
[task 2022-04-23T11:38:37.428Z] 11:38:37 INFO - 04-23 11:38:36.533 D/GeckoViewModule( 3472): registerListener ["GeckoView:MediaSession:Play","GeckoView:MediaSession:Pause","GeckoView:MediaSession:Stop","GeckoView:MediaSession:NextTrack","GeckoView:MediaSession:PrevTrack","GeckoView:MediaSession:SeekForward","GeckoView:MediaSession:SeekBackward","GeckoView:MediaSession:SkipAd","GeckoView:MediaSession:SeekTo","GeckoView:MediaSession:MuteAudio"]
[task 2022-04-23T11:38:37.428Z] 11:38:37 INFO - 04-23 11:38:36.534 I/GeckoSession( 3472): zerdatime 340634 - chrome startup finished
[task 2022-04-23T11:38:37.429Z] 11:38:37 INFO - 04-23 11:38:36.536 D/EGL_emulation( 6762): eglMakeCurrent: 0x784c5b07e7e0: ver 3 0 (tinfo 0x784c507d3120)[task 2022-04-23T11:38:37.429Z] 11:38:37 INFO - 04-23 11:38:36.538 D/GeckoSession( 3472): handleMessage GeckoView:PageStart uri=about:blank
[task 2022-04-23T11:38:37.429Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-04-23T11:38:37.429Z] 11:38:37 INFO - 04-23 11:38:36.538 D/GeckoSession( 3472): handleMessage GeckoView:LocationChange uri=about:blank
[task 2022-04-23T11:38:37.430Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2022-04-23T11:38:37.430Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-04-23T11:38:37.430Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-23T11:38:37.431Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-23T11:38:37.431Z] 11:38:37 INFO - 04-23 11:38:36.538 D/GeckoSession( 3472): handleMessage GeckoView:PageStop uri=null
[task 2022-04-23T11:38:37.431Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-23T11:38:37.431Z] 11:38:37 INFO - 04-23 11:38:36.538 E/GeckoSessionTestRule( 3472): after prepareStatement
[task 2022-04-23T11:38:37.432Z] 11:38:37 INFO - 04-23 11:38:36.539 D/GeckoViewModule( 3472): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/prompts.html","flags":0,"headerFilter":1}
[task 2022-04-23T11:38:37.432Z] 11:38:37 INFO - 04-23 11:38:36.539 D/GeckoViewNavigation( 3472): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/prompts.html","flags":0,"headerFilter":1}
[task 2022-04-23T11:38:37.432Z] 11:38:37 INFO - 04-23 11:38:36.540 D/GeckoViewSelectionActionDelegate[C]( 9396): handleEvent: visibilitychange
[task 2022-04-23T11:38:37.432Z] 11:38:37 INFO - 04-23 11:38:36.541 D/GeckoViewSettings[C]( 9396): receiveMessage: SettingsUpdate
[task 2022-04-23T11:38:37.432Z] 11:38:37 INFO - 04-23 11:38:36.544 D/GeckoViewXUL( 3472): receiveMessage GeckoView:ContentModuleLoaded {"module":"SessionStateAggregator"}
[task 2022-04-23T11:38:37.432Z] 11:38:37 INFO - 04-23 11:38:36.546 W/GeckoEditableChild( 9396): No editable parent
[task 2022-04-23T11:38:37.433Z] 11:38:37 INFO - 04-23 11:38:36.546 D/GeckoViewProgress( 3472): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2022-04-23T11:38:37.433Z] 11:38:37 INFO - 04-23 11:38:36.546 D/GeckoViewProgress( 3472): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-23T11:38:37.433Z] 11:38:37 INFO - 04-23 11:38:36.546 D/GeckoViewProgress( 3472): ProgressTracker start http://localhost:4245/assets/www/prompts.html
[task 2022-04-23T11:38:37.433Z] 11:38:37 INFO - 04-23 11:38:36.546 D/GeckoViewProgress( 3472): ProgressTracker updateProgress
[task 2022-04-23T11:38:37.433Z] 11:38:37 INFO - 04-23 11:38:36.546 D/GeckoViewProgress( 3472): ProgressTracker updateProgress data={"prev":0,"uri":"http://localhost:4245/assets/www/prompts.html","locationChange":false,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":false} progress=15
[task 2022-04-23T11:38:37.433Z] 11:38:37 INFO - 04-23 11:38:36.547 D/GeckoSession( 3472): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.547 D/GeckoViewProgress( 3472): StateTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK loadType=1
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.548 D/GeckoSession( 3472): handleMessage GeckoView:PageStart uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.551 E/eglCodecCommon( 6762): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.554 D/GeckoViewSelectionActionDelegate[C]( 9396): handleEvent: visibilitychange[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.554 D/GeckoViewAutoFill[C]( 9396): handleEvent: pagehide
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.554 D/GeckoViewAutofill( 9396): Clearing auto-fill
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.568 D/GeckoViewNavigation( 3472): onLocationChange
[task 2022-04-23T11:38:37.434Z] 11:38:37 INFO - 04-23 11:38:36.569 D/GeckoViewProgress( 3472): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/prompts.html, flags=0
[task 2022-04-23T11:38:37.435Z] 11:38:37 INFO - 04-23 11:38:36.569 D/GeckoViewProgress( 3472): ProgressTracker onLocationChange: location=http://localhost:4245/assets/www/prompts.html, flags=0
[task 2022-04-23T11:38:37.435Z] 11:38:37 INFO - 04-23 11:38:36.569 D/GeckoViewProgress( 3472): ProgressTracker changeLocation http://localhost:4245/assets/www/prompts.html
[task 2022-04-23T11:38:37.435Z] 11:38:37 INFO - 04-23 11:38:36.569 D/GeckoViewProgress( 3472): onSecurityChange
[task 2022-04-23T11:38:37.435Z] 11:38:37 INFO - 04-23 11:38:36.570 D/GeckoSession( 3472): handleMessage GeckoView:LocationChange uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-23T11:38:37.435Z] 11:38:37 INFO - 04-23 11:38:36.570 D/GeckoSession( 3472): handleMessage GeckoView:SecurityChanged uri=null
[task 2022-04-23T11:38:37.436Z] 11:38:37 INFO - 04-23 11:38:36.609 D/GeckoViewContentDelegateChild[C]( 9396): handleEvent: DOMContentLoaded
[task 2022-04-23T11:38:37.436Z] 11:38:37 INFO - 04-23 11:38:36.610 D/GeckoViewProgressDelegate[C]( 9396): handleEvent: DOMContentLoaded
[task 2022-04-23T11:38:37.436Z] 11:38:37 INFO - 04-23 11:38:36.614 D/GeckoViewProgressDelegate[C]( 9396): handleEvent: pageshow
[task 2022-04-23T11:38:37.436Z] 11:38:37 INFO - 04-23 11:38:36.614 D/GeckoViewAutoFill[C]( 9396): handleEvent: pageshow
[task 2022-04-23T11:38:37.436Z] 11:38:37 INFO - 04-23 11:38:36.615 D/GeckoViewContent[C]( 9396): handleEvent: pageshow
[task 2022-04-23T11:38:37.437Z] 11:38:37 INFO - 04-23 11:38:36.622 D/GeckoViewContentDelegateChild[C]( 9396): handleEvent: MozFirstContentfulPaint
[task 2022-04-23T11:38:37.437Z] 11:38:37 INFO - 04-23 11:38:36.639 E/eglCodecCommon( 6762): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-23T11:38:37.437Z] 11:38:37 INFO - 04-23 11:38:36.640 D/GeckoViewProgressDelegate[C]( 9396): handleEvent: MozAfterPaint
[task 2022-04-23T11:38:37.437Z] 11:38:37 INFO - 04-23 11:38:36.652 D/GeckoViewContent( 3472): handleEvent: pagetitlechanged
[task 2022-04-23T11:38:37.438Z] 11:38:37 INFO - 04-23 11:38:36.652 D/GeckoViewProgress( 3472): receiveMessage: DOMContentLoaded
[task 2022-04-23T11:38:37.438Z] 11:38:37 INFO - 04-23 11:38:36.652 D/GeckoViewProgress( 3472): ProgressTracker handleEvent: DOMContentLoaded
[task 2022-04-23T11:38:37.438Z] 11:38:37 INFO - 04-23 11:38:36.652 D/GeckoViewProgress( 3472): ProgressTracker updateProgress
[task 2022-04-23T11:38:37.438Z] 11:38:37 INFO - 04-23 11:38:36.652 D/GeckoViewProgress( 3472): ProgressTracker updateProgress data={"prev":15,"uri":"http://localhost:4245/assets/www/prompts.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":true} progress=55
[task 2022-04-23T11:38:37.439Z] 11:38:37 INFO - 04-23 11:38:36.653 D/GeckoSession( 3472): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-23T11:38:37.439Z] 11:38:37 INFO - 04-23 11:38:36.674 D/WebExtension( 3472): handleMessage GeckoView:WebExtension:Connect
[task 2022-04-23T11:38:37.439Z] 11:38:37 INFO - 04-23 11:38:36.674 D/GeckoViewProgress( 3472): receiveMessage: pageshow
[task 2022-04-23T11:38:37.439Z] 11:38:37 INFO - 04-23 11:38:36.674 D/GeckoViewProgress( 3472): ProgressTracker handleEvent: pageshow
[task 2022-04-23T11:38:37.439Z] 11:38:37 INFO - 04-23 11:38:36.675 D/GeckoViewProgress( 3472): ProgressTracker updateProgress
[task 2022-04-23T11:38:37.440Z] 11:38:37 INFO - 04-23 11:38:36.675 D/GeckoViewProgress( 3472): ProgressTracker updateProgress data={"prev":55,"uri":"http://localhost:4245/assets/www/prompts.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":true,"parsed":true} progress=100
[task 2022-04-23T11:38:37.440Z] 11:38:37 INFO - 04-23 11:38:36.675 D/GeckoSession( 3472): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-23T11:38:37.440Z] 11:38:37 INFO - 04-23 11:38:36.676 D/GeckoViewProgress( 3472): ProgressTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK
[task 2022-04-23T11:38:37.441Z] 11:38:37 INFO - 04-23 11:38:36.676 D/GeckoViewProgress( 3472): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-23T11:38:37.441Z] 11:38:37 INFO - 04-23 11:38:36.676 D/GeckoViewProgress( 3472): ProgressTracker stop[task 2022-04-23T11:38:37.441Z] 11:38:37 INFO - 04-23 11:38:36.676 D/GeckoViewProgress( 3472): ProgressTracker updateProgress
[task 2022-04-23T11:38:37.441Z] 11:38:37 INFO - 04-23 11:38:36.677 D/GeckoViewProgress( 3472): StateTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK loadType=1
[task 2022-04-23T11:38:37.441Z] 11:38:37 INFO - 04-23 11:38:36.677 D/GeckoSession( 3472): handleMessage GeckoView:PageStop uri=null
[task 2022-04-23T11:38:37.441Z] 11:38:37 INFO - 04-23 11:38:36.677 D/GeckoViewProgress( 3472): receiveMessage: MozAfterPaint
[task 2022-04-23T11:38:37.442Z] 11:38:37 INFO - 04-23 11:38:36.681 D/GeckoViewConsole( 3472): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"754cc62d-5fa3-4862-9c7c-1414f79cb763","eval":"document.getElementById('dateexample').showPicker();"}}
[task 2022-04-23T11:38:37.442Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): Error
[task 2022-04-23T11:38:37.442Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-23T11:38:37.442Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2190)
[task 2022-04-23T11:38:37.443Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2143)
[task 2022-04-23T11:38:37.443Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2309)
[task 2022-04-23T11:38:37.443Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:221)
[task 2022-04-23T11:38:37.443Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.PromptDelegateTest.dateTest(PromptDelegateTest.kt:506)
[task 2022-04-23T11:38:37.444Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at java.lang.reflect.Method.invoke(Native Method)
[task 2022-04-23T11:38:37.444Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-04-23T11:38:37.444Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-04-23T11:38:37.444Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-04-23T11:38:37.445Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-04-23T11:38:37.445Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2022-04-23T11:38:37.445Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1451)
[task 2022-04-23T11:38:37.445Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(Unknown Source)
[task 2022-04-23T11:38:37.445Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at android.os.Looper.loop(Looper.java:154)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-04-23T11:38:37.446Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at java.lang.reflect.Method.invoke(Native Method)
[task 2022-04-23T11:38:37.447Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-04-23T11:38:37.447Z] 11:38:37 INFO - 04-23 11:38:36.684 E/GeckoSessionTestRule( 3472): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-04-23T11:38:37.447Z] 11:38:37 INFO - 04-23 11:38:36.923 D/EGL_emulation( 6762): eglMakeCurrent: 0x784c5b07e7e0: ver 3 0 (tinfo 0x784c507d3120)[task 2022-04-23T11:38:37.447Z] 11:38:37 INFO - 04-23 11:38:36.926 D/GeckoViewContent( 3472): handleEvent: DOMWindowClose
[task 2022-04-23T11:38:37.448Z] 11:38:37 INFO - 04-23 11:38:36.926 D/GeckoViewProgressDelegate[C]( 9396): handleEvent: MozAfterPaint
[task 2022-04-23T11:38:37.448Z] 11:38:37 INFO - 04-23 11:38:36.927 D/GeckoViewConsole( 3472): onEvent GeckoView:WebExtension:List null
[task 2022-04-23T11:38:37.448Z] 11:38:37 INFO - 04-23 11:38:36.928 E/GeckoSessionTestRule( 3472): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 dateTest(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-04-23T11:38:37.448Z] 11:38:37 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PromptDelegateTest#dateTest | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-23T11:38:37.448Z] 11:38:37 INFO - TEST-INFO took 530ms
[task 2022-04-23T11:38:37.449Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=887
[task 2022-04-23T11:38:37.449Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-04-23T11:38:37.449Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-23T11:38:37.450Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=colorTest
[task 2022-04-23T11:38:37.450Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-04-23T11:38:37.450Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=498
[task 2022-04-23T11:38:37.450Z] 11:38:37 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2022-04-23T11:38:37.450Z] 11:38:37 INFO - TEST-START | org.mozilla.geckoview.test.PromptDelegateTest#colorTest
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=887
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=.
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=colorTest
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=498
[task 2022-04-23T11:38:38.112Z] 11:38:38 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 0
|
||
Updated•2 years ago
|
Keywords: regression
|
|
||
Comment 1•2 years ago
|
||
Set release status flags based on info from the regressing bug 1764157
status-firefox100:
--- → unaffected
status-firefox101:
--- → affected
status-firefox99:
--- → unaffected
status-firefox-esr91:
--- → unaffected
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
Assignee | |
Comment 4•2 years ago
|
||
So this line is supposed to provide user activation. My guess is that since that goes through APZ the main thread might not see it right away, and if the JS is executed too soon then this happens.
Agi, is there a good way to wait for the tap to be processed by the main thread, other than maybe add an event handler or something and await for it in JS? Alternatively I can add a pref to disable the user activation requirement which is what other tests do, but that's slightly unfortunate.
Flags: needinfo?(emilio) → needinfo?(agi)
|
|
||
Updated•2 years ago
|
Has Regression Range: --- → yes
|
||
Comment 5•2 years ago
•
|
||
(In reply to Emilio Cobos Álvarez (:emilio) from comment #4)
So this line is supposed to provide user activation. My guess is that since that goes through APZ the main thread might not see it right away, and if the JS is executed too soon then this happens.
Agi, is there a good way to wait for the tap to be processed by the main thread, other than maybe add an event handler or something and await for it in JS? Alternatively I can add a pref to disable the user activation requirement which is what other tests do, but that's slightly unfortunate.
We don't really have a way to wait until the tap is processed, synthesizeTap just sends the touch events to Gecko.
I would just add an event listener
mainSession.evaluateJS("""
document.body.addEventListener("click", () => {
document.getElementById('dateexample').showPicker();
});
""".trimIndent())
Note that you don't necessarily have to wait for the event listener to fire you can just call waitUntilCalled to assert that we call onDateTimePrompt:
mainSession.evaluateJS("""
document.body.addEventListener("click", () => {
document.getElementById('dateexample').showPicker();
});
""".trimIndent())
mainSession.synthesizeTap(1, 1) // Provides user activation.
sessionRule.waitUntilCalled(object : PromptDelegate {
@AssertCalled(count = 1)
override fun onDateTimePrompt(session: GeckoSession, prompt: PromptDelegate.DateTimePrompt): GeckoResult<PromptDelegate.PromptResponse> {
return GeckoResult.fromValue(prompt.dismiss())
}
})
which seems to work well for me locally.
Flags: needinfo?(agi)
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 7•2 years ago
|
||
There are 92 total failures in the last 4 days on
- android-em-7-0-x86_64-shippable-qr opt
- android-em-7-0-x86_64-shippable-lite-qr opt
- android-em-7-0-x86_64-qr debug, opt and debug-isolated-process
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=375794468&repo=autoland&lineNumber=10783
[task 2022-04-26T09:54:04.945Z] 09:54:04 INFO - TEST-START | org.mozilla.geckoview.test.PromptDelegateTest#dateTest
[task 2022-04-26T09:54:05.438Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=887
[task 2022-04-26T09:54:05.438Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-04-26T09:54:05.438Z] 09:54:05 INFO - org.mozilla.geckoview.test | Error in dateTest(org.mozilla.geckoview.test.PromptDelegateTest):
[task 2022-04-26T09:54:05.439Z] 09:54:05 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-26T09:54:05.439Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2190)
[task 2022-04-26T09:54:05.440Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2143)
[task 2022-04-26T09:54:05.440Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2309)
[task 2022-04-26T09:54:05.440Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:221)
[task 2022-04-26T09:54:05.440Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PromptDelegateTest.dateTest(PromptDelegateTest.kt:506)
[task 2022-04-26T09:54:05.440Z] 09:54:05 INFO - org.mozilla.geckoview.test |
[task 2022-04-26T09:54:05.441Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-26T09:54:05.441Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=dateTest
[task 2022-04-26T09:54:05.441Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-04-26T09:54:05.441Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-26T09:54:05.441Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2190)
[task 2022-04-26T09:54:05.442Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2143)
[task 2022-04-26T09:54:05.442Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2309)
[task 2022-04-26T09:54:05.442Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:221)
[task 2022-04-26T09:54:05.442Z] 09:54:05 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PromptDelegateTest.dateTest(PromptDelegateTest.kt:506)
[task 2022-04-26T09:54:05.442Z] 09:54:05 INFO - org.mozilla.geckoview.test |
[task 2022-04-26T09:54:05.443Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=497
[task 2022-04-26T09:54:05.443Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2022-04-26T09:54:05.443Z] 09:54:05 INFO - Printing logcat for test:
[task 2022-04-26T09:54:05.516Z] 09:54:05 INFO - 04-26 09:54:04.301 E/GeckoSessionTestRule( 3477): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec dateTest(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-04-26T09:54:05.517Z] 09:54:05 INFO - 04-26 09:54:04.301 E/GeckoSessionTestRule( 3477): before prepareStatement dateTest(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-04-26T09:54:05.517Z] 09:54:05 INFO - 04-26 09:54:04.303 D/GeckoViewSelectionActionDelegate[C](22716): handleEvent: visibilitychange
[task 2022-04-26T09:54:05.517Z] 09:54:05 INFO - 04-26 09:54:04.304 D/GeckoViewSelectionActionDelegate[C](22716): handleEvent: visibilitychange
[task 2022-04-26T09:54:05.517Z] 09:54:05 INFO - 04-26 09:54:04.304 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.517Z] 09:54:05 INFO - 04-26 09:54:04.305 D/GeckoViewAutoFill[C](22716): handleEvent: pagehide
[task 2022-04-26T09:54:05.518Z] 09:54:05 INFO - 04-26 09:54:04.305 D/GeckoViewAutofill(22716): Clearing auto-fill
[task 2022-04-26T09:54:05.518Z] 09:54:05 INFO - 04-26 09:54:04.306 D/GeckoViewStartup( 3477): onEvent GeckoView:StorageDelegate:Attached
[task 2022-04-26T09:54:05.518Z] 09:54:05 INFO - 04-26 09:54:04.312 E/Isolated Web Content(22716): [JavaScript Error: "TypeError: can't access dead object"]
[task 2022-04-26T09:54:05.519Z] 09:54:05 INFO - 04-26 09:54:04.314 I/ServiceChildProcess(22716): Destroying GeckoServiceChildProcess
[task 2022-04-26T09:54:05.519Z] 09:54:05 INFO - 04-26 09:54:04.314 E/Isolated Web Content(22716): [JavaScript Error: "TypeError: NetworkError when attempting to fetch resource."]
[task 2022-04-26T09:54:05.519Z] 09:54:05 INFO - 04-26 09:54:04.315 I/art (22716): System.exit called, status: 0
[task 2022-04-26T09:54:05.519Z] 09:54:05 INFO - 04-26 09:54:04.315 I/AndroidRuntime(22716): VM exiting with result code 0, cleanup skipped.
[task 2022-04-26T09:54:05.520Z] 09:54:05 INFO - 04-26 09:54:04.319 D/GeckoViewNavigation( 3477): sessionContextId=null
[task 2022-04-26T09:54:05.520Z] 09:54:05 INFO - 04-26 09:54:04.325 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.520Z] 09:54:05 INFO - 04-26 09:54:04.333 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008741
[task 2022-04-26T09:54:05.521Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewModule( 3477): registerListener ["GeckoViewContent:ExitFullScreen","GeckoView:ClearMatches","GeckoView:DisplayMatches","GeckoView:FindInPage","GeckoView:RestoreState","GeckoView:ScrollBy","GeckoView:ScrollTo","GeckoView:SetActive","GeckoView:SetFocused","GeckoView:UpdateInitData","GeckoView:ZoomToInput"]
[task 2022-04-26T09:54:05.522Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewNavigation( 3477): onInit
[task 2022-04-26T09:54:05.522Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewModule( 3477): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
[task 2022-04-26T09:54:05.522Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewNavigation( 3477): onEnable
[task 2022-04-26T09:54:05.523Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewProcessHangMonitor( 3477): onInit
[task 2022-04-26T09:54:05.523Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewProcessHangMonitor( 3477): onEnable
[task 2022-04-26T09:54:05.523Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewModule( 3477): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2022-04-26T09:54:05.523Z] 09:54:05 INFO - 04-26 09:54:04.337 D/GeckoViewProgress( 3477): onEnable
[task 2022-04-26T09:54:05.524Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoViewModule( 3477): registerListener GeckoView:FlushSessionState
[task 2022-04-26T09:54:05.524Z] 09:54:05 INFO - 04-26 09:54:04.338 D/EGL_emulation(14926): eglMakeCurrent: 0x7adf53e7bae0: ver 3 0 (tinfo 0x7adf53fb9420)
[task 2022-04-26T09:54:05.524Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoViewSettings( 3477): onInit
[task 2022-04-26T09:54:05.524Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoViewModule( 3477): registerListener ["GeckoView:GetUserAgent"]
[task 2022-04-26T09:54:05.525Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoSession( 3477): handleMessage GeckoView:PageStart uri=about:blank
[task 2022-04-26T09:54:05.525Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-04-26T09:54:05.526Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoViewSettings( 3477): onSettingsUpdate: {"chromeUri":null,"screenId":0,"userAgentOverride":null,"allowJavascript":true,"userAgentMode":0,"viewportMode":0,"useTrackingProtection":false,"suspendMediaWhenInactive":false,"usePrivateMode":false,"unsafeSessionContextId":null,"displayMode":0,"sessionContextId":null,"fullAccessibilityTree":false,"isPopup":false}
[task 2022-04-26T09:54:05.526Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoSession( 3477): handleMessage GeckoView:LocationChange uri=about:blank
[task 2022-04-26T09:54:05.526Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2022-04-26T09:54:05.527Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-04-26T09:54:05.527Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-26T09:54:05.528Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-26T09:54:05.528Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoSession( 3477): handleMessage GeckoView:PageStop uri=null
[task 2022-04-26T09:54:05.529Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-26T09:54:05.529Z] 09:54:05 INFO - 04-26 09:54:04.338 E/GeckoSessionTestRule( 3477): after prepareStatement
[task 2022-04-26T09:54:05.529Z] 09:54:05 INFO - 04-26 09:54:04.338 D/GeckoViewModule( 3477): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2022-04-26T09:54:05.530Z] 09:54:05 INFO - 04-26 09:54:04.339 D/GeckoViewModule( 3477): registerListener ["ContentBlocking:RequestLog"]
[task 2022-04-26T09:54:05.530Z] 09:54:05 INFO - 04-26 09:54:04.339 D/GeckoViewMediaControl( 3477): onEnable
[task 2022-04-26T09:54:05.530Z] 09:54:05 INFO - 04-26 09:54:04.339 D/GeckoViewSelectionActionDelegate[C](14754): handleEvent: visibilitychange
[task 2022-04-26T09:54:05.531Z] 09:54:05 INFO - 04-26 09:54:04.339 D/GeckoViewModule( 3477): registerListener ["GeckoView:MediaSession:Play","GeckoView:MediaSession:Pause","GeckoView:MediaSession:Stop","GeckoView:MediaSession:NextTrack","GeckoView:MediaSession:PrevTrack","GeckoView:MediaSession:SeekForward","GeckoView:MediaSession:SeekBackward","GeckoView:MediaSession:SkipAd","GeckoView:MediaSession:SeekTo","GeckoView:MediaSession:MuteAudio"]
[task 2022-04-26T09:54:05.531Z] 09:54:05 INFO - 04-26 09:54:04.340 D/GeckoViewSettings[C](14754): receiveMessage: SettingsUpdate
[task 2022-04-26T09:54:05.531Z] 09:54:05 INFO - 04-26 09:54:04.340 I/GeckoSession( 3477): zerdatime 362798 - chrome startup finished
[task 2022-04-26T09:54:05.532Z] 09:54:05 INFO - 04-26 09:54:04.342 W/GeckoEditableChild(14754): No editable parent
[task 2022-04-26T09:54:05.532Z] 09:54:05 INFO - 04-26 09:54:04.343 D/GeckoViewModule( 3477): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/prompts.html","flags":0,"headerFilter":1}
[task 2022-04-26T09:54:05.532Z] 09:54:05 INFO - 04-26 09:54:04.343 D/GeckoViewNavigation( 3477): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/prompts.html","flags":0,"headerFilter":1}
[task 2022-04-26T09:54:05.532Z] 09:54:05 INFO - 04-26 09:54:04.344 D/GeckoViewXUL( 3477): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-04-26T09:54:05.533Z] 09:54:05 INFO - 04-26 09:54:04.348 D/GeckoViewProgress( 3477): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2022-04-26T09:54:05.533Z] 09:54:05 INFO - 04-26 09:54:04.348 D/GeckoViewProgress( 3477): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-26T09:54:05.533Z] 09:54:05 INFO - 04-26 09:54:04.348 D/GeckoViewProgress( 3477): ProgressTracker start http://localhost:4245/assets/www/prompts.html
[task 2022-04-26T09:54:05.533Z] 09:54:05 INFO - 04-26 09:54:04.348 D/GeckoViewProgress( 3477): ProgressTracker updateProgress
[task 2022-04-26T09:54:05.534Z] 09:54:05 INFO - 04-26 09:54:04.348 D/GeckoViewProgress( 3477): ProgressTracker updateProgress data={"prev":0,"uri":"http://localhost:4245/assets/www/prompts.html","locationChange":false,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":false} progress=15
[task 2022-04-26T09:54:05.534Z] 09:54:05 INFO - 04-26 09:54:04.349 D/GeckoViewProgress( 3477): StateTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK loadType=1
[task 2022-04-26T09:54:05.534Z] 09:54:05 INFO - 04-26 09:54:04.349 D/GeckoSession( 3477): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-26T09:54:05.534Z] 09:54:05 INFO - 04-26 09:54:04.349 D/GeckoSession( 3477): handleMessage GeckoView:PageStart uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-26T09:54:05.534Z] 09:54:05 INFO - 04-26 09:54:04.355 I/art (22762): Late-enabling -Xcheck:jni
[task 2022-04-26T09:54:05.535Z] 09:54:05 INFO - 04-26 09:54:04.355 W/art (22762): Unexpected CPU variant for X86 using defaults: x86_64
[task 2022-04-26T09:54:05.535Z] 09:54:05 INFO - 04-26 09:54:04.359 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.535Z] 09:54:05 INFO - 04-26 09:54:04.362 I/ActivityManager( 1646): Start proc 22762:org.mozilla.geckoview.test:tab29/u0a62 for service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab29
[task 2022-04-26T09:54:05.535Z] 09:54:05 INFO - 04-26 09:54:04.363 I/ActivityManager( 1646): Process org.mozilla.geckoview.test:tab6 (pid 22716) has died
[task 2022-04-26T09:54:05.535Z] 09:54:05 INFO - 04-26 09:54:04.363 D/ActivityManager( 1646): cleanUpApplicationRecord -- 22716
[task 2022-04-26T09:54:05.535Z] 09:54:05 INFO - 04-26 09:54:04.364 D/ServiceAllocator( 3477): org.mozilla.gecko.process.GeckoChildProcessServices$tab29 updateBindings: FOREGROUND priority, 0 importance, 3 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-04-26T09:54:05.536Z] 09:54:05 INFO - 04-26 09:54:04.365 D/GeckoViewContent( 3477): observe: ipc:content-shutdown
[task 2022-04-26T09:54:05.536Z] 09:54:05 INFO - 04-26 09:54:04.365 I/Gecko ( 3477): [Parent 3477, Unnamed thread 7adf39c21f00] WARNING: waitpid failed pid:22716 errno:10: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:221
[task 2022-04-26T09:54:05.536Z] 09:54:05 INFO - 04-26 09:54:04.375 I/MultiDex(22762): VM with version 2.1.0 has multidex support
[task 2022-04-26T09:54:05.536Z] 09:54:05 INFO - 04-26 09:54:04.375 I/MultiDex(22762): Installing application
[task 2022-04-26T09:54:05.536Z] 09:54:05 INFO - 04-26 09:54:04.375 I/MultiDex(22762): VM has multidex support, MultiDex support library is disabled.
[task 2022-04-26T09:54:05.537Z] 09:54:05 INFO - 04-26 09:54:04.377 I/ServiceChildProcess(22762): onCreate
[task 2022-04-26T09:54:05.537Z] 09:54:05 INFO - 04-26 09:54:04.378 D/GeckoThread(22762): State changed to LAUNCHED
[task 2022-04-26T09:54:05.537Z] 09:54:05 INFO - 04-26 09:54:04.379 I/GeckoThread(22762): preparing to run Gecko
[task 2022-04-26T09:54:05.537Z] 09:54:05 INFO - 04-26 09:54:04.383 D/ServiceAllocator( 3477): org.mozilla.gecko.process.GeckoChildProcessServices$tab29 updateBindings: FOREGROUND priority, 2 importance, 0 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-04-26T09:54:05.537Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: MOZ_CRASHREPORTER=1
[task 2022-04-26T09:54:05.537Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: MOZ_CRASHREPORTER_SHUTDOWN=1
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: XPCOM_DEBUG_BREAK=stack
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: MOZ_DISABLE_NONLOCAL_CONNECTIONS=1
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: MOZ_IN_AUTOMATION=1
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: R_LOG_VERBOSE=1
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: R_LOG_LEVEL=6
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: R_LOG_DESTINATION=stderr
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: MOZ_WEBRENDER=1
[task 2022-04-26T09:54:05.538Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoThread(22762): env var: MOZ_FORCE_ENABLE_FISSION=1
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.384 D/GeckoViewXUL( 3477): WillChangeBrowserRemoteness
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.387 D/GeckoThread(22762): State changed to MOZGLUE_READY
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.387 D/GeckoViewSelectionActionDelegate[C](14754): handleEvent: visibilitychange
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.387 D/GeckoViewXUL( 3477): DidChangeBrowserRemoteness
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.388 D/GeckoViewNavigation( 3477): sessionContextId=null
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.388 D/GeckoViewAutoFill[C](14754): handleEvent: pagehide
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.388 I/GeckoLoader(22762): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-26T09:54:05.539Z] 09:54:05 INFO - 04-26 09:54:04.388 D/GeckoViewAutofill(14754): Clearing auto-fill
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.388 I/GeckoLoader(22762): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.388 E/GeckoLibLoad(22762): Load sqlite start
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.389 E/GeckoLibLoad(22762): Load sqlite done
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.389 I/GeckoLoader(22762): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.389 E/GeckoLibLoad(22762): Load nss start
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.389 E/GeckoLibLoad(22762): Load nss done
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.389 I/GeckoLoader(22762): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.401 E/GeckoLibLoad(22762): Loaded libs in 11.595001ms total, 0ms(10ms) user, 0ms(0ms) system, 0(0) faults
[task 2022-04-26T09:54:05.540Z] 09:54:05 INFO - 04-26 09:54:04.401 D/GeckoThread(22762): State changed to LIBS_READY
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.401 W/GeckoThread(22762): zerdatime 362859 - runGecko
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.406 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.416 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.453 D/GeckoThread(22762): State changed to RUNNING
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.467 D/GeckoViewStartup(22762): observe: content-process-ready-for-script
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.469 D/GeckoViewConsole(22762): enabled = true
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.481 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.489 D/GeckoViewXUL( 3477): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.492 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.541Z] 09:54:05 INFO - 04-26 09:54:04.500 D/GeckoViewSelectionActionDelegate[C](22762): handleEvent: visibilitychange
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.502 D/GeckoViewAutoFill[C](22762): handleEvent: pagehide
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.505 D/GeckoViewAutofill(22762): Clearing auto-fill
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.510 D/GeckoViewNavigation( 3477): onLocationChange
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.511 D/GeckoSession( 3477): handleMessage GeckoView:LocationChange uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.511 D/GeckoViewProgress( 3477): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/prompts.html, flags=0
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.511 D/GeckoViewProgress( 3477): ProgressTracker onLocationChange: location=http://localhost:4245/assets/www/prompts.html, flags=0
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.511 D/GeckoViewProgress( 3477): ProgressTracker changeLocation http://localhost:4245/assets/www/prompts.html
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.511 D/GeckoViewProgress( 3477): onSecurityChange
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.511 D/GeckoSession( 3477): handleMessage GeckoView:SecurityChanged uri=null
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.599 D/GeckoViewContent( 3477): handleEvent: pagetitlechanged
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.600 D/GeckoViewContentDelegateChild[C](22762): handleEvent: DOMContentLoaded
[task 2022-04-26T09:54:05.542Z] 09:54:05 INFO - 04-26 09:54:04.601 D/GeckoViewProgressDelegate[C](22762): handleEvent: DOMContentLoaded
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.602 D/GeckoViewProgress( 3477): receiveMessage: DOMContentLoaded
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.602 D/GeckoViewProgress( 3477): ProgressTracker handleEvent: DOMContentLoaded
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.602 D/GeckoViewProgress( 3477): ProgressTracker updateProgress
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.602 D/GeckoViewProgress( 3477): ProgressTracker updateProgress data={"prev":15,"uri":"http://localhost:4245/assets/www/prompts.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":true} progress=55
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.603 D/GeckoSession( 3477): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.614 D/GeckoViewProgressDelegate[C](22762): handleEvent: pageshow
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.614 D/GeckoViewAutoFill[C](22762): handleEvent: pageshow
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.615 D/GeckoViewContent[C](22762): handleEvent: pageshow
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.616 D/WebExtension( 3477): handleMessage GeckoView:WebExtension:Connect
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.616 D/GeckoViewProgress( 3477): receiveMessage: pageshow
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.616 D/GeckoViewProgress( 3477): ProgressTracker handleEvent: pageshow
[task 2022-04-26T09:54:05.543Z] 09:54:05 INFO - 04-26 09:54:04.616 D/GeckoViewProgress( 3477): ProgressTracker updateProgress
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.617 D/GeckoViewProgress( 3477): ProgressTracker updateProgress data={"prev":55,"uri":"http://localhost:4245/assets/www/prompts.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":true,"parsed":true} progress=100
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.617 D/GeckoSession( 3477): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.618 D/GeckoViewProgress( 3477): ProgressTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.618 D/GeckoViewProgress( 3477): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/prompts.html
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.618 D/GeckoViewProgress( 3477): ProgressTracker stop
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.618 D/GeckoViewContentDelegateChild[C](22762): handleEvent: MozFirstContentfulPaint
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.618 D/GeckoViewProgress( 3477): ProgressTracker updateProgress
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.619 D/GeckoViewProgress( 3477): StateTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK loadType=1
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.619 D/GeckoSession( 3477): handleMessage GeckoView:PageStop uri=null
[task 2022-04-26T09:54:05.544Z] 09:54:05 INFO - 04-26 09:54:04.624 D/GeckoViewConsole( 3477): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"24332599-7440-4a30-91c6-53bb8c83a197","eval":"document.getElementById('dateexample').showPicker();"}}
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): Error
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2190)
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2143)
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2309)
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:221)
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.PromptDelegateTest.dateTest(PromptDelegateTest.kt:506)
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at java.lang.reflect.Method.invoke(Native Method)
[task 2022-04-26T09:54:05.545Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1451)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(Unknown Source)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-04-26T09:54:05.546Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at android.os.Looper.loop(Looper.java:154)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at java.lang.reflect.Method.invoke(Native Method)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.627 E/GeckoSessionTestRule( 3477): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.629 E/eglCodecCommon(14926): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.788 D/EGL_emulation(14926): eglMakeCurrent: 0x7adf53e7bae0: ver 3 0 (tinfo 0x7adf53fb9420)
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.790 D/GeckoViewContent( 3477): handleEvent: DOMWindowClose
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.790 D/GeckoViewConsole( 3477): onEvent GeckoView:WebExtension:List null
[task 2022-04-26T09:54:05.547Z] 09:54:05 INFO - 04-26 09:54:04.790 D/GeckoViewProgressDelegate[C](22762): handleEvent: MozAfterPaint
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - 04-26 09:54:04.792 E/GeckoSessionTestRule( 3477): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 dateTest(org.mozilla.geckoview.test.PromptDelegateTest)
[task 2022-04-26T09:54:05.548Z] 09:54:05 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PromptDelegateTest#dateTest | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - TEST-INFO took 571ms
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=887
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=colorTest
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PromptDelegateTest
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=498
[task 2022-04-26T09:54:05.548Z] 09:54:05 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
Whiteboard: [stockwell needswork:owner]
|
|
Assignee | |
Comment 8•2 years ago
|
||
|
||
Updated•2 years ago
|
Assignee: nobody → emilio
Status: NEW → ASSIGNED
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•2 years ago
|
Summary: Intermittent org.mozilla.geckoview.test.PromptDelegateTest#dateTest | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation. → High frequency org.mozilla.geckoview.test.PromptDelegateTest#dateTest | org.mozilla.geckoview.test.rule.GeckoSessionTestRule$RejectedPromiseException: NotAllowedError: HTMLInputElement.showPicker: Call was blocked due to lack of user activation.
|
||
Comment 10•2 years ago
|
||
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/9ca52deb924e Try to avoid intermittent race in PromptDelegateTest. r=agi
|
|
||
Comment 11•2 years ago
|
||
| bugherder | ||
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 101 Branch
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•