Open Bug 1874668 Opened 1 year ago Updated 1 year ago

Intermittent TVw3 TinderboxPrint: Per-test run of ...\loaf-event-blocking-duration.html<br/>: FAILURE

Categories

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

Product:
Testing
Component:
web-platform-tests
Type:
defect

Tracking

(firefox-esr115 unaffected, firefox121 unaffected, firefox122 unaffected, firefox123 affected, firefox124 affected)

Tracking Flags:
Tracking Status
firefox-esr115 --- unaffected
firefox121 --- unaffected
firefox122 --- unaffected
firefox123 --- affected
firefox124 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, test-verify-fail)

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=443304257&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Y5tmkiEARv6h6ZboGkqSLA/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/Y5tmkiEARv6h6ZboGkqSLA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2024-01-15T09:45:42.068Z] 09:45:42     INFO - wptserve Stopped http server on 127.0.0.1:8445
[task 2024-01-15T09:45:42.131Z] 09:45:42     INFO - Removed font: Ahem.ttf
[task 2024-01-15T09:45:42.209Z] 09:45:42     INFO - Closing logging queue
[task 2024-01-15T09:45:42.213Z] 09:45:42     INFO - queue closed
[task 2024-01-15T09:45:42.240Z] 09:45:42     INFO - Test harness output was not a valid structured log message
[task 2024-01-15T09:45:42.240Z] 09:45:42     INFO - Traceback (most recent call last):
[task 2024-01-15T09:45:42.252Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\runtests.py", line 16, in <module>
[task 2024-01-15T09:45:42.252Z] 09:45:42     INFO -     rv = wptrunner.main()
[task 2024-01-15T09:45:42.252Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\wptrunner.py", line 573, in main
[task 2024-01-15T09:45:42.252Z] 09:45:42     INFO -     return start(**kwargs)
[task 2024-01-15T09:45:42.253Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\wptrunner.py", line 554, in start
[task 2024-01-15T09:45:42.253Z] 09:45:42     INFO -     rv = check_stability(**kwargs) or logged_critical.has_log
[task 2024-01-15T09:45:42.253Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\wptrunner.py", line 529, in check_stability
[task 2024-01-15T09:45:42.254Z] 09:45:42     INFO -     return stability.check_stability(logger,
[task 2024-01-15T09:45:42.254Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\stability.py", line 379, in check_stability
[task 2024-01-15T09:45:42.254Z] 09:45:42     INFO -     total_iterations, all_skipped, results, inconsistent, slow = step_func(**kwargs)
[task 2024-01-15T09:45:42.254Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\stability.py", line 294, in run_step
[task 2024-01-15T09:45:42.255Z] 09:45:42     INFO -     _, test_status = wptrunner.run_tests(**kwargs)
[task 2024-01-15T09:45:42.255Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\wptrunner.py", line 453, in run_tests
[task 2024-01-15T09:45:42.255Z] 09:45:42     INFO -     test_environment.ensure_started()
[task 2024-01-15T09:45:42.256Z] 09:45:42     INFO -   File "Z:\task_170530763549493\build\tests\web-platform\tests\tools\wptrunner\wptrunner\environment.py", line 283, in ensure_started
[task 2024-01-15T09:45:42.256Z] 09:45:42     INFO -     raise OSError(msg)
[task 2024-01-15T09:45:42.256Z] 09:45:42     INFO - OSError: Timed out wait for servers to start: 127.0.0.1:11000
[task 2024-01-15T09:45:42.709Z] 09:45:42     INFO - Return code: 1
[task 2024-01-15T09:45:42.713Z] 09:45:42    ERROR - No suite end message was emitted by this harness.
[task 2024-01-15T09:45:42.713Z] 09:45:42    ERROR - No checks run.
[task 2024-01-15T09:45:42.713Z] 09:45:42  WARNING - setting return code to 2
[task 2024-01-15T09:45:42.713Z] 09:45:42    ERROR - TinderboxPrint: Per-test run of ...\loaf-event-blocking-duration.html<br/>: FAILURE
[task 2024-01-15T09:45:42.716Z] 09:45:42     INFO - Running command: ['Z:\\task_170530763549493\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_170530763549493\\build\\tests\\web-platform\\runtests.py', '--log-raw=-', '--log-wptreport=Z:\\task_170530763549493\\build\\blobber_upload_dir\\wptreport.json', '--log-errorsummary=Z:\\task_170530763549493\\build\\blobber_upload_dir\\wpt-test2_errorsummary.log', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/EUcfVFCuRFWOkCozgwOFGA/artifacts/public/build/target.crashreporter-symbols.zip', '--stackwalk-binary=Z:/task_170530763549493/fetches\\minidump-stackwalk\\minidump-stackwalk.exe', '--stackfix-dir=Z:\\task_170530763549493\\build\\tests\\bin', '--no-pause-after-test', '--instrument-to-file=Z:\\task_170530763549493\\build\\blobber_upload_dir\\wpt_instruments.txt', '--specialpowers-path=Z:\\task_170530763549493\\build\\tests\\extensions\\specialpowers@mozilla.org.xpi', '--suppress-handler-traceback', '--processes=1', '--binary=Z:\\task_170530763549493\\build\\application\\firefox\\firefox.exe', '--product=firefox', '--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_170530763549493\\build\\tests\\web-platform\\prefs', '--config=Z:\\task_170530763549493\\build\\tests\\web-platform\\wptrunner.ini', '--ca-cert-path=Z:\\task_170530763549493\\build\\tests\\web-platform\\tests\\tools\\certs\\cacert.pem', '--host-key-path=Z:\\task_170530763549493\\build\\tests\\web-platform\\tests\\tools\\certs\\web-platform.test.key', '--host-cert-path=Z:\\task_170530763549493\\build\\tests\\web-platform\\tests\\tools\\certs\\web-platform.test.pem', '--certutil-binary=Z:\\task_170530763549493\\build\\tests\\bin\\certutil.exe', '--verify-log-full', '--verify', 'tests/web-platform/tests/long-animation-frame/tentative/loaf-first-ui-event.html'] in Z:\task_170530763549493\build
[task 2024-01-15T09:45:42.716Z] 09:45:42     INFO - Copy/paste: Z:\task_170530763549493\build\venv\Scripts\python -u Z:\task_170530763549493\build\tests\web-platform\runtests.py --log-raw=- --log-wptreport=Z:\task_170530763549493\build\blobber_upload_dir\wptreport.json --log-errorsummary=Z:\task_170530763549493\build\blobber_upload_dir\wpt-test2_errorsummary.log --symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/EUcfVFCuRFWOkCozgwOFGA/artifacts/public/build/target.crashreporter-symbols.zip --stackwalk-binary=Z:/task_170530763549493/fetches\minidump-stackwalk\minidump-stackwalk.exe --stackfix-dir=Z:\task_170530763549493\build\tests\bin --no-pause-after-test --instrument-to-file=Z:\task_170530763549493\build\blobber_upload_dir\wpt_instruments.txt --specialpowers-path=Z:\task_170530763549493\build\tests\extensions\specialpowers@mozilla.org.xpi --suppress-handler-traceback --processes=1 --binary=Z:\task_170530763549493\build\application\firefox\firefox.exe --product=firefox --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_170530763549493\build\tests\web-platform\prefs --config=Z:\task_170530763549493\build\tests\web-platform\wptrunner.ini --ca-cert-path=Z:\task_170530763549493\build\tests\web-platform\tests\tools\certs\cacert.pem --host-key-path=Z:\task_170530763549493\build\tests\web-platform\tests\tools\certs\web-platform.test.key --host-cert-path=Z:\task_170530763549493\build\tests\web-platform\tests\tools\certs\web-platform.test.pem --certutil-binary=Z:\task_170530763549493\build\tests\bin\certutil.exe --verify-log-full --verify tests/web-platform/tests/long-animation-frame/tentative/loaf-first-ui-event.html
[task 2024-01-15T09:45:42.716Z] 09:45:42     INFO - Using env: (same as previous command)
[task 2024-01-15T09:45:42.833Z] 09:45:42     INFO - Calling ['Z:\\task_170530763549493\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_170530763549493\\build\\tests\\web-platform\\runtests.py', '--log-raw=-', '--log-wptreport=Z:\\task_170530763549493\\build\\blobber_upload_dir\\wptreport.json', '--log-errorsummary=Z:\\task_170530763549493\\build\\blobber_upload_dir\\wpt-test2_errorsummary.log', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/EUcfVFCuRFWOkCozgwOFGA/artifacts/public/build/target.crashreporter-symbols.zip', '--stackwalk-binary=Z:/task_170530763549493/fetches\\minidump-stackwalk\\minidump-stackwalk.exe', '--stackfix-dir=Z:\\task_170530763549493\\build\\tests\\bin', '--no-pause-after-test', '--instrument-to-file=Z:\\task_170530763549493\\build\\blobber_upload_dir\\wpt_instruments.txt', '--specialpowers-path=Z:\\task_170530763549493\\build\\tests\\extensions\\specialpowers@mozilla.org.xpi', '--suppress-handler-traceback', '--processes=1', '--binary=Z:\\task_170530763549493\\build\\application\\firefox\\firefox.exe', '--product=firefox', '--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_170530763549493\\build\\tests\\web-platform\\prefs', '--config=Z:\\task_170530763549493\\build\\tests\\web-platform\\wptrunner.ini', '--ca-cert-path=Z:\\task_170530763549493\\build\\tests\\web-platform\\tests\\tools\\certs\\cacert.pem', '--host-key-path=Z:\\task_170530763549493\\build\\tests\\web-platform\\tests\\tools\\certs\\web-platform.test.key', '--host-cert-path=Z:\\task_170530763549493\\build\\tests\\web-platform\\tests\\tools\\certs\\web-platform.test.pem', '--certutil-binary=Z:\\task_170530763549493\\build\\tests\\bin\\certutil.exe', '--verify-log-full', '--verify', 'tests/web-platform/tests/long-animation-frame/tentative/loaf-first-ui-event.html'] with output_timeout 1000
[task 2024-01-15T09:45:43.522Z] 09:45:43     INFO - :::
[task 2024-01-15T09:45:43.539Z] 09:45:43     INFO - ::: Running test verification step "Running tests in a loop 10 times"...
[task 2024-01-15T09:45:43.540Z] 09:45:43     INFO - :::
[task 2024-01-15T09:45:43.662Z] 09:45:43     INFO - mozversion application_buildid: 20240115090949
[task 2024-01-15T09:45:43.672Z] 09:45:43     INFO - mozversion application_changeset: 4a8011414b51c59e4bee6dba1006c6fbd254d445
[task 2024-01-15T09:45:43.672Z] 09:45:43     INFO - mozversion application_display_name: Firefox Nightly
[task 2024-01-15T09:45:43.673Z] 09:45:43     INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
[task 2024-01-15T09:45:43.673Z] 09:45:43     INFO - mozversion application_name: Firefox
[task 2024-01-15T09:45:43.673Z] 09:45:43     INFO - mozversion application_remotingname: firefox-default
[task 2024-01-15T09:45:43.674Z] 09:45:43     INFO - mozversion application_repository: https://hg.mozilla.org/integration/autoland
[task 2024-01-15T09:45:43.675Z] 09:45:43     INFO - mozversion application_vendor: Mozilla
[task 2024-01-15T09:45:43.675Z] 09:45:43     INFO - mozversion application_version: 123.0a1
[task 2024-01-15T09:45:43.675Z] 09:45:43     INFO - mozversion platform_buildid: 20240115090949
[task 2024-01-15T09:45:43.676Z] 09:45:43     INFO - mozversion platform_changeset: 4a8011414b51c59e4bee6dba1006c6fbd254d445
[task 2024-01-15T09:45:43.676Z] 09:45:43     INFO - mozversion platform_repository: https://hg.mozilla.org/integration/autoland
[task 2024-01-15T09:45:43.677Z] 09:45:43     INFO - mozversion platform_version: 123.0a1
[task 2024-01-15T09:45:51.399Z] 09:45:51     INFO - Installed font: Ahem.ttf
[task 2024-01-15T09:45:52.120Z] 09:45:52     INFO - wptserve Starting http server on http://127.0.0.1:8000
[task 2024-01-15T09:45:52.786Z] 09:45:52     INFO - wptserve Starting http server on http://127.0.0.1:8001
[task 2024-01-15T09:45:53.371Z] 09:45:53     INFO - wptserve Starting http server on http://127.0.0.1:8002
[task 2024-01-15T09:45:54.012Z] 09:45:54     INFO - wptserve Starting http server on http://127.0.0.1:8003
[task 2024-01-15T09:45:54.622Z] 09:45:54     INFO - wptserve Starting https server on https://127.0.0.1:8443
[task 2024-01-15T09:45:55.231Z] 09:45:55     INFO - wptserve Starting https server on https://127.0.0.1:8444
[task 2024-01-15T09:45:55.841Z] 09:45:55     INFO - wptserve Starting https server on https://127.0.0.1:8445
[task 2024-01-15T09:45:56.435Z] 09:45:56     INFO - wptserve Starting https server on https://127.0.0.1:8446
[task 2024-01-15T09:45:57.044Z] 09:45:57     INFO - wptserve Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2024-01-15T09:45:57.045Z] 09:45:57     INFO - wptserve Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2024-01-15T09:45:57.045Z] 09:45:57     INFO - wptserve Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2024-01-15T09:45:57.654Z] 09:45:57     INFO - wptserve Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2024-01-15T09:45:57.656Z] 09:45:57     INFO - wptserve Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2024-01-15T09:45:57.657Z] 09:45:57     INFO - wptserve Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2024-01-15T09:45:58.248Z] 09:45:58     INFO - wptserve Starting http2 server on https://127.0.0.1:9000
[task 2024-01-15T09:45:58.936Z] 09:45:58     INFO - wptserve Starting WebTransport over HTTP/3 server on 127.0.0.1:11000
[task 2024-01-15T09:46:05.392Z] 09:46:05     INFO - SUITE-START | Running 1 tests
[task 2024-01-15T09:46:05.396Z] 09:46:05     INFO - Using 1 child processes
[task 2024-01-15T09:46:05.407Z] 09:46:05     INFO - Setting up ssl
[task 2024-01-15T09:48:05.667Z] 09:48:05     INFO - certutil | b''
[task 2024-01-15T09:48:05.824Z] 09:48:05     INFO - certutil | b''
[task 2024-01-15T09:48:05.840Z] 09:48:05     INFO - certutil | b'\nCertificate Nickname                                         Trust Attributes\n                                                             SSL,S/MIME,JAR/XPI\n\nweb-platform-tests                                           CT,, \r\n'
[task 2024-01-15T09:48:05.855Z] 09:48:05     INFO - Application command: Z:\task_170530763549493\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_170530763549493\AppData\Local\Temp\tmpb124rrhx
[task 2024-01-15T09:48:29.894Z] 09:48:29     INFO - Starting runner
[task 2024-01-15T09:49:18.067Z] 09:49:18     INFO - Browser exited with return code 572
[task 2024-01-15T09:49:28.070Z] 09:49:28  WARNING - Forcibly terminating runner process
[task 2024-01-15T09:49:28.082Z] 09:49:28     INFO - Application command: Z:\task_170530763549493\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_170530763549493\AppData\Local\Temp\tmpw3p9llz8
[task 2024-01-15T09:49:28.090Z] 09:49:28     INFO - Starting runner
[task 2024-01-15T09:50:19.023Z] 09:50:19     INFO - PID 2804 | 1705312219028	Marionette	INFO	Marionette enabled
[task 2024-01-15T09:50:19.101Z] 09:50:19     INFO - PID 2804 | 1705312219103	Marionette	INFO	Listening on port 50195
[task 2024-01-15T09:50:29.346Z] 09:50:29     INFO - PID 2804 | [GFX1-]: Killing GPU process due to IPC reply timeout
[task 2024-01-15T09:50:29.347Z] 09:50:29     INFO - PID 2804 | [GFX1-]: Fallback WR to SW-WR + D3D11
[task 2024-01-15T09:50:29.348Z] 09:50:29     INFO - PID 2804 | [Parent 8524, Main Thread] WARNING: base::KillProcess refusing to terminate process handle 0: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_win.cc:349
[task 2024-01-15T09:50:31.307Z] 09:50:31     INFO - TEST-START | /long-animation-frame/tentative/loaf-first-ui-event.html

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

status-firefox121: --- → unaffected
status-firefox122: --- → unaffected
status-firefox123: --- → affected
status-firefox-esr115: --- → unaffected

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

status-firefox124: --- → affected
You need to log in before you can comment on or make changes to this bug.