Fix and improve the reporting of errors from timeouts and crashes

[nickrobinson251]

1. Fix the recording of timeouts and worker crashes, so that every attempt is recorded
   • previously, we would only record an error if on timeout/crash if it was the last attempt, and so that testitem had failed overall. this means that for a testitem that timedout/crashed then passed on retry, there would be no record of the timeout/crash in the generated XML report
   • now all attempts, including timeout/crash, are recorded
   • To fix this, i refactored the code for handling retries so that it was separated from the code that handles the recording of an error, to reduce the paths through the code and ensure recording only needs to be handled in one place, independent of if we're retrying.
   • The reporting is tested using reference tests, so please review the new additions in the committed test/reference/ JUnit XML reports
   • hopefully this fixes https://relationalai.atlassian.net/browse/RAI-13829
2. Improve the error message reported for a timeout or worker crash
   • Previously, we would log (to stderr) a timeout or worker crash, but the test error we recorded (and which would appear in the XML report) just said "test item \"foo\" didn't succeed"
   • now it says either "Worker aborted evaluating test item \"foo\"" or "Timed out after XmYs evaluating test item \"foo\""
   • fix https://relationalai.atlassian.net/browse/RAI-13675

[nickrobinson251]

writing tests for timeouts is pretty tricky

i added tests to test/testfiles/_retry_tests.jl, but have to rely on writing out files to disk for tracking how many times we've run

[nickrobinson251]

since timeouts are not supported with nworkers=0 (#87), the "timeout tests" both run once and pass once (hence we have the addition here of an entry each for testcase name="Timeout always" and testcase name="Timeout first, pass after")

[nickrobinson251]

All 3 runs of Timeout always should be here, i.e. there should be 3 <testcase name="Timeout always" entries

[nickrobinson251]

there should be 2 <testcase name="Timeout first, pass after" (one timeout, then one pass)

[quinnj]

where do we print the error? It seems we previously had a block that was removed above that did println(DEFAULT_STDOUT[]). were we double printing?

[nickrobinson251]

we had

            if !(e isa TestSetFailure)
                println(DEFAULT_STDOUT[])
                # Explicitly show captured logs or say there weren't any in case we're about
                # to terminte the worker
                _print_captured_logs(DEFAULT_STDOUT[], testitem, nretries + 1)
            end

but that moved into the if e isa TimeoutException block (since it doesn't actually apply in the worker crash case i don't think? but maybe it should be in that branch too?)

            if e isa TimeoutException
                @debugv 1 "Test item $(repr(testitem.name)) timed out. Terminating worker $worker"
                # Explicitly show captured logs or say there weren't any before terminating worker
                println(DEFAULT_STDOUT[])
                _print_captured_logs(DEFAULT_STDOUT[], testitem, run_number)
                terminate!(worker)
                wait(worker)
                ...

For the e isa TestSetFailure case, we only go to this whole catch block when we call throw_if_failed, and we have already called print_errors_and_captured_logs before that
Does this addition to the comment help?

Suggested change

	# We already printed the error and recorded the testset.
	# We already printed the error and recorded the testset before calling `throw_if_failed`.

[quinnj]

I think we still want to try and print in the worker crash case, right @Drvi? like, ideally we get the segfault backtrace printed

[nickrobinson251]

ah yeah, makes sense -- i was misled by the in case we're about to terminate the worker comment, which i thought meant these logs wouldn't exist if the worker had already terminated, but that's not the case (idk what that comment was meaning to say)

[nickrobinson251]

okay, did a little refactor again so that everything related to the simple test failures is handled above, rather than purposefully throwing and then handling some stuff down here

[Drvi]

in case we're about to terminate the worker

I don't remember, but I think that at some point we just wanted to be extra sure we didn't lose any logs from dead workers, so we explicitly print "No Captured Logs" to signal that the reporting process didn't fail.

[quinnj]

LGTM; merge away!

[quinnj]

Overall great cleanup. I left one question that I wasn't sure I followed.