Open Bug 1892364 Opened 10 months ago Updated 5 months ago

Capture screenshots on crashtest test-failures (including test timeouts) like we do for mochitest test-failures

Categories

(Testing :: Reftest, defect)

defect

Tracking

(Not tracked)

People

(Reporter: dholbert, Unassigned)

References

Details

We capture full-screen screenshots for mochitest failures on TreeHerder (e.g. here and here), with the screenshots linked at the top, named something like mozilla-test-fail-screenshot_0ex3l1pn.png.

However, we don't seem to do that for crashtest test-failures (specifically test-timeouts, which is what I'm really interested in, per below, but I think that's just a special case of test-failure). E.g. this one doesn't have any PNG link at the top:
https://treeherder.mozilla.org/logviewer?job_id=455034902&repo=try&lineNumber=18705

Could we please add that functionality?

(motivation: I'm investigating an intermittent timeout in a new test right now that looks suspiciously like the system might somehow be stealing focus[1] from the Firefox crashtest-harness window, and it would be great to be able to confirm or refute that hypothesis with a screenshot taken right at the moment the harness decides the test has timed out.)

Flags: needinfo?(jmaher)
Summary: Capture screenshots on crashtest test-timeouts → Capture screenshots on crashtest test-failures (including test timeouts) like we do for mochitest test-failurs
Summary: Capture screenshots on crashtest test-failures (including test timeouts) like we do for mochitest test-failurs → Capture screenshots on crashtest test-failures (including test timeouts) like we do for mochitest test-failures
Component: General → Reftest
Product: Release Engineering → Testing
QA Contact: jlorenzo

Do we fail to take a screenshot because the internal reftest harness hits its timeout for the test before the timeout detection that happens at a higher level is able to kick in?

I think to test this hypothesis one could modify the timeout here

https://searchfox.org/mozilla-central/rev/47db1be98f8069b387ce07dcbea22d09f1854515/layout/tools/reftest/reftest-content.js#148

to make it really long and see.

This of course would be a one time solution in a try push type of thing that could solve it for you but not in general. I'm not sure where the system level screenshots are taken.

Another option would be to modify the reftest harness code to trigger the internal reftest harness snapshot logic in the case of a timeout, that would show you the state of the firefox window and might be enough to determine if focus was lost.

(In reply to Daniel Holbert [:dholbert] from comment #0)

(motivation: I'm investigating an intermittent timeout in a new test right now that looks suspiciously like the system might somehow be stealing focus[1] from the Firefox crashtest-harness window, and it would be great to be able to confirm or refute that hypothesis with a screenshot taken right at the moment the harness decides the test has timed out.)

off-topic, but just for the record: for the particular thing I'm debugging right now, I'm now pretty sure it's bug 1864255.

I was able to force a screenshot to be taken when my crashtest timed out, by adding an infinite loop -- while (true) { /* Loop forever, muahaha */ } -- between these last two lines in LoadFailed(why):
https://searchfox.org/mozilla-central/rev/8c3ca2f5a74e0ba59c3d9dddf5468a2ffab13467/layout/tools/reftest/reftest.sys.mjs#1553,1572-1573

function LoadFailed(why) {
...
  FlushTestBuffer();
  FinishTestItem();

That stops the test harness from advancing to the next test, at the moment that things went wrong; and it trips the harness's application timed out after 370 seconds with no output timeout, which causes a screenshot to be captured as in e.g. this log.

And that screenshot shows an about:blank popup that's occluding the test harness, which I think was spawned by earlier crashtest 1419902.html, per bug 1864255 comment 19.

In a perfect world, we would automatically capture a screenshot like that one whenever we hit REFTEST TEST-UNEXPECTED-FAIL | [path/to/some/reftest/or/crashtest.html] | load failed: timed out waiting for reftest-wait to be removed -- hence this bug here.

(In reply to Timothy Nikkel (:tnikkel) from comment #1)

Do we fail to take a screenshot because the internal reftest harness hits its timeout for the test before the timeout detection that happens at a higher level is able to kick in?

So right now, we don't attempt to take a screenshot when the test times out, afaict. We only attempt to take a screenshot when the whole harness times out.

The relevant python files are here, I think:
https://searchfox.org/mozilla-central/rev/8c3ca2f5a74e0ba59c3d9dddf5468a2ffab13467/layout/tools/reftest/runreftest.py
https://searchfox.org/mozilla-central/rev/8c3ca2f5a74e0ba59c3d9dddf5468a2ffab13467/layout/tools/reftest/output.py

from mozscreenshot import dump_screen is the relevant API to take a screenshot, and we only call that in one set of circumstances that I'm seeing: handleTimeout --> killAndGetStack --> dumpScreen --> dump_screen in runreftest.py. Here, handleTimeout is referring to the harness-as-a-whole timing out, as with application timed out after 370 seconds with no output as noted in previous comment.

I think to test this hypothesis one could modify the timeout here

https://searchfox.org/mozilla-central/rev/47db1be98f8069b387ce07dcbea22d09f1854515/layout/tools/reftest/reftest-content.js#148

to make it really long and see.

That looks right; that probably has the same effect as the infinite loop approach that I used, i.e. forcing us to halt progress when a test times out, and let the harness declare a timeout.

Another option would be to modify the reftest harness code to trigger the internal reftest harness snapshot logic in the case of a timeout, that would show you the state of the firefox window and might be enough to determine if focus was lost.

I suspect it's just-as-easy to get a full-screen screenshot, given that we have this python API for it already. It's probably easiest and most-useful (and most consistent with mochitests and whole-harness-timeouts) to just use that same sort of screenshot.

See Also: → 1856368

so this isn't as simple as it should be (or I am missing the obvious). For mochitest we do screenshots in python, this typically happens when we are parsing the log (output from the in-browser JS harness) and determine a screenshot is needed.

For reftest harness, we capture the pixels of the drawwindow and present those as a base64 encoded string to compare. For crashtest, this is run via the same harness, so plumbing in screen capture will be a bit of work, likewise adjusting the python side to detect failures from the browser by reading the logs will not be as simple as calling an api.

Flags: needinfo?(jmaher)

(In reply to Joel Maher ( :jmaher ) (UTC -8) from comment #4)

so this isn't as simple as it should be (or I am missing the obvious). For mochitest we do screenshots in python, this typically happens when we are parsing the log (output from the in-browser JS harness) and determine a screenshot is needed.

For reftest harness, we capture the pixels of the drawwindow and present those as a base64 encoded string to compare. For crashtest, this is run via the same harness, so plumbing in screen capture will be a bit of work, likewise adjusting the python side to detect failures from the browser by reading the logs will not be as simple as calling an api.

Note that we do have full-screen capture already happening for reftest/crashtest, when the harness is considered to have timed out. See comment 2 for one way that I was able to force that to happen.

(Having said that, it's entirely possible that this full-screen-capture API isn't easily reachable at the point where we judge individual tests to time out. But if it's possible to make it available somehow, that would be super-great for diagnosing unexpected test timeouts -- in crashtests as well as reftests, actually.)

The severity field is not set for this bug.
:tnikkel, could you have a look please?

For more information, please visit BugBot documentation.

Flags: needinfo?(tnikkel)
Severity: -- → S3
Flags: needinfo?(tnikkel)
See Also: → 1914308
You need to log in before you can comment on or make changes to this bug.