Print a more useful error message if any PHPUnit tests crash
ClosedPublic
Actions

Authored by Firehed on Dec 27 2013, 9:45 PM.

Details

Reviewers

epriestley

Group Reviewers

Blessed Reviewers

Commits

rARC739881a3f402: Print a more useful error message if any PHPUnit tests crash

Summary

Before, if PHPUnit crashed (syntax error, undefined constant, etc), you would get a relatively unhelpful error message:

firehed@Eric-Sterns-Mac-Pro ~/dev/php-lcd: arc unit
Exception
Clover coverage XML report file is empty, it probably means that phpunit failed to run tests. Try running arc unit with --trace option and then run generated phpunit command yourself, you might get the answer.
(Run with --trace for a full exception trace.)

This now checks the json and code coverage reports and tries to pull a useful error message:

firehed@Eric-Sterns-Mac-Pro ~/dev/php-lcd: arc unit
Exception
The test '/Users/firehed/dev/php-lcd/tests/PlateButtonsTest.php' crashed with the following output:

Fatal error: Undefined class constant 'EFT' in /Users/firehed/dev/php-lcd/tests/PlateButtonsTest.php on line 25

Call Stack:
	0.0002     233104   1. {main}() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:0
	0.0039     564872   2. PHPUnit_TextUI_Command::main() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:63
	0.0039     565496   3. PHPUnit_TextUI_Command->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:129
	0.0247    2280168   4. PHPUnit_TextUI_TestRunner->doRun() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:176
	0.0293    2730760   5. PHPUnit_Framework_TestSuite->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/TestRunner.php:349
	0.1211    3996832   6. PHPUnit_Framework_TestSuite->runTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestSuite.php:745
	0.1211    3996832   7. PHPUnit_Framework_TestCase->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestSuite.php:775
	0.1211    3996832   8. PHPUnit_Framework_TestResult->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:783
	0.1233    3999752   9. PHPUnit_Framework_TestCase->runBare() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestResult.php:648
	0.1236    4016432  10. PHPUnit_Framework_TestCase->runTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:838
	0.1237    4017240  11. ReflectionMethod->invokeArgs() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:983
	0.1237    4017520  12. Firehed\PlateButtonsTest->testSingleButtonOnButtonDown() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:983


(Run with --trace for a full exception trace.)

Or if nothing was written to stderr, you may get something like this:

firehed@Eric-Sterns-Mac-Pro ~/dev/php-lcd: arc unit --no-coverage
Exception
Test Firehed\PlateButtonsTest::testSingleButtonOnButtonDown did not finish
(Run with --trace for a full exception trace.)

Test Plan

arc unit for arcanist itself
arc unit before and after the change on a project where:

all tests pass
some tests are failing
a test causes a fatal error (undefined constant, bad method call, etc)
a test file is invalid (syntax error)

No regressions that I could find, and all crashes now display a more useful error.

Diff Detail

Lint

Lint Skipped

Unit

Tests Skipped

Event Timeline

Ideally, we should cascade these into ArcanistUnitTestResult::RESULT_BROKEN test results but complete the test run (i.e., return a mixture of normal and and broken $results). Is that practical? The RESULT_BROKEN constant means "the test exploded/crashed/fataled", and is more useful than an exception since we can aggregate it in Harbormaster soon, e.g.

I like the concept, not sure how it will pan out. Both syntax errors and a fatal error inside a test will stop the rest of the file from running so it's still likely to lose _some_ information. There's no suite-level information so the name will have to get fudged a bit, but I think it's sufficient to get the point across.

Related, what's the difference between broken and unsound, and is postponed actually used? I don't see anything actually setting a single test result to postponed (and therefore it won't ever cascade to the overall result); looking a little closer, that also seems to hold true for the linter which also has a RESULT_POSTPONED but nothing really using it. Not sure if a) it's legacy, b) it's an impending feature, or c) I'm missing something. Happy to lend a hand wherever.

Facebook uses POSTPONED, but does so in a hacky mess of a way. I hope to get rid of it. It indicates a test (or lint result) which will be run asynchronously, but no part of the implementation makes much sense. It is not normally possible to generate it (Facebook has custom code which does, and then a tangled mess of garbage after that). Generally, I think marking named tests as POSTPONED isn't very desirable and I believe the entire mechanism can be removed once Harbormaster is slightly further along.
UNSOUND indicates a failing test which is also failing in CI. The idea is "this test failed, but it's probably not your fault, since evidence points to someone else having broken it". The mechanism here is for arc unit to check CI for failing tests, then downgrade them to UNSOUND if they're failing at HEAD/the base revision. There's currently no code in Arcanist to do this, although it shouldn't be much of a stretch to add it once Harbormaster is online. In theory, this downgrade should be able to happen automatically.
BROKEN indicates a test which has failed abnormally. This could downgrade to UNSOUND as well.

I think it's OK to return BROKEN with a best-effort test name, and it's more desirable to return BROKEN even with a totally generic name ("PHPUnit Tests") than to raise an exception. For example, once Harbormaster can CI arc unit, it will be able to interpret BROKEN + generic name, but unable to meaningfully distinguish between different types of exception, at least in the general case.

Updates per @epriestley's suggestion: return broken results if a file dies, and print as much information as possible.

remove unused variable
allow test engine to pass result of stderr to result parser
pass stderr to PhpunitResultParser
simplify 'last test did not finish' logic, and return a 'broken' result instead
if there was no json report, treat the entire file as broken
an empty coverage file should return no coverage, not throw an exception
revert to original exception non-handling, as all expected cases should now return a broken result correctly

Latest output from various dying tests. Top one is a broken test file, middle one is a valid test file that fatals on the first test, last one is a valid test that fatals after several tests have run.

I think there's enough information in the json reports to indicate how many tests did not run (though not which ones), but I'm not doing anything with it right now. Probably better to not overcomplicate it.

firehed@Eric-Sterns-Mac-Pro ~/dev/php-lcd: arc unit
   BROKEN  /Users/firehed/dev/php-lcd/tests/HD44780Test.php

Parse error: syntax error, unexpected 'Firehed' (T_STRING) in /Users/firehed/dev/php-lcd/tests/HD44780Test.php on line 3

Call Stack:
    0.0002     233104   1. {main}() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:0
    0.0039     564872   2. PHPUnit_TextUI_Command::main() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:63
    0.0039     565496   3. PHPUnit_TextUI_Command->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:129
    0.0100    1135432   4. PHPUnit_Runner_BaseTestRunner->getTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:150
    0.0100    1135504   5. PHPUnit_Runner_BaseTestRunner->loadSuiteClass() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Runner/BaseTestRunner.php:104
    0.0103    1159392   6. PHPUnit_Runner_StandardTestSuiteLoader->load() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Runner/BaseTestRunner.php:168
    0.0108    1232960   7. PHPUnit_Util_Fileloader::checkAndLoad() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Runner/StandardTestSuiteLoader.php:77
    0.0108    1233080   8. PHPUnit_Util_Fileloader::load() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Util/Fileloader.php:76


   BROKEN  Firehed\PlateButtonsTest::testSingleButtonOnButtonDown

Parse error: syntax error, unexpected 'rivate' (T_STRING), expecting function (T_FUNCTION) in /Users/firehed/dev/php-lcd/PlateButtons.php on line 7

Call Stack:
    0.0003     233104   1. {main}() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:0
    0.0043     564872   2. PHPUnit_TextUI_Command::main() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:63
    0.0043     565496   3. PHPUnit_TextUI_Command->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:129
    0.0257    2277576   4. PHPUnit_TextUI_TestRunner->doRun() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:176
    0.0305    2728056   5. PHPUnit_Framework_TestSuite->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/TestRunner.php:349
    0.0309    2740264   6. PHPUnit_Framework_TestSuite->runTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestSuite.php:745
    0.0309    2740944   7. PHPUnit_Framework_TestCase->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestSuite.php:775
    0.0310    2742416   8. PHPUnit_Framework_TestResult->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:783
    0.0382    2802376   9. PHPUnit_Framework_TestCase->runBare() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestResult.php:648
    0.0386    2820840  10. PHPUnit_Framework_TestCase->runTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:838
    0.0386    2821648  11. ReflectionMethod->invokeArgs() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:983
    0.0386    2821928  12. Firehed\PlateButtonsTest->testSingleButtonOnButtonDown() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:983
    0.0443    3098536  13. spl_autoload_call() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:18
    0.0443    3098576  14. Composer\Autoload\ClassLoader->loadClass() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:0


   PASS   17ms★  Firehed\BacklightTest::testConstructRegistersDevice
   PASS    2ms★  Firehed\BacklightTest::testGetUsedPins
   PASS    8ms★  Firehed\BacklightTest::testBacklight with data set #0
   PASS    7ms★  Firehed\BacklightTest::testBacklight with data set #1
   BROKEN  Firehed\BacklightTest::testDies

Fatal error: Class 'Firehed\X' not found in /Users/firehed/dev/php-lcd/tests/BacklightTest.php on line 53

Call Stack:
    0.0003     233104   1. {main}() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:0
    0.0041     564872   2. PHPUnit_TextUI_Command::main() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/composer/bin/phpunit:63
    0.0041     565496   3. PHPUnit_TextUI_Command->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:129
    0.0269    2371248   4. PHPUnit_TextUI_TestRunner->doRun() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/Command.php:176
    0.0317    2821752   5. PHPUnit_Framework_TestSuite->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/TextUI/TestRunner.php:349
    0.1335    4392024   6. PHPUnit_Framework_TestSuite->runTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestSuite.php:745
    0.1335    4392024   7. PHPUnit_Framework_TestCase->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestSuite.php:775
    0.1335    4392024   8. PHPUnit_Framework_TestResult->run() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:783
    0.1338    4394968   9. PHPUnit_Framework_TestCase->runBare() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestResult.php:648
    0.1341    4411736  10. PHPUnit_Framework_TestCase->runTest() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:838
    0.1341    4412512  11. ReflectionMethod->invokeArgs() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:983
    0.1341    4412576  12. Firehed\BacklightTest->testDies() /Users/firehed/dev/php-lcd/vendor/phpunit/phpunit/PHPUnit/Framework/TestCase.php:983