Closed Bug 1762485 Opened 4 years ago Closed 3 years ago

Intermittent org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_commitText[#input] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms

Tracking

(Not tracked)

Status:

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Treeherder Bug Filer

Reporter

Description

•

4 years ago

treeherder

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

[task 2022-03-31T21:53:04.020Z] 21:53:04     INFO -  TEST-START | org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_commitText[#input]
[task 2022-03-31T21:53:34.256Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=884
[task 2022-03-31T21:53:34.257Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-03-31T21:53:34.257Z] 21:53:34     INFO -  org.mozilla.geckoview.test | Error in inputConnection_commitText[#input](org.mozilla.geckoview.test.TextInputDelegateTest):
[task 2022-03-31T21:53:34.257Z] 21:53:34     INFO -  org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-03-31T21:53:34.258Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-03-31T21:53:34.258Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-03-31T21:53:34.258Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-03-31T21:53:34.258Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-03-31T21:53:34.258Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1741)
[task 2022-03-31T21:53:34.259Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1522)
[task 2022-03-31T21:53:34.259Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1497)
[task 2022-03-31T21:53:34.259Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.waitForPageStop(BaseSessionTest.kt:181)
[task 2022-03-31T21:53:34.259Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.setupContent(TextInputDelegateTest.kt:402)
[task 2022-03-31T21:53:34.259Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.inputConnection_commitText(TextInputDelegateTest.kt:441)
[task 2022-03-31T21:53:34.260Z] 21:53:34     INFO -  org.mozilla.geckoview.test |
[task 2022-03-31T21:53:34.260Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-03-31T21:53:34.260Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=inputConnection_commitText[#input]
[task 2022-03-31T21:53:34.260Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.TextInputDelegateTest
[task 2022-03-31T21:53:34.260Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-03-31T21:53:34.261Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-03-31T21:53:34.261Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-03-31T21:53:34.261Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-03-31T21:53:34.261Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-03-31T21:53:34.261Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1741)
[task 2022-03-31T21:53:34.262Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1522)
[task 2022-03-31T21:53:34.262Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1497)
[task 2022-03-31T21:53:34.262Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.waitForPageStop(BaseSessionTest.kt:181)
[task 2022-03-31T21:53:34.262Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.setupContent(TextInputDelegateTest.kt:402)
[task 2022-03-31T21:53:34.263Z] 21:53:34     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.inputConnection_commitText(TextInputDelegateTest.kt:441)
[task 2022-03-31T21:53:34.263Z] 21:53:34     INFO -  org.mozilla.geckoview.test |
[task 2022-03-31T21:53:34.263Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=661
[task 2022-03-31T21:53:34.263Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2022-03-31T21:53:34.263Z] 21:53:34     INFO -  Printing logcat for test:
[task 2022-03-31T21:53:34.329Z] 21:53:34     INFO -  03-31 21:53:03.313 E/GeckoSessionTestRule( 3405): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec inputConnection_commitText[#input](org.mozilla.geckoview.test.TextInputDelegateTest)
[task 2022-03-31T21:53:34.329Z] 21:53:34     INFO -  03-31 21:53:03.313 E/GeckoSessionTestRule( 3405): before prepareStatement inputConnection_commitText[#input](org.mozilla.geckoview.test.TextInputDelegateTest)
[task 2022-03-31T21:53:34.330Z] 21:53:34     INFO -  03-31 21:53:03.316 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.330Z] 21:53:34     INFO -  03-31 21:53:03.318 D/GeckoViewStartup( 3405): onEvent GeckoView:StorageDelegate:Attached
[task 2022-03-31T21:53:34.330Z] 21:53:34     INFO -  03-31 21:53:03.324 I/ServiceChildProcess(29004): Destroying GeckoServiceChildProcess
[task 2022-03-31T21:53:34.330Z] 21:53:34     INFO -  03-31 21:53:03.326 I/art     (29004): System.exit called, status: 0
[task 2022-03-31T21:53:34.330Z] 21:53:34     INFO -  03-31 21:53:03.326 I/AndroidRuntime(29004): VM exiting with result code 0, cleanup skipped.
[task 2022-03-31T21:53:34.331Z] 21:53:34     INFO -  03-31 21:53:03.331 D/GeckoViewNavigation( 3405): sessionContextId=null
[task 2022-03-31T21:53:34.331Z] 21:53:34     INFO -  03-31 21:53:03.336 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.331Z] 21:53:34     INFO -  03-31 21:53:03.344 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008741
[task 2022-03-31T21:53:34.331Z] 21:53:34     INFO -  03-31 21:53:03.349 D/GeckoViewModule( 3405): 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-03-31T21:53:34.332Z] 21:53:34     INFO -  03-31 21:53:03.350 D/GeckoViewNavigation( 3405): onInit
[task 2022-03-31T21:53:34.332Z] 21:53:34     INFO -  03-31 21:53:03.350 D/GeckoViewModule( 3405): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
[task 2022-03-31T21:53:34.332Z] 21:53:34     INFO -  03-31 21:53:03.350 D/GeckoViewNavigation( 3405): onEnable
[task 2022-03-31T21:53:34.332Z] 21:53:34     INFO -  03-31 21:53:03.350 D/GeckoViewProcessHangMonitor( 3405): onInit
[task 2022-03-31T21:53:34.332Z] 21:53:34     INFO -  03-31 21:53:03.350 D/GeckoViewProcessHangMonitor( 3405): onEnable
[task 2022-03-31T21:53:34.333Z] 21:53:34     INFO -  03-31 21:53:03.350 D/GeckoViewModule( 3405): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2022-03-31T21:53:34.333Z] 21:53:34     INFO -  03-31 21:53:03.351 D/GeckoViewProgress( 3405): onEnable
[task 2022-03-31T21:53:34.333Z] 21:53:34     INFO -  03-31 21:53:03.351 D/GeckoViewModule( 3405): registerListener GeckoView:FlushSessionState
[task 2022-03-31T21:53:34.333Z] 21:53:34     INFO -  03-31 21:53:03.351 D/GeckoViewSettings( 3405): onInit
[task 2022-03-31T21:53:34.333Z] 21:53:34     INFO -  03-31 21:53:03.352 D/GeckoViewModule( 3405): registerListener ["GeckoView:GetUserAgent"]
[task 2022-03-31T21:53:34.334Z] 21:53:34     INFO -  03-31 21:53:03.352 D/GeckoViewSettings( 3405): 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-03-31T21:53:34.334Z] 21:53:34     INFO -  03-31 21:53:03.352 D/GeckoViewModule( 3405): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2022-03-31T21:53:34.334Z] 21:53:34     INFO -  03-31 21:53:03.352 D/GeckoViewModule( 3405): registerListener ["ContentBlocking:RequestLog"]
[task 2022-03-31T21:53:34.334Z] 21:53:34     INFO -  03-31 21:53:03.353 D/GeckoViewMediaControl( 3405): onEnable
[task 2022-03-31T21:53:34.335Z] 21:53:34     INFO -  03-31 21:53:03.353 D/GeckoViewModule( 3405): 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-03-31T21:53:34.335Z] 21:53:34     INFO -  03-31 21:53:03.354 D/EGL_emulation(23248): eglMakeCurrent: 0x7d191da7e4c0: ver 3 0 (tinfo 0x7d191dab4760)
[task 2022-03-31T21:53:34.335Z] 21:53:34     INFO -  03-31 21:53:03.354 I/GeckoSession( 3405): zerdatime 452843 - chrome startup finished
[task 2022-03-31T21:53:34.336Z] 21:53:34     INFO -  03-31 21:53:03.354 D/GeckoSession( 3405): handleMessage GeckoView:PageStart uri=about:blank
[task 2022-03-31T21:53:34.336Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-03-31T21:53:34.336Z] 21:53:34     INFO -  03-31 21:53:03.354 D/GeckoSession( 3405): handleMessage GeckoView:LocationChange uri=about:blank
[task 2022-03-31T21:53:34.337Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2022-03-31T21:53:34.337Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-03-31T21:53:34.337Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-03-31T21:53:34.337Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-03-31T21:53:34.338Z] 21:53:34     INFO -  03-31 21:53:03.354 D/GeckoSession( 3405): handleMessage GeckoView:PageStop uri=null
[task 2022-03-31T21:53:34.338Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-03-31T21:53:34.338Z] 21:53:34     INFO -  03-31 21:53:03.354 E/GeckoSessionTestRule( 3405): after prepareStatement
[task 2022-03-31T21:53:34.338Z] 21:53:34     INFO -  03-31 21:53:03.355 D/GeckoViewSelectionActionDelegate[C](28385): handleEvent: visibilitychange
[task 2022-03-31T21:53:34.339Z] 21:53:34     INFO -  03-31 21:53:03.356 D/GeckoViewSettings[C](28385): receiveMessage: SettingsUpdate
[task 2022-03-31T21:53:34.339Z] 21:53:34     INFO -  03-31 21:53:03.357 D/GeckoViewConsole( 3405): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"97e214d9-c74e-4cc4-be93-6e1c16349fc6","args":{"oldPrefs":{},"newPrefs":{"dom.select_events.textcontrols.enabled":true}},"type":"SetPrefs"}}
[task 2022-03-31T21:53:34.339Z] 21:53:34     INFO -  03-31 21:53:03.358 W/GeckoEditableChild(28385): No editable parent
[task 2022-03-31T21:53:34.339Z] 21:53:34     INFO -  03-31 21:53:03.359 D/GeckoViewXUL( 3405): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-03-31T21:53:34.340Z] 21:53:34     INFO -  03-31 21:53:03.359 D/GeckoViewModule( 3405): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/inputs.html","flags":0,"headerFilter":1}
[task 2022-03-31T21:53:34.340Z] 21:53:34     INFO -  03-31 21:53:03.359 D/GeckoViewNavigation( 3405): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/inputs.html","flags":0,"headerFilter":1}
[task 2022-03-31T21:53:34.340Z] 21:53:34     INFO -  03-31 21:53:03.365 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.340Z] 21:53:34     INFO -  03-31 21:53:03.366 D/GeckoViewProgress( 3405): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2022-03-31T21:53:34.341Z] 21:53:34     INFO -  03-31 21:53:03.366 D/GeckoViewProgress( 3405): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/inputs.html
[task 2022-03-31T21:53:34.341Z] 21:53:34     INFO -  03-31 21:53:03.366 D/GeckoViewProgress( 3405): ProgressTracker start http://localhost:4245/assets/www/inputs.html
[task 2022-03-31T21:53:34.341Z] 21:53:34     INFO -  03-31 21:53:03.366 D/GeckoViewProgress( 3405): ProgressTracker updateProgress
[task 2022-03-31T21:53:34.341Z] 21:53:34     INFO -  03-31 21:53:03.366 D/GeckoViewProgress( 3405): ProgressTracker updateProgress data={"prev":0,"uri":"http://localhost:4245/assets/www/inputs.html","locationChange":false,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":false} progress=15
[task 2022-03-31T21:53:34.342Z] 21:53:34     INFO -  03-31 21:53:03.367 D/GeckoViewProgress( 3405): StateTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK loadType=1
[task 2022-03-31T21:53:34.342Z] 21:53:34     INFO -  03-31 21:53:03.367 D/GeckoSession( 3405): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-03-31T21:53:34.342Z] 21:53:34     INFO -  03-31 21:53:03.367 D/GeckoSession( 3405): handleMessage GeckoView:PageStart uri=http://localhost:4245/assets/www/inputs.html
[task 2022-03-31T21:53:34.342Z] 21:53:34     INFO -  03-31 21:53:03.373 I/art     (29050): Late-enabling -Xcheck:jni
[task 2022-03-31T21:53:34.342Z] 21:53:34     INFO -  03-31 21:53:03.374 W/art     (29050): Unexpected CPU variant for X86 using defaults: x86_64
[task 2022-03-31T21:53:34.342Z] 21:53:34     INFO -  03-31 21:53:03.379 I/ActivityManager( 1647): Start proc 29050:org.mozilla.geckoview.test:tab0/u0a62 for service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab0
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.381 D/ServiceAllocator( 3405): org.mozilla.gecko.process.GeckoChildProcessServices$tab0 updateBindings: FOREGROUND priority, 0 importance, 3 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.389 I/MultiDex(29050): VM with version 2.1.0 has multidex support
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.389 I/MultiDex(29050): Installing application
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.389 I/MultiDex(29050): VM has multidex support, MultiDex support library is disabled.
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.390 I/ServiceChildProcess(29050): onCreate
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.391 D/GeckoThread(29050): State changed to LAUNCHED
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.391 I/GeckoThread(29050): preparing to run Gecko
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: MOZ_CRASHREPORTER=1
[task 2022-03-31T21:53:34.343Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: MOZ_CRASHREPORTER_SHUTDOWN=1
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: XPCOM_DEBUG_BREAK=stack
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: MOZ_DISABLE_NONLOCAL_CONNECTIONS=1
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: MOZ_IN_AUTOMATION=1
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: R_LOG_VERBOSE=1
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: R_LOG_LEVEL=6
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: R_LOG_DESTINATION=stderr
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: MOZ_WEBRENDER=1
[task 2022-03-31T21:53:34.344Z] 21:53:34     INFO -  03-31 21:53:03.395 D/GeckoThread(29050): env var: MOZ_FORCE_ENABLE_FISSION=1
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.395 D/ServiceAllocator( 3405): org.mozilla.gecko.process.GeckoChildProcessServices$tab0 updateBindings: FOREGROUND priority, 2 importance, 0 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.396 D/GeckoThread(29050): State changed to MOZGLUE_READY
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.396 D/GeckoViewXUL( 3405): WillChangeBrowserRemoteness
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.397 I/GeckoLoader(29050): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.397 I/GeckoLoader(29050): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.397 E/GeckoLibLoad(29050): Load sqlite start
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.397 E/GeckoLibLoad(29050): Load sqlite done
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.397 I/GeckoLoader(29050): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-03-31T21:53:34.345Z] 21:53:34     INFO -  03-31 21:53:03.397 E/GeckoLibLoad(29050): Load nss start
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.397 E/GeckoLibLoad(29050): Load nss done
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.397 I/GeckoLoader(29050): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.398 D/GeckoViewSelectionActionDelegate[C](28385): handleEvent: visibilitychange
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.399 D/GeckoViewAutoFill[C](28385): handleEvent: pagehide
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.399 D/GeckoViewXUL( 3405): DidChangeBrowserRemoteness
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.399 D/GeckoViewAutofill(28385): Clearing auto-fill
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.399 D/GeckoViewNavigation( 3405): sessionContextId=null
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.408 E/GeckoLibLoad(29050): Loaded libs in 10.123461ms total, 0ms(10ms) user, 0ms(0ms) system, 0(0) faults
[task 2022-03-31T21:53:34.346Z] 21:53:34     INFO -  03-31 21:53:03.408 D/GeckoThread(29050): State changed to LIBS_READY
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.408 W/GeckoThread(29050): zerdatime 452896 - runGecko
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.412 I/ActivityManager( 1647): Process org.mozilla.geckoview.test:tab15 (pid 29004) has died
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.412 D/ActivityManager( 1647): cleanUpApplicationRecord -- 29004
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.414 D/GeckoViewContent( 3405): observe: ipc:content-shutdown
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.414 I/Gecko   ( 3405): [Parent 3405, Unnamed thread 7d1903722ef0] WARNING: waitpid failed pid:29004 errno:10: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:221
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.418 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.428 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.347Z] 21:53:34     INFO -  03-31 21:53:03.472 D/GeckoThread(29050): State changed to RUNNING
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.493 D/GeckoViewStartup(29050): observe: content-process-ready-for-script
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.494 D/GeckoViewConsole(29050): enabled = true
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.506 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.514 D/GeckoViewXUL( 3405): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.522 D/GeckoViewSelectionActionDelegate[C](29050): handleEvent: visibilitychange
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.523 D/GeckoViewAutoFill[C](29050): handleEvent: pagehide
[task 2022-03-31T21:53:34.348Z] 21:53:34     INFO -  03-31 21:53:03.524 D/GeckoViewAutofill(29050): Clearing auto-fill
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.527 W/Isolated Web Content(29050): [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/inputs.html" line: 0}]
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.528 D/GeckoViewNavigation( 3405): onLocationChange
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.529 E/eglCodecCommon(23248): glUtilsParamSize: unknow param 0x00008caa
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.529 D/GeckoSession( 3405): handleMessage GeckoView:LocationChange uri=http://localhost:4245/assets/www/inputs.html
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.529 D/GeckoViewProgress( 3405): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/inputs.html, flags=0
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.529 D/GeckoViewProgress( 3405): ProgressTracker onLocationChange: location=http://localhost:4245/assets/www/inputs.html, flags=0
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.529 D/GeckoViewProgress( 3405): ProgressTracker changeLocation http://localhost:4245/assets/www/inputs.html
[task 2022-03-31T21:53:34.349Z] 21:53:34     INFO -  03-31 21:53:03.529 D/GeckoViewProgress( 3405): onSecurityChange
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:03.529 D/GeckoSession( 3405): handleMessage GeckoView:SecurityChanged uri=null
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:07.129 D/GeckoIdleService( 3405): Get idle time: time since reset 5007 msec
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:07.129 D/GeckoIdleService( 3405): Idle timer callback: current idle time 5007 msec
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:07.129 D/GeckoIdleService( 3405): next timeout 4294967289992 msec from now
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:07.129 D/GeckoIdleService( 3405): SetTimerExpiryIfBefore: next timeout 4294967289992 msec from now
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:07.129 D/GeckoIdleService( 3405): reset timer expiry to 4294967290002 msec from now
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:07.129 D/GeckoIdleService( 3405): Idle timer callback: tell observer 0x7d18ef4a51e8 user is idle
[task 2022-03-31T21:53:34.350Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): Error
[task 2022-03-31T21:53:34.351Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-03-31T21:53:34.351Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-03-31T21:53:34.351Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-03-31T21:53:34.351Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-03-31T21:53:34.351Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-03-31T21:53:34.351Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1741)
[task 2022-03-31T21:53:34.352Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1522)
[task 2022-03-31T21:53:34.352Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1497)
[task 2022-03-31T21:53:34.352Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.BaseSessionTest.waitForPageStop(BaseSessionTest.kt:181)
[task 2022-03-31T21:53:34.352Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.TextInputDelegateTest.setupContent(TextInputDelegateTest.kt:402)
[task 2022-03-31T21:53:34.352Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.TextInputDelegateTest.inputConnection_commitText(TextInputDelegateTest.kt:441)
[task 2022-03-31T21:53:34.352Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1451)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(Unknown Source)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-03-31T21:53:34.353Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.os.Looper.loop(Looper.java:154)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.536 E/GeckoSessionTestRule( 3405): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.537 D/GeckoViewConsole( 3405): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"66c962b8-66bd-454c-b979-d2c997481fc7","args":{"oldPrefs":{"dom.select_events.textcontrols.enabled":null}},"type":"RestorePrefs"}}
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.543 D/EGL_emulation(23248): eglMakeCurrent: 0x7d191da7e4c0: ver 3 0 (tinfo 0x7d191dab4760)
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.545 D/GeckoViewContent( 3405): handleEvent: DOMWindowClose
[task 2022-03-31T21:53:34.354Z] 21:53:34     INFO -  03-31 21:53:33.546 D/GeckoViewConsole( 3405): onEvent GeckoView:WebExtension:List null
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  03-31 21:53:33.547 E/GeckoSessionTestRule( 3405): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 inputConnection_commitText[#input](org.mozilla.geckoview.test.TextInputDelegateTest)
[task 2022-03-31T21:53:34.355Z] 21:53:34  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_commitText[#input] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  TEST-INFO took 30310ms
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=884
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=restartInput_temporaryFocus[#input]
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.TextInputDelegateTest
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=662
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2022-03-31T21:53:34.355Z] 21:53:34     INFO -  TEST-START | org.mozilla.geckoview.test.TextInputDelegateTest#restartInput_temporaryFocus[#input]

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

Comment 3

•

4 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED

Closed: 4 years ago

Resolution: --- → INCOMPLETE

Chris Peterson [:cpeterson]

Comment 4

•

4 years ago

Moving some input bugs to the new GeckoView::IME component.

Component: General → IME

Treeherder Bug Filer

Reporter

Comment 5

•

3 years ago

treeherder

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=394663484&repo=mozilla-central

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

Comment 7

•

3 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED

Closed: 4 years ago → 3 years ago

Resolution: --- → INCOMPLETE

You need to log in before you can comment on or make changes to this bug.

Bugzilla

Intermittent org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_commitText[#input] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms

Categories

(GeckoView :: IME, defect, P5)

Tracking

(Not tracked)

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7