Intermittent ASAN /webdriver/tests/bidi/network/add_intercept/url_patterns.py | single tracking bug
Categories
(Remote Protocol :: WebDriver BiDi, defect, P5)
Tracking
(firefox-esr128 unaffected, firefox135 unaffected, firefox136 unaffected, firefox137 fixed)
Tracking | Status | |
---|---|---|
firefox-esr128 | --- | unaffected |
firefox135 | --- | unaffected |
firefox136 | --- | unaffected |
firefox137 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: jdescottes)
References
(Regression)
Details
(4 keywords)
Attachments
(1 file, 2 obsolete files)
Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=434652466&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/YP0U93-bS9CZEvPo3T5YIQ/runs/0/artifacts/public/logs/live_backing.log
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - TEST-PASS | /webdriver/tests/bidi/network/add_intercept/url_patterns.py | test_string_patterns_not_matching[https://{wpt_host}/?a=b&c=d-https://{wpt_host}/?c=d&a=b]
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/bidi/network/add_intercept/url_patterns.py | test_string_patterns_not_matching[https://{wpt_host}/??-https://{wpt_host}/?] - teardown error: OSError: [WinError 10048] Only one usage of each socket address (protocol/network address/port) is normally permitted
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - def finalizer() -> None:
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - """Yield again, to finalize."""
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO -
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - async def async_finalizer() -> None:
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - try:
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - await gen_obj.__anext__()
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - except StopAsyncIteration:
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - pass
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - else:
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - msg = "Async generator fixture didn't stop."
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - msg += "Yield only once."
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - raise ValueError(msg)
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO -
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - > event_loop.run_until_complete(async_finalizer())
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO -
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - async_finalizer = <function _wrap_asyncgen.<locals>._asyncgen_fixture_wrapper.<locals>.finalizer.<locals>.async_finalizer at 0x000001D71B4B1C10>
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - event_loop = <ProactorEventLoop running=False closed=True debug=False>
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO - gen_obj = <async_generator object bidi_session at 0x000001D71B4B1820>
[task 2023-11-02T07:18:14.661Z] 07:18:14 INFO -
Comment 1•1 year ago
|
||
This is an error during teardown:
OSError: [WinError 10048] Only one usage of each socket address (protocol/network address/port) is normally permitted
Maybe available ports are exhausted? Might be a badly behaving machine. Lets observe.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 16•1 year ago
|
||
The failures here come from the following assertion:
https://treeherder.mozilla.org/logviewer?job_id=446641494&repo=mozilla-beta&lineNumber=129134-129196
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO - if is_blocked is not None:
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO - > assert event["isBlocked"] == is_blocked
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO - E AssertionError
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO -
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO - context = None
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO - event = {'context': '3246b459-9ed3-4b45-ace2-368aaacec804',
[task 2024-02-09T11:04:32.963Z] 11:04:32 INFO - 'initiator': {'type': 'other'},
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'intercepts': ['1fcb741f-44f2-4a22-9f5d-db2ab0800ff2'],
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'isBlocked': True,
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'navigation': None,
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'redirectCount': 0,
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'request': {'bodySize': None,
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'cookies': [],
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'headers': [{'name': 'Host',
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'value': {'type': 'string',
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'value': 'web-platform.test'}},
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - {'name': 'User-Agent',
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'value': {'type': 'string',
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'value': 'Mozilla/5.0 (Windows NT 10.0; '
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'Win64; x64; rv:123.0) '
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'Gecko/20100101 Firefox/123.0'}},
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - {'name': 'Accept',
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - 'value': {'type': 'string', 'value': '*/*'}},
[task 2024-02-09T11:04:32.964Z] 11:04:32 INFO - {'name': 'Accept-Language',
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - 'value': {'type': 'string',
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - 'value': 'en-US,en;q=0.5'}},
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - {'name': 'Accept-Encoding',
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - 'value': {'type': 'string',
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - 'value': 'gzip, deflate, br'}},
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - {'name': 'Origin',
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - 'value': {'type': 'string', 'value': 'null'}},
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - {'name': 'Connection',
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - 'value': {'type': 'string', 'value': 'keep-alive'}},
[task 2024-02-09T11:04:32.965Z] 11:04:32 INFO - {'name': 'Sec-Fetch-Dest',
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'value': {'type': 'string', 'value': 'empty'}},
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - {'name': 'Sec-Fetch-Mode',
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'value': {'type': 'string', 'value': 'cors'}},
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - {'name': 'Sec-Fetch-Site',
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'value': {'type': 'string', 'value': 'cross-site'}}],
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'headersSize': 0,
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'method': 'GET',
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'request': '34',
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'timings': {'connectEnd': 0,
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'connectStart': 1707476669865526,
[task 2024-02-09T11:04:32.966Z] 11:04:32 INFO - 'dnsEnd': 1707476667828944,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'dnsStart': 1707476667828814,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'fetchStart': 1707476667828814,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'redirectEnd': 0,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'redirectStart': 0,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'requestStart': 0,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'requestTime': 1707476667827000,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'responseEnd': 0,
[task 2024-02-09T11:04:32.967Z] 11:04:32 INFO - 'responseStart': 0,
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - 'timeOrigin': 0,
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - 'tlsEnd': 0,
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - 'tlsStart': 0},
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - 'url': 'https://web-platform.test/'},
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - 'timestamp': 1707476670118}
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - expected_request = None
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - intercepts = None
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - is_blocked = False
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - navigation = None
[task 2024-02-09T11:04:32.968Z] 11:04:32 INFO - redirect_count = None
Julian, could you please have a quick look?
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 18•1 year ago
|
||
It seems that we are randomly getting a beforeRequestSent event for a request which was already emitted for a previous test. Most likely this is because we receive the response for that request and re-create a beforeRequestSent event for it.
The network observer gets stopped and started dynamically as the tests are running, and if a new instance of the network observer catches a response for which it did not catch the request, it will emit a beforeRequestSent event for consistency.
To fix this, we could either isolate the browsing contexts used for the tests by using the new_tab fixture (so that we only capture network events for that specific context) or try to ignore those "fake" beforeRequestSent notifications.
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 23•10 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 24•9 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=459083018&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment 26•6 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 27•6 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=472497598&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 36•3 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 37•27 days ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=491751941&repo=mozilla-esr128
Comment hidden (Intermittent Failures Robot) |
Comment 40•15 days ago
•
|
||
There's been a recent spike in failures as you can see here , all failing on linux1804-64-asan-qr
Failure log: https://treeherder.mozilla.org/logviewer?job_id=493449971&repo=autoland&lineNumber=104330
Could you please take a look? Thanks.
Comment 41•15 days ago
|
||
Set release status flags based on info from the regressing bug 1945706
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 43•15 days ago
•
|
||
We used to OK, TIMEOUT on asan but the bot removed it with https://hg.mozilla.org/integration/autoland/rev/8cfaeb03aace407860088b65a2fb66ad39a81b13#l5.7
We can either fix it early here or wait for Bug 1938604 to land.
Comment 44•13 days ago
|
||
Updated•13 days ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•10 days ago
|
Updated•10 days ago
|
Comment 46•10 days ago
|
||
The bot updated it: https://hg.mozilla.org/mozilla-central/diff/167e09399035777045ef76a98340107b026b6a29/testing/web-platform/meta/webdriver/tests/bidi/network/add_intercept/url_patterns.py.ini.
And the failures also went down over the weekend.
Updated•10 days ago
|
Comment 47•10 days ago
|
||
Comment 48•10 days ago
|
||
Sasha, as Joel mentioned to me recently we should keep separate entries for different variations, so the entries as done by the bot were fine. Also the OK, TIMEOUT
multiple status we probably should not set as a default. Maybe we should backout this recently landed patch?
Comment 49•10 days ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #48)
Sasha, as Joel mentioned to me recently we should keep separate entries for different variations, so the entries as done by the bot were fine. Also the
OK, TIMEOUT
multiple status we probably should not set as a default. Maybe we should backout this recently landed patch?
Ok, I've requested the backout
Comment 50•10 days ago
|
||
Backed out changeset 36d5e330a6ad (Bug 1862600) by developer request: https://hg.mozilla.org/integration/autoland/rev/03ffd79deed43cc44de3fd89c3f3732f1127f39e
Updated•10 days ago
|
Updated•10 days ago
|
Updated•6 days ago
|
Assignee | ||
Comment 51•2 days ago
|
||
push enabling the tests on ASAN with rebuild 10: https://treeherder.mozilla.org/jobs?repo=try&revision=83e4d7cf7b0479d5ab3c1a55a425c4a085e4dc70
Compared to comment 18, it seems we already moved the test to use the new_tab
fixture so this is most likely a different issue.
The recent failures are however a bit tricky to investigate because they hit a temporary regression in the EventsDispatcher which was recently fixed by Sasha. It's also possible that the recent spike was due to this regression?
Let's see if we can get a failure on try.
Assignee | ||
Comment 52•2 days ago
|
||
No failure on try, reenable to monitor.
Updated•2 days ago
|
Comment 53•2 days ago
|
||
Comment 54•2 days ago
|
||
bugherder |
Description
•