Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=415668796&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/I_6U1IeATICSL6YDg3kzdQ/runs/0/artifacts/public/logs/live_backing.log
[task 2023-05-13T13:41:30.006Z] 13:41:30 INFO - TEST-START | org.mozilla.geckoview.test.PrintDelegateTest#contentIframeWindowDotPrintTest
[task 2023-05-13T13:42:03.153Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=1033
[task 2023-05-13T13:42:03.153Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2023-05-13T13:42:03.153Z] 13:42:03 INFO - org.mozilla.geckoview.test | Error in contentIframeWindowDotPrintTest(org.mozilla.geckoview.test.PrintDelegateTest):
[task 2023-05-13T13:42:03.153Z] 13:42:03 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2023-05-13T13:42:03.153Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForResult(UiThreadUtils.java:79)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2911)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2896)
[task 2023-05-13T13:42:03.154Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest.contentIframeWindowDotPrintTest$lambda$14(PrintDelegateTest.kt:252)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest.$r8$lambda$wtN9ZgA5fbISxrBr-WlYtlMwuBg(PrintDelegateTest.kt)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest$$ExternalSyntheticLambda7.perform(D8$$SyntheticClass)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | at androidx.test.core.app.ActivityScenario.lambda$onActivity$2$ActivityScenario(ActivityScenario.java:660)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | at androidx.test.core.app.ActivityScenario$$Lambda$4.run(ActivityScenario.java:652)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | at androidx.test.core.app.ActivityScenario.onActivity(ActivityScenario.java:670)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest.contentIframeWindowDotPrintTest(PrintDelegateTest.kt:242)
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test |
[task 2023-05-13T13:42:03.155Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=contentIframeWindowDotPrintTest
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PrintDelegateTest
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2023-05-13T13:42:03.156Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForResult(UiThreadUtils.java:79)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2911)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2896)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest.contentIframeWindowDotPrintTest$lambda$14(PrintDelegateTest.kt:252)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest.$r8$lambda$wtN9ZgA5fbISxrBr-WlYtlMwuBg(PrintDelegateTest.kt)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest$$ExternalSyntheticLambda7.perform(D8$$SyntheticClass)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at androidx.test.core.app.ActivityScenario.lambda$onActivity$2$ActivityScenario(ActivityScenario.java:660)
[task 2023-05-13T13:42:03.157Z] 13:42:03 INFO - org.mozilla.geckoview.test | at androidx.test.core.app.ActivityScenario$$Lambda$4.run(ActivityScenario.java:652)
[task 2023-05-13T13:42:03.158Z] 13:42:03 INFO - org.mozilla.geckoview.test | at androidx.test.core.app.ActivityScenario.onActivity(ActivityScenario.java:670)
[task 2023-05-13T13:42:03.158Z] 13:42:03 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.PrintDelegateTest.contentIframeWindowDotPrintTest(PrintDelegateTest.kt:242)
[task 2023-05-13T13:42:03.158Z] 13:42:03 INFO - org.mozilla.geckoview.test |
[task 2023-05-13T13:42:03.158Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=543
[task 2023-05-13T13:42:03.158Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2023-05-13T13:42:03.158Z] 13:42:03 INFO - Printing logcat for test:
[task 2023-05-13T13:42:03.583Z] 13:42:03 INFO - 05-13 13:41:29.722 E/GeckoSessionTestRule( 3456): test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec contentIframeWindowDotPrintTest(org.mozilla.geckoview.test.PrintDelegateTest)
[task 2023-05-13T13:42:03.583Z] 13:42:03 INFO - 05-13 13:41:29.723 E/GeckoSessionTestRule( 3456): before prepareStatement contentIframeWindowDotPrintTest(org.mozilla.geckoview.test.PrintDelegateTest)
[task 2023-05-13T13:42:03.583Z] 13:42:03 INFO - 05-13 13:41:29.727 D/GeckoViewStartup( 3456): onEvent GeckoView:StorageDelegate:Attached
[task 2023-05-13T13:42:03.583Z] 13:42:03 INFO - 05-13 13:41:29.739 D/EGL_emulation( 2087): eglMakeCurrent: 0x71ad1406d9e0: ver 3 0 (tinfo 0x71ad140fa720)
[task 2023-05-13T13:42:03.584Z] 13:42:03 INFO - 05-13 13:41:29.740 I/WindowManager( 1657): Destroying surface Surface(name=com.android.launcher3/com.android.launcher3.Launcher) called by com.android.server.wm.WindowStateAnimator.destroySurface:2014 com.android.server.wm.WindowStateAnimator.destroySurfaceLocked:881 com.android.server.wm.WindowState.destroyOrSaveSurface:2073 com.android.server.wm.WindowManagerService.tryStartExitingAnimation:3017 com.android.server.wm.WindowManagerService.relayoutWindow:2897 com.android.server.wm.Session.relayout:215 android.view.IWindowSession$Stub.onTransact:286 com.android.server.wm.Session.onTransact:136
[task 2023-05-13T13:42:03.584Z] 13:42:03 INFO - 05-13 13:41:29.752 D/GeckoViewNavigation( 3456): sessionContextId=null
[task 2023-05-13T13:42:03.584Z] 13:42:03 INFO - 05-13 13:41:29.756 D/EGL_emulation( 3456): eglMakeCurrent: 0x71ad2496f860: ver 3 0 (tinfo 0x71ad2491fce0)
[task 2023-05-13T13:42:03.584Z] 13:42:03 INFO - 05-13 13:41:29.768 E/eglCodecCommon( 6928): glUtilsParamSize: unknow param 0x00008caa
[task 2023-05-13T13:42:03.584Z] 13:42:03 INFO - 05-13 13:41:29.777 I/ActivityManager( 1657): Displayed org.mozilla.geckoview.test/.GeckoViewTestActivity: +66ms (total +96ms)
[task 2023-05-13T13:42:03.584Z] 13:42:03 INFO - 05-13 13:41:29.779 E/eglCodecCommon( 6928): glUtilsParamSize: unknow param 0x00008741
[task 2023-05-13T13:42:03.585Z] 13:42:03 INFO - 05-13 13:41:29.786 D/LifecycleMonitor( 3456): Lifecycle status change: androidx.test.core.app.InstrumentationActivityInvoker$BootstrapActivity@445c02c in: STOPPED
[task 2023-05-13T13:42:03.585Z] 13:42:03 INFO - 05-13 13:41:29.786 V/ActivityScenario( 3456): Activity lifecycle changed event received but ignored because the intent does not match. startActivityIntent=Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] cmp=org.mozilla.geckoview.test/.GeckoViewTestActivity }, activity.getIntent()=Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10008000 cmp=org.mozilla.geckoview.test/androidx.test.core.app.InstrumentationActivityInvoker$BootstrapActivity (has extras) }, activity=androidx.test.core.app.InstrumentationActivityInvoker$BootstrapActivity@445c02c
[task 2023-05-13T13:42:03.585Z] 13:42:03 INFO - 05-13 13:41:29.791 D/GeckoViewModule( 3456): registerListener ["GeckoViewContent:ExitFullScreen","GeckoView:ClearMatches","GeckoView:DisplayMatches","GeckoView:FindInPage","GeckoView:HasCookieBannerRuleForBrowsingContextTree","GeckoView:RestoreState","GeckoView:ContainsFormData","GeckoView:ScrollBy","GeckoView:ScrollTo","GeckoView:SetActive","GeckoView:SetFocused","GeckoView:SetPriorityHint","GeckoView:UpdateInitData","GeckoView:ZoomToInput","GeckoView:IsPdfJs"]
[task 2023-05-13T13:42:03.585Z] 13:42:03 INFO - 05-13 13:41:29.791 D/GeckoViewNavigation( 3456): onInit
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.792 D/GeckoViewModule( 3456): registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory","GeckoView:DotPrintFinish"]
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.792 D/GeckoViewNavigation( 3456): onEnable
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.793 D/GeckoViewProcessHangMonitor( 3456): onInit
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.793 D/GeckoViewProcessHangMonitor( 3456): onEnable
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.793 D/GeckoViewModule( 3456): registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.794 D/GeckoViewProgress( 3456): onEnable
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.794 D/GeckoSession( 3456): handleMessage GeckoView:PageStart uri=about:blank
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.794 E/GeckoSessionTestRule( 3456): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStart(org.mozilla.geckoview.GeckoSession,java.lang.String)
[task 2023-05-13T13:42:03.586Z] 13:42:03 INFO - 05-13 13:41:29.794 D/GeckoViewSelectionActionDelegate[C]( 5854): handleEvent: visibilitychange
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.795 D/GeckoViewClipboardPermissionChild[C]( 5854): handleEvent: deactivate
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.795 D/GeckoSession( 3456): handleMessage GeckoView:LocationChange uri=about:blank
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.795 E/GeckoSessionTestRule( 3456): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onLocationChange(org.mozilla.geckoview.GeckoSession,java.lang.String,java.util.List)
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.795 E/GeckoSessionTestRule( 3456): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoBack(org.mozilla.geckoview.GeckoSession,boolean)
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.795 E/GeckoSessionTestRule( 3456): method: public abstract void org.mozilla.geckoview.GeckoSession$NavigationDelegate.onCanGoForward(org.mozilla.geckoview.GeckoSession,boolean)
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.795 D/GeckoSession( 3456): handleMessage GeckoView:PageStop uri=null
[task 2023-05-13T13:42:03.587Z] 13:42:03 INFO - 05-13 13:41:29.796 E/GeckoSessionTestRule( 3456): method: public abstract void org.mozilla.geckoview.GeckoSession$ProgressDelegate.onPageStop(org.mozilla.geckoview.GeckoSession,boolean)
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.796 E/GeckoSessionTestRule( 3456): after prepareStatement
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.796 D/GeckoViewModule( 3456): registerListener GeckoView:FlushSessionState
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.796 D/GeckoViewSelectionAction( 3456): onEnable
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.797 D/GeckoViewModule( 3456): registerListener ["GeckoView:ExecuteSelectionAction"]
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.797 D/GeckoViewSettings( 3456): onInit
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.797 D/GeckoViewModule( 3456): registerListener ["GeckoView:GetUserAgent"]
[task 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.798 D/GeckoViewSettings( 3456): 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 2023-05-13T13:42:03.588Z] 13:42:03 INFO - 05-13 13:41:29.799 D/GeckoViewModule( 3456): registerListener ["GeckoView:WebExtension:SetTabActive"]
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.799 D/GeckoViewModule( 3456): registerListener ["ContentBlocking:RequestLog"]
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.800 D/GeckoViewMediaControl( 3456): onEnable
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.800 D/GeckoViewModule( 3456): 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 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.802 D/GeckoViewSettings[C]( 5854): receiveMessage: SettingsUpdate
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.802 I/GeckoSession( 3456): zerdatime 494298 - chrome startup finished
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.817 W/GeckoEditableChild( 5854): No editable parent
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.820 D/GeckoViewClipboardPermissionParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.589Z] 13:42:03 INFO - 05-13 13:41:29.821 D/GeckoSession( 3456): handleMessage: GeckoView:DismissClipboardPermissionRequest
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.822 D/GeckoViewConsole( 3456): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"62071f4e-2067-4f95-83d3-57af199aeeaf","args":{"oldPrefs":{},"newPrefs":{"dom.enable_window_print":true}},"type":"SetPrefs"}}
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.827 D/GeckoViewModule( 3456): dispatch GeckoView:SetActive, data={"active":true}
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.828 D/GeckoViewContent( 3456): onEvent: event=GeckoView:SetActive, data={"active":true}
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.832 D/GeckoViewXUL( 3456): receiveMessage GeckoView:ContentModuleLoaded {"module":"SessionStateAggregator"}
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.853 D/GeckoViewModule( 3456): dispatch GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/print_iframe.html","flags":0,"headerFilter":1}
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.853 D/GeckoViewNavigation( 3456): onEvent: event=GeckoView:LoadUri, data={"uri":"http://localhost:4245/assets/www/print_iframe.html","flags":0,"headerFilter":1}
[task 2023-05-13T13:42:03.590Z] 13:42:03 INFO - 05-13 13:41:29.875 D/GeckoViewProgress( 3456): ProgressTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.875 D/GeckoViewProgress( 3456): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/print_iframe.html
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.876 D/GeckoViewProgress( 3456): ProgressTracker start http://localhost:4245/assets/www/print_iframe.html
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.876 D/GeckoViewProgress( 3456): ProgressTracker updateProgress
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.876 D/GeckoViewProgress( 3456): ProgressTracker updateProgress data={"prev":0,"uri":"http://localhost:4245/assets/www/print_iframe.html","locationChange":false,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":false} progress=15
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.877 D/GeckoSession( 3456): handleMessage GeckoView:ProgressChanged uri=null
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.877 D/GeckoViewProgress( 3456): StateTracker onStateChange: isTopLevel=true, flags=0xf0001, status=NS_OK loadType=1
[task 2023-05-13T13:42:03.591Z] 13:42:03 INFO - 05-13 13:41:29.877 D/GeckoSession( 3456): handleMessage GeckoView:PageStart uri=http://localhost:4245/assets/www/print_iframe.html
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.900 D/GeckoViewSelectionActionDelegate[C]( 5854): handleEvent: visibilitychange
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.900 D/GeckoViewClipboardPermissionChild[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.901 D/GeckoViewAutoFill[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.906 D/GeckoViewClipboardPermissionParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.908 D/GeckoSession( 3456): handleMessage: GeckoView:DismissClipboardPermissionRequest
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.909 D/GeckoViewAutoFill( 3456): receiveMessage Clear
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.914 D/GeckoViewContentBlocking( 3456): onContentBlockingEvent 8000
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.914 D/GeckoViewContentBlocking( 3456): onContentBlockingEvent matchedList: null
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.915 D/GeckoViewContentBlocking( 3456): onContentBlockingEvent matchedTrackingLists: []
[task 2023-05-13T13:42:03.592Z] 13:42:03 INFO - 05-13 13:41:29.923 D/GeckoViewNavigation( 3456): onLocationChange
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.924 D/GeckoSession( 3456): handleMessage GeckoView:LocationChange uri=http://localhost:4245/assets/www/print_iframe.html
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.925 D/GeckoViewProgress( 3456): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/print_iframe.html, flags=0
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.925 D/GeckoViewProgress( 3456): ProgressTracker onLocationChange: location=http://localhost:4245/assets/www/print_iframe.html, flags=0
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.925 D/GeckoViewProgress( 3456): ProgressTracker changeLocation http://localhost:4245/assets/www/print_iframe.html
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.926 D/GeckoViewProgress( 3456): onSecurityChange
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.926 D/GeckoSession( 3456): handleMessage GeckoView:SecurityChanged uri=null
[task 2023-05-13T13:42:03.593Z] 13:42:03 INFO - 05-13 13:41:29.951 D/GeckoViewContentDelegateChild[C]( 5854): handleEvent: DOMContentLoaded
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.954 D/GeckoViewContent( 3456): handleEvent: pagetitlechanged
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.954 D/GeckoViewProgressDelegate[C]( 5854): handleEvent: DOMContentLoaded
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.963 I/Gecko ( 3456): console.error: "Fail on getting domain pref:" ({})
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.963 E/GeckoConsole( 3456): [JavaScript Error: "Fail on getting domain pref: [Exception... "Component returned failure code: 0x804b0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS) [nsICookieBannerService.getDomainPref]" nsresult: "0x804b0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS)" location: "JS frame :: resource://gre/actors/CookieBannerParent.sys.mjs :: receiveMessage :: line 116" data: no]"]
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.965 D/GeckoViewProgress( 3456): receiveMessage: DOMContentLoaded
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.965 D/GeckoViewProgress( 3456): ProgressTracker handleEvent: DOMContentLoaded
[task 2023-05-13T13:42:03.594Z] 13:42:03 INFO - 05-13 13:41:29.966 D/GeckoViewProgress( 3456): ProgressTracker updateProgress
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:29.966 D/GeckoViewProgress( 3456): ProgressTracker updateProgress data={"prev":15,"uri":"http://localhost:4245/assets/www/print_iframe.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":false,"parsed":true} progress=55
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:29.967 D/GeckoSession( 3456): handleMessage GeckoView:ProgressChanged uri=null
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:29.971 I/WindowManager( 1657): Destroying surface Surface(name=Starting org.mozilla.geckoview.test) called by com.android.server.wm.WindowStateAnimator.destroySurface:2014 com.android.server.wm.WindowStateAnimator.destroySurfaceLocked:881 com.android.server.wm.WindowState.destroyOrSaveSurface:2073 com.android.server.wm.AppWindowToken.destroySurfaces:363 com.android.server.wm.WindowStateAnimator.finishExit:565 com.android.server.wm.WindowStateAnimator.stepAnimationLocked:491 com.android.server.wm.WindowAnimator.updateWindowsLocked:303 com.android.server.wm.WindowAnimator.animateLocked:704
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:29.999 D/GeckoViewSelectionActionDelegate[C]( 5854): handleEvent: visibilitychange
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:30.000 D/GeckoViewClipboardPermissionChild[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:30.001 D/GeckoViewAutoFill[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:30.006 D/GeckoViewClipboardPermissionParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.595Z] 13:42:03 INFO - 05-13 13:41:30.007 D/GeckoSession( 3456): handleMessage: GeckoView:DismissClipboardPermissionRequest
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.011 D/GeckoViewContentBlocking( 3456): onContentBlockingEvent 8000
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.011 D/GeckoViewContentBlocking( 3456): onContentBlockingEvent matchedList: null
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.011 D/GeckoViewContentBlocking( 3456): onContentBlockingEvent matchedTrackingLists: []
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.017 D/GeckoViewContentDelegateChild[C]( 5854): handleEvent: DOMContentLoaded
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.018 D/GeckoViewNavigation( 3456): onLocationChange
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.019 D/GeckoSession( 3456): handleMessage GeckoView:LocationChange uri=http://localhost:4245/assets/www/print_content_change.html
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.019 D/GeckoViewProgress( 3456): SecurityTracker onLocationChange: location=http://localhost:4245/assets/www/print_content_change.html, flags=0
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.023 D/GeckoViewContent[C]( 5854): handleEvent: pageshow
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.023 I/Gecko ( 3456): console.error: "Fail on getting domain pref:" ({})
[task 2023-05-13T13:42:03.596Z] 13:42:03 INFO - 05-13 13:41:30.023 D/GeckoViewAutoFill[C]( 5854): handleEvent: pageshow
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.024 E/GeckoConsole( 3456): [JavaScript Error: "Fail on getting domain pref: [Exception... "Component returned failure code: 0x804b0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS) [nsICookieBannerService.getDomainPref]" nsresult: "0x804b0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS)" location: "JS frame :: resource://gre/actors/CookieBannerParent.sys.mjs :: receiveMessage :: line 116" data: no]"]
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.043 D/GeckoViewContent[C]( 5854): handleEvent: pageshow
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.043 D/GeckoViewProgressDelegate[C]( 5854): handleEvent: pageshow
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.045 D/GeckoViewAutoFill[C]( 5854): handleEvent: pageshow
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.062 D/WebExtension( 3456): handleMessage GeckoView:WebExtension:Connect
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.064 D/GeckoViewProgress( 3456): receiveMessage: pageshow
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.064 D/GeckoViewProgress( 3456): ProgressTracker handleEvent: pageshow
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.064 D/GeckoViewProgress( 3456): ProgressTracker updateProgress
[task 2023-05-13T13:42:03.597Z] 13:42:03 INFO - 05-13 13:41:30.064 D/GeckoViewProgress( 3456): ProgressTracker updateProgress data={"prev":55,"uri":"http://localhost:4245/assets/www/print_iframe.html","locationChange":true,"pageStart":true,"pageStop":false,"firstPaint":false,"pageShow":true,"parsed":true} progress=100
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.065 D/GeckoSession( 3456): handleMessage GeckoView:ProgressChanged uri=null
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.067 D/GeckoViewProgress( 3456): ProgressTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.067 D/GeckoViewProgress( 3456): ProgressTracker onStateChange: uri=http://localhost:4245/assets/www/print_iframe.html
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.067 D/GeckoViewProgress( 3456): ProgressTracker stop
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.067 D/GeckoViewProgress( 3456): ProgressTracker updateProgress
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.068 D/GeckoViewProgress( 3456): StateTracker onStateChange: isTopLevel=true, flags=0xc0010, status=NS_OK loadType=1
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.068 D/GeckoSession( 3456): handleMessage GeckoView:PageStop uri=null
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.070 D/GeckoViewContentDelegateParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.073 D/GeckoViewContentDelegateParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.598Z] 13:42:03 INFO - 05-13 13:41:30.075 D/GeckoViewXUL( 3456): onEvent GeckoView:UpdateModuleState {"enabled":true,"module":"GeckoViewPrint"}
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.076 D/GeckoViewConsole( 3456): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"f25c7977-8040-4b9d-940a-3673eafaddf6","eval":"document.getElementById('print-button-page').click();"}}
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.090 D/GeckoViewNavigation( 3456): createContentWindowInFrame: uri=null where=4 flags=0 name=null
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.101 D/GeckoViewClipboardPermissionChild[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.102 D/GeckoViewModule( 3456): dispatch GeckoView:IsPdfJs, data=null
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.102 D/GeckoViewContent( 3456): onEvent: event=GeckoView:IsPdfJs, data=null
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.107 D/GeckoViewClipboardPermissionParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.108 D/GeckoSession( 3456): handleMessage: GeckoView:DismissClipboardPermissionRequest
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.115 I/ActivityManager( 1657): START u0 {act=android.print.PRINT_DIALOG dat=printjob:f746dcca-2349-436f-a9bf-0e9dee9606ac cmp=com.android.printspooler/.ui.PrintActivity (has extras)} from uid 1000 on display 0
[task 2023-05-13T13:42:03.599Z] 13:42:03 INFO - 05-13 13:41:30.122 D/LifecycleMonitor( 3456): Lifecycle status change: org.mozilla.geckoview.test.GeckoViewTestActivity@af156fb in: PAUSED
[task 2023-05-13T13:42:03.600Z] 13:42:03 INFO - 05-13 13:41:30.122 V/ActivityScenario( 3456): Update currentActivityStage to PAUSED, currentActivity=org.mozilla.geckoview.test.GeckoViewTestActivity@af156fb
[task 2023-05-13T13:42:03.600Z] 13:42:03 INFO - 05-13 13:41:30.154 D/GeckoViewContent( 3456): handleEvent: pagetitlechanged
[task 2023-05-13T13:42:03.600Z] 13:42:03 INFO - 05-13 13:41:30.176 D/EGL_emulation( 2059): eglMakeCurrent: 0x71ad21f93380: ver 3 0 (tinfo 0x71ad2c6dd680)
[task 2023-05-13T13:42:03.600Z] 13:42:03 INFO - 05-13 13:41:30.186 I/ActivityManager( 1657): Displayed com.android.printspooler/.ui.PrintActivity: +64ms
[task 2023-05-13T13:42:03.600Z] 13:42:03 INFO - 05-13 13:41:30.272 W/View ( 2059): requestLayout() improperly called by android.widget.TextView{c9ec80a V..D..... ......ID 181,0-201,49 #7f05000e app:id/copies_count_summary} during layout: running second layout pass
[task 2023-05-13T13:42:03.600Z] 13:42:03 INFO - 05-13 13:41:30.273 W/View ( 2059): requestLayout() improperly called by android.widget.TextView{fa62698 V..D..... ......ID 434,0-527,49 #7f05000f app:id/paper_size_summary} during layout: running second layout pass
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.055 D/GeckoViewClipboardPermissionChild[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.056 D/GeckoViewClipboardPermissionChild[C]( 5854): handleEvent: pagehide
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.059 I/Choreographer( 3456): Skipped 111 frames! The application may be doing too much work on its main thread.
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.062 I/GeolocationTest( 3456): onPause Event
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.063 W/GeolocationTest( 3456): onPause was called too late.
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.063 D/GeckoRuntime( 3456): Lifecycle: onPause
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.063 D/GeckoNetworkManager( 3456): Incoming event stop for state OnWithListeners -> OffWithListeners
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.063 W/GeckoSession( 3456): No history entries found.
[task 2023-05-13T13:42:03.601Z] 13:42:03 INFO - 05-13 13:41:32.064 D/GeckoSession( 3456): handleMessage GeckoView:StateUpdated uri=null
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.076 I/MutexFileProvider( 2059): Acquired file: /data/user/0/com.android.printspooler/files/print_job_f746dcca-2349-436f-a9bf-0e9dee9606ac.pdf by thread: Thread[AsyncTask #2,5,main]
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.077 I/MutexFileProvider( 2059): Released file: /data/user/0/com.android.printspooler/files/print_job_f746dcca-2349-436f-a9bf-0e9dee9606ac.pdf from thread: Thread[AsyncTask #2,5,main]
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.102 I/MutexFileProvider( 2059): Acquired file: /data/user/0/com.android.printspooler/files/print_job_f746dcca-2349-436f-a9bf-0e9dee9606ac.pdf by thread: Thread[main,5,main]
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.111 W/art ( 9153): Unexpected CPU variant for X86 using defaults: x86_64
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.114 I/ActivityManager( 1657): Start proc 9153:com.android.printspooler:renderer/u0i5 for service com.android.printspooler/.renderer.PdfManipulationService
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.211 I/art ( 2059): Background partial concurrent mark sweep GC freed 6337(351KB) AllocSpace objects, 4(8MB) LOS objects, 19% free, 16MB/20MB, paused 5.231ms total 26.104ms
[task 2023-05-13T13:42:03.602Z] 13:42:03 INFO - 05-13 13:41:32.533 D/GeckoViewClipboardPermissionParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:41:32.533 D/GeckoViewActorParent( 3456): receiveMessage window destroyed DispatcherMessage GeckoView:DismissClipboardPermissionRequest
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:41:32.536 D/GeckoViewClipboardPermissionParent( 3456): receiveMessage: DispatcherMessage
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:41:32.536 D/GeckoViewActorParent( 3456): receiveMessage window destroyed DispatcherMessage GeckoView:DismissClipboardPermissionRequest
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:41:32.544 E/eglCodecCommon( 6928): glUtilsParamSize: unknow param 0x00008caa
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:41:32.547 D/ServiceAllocator( 3456): org.mozilla.gecko.process.GeckoChildProcessServices$utility updateBindings: IDLE priority, 0 importance, 0 successful binds, 0 failed binds, 2 successful unbinds
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:41:32.549 D/ServiceAllocator( 3456): org.mozilla.gecko.process.GeckoChildProcessServices$gpu updateBindings: IDLE priority, 0 importance, 0 successful binds, 0 failed binds, 2 successful unbinds
[task 2023-05-13T13:42:03.603Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): Error
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.os.Handler.handleCallback(Handler.java:751)
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.util.UiThreadUtils.waitForResult(UiThreadUtils.java:79)
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2911)
[task 2023-05-13T13:42:03.604Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.waitForResult(GeckoSessionTestRule.java:2896)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.PrintDelegateTest.contentIframeWindowDotPrintTest$lambda$14(PrintDelegateTest.kt:252)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.PrintDelegateTest.$r8$lambda$wtN9ZgA5fbISxrBr-WlYtlMwuBg(PrintDelegateTest.kt)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.PrintDelegateTest$$ExternalSyntheticLambda7.perform(D8$$SyntheticClass)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at androidx.test.core.app.ActivityScenario.lambda$onActivity$2$ActivityScenario(ActivityScenario.java:660)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at androidx.test.core.app.ActivityScenario$$Lambda$4.run(ActivityScenario.java:652)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at androidx.test.core.app.ActivityScenario.onActivity(ActivityScenario.java:670)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.PrintDelegateTest.contentIframeWindowDotPrintTest(PrintDelegateTest.kt:242)
[task 2023-05-13T13:42:03.605Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at java.lang.reflect.Method.invoke(Native Method)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at androidx.test.internal.runner.junit4.statement.RunBefores.evaluate(RunBefores.java:80)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at androidx.test.internal.runner.junit4.statement.RunAfters.evaluate(RunAfters.java:61)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$org-mozilla-geckoview-test-rule-GeckoSessionTestRule$2(GeckoSessionTestRule.java:1476)
[task 2023-05-13T13:42:03.606Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda1.run(D8$$SyntheticClass)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.os.Handler.handleCallback(Handler.java:751)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.os.Looper.loop(Looper.java:154)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at java.lang.reflect.Method.invoke(Native Method)
[task 2023-05-13T13:42:03.607Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2023-05-13T13:42:03.608Z] 13:42:03 INFO - 05-13 13:42:02.548 E/GeckoSessionTestRule( 3456): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2023-05-13T13:42:03.608Z] 13:42:03 INFO - 05-13 13:42:02.551 D/GeckoViewConsole( 3456): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"42b27c60-4dc3-4b01-adde-034702f00b8c","args":{"oldPrefs":{"dom.enable_window_print":true}},"type":"RestorePrefs"}}
[task 2023-05-13T13:42:03.608Z] 13:42:03 INFO - 05-13 13:42:02.570 D/GeckoViewContent( 3456): handleEvent: DOMWindowClose
[task 2023-05-13T13:42:03.608Z] 13:42:03 INFO - 05-13 13:42:02.573 D/GeckoViewConsole( 3456): onEvent GeckoView:WebExtension:List null
[task 2023-05-13T13:42:03.608Z] 13:42:03 INFO - 05-13 13:42:02.577 E/GeckoSessionTestRule( 3456): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 contentIframeWindowDotPrintTest(org.mozilla.geckoview.test.PrintDelegateTest)
[task 2023-05-13T13:42:03.608Z] 13:42:03 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PrintDelegateTest#contentIframeWindowDotPrintTest | org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2023-05-13T13:42:03.608Z] 13:42:03 INFO - TEST-INFO took 33577ms
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=1033
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.PrivateModeTest:
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=privateModeStorageShared
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PrivateModeTest
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=544
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2023-05-13T13:42:03.609Z] 13:42:03 INFO - TEST-START | org.mozilla.geckoview.test.PrivateModeTest#privateModeStorageShared
Description
•