Generic logging for 4xx errors

Some contrib modules rely on the logic provided by existing methods (see redirect_404)

I re-added them but kept the 4xx fallback.

Reroll for Drupal 9.

Adding a test.

Reviewed the Patch #9
https://www.drupal.org/files/issues/2020-07-09/4xx-log-3039266-9.patch
Php 7.4 and Drupal core 9.1 4xx-log-3039266-9.patch

1. +++ b/core/modules/dblog/tests/src/Functional/DbLogTest.php
   @@ -881,4 +881,26 @@ public function testBacktrace() {
   +   * Tests that a 4xx exceptions are handled.
   

   s/that a/that

2. +++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
   @@ -57,6 +57,21 @@ public function on404(ExceptionEvent $event) {
   +   * @param \Symfony\Component\HttpKernel\Event\GetResponseForExceptionEvent $event
   ...
   +  public function on4xx(ExceptionEvent $event) {
   

   This doesn't seem right?

3. +++ b/core/modules/dblog/tests/src/Functional/DbLogTest.php
   @@ -881,4 +881,26 @@ public function testBacktrace() {
   +   * Tests that a 4xx exceptions are handled.
   

   /s/that a/that

4. +++ b/core/modules/dblog/tests/src/Functional/DbLogTest.php
   @@ -881,4 +881,26 @@ public function testBacktrace() {
   +    $uri = $node->toUrl('canonical', [
   ...
   +    $this->drupalGet($uri);
   

   Maybe a blank line, and a comment to explain what we're doing here to trigger the exception. Doesn't necessarily need a comment, but we can at least separate the preparation for the test, and the trigger of the exception.

Thanks for the review. 3. should be correct, given that it's a fallback method for 4xx exceptions. Or did you mean something else?

Looks good
I tested this manually
Before Applying the patch

1. Navigate to http://localhost:8888/drupal/node/1?_format=hal_json%27. (Replace localhost with ur site base url)
2. You should see site encountered error
3. Check DBlog
4. See latet php error
5. Now apply the latest patch given in #13
6. Repeat step 1 to 3
7. In dblog u should see 4xx error

This can be moved to RTBC

Retested. https://www.drupal.org/pift-ci-job/1868692 It was a random test failure #2825845: DST-related test failures in FilterDateTimeTest.

Applied #13 patch Working fine showing 4xx error in recent log

The last patch works fine.

Before patch

After patch

RTBC

One cs error to fix:

FILE: ...e/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
----------------------------------------------------------------------
FOUND 1 ERROR AFFECTING 1 LINE
----------------------------------------------------------------------
 67 | ERROR | Expected type hint "GetResponseForExceptionEvent";
    |       | found "ExceptionEvent" for $event
----------------------------------------------------------------------

I did a code review.

1. +++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
   @@ -57,6 +57,21 @@ public function on404(ExceptionEvent $event) {
   +   * @param \Symfony\Component\HttpKernel\Event\GetResponseForExceptionEvent $event
   

   This type does not agree with the parameter declared in the function.

2. +++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
   @@ -88,9 +103,18 @@ public function onException(ExceptionEvent $event) {
   +
   +      // If the specific status code isn't handled, we try to match the status code type
   +      // For example if there's no on406() method, this will match on4xx().
   +      $method_fallback = 'on' . substr($exception->getStatusCode(), 0, 1) . 'xx';
   +
   +      // Check for methods to handle this error.
          if (method_exists($this, $possible_method)) {
            $method = $possible_method;
          }
   +      elseif (method_exists($this, $method_fallback)) {
   +        $method = $method_fallback;
   +      }
   

   I think this can be changed so that the fallback method name is only generated when $possible_method does not exist. Also, tweaked the comment to make it read a bit better and wrap at 80 columns.

         if (method_exists($this, $possible_method)) {
           $method = $possible_method;
         }
         else {
           // If the specific status code isn't handled, try to match the status
           // code type. For example, instead of using method on406() method use
           // method on4xx().
           $method_fallback = 'on' . substr($exception->getStatusCode(), 0, 1) . 'xx';
   
           if (method_exists($this, $method_fallback)) {
             $method = $method_fallback;
           }
         }

3. +++ b/core/modules/dblog/tests/src/Functional/DbLogTest.php
   @@ -881,4 +881,28 @@ public function testBacktrace() {
   +   * Tests that 4xx exceptions are reported in logs correctly.
   

   Lets be clear about what this does, "Tests that a 4xx errors are logged as a '4xx error'."

4. +++ b/core/modules/dblog/tests/src/Functional/DbLogTest.php
   @@ -881,4 +881,28 @@ public function testBacktrace() {
   +    // 4xx exceptions that are not handled should not be logged as php errors.
   

   Change to "Create a uri that will cause a 406 error."

5. +++ b/core/modules/dblog/tests/src/Functional/DbLogTest.php
   @@ -881,4 +881,28 @@ public function testBacktrace() {
   +    $php = Database::getConnection()->query("SELECT * FROM {watchdog} WHERE type='php'")->fetchAll();
   

   Add a comment above this line.
   // Confirm that a php error was not logged and that a 4xx error was.

6. +++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
   @@ -57,6 +57,21 @@ public function on404(ExceptionEvent $event) {
   +      ['%status_code' => $exception->getStatusCode(), '@message' => $exception->getMessage(), '@uri' => $request->getRequestUri()]
   

   @uri is not used. Should it be?

Here I have addressed comment #20, #21.1, #21.3, #21.4, and #21.5.
Still needs work for #21.2 and #21.6

Updated the patch from #22
- Rerolled for 9.5.x
- Worked on the pending points from #21

Result:

Updated test

Doesn't it duplicate #2828706: ExceptionLoggingSubscriber should not log HTTP 4XX errors using PHP logger channel?

I think Chi is right, that this is a duplicate of an earlier issue, #2828706: ExceptionLoggingSubscriber should not log HTTP 4XX errors using PHP logger channel.

I am closing this and moving credit.