Open Bug 1827515 Opened 1 year ago Updated 2 days ago

Intermittent /fetch/metadata/generated/svg-image.https.sub.html | single tracking bug

Categories

(Core :: SVG, defect, P3)

defect

Tracking

()

Tracking Status
firefox-esr102 --- unaffected
firefox112 --- unaffected
firefox113 --- unaffected
firefox114 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [retriggered][stockwell unknown][necko-triaged])

Attachments

(1 obsolete file)

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=412046453&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/XQ8-8lB-RYO8cFLU0yXIBA/runs/0/artifacts/public/logs/live_backing.log


[task 2023-04-11T17:13:18.199Z] 17:13:18     INFO - TEST-OK | /fetch/metadata/generated/serviceworker.https.sub.html | took 6536ms
[task 2023-04-11T17:13:18.199Z] 17:13:18     INFO - TEST-START | /fetch/metadata/generated/svg-image.https.sub.html
[task 2023-04-11T17:13:18.203Z] 17:13:18     INFO - Closing window a90ee4b3-6162-4a3f-91cb-3f0a7646478b
[task 2023-04-11T17:13:19.824Z] 17:13:19  WARNING - wptserve HTTPException in handler: 500
[task 2023-04-11T17:13:19.827Z] 17:13:19  WARNING - wptserve Traceback (most recent call last):
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/handlers.py", line 361, in __call__
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     rv = self.func(request, response)
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/fetch/metadata/resources/record-headers.py", line 60, in main
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     request.server.stash.put(testId, json.dumps(bytes_to_strings(request.headers)))
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/stash.py", line 212, in put
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     (internal_key, self.data[internal_key], value))
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - wptserve.stash.StashError: Tried to overwrite existing shared stash value for key (b'/fetch/metadata/resources/record-headers.py', b'd\x0b\x96\x86\xddb\x804F\xe30\x9c\xd9\x13\x90\x9b') (old value was {"host": ["web-platform.test:8443"], "user-agent": ["Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/114.0"], "accept": ["image/avif,image/webp,*/*"], "accept-language": ["en-US,en;q=0.5"], "accept-encoding": ["gzip, deflate, br"], "connection": ["keep-alive"], "referer": ["https://web-platform.test:8443/fetch/metadata/generated/svg-image.https.sub.html"], "sec-fetch-dest": ["image"], "sec-fetch-mode": ["no-cors"], "sec-fetch-site": ["same-origin"]}, new value is {"host": ["web-platform.test:8443"], "user-agent": ["Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/114.0"], "accept": ["image/avif,image/webp,*/*"], "accept-language": ["en-US,en;q=0.5"], "accept-encoding": ["gzip, deflate, br"], "connection": ["keep-alive"], "referer": ["https://web-platform.test:8443/fetch/metadata/generated/svg-image.https.sub.html"], "sec-fetch-dest": ["image"], "sec-fetch-mode": ["cors"], "sec-fetch-site": ["same-origin"], "cache-control": ["max-age=0"]})
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - 
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - During handling of the above exception, another exception occurred:
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - 
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - Traceback (most recent call last):
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/server.py", line 289, in finish_handling
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     handler(request, response)
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/handlers.py", line 322, in __call__
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     self._load_file(request, response, func)
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/handlers.py", line 308, in _load_file
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     return func(request, response, environ, path)
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/handlers.py", line 317, in func
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     handler(request, response)
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptserve/wptserve/handlers.py", line 366, in __call__
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING -     raise HTTPException(500, message=msg)
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - wptserve.utils.HTTPException: 500
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - 
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - wptserve Exception loading https://web-platform.test:8443/fetch/metadata/resources/record-headers.py?key=ac3931aa-6959-4604-8e08-0252ab008c7e&body=%0A++++++%3Csvg+xmlns%3D%22http%3A%2F%2Fwww.w3.org%2F2000%2Fsvg%22+width%3D%22123%22+height%3D%22123%22%3E%0A++++++++%3Crect+fill%3D%22lime%22+width%3D%22123%22+height%3D%22123%22%2F%3E%0A++++++%3C%2Fsvg%3E%0A++++&mime=image%2Fsvg%2Bxml: 500
[task 2023-04-11T17:13:19.829Z] 17:13:19     INFO - wptserve 500
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - wptserve.utils.HTTPException: 500
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - 
[task 2023-04-11T17:13:19.828Z] 17:13:19  WARNING - wptserve Exception loading https://web-platform.test:8443/fetch/metadata/resources/record-headers.py?key=ac3931aa-6959-4604-8e08-0252ab008c7e&body=%0A++++++%3Csvg+xmlns%3D%22http%3A%2F%2Fwww.w3.org%2F2000%2Fsvg%22+width%3D%22123%22+height%3D%22123%22%3E%0A++++++++%3Crect+fill%3D%22lime%22+width%3D%22123%22+height%3D%22123%22%2F%3E%0A++++++%3C%2Fsvg%3E%0A++++&mime=image%2Fsvg%2Bxml: 500
[task 2023-04-11T17:13:19.829Z] 17:13:19     INFO - wptserve 500
[task 2023-04-11T17:13:20.255Z] 17:13:20     INFO - ......
[task 2023-04-11T17:13:20.256Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Cross-Site -> Same-Site no attributes 
[task 2023-04-11T17:13:20.256Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Cross-Site -> Cross-Site no attributes 
[task 2023-04-11T17:13:20.256Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Origin -> Same Origin no attributes 
[task 2023-04-11T17:13:20.256Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Origin -> Same-Site no attributes 
[task 2023-04-11T17:13:20.257Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Origin -> Cross-Site no attributes 
[task 2023-04-11T17:13:20.257Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Site -> Same Origin no attributes 
[task 2023-04-11T17:13:20.257Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Site -> Same-Site no attributes 
[task 2023-04-11T17:13:20.258Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Site -> Cross-Site no attributes 
[task 2023-04-11T17:13:20.259Z] 17:13:20     INFO - TEST-FAIL | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - HTTPS downgrade-upgrade no attributes - promise_test: Unhandled rejection with value: object "[object Event]"
[task 2023-04-11T17:13:20.260Z] 17:13:20     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-mode no attributes 
[task 2023-04-11T17:13:20.261Z] 17:13:20     INFO - TEST-UNEXPECTED-FAIL | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-mode attributes: crossorigin - promise_test: Unhandled rejection with value: object "[object Event]"
[task 2023-04-11T17:13:20.262Z] 17:13:20     INFO - ....
[task 2023-04-11T17:13:20.263Z] 17:13:20     INFO - TEST-OK | /fetch/metadata/generated/svg-image.https.sub.html | took 2054ms
[task 2023-04-11T17:13:20.264Z] 17:13:20     INFO - PID 15104 | 1681233200252	Marionette	INFO	Stopped listening on port 60365
See Also: → 1769468
Keywords: regression
Regressed by: 1240357

Set release status flags based on info from the regressing bug 1240357

:longsonr, since you are the author of the regressor, bug 1240357, could you take a look?

For more information, please visit auto_nag documentation.

Seems to be only linux with fission disabled. There are various other tests with a linux and no fission annotation. https://phabricator.services.mozilla.com/D147691 so I guess that's what this needs too.

Flags: needinfo?(longsonr)
Assignee: nobody → longsonr
Status: NEW → ASSIGNED
Attachment #9328109 - Attachment is obsolete: true
Assignee: longsonr → nobody
Status: ASSIGNED → NEW

Update

There have been 34 failures within the last 7 days:

  • 8 failures on Linux 18.04 x64 WebRender Shippable opt
  • 24 failures on Linux 18.04 x64 WebRender debug/opt
  • 2 failures on Linux 18.04 x64 WebRender asan opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=412594201&repo=autoland&lineNumber=11476

[task 2023-04-15T23:21:00.943Z] 23:21:00     INFO - TEST-PASS | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-mode attributes: crossorigin=anonymous 
[task 2023-04-15T23:21:00.943Z] 23:21:00     INFO - TEST-UNEXPECTED-FAIL | /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-mode attributes: crossorigin=use-credentials - promise_test: Unhandled rejection with value: object "[object Event]"
[task 2023-04-15T23:21:00.945Z] 23:21:00     INFO - ..
[task 2023-04-15T23:21:00.945Z] 23:21:00     INFO - TEST-OK | /fetch/metadata/generated/svg-image.https.sub.html | took 2840ms

Robert, are you still looking into this?
Thank you.

Flags: needinfo?(longsonr)
Whiteboard: [stockwell needswork:owner]
Whiteboard: [stockwell needswork:owner] → [retriggered][stockwell needswork:owner]

It seems to me like the previous test i.e. /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Site -> Cross-Site no attributes hasn't cleaned up properly and then the next test asserts that it shouldn't find something populated when it starts but it does.

The client tests run against a python server and that server is asserting.

I'm afraid I don't really know how to debug this.

The tests I wrote for this bug do appear to consistently pass and the code itself is simply a copy of what html images do ported to SVG images so although there may be a bug there I'm not convinced there is and I suspect this is some kind of bug in the python server code.

Flags: needinfo?(longsonr)

(In reply to Robert Longson [:longsonr] from comment #7)

It seems to me like the previous test i.e. /fetch/metadata/generated/svg-image.https.sub.html | sec-fetch-site - Same-Site -> Cross-Site no attributes hasn't cleaned up properly and then the next test asserts that it shouldn't find something populated when it starts but it does.

The client tests run against a python server and that server is asserting.

https://treeherder.mozilla.org/logviewer?job_id=414861845&repo=mozilla-central&lineNumber=13712

James, do you know what we should be doing in this case?

Flags: needinfo?(james)
Priority: P5 → P3
Whiteboard: [retriggered][stockwell unknown] → [retriggered][stockwell unknown][necko-triaged]

Stash keys are supposed to be UUIDs and tests aren't supposed to share keys, exactly so that multiple tests can't interfere with each other. Weirdly it looks like the test here is using the server subsitution UUID pipe, which should be getting fresh UUID4 for each usage, so it looks correct. record-headers.py hashed the key, which seems unnecessary, but I don't know why it would lead to conflicts.

So I'm not really sure why we'd hit a conflict here.

Flags: needinfo?(james)

Since this is triggered by https://phabricator.services.mozilla.com/D174737, I'm going to move this into Core::SVG
Otherwise, my approach would have been to edit the expectations to be:

  [sec-fetch-mode attributes: crossorigin]
    expected: [FAIL, PASS]
Component: DOM: Networking → SVG
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: