Closed
Bug 1779662
Opened 3 years ago
Closed 2 years ago
Intermittent org.mozilla.geckoview.test.SelectionActionDelegateTest#paste[#textarea] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
Categories
(GeckoView :: General, defect, P5)
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=384415682&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/A06EO65NSuK0J7g31YyYiw/runs/0/artifacts/public/logs/live_backing.log
[task 2022-07-14T22:17:51.210Z] 22:17:51 INFO - TEST-START | org.mozilla.geckoview.test.SelectionActionDelegateTest#paste[#textarea]
[task 2022-07-14T22:18:22.374Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=930
[task 2022-07-14T22:18:22.375Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-07-14T22:18:22.375Z] 22:18:22 INFO - org.mozilla.geckoview.test | Error in paste[#textarea](org.mozilla.geckoview.test.SelectionActionDelegateTest):
[task 2022-07-14T22:18:22.375Z] 22:18:22 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2299)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2259)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2425)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:225)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$SelectedEditableElement.focus(SelectionActionDelegateTest.kt:433)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.testThat(SelectionActionDelegateTest.kt:273)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$testThat(SelectionActionDelegateTest.kt:37)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1$1.invoke(SelectionActionDelegateTest.kt:165)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1$1.invoke(SelectionActionDelegateTest.kt:164)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.withClipboard(SelectionActionDelegateTest.kt:368)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$withClipboard(SelectionActionDelegateTest.kt:37)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1.invoke(SelectionActionDelegateTest.kt:164)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1.invoke(SelectionActionDelegateTest.kt:163)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.assumingEditable(SelectionActionDelegateTest.kt:393)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.paste(SelectionActionDelegateTest.kt:163)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test |
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=paste[#textarea]
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SelectionActionDelegateTest
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2299)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2259)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2425)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:225)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$SelectedEditableElement.focus(SelectionActionDelegateTest.kt:433)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.testThat(SelectionActionDelegateTest.kt:273)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$testThat(SelectionActionDelegateTest.kt:37)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1$1.invoke(SelectionActionDelegateTest.kt:165)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1$1.invoke(SelectionActionDelegateTest.kt:164)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.withClipboard(SelectionActionDelegateTest.kt:368)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$withClipboard(SelectionActionDelegateTest.kt:37)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1.invoke(SelectionActionDelegateTest.kt:164)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1.invoke(SelectionActionDelegateTest.kt:163)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.assumingEditable(SelectionActionDelegateTest.kt:393)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.paste(SelectionActionDelegateTest.kt:163)
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test |
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=604
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2022-07-14T22:18:22.381Z] 22:18:22 INFO - Printing logcat for test:
[task 2022-07-14T22:18:22.430Z] 22:18:22 INFO - 07-14 22:17:50.448 E/GeckoSessionTestRule( 3452): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec paste[#textarea](org.mozilla.geckoview.test.SelectionActionDelegateTest)
[task 2022-07-14T22:18:22.430Z] 22:18:22 INFO - 07-14 22:17:50.448 E/GeckoSessionTestRule( 3452): before prepareStatement paste[#textarea](org.mozilla.geckoview.test.SelectionActionDelegateTest)
[task 2022-07-14T22:18:22.430Z] 22:18:22 INFO - 07-14 22:17:50.452 D/GeckoViewStartup( 3452): onEvent GeckoView:StorageDelegate:Attached
[task 2022-07-14T22:18:22.430Z] 22:18:22 INFO - 07-14 22:17:50.452 I/Gecko ( 3452): nsWindow[0x73d927c18400]::Create 0x0 [0 0 1 1]
[task 2022-07-14T22:18:22.431Z] 22:18:22 INFO - 07-14 22:17:50.503 D/GeckoViewNavigation( 3452): sessionContextId=null
[task 2022-07-14T22:18:22.431Z] 22:18:22 INFO - 07-14 22:17:50.503 D/EGL_emulation( 2105): eglMakeCurrent: 0x73d989a81b20: ver 3 0 (tinfo 0x73d989a95ae0)
[task 2022-07-14T22:18:22.431Z] 22:18:22 INFO - 07-14 22:17:50.517 I/WindowManager( 1652): Destroying surface Surface(name=com.android.launcher3/com.android.launcher3.Launcher) called by com.android.server.wm.WindowStateAnimator.destroySurface:2014 com.android.server.wm.WindowStateAnimator.destroySurfaceLocked:881 com.android.server.wm.WindowState.destroyOrSaveSurface:2073 com.android.server.wm.WindowManagerService.tryStartExitingAnimation:3017 com.android.server.wm.WindowManagerService.relayoutWindow:2897 com.android.server.wm.Session.relayout:215 android.view.IWindowSession$Stub.onTransact:286 com.android.server.wm.Session.onTransact:136
[task 2022-07-14T22:18:22.431Z] 22:18:22 INFO - 07-14 22:17:50.518 E/eglCodecCommon(20887): glUtilsParamSize: unknow param 0x00008caa
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.522 D/EGL_emulation( 3452): eglMakeCurrent: 0x73d95f8a7ac0: ver 3 0 (tinfo 0x73d96485cf60)
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.559 W/webrender::device::gl(20887): Missing optimized shader source for gpu_cache_update
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.560 I/ActivityManager( 1652): Displayed org.mozilla.geckoview.test/.GeckoViewTestActivity: +121ms (total +144ms)
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.571 E/eglCodecCommon(20887): glUtilsParamSize: unknow param 0x00008741
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.581 D/GeckoViewModule( 3452): registerListener ["GeckoViewContent:ExitFullScreen","GeckoView:ClearMatches","GeckoView:DisplayMatches","GeckoView:FindInPage","GeckoView:RestoreState","GeckoView:ScrollBy","GeckoView:ScrollTo","GeckoView:SetActive","GeckoView:SetFocused","GeckoView:SetPriorityHint","GeckoView:UpdateInitData","GeckoView:ZoomToInput"]
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.582 D/GeckoViewNavigation( 3452): onInit
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.583 D/GeckoViewSelectionActionDelegate[C](15520): handleEvent: visibilitychange
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.583 D/GeckoViewModule( 3452): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.584 D/GeckoViewNavigation( 3452): onEnable
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.585 D/GeckoViewProcessHangMonitor( 3452): onInit
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.585 D/GeckoViewProcessHangMonitor( 3452): onEnable
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.586 D/GeckoViewModule( 3452): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.587 D/GeckoViewProgress( 3452): onEnable
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.588 D/GeckoViewModule( 3452): registerListener GeckoView:FlushSessionState
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.589 D/EGL_emulation(20887): eglMakeCurrent: 0x73d99187eba0: ver 3 0 (tinfo 0x73d9871c3cc0)
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.589 D/GeckoViewSelectionAction( 3452): onEnable
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.590 D/GeckoViewModule( 3452): registerListener ["GeckoView:ExecuteSelectionAction"]
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.590 D/GeckoSession( 3452): handleMessage GeckoView:PageStart uri=about:blank
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.590 E/GeckoSessionTestRule( 3452): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-07-14T22:18:22.436Z] 22:18:22 INFO - 07-14 22:17:50.590 D/GeckoSession( 3452): handleMessage GeckoView:LocationChange uri=about:blank
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 E/GeckoSessionTestRule( 3452): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 E/GeckoSessionTestRule( 3452): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 E/GeckoSessionTestRule( 3452): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 D/GeckoSession( 3452): handleMessage GeckoView:PageStop uri=null
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 E/GeckoSessionTestRule( 3452): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 E/GeckoSessionTestRule( 3452): after prepareStatement
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.590 D/GeckoViewSettings( 3452): onInit
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.591 D/GeckoViewModule( 3452): registerListener ["GeckoView:GetUserAgent"]
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.592 D/GeckoViewSettings( 3452): 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-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.593 D/GeckoViewModule( 3452): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.594 D/GeckoViewModule( 3452): registerListener ["ContentBlocking:RequestLog"]
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.595 D/LifecycleMonitor( 3452): Lifecycle status change: androidx.test.core.app.InstrumentationActivityInvoker$BootstrapActivity@50b350e in: STOPPED
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.595 V/ActivityScenario( 3452): Activity lifecycle changed event received but ignored because the intent does not match. startActivityIntent=Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] cmp=org.mozilla.geckoview.test/.GeckoViewTestActivity }, activity.getIntent()=Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10008000 cmp=org.mozilla.geckoview.test/androidx.test.core.app.InstrumentationActivityInvoker$BootstrapActivity (has extras) }, activity=androidx.test.core.app.InstrumentationActivityInvoker$BootstrapActivity@50b350e
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.596 D/GeckoViewMediaControl( 3452): onEnable
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.596 D/GeckoViewSettings[C](15520): receiveMessage: SettingsUpdate
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.596 D/GeckoViewModule( 3452): 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-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.599 I/GeckoSession( 3452): zerdatime 832696 - chrome startup finished
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.599 I/Gecko ( 3452): nsWindow[0x73d927c18400]::Show 1
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.608 W/GeckoEditableChild(15520): No editable parent
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.619 I/Gecko ( 3452): nsWindow[0x73d927c18400]::Resize [0.000000 0.000000 400.000000 400.000000] (repaint 0)
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.619 I/Gecko ( 3452): nsWindow: 0x73d927c18400 OnSizeChanged [400 400]
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.621 I/Gecko ( 3452): nsWindow[0x73d927c18400]::Resize [0.000000 0.000000 400.000000 400.000000] (repaint 0)
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.622 D/GeckoViewModule( 3452): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/inputs.html","flags":0,"headerFilter":1}
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.623 D/GeckoViewNavigation( 3452): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/inputs.html","flags":0,"headerFilter":1}
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.627 D/GeckoViewXUL( 3452): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.636 D/GeckoViewProgress( 3452): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2022-07-14T22:18:22.437Z] 22:18:22 INFO - 07-14 22:17:50.637 D/GeckoViewProgress( 3452): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/inputs.html
<...>
[task 2022-07-14T22:18:22.449Z] 22:18:22 INFO - 07-14 22:17:51.164 W/Isolated Web Content(22422): [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "http://localhost:4245/assets/www/selectionAction_frame.html" line: 0}]
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.165 D/GeckoViewProgress( 3452): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/selectionAction_frame.html, flags=0
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.173 D/GeckoViewContentDelegateChild[C](22422): handleEvent: DOMContentLoaded
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.179 D/GeckoViewAutoFill[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.184 D/GeckoViewContent[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.186 D/GeckoViewContentDelegateChild[C](22422): handleEvent: DOMContentLoaded
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.191 D/GeckoViewAutoFill[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.191 D/GeckoViewContent[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.197 I/Gecko (22422): [Child 22422, Main Thread] WARNING: EditorBase::GetInlineSpellChecker() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/EditorBase.cpp:2005
[task 2022-07-14T22:18:22.450Z] 22:18:22 INFO - 07-14 22:17:51.197 I/Gecko (22422): [Child 22422, Main Thread] WARNING: EditorBase::GetInlineSpellChecker() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/EditorBase.cpp:2005
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.297 D/GeckoViewProgressDelegate[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.298 D/GeckoViewAutoFill[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.299 D/WebExtension( 3452): handleMessage GeckoView:WebExtension:Connect
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.299 D/GeckoViewContent[C](22422): handleEvent: pageshow
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.300 D/GeckoViewProgress( 3452): receiveMessage: pageshow
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.300 D/GeckoViewProgress( 3452): ProgressTracker handleEvent: pageshow
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.300 D/GeckoViewProgress( 3452): ProgressTracker updateProgress
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.300 D/GeckoViewProgress( 3452): ProgressTracker updateProgress data={"prev":55,"uri":"http://localhost:4245/assets/www/inputs.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":true,"parsed":true} progress=100
[task 2022-07-14T22:18:22.451Z] 22:18:22 INFO - 07-14 22:17:51.301 D/GeckoSession( 3452): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.302 D/GeckoViewProgress( 3452): ProgressTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.302 D/GeckoViewProgress( 3452): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/inputs.html
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.302 D/GeckoViewProgress( 3452): ProgressTracker stop
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.303 D/GeckoViewProgress( 3452): ProgressTracker updateProgress
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.303 D/GeckoViewProgress( 3452): StateTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK loadType=1
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.303 D/GeckoSession( 3452): handleMessage GeckoView:PageStop uri=null
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.305 D/GeckoViewConsole( 3452): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"c235ffa0-7dd8-450a-814d-dfab82558629","eval":"document.querySelector('#textarea').focus()"}}
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.307 D/GeckoViewProgressDelegate[C](22422): handleEvent: MozAfterPaint
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.309 D/GeckoViewProgress( 3452): receiveMessage: MozAfterPaint
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.309 D/GeckoViewContentDelegateChild[C](22422): handleEvent: MozFirstContentfulPaint
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.310 D/GeckoViewContentDelegateParent( 3452): receiveMessage: DispatcherMessage
[task 2022-07-14T22:18:22.452Z] 22:18:22 INFO - 07-14 22:17:51.310 D/GeckoViewContentDelegateChild[C](22422): handleEvent: MozFirstContentfulPaint
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:51.311 D/GeckoViewContentDelegateParent( 3452): receiveMessage: DispatcherMessage
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:51.315 I/Gecko (22422): [Child 22422, Main Thread] WARNING: '!editingHost', file /builds/worker/checkouts/gecko/editor/libeditor/HTMLEditor.cpp:856
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:51.315 I/Gecko (22422): [Child 22422, Main Thread] WARNING: EditorBase::GetInlineSpellChecker() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/EditorBase.cpp:2005
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:51.321 E/eglCodecCommon(20887): glUtilsParamSize: unknow param 0x00008caa
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:51.770 D/ServiceAllocator( 3452): org.mozilla.gecko.process.GeckoChildProcessServices$tab22 updateBindings: IDLE priority, 6 importance, 0 successful binds, 0 failed binds, 2 successful unbinds
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:52.449 I/Gecko ( 3452): nsWindow 0x73d927c19c00 destructor
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:52.449 I/Gecko ( 3452): nsWindow 0x73d927c1a500 destructor
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:17:52.449 I/Gecko ( 3452): nsWindow 0x73d927c18100 destructor
[task 2022-07-14T22:18:22.453Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): Error
[task 2022-07-14T22:18:22.454Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2299)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.evaluateJS(GeckoSessionTestRule.java:2259)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForJS(GeckoSessionTestRule.java:2425)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.BaseSessionTest.waitForJS(BaseSessionTest.kt:225)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest$SelectedEditableElement.focus(SelectionActionDelegateTest.kt:433)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest.testThat(SelectionActionDelegateTest.kt:273)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$testThat(SelectionActionDelegateTest.kt:37)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1$1.invoke(SelectionActionDelegateTest.kt:165)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1$1.invoke(SelectionActionDelegateTest.kt:164)
[task 2022-07-14T22:18:22.455Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest.withClipboard(SelectionActionDelegateTest.kt:368)
[task 2022-07-14T22:18:22.456Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$withClipboard(SelectionActionDelegateTest.kt:37)
[task 2022-07-14T22:18:22.456Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1.invoke(SelectionActionDelegateTest.kt:164)
[task 2022-07-14T22:18:22.456Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest$paste$1.invoke(SelectionActionDelegateTest.kt:163)
[task 2022-07-14T22:18:22.456Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest.assumingEditable(SelectionActionDelegateTest.kt:393)
[task 2022-07-14T22:18:22.456Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.SelectionActionDelegateTest.paste(SelectionActionDelegateTest.kt:163)
[task 2022-07-14T22:18:22.456Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at java.lang.reflect.Method.invoke(Native Method)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1463)
[task 2022-07-14T22:18:22.457Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(Unknown Source)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.os.Looper.loop(Looper.java:154)
[task 2022-07-14T22:18:22.458Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-07-14T22:18:22.459Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at java.lang.reflect.Method.invoke(Native Method)
[task 2022-07-14T22:18:22.459Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - 07-14 22:18:21.305 E/GeckoSessionTestRule( 3452): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - 07-14 22:18:21.309 D/EGL_emulation(20887): eglMakeCurrent: 0x73d99187eba0: ver 3 0 (tinfo 0x73d9871c3cc0)
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - 07-14 22:18:21.312 D/GeckoViewContent( 3452): handleEvent: DOMWindowClose
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - 07-14 22:18:21.313 D/GeckoViewConsole( 3452): onEvent GeckoView:WebExtension:List null
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - 07-14 22:18:21.317 I/Gecko ( 3452): nsWindow[0x73d927c18400]::Show 0
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - 07-14 22:18:21.317 E/GeckoSessionTestRule( 3452): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 paste[#textarea](org.mozilla.geckoview.test.SelectionActionDelegateTest)
[task 2022-07-14T22:18:22.460Z] 22:18:22 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.SelectionActionDelegateTest#paste[#textarea] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-14T22:18:22.460Z] 22:18:22 INFO - TEST-INFO took 31221ms
[task 2022-07-14T22:18:22.476Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=930
[task 2022-07-14T22:18:22.476Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-07-14T22:18:22.476Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-07-14T22:18:22.477Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=multipleActions[#textarea]
[task 2022-07-14T22:18:22.477Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SelectionActionDelegateTest
[task 2022-07-14T22:18:22.477Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=605
[task 2022-07-14T22:18:22.477Z] 22:18:22 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2022-07-14T22:18:22.477Z] 22:18:22 INFO - TEST-START | org.mozilla.geckoview.test.SelectionActionDelegateTest#multipleActions[#textarea]
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•3 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
|
Reporter | |
Comment 3•3 years ago
|
||
| treeherder | ||
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=387531065&repo=autoland
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 5•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: REOPENED → RESOLVED
Closed: 3 years ago → 2 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•