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

[task 2025-03-23T01:20:53.662Z] TEST-START | test_youtube
[task 2025-03-23T01:20:55.651Z] Wait for consent form
[task 2025-03-23T01:21:05.929Z] Wait for consent form: timed out, maybe it is not here
[task 2025-03-23T01:21:05.929Z] Wait for one video
[task 2025-03-23T01:21:06.338Z] Wait for video to start
[task 2025-03-23T01:21:16.647Z] Saving screenshot 'screenshot_test_youtube_timeout.png' to '/task_174269258144074/builds/worker/artifacts/screenshot_test_youtube_timeout.png'
[task 2025-03-23T01:21:16.732Z] Saving screenshot 'screenshot_test_youtube_timeout_parent.png' to '/task_174269258144074/builds/worker/artifacts/screenshot_test_youtube_timeout_parent.png'
[task 2025-03-23T01:21:16.811Z] TEST-UNEXPECTED-TIMEOUT | test_youtube | TimeoutException()
[task 2025-03-23T01:21:16.811Z] TEST-INFO took 23149ms
[task 2025-03-23T01:21:16.812Z] Traceback (most recent call last):
[task 2025-03-23T01:21:16.812Z]   File "/task_174269258144074/fetches/basic_tests.py", line 146, in __init__
[task 2025-03-23T01:21:16.812Z]     rv = getattr(self, m)(expectations)
[task 2025-03-23T01:21:16.812Z]   File "/task_174269258144074/fetches/basic_tests.py", line 467, in test_youtube
[task 2025-03-23T01:21:16.812Z]     video = self._wait.until(
[task 2025-03-23T01:21:16.812Z]   File "/home/task_174269258144074/.local/lib/python3.10/site-packages/selenium/webdriver/support/wait.py", line 95, in until
[task 2025-03-23T01:21:16.812Z]     raise TimeoutException(message, screen, stacktrace)
[task 2025-03-23T01:21:16.812Z] selenium.common.exceptions.TimeoutException: Message: 
[task 2025-03-23T01:21:16.812Z] 
[task 2025-03-23T01:21:16.813Z] tabs_after EXCEPTION {'f8629a09-5b4f-4c26-b029-1f53f1bf19c5', '2f9aa710-cf2a-4edb-9f6b-06ea09272414'}
[task 2025-03-23T01:21:16.814Z] tabs_before {'f8629a09-5b4f-4c26-b029-1f53f1bf19c5'}
[task 2025-03-23T01:21:16.814Z] opened 1 tabs
[task 2025-03-23T01:21:16.814Z] opened {'2f9aa710-cf2a-4edb-9f6b-06ea09272414'} tabs
[task 2025-03-23T01:21:16.814Z] switch to 2f9aa710-cf2a-4edb-9f6b-06ea09272414
[task 2025-03-23T01:21:16.815Z] close 2f9aa710-cf2a-4edb-9f6b-06ea09272414
[task 2025-03-23T01:21:16.928Z] wait EC.number_of_windows_to_be(1)
[task 2025-03-23T01:21:16.949Z] TEST-START | test_youtube_film
[task 2025-03-23T01:21:16.954Z] tabs_after OK {'f8629a09-5b4f-4c26-b029-1f53f1bf19c5'}
[task 2025-03-23T01:21:16.956Z] TEST-OK | test_youtube_film | took 6ms
[task 2025-03-23T01:21:16.956Z] tabs_before {'f8629a09-5b4f-4c26-b029-1f53f1bf19c5'}
[task 2025-03-23T01:21:16.956Z] opened 0 tabs
[task 2025-03-23T01:21:16.956Z] opened set() tabs
[task 2025-03-23T01:21:17.791Z] Exiting with 1
[task 2025-03-23T01:21:17.791Z] SUITE-END | took 26s
[taskcluster 2025-03-23T01:21:17.821Z]    Exit Code: 1
[taskcluster 2025-03-23T01:21:17.821Z]    User Time: 17.714485s
[taskcluster 2025-03-23T01:21:17.821Z]  Kernel Time: 5.760653s
[taskcluster 2025-03-23T01:21:17.821Z]    Wall Time: 2m44.56842974s
[taskcluster 2025-03-23T01:21:17.821Z]       Result: FAILED
[taskcluster 2025-03-23T01:21:17.822Z] === Task Finished ===
[taskcluster 2025-03-23T01:21:17.822Z] Task Duration: 2m44.570065986s
[taskcluster 2025-03-23T01:21:17.931Z] Uploading artifact public/build/screenshot_test_youtube_timeout_parent.png from file /task_174269258144074/builds/worker/artifacts/screenshot_test_youtube_timeout_parent.png with content encoding "identity", mime type "image/png" and expiry 2025-06-21T00:04:53.126Z
[taskcluster 2025-03-23T01:21:17.951Z] Uploading artifact public/build/geckodriver.log from file /task_174269258144074/builds/worker/artifacts/geckodriver.log with content encoding "gzip", mime type "text/plain" and expiry 2025-06-21T00:04:53.126Z
[taskcluster 2025-03-23T01:21:17.955Z] Uploading artifact public/build/screenshot_test_youtube_timeout.png from file /task_174269258144074/builds/worker/artifacts/screenshot_test_youtube_timeout.png with content encoding "identity", mime type "image/png" and expiry 2025-06-21T00:04:53.126Z
[taskcluster 2025-03-23T01:21:18.244Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2025-06-21T00:04:53.126Z
[taskcluster:error] exit status 1

Tests show that this failure started from this push.

Hi, do you have an idea what could have caused this?

Nothing the test was likely broken for a while but a bug made tests failures hidden. Last I saw its YouTube flagging as bot so I'm not sure what more we can do and may need to disable or have an account... ?

Of course, none of my retries so far are reproducing the issue.

I hacked a bit and got something much less frequent. Unfortunately a real fix would be to do like test perfs and serve a copy of the website / video from a local server and not hit actual youtube website. But that's a lot of things, out of my reach for now.

things should look a bit better: https://treeherder.mozilla.org/jobs?repo=try&revision=c5039834c846a5b717fad2e64b12d447a328a104

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

Hi Gerard! It seems that this is not entirely resolved as some failures still happens. Could you please take another look?

Thank you!

(In reply to Serban Stanca [:SerbanS] from comment #13)

Hi Gerard! It seems that this is not entirely resolved as some failures still happens. Could you please take another look?

Thank you!

As mentionned in comment 10 and 6, there's going to be a limit to what we can achieve here? On try it was hard to get something clear in term of reliability but there was vast improvement. Before nuking the test I wanted to see how things would evolve with more reliability. While the first landing was not perfect trigger from tonight was better even though not perfect: https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=snap-upstream&revision=95ab320730a75389873fadbb70f1464a9d849d67

Fixed by bug 1957798