1762428 - Intermittent Android /webdriver/tests/print/<test-module> | <test-name> - AssertionError: unknown error (500): Failed to decode response from marionette

Reporter

Description

•

8 months ago

treeherder

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

[task 2022-03-31T15:59:31.714Z] 15:59:31     INFO - PID 4185 | 1648742371705	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-03-31T15:59:31.715Z] 15:59:31     INFO - STDOUT: ==================================== ERRORS ====================================
[task 2022-03-31T15:59:31.727Z] 15:59:31     INFO - STDOUT: ________________ ERROR at setup of test_no_top_browsing_context ________________
[task 2022-03-31T15:59:31.728Z] 15:59:31     INFO - STDOUT: session = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.729Z] 15:59:31     INFO - STDOUT: inline = <function inline.<locals>.inline at 0x7fb9034c3c80>
[task 2022-03-31T15:59:31.731Z] 15:59:31     INFO - STDOUT:     @pytest.fixture
[task 2022-03-31T15:59:31.733Z] 15:59:31     INFO - STDOUT:     def closed_window(session, inline):
[task 2022-03-31T15:59:31.739Z] 15:59:31     INFO - STDOUT:         """Create a window and close it immediately.
[task 2022-03-31T15:59:31.741Z] 15:59:31     INFO - STDOUT:     
[task 2022-03-31T15:59:31.743Z] 15:59:31     INFO - STDOUT:         The window handle will be kept selected, which allows to test for invalid
[task 2022-03-31T15:59:31.744Z] 15:59:31     INFO - STDOUT:         top-level browsing context references.
[task 2022-03-31T15:59:31.746Z] 15:59:31     INFO - STDOUT:         """
[task 2022-03-31T15:59:31.748Z] 15:59:31     INFO - STDOUT:         original_handle = session.window_handle
[task 2022-03-31T15:59:31.749Z] 15:59:31     INFO - STDOUT: >       new_handle = session.new_window()
[task 2022-03-31T15:59:31.750Z] 15:59:31     INFO - STDOUT: inline     = <function inline.<locals>.inline at 0x7fb9034c3c80>
[task 2022-03-31T15:59:31.751Z] 15:59:31     INFO - STDOUT: original_handle = 'eef91cdd-0952-4832-8a6b-07d964f68716'
[task 2022-03-31T15:59:31.753Z] 15:59:31     INFO - STDOUT: session    = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.754Z] 15:59:31     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/fixtures_http.py
[task 2022-03-31T15:59:31.755Z] 15:59:31     INFO - STDOUT: :67: 
[task 2022-03-31T15:59:31.756Z] 15:59:31     INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-03-31T15:59:31.757Z] 15:59:31     INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py
[task 2022-03-31T15:59:31.758Z] 15:59:31     INFO - STDOUT: :20: in inner
[task 2022-03-31T15:59:31.759Z] 15:59:31     INFO - STDOUT:     return func(self, *args, **kwargs)
[task 2022-03-31T15:59:31.761Z] 15:59:31     INFO - STDOUT:         args       = ()
[task 2022-03-31T15:59:31.763Z] 15:59:31     INFO - STDOUT:         func       = <function Session.new_window at 0x7fb903544f28>
[task 2022-03-31T15:59:31.764Z] 15:59:31     INFO - STDOUT:         kwargs     = {}
[task 2022-03-31T15:59:31.765Z] 15:59:31     INFO - STDOUT:         self       = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.767Z] 15:59:31     INFO - STDOUT:         session    = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.768Z] 15:59:31     INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py
[task 2022-03-31T15:59:31.770Z] 15:59:31     INFO - STDOUT: :699: in new_window
[task 2022-03-31T15:59:31.771Z] 15:59:31     INFO - STDOUT:     value = self.send_session_command("POST", "window/new", body)
[task 2022-03-31T15:59:31.773Z] 15:59:31     INFO - STDOUT:         body       = {'type': 'tab'}
[task 2022-03-31T15:59:31.774Z] 15:59:31     INFO - STDOUT:         self       = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.775Z] 15:59:31     INFO - STDOUT:         type_hint  = 'tab'
[task 2022-03-31T15:59:31.779Z] 15:59:31     INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py
[task 2022-03-31T15:59:31.781Z] 15:59:31     INFO - STDOUT: :659: in send_session_command
[task 2022-03-31T15:59:31.782Z] 15:59:31     INFO - STDOUT:     return self.send_command(method, url, body, timeout)
[task 2022-03-31T15:59:31.783Z] 15:59:31     INFO - STDOUT:         body       = {'type': 'tab'}
[task 2022-03-31T15:59:31.784Z] 15:59:31     INFO - STDOUT:         method     = 'POST'
[task 2022-03-31T15:59:31.785Z] 15:59:31     INFO - STDOUT:         self       = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.786Z] 15:59:31     INFO - STDOUT:         timeout    = None
[task 2022-03-31T15:59:31.788Z] 15:59:31     INFO - STDOUT:         uri        = 'window/new'
[task 2022-03-31T15:59:31.789Z] 15:59:31     INFO - STDOUT:         url        = 'session/f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a/window/new'
[task 2022-03-31T15:59:31.790Z] 15:59:31     INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-03-31T15:59:31.792Z] 15:59:31     INFO - STDOUT: self = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>, method = 'POST'
[task 2022-03-31T15:59:31.793Z] 15:59:31     INFO - STDOUT: url = 'session/f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a/window/new'
[task 2022-03-31T15:59:31.794Z] 15:59:31     INFO - STDOUT: body = {'type': 'tab'}, timeout = None
[task 2022-03-31T15:59:31.795Z] 15:59:31     INFO - STDOUT:     def send_command(self, method, url, body=None, timeout=None):
[task 2022-03-31T15:59:31.796Z] 15:59:31     INFO - STDOUT:         """
[task 2022-03-31T15:59:31.797Z] 15:59:31     INFO - STDOUT:         Send a command to the remote end and validate its success.
[task 2022-03-31T15:59:31.798Z] 15:59:31     INFO - STDOUT:     
[task 2022-03-31T15:59:31.804Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.804Z] 15:59:31     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/print/printcmd.py | test_html_document - AssertionError: unknown error (500): Failed to decode response from marionette
[task 2022-03-31T15:59:31.804Z] 15:59:31     INFO - session = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.804Z] 15:59:31     INFO - inline = <function inline.<locals>.inline at 0x7fb902bd0bf8>
[task 2022-03-31T15:59:31.804Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -     def test_html_document(session, inline):
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -         session.url = inline("Test")
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -     
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -         response = do_print(session, {
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -             "page": {"width": 10,
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -                      "height": 20},
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -             "shrinkToFit": False
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO -         })
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO - >       value = assert_success(response)
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO - inline     = <function inline.<locals>.inline at 0x7fb902bd0bf8>
[task 2022-03-31T15:59:31.805Z] 15:59:31     INFO - response   = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - session    = <Session f2a8b4d4-fc42-42ed-87fb-0c9b61c59a1a>
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - tests/web-platform/tests/webdriver/tests/print/printcmd.py:41: 
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - response = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - value = None
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -     def assert_success(response, value=None):
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -         """
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -         Verify that the provided webdriver.Response instance described
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -         a valid success response as defined by `dfn-send-a-response` and
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -         the provided response value.
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -     
[task 2022-03-31T15:59:31.806Z] 15:59:31     INFO -         :param response: ``webdriver.Response`` instance.
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO -         :param value: Expected value of the response body, if any.
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO -         """
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - >       assert response.status == 200, str(response.error)
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - E       AssertionError: unknown error (500): Failed to decode response from marionette
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - E         
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - E       assert 500 == 200
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - E         +500
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - E         -200
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - response   = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - value      = None
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.807Z] 15:59:31     INFO - tests/web-platform/tests/webdriver/tests/support/asserts.py:69: AssertionError
[task 2022-03-31T15:59:31.815Z] 15:59:31     INFO - 
[task 2022-03-31T15:59:31.815Z] 15:59:31     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/print/printcmd.py | test_large_html_document - AssertionError: unknown error (500): Failed to decode response from marionette
[task 2022-03-31T15:59:31.815Z] 15:59:31     INFO - session = <Session f6000976-95a4-436e-9a14-afafbfdb2abf>

Norisz Fay [:noriszfay]

Comment 1

•

8 months ago

Hello Henrik, this started perma failing as tier 2 so far on autoland, could you take a look at it please?

Flags: needinfo?(hskupin)

Summary: Intermittent [tier 2] /webdriver/tests/print/printcmd.py | test_html_document - AssertionError: unknown error (500): Failed to decode response from marionette → Perma [tier 2] /webdriver/tests/print/printcmd.py | test_html_document - AssertionError: unknown error (500): Failed to decode response from marionette

Cristian Tuns

Comment 2

•

8 months ago

This was fixed by backout: https://hg.mozilla.org/integration/autoland/rev/6636af869a1ea8ffbf38b5523a6b02a5a0f2d767

Status: NEW → RESOLVED

Closed: 8 months ago

Flags: needinfo?(hskupin)

Resolution: --- → INVALID

Henrik Skupin (:whimboo) [⌚️UTC+2]

Comment 3

•

8 months ago

As discussed on Element we will keep this bug open and I'll temporarily disable these tests on Android. Once bug 1749444 landed I'll have to take a look what's wrong here.

Blocks: 1729409

Status: RESOLVED → REOPENED

Depends on: 1749444

Keywords: regression

OS: Unspecified → Android

No longer regressed by: 1749444

Hardware: Unspecified → All

Resolution: INVALID → ---

Summary: Perma [tier 2] /webdriver/tests/print/printcmd.py | test_html_document - AssertionError: unknown error (500): Failed to decode response from marionette → Intermittent /webdriver/tests/print/<test-module> | <test-name> - AssertionError: unknown error (500): Failed to decode response from marionette

Comment hidden (Intermittent Failures Robot)

Henrik Skupin (:whimboo) [⌚️UTC+2]

Updated

•

8 months ago

Summary: Intermittent /webdriver/tests/print/<test-module> | <test-name> - AssertionError: unknown error (500): Failed to decode response from marionette → Intermittent Android /webdriver/tests/print/<test-module> | <test-name> - AssertionError: unknown error (500): Failed to decode response from marionette

Henrik Skupin (:whimboo) [⌚️UTC+2]

Comment 5

•

8 months ago

The tab that is used via Marionette to generate a PDF file actually crashes.

[task 2022-03-31T15:58:19.220Z] 15:58:19     INFO - PID 4185 | 1648742299218	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-03-31T15:58:19.222Z] 15:58:19     INFO - PID 4185 | 1648742299220	webdriver::server	DEBUG	-> POST /session/f6000976-95a4-436e-9a14-afafbfdb2abf/print {}
[task 2022-03-31T15:58:20.272Z] 15:58:20     INFO - PID 4185 | 1648742300270	webdriver::server	DEBUG	Teardown session
[task 2022-03-31T15:58:20.273Z] 15:58:20     INFO - PID 4185 | 1648742300270	geckodriver::android	DEBUG	Force stopping the Android package: org.mozilla.geckoview.test_runner

Entries from the adb logcat:

03-31 15:58:06.238 16672 16687 I Gecko   : 1648742286238	Marionette	DEBUG	0 -> [0,33,"WebDriver:Print",{"background":false,"margin":{"bottom":1,"left":1,"right":1,"top":1},"orientation":"portrait","page":{"height":20,"width":10},"pageRanges":[],"scale":1,"shrinkToFit":false}]
03-31 15:58:06.245 16672 16687 I Gecko   : [Parent 16672, Main Thread] WARNING: Caller should supply a printer name.: file /builds/worker/checkouts/gecko/widget/nsPrintSettingsService.cpp:926
03-31 15:58:06.247 16699 16716 I Gecko   : [Child 16699, Main Thread] WARNING: Caller should supply a printer name.: file /builds/worker/checkouts/gecko/widget/nsPrintSettingsService.cpp:926
03-31 15:58:06.255 16672 16687 I Gecko   : [Parent 16672, Main Thread] WARNING: NS_ENSURE_TRUE(domWin) failed: file /builds/worker/checkouts/gecko/widget/android/GeckoProcessManager.h:41
03-31 15:58:06.258 16672 16687 D GeckoViewNavigation: createContentWindowInFrame: uri=null where=4 flags=0 name=null
03-31 15:58:06.262 16672 16672 D GeckoSession: handleMessage GeckoView:OnLoadRequest uri=
03-31 15:58:06.263 16672 16687 D GeckoViewNavigation: handleNewSession: uri=null where=4 flags=0
03-31 15:58:06.264 16672 16672 D GeckoSession: handleMessage GeckoView:OnNewSession uri=
03-31 15:58:06.265 16672 16687 D GeckoViewModule: dispatch GeckoView:WebExtension:SetTabActive, data={"active":false}
03-31 15:58:06.265 16672 16687 D GeckoViewTab: onEvent: event=GeckoView:WebExtension:SetTabActive, data={"active":false}
03-31 15:58:06.267 16672 16687 I Gecko   : nsWindow[0x7c15c0c90d00]::Create 0x0 [0 0 1 1]
03-31 15:58:06.274 16672 16687 I Gecko   : 1648742286274	Marionette	TRACE	Received observer notification domwindowopened
03-31 15:58:06.277 16672 16687 I Gecko   : [Parent 16672, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4147
03-31 15:58:06.278 16672 16687 I Gecko   : nsWindow[0x7c15c0c90d00]::Resize [0.000000 0.000000 800.000000 1136.000000] (repaint 0)
03-31 15:58:06.278 16672 16687 I Gecko   : nsWindow: 0x7c15c0c90d00 OnSizeChanged [800 1136]
03-31 15:58:06.278 16672 16687 I Gecko   : [Parent 16672, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4147
03-31 15:58:06.299 16672 16687 D GeckoViewNavigation: sessionContextId=null
03-31 15:58:06.327 16733 16757 E eglCodecCommon: glUtilsParamSize: unknow param 0x00008741
03-31 15:58:06.454 16733 16757 D EGL_emulation: eglMakeCurrent: 0x7c15efe7e420: ver 3 0 (tinfo 0x7c15e57bef40)
03-31 15:58:06.463 16733 16757 E eglCodecCommon: glUtilsParamSize: unknow param 0x00008caa
03-31 15:58:06.485 16733 16757 W webrender::device::gl: Missing optimized shader source for gpu_cache_update
03-31 15:58:06.491 16733 16757 E eglCodecCommon: glUtilsParamSize: unknow param 0x00008741
03-31 15:58:06.499 16672 16687 D GeckoViewModule: registerListener ["GeckoViewContent:ExitFullScreen","GeckoView:ClearMatches","GeckoView:DisplayMatches","GeckoView:FindInPage","GeckoView:RestoreState","GeckoView:ScrollBy","GeckoView:ScrollTo","GeckoView:SetActive","GeckoView:SetFocused","GeckoView:UpdateInitData","GeckoView:ZoomToInput"]
03-31 15:58:06.500 16672 16684 D         : HostConnection::get() New Host Connection established 0x7c15e577e0e0, tid 16684
03-31 15:58:06.500 16672 16687 D GeckoViewNavigation: onInit
03-31 15:58:06.501 16672 16687 D GeckoViewModule: registerListener ["GeckoView:GoBack","GeckoView:GoForward","GeckoView:GotoHistoryIndex","GeckoView:LoadUri","GeckoView:Reload","GeckoView:Stop","GeckoView:PurgeHistory"]
03-31 15:58:06.501 16672 16687 D GeckoViewNavigation: onEnable
03-31 15:58:06.502 16672 16687 D GeckoViewProcessHangMonitor: onInit
03-31 15:58:06.502 16672 16687 D GeckoViewProcessHangMonitor: onEnable
03-31 15:58:06.502 16672 16687 D GeckoViewModule: registerListener ["GeckoView:HangReportStop","GeckoView:HangReportWait"]
03-31 15:58:06.503 16733 16757 D EGL_emulation: eglMakeCurrent: 0x7c15efe7e420: ver 3 0 (tinfo 0x7c15e57bef40)
03-31 15:58:06.503 16672 16687 D GeckoViewSettings: onInit
03-31 15:58:06.504 16672 16687 D GeckoViewModule: registerListener ["GeckoView:GetUserAgent"]
03-31 15:58:06.504 16672 16687 D GeckoViewSettings: 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}
03-31 15:58:06.505 16672 16687 D GeckoViewModule: registerListener ["GeckoView:WebExtension:SetTabActive"]
03-31 15:58:06.508 16699 16716 D GeckoViewSelectionActionDelegate[C]: handleEvent: visibilitychange
03-31 15:58:06.508 16672 16687 I GeckoSession: zerdatime 696619 - chrome startup finished
03-31 15:58:06.509 16672 16687 I Gecko   : nsWindow[0x7c15c0c90d00]::Show 1
03-31 15:58:06.509 16672 16685 D         : HostConnection::get() New Host Connection established 0x7c15e8220360, tid 16685
03-31 15:58:06.510 16699 16716 D GeckoViewSettings[C]: receiveMessage: SettingsUpdate
03-31 15:58:06.512 16699 16716 D GeckoViewSelectionActionDelegate[C]: handleEvent: visibilitychange
03-31 15:58:06.513 16672 16687 I Gecko   : nsWindow[0x7c15c0c90d00]::Resize [0.000000 0.000000 800.000000 1136.000000] (repaint 0)
03-31 15:58:06.513 16672 16687 W GeckoEventDispatcher: No listener for GeckoView:StateUpdated
03-31 15:58:06.515 16672 16687 D GeckoViewModule: dispatch GeckoView:WebExtension:SetTabActive, data={"active":true}
03-31 15:58:06.515 16672 16687 D GeckoViewTab: onEvent: event=GeckoView:WebExtension:SetTabActive, data={"active":true}
03-31 15:58:06.517 16672 16687 D GeckoViewXUL: receiveMessage GeckoView:ContentModuleLoaded {"module":"SessionStateAggregator"}
03-31 15:58:06.519 16699 16716 D GeckoViewSelectionActionDelegate[C]: handleEvent: visibilitychange
03-31 15:58:06.520 16699 16716 D GeckoViewAutoFill[C]: handleEvent: pagehide
03-31 15:58:06.520 16699 16716 D GeckoViewAutofill: Clearing auto-fill
03-31 15:58:06.523 16733 16757 E eglCodecCommon: glUtilsParamSize: unknow param 0x00008caa
03-31 15:58:06.531 16672 16687 D GeckoViewNavigation: onLocationChange
03-31 15:58:06.544 16699 16716 F MOZ_Assert: Assertion failure: XRE_IsParentProcess(), at /builds/worker/checkouts/gecko/xpcom/io/nsAnonymousTemporaryFile.cpp:80
03-31 15:58:06.544 16699 16716 F MOZ_Assert: #01: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1370600]
03-31 15:58:06.544 16699 16716 F MOZ_Assert: 
03-31 15:58:06.544 16699 16716 F MOZ_Assert: #02: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x3f87860]
03-31 15:58:06.544 16699 16716 F MOZ_Assert: 
03-31 15:58:06.544 16699 16716 F MOZ_Assert: #03: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1d9a956]
03-31 15:58:06.544 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #04: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x4441c3f]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #05: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x444145f]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #06: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x4442f60]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #07: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x41b2f54]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #08: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x218beb8]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #09: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x3a84ca2]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #10: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x3b07b43]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.545 16699 16716 F MOZ_Assert: #11: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x3b32429]
03-31 15:58:06.545 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #12: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a908a4]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #13: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a8fc31]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #14: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a902c4]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #15: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13d8a23]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #16: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13c29ed]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #17: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13c1d02]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #18: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13c1f22]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #19: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13ddf05]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #20: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13cf296]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.546 16699 16716 F MOZ_Assert: #21: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x13d352e]
03-31 15:58:06.546 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #22: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a92e48]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #23: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a33908]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #24: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a33871]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #25: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x3f2af31]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #26: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x518d673]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #27: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a934b7]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #28: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a33908]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #29: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x1a33871]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #30: ???[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libxul.so +0x518d0ed]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #31: Java_org_mozilla_gecko_mozglue_GeckoLoader_nativeRun[/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64/libmozglue.so +0x72c6b]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.547 16699 16716 F MOZ_Assert: #32: oatexec[/data/app/org.mozilla.geckoview.test_runner-1/oat/x86_64/base.odex +0xddbb1f]
03-31 15:58:06.547 16699 16716 F MOZ_Assert: 
03-31 15:58:06.581 16733 16757 W webrender::device::gl: Cropping texture upload Box2D((0, 0), (0, 1)) to None
03-31 15:58:06.582 16733 16757 W webrender::device::gl: Cropping texture upload Box2D((0, 0), (0, 1)) to None
03-31 15:58:06.584 16733 16757 W webrender::device::gl: Cropping texture upload Box2D((0, 0), (0, 1)) to None
03-31 15:58:06.591 16733 16757 D EGL_emulation: eglMakeCurrent: 0x7c15efe7e420: ver 3 0 (tinfo 0x7c15e57bef40)
03-31 15:58:06.592 16733 16757 E eglCodecCommon: glUtilsParamSize: unknow param 0x00008caa
03-31 15:58:07.050  1658  2107 I ActivityManager: Process org.mozilla.geckoview.test_runner:tab11 (pid 16699) has died
03-31 15:58:07.050  1658  2107 D ActivityManager: cleanUpApplicationRecord -- 16699
03-31 15:58:07.050  1658  2107 W ActivityManager: Scheduling restart of crashed service

Agi, is there a known issue with that on Android? I can remember that print to pdf isn't implemented yet on Android, so maybe that's the problem here? Our implementation can be found at https://searchfox.org/mozilla-central/source/remote/marionette/print.js.

Flags: needinfo?(agi)

[ex-Mozilla] Agi Sferro | :agi

Comment 6

•

8 months ago

•

Edited

I think Emilio might know actually, yeah print doesn't work but shouldn't crash either I think?

Emilio, if you don't know off the top of your head I can look at this.

Flags: needinfo?(agi) → needinfo?(emilio)

Henrik Skupin (:whimboo) [⌚️UTC+2]

Comment 7

•

8 months ago

I had another look and interestingly the assertion which might trigger this crash comes from:
https://searchfox.org/mozilla-central/rev/fbb1e8462ad82b0e76b5c13dd0d6280cfb69e68d/xpcom/io/nsAnonymousTemporaryFile.cpp#80

Means we are in a content process? Given the Marionette code we do trigger the code from the parent process:

https://searchfox.org/mozilla-central/rev/fbb1e8462ad82b0e76b5c13dd0d6280cfb69e68d/remote/marionette/driver.js#2905
https://searchfox.org/mozilla-central/rev/fbb1e8462ad82b0e76b5c13dd0d6280cfb69e68d/remote/marionette/print.js#198

Emilio Cobos Álvarez (:emilio)

Assignee

Comment 8

•

8 months ago

Attached file Bug 1762428 - Print via parent on Android. r=Agi — Details

This proxies the printing operation via the parent like we do everywhere
else.

Otherwise we try to create anonymous files in the child process which is
forbidden.

Phabricator Automation

Updated

•

8 months ago

Assignee: nobody → emilio

Emilio Cobos Álvarez (:emilio)

Assignee

Updated

•

8 months ago

Flags: needinfo?(emilio)

Pulsebot

Comment 10

•

8 months ago

Pushed by ealvarez@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/ce4059195e1f
Print via parent on Android. r=agi,whimboo,webdriver-reviewers

Treeherder Bug Filer

Reporter

Updated

•

8 months ago

Regressions: 1763456

Norisz Fay [:noriszfay]

Comment 11

•

8 months ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/ce4059195e1f

Status: REOPENED → RESOLVED

Closed: 8 months ago → 8 months ago

status-firefox101: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → 101 Branch

Henrik Skupin (:whimboo) [⌚️UTC+2]

Comment 12

•

8 months ago

Emilio, given that this is a regression in Firefox 100 could you request an uplift please?

status-firefox100: --- → affected

status-firefox99: --- → unaffected

status-firefox-esr91: --- → unaffected

Flags: needinfo?(emilio)

Emilio Cobos Álvarez (:emilio)

Assignee

Comment 13

•

8 months ago

Comment on attachment 9270934 [details]
Bug 1762428 - Print via parent on Android. r=Agi

Beta/Release Uplift Approval Request

User impact if declined: None (we don't expose printing on android to users afaict)
Is this code covered by automated tests?: Yes
Has the fix been verified in Nightly?: Yes
Needs manual test from QE?: No
If yes, steps to reproduce:
List of other uplifts needed: nonne
Risk to taking this patch: Low
Why is the change risky/not risky? (and alternatives if risky): Flips a pref to do what we do on desktop.
String changes made/needed: none

Flags: needinfo?(emilio)

Attachment #9270934 - Flags: approval-mozilla-beta?

Dianna Smith [:diannaS]

Comment 14

•

8 months ago

Comment on attachment 9270934 [details]
Bug 1762428 - Print via parent on Android. r=Agi

Approved for 100.0b3

Attachment #9270934 - Flags: approval-mozilla-beta? → approval-mozilla-beta+

Dianna Smith [:diannaS]

Comment 15

•

8 months ago

bugherderuplift

https://hg.mozilla.org/releases/mozilla-beta/rev/3d31ea6a5482

status-firefox100: affected → fixed

Bugzilla

Intermittent Android /webdriver/tests/print/<test-module> | <test-name> - AssertionError: unknown error (500): Failed to decode response from marionette

Categories

(Testing :: geckodriver, defect, P5)

Tracking

(firefox-esr91 unaffected, firefox99 unaffected, firefox100 fixed, firefox101 fixed)

People

(Reporter: intermittent-bug-filer, Assigned: emilio)

References

(Blocks 1 open bug)

Details

(Keywords: assertion, intermittent-failure)

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Comment 2

Comment 3

Comment 4

Updated

Comment 5

Comment 6

Comment 7

Comment 8

Updated

Updated

Comment 10

Updated

Comment 11

Comment 12

Comment 13

Beta/Release Uplift Approval Request

Comment 14

Comment 15