Closed Bug 1780721 Opened 3 years ago Closed 3 years ago

Intermittent org.mozilla.geckoview.test.PanZoomControllerTest#scrollToVerticalTwiceSmooth | 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

•

3 years ago

treeherder

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

[task 2022-07-22T05:45:38.251Z] 05:45:38     INFO -  TEST-START | org.mozilla.geckoview.test.PanZoomControllerTest#scrollToVerticalTwiceSmooth
[task 2022-07-22T05:46:08.499Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=933
[task 2022-07-22T05:46:08.500Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-07-22T05:46:08.500Z] 05:46:08     INFO -  org.mozilla.geckoview.test | Error in scrollToVerticalTwiceSmooth(org.mozilla.geckoview.test.PanZoomControllerTest):
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2327)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.webExtensionApiCall(GeckoSessionTestRule.java:2629)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.promiseAllPaintsDone(GeckoSessionTestRule.java:2561)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.promiseAllPaintsDone(BaseSessionTest.kt:244)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.setupDocument(PanZoomControllerTest.kt:26)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.setupScroll(PanZoomControllerTest.kt:31)
[task 2022-07-22T05:46:08.501Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.scrollToVerticalTwice(PanZoomControllerTest.kt:216)
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.scrollToVerticalTwiceSmooth(PanZoomControllerTest.kt:230)
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test |
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=scrollToVerticalTwiceSmooth
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PanZoomControllerTest
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-22T05:46:08.502Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2327)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.webExtensionApiCall(GeckoSessionTestRule.java:2629)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.promiseAllPaintsDone(GeckoSessionTestRule.java:2561)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.promiseAllPaintsDone(BaseSessionTest.kt:244)
[task 2022-07-22T05:46:08.503Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.setupDocument(PanZoomControllerTest.kt:26)
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.setupScroll(PanZoomControllerTest.kt:31)
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.scrollToVerticalTwice(PanZoomControllerTest.kt:216)
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.scrollToVerticalTwiceSmooth(PanZoomControllerTest.kt:230)
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  org.mozilla.geckoview.test |
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=457
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2022-07-22T05:46:08.504Z] 05:46:08     INFO -  Printing logcat for test:
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.803 E/GeckoSessionTestRule( 3430): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec scrollToVerticalTwiceSmooth(org.mozilla.geckoview.test.PanZoomControllerTest)
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.803 E/GeckoSessionTestRule( 3430): before prepareStatement scrollToVerticalTwiceSmooth(org.mozilla.geckoview.test.PanZoomControllerTest)
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.803 D/GeckoViewSelectionActionDelegate[C](20041): handleEvent: visibilitychange
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.803 D/GeckoViewAutoFill[C](20041): handleEvent: pagehide
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.805 D/EGL_emulation(15876): eglMakeCurrent: 0x70bcea07bd60: ver 3 0 (tinfo 0x70bcdf9b2280)
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.806 E/eglCodecCommon(15876): glUtilsParamSize: unknow param 0x00008caa
[task 2022-07-22T05:46:08.591Z] 05:46:08     INFO -  07-22 05:45:37.808 D/GeckoViewActorParent( 3430): receiveMessage window destroyed MozAfterPaint undefined
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.808 D/GeckoViewStartup( 3430): onEvent GeckoView:StorageDelegate:Attached
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.811 D/GeckoViewAutoFill( 3430): receiveMessage Clear
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.813 I/ServiceChildProcess(20041): Destroying GeckoServiceChildProcess
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.814 I/art     (20041): System.exit called, status: 0
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.814 I/AndroidRuntime(20041): VM exiting with result code 0, cleanup skipped.
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.819 D/GeckoViewNavigation( 3430): sessionContextId=null
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.825 E/eglCodecCommon(15876): glUtilsParamSize: unknow param 0x00008caa
[task 2022-07-22T05:46:08.592Z] 05:46:08     INFO -  07-22 05:45:37.835 E/eglCodecCommon(15876): glUtilsParamSize: unknow param 0x00008741
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.837 D/GeckoViewModule( 3430): 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-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.837 D/GeckoViewNavigation( 3430): onInit
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.837 D/GeckoViewModule( 3430): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.837 D/GeckoViewNavigation( 3430): onEnable
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.837 D/GeckoViewProcessHangMonitor( 3430): onInit
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.837 D/GeckoViewProcessHangMonitor( 3430): onEnable
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.838 D/GeckoViewModule( 3430): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2022-07-22T05:46:08.593Z] 05:46:08     INFO -  07-22 05:45:37.838 D/GeckoViewProgress( 3430): onEnable
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.838 D/EGL_emulation(15876): eglMakeCurrent: 0x70bcea07bd60: ver 3 0 (tinfo 0x70bcdf9b2280)
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.838 D/GeckoViewModule( 3430): registerListener GeckoView:FlushSessionState
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.838 D/GeckoSession( 3430): handleMessage GeckoView:PageStart uri=about:blank
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.838 E/GeckoSessionTestRule( 3430): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.838 D/GeckoSession( 3430): handleMessage GeckoView:LocationChange uri=about:blank
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.839 E/GeckoSessionTestRule( 3430): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewSelectionAction( 3430): onEnable
[task 2022-07-22T05:46:08.594Z] 05:46:08     INFO -  07-22 05:45:37.839 E/GeckoSessionTestRule( 3430): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 E/GeckoSessionTestRule( 3430): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoSession( 3430): handleMessage GeckoView:PageStop uri=null
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewModule( 3430): registerListener ["GeckoView:ExecuteSelectionAction"]
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 E/GeckoSessionTestRule( 3430): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 E/GeckoSessionTestRule( 3430): after prepareStatement
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewSettings( 3430): onInit
[task 2022-07-22T05:46:08.595Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewModule( 3430): registerListener ["GeckoView:GetUserAgent"]
[task 2022-07-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewSettings( 3430): 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-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewSelectionActionDelegate[C](15605): handleEvent: visibilitychange
[task 2022-07-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewModule( 3430): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2022-07-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.839 D/GeckoViewModule( 3430): registerListener ["ContentBlocking:RequestLog"]
[task 2022-07-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.840 D/GeckoViewSettings[C](15605): receiveMessage: SettingsUpdate
[task 2022-07-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.840 D/GeckoViewMediaControl( 3430): onEnable
[task 2022-07-22T05:46:08.596Z] 05:46:08     INFO -  07-22 05:45:37.840 D/GeckoViewModule( 3430): 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-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.841 I/GeckoSession( 3430): zerdatime 286418 - chrome startup finished
[task 2022-07-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.842 W/GeckoEditableChild(15605): No editable parent
[task 2022-07-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.843 D/GeckoViewXUL( 3430): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-07-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.843 D/GeckoViewModule( 3430): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/scroll.html","flags":0,"headerFilter":1}
[task 2022-07-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.843 D/GeckoViewNavigation( 3430): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/scroll.html","flags":0,"headerFilter":1}
[task 2022-07-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.846 D/GeckoViewProgress( 3430): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2022-07-22T05:46:08.597Z] 05:46:08     INFO -  07-22 05:45:37.846 D/GeckoViewProgress( 3430): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/scroll.html
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.847 D/GeckoViewProgress( 3430): ProgressTracker start http://localhost:4245/assets/www/scroll.html
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.847 D/GeckoViewProgress( 3430): ProgressTracker updateProgress
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.847 D/GeckoViewProgress( 3430): ProgressTracker updateProgress data={"prev":0,"uri":"http://localhost:4245/assets/www/scroll.html","locationChange":false,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":false} progress=15
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.847 D/GeckoSession( 3430): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.847 D/GeckoViewProgress( 3430): StateTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK loadType=1
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.848 D/GeckoSession( 3430): handleMessage GeckoView:PageStart uri=http://localhost:4245/assets/www/scroll.html
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.851 E/JavaBinder( 1651): !!! FAILED BINDER TRANSACTION !!!  (parcel size = 76)
[task 2022-07-22T05:46:08.598Z] 05:46:08     INFO -  07-22 05:45:37.852 E/JavaBinder( 1651): !!! FAILED BINDER TRANSACTION !!!  (parcel size = 1784)
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.852 W/ActivityManager( 1651): Application dead when creating service ServiceRecord{d7a57fe u0 org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab5}
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.852 I/ActivityManager( 1651): Process org.mozilla.geckoview.test:tab5 (pid 20041) has died
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.852 D/ActivityManager( 1651): cleanUpApplicationRecord -- 20041
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): Scheduling restart of crashed service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab5 in 1000ms
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): Scheduling restart of crashed service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab5 in 4000ms
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): Exception when starting service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab5
[task 2022-07-22T05:46:08.599Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): android.os.DeadObjectException: Transaction failed on small parcel; remote process probably died
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at android.os.BinderProxy.transactNative(Native Method)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at android.os.BinderProxy.transact(Binder.java:615)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at android.app.ApplicationThreadProxy.scheduleCreateService(ApplicationThreadNative.java:986)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at com.android.server.am.ActiveServices.realStartServiceLocked(ActiveServices.java:1796)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at com.android.server.am.ActiveServices.bringUpServiceLocked(ActiveServices.java:1699)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at com.android.server.am.ActiveServices.bindServiceLocked(ActiveServices.java:1025)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at com.android.server.am.ActivityManagerService.bindService(ActivityManagerService.java:17136)
[task 2022-07-22T05:46:08.600Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at android.app.ActivityManagerNative.onTransact(ActivityManagerNative.java:1134)
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2757)
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.853 W/ActivityManager( 1651): 	at android.os.Binder.execTransact(Binder.java:565)
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.857 I/art     (20085): Late-enabling -Xcheck:jni
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.857 W/art     (20085): Unexpected CPU variant for X86 using defaults: x86_64
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.864 I/ActivityManager( 1651): Start proc 20085:org.mozilla.geckoview.test:tab5/u0a62 for service org.mozilla.geckoview.test/org.mozilla.gecko.process.GeckoChildProcessServices$tab5
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.865 D/ServiceAllocator( 3430): org.mozilla.gecko.process.GeckoChildProcessServices$tab5 updateBindings: FOREGROUND priority, 0 importance, 3 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.874 I/MultiDex(20085): VM with version 2.1.0 has multidex support
[task 2022-07-22T05:46:08.601Z] 05:46:08     INFO -  07-22 05:45:37.874 I/MultiDex(20085): Installing application
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.874 I/MultiDex(20085): VM has multidex support, MultiDex support library is disabled.
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.875 I/ServiceChildProcess(20085): onCreate
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.876 D/GeckoThread(20085): State changed to LAUNCHED
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.877 I/GeckoThread(20085): preparing to run Gecko
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.880 D/ServiceAllocator( 3430): org.mozilla.gecko.process.GeckoChildProcessServices$tab5 updateBindings: FOREGROUND priority, 2 importance, 0 successful binds, 0 failed binds, 0 successful unbinds
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.881 D/GeckoViewXUL( 3430): WillChangeBrowserRemoteness
[task 2022-07-22T05:46:08.602Z] 05:46:08     INFO -  07-22 05:45:37.881 D/GeckoThread(20085): State changed to MOZGLUE_READY
[task 2022-07-22T05:46:08.603Z] 05:46:08     INFO -  07-22 05:45:37.882 I/GeckoLoader(20085): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-07-22T05:46:08.603Z] 05:46:08     INFO -  07-22 05:45:37.882 D/GeckoViewSelectionActionDelegate[C](15605): handleEvent: visibilitychange
[task 2022-07-22T05:46:08.603Z] 05:46:08     INFO -  07-22 05:45:37.882 I/GeckoLoader(20085): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-07-22T05:46:08.603Z] 05:46:08     INFO -  07-22 05:45:37.882 E/GeckoLibLoad(20085): Load sqlite start
[task 2022-07-22T05:46:08.603Z] 05:46:08     INFO -  07-22 05:45:37.882 D/GeckoViewAutoFill[C](15605): handleEvent: pagehide
[task 2022-07-22T05:46:08.603Z] 05:46:08     INFO -  07-22 05:45:37.883 E/GeckoLibLoad(20085): Load sqlite done
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.883 I/GeckoLoader(20085): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.883 E/GeckoLibLoad(20085): Load nss start
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.883 E/GeckoLibLoad(20085): Load nss done
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.883 I/GeckoLoader(20085): Library base=/data/app/org.mozilla.geckoview.test-1/lib/x86_64
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.886 D/GeckoViewXUL( 3430): DidChangeBrowserRemoteness
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.886 D/GeckoViewNavigation( 3430): sessionContextId=null
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.887 D/GeckoViewAutoFill( 3430): receiveMessage Clear
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.893 E/GeckoLibLoad(20085): Loaded libs in 10.053979ms total, 10ms(10ms) user, 0ms(0ms) system, 0(0) faults
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.893 D/GeckoThread(20085): State changed to LIBS_READY
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.893 W/GeckoThread(20085): zerdatime 286471 - runGecko
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.894 D/GeckoViewContent( 3430): observe: ipc:content-shutdown
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.894 I/Gecko   ( 3430): [Parent 3430, Unnamed thread 70bccfe22670] WARNING: waitpid failed pid:20041 errno:10: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:221
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.958 D/GeckoThread(20085): State changed to RUNNING
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.972 D/GeckoViewStartup(20085): observe: content-process-ready-for-script
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.974 D/GeckoViewConsole(20085): enabled = true
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.989 D/GeckoViewXUL( 3430): receiveMessage GeckoView:ContentModuleLoaded {}
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.995 D/GeckoViewSelectionActionDelegate[C](20085): handleEvent: visibilitychange
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.997 D/GeckoViewAutoFill[C](20085): handleEvent: pagehide
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.998 D/GeckoViewAutoFill( 3430): receiveMessage Clear
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.999 D/GeckoViewContentBlocking( 3430): onContentBlockingEvent 8000
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.999 D/GeckoViewContentBlocking( 3430): onContentBlockingEvent matchedList: null
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:37.999 D/GeckoViewContentBlocking( 3430): onContentBlockingEvent matchedTrackingLists: []
[task 2022-07-22T05:46:08.605Z] 05:46:08     INFO -  07-22 05:45:38.000 W/Isolated Web Content(20085): [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/scroll.html" line: 0}]
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.001 D/GeckoViewNavigation( 3430): onLocationChange
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.001 D/GeckoSession( 3430): handleMessage GeckoView:LocationChange uri=http://localhost:4245/assets/www/scroll.html
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.001 D/GeckoViewProgress( 3430): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/scroll.html, flags=0
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.001 D/GeckoViewProgress( 3430): ProgressTracker onLocationChange: location=http://localhost:4245/assets/www/scroll.html, flags=0
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.001 D/GeckoViewProgress( 3430): ProgressTracker changeLocation http://localhost:4245/assets/www/scroll.html
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.001 D/GeckoViewProgress( 3430): onSecurityChange
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.002 D/GeckoSession( 3430): handleMessage GeckoView:SecurityChanged uri=null
[task 2022-07-22T05:46:08.606Z] 05:46:08     INFO -  07-22 05:45:38.023 D/GeckoViewContentDelegateChild[C](20085): handleEvent: DOMMetaViewportFitChanged
[task 2022-07-22T05:46:08.607Z] 05:46:08     INFO -  07-22 05:45:38.027 D/GeckoViewContentDelegateChild[C](20085): handleEvent: DOMContentLoaded
[task 2022-07-22T05:46:08.607Z] 05:46:08     INFO -  07-22 05:45:38.027 D/GeckoViewContent( 3430): handleEvent: pagetitlechanged
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.030 D/GeckoViewProgressDelegate[C](20085): handleEvent: DOMContentLoaded
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.031 D/GeckoViewProgress( 3430): receiveMessage: DOMContentLoaded
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.031 D/GeckoViewProgress( 3430): ProgressTracker handleEvent: DOMContentLoaded
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.031 D/GeckoViewProgress( 3430): ProgressTracker updateProgress
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.031 D/GeckoViewProgress( 3430): ProgressTracker updateProgress data={"prev":15,"uri":"http://localhost:4245/assets/www/scroll.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":true} progress=55
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.032 D/GeckoSession( 3430): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.045 D/GeckoViewProgressDelegate[C](20085): handleEvent: pageshow
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.045 D/GeckoViewAutoFill[C](20085): handleEvent: pageshow
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.046 D/GeckoViewContent[C](20085): handleEvent: pageshow
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.047 D/WebExtension( 3430): handleMessage GeckoView:WebExtension:Connect
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.047 D/GeckoViewProgress( 3430): receiveMessage: pageshow
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.047 D/GeckoViewProgress( 3430): ProgressTracker handleEvent: pageshow
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.047 D/GeckoViewProgress( 3430): ProgressTracker updateProgress
[task 2022-07-22T05:46:08.608Z] 05:46:08     INFO -  07-22 05:45:38.048 D/GeckoViewProgress( 3430): ProgressTracker updateProgress data={"prev":55,"uri":"http://localhost:4245/assets/www/scroll.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":true,"parsed":true} progress=100
[task 2022-07-22T05:46:08.609Z] 05:46:08     INFO -  07-22 05:45:38.048 D/GeckoSession( 3430): handleMessage GeckoView:ProgressChanged uri=null
[task 2022-07-22T05:46:08.609Z] 05:46:08     INFO -  07-22 05:45:38.049 D/GeckoViewProgress( 3430): ProgressTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK
[task 2022-07-22T05:46:08.609Z] 05:46:08     INFO -  07-22 05:45:38.049 D/GeckoViewProgress( 3430): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/scroll.html
[task 2022-07-22T05:46:08.609Z] 05:46:08     INFO -  07-22 05:45:38.049 D/GeckoViewProgress( 3430): ProgressTracker stop
[task 2022-07-22T05:46:08.609Z] 05:46:08     INFO -  07-22 05:45:38.049 D/GeckoViewProgress( 3430): ProgressTracker updateProgress
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:38.049 D/GeckoViewProgress( 3430): StateTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK loadType=1
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:38.049 D/GeckoSession( 3430): handleMessage GeckoView:PageStop uri=null
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:38.050 D/GeckoViewContentDelegateParent( 3430): receiveMessage: DispatcherMessage
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:38.051 D/GeckoViewConsole( 3430): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"91d50daa-663f-42c2-ac0a-bd14b7f046e3","args":{},"type":"PromiseAllPaintsDone"}}
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:38.055 D/GeckoViewTestSupport[C](20085): receiveMessage: PromiseAllPaintsDone
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:38.055 I/Gecko   (20085): waiting for paint...
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:39.393 D/ServiceAllocator( 3430): org.mozilla.gecko.process.GeckoChildProcessServices$tab33 updateBindings: IDLE priority, 6 importance, 0 successful binds, 0 failed binds, 2 successful unbinds
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:40.910 D/GeckoIdleService( 3430): Get idle time: time since reset 4750 msec
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:40.910 D/GeckoIdleService( 3430): Idle timer callback: current idle time 4750 msec
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:40.910 D/GeckoIdleService( 3430): next timeout 249 msec from now
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:40.910 D/GeckoIdleService( 3430): SetTimerExpiryIfBefore: next timeout 249 msec from now
[task 2022-07-22T05:46:08.610Z] 05:46:08     INFO -  07-22 05:45:40.910 D/GeckoIdleService( 3430): reset timer expiry to 259 msec from now
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:41.169 D/GeckoIdleService( 3430): Get idle time: time since reset 5009 msec
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:41.169 D/GeckoIdleService( 3430): Idle timer callback: current idle time 5009 msec
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:41.169 D/GeckoIdleService( 3430): next timeout 4294967289990 msec from now
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:41.169 D/GeckoIdleService( 3430): SetTimerExpiryIfBefore: next timeout 4294967289990 msec from now
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:41.169 D/GeckoIdleService( 3430): reset timer expiry to 4294967290000 msec from now
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:41.169 D/GeckoIdleService( 3430): Idle timer callback: tell observer 0x70bcbbfbd6a8 user is idle
[task 2022-07-22T05:46:08.611Z] 05:46:08     INFO -  07-22 05:45:57.439 D/GeckoViewContent( 3430): observe: ipc:content-shutdown
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:45:57.439 I/Gecko   ( 3430): [Parent 3430, Unnamed thread 70bccfe22670] WARNING: waitpid failed pid:19418 errno:10: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:221
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:45:57.487 I/ActivityManager( 1651): Process org.mozilla.geckoview.test:tab28 (pid 19418) has died
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:45:57.487 D/ActivityManager( 1651): cleanUpApplicationRecord -- 19418
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): Error
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-22T05:46:08.612Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForMessage(GeckoSessionTestRule.java:2327)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.webExtensionApiCall(GeckoSessionTestRule.java:2629)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.promiseAllPaintsDone(GeckoSessionTestRule.java:2561)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.BaseSessionTest.promiseAllPaintsDone(BaseSessionTest.kt:244)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.PanZoomControllerTest.setupDocument(PanZoomControllerTest.kt:26)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.PanZoomControllerTest.setupScroll(PanZoomControllerTest.kt:31)
[task 2022-07-22T05:46:08.613Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.PanZoomControllerTest.scrollToVerticalTwice(PanZoomControllerTest.kt:216)
[task 2022-07-22T05:46:08.614Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.PanZoomControllerTest.scrollToVerticalTwiceSmooth(PanZoomControllerTest.kt:230)
[task 2022-07-22T05:46:08.614Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-07-22T05:46:08.614Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2022-07-22T05:46:08.614Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2022-07-22T05:46:08.614Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2022-07-22T05:46:08.614Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.junit.rules.Verifier$1.evaluate(Verifier.java:35)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1465)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda0.run(Unknown Source)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2022-07-22T05:46:08.615Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.os.Looper.loop(Looper.java:154)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at java.lang.reflect.Method.invoke(Native Method)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.051 E/GeckoSessionTestRule( 3430): 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.051 D/EGL_emulation(15876): eglMakeCurrent: 0x70bcea07bd60: ver 3 0 (tinfo 0x70bcdf9b2280)
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.053 D/GeckoViewContent( 3430): handleEvent: DOMWindowClose
[task 2022-07-22T05:46:08.616Z] 05:46:08     INFO -  07-22 05:46:08.054 D/GeckoViewConsole( 3430): onEvent GeckoView:WebExtension:List null
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  07-22 05:46:08.056 E/GeckoSessionTestRule( 3430): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 scrollToVerticalTwiceSmooth(org.mozilla.geckoview.test.PanZoomControllerTest)
[task 2022-07-22T05:46:08.617Z] 05:46:08  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PanZoomControllerTest#scrollToVerticalTwiceSmooth | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  TEST-INFO took 30339ms
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=933
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=scrollToHorizontalSmooth
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PanZoomControllerTest
[task 2022-07-22T05:46:08.617Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=458
[task 2022-07-22T05:46:08.618Z] 05:46:08     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2022-07-22T05:46:08.618Z] 05:46:08     INFO -  TEST-START | org.mozilla.geckoview.test.PanZoomControllerTest#scrollToHorizontalSmooth

Comment hidden (Intermittent Failures Robot)

BugBot [:suhaib / :marco/ :calixte]

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

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

Bugzilla

Intermittent org.mozilla.geckoview.test.PanZoomControllerTest#scrollToVerticalTwiceSmooth | 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