Open Bug 1834837 Opened 11 months ago Updated 11 months ago

Intermittent TVw TinderboxPrint: Per-test run of ...\popover-light-dismiss.html<br/>: FAILURE

Categories

(Core :: DOM: Core & HTML, defect, P5)

Product:
Core
Component:
DOM: Core & HTML
Type:
defect

Tracking

()

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

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

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

[task 2023-05-24T15:06:13.962Z] 15:06:13     INFO - TEST-PASS | leakcheck | utility no leaks detected!
[task 2023-05-24T15:06:13.964Z] 15:06:13     INFO - Closing logging queue
[task 2023-05-24T15:06:13.964Z] 15:06:13     INFO - queue closed
[task 2023-05-24T15:06:13.965Z] 15:06:13  WARNING - Firefox didn't exit cleanly, not processing leak logs
[task 2023-05-24T15:06:13.999Z] Exception in thread ProcessReader:
[task 2023-05-24T15:06:13.999Z] Traceback (most recent call last):
[task 2023-05-24T15:06:13.999Z]   File "c:\mozilla-build\python3\lib\threading.py", line 973, in _bootstrap_inner
[task 2023-05-24T15:06:14.015Z]     self.run()
[task 2023-05-24T15:06:14.015Z]   File "c:\mozilla-build\python3\lib\threading.py", line 910, in run
[task 2023-05-24T15:06:14.015Z]     self._target(*self._args, **self._kwargs)
[task 2023-05-24T15:06:14.015Z]   File "Z:\task_168493829045327\mozharness\mozprocess\processhandler.py", line 1160, in _read
[task 2023-05-24T15:06:14.016Z]     callback(line.rstrip())
[task 2023-05-24T15:06:14.016Z]   File "Z:\task_168493829045327\mozharness\mozprocess\processhandler.py", line 1066, in __call__
[task 2023-05-24T15:06:14.016Z]     e(*args, **kwargs)
[task 2023-05-24T15:06:14.016Z]   File "Z:\task_168493829045327\mozharness\mozharness\base\script.py", line 1600, in processOutput
[task 2023-05-24T15:06:14.017Z]     parser.add_lines(line)
[task 2023-05-24T15:06:14.017Z]   File "Z:\task_168493829045327\mozharness\mozharness\base\log.py", line 371, in add_lines
[task 2023-05-24T15:06:14.017Z]     self.parse_single_line(line)
[task 2023-05-24T15:06:14.017Z]   File "Z:\task_168493829045327\mozharness\mozharness\mozilla\structuredlog.py", line 124, in parse_single_line
[task 2023-05-24T15:06:14.018Z]     log_data = self.formatter(data)
[task 2023-05-24T15:06:14.018Z]   File "Z:\task_168493829045327\build\venv\Lib\site-packages\mozlog\formatters\tbplformatter.py", line 47, in __call__
[task 2023-05-24T15:06:14.018Z]     return super(TbplFormatter, self).__call__(data)
[task 2023-05-24T15:06:14.018Z]   File "Z:\task_168493829045327\build\venv\Lib\site-packages\mozlog\reader.py", line 72, in __call__
[task 2023-05-24T15:06:14.018Z]     return handler(data)
[task 2023-05-24T15:06:14.018Z]   File "Z:\task_168493829045327\build\venv\Lib\site-packages\mozlog\formatters\tbplformatter.py", line 311, in suite_end
[task 2023-05-24T15:06:14.019Z]     time = int((data["time"] - start_time) / 1000)
[task 2023-05-24T15:06:14.019Z] TypeError: unsupported operand type(s) for -: 'int' and 'NoneType'
[task 2023-05-24T15:09:44.032Z] Traceback (most recent call last):
[task 2023-05-24T15:09:44.032Z]   File "Z:\task_168493829045327\mozharness\mozprocess\processhandler.py", line 640, in _custom_wait
[task 2023-05-24T15:09:44.032Z]     item = self._process_events.get(timeout=timeout)
[task 2023-05-24T15:09:44.032Z]   File "c:\mozilla-build\python3\lib\queue.py", line 179, in get
[task 2023-05-24T15:09:44.032Z]     raise Empty
[task 2023-05-24T15:09:44.032Z] _queue.Empty
[task 2023-05-24T15:09:44.035Z] 15:09:44    ERROR - caught OS error None: None while running ['Z:\\task_168493829045327\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_168493829045327\\build\\tests\\web-platform\\runtests.py', '--log-raw=-', '--log-wptreport=Z:\\task_168493829045327\\build\\blobber_upload_dir\\wptreport.json', '--log-errorsummary=Z:\\task_168493829045327\\build\\blobber_upload_dir\\wpt-test1_errorsummary.log', '--symbols-path=Z:\\task_168493829045327\\build\\symbols', '--stackwalk-binary=Z:/task_168493829045327/fetches\\minidump-stackwalk\\minidump-stackwalk.exe', '--stackfix-dir=Z:\\task_168493829045327\\build\\tests\\bin', '--no-pause-after-test', '--instrument-to-file=Z:\\task_168493829045327\\build\\blobber_upload_dir\\wpt_instruments.txt', '--specialpowers-path=Z:\\task_168493829045327\\build\\tests\\extensions\\specialpowers@mozilla.org.xpi', '--processes=1', '--binary=Z:\\task_168493829045327\\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_168493829045327\\build\\tests\\web-platform\\prefs', '--config=Z:\\task_168493829045327\\build\\tests\\web-platform\\wptrunner.ini', '--ca-cert-path=Z:\\task_168493829045327\\build\\tests\\web-platform\\tests\\tools\\certs\\cacert.pem', '--host-key-path=Z:\\task_168493829045327\\build\\tests\\web-platform\\tests\\tools\\certs\\web-platform.test.key', '--host-cert-path=Z:\\task_168493829045327\\build\\tests\\web-platform\\tests\\tools\\certs\\web-platform.test.pem', '--certutil-binary=Z:\\task_168493829045327\\build\\tests\\bin\\certutil.exe', '--verify-log-full', '--verify', 'tests/web-platform/tests/html/semantics/popovers/popover-light-dismiss.html']
[task 2023-05-24T15:09:44.035Z] 15:09:44  WARNING - setting return code to 2
[task 2023-05-24T15:09:44.035Z] 15:09:44    ERROR - TinderboxPrint: Per-test run of ...\popover-light-dismiss.html<br/>: FAILURE
[task 2023-05-24T15:09:44.035Z] 15:09:44     INFO - Running post-action listener: _package_coverage_data
[task 2023-05-24T15:09:44.035Z] 15:09:44     INFO - Running post-action listener: _resource_record_post_action
[task 2023-05-24T15:09:44.035Z] 15:09:44     INFO - Running post-action listener: process_java_coverage_data
[task 2023-05-24T15:09:44.035Z] 15:09:44     INFO - Running post-action listener: stop_device
[task 2023-05-24T15:09:44.035Z] 15:09:44     INFO - [mozharness: 2023-05-24 15:09:44.035827Z] Finished run-tests step (success)
[task 2023-05-24T15:09:44.035Z] 15:09:44     INFO - Running post-run listener: _resource_record_post_run
[task 2023-05-24T15:09:44.052Z] IO Completion Port unexpectedly closed
[task 2023-05-24T15:09:44.220Z] 15:09:44     INFO - Total resource usage - Wall time: 355s; CPU: 39%; Read bytes: 498739712; Write bytes: 1335302144; Read time: 134; Write time: 58
[task 2023-05-24T15:09:44.220Z] 15:09:44     INFO - TinderboxPrint: CPU usage<br/>39.4%
[task 2023-05-24T15:09:44.220Z] 15:09:44     INFO - TinderboxPrint: I/O read bytes / time<br/>498,739,712 / 134
[task 2023-05-24T15:09:44.220Z] 15:09:44     INFO - TinderboxPrint: I/O write bytes / time<br/>1,335,302,144 / 58
[task 2023-05-24T15:09:44.221Z] 15:09:44     INFO - TinderboxPrint: CPU idle<br/>1,721.2 (60.5%)
[task 2023-05-24T15:09:44.221Z] 15:09:44     INFO - TinderboxPrint: CPU system<br/>311.6 (11.0%)
[task 2023-05-24T15:09:44.221Z] 15:09:44     INFO - TinderboxPrint: CPU user<br/>806.5 (28.4%)
[task 2023-05-24T15:09:44.221Z] 15:09:44     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-05-24T15:09:44.222Z] 15:09:44     INFO - start-emulator - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-05-24T15:09:44.222Z] 15:09:44     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-05-24T15:09:44.222Z] 15:09:44     INFO - install - Wall time: 3s; CPU: 32%; Read bytes: 3562496; Write bytes: 47235072; Read time: 0; Write time: 1
[task 2023-05-24T15:09:44.225Z] 15:09:44     INFO - run-tests - Wall time: 353s; CPU: 40%; Read bytes: 494275072; Write bytes: 1258854400; Read time: 134; Write time: 56
[task 2023-05-24T15:09:44.298Z] 15:09:44  WARNING - returning nonzero exit status 2
[taskcluster 2023-05-24T15:09:44.862Z]    Exit Code: 2
[taskcluster 2023-05-24T15:09:44.862Z]    User Time: 0s
[taskcluster 2023-05-24T15:09:44.862Z]  Kernel Time: 15.625ms
[taskcluster 2023-05-24T15:09:44.862Z]    Wall Time: 11m59.418301s
[taskcluster 2023-05-24T15:09:44.862Z]       Result: FAILED
[taskcluster 2023-05-24T15:09:44.862Z] === Task Finished ===
[taskcluster 2023-05-24T15:09:44.862Z] Task Duration: 11m59.4231031s
[taskcluster 2023-05-24T15:09:45.188Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2024-05-23T14:16:56.146Z
[taskcluster 2023-05-24T15:09:45.637Z] Uploading artifact public/test_info/resource-usage.json from file build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-05-23T14:16:56.146Z
[taskcluster 2023-05-24T15:09:45.950Z] Uploading artifact public/test_info/wpt-test1_errorsummary.log from file build\blobber_upload_dir\wpt-test1_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2024-05-23T14:16:56.146Z
[taskcluster 2023-05-24T15:09:46.131Z] Uploading artifact public/test_info/wpt_instruments.txt from file build\blobber_upload_dir\wpt_instruments.txt with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2024-05-23T14:16:56.146Z
[taskcluster 2023-05-24T15:09:46.299Z] Uploading artifact public/test_info/wptreport.json from file build\blobber_upload_dir\wptreport.json with content encoding "gzip", mime type "application/json" and expiry 2024-05-23T14:16:56.146Z
[taskcluster 2023-05-24T15:09:46.486Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2024-05-23T14:16:56.146Z
[taskcluster:error] exit status 2

:surkov, since you are the author of the regressor, bug 1821732, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(surkov.alexander)

which changeset is guilty? I wonder if https://phabricator.services.mozilla.com/D178535 helps.

Flags: needinfo?(surkov.alexander)
You need to log in before you can comment on or make changes to this bug.