DrushLoggerServiceProvider is not registered after a cache rebuild

[mcdruid]

Describe the bug

There's an inconsistency with how logging behaves in drush on a fresh install vs. after a cache rebuild.

As far as I can tell, this is because after the cache rebuild the DrushLoggerServiceProvider doesn't register the drush logger with the container. I'm not sure why this is.

To Reproduce

Clean install:

$ drush -y si

$ drush ev "\Drupal::logger('Test')->error('Hello, this is an error from drush');"
 [error]  Hello, this is an error from drush 

Now rebuild caches and try again:

$ drush cr
 [success] Cache rebuild complete.
$ drush ev "\Drupal::logger('Test')->error('Hello, this is an error from drush');"
$

This is a hacky way to access / view the registered services, but hopefully proves the point:

before (drush has registered its logger):

$ drush ev "var_dump((fn() => \$this->loggers)->call(\Drupal::logger('foo')));"

array(1) {
  [0] =>
  array(2) {
    [0] =>
    class Drupal\dblog\Logger\DbLog#4641 (4) {
      protected $connection =>
      class Drupal\mysql\Driver\Database\mysql\Connection#874 (25) {

...snip...

    }
    [1] =>
    class Drush\Log\DrushLog#4724 (2) {
      protected Drupal\Core\Logger\LogMessageParserInterface $parser =>
      class Drupal\Core\Logger\LogMessageParser#4704 (0) {
      }
      protected ?Psr\Log\LoggerInterface $logger =>
      NULL
    }
  }
}

after (only dblog is registered):

$ drush ev "var_dump((fn() => \$this->loggers)->call(\Drupal::logger('foo')));"

array(1) {
  [0] =>
  array(1) {
    [0] =>
    class Drupal\dblog\Logger\DbLog#1056 (4) {
      protected $connection =>
      class Drupal\mysql\Driver\Database\mysql\Connection#874 (25) {

...snip...

    }
  }
}

Expected behavior

Drush continues to successfully register its logger after a cache rebuild, and therefore the behaviour of the cli is consistent.

Actual behavior

After a drush cr drush doesn't do its own logging as its logger is AWOL.

Workaround

I've not yet worked out if there's a way of restoring the drush logger once it's no longer being registered.

System Configuration

Q	A
Drush version?	12.4.3.0
Drupal version?	11.0-dev
PHP version	8.1
OS?	Linux

Additional Information

I've reproduced this locally with ddev and the versions listed above, and also on Acquia with Drupal 10.2.3 and PHP 8.2 so it doesn't look like a narrow environment-specific issue as far as I can see.

[mcdruid]

Looks like one way to fix the specific problem described here is to ensure that the global used to ensure that the service is discovered within \Drush\Boot\DrupalBoot8::bootstrapDrupalConfiguration is set before drush causes the container to be rebuilt during cache rebuild (in \Drush\Commands\core\CacheRebuildCommands::rebuild).

e.g.

use Drush\Drupal\DrushLoggerServiceProvider;

...snip..

    public function rebuild($options = ['cache-clear' => true])
    {

...snip..

        $GLOBALS['conf']['container_service_providers'][] = DrushLoggerServiceProvider::class;

        // drupal_rebuild() calls drupal_flush_all_caches() itself, so we don't do it manually.
        drupal_rebuild($this->autoloader, $request);

I'm not sure how any of this works if drush is not used to install the site / rebuild the caches.

I can submit a PR for the change above - which seems mostly harmless AFAICS - as it looks like it would fix this specific issue, but I'm not sure if there would be any wider consequences.

[nikunjkotecha]

I confirm the fix, I added following in the secret settings file directly on server to confirm

if (PHP_SAPI === 'cli') {
  $GLOBALS['conf']['container_service_providers'][] = Drush\Drupal\DrushLoggerServiceProvider::class;
}

[jonathan1055]

This is great! It has solved a bug I reported https://www.drupal.org/project/scheduler/issues/3359998#comment-15048675 where messages are no longer being shown, which causes phpunit tests failures. It was OK on drush 11 but failed at drush 12 and I isolated the commit that caused it. But this PR solves the problem.

Without the fix, as current

drush sch:cron
 [notice] Message: Scheduler lightweight cron completed.

This is the message written in the projects Drush command definition, via $this->messenger->addMessage()

With the fix we recover the two other messages

drush sch:cron 
 [notice] Lightweight cron run activated by drush command.
 [notice] Lightweight cron run completed.
 [notice] Message: Scheduler lightweight cron completed.

The missing first two messages are written in other places in the code via $this->logger->notice()

Thank you for solving this. I have had to isolate and turn off the projects drush tests to avoid the test runs failing. When this is committed I can get those tests reinstated.

[weitzman]

Fixed in #5863

[jonathan1055]

I reported that this problem is fixed. It was fixed when I ran the commands locally. But the phpunit tests still fail to find the message lines.