1798447 - Intermittent TimeoutError: No applicable application window found after 1500 ms

Status: RESOLVED INCOMPLETE

(Toolkit :: Telemetry, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[taskcluster 2022-11-01T05:47:32.266Z] === Task Starting ===
[taskcluster 2022-11-01T05:47:32.581Z] Uploading redirect artifact public/logs/live.log to URL https://firefoxci-websocktunnel.services.mozilla.com/mdc1.macmini-r8-233.60099/log/MV-3qrxsTy2aP7YL3PQ4Jg with mime type "text/plain; charset=utf-8" and expiry 2022-11-01T06:22:32.517Z
[taskcluster:warn 2022-11-01T05:47:32.610Z] [mounts] No SHA256 specified in task mounts for artifact:TJbc9780S1y2ULoVWmF8Cw:public/build/mozharness.zip - SHA256 from downloaded file /opt/worker/downloads/KiQhryJWSl6Rd827Pn4mKw is 79194a5fede55dff20884e1ed8ecb5fffb102034930ab52c16722720d2edf77d.
[taskcluster 2022-11-01T05:47:32.610Z] [mounts] Creating directory /opt/worker/tasks/task_166728164956974/mozharness with permissions 0700
[taskcluster 2022-11-01T05:47:32.610Z] [mounts] Extracting zip file /opt/worker/downloads/KiQhryJWSl6Rd827Pn4mKw to '/opt/worker/tasks/task_166728164956974/mozharness'
[taskcluster:warn 2022-11-01T05:47:32.821Z] [mounts] No SHA256 specified in task mounts for urlcontent:http://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FIUZWL6PSSunD16q4T5yww/artifacts/public/run-task - SHA256 from downloaded file /opt/worker/downloads/OJBRuf7HSeyynbkzSiAKcA is 3578569271891feda869dab883aca7a6ff9ce0e329fb8acec3d3d7f625609e80.
[taskcluster 2022-11-01T05:47:32.821Z] [mounts] Creating directory /opt/worker/tasks/task_166728164956974 with permissions 0700
[taskcluster 2022-11-01T05:47:32.821Z] [mounts] Copying /opt/worker/downloads/OJBRuf7HSeyynbkzSiAKcA to /opt/worker/tasks/task_166728164956974/run-task
[taskcluster:warn 2022-11-01T05:47:32.866Z] [mounts] No SHA256 specified in task mounts for urlcontent:http://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FIUZWL6PSSunD16q4T5yww/artifacts/public/fetch-content - SHA256 from downloaded file /opt/worker/downloads/AsBDoGczTGGcsm8lyVzVsw is 4045946aac205f009c2aff89c96949d8875cd088ad7b139802b1e17a57edbc3e.
[taskcluster 2022-11-01T05:47:32.869Z] [mounts] Creating directory /opt/worker/tasks/task_166728164956974 with permissions 0700
[taskcluster 2022-11-01T05:47:32.869Z] [mounts] Copying /opt/worker/downloads/AsBDoGczTGGcsm8lyVzVsw to /opt/worker/tasks/task_166728164956974/fetch-content
[taskcluster 2022-11-01T05:47:32.892Z] Executing command 0: chmod '+x' run-task
[taskcluster 2022-11-01T05:47:32.898Z]    Exit Code: 0
[taskcluster 2022-11-01T05:47:32.898Z]    User Time: 549µs
[taskcluster 2022-11-01T05:47:32.898Z]  Kernel Time: 1.099ms
[taskcluster 2022-11-01T05:47:32.898Z]    Wall Time: 5.843ms
[taskcluster 2022-11-01T05:47:32.898Z]       Result: SUCCEEDED
[taskcluster 2022-11-01T05:47:32.898Z] Executing command 1: /usr/local/bin/python3 run-task -- /usr/local/bin/python3 -u 'mozharness/scripts/telemetry/telemetry_client.py' '--setpref=media.peerconnection.mtransport_process=false' '--setpref=network.process.enabled=false' '--setpref=layers.d3d11.enable-blacklist=false' --download-symbols ondemand
<...>
[task 2022-11-01T05:48:56.470Z] 05:48:56     INFO -  1667281736466	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2022-11-01T05:48:56.470Z] 05:48:56     INFO -  1667281736467	Toolkit.Telemetry	TRACE	TelemetryStorage::removeAbortedSessionPing - success
[task 2022-11-01T05:48:56.470Z] 05:48:56     INFO -  1667281736467	Toolkit.Telemetry	TRACE	TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2022-11-01T05:48:56.471Z] 05:48:56     INFO -  1667281736467	Toolkit.Telemetry	TRACE	TelemetryStorage::_enforceArchiveQuota - Terminating the clean up task due to shutdown
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - TimeoutError: No applicable application window found after 1500 ms
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - stacktrace:
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 	RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 	WebDriverError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:182:5
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 	TimeoutError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:471:5
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 	bail@chrome://remote/content/marionette/sync.sys.mjs:211:19
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - Traceback (most recent call last):
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_harness/runtests.py", line 82, in run
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR -     runner.run_tests(tests)
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 986, in run_tests
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR -     self.fixture_servers = self.start_fixture_servers()
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.705Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1086, in start_fixture_servers
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     if self.appName == "fennec":
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 803, in appName
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     self._appName = self.capabilities.get("browserName")
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 793, in capabilities
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     self.marionette.start_session()
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     return func(*args, **kwargs)
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1263, in start_session
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     resp = self._send_message("WebDriver:NewSession", capabilities)
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     return func(*args, **kwargs)
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 668, in _send_message
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     self._handle_error(err)
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -   File "/opt/worker/tasks/task_166728164956974/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 680, in _handle_error
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR -     raise errors.lookup(error)(message, stacktrace=stacktrace)
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - marionette_driver.errors.SessionNotCreatedException: TimeoutError: No applicable application window found after 1500 ms
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - stacktrace:
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 	RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 	WebDriverError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:182:5
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 	TimeoutError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:471:5
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 	bail@chrome://remote/content/marionette/sync.sys.mjs:211:19
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - During handling of the above exception, another exception occurred:
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 
[task 2022-11-01T05:48:58.706Z] 05:48:58    ERROR - 

Comment 1

[Natalia Csoregi [:nataliaCs]]

First occurrence so far: https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=OS%2CX%2C10.15%2CWebRender%2CShippable%2Copt%2CTelemetry%2Ctests%2Ctest-macosx1015-64-shippable-qr%2Fopt-telemetry-tests-client%2Cc&tochange=ad436fbed86da794516dc7dc72ca49875a363d5d&fromchange=f346806c13d6600f4c62688788e783e7dd89e167&group_state=expanded&selectedTaskRun=RIH2b1l4QdivhMApSf7avQ.0

Comment 2

[Intermittent Failures Robot]

8 failures in 3626 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• try: 2
• autoland: 4
• mozilla-beta: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 4
  • opt: 4
• macosx1015-64-devedition-qr: 1
  • opt: 1
• macosx1015-64-qr: 3
  • debug: 2
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798447&startday=2022-10-31&endday=2022-11-06&tree=all

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 4

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=404663486&repo=mozilla-esr102

Comment 5

[Intermittent Failures Robot]

5 failures in 3606 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr102: 1
• mozilla-beta: 2
• mozilla-central: 1
• autoland: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 2
  • opt: 2
• macosx1015-64-devedition-qr: 1
  • opt: 1
• macosx1015-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798447&startday=2023-01-30&endday=2023-02-05&tree=all

Comment 6

[Intermittent Failures Robot]

3 failures in 3766 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• mozilla-esr102: 2

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1
• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798447&startday=2023-02-06&endday=2023-02-12&tree=all

Comment 7

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.