Deprecate watchdog_exception

xjm → closed merge request !1172

xjm → closed merge request !2885

We don't deprecate new things in 9.5.x anymore, so hiding the patch files. Also closed the redundant MRs for clarity. Thanks!

We don't need to add a test dependency, I don't think; we can construct our own test logger.

Updated for latest 9.5.x, not for review but reference.

📌 Add colinodell/psr-test-logger to core's dev dependencies Fixed was committed so I think this unblocks the test logger issues.

Revisiting this issue after a long while and found it difficult to work out what MRs to use etc. Added a bit more dependency injection of the logger.

Code style fixes.

#122 you tagged for issue summary update that still needed?

Patch #157 appears to have some failures.

The service "drupal.proxy_original_service.module_installer" has a dependen
20:35:49 cy on a non-existent service "logger.channel.system". Did you mean one of t
20:35:49 hese: "logger.channel.default", "logger.channel.php", "logger.channel.image
20:35:49 ", "logger.channel.cron", "logger.channel.file", "logger.channel.form", "lo
20:35:49 gger.channel.security"?

Looks like the module installer has undeclared dependency on the 'system' logger channel. I've changed this to 'default' as this causes issues with the proxy.

Also reworked \Drupal\Tests\update\Unit\UpdateFetcherTest to use the new test logger which greatly simplifies this test.

The last submitted patch, 159: 2932518-159.patch, failed testing. View results →

Fixes `workspaces.association` service definition.

Assuming this no longer needs a reroll.

Only think I saw was that there are 2 instances of

is deprecated in drupal:10.0.0

But the others are deprecation in 10.1

Shouldn't they be the same?

Patch cleaning up DI and fix #162

1. +++ b/core/lib/Drupal/Core/EventSubscriber/MenuRouterRebuildSubscriber.php
   @@ -87,7 +88,7 @@ protected function menuLinksRebuild() {
   -        watchdog_exception('menu', $e);
   +        \Drupal::logger('menu')->error(...Error::decodeExceptionWithMessage($e));
   

   I think logger needs injection here

2. +++ b/core/lib/Drupal/Core/Routing/MatcherDumper.php
   @@ -152,7 +153,7 @@ public function dump(array $options = []): string {
   -      watchdog_exception('Routing', $e);
   +      \Drupal::logger('Routing')->error(...Error::decodeExceptionWithMessage($e));
   

   may need DI too

3. +++ b/core/modules/system/src/SecurityAdvisories/SecurityAdvisoriesFetcher.php
   @@ -321,7 +322,7 @@ protected function doRequest(int $timeout): string {
   -        watchdog_exception('system', $exception);
   +        \Drupal::logger('system')->error(...Error::decodeExceptionWithMessage($exception));
   

   already using system logger

4. +++ b/core/modules/update/src/ProjectSecurityData.php
   @@ -224,11 +225,9 @@ private function getAdditionalSecurityCoveredMinors($security_covered_version) {
   +        \Drupal::logger('update')->error(
   

   no DI found

@andypost not sure if you meant to leave in Review for the points you mentioned.

I set NR for my changes, also fixed #163-3

Fixes for #163 1,2 & 3.

4. This is a value object, and doesn't need DI IMO.

The last submitted patch, 166: 2932518-166.patch, failed testing. View results →

Fixed the RouteProviderTest which needed to pass the logger to the constructor.

I have changed the order of arguments in \Drupal\Core\Routing\MatcherDumper::__construct() so the $table = 'router' param is last. This is because we want the logger to be required in 10.0.x but a required param can't come after an optional one. This $table param is only for tests as far as I can tell. Is there a better way to handle this?

Can we remove the IS update tag?

Also applied patch #168 and there were 2 instances of watchdog_exception I found that may need replacing.

In SecurityAdvisoriesFetcherTest

  /**
   * The log messages from watchdog_exception.
   *
   * @var string[]
   */
  protected $watchdogExceptionMessages = [];

Then in CronSuspendQueueDelayTest
// Capture logs to watchdog_exception().

Everything else looked good to me.

#169 Replaced comment instances of watchdog_exception and removed IS update tag.

Thanks @kim.pepper!

The patch looks good, but in my opinion the change record needs to be a bit more verbose on other ways the watchdog_exception needs to be replaced:

Only the 2 first parameters of this function are covered:

function watchdog_exception($type, Exception $exception, $message = NULL, $variables = [], $severity = RfcLogLevel::ERROR, $link = NULL)

There is no example of how to use $link and other errors than RfcLogLevel::ERROR.

+++ b/core/lib/Drupal/Core/Utility/Error.php
@@ -75,6 +75,25 @@ public static function decodeException($exception) {
+  /**
+   * Decodes an exception and retrieves the correct caller with a message.
+   *
+   * @param \Exception|\Throwable $exception
+   *   The exception object that was thrown.
+   * @param string $message
+   *   A custom error message.
+   *
+   * @return array
+   *   An error in the format expected by Drupal::logger()->error().
+   */
+  public static function decodeExceptionWithMessage($exception, $message = Error::DEFAULT_ERROR_MESSAGE) {
+    $decode = static::decodeException($exception);

+++ b/core/modules/system/src/SecurityAdvisories/SecurityAdvisoriesFetcher.php
@@ -152,7 +153,7 @@ public function getSecurityAdvisories(bool $allow_outgoing_request = TRUE, int $
+        $this->logger->error('Invalid security advisory format: ' . Json::encode($advisory_data), Error::decodeException($unexpected_value_exception));

There's no cases of ever passing a $message in core so it seems this is unnecessary. Everywhere it could be used we see: $this->logger->error('Invalid security advisory format: ' . Json::encode($advisory_data), Error::decodeException($unexpected_value_exception));

So perhaps this method that returns a tuple is unnecessary.

Did we consider adding Error::logException($logger, \Exception|\Throwable $exception, string $message = Error::DEFAULT_ERROR_MESSAGE, array $additional_variables = []) :void

The implementation could then be:

$logger->error($message, static::decodeException($exception) + $additional_variables);

1. +++ b/core/lib/Drupal/Core/Extension/ModuleInstaller.php
   @@ -302,7 +310,9 @@ public function install(array $module_list, $enable_dependencies = TRUE) {
                    }
                    catch (EntityStorageException $e) {
   -                  watchdog_exception('system', $e, 'An error occurred while notifying the creation of the @name field storage definition: "@message" in %function (line %line of %file).', ['@name' => $storage_definition->getName(), '@message' => $e->getMessage()]);
   +                  $variables = Error::decodeException($e);
   +                  $variables['@name'] = $storage_definition->getName();
   +                  $this->logger->error('An error occurred while notifying the creation of the @name field storage definition: "!message" in %function (line %line of %file).', $variables);
                    }
   

   This is reverting back to a !placeholder, that doesn't exist and is wrong. Not sure why that's not failing, not tested?

2. +++ b/core/modules/system/src/SecurityAdvisories/SecurityAdvisoriesFetcher.php
   @@ -152,7 +153,7 @@ public function getSecurityAdvisories(bool $allow_outgoing_request = TRUE, int $
            // this is highly unlikely we should still display the items that are
            // in the correct format.
   -        watchdog_exception('system', $unexpected_value_exception, 'Invalid security advisory format: ' . Json::encode($advisory_data));
   +        $this->logger->error('Invalid security advisory format: ' . Json::encode($advisory_data), Error::decodeException($unexpected_value_exception));
            continue;
   

   this was not introduced here, but this usage is wrong. the message must never by dynamic. The messsage is passed to t(), every unique combination will result in a separate, translatable string and fill up the locale tables. the advisory data needs to be put in the variables and passed together with the decoded exception.

I'll look at implementing #173

Thanks for the reviews.

Implemented Error::logException() as suggested in #173 and made a few conversions that simplify the code. I removed the decodeExceptionWithMessage() function. Great improvement!

Fixed issues with #174 1 & 2.

I updated the CR to address feedback in #172 and realised we had hard-coded the log level to ERROR where previously this was an option. I've added an extra param to Error::logException() to take a LogLevel defaulting to LogLevel::ERROR.

The last submitted patch, 176: 2932518-176.patch, failed testing. View results →

Missed a couple of things which are now fixed:

1. watchdog_exception takes a RfcLogLevel $severity (int) while our new Error::logException() takes a PsrLevel $level (string). Added a conversion because I assume we want to use PSR level with our PSR logger interface to be consistent.
2. I converted watchdog_exception() to use Error::logException() too and updated the deprecation message

✨ Add Single Directory Components as a new experimental module Fixed Added a new call to watchdog_exception. Fixing that.

The last submitted patch, 177: 2932518-177.patch, failed testing. View results →

The last submitted patch, 179: 2932518-178.patch, failed testing. View results →

Wow quick turnaround on the new sdc module.

These ones are sometimes above my head but from what I can tell all the points 173 + 174 have been addressed. So don't mind remarking.

1. +++ b/core/includes/bootstrap.inc
   @@ -124,21 +125,37 @@ function t($string, array $args = [], array $options = []) {
   +  $variables = [];
   

   This is a breaking change - we should not be setting $variables to an empty array here.

2. +++ b/core/lib/Drupal/Core/Database/database.api.php
   @@ -202,7 +202,7 @@
   - *     watchdog_exception('type', $e);
   + *     \Drupal::logger('type')->error(...Error::decodeExceptionWithMessage($e));
   

   Let's change this to use the new Error::logException() too.

3. +++ b/core/modules/sdc/sdc.services.yml
   @@ -8,6 +8,7 @@ services:
      Drupal\sdc\Twig\TwigComponentLoader:
        arguments:
          - '@plugin.manager.sdc'
   +      - '@logger.channel.sdc'
        tags:
          - { name: twig.loader, priority: 5 }
    
   @@ -53,3 +54,8 @@ services:
   
   @@ -53,3 +54,8 @@ services:
      Drupal\sdc\Component\ComponentValidator:
        calls:
          - [setValidator, []]
   +
   +  logger.channel.sdc:
   +    class: Drupal\Core\Logger\LoggerChannel
   +    factory: [ '@logger.factory', 'get' ]
   +    arguments: [ 'sdc' ]
   

   This module will be added to the core library and will not be a module. I think we should take this opportunity to chose an existing logger channel. I think this message should end up in the default logger channel. Ie. logger.channel.default.

Re: #185 Thanks for the review.

1. Fixed
2. Fixed
3. Fixed

+++ b/core/includes/bootstrap.inc
@@ -136,9 +143,18 @@ function watchdog_exception($type, Exception $exception, $message = NULL, $varia
-  $variables += Error::decodeException($exception);
-
-  \Drupal::logger($type)->log($severity, $message, $variables);
+  $level = match ($severity) {
+    RfcLogLevel::EMERGENCY => LogLevel::EMERGENCY,
+    RfcLogLevel::ALERT => LogLevel::ALERT,
+    RfcLogLevel::CRITICAL => LogLevel::CRITICAL,
+    RfcLogLevel::WARNING => LogLevel::WARNING,
+    RfcLogLevel::NOTICE => LogLevel::NOTICE,
+    RfcLogLevel::INFO => LogLevel::INFO,
+    RfcLogLevel::DEBUG => LogLevel::DEBUG,
+    default => LogLevel::ERROR,
+  };
+
+  Error::logException(\Drupal::logger($type), $exception, $message, $variables, $level);

I was thinking about asking for a test about passing variables into the watchdog_exception() function because we broke it... and this has lead me to wondering why are we changing the deprecated code? I think in general we should only do this when we have to and I can't see a reason why we have to here.

re: #187 rolled back changes to watchdog_exception().

From what I can tell #185 + #187 have been addressed. Don't mind moving this forward.

1. +++ b/core/lib/Drupal/Core/Routing/MatcherDumper.php
   @@ -51,13 +53,18 @@ class MatcherDumper implements MatcherDumperInterface {
   -  public function __construct(Connection $connection, StateInterface $state, $table = 'router') {
   +  public function __construct(Connection $connection, StateInterface $state, protected ?LoggerInterface $logger = NULL, $table = 'router') {
        $this->connection = $connection;
        $this->state = $state;
   -
   +    if ($this->logger === NULL) {
   

   This won't work how we're expecting here.

   If someone is extending it, their third param will be a string (The table name) and they will get a fatal here rather than a deprecation error.

   I think we need to remove the type hint and use an instanceof check too.

   There are four scenarios here:
   * two params
   * three params, where third is a string
   * three params, where third is a logger
   * four params

   We're missing handling for the second case

2. +++ b/core/lib/Drupal/Core/Utility/Error.php
   @@ -75,6 +77,24 @@ public static function decodeException($exception) {
   +  public static function logException(LoggerInterface $logger, \Exception | \Throwable $exception, string $message = Error::DEFAULT_ERROR_MESSAGE, array $additional_variables = [], string $level = LogLevel::ERROR): void {
   

   Exception extends Throwable, any reason we needed the union here instead of just using Throwable?

Unrelated, but I'm not too keen on the use of colinodell/psr-test-logger when we already had \Symfony\Component\Debug\BufferingLogger - I commented in 📌 Add colinodell/psr-test-logger to core's dev dependencies Fixed to clarify why we need both.

Thanks for the feedback in #190

1. Fixed the logic of the constructor and added a legacy deprecation test for the 4 different scenarios.
2. Replaced with just \Throwable and added typehint.

Had a quick look at \Symfony\Component\Debug\BufferingLogger and doesn't provide the ability to read back the logs AFAIK. It does log to error_log on __destruct() so maybe that's useful?

Oops. Forgot to actually set the logger.

Replaced typehint on decodeException() instead of logException()

The last submitted patch, 192: 2932518-192.patch, failed testing. View results →

The last submitted patch, 193: 2932518-193.patch, failed testing. View results →

Couple nits and questions but NW on the comment about $table. Otherwise LGTM.

+++ b/core/includes/bootstrap.inc
@@ -7,9 +7,9 @@
+use Drupal\Core\StringTranslation\TranslatableMarkup;
 use Drupal\Core\Test\TestDatabase;
 use Drupal\Core\Utility\Error;
-use Drupal\Core\StringTranslation\TranslatableMarkup;

@@ -124,8 +124,14 @@ function t($string, array $args = [], array $options = []) {
+ * @see https://www.drupal.org/node/2932520

+++ b/core/lib/Drupal/Core/EventSubscriber/MenuRouterRebuildSubscriber.php
@@ -52,12 +54,18 @@ class MenuRouterRebuildSubscriber implements EventSubscriberInterface {
+      $this->logger = \Drupal::service('logger.channel.menu');

Doesn't bother me but re-ordering this is technically out of scope.

1. +++ b/core/lib/Drupal/Core/Routing/MatcherDumper.php
   @@ -51,14 +60,25 @@ class MatcherDumper implements MatcherDumperInterface {
   +    if (!is_null($table)) {
   +      $this->tableName = $table;
   +    }
   

   $table is not nullable so this condition is unreachable

2. +++ b/core/lib/Drupal/Core/Utility/Error.php
   @@ -75,6 +77,24 @@ public static function decodeException($exception) {
   +  /**
   +   * Log a formatted exception message to the provided logger.
   +   *
   +   * @param \Psr\Log\LoggerInterface $logger
   +   *   The logger.
   +   * @param \Exception|\Throwable $exception
   +   *   The exception.
   +   * @param string $message
   +   *   (optional) The message.
   +   * @param array $additional_variables
   +   *   (optional) Any additional variables.
   +   * @param string $level
   +   *   The log level.
   +   */
   +  public static function logException(LoggerInterface $logger, \Exception | \Throwable $exception, string $message = Error::DEFAULT_ERROR_MESSAGE, array $additional_variables = [], string $level = LogLevel::ERROR): void {
   +    $logger->log($level, $message, static::decodeException($exception) + $additional_variables);
   +  }
   

   Do we need \Exception here since it extends \Throwable?

3. +++ b/core/lib/Drupal/Core/Utility/Error.php
   @@ -75,6 +77,24 @@ public static function decodeException($exception) {
   +   * @param string $level
   +   *   The log level.
   

   Is it worth mentioning that this should be one of the levels defined in \Psr\Log\LogLevel?

Thanks for the review @mstrelan! RE: #196:

Rolled back the import re-ordering.

1. Fixed the logic to check for a null $this->tableName instead.
2. Fixed in #193
3. Updated to mention the PSR LogLevel.

Also fixed incorrect namespace for \Drupal\KernelTests\Core\Routing\LegacyMatcherDumperTest after moving it.

FWIW \Symfony\Component\Debug\BufferingLogger::cleanLogs is how you read them back. But regardless, out of scope here - the horse has bolted - the discussion can happen elsewhere

All feedback since #190 has been addressed, marking RTBC.

Saving issue credits.

Committed to 10.1.x and published the change record.

Created a follow-up for somewhat related 📌 Fix typehints in \Drupal\Core\Utility\Error::decodeException() Fixed

Added 📌 Replace usages of colinodell/testlogger with BufferingLogger from symfony/error-handler, then remove dev dependency on testlogger Closed: won't fix to discuss use of TestLogger

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