Closed Bug 1815080 Opened 2 years ago Closed 2 years ago

Intermittent TV TinderboxPrint: Per-test run of ...\image-set-computed.sub.html<br/>: FAILURE

Categories

(Testing :: web-platform-tests, defect, P5)

defect

Tracking

(firefox-esr102 unaffected, firefox110 unaffected, firefox111 wontfix, firefox112 wontfix)

RESOLVED INCOMPLETE
Tracking Status
firefox-esr102 --- unaffected
firefox110 --- unaffected
firefox111 --- wontfix
firefox112 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=404613777&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fch50JfnQ5G9jzAo0LCjCw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fch50JfnQ5G9jzAo0LCjCw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2023-02-04T21:12:45.514Z] 21:12:45     INFO - | `Property background-image value '-webkit-image-set(url(http://web-platform.test/example.png) type('image/png') 1x)'`                                 | PASS    |                                                                                                                                                                                    |
[task 2023-02-04T21:12:45.515Z] 21:12:45     INFO - | `Property content value 'image-set(url('http://web-platform.test/example.png') 192dpi, linear-gradient(black, white) 1x)'`                            | FAIL    | `assert_true: 'image-set(url('http://web-platform.test/example.png') 192dpi, linear-gradient(black, white) 1x)' is a supported value for content. expected true got false`         |
[task 2023-02-04T21:12:45.515Z] 21:12:45     INFO - | `Property content value '-webkit-image-set(url('http://web-platform.test/example.png') 192dpi, linear-gradient(black, white) 1x)'`                    | FAIL    | `assert_true: '-webkit-image-set(url('http://web-platform.test/example.png') 192dpi, linear-gradient(black, white) 1x)' is a supported value for content. expected true got false` |
[task 2023-02-04T21:12:45.516Z] 21:12:45     INFO - 
[task 2023-02-04T21:12:45.516Z] 21:12:45     INFO - ## Slow tests ##
[task 2023-02-04T21:12:45.516Z] 21:12:45     INFO - 
[task 2023-02-04T21:12:45.517Z] 21:12:45     INFO - |                           Test                          | Result | Longest duration (ms) | Timeout (ms) |
[task 2023-02-04T21:12:45.518Z] 21:12:45     INFO - |---------------------------------------------------------|--------|-----------------------|--------------|
[task 2023-02-04T21:12:45.518Z] 21:12:45     INFO - | `/css/css-images/image-set/image-set-computed.sub.html` | `OK`   | `8679`                | `10000`      |
[task 2023-02-04T21:12:45.518Z] 21:12:45     INFO - 
[task 2023-02-04T21:12:45.519Z] 21:12:45     INFO - ::: Running tests in a loop 10 times : FAIL
[task 2023-02-04T21:12:45.519Z] 21:12:45     INFO - :::
[task 2023-02-04T21:12:45.519Z] 21:12:45    ERROR - ::: Test verification FAIL
[task 2023-02-04T21:12:45.520Z] 21:12:45     INFO - :::
[task 2023-02-04T21:12:45.739Z] 21:12:45    ERROR - Return code: 1
[task 2023-02-04T21:12:45.740Z] 21:12:45    ERROR - # TBPL FAILURE #
[task 2023-02-04T21:12:45.740Z] 21:12:45  WARNING - setting return code to 2
[task 2023-02-04T21:12:45.740Z] 21:12:45    ERROR - TinderboxPrint: Per-test run of ...\image-set-computed.sub.html<br/>: FAILURE
[task 2023-02-04T21:12:45.743Z] 21:12:45     INFO - Running command: ['Z:\\task_167554099460242\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_167554099460242\\build\\tests\\web-platform\\runtests.py', '--log-raw=-', '--log-raw=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wpt-test7_raw.log', '--log-wptreport=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wptreport.json', '--log-errorsummary=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wpt-test7_errorsummary.log', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HpsadME8SlyW9QITo5MzRw/artifacts/public/build/target.crashreporter-symbols.zip', '--stackwalk-binary=Z:/task_167554099460242/fetches\\minidump-stackwalk\\minidump-stackwalk.exe', '--stackfix-dir=Z:\\task_167554099460242\\build\\tests\\bin', '--no-pause-after-test', '--instrument-to-file=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wpt_instruments.txt', '--specialpowers-path=Z:\\task_167554099460242\\build\\tests\\extensions\\specialpowers@mozilla.org.xpi', '--processes=1', '--binary=Z:\\task_167554099460242\\build\\application\\firefox\\firefox.exe', '--install-fonts', '--test-type=testharness', '--setpref=media.peerconnection.mtransport_process=false', '--setpref=network.process.enabled=false', '--setpref=layers.d3d11.enable-blacklist=false', '--prefs-root=Z:\\task_167554099460242\\build\\tests\\web-platform/prefs', '--config=Z:\\task_167554099460242\\build\\tests\\web-platform/wptrunner.ini', '--ca-cert-path=Z:\\task_167554099460242\\build\\tests\\web-platform/tests/tools/certs/cacert.pem', '--host-key-path=Z:\\task_167554099460242\\build\\tests\\web-platform/tests/tools/certs/web-platform.test.key', '--host-cert-path=Z:\\task_167554099460242\\build\\tests\\web-platform/tests/tools/certs/web-platform.test.pem', '--certutil-binary=Z:\\task_167554099460242\\build\\tests/bin/certutil', '--verify-log-full', '--verify', 'tests/web-platform/tests/css/css-images/image-set/image-set-parsing.html'] in Z:\task_167554099460242\build
[task 2023-02-04T21:12:45.743Z] 21:12:45     INFO - Copy/paste: Z:\task_167554099460242\build\venv\Scripts\python -u Z:\task_167554099460242\build\tests\web-platform\runtests.py --log-raw=- --log-raw=Z:\task_167554099460242\build\blobber_upload_dir\wpt-test7_raw.log --log-wptreport=Z:\task_167554099460242\build\blobber_upload_dir\wptreport.json --log-errorsummary=Z:\task_167554099460242\build\blobber_upload_dir\wpt-test7_errorsummary.log --symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HpsadME8SlyW9QITo5MzRw/artifacts/public/build/target.crashreporter-symbols.zip --stackwalk-binary=Z:/task_167554099460242/fetches\minidump-stackwalk\minidump-stackwalk.exe --stackfix-dir=Z:\task_167554099460242\build\tests\bin --no-pause-after-test --instrument-to-file=Z:\task_167554099460242\build\blobber_upload_dir\wpt_instruments.txt --specialpowers-path=Z:\task_167554099460242\build\tests\extensions\specialpowers@mozilla.org.xpi --processes=1 --binary=Z:\task_167554099460242\build\application\firefox\firefox.exe --install-fonts --test-type=testharness --setpref=media.peerconnection.mtransport_process=false --setpref=network.process.enabled=false --setpref=layers.d3d11.enable-blacklist=false --prefs-root=Z:\task_167554099460242\build\tests\web-platform/prefs --config=Z:\task_167554099460242\build\tests\web-platform/wptrunner.ini --ca-cert-path=Z:\task_167554099460242\build\tests\web-platform/tests/tools/certs/cacert.pem --host-key-path=Z:\task_167554099460242\build\tests\web-platform/tests/tools/certs/web-platform.test.key --host-cert-path=Z:\task_167554099460242\build\tests\web-platform/tests/tools/certs/web-platform.test.pem --certutil-binary=Z:\task_167554099460242\build\tests/bin/certutil --verify-log-full --verify tests/web-platform/tests/css/css-images/image-set/image-set-parsing.html
[task 2023-02-04T21:12:45.760Z] 21:12:45     INFO - Using env: (same as previous command)
[task 2023-02-04T21:12:45.760Z] 21:12:45     INFO - Calling ['Z:\\task_167554099460242\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_167554099460242\\build\\tests\\web-platform\\runtests.py', '--log-raw=-', '--log-raw=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wpt-test7_raw.log', '--log-wptreport=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wptreport.json', '--log-errorsummary=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wpt-test7_errorsummary.log', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HpsadME8SlyW9QITo5MzRw/artifacts/public/build/target.crashreporter-symbols.zip', '--stackwalk-binary=Z:/task_167554099460242/fetches\\minidump-stackwalk\\minidump-stackwalk.exe', '--stackfix-dir=Z:\\task_167554099460242\\build\\tests\\bin', '--no-pause-after-test', '--instrument-to-file=Z:\\task_167554099460242\\build\\blobber_upload_dir\\wpt_instruments.txt', '--specialpowers-path=Z:\\task_167554099460242\\build\\tests\\extensions\\specialpowers@mozilla.org.xpi', '--processes=1', '--binary=Z:\\task_167554099460242\\build\\application\\firefox\\firefox.exe', '--install-fonts', '--test-type=testharness', '--setpref=media.peerconnection.mtransport_process=false', '--setpref=network.process.enabled=false', '--setpref=layers.d3d11.enable-blacklist=false', '--prefs-root=Z:\\task_167554099460242\\build\\tests\\web-platform/prefs', '--config=Z:\\task_167554099460242\\build\\tests\\web-platform/wptrunner.ini', '--ca-cert-path=Z:\\task_167554099460242\\build\\tests\\web-platform/tests/tools/certs/cacert.pem', '--host-key-path=Z:\\task_167554099460242\\build\\tests\\web-platform/tests/tools/certs/web-platform.test.key', '--host-cert-path=Z:\\task_167554099460242\\build\\tests\\web-platform/tests/tools/certs/web-platform.test.pem', '--certutil-binary=Z:\\task_167554099460242\\build\\tests/bin/certutil', '--verify-log-full', '--verify', 'tests/web-platform/tests/css/css-images/image-set/image-set-parsing.html'] with output_timeout 1000
[task 2023-02-04T21:12:46.052Z] 21:12:46     INFO - :::
[task 2023-02-04T21:12:46.060Z] 21:12:46     INFO - ::: Running test verification step "Running tests in a loop 10 times"...
[task 2023-02-04T21:12:46.060Z] 21:12:46     INFO - :::
[task 2023-02-04T21:12:46.353Z] 21:12:46     INFO - mozversion application_buildid: 20230204202557
[task 2023-02-04T21:12:46.360Z] 21:12:46     INFO - mozversion application_changeset: 94d5fff2532c6145e2ba75460c2c025ab9c4e190
[task 2023-02-04T21:12:46.360Z] 21:12:46     INFO - mozversion application_display_name: Firefox Nightly
[task 2023-02-04T21:12:46.360Z] 21:12:46     INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
[task 2023-02-04T21:12:46.361Z] 21:12:46     INFO - mozversion application_name: Firefox
[task 2023-02-04T21:12:46.361Z] 21:12:46     INFO - mozversion application_remotingname: firefox-default
[task 2023-02-04T21:12:46.362Z] 21:12:46     INFO - mozversion application_repository: https://hg.mozilla.org/integration/autoland
[task 2023-02-04T21:12:46.362Z] 21:12:46     INFO - mozversion application_vendor: Mozilla
[task 2023-02-04T21:12:46.363Z] 21:12:46     INFO - mozversion application_version: 111.0a1
[task 2023-02-04T21:12:46.363Z] 21:12:46     INFO - mozversion platform_buildid: 20230204202557
[task 2023-02-04T21:12:46.363Z] 21:12:46     INFO - mozversion platform_changeset: 94d5fff2532c6145e2ba75460c2c025ab9c4e190
[task 2023-02-04T21:12:46.364Z] 21:12:46     INFO - mozversion platform_repository: https://hg.mozilla.org/integration/autoland
[task 2023-02-04T21:12:46.364Z] 21:12:46     INFO - mozversion platform_version: 111.0a1
[task 2023-02-04T21:12:50.970Z] 21:12:50     INFO - Using 1 client processes
[task 2023-02-04T21:12:51.990Z] 21:12:51     INFO - Installed font: Ahem.ttf
[task 2023-02-04T21:12:52.589Z] 21:12:52     INFO - wptserve Starting http server on http://127.0.0.1:8000
[task 2023-02-04T21:12:53.139Z] 21:12:53     INFO - wptserve Starting http server on http://127.0.0.1:8001
[task 2023-02-04T21:12:53.696Z] 21:12:53     INFO - wptserve Starting http server on http://127.0.0.1:8002
[task 2023-02-04T21:12:54.268Z] 21:12:54     INFO - wptserve Starting http server on http://127.0.0.1:8003
[task 2023-02-04T21:12:54.832Z] 21:12:54     INFO - wptserve Starting https server on https://127.0.0.1:8443
[task 2023-02-04T21:12:55.410Z] 21:12:55     INFO - wptserve Starting https server on https://127.0.0.1:8444
[task 2023-02-04T21:12:55.955Z] 21:12:55     INFO - wptserve Starting https server on https://127.0.0.1:8445
[task 2023-02-04T21:12:56.506Z] 21:12:56     INFO - wptserve Starting https server on https://127.0.0.1:8446
[task 2023-02-04T21:12:57.060Z] 21:12:57     INFO - wptserve Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2023-02-04T21:12:57.075Z] 21:12:57     INFO - wptserve Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2023-02-04T21:12:57.076Z] 21:12:57     INFO - wptserve Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2023-02-04T21:12:57.635Z] 21:12:57     INFO - wptserve Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2023-02-04T21:12:57.651Z] 21:12:57     INFO - wptserve Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2023-02-04T21:12:57.652Z] 21:12:57     INFO - wptserve Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2023-02-04T21:12:58.195Z] 21:12:58     INFO - wptserve Starting http2 server on https://127.0.0.1:9000
[task 2023-02-04T21:12:58.294Z] 21:12:58     INFO - SUITE-START | Running 1 tests
[task 2023-02-04T21:12:58.308Z] 21:12:58     INFO - Setting up ssl
[task 2023-02-04T21:12:58.406Z] 21:12:58     INFO - certutil | b''
[task 2023-02-04T21:12:58.524Z] 21:12:58     INFO - certutil | b''
[task 2023-02-04T21:12:58.539Z] 21:12:58     INFO - certutil | b'\nCertificate Nickname                                         Trust Attributes\n                                                             SSL,S/MIME,JAR/XPI\n\nweb-platform-tests                                           CT,, \r\n'
[task 2023-02-04T21:12:58.560Z] 21:12:58     INFO - Application command: Z:\task_167554099460242\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_167554099460242\AppData\Local\Temp\tmpku_2h9z1
[task 2023-02-04T21:12:58.564Z] 21:12:58     INFO - Starting runner
[task 2023-02-04T21:12:58.935Z] 21:12:58     INFO - PID 7428 | 1675545178944	Marionette	INFO	Marionette enabled
[task 2023-02-04T21:12:58.948Z] 21:12:58     INFO - PID 7428 | 1675545178948	Marionette	INFO	Listening on port 51473
[task 2023-02-04T21:12:59.350Z] 21:12:59     INFO - PID 7428 | JavaScript error: resource://gre/modules/XULStore.jsm, line 58: Error: Can't find profile directory.
[task 2023-02-04T21:12:59.750Z] 21:12:59     INFO - PID 7428 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-04T21:13:00.330Z] 21:13:00     INFO - PID 7428 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_167554099460242\\AppData\\Local\\Temp\\tmpku_2h9z1\\search.json.mozlz4", (void 0)))
[task 2023-02-04T21:13:00.554Z] 21:13:00     INFO - PID 7428 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-04T21:13:00.558Z] 21:13:00     INFO - PID 7428 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-04T21:13:00.558Z] 21:13:00     INFO - PID 7428 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-02-04T21:13:01.268Z] 21:13:01     INFO - PID 7428 | console.error: (new TypeError("can't access property \"find\", this._searchProviderInfo is null", "resource:///modules/SearchSERPTelemetry.sys.mjs", 461))
[task 2023-02-04T21:13:01.343Z] 21:13:01     INFO - TEST-START | /css/css-images/image-set/image-set-parsing.html
Regressed by: 1813467

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

The failure here was just a "slow test" failure, since the longest duration was 8679ms which was "too close" to the test-timeout threshold which I guess is still 10 seconds.

I think this is just bug 1734020, which was fixed but apparently not entirely.

jmaher, could you take a look at what might've gone wrong here to prevent bug 1734020 from mitigating this?

Component: Layout: Images, Video, and HTML Frames → web-platform-tests
Flags: needinfo?(jmaher)
Keywords: regression
Product: Core → Testing
Aha, this wasn't in chaos mode. This was just during `Running test verification step "Running tests in a loop 10 times"...` Log snippet: ``` [task 2023-02-04T21:11:24.772Z] 21:11:24 INFO - ::: [task 2023-02-04T21:11:24.780Z] 21:11:24 INFO - ::: Running test verification step "Running tests in a loop 10 times"... [task 2023-02-04T21:11:24.781Z] 21:11:24 INFO - ::: [...] [task 2023-02-04T21:12:45.516Z] 21:12:45 INFO - ## Slow tests ## [task 2023-02-04T21:12:45.516Z] 21:12:45 INFO - [task 2023-02-04T21:12:45.517Z] 21:12:45 INFO - | Test | Result | Longest duration (ms) | Timeout (ms) | [task 2023-02-04T21:12:45.518Z] 21:12:45 INFO - |---------------------------------------------------------|--------|-----------------------|--------------| [task 2023-02-04T21:12:45.518Z] 21:12:45 INFO - | `/css/css-images/image-set/image-set-computed.sub.html` | `OK` | `8679` | `10000` | [task 2023-02-04T21:12:45.518Z] 21:12:45 INFO - [task 2023-02-04T21:12:45.519Z] 21:12:45 INFO - ::: Running tests in a loop 10 times : FAIL [task 2023-02-04T21:12:45.519Z] 21:12:45 INFO - ::: [task 2023-02-04T21:12:45.519Z] 21:12:45 ERROR - ::: Test verification FAIL ``` This wasn't an outlier; many of the test iterations were 6+ seconds long: So this might just be a slow test. Needs investigation to find out why & if it's also slow in other browsers as well. If the slowness isn't unique to Firefox, we can just annotate the test as needing a longer timeout.
Flags: needinfo?(jmaher)
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: