Humbug breaks on Symfony when test tries to boot a new kernel

frenetic commented 9 years ago

Using Symfony 2.6
Using Humbug from master branch

Some of my unit tests need to use the Symfony Container. For that, I have use the static::bootKernel(); from Symfony\Bundle\FrameworkBundle\Test\KernelTestCase. When running PhpUnit, it works fine. But, when using Humbug, I get the " tests must be fully passing" message.

I've been trying to identify why my tests fail, and I think the problem is here: https://github.com/symfony/symfony/blob/2.6/src/Symfony/Bundle/FrameworkBundle/Test/KernelTestCase.php#L44

It seems Humbug adapter isn't fully configuring Phpunit.

frenetic commented 9 years ago

My $_SERVER variable the moment before the exception being raised:

Array
(
    [PWD] => /vagrant/MyBundle
    [SHLVL] => 0
    [PHP_SELF] => -
    [SCRIPT_NAME] => -
    [SCRIPT_FILENAME] => 
    [PATH_TRANSLATED] => 
    [DOCUMENT_ROOT] => 
    [REQUEST_TIME_FLOAT] => 1424875379.022
    [REQUEST_TIME] => 1424875379
    [argv] => Array
        (
            [0] => -
        )

    [argc] => 1
    [KERNEL_DIR] => /Tests/Fixtures/app
)

rollenes commented 9 years ago

Humbug works running PhpProceses using php code generated by https://github.com/padraic/humbug/blob/master/src/Adapter/Phpunit/Job.php#L24 instead of executing phpunit executable. Each PhpProcess runs \PHPUnit_TextUI_Command directly and there is no additional $_SERVER parameters. That is why your $_SERVER['argv'] does not contain phpunit at index 0, and that is why humbug detects and error running initional test suite.

I got the same problem using KernelTestCase. To use humbug for mutation testing Kernel I had to rewrite those tests. I think that tests should not be dependent on configuration.

padraic commented 9 years ago

Is there any means of rectifying this within Humbug? It sounds like Humbug is not fully replicating the environment that phpunit would provide, so I would classify it as a Humbug bug if we can figure out the best solution.

A Humbugbug? Sorry. ;)

rollenes commented 9 years ago

I did some regression testing in this area to find the best solution. See: https://github.com/rollenes/humbug/compare/issue/server-argv

And first solution i kame up with is just replacing $_SERVER['argv'] variable while generating phpcode for process. See: https://github.com/rollenes/humbug/compare/issue/server-argv-first-solution But it is rather workaround then real solution.

padraic commented 9 years ago

We can probably live with it, I think.

rollenes commented 9 years ago

I found better solution, by replacing PhpProcess with Process. See: https://github.com/padraic/humbug/compare/master...rollenes:issue/server-argv-second-solution

One of problem is that user will have to give path to phpunit executable, or humbug will have to guess where phpunit executable is.

padraic commented 9 years ago

@rollenes Aren't we missing the $job script in there?

I may be missing where it aims, but we do need to use the Humbug specific PHPUnit version. It does away with guessing the executable, and it also does away with using older phpunit versions that were unreliable but still dependencies of certain projects. The remainder risk is running into test suites not patched for later phpunit BC breaks.

rollenes commented 9 years ago

With running phpunit executable as a separate process $job script is no longer needed. I left it there because Job::generate writes new humbug bootstrap on disk, and this is required to intercept mutant file. I left it there also because it is just proposal, so I didn`t want to modify more then is needed to share idea. With this solution humbug requires from phpunit and any other framework only to preserve behaviors like:

end with specified exit codes on failure(phpunit returns 1), and framework error(phpunit returns 2)
TAP output
filtering test suites
generate coverage report

All this behaviours are available from phpunit cli interface. I don`t know if other frameworks have those behaviours. If other frameworks behave like that, it means that humbug can easyly support other frameworks.

If framework changes cli interface that mens that user should run his test suites in other way. He also would have to update all his CI scripts. And this is no cost to change path to framework executable in configuration file(humbug.json). If framework changes its internals it also means that user have to rewrite his tests, and it generates costs. If I was this user I would back in project to previous framework version.

BC breaks in testing framework are very rare IMO. Also BC breaks are planned ahead of time. So if BC break comes humbug may support it even before its published.

As I wrote this is only proposal. I believe that it would open humbug to support other testing frameworks(with many versions) without deep analising framework internals.

padraic commented 9 years ago

@rollenes There are also phpunit bugs - certain versions fail to generate code coverage in the format Humbug consumes, for example, so relying on a user's (albeit outdated when it shouldn't be) version can be brittle. We could probably do some version checking or have a warning message for outdated phpunit versions - often the project simply hasn't switched up their minor version ref in composer.json.

Note: Not saying no to any changes, more than happy to see where this leads! A lot of early assumptions in building Humbug may not be perfect, and can be improved.

Main points I have:

Need to retain use of the XML configuration - we can't rely on the CLI too much since the stated policy of PHPUnit is not to improve it but add all new options to the XML conf.
Likely have a warning when the version of phpunit to be used is below a certain threshold.
Check for performance regressions. I believe we already had one over the past few weeks which I need to diagnose. When you hit up to 1000 mutations, it amplifies any slowdown quite a lot.
Reason out an approach for auto-detection, presumably vendor/bin/phpunit, then global, then look for phpunit.phar, and then request config to be completed? Not everyone will use same executable, even for same project. I probably need to do humbug.dist.json vs humbug.json so users can customise locally but keep a default copy in git.

rollenes commented 9 years ago

@padraic You are right with that testing frameworks has bugs. Note that code coverage is used only to speed up humbug analysis, and this is not major Humbug feature. If testing framework fails to generate code coverage I would expect Humbug to warn user that mutation analysis may take many more time then running it with code coverage properly generated. Version checking in this or similar situation is very good solution.

Xml configuration should be preserved. There is no doubt about it. But some features may be move away from XML to CLI with benefits. For example: Test suite filtering. It would eliminate regeneration of phpunit.humbug.xml file for each mutant. (Less I/O should speed up humbug a little) There is no way that phpunit or any other testing framework will stop support filtering tests from CLI interface.
Displaying message is not a problem. Problem is that which versions are supported. I would consider creating some project or use some existing project to analyze. Then run phpunit tests with required features(coverage, filtering...) for every available phpunit version. It would be starting point to know which version of phpunit may be supported, and which causes problems. The last part would be running humbug for each available version of phpunit to see what problems it may generate in humbug.
This part is difficult and very time consuming. But I believe that it can be done. It would require to run each humbug version/commit for each available version of phpunit and store execution times. Then run it several times and take some average time to compare with previous version. This would give perfect feedback of which change causes performance regression.
I see here an abstract auto-detect approach based on some kind of chain of "possibilities". First matched is running all suites. Dist is good solution for users running different versions.

padraic commented 9 years ago

Call me convinced - with the exception of the test filtering. It's not very obvious right now with the support limited to large grained test class ordering and a single test suite, but a bit of effort on the tests to clean up inter-test dependencies would allow various ordering strategies and those are just easier done via a TestListener (with or without proper extension support in PHPUnit). There is an IO cost, but it's not overly significant.

There's actually a performance regression (around 2.5-3x slower locally in some cases) in the mid to late Feb changes somewhere I noticed last week that I need to get around to figuring out... Note to self to monitor performance more closely on changes or have Travis do something in that regard that's reportable.

aledeg commented 9 years ago

I have the same problem using WebTestCase from Liip\FunctionalTestBundle.

I checked the bundle code and it uses also the Kernel.

I am using 3dcc344 version of humbug

padraic commented 9 years ago

@aledeg @frenetic Does the current master resolve your issues? The new approach runs phpunit more directly in a process and it should fix this issue, along with some others.

frenetic commented 9 years ago

Sorry for the delay. Im having a hard time to test it, since my project is unstable right now. Please, give me a few more days, so I can finish this sprint, make things stable, and have the time to play around with Humbug.

PS: thanks for the cool effort :)

aledeg commented 9 years ago

I updated the master today and I still have the issue. Is there something I can post to help you find why?

padraic commented 9 years ago

@aledeg Can you var_dump $_SERVER just prior to where the error occurs? Let's see what it actually contains at that point compared to what's needed. What I do need is something in a public repo or gist where I can reproduce this.

Note to self - need a debug flag around first run to view exceptions/errors ;). I assume it's just noting a failed run, a snippet of TAP output, and no actual error/exception details?

aledeg commented 9 years ago

@padraic do you mean in my test suite? Because I tried to put that in my test as the first line and nothing displays in the console.

Here is the output of the run:

 _  _            _
| || |_  _ _ __ | |__ _  _ __ _
| __ | || | '  \| '_ \ || / _` |
|_||_|\_,_|_|_|_|_.__/\_,_\__, |
                          |___/
Humbug version 1.0-dev

Humbug running test suite to generate logs and code coverage data...

    0 [>---------------------------------------------------------]  1 sec

Tests must be in a fully passing state before Humbug is run.
Incomplete, skipped or risky tests are allowed.
The testing framework reported an exit code of 1.
The testing framework ran into a failure or error. Refer to output below.
Stdout:
   > TAP version 13
   > not ok 1 - Error: \MyBundle\Tests\Controller\ApplicationControllerTest::testGetApplication_whenApplicationExists_returns200WithJsonContentAndLinkHeaders
   > 1..1
   >
   > Generating code coverage report in PHP format ...

aledeg commented 9 years ago

Here is the version I am using => facf91175e30d5f73d86f6f4f7c43915bfaadf00

padraic commented 9 years ago

@aledeg Yeah, it's an issue I need to solve. There needs to be a debug switch included in Humbug to get the underlying exception printed. What you can do locally, however, is comment out the following line: https://github.com/padraic/humbug/blob/master/src/Adapter/Phpunit.php#L64

That should result in output of some length containing the error details.

aledeg commented 9 years ago

@padraic I made the change in the Phpunit.php file.

I first got that error:

RuntimeException: Either set KERNEL_DIR in your phpunit.xml according to http://symfony.com/doc/current/book/testing.html#your-first-functional-test or override the WebTestCase::createKernel() method.

So I followed the documentation and I added the following code to my phpunit.xml dist file:

<php>
    <server name="KERNEL_DIR" value="../app" />
</php>

Now the process starts but I have a weird behavior. There is only one line displayed in the progress bar when there was more before adding the tests calling the Kernel. It also cannot find tests but says that the coverage is over 90%. And last, there is not a single mutation killed. Here is the output I got:

 _  _            _
| || |_  _ _ __ | |__ _  _ __ _
| __ | || | '  \| '_ \ || / _` |
|_||_|\_,_|_|_|_|_.__/\_,_\__, |
                          |___/
Humbug version 1.0-dev

Humbug running test suite to generate logs and code coverage data...

    0 [>---------------------------------------------------------]  1 sec

Humbug has completed the initial test run successfully.
Tests: 0 Line Coverage: 94.73%

Humbug is analysing source files...

Mutation Testing is commencing on 161 files...
(.: killed, M: escaped, S: uncovered, E: fatal error, T: timed out)

TTTTTTTTTTTSSSSSSSSSSSSSSSSSSSSSSSMEEEEEEEEMMMMMMMSSMMMMMMMM |   60 ( 34/161)
MMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMTMTMMMMMMMMMMMMMMMMMM |  120 ( 54/161)
MMMMMMEMMMMMMMMMMMMTMMTTTTEMMTTTTSTTTMMMMTMMMEMMMMMMMEMMMMMM |  180 ( 58/161)
TTTTMMMMSMTMSEEMETMSMSSSSSSSSSSSSTTMTMMMMTTTMMMMMMMMMMMMMTTT |  240 ( 71/161)
TTTTTTTTTTTTTT

  [Symfony\Component\Process\Exception\RuntimeException]
  Unable to kill the process

run [-a|--adapter="..."] [-o|--options="..."] [-f|--file="..."] [-c|--constraints="..."] [-t|--timeout="..."] [-b|--no-progress-bar] [-i|--incremental]

I hope it helps

padraic commented 9 years ago

@aledeg Did you reverse the change after fixing the KERNEL issue? The TAP output is what Humbug depends on for checking passes, test counts. It's just absolutely useless for getting detailed error/exception information hence the suggested temporary edit.

I'm a bit concerned about all the timeouts. The default time limit set for a test run is 10 seconds. If it's still an issue, and TAP is enabled (my suggested edit reversed), you might need to increase the timeout.

Very useful though! I'll look into a means of making that configuration change automatically when needed.

aledeg commented 9 years ago

@padraic I didn't reverse the change.

I run it again after reversing the change and changing the timeout to 30. The good news is that the process finished without raising exception. The bad news is I still have a lot of timeout. I'll dig into the log file later to find if there is something suspicious. I'll let you know.

Here is the new output:

 _  _            _
| || |_  _ _ __ | |__ _  _ __ _
| __ | || | '  \| '_ \ || / _` |
|_||_|\_,_|_|_|_|_.__/\_,_\__, |
                          |___/
Humbug version 1.0-dev

Humbug running test suite to generate logs and code coverage data...

    0 [>---------------------------------------------------------]  1 sec
   60 [-->-------------------------------------------------------] 7 mins
  120 [---->-----------------------------------------------------] 8 mins
  180 [------>---------------------------------------------------] 8 mins
  240 [-------->-------------------------------------------------] 8 mins
  300 [---------->-----------------------------------------------] 8 mins
  360 [------------>---------------------------------------------] 9 mins
  420 [-------------->-------------------------------------------] 9 mins
  480 [---------------->-----------------------------------------] 9 mins
  540 [------------------>---------------------------------------] 9 mins
  600 [-------------------->-------------------------------------] 9 mins
  660 [---------------------->-----------------------------------] 9 mins
  720 [------------------------>---------------------------------] 9 mins

Humbug has completed the initial test run successfully.
Tests: 708 Line Coverage: 94.69%

Humbug is analysing source files...

Mutation Testing is commencing on 162 files...
(.: killed, M: escaped, S: uncovered, E: fatal error, T: timed out)

TT.TT..TT.TSSSSSSSSSSSSSSSSSSSSSSS.EEEEEEEE.......SS........ |   60 ( 34/162)
.....M.................................T.T.................. |  120 ( 54/162)
......E............T..TTTTE..TTTTSTTT....T...E.......E...... |  180 ( 58/162)
TTTT..M.S.TMSEE.ETMSMSSSSSSSSSSSSTT.T....TTT.............TT. |  240 ( 71/162)
T.T.T.T.TTTT...TMMMMMMTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTT |  300 ( 80/162)
TTTTTTT..........................................M.SSS...... |  360 ( 90/162)
M.SSSSSSSSSS................................................ |  420 (148/162)
...SSSSSSSSSSSSSSSSSSSSSSSSSSSSS

452 mutations were generated:
     251 mutants were killed
      83 mutants were not covered by tests
      13 covered mutants were not detected
      15 fatal errors were encountered
      90 time outs were encountered

Metrics:
    Mutation Score Indicator (MSI): 79%
    Mutation Code Coverage: 82%
    Covered Code MSI: 96%

Remember that some mutants will inevitably be harmless (i.e. false positives).

Time: 1.09 hours Memory: 95.00MB
Humbug results are being logged as TEXT to: app/logs/humbug.log

humbug / humbug

Humbug breaks on Symfony when test tries to boot a new kernel #109