Problem/Motivation

In #3432171: dump() no longer produces output in PHPUnit tests running under PHP 8.3 we fixed dump() no longer producing output in PHPUnit tests running in isolation under PHP 8.3, by changing writing to STDERR instead of STDOUT.

However, the fix is not sufficient as later #3452269: dump() calls in tests are producing a PHPUnit\Framework\Exception reported that dump() in kernel tests leads to test failures.

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

Proposed resolution

Take clues from HtmlOutputLogger and #3453341: Bootstrap HtmlOutputLogger from phpunit.xml, and introduce a PHPUnit extension that captures the output of dump() during the tests, and prints it cumulatively at the end of the testrunner execution. In this, enhance the experience to also add information about where each dump() call happened.

The bigger hurdle here are processes run in isolation (many unit ones, and all kernel/functional/functionaljavascript ones): there's no easy way to return information from the 'isolated' test back to its parent testrunner. However, using an environment variable and a staging file likewise HtmlOutputLogger, we can achieve that.

Remaining tasks

User interface changes

API changes

Data model changes

Release notes snippet

Please at this issue at the top of the release notes. To make dump() work you need to update your local phpunit.xml file with the following code:

  <extensions>
    .... 
    <!-- Debug dump() printer. -->
    <bootstrap class="Drupal\TestTools\Extension\Dump\DebugDump">
      <parameter name="colors" value="true"/>
      <parameter name="printCaller" value="true"/>
    </bootstrap>
  </extensions>

Issue fork drupal-3436029

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

Comments

mondrake created an issue. See original summary.

dineshkumarbollu’s picture

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.

mondrake’s picture

longwave’s picture

Status: Postponed » Active

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, unless PHPUnit 10 is even more restrictive in some way.

mondrake’s picture

Category: Bug report » Task

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 test 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.

longwave’s picture

Status: Active » Postponed

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.

mondrake’s picture

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.

mondrake’s picture

Title: Make dump() output in tests no longer use standard streams » [PHPUnit 10+ only] Make dump() output in tests no longer use standard streams
mondrake’s picture

Issue tags: +PHPUnit 10
mondrake’s picture

Status: Postponed » Active

mondrake’s picture

Status: Active » Needs review
mondrake’s picture

smustgrave’s picture

Status: Needs review » Needs work

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

mondrake’s picture

Issue summary: View changes
Status: Needs work » Needs review
Issue tags: -Needs issue summary update

Updated IS

needs-review-queue-bot’s picture

Status: Needs review » Needs work
StatusFileSize
new90 bytes

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.

mondrake’s picture

Status: Needs work » Needs review
joachim’s picture

Status: Needs review » Needs work
Issue tags: +Needs change record

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 list, and the list being simple is important to being able to do this. Filenames and line numbers will hamper this. (Generally, debugging something on a foreach loop is a scenario where I find dump()ing so much easier than using the debugger, as I can see all the values at a glance rather than keep advancing from a break point for each loop iteration.)

> 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.

mondrake’s picture

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.

joachim’s picture

Ahh right. That's a shame!

Parameter in the extension config -- perfect! :)

mondrake’s picture

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.

mondrake’s picture

Added

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

as a config parameter for the extension.

joachim’s picture

> 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?

mondrake’s picture

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

joachim’s picture

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.

mondrake’s picture

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 :)

joachim’s picture

> 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.

mondrake’s picture

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.

joachim’s picture

> 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.

mondrake’s picture

Status: Needs work » Needs review

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.

mondrake’s picture

merged with head

smustgrave’s picture

Can the CR be written?

mondrake’s picture

Assigned: Unassigned » mondrake
Status: Needs review » Needs work

#32 yes I will look into it

mondrake’s picture

Assigned: mondrake » Unassigned
Status: Needs work » Needs review
Issue tags: -Needs change record

Added draft CR

smustgrave’s picture

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

needs-review-queue-bot’s picture

Status: Needs review » Needs work
StatusFileSize
new3.14 KB

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.

smustgrave’s picture

Status: Needs work » Needs review

False positive

mondrake’s picture

rebased

mondrake’s picture

daffie’s picture

Status: Needs review » Needs work

@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?

Edit: Found the solution. I forgot to update my phpunit.xml. I will review the MR.

daffie’s picture

Issue summary: View changes
Status: Needs work » Reviewed & tested by the community

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.

quietone’s picture

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

mondrake’s picture

rabased for baseline conflicts

quietone’s picture

I read the IS and the comments. I didn't find any unanswered questions or other work to do. Tweaked the change record some more.

catch’s picture

I keep looking at this issue and then closing the tab eventually, because it feels like a lot of work and disruption to fix the issue. But also, I don't have any alternative solution and it is annoying when a test fails only because of a dump() call - makes it harder to spot when you've fixed it.

So I think we should go ahead here - will do so in a couple of days if no-one turns up with a way to avoid the phpunit.xml change in the meantime.

mondrake’s picture

I keep looking at this issue and then closing the tab eventually

😂 understand the feeling...

mondrake’s picture

... on the other hand, I used this several times in the last months and it turned to be very useful and stable to me.

  • catch committed 9ef9b0f7 on 11.x
    Issue #3436029 by mondrake, joachim, smustgrave, daffie, longwave,...
catch’s picture

Status: Reviewed & tested by the community » Fixed

Let's go ahead here. I linked to this issue and the CR in #core-development on slack for additional visibility.

Committed/pushed to 11.x, thanks!

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.