Closed Bug 1763377 Opened 4 years ago Closed 3 years ago

Intermittent org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_multiple_setComposingText[#contenteditable] | 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: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=373578341&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/duKunBfWTWG4oaWhc6Wasw/runs/0/artifacts/public/logs/live_backing.log

[task 2022-04-06T10:19:59.193Z] 10:19:59     INFO -  TEST-START | org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_multiple_setComposingText[#contenteditable]
[task 2022-04-06T10:20:29.582Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=884
[task 2022-04-06T10:20:29.582Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-04-06T10:20:29.582Z] 10:20:29     INFO -  org.mozilla.geckoview.test | Error in inputConnection_multiple_setComposingText[#contenteditable](org.mozilla.geckoview.test.TextInputDelegateTest):
[task 2022-04-06T10:20:29.582Z] 10:20:29     INFO -  org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-04-06T10:20:29.582Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-04-06T10:20:29.582Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1741)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1522)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1497)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.waitForPageStop(BaseSessionTest.kt:181)
[task 2022-04-06T10:20:29.583Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.setupContent(TextInputDelegateTest.kt:402)
[task 2022-04-06T10:20:29.584Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.inputConnection_multiple_setComposingText(TextInputDelegateTest.kt:650)
[task 2022-04-06T10:20:29.584Z] 10:20:29     INFO -  org.mozilla.geckoview.test |
[task 2022-04-06T10:20:29.584Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-06T10:20:29.584Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=inputConnection_multiple_setComposingText[#contenteditable]
[task 2022-04-06T10:20:29.584Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.TextInputDelegateTest
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1741)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1522)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1497)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.waitForPageStop(BaseSessionTest.kt:181)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.setupContent(TextInputDelegateTest.kt:402)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.TextInputDelegateTest.inputConnection_multiple_setComposingText(TextInputDelegateTest.kt:650)
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test |
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=712
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2022-04-06T10:20:29.586Z] 10:20:29     INFO -  Printing logcat for test:
[task 2022-04-06T10:20:29.649Z] 10:20:29     INFO -  04-06 10:19:58.549 E/GeckoSessionTestRule( 3494): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec inputConnection_multiple_setComposingText[#contenteditable](org.mozilla.geckoview.test.TextInputDelegateTest)
[task 2022-04-06T10:20:29.650Z] 10:20:29     INFO -  04-06 10:19:58.549 E/GeckoSessionTestRule( 3494): before prepareStatement inputConnection_multiple_setComposingText[#contenteditable](org.mozilla.geckoview.test.TextInputDelegateTest)
[task 2022-04-06T10:20:29.650Z] 10:20:29     INFO -  04-06 10:19:58.550 D/GeckoViewSelectionActionDelegate[C](31207): handleEvent: visibilitychange
[task 2022-04-06T10:20:29.650Z] 10:20:29     INFO -  04-06 10:19:58.550 D/GeckoViewAutoFill[C](31207): handleEvent: pagehide
[task 2022-04-06T10:20:29.650Z] 10:20:29     INFO -  04-06 10:19:58.550 D/GeckoViewSelectionActionDelegate[C](31207): handleEvent: visibilitychange
[task 2022-04-06T10:20:29.650Z] 10:20:29     INFO -  04-06 10:19:58.550 D/GeckoViewAutoFill[C](31207): handleEvent: pagehide
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.553 E/eglCodecCommon(23407): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.556 D/GeckoViewStartup( 3494): onEvent GeckoView:StorageDelegate:Attached
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.565 I/ServiceChildProcess(31207): Destroying GeckoServiceChildProcess
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.566 I/art     (31207): System.exit called, status: 0
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.567 I/AndroidRuntime(31207): VM exiting with result code 0, cleanup skipped.
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.571 D/GeckoViewNavigation( 3494): sessionContextId=null
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.578 E/eglCodecCommon(23407): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.599 E/eglCodecCommon(23407): glUtilsParamSize: unknow param 0x00008741
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.603 D/GeckoViewModule( 3494): 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-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.603 D/GeckoViewNavigation( 3494): onInit
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.603 D/GeckoViewModule( 3494): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.603 D/GeckoViewNavigation( 3494): onEnable
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.604 D/GeckoViewProcessHangMonitor( 3494): onInit
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.604 D/GeckoViewProcessHangMonitor( 3494): onEnable
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.604 D/GeckoViewModule( 3494): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.604 D/GeckoViewProgress( 3494): onEnable
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.604 D/GeckoViewModule( 3494): registerListener GeckoView:FlushSessionState
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.605 D/GeckoViewSettings( 3494): onInit
[task 2022-04-06T10:20:29.652Z] 10:20:29     INFO -  04-06 10:19:58.605 D/GeckoViewModule( 3494): registerListener ["GeckoView:GetUserAgent"]
[task 2022-04-06T10:20:29.653Z] 10:20:29     INFO -  04-06 10:19:58.605 D/GeckoViewSettings( 3494): 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-06T10:20:29.653Z] 10:20:29     INFO -  04-06 10:19:58.607 D/EGL_emulation(23407): eglMakeCurrent: 0x7a1a9a588f40: ver 3 0 (tinfo 0x7a1a9a59aaa0)
[task 2022-04-06T10:20:29.653Z] 10:20:29     INFO -  04-06 10:19:58.607 D/GeckoViewModule( 3494): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2022-04-06T10:20:29.653Z] 10:20:29     INFO -  04-06 10:19:58.607 D/GeckoSession( 3494): handleMessage GeckoView:PageStart uri=about:blank
[task 2022-04-06T10:20:29.653Z] 10:20:29     INFO -  04-06 10:19:58.607 E/GeckoSessionTestRule( 3494): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-04-06T10:20:29.654Z] 10:20:29     INFO -  04-06 10:19:58.607 D/GeckoSession( 3494): handleMessage GeckoView:LocationChange uri=about:blank
[task 2022-04-06T10:20:29.654Z] 10:20:29     INFO -  04-06 10:19:58.607 E/GeckoSessionTestRule( 3494): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2022-04-06T10:20:29.654Z] 10:20:29     INFO -  04-06 10:19:58.607 E/GeckoSessionTestRule( 3494): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-04-06T10:20:29.654Z] 10:20:29     INFO -  04-06 10:19:58.607 E/GeckoSessionTestRule( 3494): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-06T10:20:29.654Z] 10:20:29     INFO -  04-06 10:19:58.607 E/GeckoSessionTestRule( 3494): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-06T10:20:29.654Z] 10:20:29     INFO -  04-06 10:19:58.607 D/GeckoSession( 3494): handleMessage GeckoView:PageStop uri=null
[task 2022-04-06T10:20:29.655Z] 10:20:29     INFO -  04-06 10:19:58.608 E/GeckoSessionTestRule( 3494): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.608 E/GeckoSessionTestRule( 3494): after prepareStatement
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.608 D/GeckoViewModule( 3494): registerListener ["ContentBlocking:RequestLog"]
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.608 D/GeckoViewSelectionActionDelegate[C](28536): handleEvent: visibilitychange
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.609 D/GeckoViewMediaControl( 3494): onEnable
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.609 D/GeckoViewSettings[C](28536): receiveMessage: SettingsUpdate
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.609 D/GeckoViewModule( 3494): 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-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.611 I/GeckoSession( 3494): zerdatime 632605 - chrome startup finished
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.614 D/GeckoViewConsole( 3494): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"4e5dd765-2207-4ec0-9d70-b4935fdd4956","args":{"oldPrefs":{},"newPrefs":{"dom.select_events.textcontrols.enabled":true}},"type":"SetPrefs"}}
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.614 W/GeckoEditableChild(28536): No editable parent
[task 2022-04-06T10:20:29.656Z] 10:20:29     INFO -  04-06 10:19:58.616 I/ActivityManager( 1658): Process org.mozilla.geckoview.test:tab15 (pid 31207) has died
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.616 D/ActivityManager( 1658): cleanUpApplicationRecord -- 31207
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.617 D/GeckoViewXUL( 3494): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.618 D/GeckoViewContent( 3494): observe: ipc:content-shutdown
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.619 I/Gecko   ( 3494): [Parent 3494, Unnamed thread 7a1a8aa22ab0] WARNING: waitpid failed pid:31207 errno:10: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:221
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.620 D/GeckoViewModule( 3494): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/inputs.html","flags":0,"headerFilter":1}
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.621 D/GeckoViewNavigation( 3494): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/inputs.html","flags":0,"headerFilter":1}
[task 2022-04-06T10:20:29.657Z] 10:20:29     INFO -  04-06 10:19:58.623 E/eglCodecCommon(23407): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-06T10:20:29.658Z] 10:20:29     INFO -  04-06 10:19:58.626 D/GeckoViewProgress( 3494): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2022-04-06T10:20:29.658Z] 10:20:29     INFO -  04-06 10:19:58.626 D/GeckoViewProgress( 3494): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/inputs.html
[task 2022-04-06T10:20:29.658Z] 10:20:29     INFO -  04-06 10:19:58.626 D/GeckoViewProgress( 3494): ProgressTracker start http://localhost:4245/assets/www/inputs.html
[task 2022-04-06T10:20:29.658Z] 10:20:29     INFO -  04-06 10:19:58.626 D/GeckoViewProgress( 3494): ProgressTracker updateProgress
[task 2022-04-06T10:20:29.658Z] 10:20:29     INFO -  04-06 10:19:58.626 D/GeckoViewProgress( 3494): 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-04-06T10:20:29.658Z] 10:20:29     INFO -  04-06 10:19:58.627 D/GeckoSession( 3494): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-04-06T10:20:29.659Z] 10:20:29     INFO -  04-06 10:19:58.627 D/GeckoViewProgress( 3494): StateTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK loadType=1
[task 2022-04-06T10:20:29.659Z] 10:20:29     INFO -  04-06 10:19:58.627 D/GeckoSession( 3494): handleMessage GeckoView:PageStart uri=http://localhost:4245/assets/www/inputs.html
[task 2022-04-06T10:20:29.659Z] 10:20:29     INFO -  04-06 10:19:58.636 I/art     (31253): Late-enabling -Xcheck:jni
[task 2022-04-06T10:20:29.659Z] 10:20:29     INFO -  04-06 10:19:58.636 W/art     (31253): Unexpected CPU variant for X86 using defaults: x86_64
[task 2022-04-06T10:20:29.659Z] 10:20:29     INFO -  04-06 10:19:58.641 I/ActivityManager( 1658): Start proc 31253:org.mozilla.geckoview.test:tab17/u0a62 for service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab17
[task 2022-04-06T10:20:29.659Z] 10:20:29     INFO -  04-06 10:19:58.642 D/ServiceAllocator( 3494): org.mozilla.gecko.process.GeckoChildProcessServices$tab17 updateBindings: FOREGROUND priority, 0 importance, 3 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-04-06T10:20:29.660Z] 10:20:29     INFO -  04-06 10:19:58.652 I/MultiDex(31253): VM with version 2.1.0 has multidex support
[task 2022-04-06T10:20:29.660Z] 10:20:29     INFO -  04-06 10:19:58.652 I/MultiDex(31253): Installing application
[task 2022-04-06T10:20:29.660Z] 10:20:29     INFO -  04-06 10:19:58.652 I/MultiDex(31253): VM has multidex support, MultiDex support library is disabled.
[task 2022-04-06T10:20:29.660Z] 10:20:29     INFO -  04-06 10:19:58.654 I/ServiceChildProcess(31253): onCreate
[task 2022-04-06T10:20:29.660Z] 10:20:29     INFO -  04-06 10:19:58.655 D/GeckoThread(31253): State changed to LAUNCHED
[task 2022-04-06T10:20:29.660Z] 10:20:29     INFO -  04-06 10:19:58.656 I/GeckoThread(31253): preparing to run Gecko
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.659 D/ServiceAllocator( 3494): org.mozilla.gecko.process.GeckoChildProcessServices$tab17 updateBindings: FOREGROUND priority, 2 importance, 0 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: MOZ_CRASHREPORTER=1
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: MOZ_CRASHREPORTER_SHUTDOWN=1
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: XPCOM_DEBUG_BREAK=stack
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: MOZ_DISABLE_NONLOCAL_CONNECTIONS=1
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: MOZ_IN_AUTOMATION=1
[task 2022-04-06T10:20:29.661Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: R_LOG_VERBOSE=1
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: R_LOG_LEVEL=6
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: R_LOG_DESTINATION=stderr
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: MOZ_WEBRENDER=1
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.660 D/GeckoThread(31253): env var: MOZ_FORCE_ENABLE_FISSION=1
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.661 D/GeckoViewXUL( 3494): WillChangeBrowserRemoteness
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.662 D/GeckoViewSelectionActionDelegate[C](28536): handleEvent: visibilitychange
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.662 D/GeckoThread(31253): State changed to MOZGLUE_READY
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.662 D/GeckoViewAutoFill[C](28536): handleEvent: pagehide
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.663 I/GeckoLoader(31253): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.663 D/GeckoViewXUL( 3494): DidChangeBrowserRemoteness
[task 2022-04-06T10:20:29.662Z] 10:20:29     INFO -  04-06 10:19:58.663 D/GeckoViewAutofill(28536): Clearing auto-fill
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 I/GeckoLoader(31253): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 D/GeckoViewNavigation( 3494): sessionContextId=null
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 E/GeckoLibLoad(31253): Load sqlite start
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 E/GeckoLibLoad(31253): Load sqlite done
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 I/GeckoLoader(31253): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 E/GeckoLibLoad(31253): Load nss start
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 E/GeckoLibLoad(31253): Load nss done
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.663 I/GeckoLoader(31253): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.672 E/GeckoLibLoad(31253): Loaded libs in 8.870556ms total, 0ms(10ms) user, 0ms(0ms) system, 0(0) faults
[task 2022-04-06T10:20:29.663Z] 10:20:29     INFO -  04-06 10:19:58.672 D/GeckoThread(31253): State changed to LIBS_READY
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:19:58.673 W/GeckoThread(31253): zerdatime 632667 - runGecko
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:19:58.732 E/eglCodecCommon(23407): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:19:58.757 D/GeckoThread(31253): State changed to RUNNING
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:19:58.781 D/GeckoViewStartup(31253): observe: content-process-ready-for-script
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:19:58.783 D/GeckoViewConsole(31253): enabled = true
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:19:58.804 E/eglCodecCommon(23407): glUtilsParamSize: unknow param 0x00008caa
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:20:03.915 D/GeckoIdleService( 3494): Get idle time: time since reset 5413 msec
[task 2022-04-06T10:20:29.664Z] 10:20:29     INFO -  04-06 10:20:03.915 D/GeckoIdleService( 3494): Idle timer callback: current idle time 5413 msec
[task 2022-04-06T10:20:29.665Z] 10:20:29     INFO -  04-06 10:20:03.915 D/GeckoIdleService( 3494): next timeout 4294967289586 msec from now
[task 2022-04-06T10:20:29.665Z] 10:20:29     INFO -  04-06 10:20:03.915 D/GeckoIdleService( 3494): SetTimerExpiryIfBefore: next timeout 4294967289586 msec from now
[task 2022-04-06T10:20:29.665Z] 10:20:29     INFO -  04-06 10:20:03.915 D/GeckoIdleService( 3494): reset timer expiry to 4294967289596 msec from now
[task 2022-04-06T10:20:29.665Z] 10:20:29     INFO -  04-06 10:20:03.915 D/GeckoIdleService( 3494): Idle timer callback: tell observer 0x7a1a78113cc8 user is idle
[task 2022-04-06T10:20:29.665Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): Error
[task 2022-04-06T10:20:29.665Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-04-06T10:20:29.666Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-04-06T10:20:29.666Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-04-06T10:20:29.666Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-04-06T10:20:29.666Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-04-06T10:20:29.666Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitUntilCalled(GeckoSessionTestRule.java:1741)
[task 2022-04-06T10:20:29.666Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStops(GeckoSessionTestRule.java:1522)
[task 2022-04-06T10:20:29.667Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForPageStop(GeckoSessionTestRule.java:1497)
[task 2022-04-06T10:20:29.667Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.BaseSessionTest.waitForPageStop(BaseSessionTest.kt:181)
[task 2022-04-06T10:20:29.667Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.TextInputDelegateTest.setupContent(TextInputDelegateTest.kt:402)
[task 2022-04-06T10:20:29.667Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.TextInputDelegateTest.inputConnection_multiple_setComposingText(TextInputDelegateTest.kt:650)
[task 2022-04-06T10:20:29.668Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-04-06T10:20:29.668Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-04-06T10:20:29.668Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-04-06T10:20:29.668Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-04-06T10:20:29.668Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1451)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(Unknown Source)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.os.Looper.loop(Looper.java:154)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.736 E/GeckoSessionTestRule( 3494): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.919 D/GeckoViewConsole( 3494): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"2902fd7b-426f-473d-b972-7f6e11670324","args":{"oldPrefs":{"dom.select_events.textcontrols.enabled":null}},"type":"RestorePrefs"}}
[task 2022-04-06T10:20:29.670Z] 10:20:29     INFO -  04-06 10:20:28.926 D/EGL_emulation(23407): eglMakeCurrent: 0x7a1a9a588f40: ver 3 0 (tinfo 0x7a1a9a59aaa0)
[task 2022-04-06T10:20:29.671Z] 10:20:29     INFO -  04-06 10:20:28.931 D/GeckoViewContent( 3494): handleEvent: DOMWindowClose
[task 2022-04-06T10:20:29.671Z] 10:20:29     INFO -  04-06 10:20:28.932 D/GeckoViewConsole( 3494): onEvent GeckoView:WebExtension:List null
[task 2022-04-06T10:20:29.671Z] 10:20:29     INFO -  04-06 10:20:28.935 E/GeckoSessionTestRule( 3494): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 inputConnection_multiple_setComposingText[#contenteditable](org.mozilla.geckoview.test.TextInputDelegateTest)
[task 2022-04-06T10:20:29.671Z] 10:20:29  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_multiple_setComposingText[#contenteditable] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-04-06T10:20:29.672Z] 10:20:29     INFO -  TEST-INFO took 30456ms
[task 2022-04-06T10:20:29.672Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=884
[task 2022-04-06T10:20:29.672Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-04-06T10:20:29.672Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-04-06T10:20:29.672Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=inputConnection_getTextBeforeAfterCursor[#contenteditable]
[task 2022-04-06T10:20:29.673Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.TextInputDelegateTest
[task 2022-04-06T10:20:29.673Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=713
[task 2022-04-06T10:20:29.673Z] 10:20:29     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2022-04-06T10:20:29.673Z] 10:20:29     INFO -  TEST-START | org.mozilla.geckoview.test.TextInputDelegateTest#inputConnection_getTextBeforeAfterCursor[#contenteditable]

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

Comment 3

•

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

Treeherder Bug Filer

Reporter

Comment 4

•

3 years ago

treeherder

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=381047094&repo=autoland

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

Comment 6

•

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: 3 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_multiple_setComposingText[#contenteditable] | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms

Categories

(GeckoView :: General, 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