Closed Bug 1805376 Opened 3 years ago Closed 3 years ago

Intermittent mozilla/tests/webdriver/bidi/script/exception_details.py | test_call_function_without_to_string_interface[null-True] - setup error: webdriver.error.UnknownErrorException: unknown error (500): adb error: cannot bind listener

Categories

(Remote Protocol :: WebDriver BiDi, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1791216

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2022-12-13T06:34:21.380Z] 06:34:21     INFO - STDOUT: PASSED
[task 2022-12-13T06:34:21.390Z] 06:34:21     INFO - PID 4423 | 1670913261390	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/timeouts {"implicit": 0}
[task 2022-12-13T06:34:21.397Z] 06:34:21     INFO - PID 4423 | 1670913261396	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.398Z] 06:34:21     INFO - PID 4423 | 1670913261397	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/timeouts {"pageLoad": 300000}
[task 2022-12-13T06:34:21.404Z] 06:34:21     INFO - PID 4423 | 1670913261404	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.405Z] 06:34:21     INFO - PID 4423 | 1670913261404	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/timeouts {"script": 30000}
[task 2022-12-13T06:34:21.412Z] 06:34:21     INFO - PID 4423 | 1670913261411	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.412Z] 06:34:21     INFO - PID 4423 | 1670913261412	webdriver::server	DEBUG	-> GET /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window
[task 2022-12-13T06:34:21.420Z] 06:34:21     INFO - PID 4423 | 1670913261419	webdriver::server	DEBUG	<- 200 OK {"value":"9d5ed4df-573a-494b-9a75-565ce65f9df9"}
[task 2022-12-13T06:34:21.420Z] 06:34:21     INFO - PID 4423 | 1670913261420	webdriver::server	DEBUG	-> GET /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window
[task 2022-12-13T06:34:21.428Z] 06:34:21     INFO - PID 4423 | 1670913261427	webdriver::server	DEBUG	<- 200 OK {"value":"9d5ed4df-573a-494b-9a75-565ce65f9df9"}
[task 2022-12-13T06:34:21.428Z] 06:34:21     INFO - PID 4423 | 1670913261427	webdriver::server	DEBUG	-> GET /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window/handles
[task 2022-12-13T06:34:21.434Z] 06:34:21     INFO - PID 4423 | 1670913261434	webdriver::server	DEBUG	<- 200 OK {"value":["9d5ed4df-573a-494b-9a75-565ce65f9df9"]}
[task 2022-12-13T06:34:21.435Z] 06:34:21     INFO - PID 4423 | 1670913261434	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window {"handle": "9d5ed4df-573a-494b-9a75-565ce65f9df9"}
[task 2022-12-13T06:34:21.442Z] 06:34:21     INFO - PID 4423 | 1670913261441	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.443Z] 06:34:21     INFO - PID 4423 | 1670913261442	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/alert/dismiss {}
[task 2022-12-13T06:34:21.450Z] 06:34:21     INFO - PID 4423 | 1670913261449	webdriver::server	DEBUG	<- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"RemoteError@chrome://remote/content/shared/Remo ... ontent/marionette/server.sys.mjs:250:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"}}
[task 2022-12-13T06:34:21.450Z] 06:34:21     INFO - PID 4423 | 1670913261449	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window {"handle": "9d5ed4df-573a-494b-9a75-565ce65f9df9"}
[task 2022-12-13T06:34:21.457Z] 06:34:21     INFO - PID 4423 | 1670913261456	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.458Z] 06:34:21     INFO - PID 4423 | 1670913261457	webdriver::server	DEBUG	-> GET /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window
[task 2022-12-13T06:34:21.464Z] 06:34:21     INFO - PID 4423 | 1670913261463	webdriver::server	DEBUG	<- 200 OK {"value":"9d5ed4df-573a-494b-9a75-565ce65f9df9"}
[task 2022-12-13T06:34:21.464Z] 06:34:21     INFO - PID 4423 | 1670913261464	webdriver::server	DEBUG	-> GET /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window/handles
[task 2022-12-13T06:34:21.471Z] 06:34:21     INFO - PID 4423 | 1670913261470	webdriver::server	DEBUG	<- 200 OK {"value":["9d5ed4df-573a-494b-9a75-565ce65f9df9"]}
[task 2022-12-13T06:34:21.472Z] 06:34:21     INFO - PID 4423 | 1670913261471	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/window {"handle": "9d5ed4df-573a-494b-9a75-565ce65f9df9"}
[task 2022-12-13T06:34:21.479Z] 06:34:21     INFO - PID 4423 | 1670913261478	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.479Z] 06:34:21     INFO - PID 4423 | 1670913261479	webdriver::server	DEBUG	-> POST /session/dd452fc5-8152-4cae-8be2-cacc74d81084/frame {"id": null}
[task 2022-12-13T06:34:21.491Z] 06:34:21     INFO - PID 4423 | 1670913261491	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:21.494Z] 06:34:21     INFO - PID 4423 | 1670913261493	webdriver::server	DEBUG	-> DELETE /session/dd452fc5-8152-4cae-8be2-cacc74d81084
[task 2022-12-13T06:34:21.561Z] 06:34:21     INFO - PID 4423 | 1670913261560	webdriver::server	DEBUG	Teardown session
[task 2022-12-13T06:34:21.561Z] 06:34:21     INFO - PID 4423 | 1670913261560	geckodriver::android	DEBUG	Force stopping the Android package: org.mozilla.geckoview.test_runner
[task 2022-12-13T06:34:21.562Z] 06:34:21     INFO - PID 4423 | 1670913261560	mozdevice	DEBUG	Force stopping Android package: org.mozilla.geckoview.test_runner
[task 2022-12-13T06:34:21.562Z] 06:34:21     INFO - PID 4423 | 1670913261560	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-12-13T06:34:21.562Z] 06:34:21     INFO - PID 4423 | 1670913261560	mozdevice	TRACE	execute_host_command: << []
[task 2022-12-13T06:34:21.563Z] 06:34:21     INFO - PID 4423 | 1670913261560	mozdevice	TRACE	execute_host_command: >> "shell:am force-stop org.mozilla.geckoview.test_runner"
[task 2022-12-13T06:34:21.786Z] 06:34:21     INFO - PID 4423 | 1670913261785	mozdevice	TRACE	execute_host_command: << ""
[task 2022-12-13T06:34:21.787Z] 06:34:21     INFO - PID 4423 | 1670913261786	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-12-13T06:34:21.787Z] 06:34:21     INFO - PID 4423 | 1670913261786	mozdevice	TRACE	execute_host_command: << []
[task 2022-12-13T06:34:21.788Z] 06:34:21     INFO - PID 4423 | 1670913261786	mozdevice	TRACE	execute_host_command: >> "shell:am clear-debug-app org.mozilla.geckoview.test_runner"
[task 2022-12-13T06:34:22.022Z] 06:34:22     INFO - PID 4423 | 1670913262020	mozdevice	TRACE	execute_host_command: << ""
[task 2022-12-13T06:34:22.022Z] 06:34:22     INFO - PID 4423 | 1670913262020	geckodriver::android	DEBUG	Disabled reading from configuration file
[task 2022-12-13T06:34:22.022Z] 06:34:22     INFO - PID 4423 | 1670913262020	mozdevice	DEBUG	Deleting /data/local/tmp/org.mozilla.geckoview.test_runner-geckoview-config.yaml
[task 2022-12-13T06:34:22.023Z] 06:34:22     INFO - PID 4423 | 1670913262021	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-12-13T06:34:22.023Z] 06:34:22     INFO - PID 4423 | 1670913262021	mozdevice	TRACE	execute_host_command: << []
[task 2022-12-13T06:34:22.024Z] 06:34:22     INFO - PID 4423 | 1670913262021	mozdevice	TRACE	execute_host_command: >> "shell:rm -rf /data/local/tmp/org.mozilla.geckoview.test_runner-geckoview-config.yaml"
[task 2022-12-13T06:34:22.031Z] 06:34:22     INFO - PID 4423 | 1670913262030	mozdevice	TRACE	execute_host_command: << ""
[task 2022-12-13T06:34:22.031Z] 06:34:22     INFO - PID 4423 | 1670913262030	geckodriver::android	DEBUG	Deleted GeckoView configuration file
[task 2022-12-13T06:34:22.031Z] 06:34:22     INFO - PID 4423 | 1670913262030	mozdevice	DEBUG	Deleting /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root
[task 2022-12-13T06:34:22.032Z] 06:34:22     INFO - PID 4423 | 1670913262030	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-12-13T06:34:22.032Z] 06:34:22     INFO - PID 4423 | 1670913262030	mozdevice	TRACE	execute_host_command: << []
[task 2022-12-13T06:34:22.033Z] 06:34:22     INFO - PID 4423 | 1670913262030	mozdevice	TRACE	execute_host_command: >> "shell:rm -rf /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root"
[task 2022-12-13T06:34:22.121Z] 06:34:22     INFO - PID 4423 | 1670913262119	mozdevice	TRACE	execute_host_command: << ""
[task 2022-12-13T06:34:22.121Z] 06:34:22     INFO - PID 4423 | 1670913262120	geckodriver::android	DEBUG	Deleted test root folder: /sdcard/Android/data/org.mozilla.geckoview.test_runner/files/test_root
[task 2022-12-13T06:34:22.122Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-12-13T06:34:22.122Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: << []
[task 2022-12-13T06:34:22.125Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: >> "host-serial:emulator-5554:killforward:tcp:40982"
[task 2022-12-13T06:34:22.125Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: << ""
[task 2022-12-13T06:34:22.125Z] 06:34:22     INFO - PID 4423 | 1670913262120	geckodriver::android	DEBUG	Marionette port forward (40982 -> 2829) stopped
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - STDOUT: ==================================== ERRORS ====================================
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: << []
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: >> "host-serial:emulator-5554:killforward:tcp:9222"
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - PID 4423 | 1670913262120	mozdevice	TRACE	execute_host_command: << ""
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - PID 4423 | 1670913262120	geckodriver::android	DEBUG	WebSocket port forward (9222 -> 9222) stopped
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - PID 4423 | 1670913262120	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-12-13T06:34:22.126Z] 06:34:22     INFO - STDOUT: _ ERROR at setup of test_call_function_without_to_string_interface[null-True] __
[task 2022-12-13T06:34:22.127Z] 06:34:22     INFO - STDOUT: args = ()
[task 2022-12-13T06:34:22.128Z] 06:34:22     INFO - STDOUT: kwargs = {'capabilities': {}, 'configuration': {'capabilities': {'moz:firefoxOptions': {'androidDeviceSerial': 'emulator-5554',...}, 'host': '127.0.0.1', 'port': 45909, 'webdriver': {'args': ['-vv'], 'binary': '/builds/worker/fetches/geckodriver'}}}
[task 2022-12-13T06:34:22.128Z] 06:34:22     INFO - STDOUT: request = <SubRequest 'bidi_session' for <Function test_call_function_without_to_string_interface[null-True]>>
[task 2022-12-13T06:34:22.129Z] 06:34:22     INFO - STDOUT: setup = <function pytest_fixture_setup.<locals>.wrapper.<locals>.setup at 0x7f9e6b914f28>
[task 2022-12-13T06:34:22.129Z] 06:34:22     INFO - STDOUT: finalizer = <function pytest_fixture_setup.<locals>.wrapper.<locals>.finalizer at 0x7f9e6b076048>
[task 2022-12-13T06:34:22.130Z] 06:34:22     INFO - STDOUT:     def wrapper(*args, **kwargs):
[task 2022-12-13T06:34:22.130Z] 06:34:22     INFO - STDOUT:         loop = fixture_stripper.get_and_strip_from(FixtureStripper.EVENT_LOOP, kwargs)
[task 2022-12-13T06:34:22.131Z] 06:34:22     INFO - STDOUT:         request = fixture_stripper.get_and_strip_from(FixtureStripper.REQUEST, kwargs)
[task 2022-12-13T06:34:22.131Z] 06:34:22     INFO - STDOUT:     
[task 2022-12-13T06:34:22.132Z] 06:34:22     INFO - STDOUT:         gen_obj = generator(*args, **kwargs)
[task 2022-12-13T06:34:22.132Z] 06:34:22     INFO - STDOUT:     
[task 2022-12-13T06:34:22.133Z] 06:34:22     INFO - STDOUT:         async def setup():
[task 2022-12-13T06:34:22.133Z] 06:34:22     INFO - STDOUT:             res = await gen_obj.__anext__()
[task 2022-12-13T06:34:22.134Z] 06:34:22     INFO - STDOUT:             return res
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - 
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - TEST-UNEXPECTED-ERROR | /_mozilla/webdriver/bidi/script/exception_details.py | test_call_function_without_to_string_interface[null-True] - setup error: webdriver.error.UnknownErrorException: unknown error (500): adb error: cannot bind listener: Address already in use
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - args = ()
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - kwargs = {'capabilities': {}, 'configuration': {'capabilities': {'moz:firefoxOptions': {'androidDeviceSerial': 'emulator-5554',...}, 'host': '127.0.0.1', 'port': 45909, 'webdriver': {'args': ['-vv'], 'binary': '/builds/worker/fetches/geckodriver'}}}
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - request = <SubRequest 'bidi_session' for <Function test_call_function_without_to_string_interface[null-True]>>
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - setup = <function pytest_fixture_setup.<locals>.wrapper.<locals>.setup at 0x7f9e6b914f28>
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - finalizer = <function pytest_fixture_setup.<locals>.wrapper.<locals>.finalizer at 0x7f9e6b076048>
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO - 
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -     def wrapper(*args, **kwargs):
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -         loop = fixture_stripper.get_and_strip_from(FixtureStripper.EVENT_LOOP, kwargs)
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -         request = fixture_stripper.get_and_strip_from(FixtureStripper.REQUEST, kwargs)
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -     
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -         gen_obj = generator(*args, **kwargs)
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -     
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -         async def setup():
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -             res = await gen_obj.__anext__()
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -             return res
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -     
[task 2022-12-13T06:34:22.142Z] 06:34:22     INFO -         def finalizer():
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -             """Yield again, to finalize."""
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -             async def async_finalizer():
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                 try:
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                     await gen_obj.__anext__()
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                 except StopAsyncIteration:
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                     pass
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                 else:
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                     msg = "Async generator fixture didn't stop."
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                     msg += "Yield only once."
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -                     raise ValueError(msg)
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -             loop.run_until_complete(async_finalizer())
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -     
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -         request.addfinalizer(finalizer)
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - >       return loop.run_until_complete(setup())
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - 
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - args       = ()
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - finalizer  = <function pytest_fixture_setup.<locals>.wrapper.<locals>.finalizer at 0x7f9e6b076048>
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - fixture_stripper = <pytest_asyncio.plugin.FixtureStripper object at 0x7f9e6b0b3550>
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - gen_obj    = <async_generator object bidi_session at 0x7f9e6b0744c0>
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - generator  = <function bidi_session at 0x7f9e6b968158>
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO - kwargs     = {'capabilities': {},
[task 2022-12-13T06:34:22.143Z] 06:34:22     INFO -  'configuration': {'capabilities': {'moz:firefoxOptions': {'androidDeviceSerial': 'emulator-5554',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                            'androidPackage': 'org.mozilla.geckoview.test_runner',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                            'args': ['--profile',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                                     '/tmp/tmpqgw3ynae.mozrunner'],
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                            'env': {'MOZ_CRASHREPORTER': '1',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                                    'MOZ_CRASHREPORTER_SHUTDOWN': '1',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                                    'RUST_BACKTRACE': '1',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                                                    'STYLO_THREADS': '1'}}},
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                    'host': '127.0.0.1',
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                    'port': 45909,
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                    'webdriver': {'args': ['-vv'],
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO -                                  'binary': '/builds/worker/fetches/geckodriver'}}}
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO - loop       = <_UnixSelectorEventLoop running=False closed=False debug=False>
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO - request    = <SubRequest 'bidi_session' for <Function test_call_function_without_to_string_interface[null-True]>>
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO - setup      = <function pytest_fixture_setup.<locals>.wrapper.<locals>.setup at 0x7f9e6b914f28>
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO - 
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO - tests/web-platform/tests/tools/third_party/pytest-asyncio/pytest_asyncio/plugin.py:127: 
[task 2022-12-13T06:34:22.144Z] 06:34:22     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
Status: NEW → RESOLVED
Closed: 3 years ago
Duplicate of bug: 1791216
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.