Logger mesages are no longer retrievable in contrib phpunit tests

[jonathan1055]

Describe the bug
A recent change in Drush 12 has side-effects for contrib modules who provide commands and test them in phpunit.

To Reproduce
The tests fail on DrupalCI and I can replicate the test failure locally on MacOS php8.1 with latest Drush 12 dev
https://www.drupal.org/project/scheduler/issues/3359998#comment-15050025 has more details

Expected behavior
Log messages created via a modules logger using $this->logger->notice() used to be availbale during phpunit test. They could be retrieved in the test using $messages = $this->getErrorOutput(). But this behavior stopped in the latest Drush 12 and the messages are not retrievable. Phpunit tests that were checking for message fail where they previously passed.

I have isolated the problem and it was created in this commit from #5553
Rebasing Drush 12 dev locally back to the immediately preceding commit from #5560 and the tests pass

I'm not saying there is necessarily anything wrong with that commit. Maybe getting the log messages needs to be done differently now?

System Configuration

Q	A
Drush version?	12.x latest dev
Drupal version?	10.1 and 9.5
PHP version	any
OS?	Mac and DrupalCI

Additional information
The messages are still written to the terminal when the command is run. It is only in phpunit tests that they are not in the message array.

[greg-1-anderson]

That commit is a rather drastic one, in that it stops merging the drush.service.yml files into the Drupal kernel, and instead uses a bespoke adaptor class to instantiate command files. Overall, though, the behavior of Drush should be about the same as it was before, and off the top of my head, can't think of a reason why that logger behavior would be different.

Do you think that you could submit a failing test in Drush core (e.g. maybe in the woot module) that demonstrates the problem?

[jonathan1055]

Do you think that you could submit a failing test in Drush core (e.g. maybe in the woot module) that demonstrates the problem?

Yes sure will. I was wondering the best way to show you succinctly how the behaviour changed. I am totally unfamiliar woot. Do you mean add MR for https://github.com/drush-ops/drush/tree/12.x/sut/modules/unish/woot with example code and test?

[greg-1-anderson]

Yes; that is a test fixture module, it should be a good place to demonstrate the behavior.

[jonathan1055]

I've never tried to run drush tests locally. My first attempt fails with
PHP Fatal error: Uncaught Error: Class "Unish\CommandUnishTestCase" not found in /path/to/mysite/vendor/drush/drush/tests/functional/ArchiveTest.php:17

I'm not expecting you to help me all the way here, but are there some docs on what I need as pre-requisites to be able to run these drush functional tests locally?

[weitzman]

See https://www.drush.org/12.x/contribute/unish/

[jonathan1055]

I saw your slack post about rc candidiates and requests for review. I spent some hours trying to expand/write a woot test to demonstate the above problem, but I did not get it working. I was trying to replicate the code structure I have in Scheduler, which needs a new service, and paramters added to the woot manager, and a logger, and I was getting further and further bogged down. Sorry I've not managed it yet, and now I won't be able to do much for a few days. Don't let this hold up your progress, but just want you know that I do want to work on this again when I can.

[greg-1-anderson]

The failure is demonstrated by the tests in https://www.drupal.org/project/scheduler, though?

[jonathan1055]

Oh yes, precisely. The first assertion here used to pass before the latest drush commits
https://git.drupalcode.org/project/scheduler/-/blob/2.x/tests/src/Functional/SchedulerDrushTest.php?ref_type=heads#L22-24

I just wanted to make sure I could replicate here, isolated with a clean new test, to make sure it was not something I was doing wrong in the Scheduler tests.

[greg-1-anderson]

Yes, it would be our preference if you could reproduce it here, but if you don't have time or otherwise can't do that, I'll try to take a look at it in the context of your project and see if I can figure it out. I only have a little time left before DrupalCon, though, so we'll see what I can get to.

[jonathan1055]

I've added a test which replicates the log message process and the test failure in Scehduler.

I have also worked out another way to specify the logger, which matches the way you do this in other tests, using @logger.factory as argument, not @logger.channel.woot. The new drush test passes using this alternative, so I will see if I can change the original scheduler test to pass likewise.

[weitzman]

See discussion on PR.