Make dump() output in tests no longer use standard streams

Hi @mondrake
Any reason for postpone of issue,

In this issue for PHPUnit 10+, see if we can adopt a different technique instead of using standard streams.

Looking for different technique, will be good if the status is Active. Any Thoughts on this.

@dineshkumarbollu see #3432171-14: dump() no longer produces output in PHPUnit tests running under PHP 8.3 → for the reason.

The parent was committed but not sure there is anything worth fixing here, I think stderr is a fine place to put debugging information during tests.

My idea: during the test execution, make TestVarDumper store the dump strings in an array instead of outputting it (so we do not pollute SUT output with output).

Then, after test end (or testrunner end), subscribe to PHPUnit events and print the dump - similar to what we are doing for the HTMLOutputLogger.

That would make it more aligned to PHPUnit architecture.

Waiting for PHPUnit 10 though, where the event system is implemented. Trying it before would mean to touch listeners which are deprecated in PHPUnit 9 and gone in 10.

Personally I find it more valuable to get immediate debug feedback as the test runs rather than wait until the end - and if somehow you crash the test or the test runner, is there a chance the captured output is lost? I guess this needs to still be postponed until we are on PHPUnit 10, in any case.

Well hopefully the post test execution events should still run even if the test itself crashes, otherwise we'd have a problem in PHPUnit. Anyway, let's see what we can do once the right time comes.

Sorry if I missed something but can the issue summary be updated then reviewed?

Updated IS

The Needs Review Queue Bot → tested this issue. It no longer applies to Drupal core. Therefore, this issue status is now "Needs work".

This does not mean that the patch necessarily needs to be re-rolled or the MR rebased. Read the Issue Summary, the issue tags and the latest discussion here to determine what needs to be done.

Consult the Drupal Contributor Guide → to find step-by-step guides for working with issues.

First time I'm looking at this, and wow, totally new approach! I guess this is required because of changes in PHPUnit 10?

This needs a CR to explain that phpunit.xml files need to be updated.

I like the printing of the file and line number, though in some instances that might get noisy.

For example, if I'm developing a migration and I want to see the value that's computed on each processing of a row. I'm going to add a single dump() statement and what I want to see is a monotonic list of values:

foo
foo
foo
somethingbad 
foo

I want 'somethingbad' to stick out in the last, and the list being simple is important to being able to do this. Filenames and line numbers will hamper this.

> Personally I find it more valuable to get immediate debug feedback as the test runs rather than wait until the end -

Same! Though I appreciate there may not be a way to do that with this approach.

The testVarDump() test outputs the dump statements it is testing. Is there a way of capturing the dump() output from testVarDump(), like it used to be?

I suspect some test runners will spot dump() output and not like it. It's also going to be noise in the test results from d.org CI.

Also, if the DebugDump extension it not registered, the testVarDump() test fails.

> public static function setDebugDumpHandler

The docs here could do with a @see to a fully-qualified DebugDump

> + * Drupal's extension for printing dump() output results.

Say it's a PHPUnit extension.

> self::$stagingFilePath = tempnam(sys_get_temp_dir(), 'dpd');

Could we use the VFS here? Would that be quicker?

> and if somehow you crash the test or the test runner, is there a chance the captured output is lost?

I think it's more likely that the file won't get cleaned up from the tmp directory. Though if we switch to using the VFS then that is solved.

No VFS, sorry. In tests run in process isolation, the VFS instance will only be visibile to the child process, and then destructed before returning to the main process. Or viceversa, if visible to the main process, it won't be visible to the children.

I want 'somethingbad' to stick out in the last, and the list being simple is important to being able to do this. Filenames and line numbers will hamper this.

We could add a parameter in the extension configuration in the xml file to opt-out from printing the whereabouts of the dump() call.

Ahh right. That's a shame!

Parameter in the extension config -- perfect! :)

I guess this is required because of changes in PHPUnit 10?

Well yes and no. There were already changes in PHPUnit 9 that forced to change the current solution to print to STDERR instead of STDOUT. The real problem is that, to an extent, test code and SUT code share the same standard streams. Quite rightly IMHO, especially if tests need to run in isolation, PHPUnit is 'sealing' more and more the SUT to prevent confusion between SUT and test output.

Added

<parameter name="printCaller" value="true"/>

as a config parameter for the extension.

> There were already changes in PHPUnit 9 that forced to change the current solution to print to STDERR instead of STDOUT. The real problem is that, to an extent, test code and SUT code share the same standard streams

So is output to STERR still possible, even if not always desirable?

If so, could we add an option for it?

No, we changed from STDOUT to STDERR already, and the newly reported failures in kernel tests are related to this.

If we want 'live' output, would it work to `tail -f` the file in which the output is getting sent to? If so, it would be useful to document that solution.

Well that would mean writing to STDOUT, so back to square one. This issue is, fundamentally, avoiding to use standard streams - just capture the output of dump in a temp file, and post-test-mortem, print it via the standard streams of the CLI testrunner that are no longer being checked by PHPUnit for unexpected output. No live output, in this case, sorry - it's the design of the MR itself that prevents it.

Note that if you call dump() from a component test that extends directly from PHPUnit's TestCase, or from a Drupal unit test case not run isolation, without the extension being active, then yes, you got exactly that - live dumps, and for free since there is not even the need to do anything.

This entire issue is about tests run in isolation. It's process isolation (and all kernel+functional tests, plus a few Drupal unit tests, are executied in isolation) that causes the dump() failures.

At least, that's my understanding - but I'd love to be proven wrong :)

> Well that would mean writing to STDOUT, so back to square one. This issue is, fundamentally, avoiding to use standard streams - just capture the output of dump in a temp file,

No, you don't need STDOUT. If the temp file is readable by a second terminal window, then `tail -f` outputs the end of the file *LIVE* as it is being written to. `tail -f` is particularly useful for watching log files, but would work here too, as long as the file is accessible and readable.

Interesting. If I understand your idea, that would mean running two separate terminals, one running PHPUnit CLI, and the other the tail command? That would pose the problem of knowing in advance the filepath of the temp file across both terminals, and of course of avoiding the hashing of the file content that the MR is currently doing.

> If I understand your idea, that would mean running two separate terminals, one running PHPUnit CLI, and the other the tail command?

Yup.

I wouldn't want that to be the main intended mode of operation, but it would be useful in some circumstances -- such as something that crashes PHPUnit so badly the output is not printed.

Thought about this, and IMHO dumping to a file for it to be tracked in real time via tail -f would better be done with an alternative extension, rather than trying to fit both behaviors in one.

merged with head

Can the CR be written?

#32 yes I will look into it

Added draft CR

CR looks good to me and helps me understand more what's going on.

May be one of those things easier to see once merged so will give it a +1 but will leave in review for others more advanced in phpunit her.e

The Needs Review Queue Bot → tested this issue. It fails the Drupal core commit checks. Therefore, this issue status is now "Needs work".

This does not mean that the patch necessarily needs to be re-rolled or the MR rebased. Read the Issue Summary, the issue tags and the latest discussion here to determine what needs to be done.

Consult the Drupal Contributor Guide → to find step-by-step guides for working with issues.

False positive

rebased

@mondrake: I am testing the MR on my local machine and there the tests are failing. I am using a DDEV environment.

ddev exec -d /var/www/html "./vendor/bin/phpunit -c ./core/phpunit.xml ./core/tests/Drupal/Tests/UnitTestCaseTest.php" results in:

PHPUnit 10.5.38 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.3.10
Configuration: /var/www/html/core/phpunit.xml

^ {#571
  +"Aldebaran": "Betelgeuse"
}
^ "Alpheratz"
FF                                                                  2 / 2 (100%)

Time: 00:00.147, Memory: 4.00 MB

There were 2 failures:

1) Drupal\Tests\UnitTestCaseTest::testVarDumpSameProcess
Failed asserting that '[]' [ASCII](length: 2) contains "Aldebaran" [ASCII](length: 9).

/var/www/html/core/tests/Drupal/Tests/UnitTestCaseTest.php:29

2) Drupal\Tests\UnitTestCaseTest::testVarDumpSeparateProcess
Failed asserting that '[]' [ASCII](length: 2) contains "Denebola" [ASCII](length: 8).

/var/www/html/core/tests/Drupal/Tests/UnitTestCaseTest.php:49

ddev exec -d /var/www/html "./vendor/bin/phpunit -c ./core/phpunit.xml --filter testVarDump ./core/tests/Drupal/KernelTests/KernelTestBaseTest.php" results in:

PHPUnit 10.5.38 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.3.10
Configuration: /var/www/html/core/phpunit.xml

F                                                                   1 / 1 (100%)

Time: 00:00.479, Memory: 4.00 MB

There was 1 failure:

1) Drupal\KernelTests\KernelTestBaseTest::testVarDump
Failed asserting that '[]' [ASCII](length: 2) contains "KernelTestBaseTest::testVarDump" [ASCII](length: 31).

/var/www/html/core/tests/Drupal/KernelTests/KernelTestBaseTest.php:316

ddev exec -d /var/www/html "./vendor/bin/phpunit -c ./core/phpunit.xml --filter testVarDump ./core/tests/Drupal/FunctionalTests/BrowserTestBaseTest.php" results in:

PHPUnit 10.5.38 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.3.10
Configuration: /var/www/html/core/phpunit.xml

F                                                                   1 / 1 (100%)

Time: 00:09.816, Memory: 4.00 MB

There was 1 failure:

1) Drupal\FunctionalTests\BrowserTestBaseTest::testVarDump
Failed asserting that '[]' [ASCII](length: 2) contains "BrowserTestBaseTest::testVarDump" [ASCII](length: 32).

/var/www/html/core/tests/Drupal/FunctionalTests/BrowserTestBaseTest.php:612

Maybe I am doing something wrong. Can you help me?

All the code changes look good to me.
I have run the tests for the new version of dump() on my local machine and it work.
The CR is in order and I should have read it earlier.
My suggestion is to put this requirement at the top of the release notes!!!
When you do not update your local phpunit.xml file, the function just does not do anything. It will take some time to find out that you need to update your local phpunit.xml file. I have updated the IS for this.
For me it is RTBC.

I corrected spelling in the CR and other minor tweaks. Updating credit.