Improve error & debug messages for Codeception early exit

[andronocean]

This provides a better debug message and error log when Codeception's ErrorHandler exits early with COMMAND DID NOT FINISH PROPERLY. (This is the improvement I mentioned in #753 ... better late than never!)

Background:

There are a lot of ways execution can stop before WordPress has fully loaded through /wp-load.php. LoadSandbox already tries to address some of these specifically in the obCallback method — like a missing database, a plugin throwing an uncaught exception. Another scenario is when a call to exit() occurs without an uncaught exception or error. In that situation, Codeception runs its \Codeception\Subscriber\ErrorHandler->shutdownHandler() method (source code). That method echoes COMMAND DID NOT FINISH PROPERLY. and then exit(125).

Wp-browser's behavior in this situation has been to shutdown silently on the command line, and log a rather unhelpful message: WordPress failed to load for the following reason: cOMMAND DID NOT FINISH PROPERLY. This leads to rather arduous step-by-step debugging to track down the source.

(In case it helps anyone who finds this or can spur further improvement: my own impetus for fixing this was trying to use wp-browser on a site using the Acorn framework from Roots, which adds its own WP-CLI commands. Its logic checks whether it is running in the console, which is true during codecept run, and then improperly tries to resolve and handle the run command. When it cannot find its own matching command, it exits and thereby triggers Codeception's shutdown handler.)

What I've done:

This adds a condition to the LoadSandbox::obCallback method to check for the Codeception shutdown output. If the output is found, a more specific exception message is thrown, and a clearer message printed to the console when codecept run is used with the --debug option.

I've tried to add a unit test for the new behavior, but I confess that I'm stuck: the test output shows the functionality is working correctly, but the exception is not getting properly caught by PhpUnit. It's a tricky thing to test. I modeled it after some of the existing tests in that class, but I think there's something about the LoopIsolation->assertInIsolation() method they use that I don't understand. Feedback would be welcomed, or the test can be taken out if it's unneeded.

Alternatives or possibilities

LoadSandbox->load() already sets its own error handler and wp_die handler. Maybe it could go further and register a shutdown handler as well to handle the process more cleanly? Given the difficulty of tracing exits, keeping track internally of which actions are reached in the WP loading lifecycle and printing that in debug logs could also be very helpful.

I'm also wondering if it would be appropriate for LoadSandbox to set the APP_RUNNING_IN_CONSOLE environment variable to false during the sandbox installation. This was how I resolved the problem with Acorn in my own code. Laravel (and thus Acorn and its packages) uses this to control routing to CLI or HTTP handlers. It's a bit implementation-specific, but it could save someone else some trouble.

[lucatume]

Thanks @andronocean for the pull request and the research.

Maybe it could go further and register a shutdown handler as well to handle the process more cleanly?

I had tried that and the issue I ran it is that there is no way to control the priority of registered shutdown handlers. Due to the nature of wp-browser, an extension of Codeception and not a wrapper around it, any shutdown handler registered by wp-browser would fire after the Codeception one. Since the Codeception shutdown handler exits, no other shutdown handler will fire. Consistently registering a shutdown handler before Codeception proved to be inconsistent last time I tried.

I'm also wondering if it would be appropriate for LoadSandbox to set the APP_RUNNING_IN_CONSOLE environment variable to false during the sandbox installation. This was how I resolved the problem with Acorn in my own code. Laravel (and thus Acorn and its packages) uses this to control routing to CLI or HTTP handlers. It's a bit implementation-specific, but it could save someone else some trouble.

I think your use case here, using Acorn and Laravel, is particular enough that it would not make sense to add this in wp-browser. One can easily set this in the project confiuguration, e.g. by loading an env file from the codeception.yml file. In my experience I've seen different parts and packages of Laravel applications wrapping WordPress, or being used by it, to think of setups where setting that env var would break things.

I've tried to add a unit test for the new behavior, but I confess that I'm stuck: the test output shows the functionality is working correctly, but the exception is not getting properly caught by PhpUnit. It's a tricky thing to test. I modeled it after some of the existing tests in that class, but I think there's something about the LoopIsolation->assertInIsolation() method they use that I don't understand. Feedback would be welcomed, or the test can be taken out if it's unneeded.

I've pushed code that should address the test and have changed the wording a bit to be more general.
Other commands, e..g the console one, will run through the same code as the run command and will fail in the same locations.
I've also moved the output all to the exception to make sure it will always be visible: output from the codecept_debug command will only be visible if the user is running the command with the --debug flag.

[andronocean]

That all makes sense, @lucatume. Thank you for fixing up the test! I agree about the APP_RUNNING_IN_CONSOLE config — much better to handle that within the final customer's project.

I've also moved the output all to the exception to make sure it will always be visible

I'd have done that too, only there's no guarantee that the exception message will be printed to STDOUT. When Acorn tries and fails to handle the run command, for instance, it prints its own formatted error and suppresses other messages, so all I can see is this:

I added the codecept_debug calls so there would at least be some info displayed if a user tries running with --debug or -vv. codecept_debug somehow gets around what Acorn does with symfony/console — I'm guessing Codeception uses a separate buffer. If you don't like it I have no problem leaving it out.

[lucatume]

I added the codecept_debug calls so there would at least be some info displayed if a user tries running with --debug or -vv. codecept_debug somehow gets around what Acorn does with symfony/console — I'm guessing Codeception uses a separate buffer. If you don't like it I have no problem leaving it out.

Thank you for the clarification, that was the part that I was missing.

[lucatume]

Thank you @andronocean for the contribution. This will go out in the next release.

[lucatume]

https://github.com/lucatume/wp-browser/releases/tag/4.3.5