Test failures not reported in test run

[BruceForstall]

I found a case where a test failure is not reported in the CoreCLR test run.

See the log file here:

https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-heads-main-abd91328c2f94763aa/HardwareIntrinsics_General_ro/1/console.b75ffbb8.log?helixlogtype=result

This is the console log for the HardwareIntrinsics_General_ro test run for win-x64 pri-1 outerloop run

https://dev.azure.com/dnceng-public/public/_build/results?buildId=243871&view=logs&j=bc936583-455b-59a6-ba6a-b6595d929238&t=deb3df3a-0bd3-5b15-90c9-d170d4bd5993

specifically, for DOTNET_TieredCompilation=0

Note the bottom of the log file:

11:03:55.549 Running test: _Vector512_1_ro::JIT.HardwareIntrinsics.General._Vector512_1.Program.GetAndWithLowerAndUpperByte()
Beginning scenario: RunBasicScenario
Fatal error. System.Runtime.InteropServices.SEHException (0x80004005): External component has thrown an exception.
   at JIT.HardwareIntrinsics.General._Vector512_1.VectorGetAndWithLowerAndUpper__GetAndWithLowerAndUpperByte.RunBasicScenario()
   at JIT.HardwareIntrinsics.General._Vector512_1.Program.GetAndWithLowerAndUpperByte()
   at Program.<<Main>$>g__TestExecutor26|0_25(System.IO.StreamWriter, System.IO.StreamWriter, <>c__DisplayClass0_0 ByRef)
   at Program.<Main>$(System.String[])
App Exit Code: -1073741795
Expected: 100
Actual: -1073741795
END EXECUTION - FAILED
FAILED
[XUnitLogChecker]: Item 'HardwareIntrinsics_General_ro' did not finish running. Checking and fixing the log...
[XUnitLogChecker]: XUnit log file has been fixed!

1259/2363 tests run.
* 1259 tests passed.
* 0 tests failed.
* 0 tests skipped.

[XUnitLogChecker]: Checking for dumps...
[XUnitLogChecker]: No crash dumps found. Continuing...
[XUnitLogChecker]: Finished!
ERROR: The process "corerun.exe" not found.
2023-04-19T11:03:58.485Z	INFO   	run.py	run(48)	main	Beginning reading of test results.
2023-04-19T11:03:58.485Z	INFO   	run.py	__init__(42)	read_results	Searching 'C:\h\w\B51E0A11\w\AD88096E\e' for test results files
2023-04-19T11:03:58.485Z	INFO   	run.py	__init__(48)	read_results	Found results file C:\h\w\B51E0A11\w\AD88096E\e\JIT\HardwareIntrinsics\HardwareIntrinsics_General_ro\HardwareIntrinsics_General_ro.testResults.xml with format xunit
2023-04-19T11:03:58.501Z	INFO   	run.py	__init__(42)	read_results	Searching 'C:\h\w\B51E0A11\w\AD88096E\uploads' for test results files
2023-04-19T11:03:58.501Z	INFO   	run.py	packing_test_reporter(30)	report_results	Packing 1259 test reports to 'C:\h\w\B51E0A11\w\AD88096E\e\__test_report.json'
2023-04-19T11:03:58.501Z	INFO   	run.py	packing_test_reporter(33)	report_results	Packed 281920 bytes
['HardwareIntrinsics_General_ro' END OF WORK ITEM LOG: Command exited with 0]

The test crashed, the exit code was non-100, and the wrapper script reported FAILED.

Then, XUnitLogChecker comes along, fixes the log, prints out that only a subset of the expected tests were run, and returns success. Thus, the work item is marked as succeeding, and AzDO UI does not show it as a failure.

Found when investigating #84967

@ivdiazsa @trylek
cc @hoyosjs

[ghost]

Tagging subscribers to this area: @hoyosjs
See info in area-owners.md if you want to be subscribed.

Issue Details

---

I found a case where a test failure is not reported in the CoreCLR test run.

See the log file here:

https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-heads-main-abd91328c2f94763aa/HardwareIntrinsics_General_ro/1/console.b75ffbb8.log?helixlogtype=result

This is the console log for the HardwareIntrinsics_General_ro test run for win-x64 pri-1 outerloop run

https://dev.azure.com/dnceng-public/public/_build/results?buildId=243871&view=logs&j=bc936583-455b-59a6-ba6a-b6595d929238&t=deb3df3a-0bd3-5b15-90c9-d170d4bd5993

specifically, for DOTNET_TieredCompilation=0

Note the bottom of the log file:

11:03:55.549 Running test: _Vector512_1_ro::JIT.HardwareIntrinsics.General._Vector512_1.Program.GetAndWithLowerAndUpperByte()
Beginning scenario: RunBasicScenario
Fatal error. System.Runtime.InteropServices.SEHException (0x80004005): External component has thrown an exception.
   at JIT.HardwareIntrinsics.General._Vector512_1.VectorGetAndWithLowerAndUpper__GetAndWithLowerAndUpperByte.RunBasicScenario()
   at JIT.HardwareIntrinsics.General._Vector512_1.Program.GetAndWithLowerAndUpperByte()
   at Program.<<Main>$>g__TestExecutor26|0_25(System.IO.StreamWriter, System.IO.StreamWriter, <>c__DisplayClass0_0 ByRef)
   at Program.<Main>$(System.String[])
App Exit Code: -1073741795
Expected: 100
Actual: -1073741795
END EXECUTION - FAILED
FAILED
[XUnitLogChecker]: Item 'HardwareIntrinsics_General_ro' did not finish running. Checking and fixing the log...
[XUnitLogChecker]: XUnit log file has been fixed!

1259/2363 tests run.
* 1259 tests passed.
* 0 tests failed.
* 0 tests skipped.

[XUnitLogChecker]: Checking for dumps...
[XUnitLogChecker]: No crash dumps found. Continuing...
[XUnitLogChecker]: Finished!
ERROR: The process "corerun.exe" not found.
2023-04-19T11:03:58.485Z	INFO   	run.py	run(48)	main	Beginning reading of test results.
2023-04-19T11:03:58.485Z	INFO   	run.py	__init__(42)	read_results	Searching 'C:\h\w\B51E0A11\w\AD88096E\e' for test results files
2023-04-19T11:03:58.485Z	INFO   	run.py	__init__(48)	read_results	Found results file C:\h\w\B51E0A11\w\AD88096E\e\JIT\HardwareIntrinsics\HardwareIntrinsics_General_ro\HardwareIntrinsics_General_ro.testResults.xml with format xunit
2023-04-19T11:03:58.501Z	INFO   	run.py	__init__(42)	read_results	Searching 'C:\h\w\B51E0A11\w\AD88096E\uploads' for test results files
2023-04-19T11:03:58.501Z	INFO   	run.py	packing_test_reporter(30)	report_results	Packing 1259 test reports to 'C:\h\w\B51E0A11\w\AD88096E\e\__test_report.json'
2023-04-19T11:03:58.501Z	INFO   	run.py	packing_test_reporter(33)	report_results	Packed 281920 bytes
['HardwareIntrinsics_General_ro' END OF WORK ITEM LOG: Command exited with 0]

The test crashed, the exit code was non-100, and the wrapper script reported FAILED.

Then, XUnitLogChecker comes along, fixes the log, prints out that only a subset of the expected tests were run, and returns success. Thus, the work item is marked as succeeding, and AzDO UI does not show it as a failure.

Found when investigating #84967

@ivdiazsa @trylek
cc @hoyosjs

Author:	BruceForstall
Assignees:	ivdiazsa
Labels:	area-Infrastructure-coreclr, blocking-outerloop
Milestone:	8.0.0

[ivdiazsa]

Mmmm I think I know what's going on here. It seems like the script is forgetting about the test exit code and only keeping the log checker's one. This is indeed a bug that we have to fix. I'm already working on another bug in this area so I'll try to incorporate it with this one.