Website exception via GET with QUERY_STRING "?_format=..."

I did some tests on a clean install and it seems like this specific issue is tied to the exact parameter of "_format". I tried it without the leading underscore and it works as expected. I also tried "?foo=bar&baz" as well and no issue.

Is there an unknown reason why the "_format" parameter cause such an error? It might be intentional, not a bug.

I agree that this is a bug. We should catch this exception and show the proper, HTML-formatted error page. Attached is a patch for consideration.

With this patch:
http://localhost:8080/user/1/?_format=json - Shows json error message as before
http://localhost:8080/user/1/?_format=NOPE - Shows an HTML 406 error page saying "A client error happened"
http://localhost:8080/user/1/?_format=html - Shows HTML user page
http://localhost:8080/user/1 - Shows HTML user page

Reroll

Here's another patch which fixes @indigoxela point about the exception still being logged, and it also reduces the scope of the fix to the problem at hand.

It's text/plain so that risk is mitigated. You definitely do have a point tho. Updated the patch.

Moving to "Reviewed & tested by the community" per comment #20 now that the tests are passing.

@slip thanks you so much for working on this. It is community policy to not rtbc your own patches and @indigoxela's comment in #20 says that whilst they think the code is good they don't feel they can rtbc.

I think the test needs to assert that the error is a 406. Maybe an explicit 406 test ala \Drupal\KernelTests\Core\Routing\ExceptionHandlingTest::test405().

1. +++ b/core/lib/Drupal/Core/EventSubscriber/DefaultExceptionUnknownFormatSubscriber.php
   @@ -0,0 +1,49 @@
   +    // A very low priority so that custom handlers are almost certain to fire
   +    // before it, even if someone forgets to set a priority.
   +    // This is also lower than json and HTML so that those have priority.
   +    return -200;
   

   This is a good comment. I think we should consider setting this to -250 to be even closer to the -256 of the final subscriber.

2. +++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
   @@ -53,6 +53,17 @@ public function on404(GetResponseForExceptionEvent $event) {
   +    $this->logger->get('client error')->warning('@uri', ['@uri' => $request->getRequestUri()]);
   

   Can we not log something more specific?

For logging I was mimicking what the other loggers do in that class for access denied and page not found. In this patch I'm adding all the information I think it makes sense to add.

The test is also added and I lowered the priority as suggested.

@alexpott thanks a lot for the feedback!

+++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
@@ -53,6 +53,21 @@ public function on404(GetResponseForExceptionEvent $event) {
+  /**
+   * Log 406 errors.
+   *
+   * @param \Symfony\Component\HttpKernel\Event\GetResponseForExceptionEvent $event
+   *   The event to process.
+   */
+  public function on406(GetResponseForExceptionEvent $event) {
+    $exception = $event->getException();
+    $request = $event->getRequest();
+    $this->logger->get('client error')->warning(
+      'There was an error in the client request: "@message" at @uri.',
+      ['@message' => $exception->getMessage(), '@uri' => $request->getRequestUri()]
+    );
+  }

So... I was wondering do we actually want to log these? I'm not sure it is necessary to bring them into the Drupal logs. It's not quite the same as access denied or 404.

Imo we could drop this code. It's not necessary to fix the bug.

@alexpott I get what you're saying. I personally think if we're logging 404s we should also log these. Something's going on with their request and they're not getting what they're asking for.

Additionally, if we remove this on406, an exception would get logged, which is part of the original problem and something I think we definitely don't want.

So I think we should keep this logging message or, if not, would you prefer to swallow the error with an empty function:
public function on406(GetResponseForExceptionEvent $event) {}

This is ready for more feedback.

+++ b/core/lib/Drupal/Core/EventSubscriber/ExceptionLoggingSubscriber.php
@@ -53,6 +53,21 @@ public function on404(GetResponseForExceptionEvent $event) {
+  /**
+   * Log 406 errors.
+   *
+   * @param \Symfony\Component\HttpKernel\Event\GetResponseForExceptionEvent $event
+   *   The event to process.
+   */
+  public function on406(GetResponseForExceptionEvent $event) {
+    $exception = $event->getException();
+    $request = $event->getRequest();
+    $this->logger->get('client error')->warning(
+      'There was an error in the client request: "@message" at @uri.',
+      ['@message' => $exception->getMessage(), '@uri' => $request->getRequestUri()]
+    );
+  }

406 doesn't mean client error. It has a specific HTTP meaning. Imo it's fine to remove this. Yes that means we'll get the standard message by onError but that's no change. What the user sees is fixed. We should open a follow-up to log 400s differently as the message $this->logger->get('php')->log($error['severity_level'], '%type: @message in %function (line %line of %file).', $error); doesn't work for 405s either (for example).

+++ b/core/lib/Drupal/Core/EventSubscriber/DefaultExceptionUnknownFormatSubscriber.php
@@ -0,0 +1,49 @@
+  /**
+   * Handles a 406 error for any unknown format.
+   *
+   * @param \Symfony\Component\HttpKernel\Event\GetResponseForExceptionEvent $event
+   *   The event to process.
+   */
+  public function on406(GetResponseForExceptionEvent $event) {

Hmmm thinking about this even more let's make this more generic and do

  /**
   * Handles all 4xx errors for all serialization failures.
   *
   * @param \Symfony\Component\HttpKernel\Event\GetResponseForExceptionEvent $event
   *   The event to process.
   */
  public function on4xx(GetResponseForExceptionEvent $event) {

And then we can fix logging to be more generic for 400s as well.

Updates made. This is now a generic handler.

I also added support for cacheable responses like ExceptionJsonSubscriber

Moved logging changes to https://www.drupal.org/project/drupal/issues/3039266

1. +++ b/core/lib/Drupal/Core/EventSubscriber/DefaultExceptionUnknownFormatSubscriber.php
   @@ -32,15 +34,24 @@
   +   * Handles all 4xx errors for all serialization failures.
   

   Not sure that we are specific to serialization failures - however there's no harm in including an example here - so we could mention 406s generated when handling unsupported formats.

2. +++ b/core/core.services.yml
   @@ -1275,6 +1275,10 @@ services:
   +  exception.default_unknown_format:
   

   Needs a new name.

3. +++ b/core/lib/Drupal/Core/EventSubscriber/DefaultExceptionUnknownFormatSubscriber.php
   @@ -0,0 +1,60 @@
   +class DefaultExceptionUnknownFormatSubscriber extends HttpExceptionSubscriberBase {
   

   Needs a new name.

4. +++ b/core/lib/Drupal/Core/EventSubscriber/DefaultExceptionUnknownFormatSubscriber.php
   @@ -0,0 +1,60 @@
   +      $message = Html::escape($exception->getMessage());
   

   If we're outputting plain text I think we should strip HTML. We can use \Drupal\Component\Render\PlainTextOutput::renderFromHtml()

5. However rather than adding new names I suggest we merge this into \Drupal\Core\EventSubscriber\FinalExceptionSubscriber() that way it is clearer it is generic and should be last.

   A single subscriber can register more than one listener so we could do something like:

   
     /**
      * {@inheritdoc}
      */
     public static function getSubscribedEvents() {
       // Run as the final (very late) KernelEvents::EXCEPTION subscriber.
       $events[KernelEvents::EXCEPTION][] = ['on4xx', -250];
       $events[KernelEvents::EXCEPTION][] = ['onException', -256];
       return $events;
     }
   
     public function on4xx(GetResponseForExceptionEvent $event) {
       if (substr($exception->getStatusCode(), 0, 1) !== '4') {
          // Do nothing.
          return;
       }
       // Do the new logic...
     }
   

All valid comments. New patch attached.

Developments changes should now be targeted the 8.8.x-dev branch.
Allowed changes during the Drupal 8 release cycle
Drupal 8 minor version schedule

@Krzysztof Domański - yeah but this is a bug fix so should target 8.7.x

1. +++ b/core/lib/Drupal/Core/EventSubscriber/FinalExceptionSubscriber.php
   @@ -138,11 +139,38 @@ public function onException(GetResponseForExceptionEvent $event) {
   +   * Handles all 4xx errors that aren't caught in other exception subscribers.
   +   * ¶
   

   There's a space after the * on the blank line.

2. +++ b/core/lib/Drupal/Core/EventSubscriber/FinalExceptionSubscriber.php
   @@ -138,11 +139,38 @@ public function onException(GetResponseForExceptionEvent $event) {
   +   * For example, we catch 406s and 403s generated when handling unsupported formats.
   

   This comment needs to wrap at 80 chars.

3. This fix is beginning to make me ponder if we're on the right path. Not every HttpException has a good message - see \Drupal\Core\Form\Exception\BrokenPostRequestException for example. I'm also questioning the premise of the issue itself. Drupal does not emit an exception when you do http://your-testing.tld/node/1?_format=something_odd - it emits a 406 with a message saying The website encountered an unexpected error. Please try again later.. What is actually wrong with that?

Styling fixed.

This original issue was definitely a bug. Site's are showing that error (which is basically Drupal's version of a fatal error) and exceptions are being logged. The logging part is perhaps most severe issue but we split that off. Still I'd like to finish this issue before dedicating time to that one.

I do take issue with the message displayed. The Drupal message "The website encountered an unexpected error. Please try again later." makes me think an unrecoverable fatal error happened. Additionally, If you have your site set up to show exceptions, one will be printed. This seems like overkill for something easily reproduced on every D8 site.

For messaging we could use the messaging in Http4xxController. At one point I had those simple messages being output.

Another point is that the json subscriber is actually doing something very similar to us and is outputting exception messages. for example (logged out):
https://www.site.tld/admin/?_format=json

If exception messages shouldn't be shown, that page shouldn't show them either.

If you disagree we can close this issue and tackle the logging issue. Otherwise please let me know what you think and I'll take it from there.

@indigoxela yes, that's intended. We scaled back this patch significantly and since the user is requesting a format that isn't html, it didn't seem to make sense to return HTML, although that is easy enough to do. Additionally, the logging fix was moved to a different issue. That's why the logging is still an issue even with this patch.

@slip I think using the messages in \Drupal\system\Controller\Http4xxController is a very good idea. Those messages are indeed way better than The website encountered an unexpected error. Please try again later.

It would be neat if somehow the messages could be shared between Http4xxController and FinalExceptionSubscriber.

Another thought is that maybe if you are getting these on your site it might be helpful to get the additional backtrace info added by \Drupal\Core\EventSubscriber\FinalExceptionSubscriber::onException() so perhaps we should roll this content change into that method.

+++ b/core/lib/Drupal/Core/EventSubscriber/FinalExceptionSubscriber.php
@@ -138,11 +139,39 @@ public function onException(GetResponseForExceptionEvent $event) {
+    $events[KernelEvents::EXCEPTION][] = ['on4xx', -250];

This needs to document the reasoning for this particular priority. Why -250 compared to -256?

Also: the comment above this line belongs with the -256 event.

Reroll for D9.

Added a comment, but there's not too much to say. It has to run before the final exception handler, that's pretty much all there is to it I think.

Not sure what to do about #45.

I think it would be nice to finally resolve this, there are still bots out there looking for vulnerable sites for the hal_json security issue and it's filling up logs.

Adding a reroll for D8.9.x.

Another reroll, and I can already see this conflicting again because that assertEqual() line is going to change again :-/.

Upgrading an 8.9 site to 9.x today and the reroll in #52 still applies and resolves the issue. Marking RTBC as #47 has been addressed and its not clear if #45 if necessary. @alexpott or someone else can revert back to needs work if necessary.

It does apply, but it has coding style issues that need to be resolved sadly.

Updating #52 to pass drupalCI.

How can we handle this /var/www/html/core/tests/Drupal/KernelTests/Core/Routing/ExceptionHandlingTest.php:215:59 - Unknown word (jsonalert) here - $this->assertStringStartsWith('Not acceptable format: jsonalert(123);', $response->getContent());
Should we use it as we did it before inside em tag

Yeah, I'm unsure what to do about that. The reason that we end up with jsonalert is that this is all that's left over of json<script>alert(123);</script>, this is is specifically testing that we're escaping that format.

Except now, we just strip out the HTML and don't escape it, due to `$message = PlainTextOutput::renderFromHtml($exception->getMessage());`. Similar cases of that are in \Drupal\jsonapi\Normalizer\UnprocessableHttpEntityExceptionNormalizer::buildErrorObjects and \Drupal\rest\Plugin\rest\resource\EntityResourceValidationTrait::validate().

Should we just add that word to the exception list? Or somehow handle it differently? We could change the test to add a space in front of

We should then also update the comment above that change, because that talks about escaped HTML that is no longer there.

Just a basic reroll for now.

Just cleaning up the default displayed patches to the working D8 and D9 versions. #52 and #56 no longer apply to 9.1.10 -- #58 applies and continues to work.

Another reroll for 9.3, question in #58 remains.

+++ b/core/tests/Drupal/KernelTests/Core/Routing/ExceptionHandlingTest.php
@@ -199,7 +212,7 @@ public function testExceptionEscaping() {
-    $this->assertStringStartsWith('The website encountered an unexpected error. Please try again later.<br><br><em class="placeholder">Symfony\Component\HttpKernel\Exception\NotAcceptableHttpException</em>: Not acceptable format: json&lt;script&gt;alert(123);&lt;/script&gt; in <em class="placeholder">', $response->getContent());
+    $this->assertStringStartsWith('Not acceptable format: jsonalert(123);', $response->getContent());

Add a comment

// cspell:ignore jsonalert

before the assertion and then this spelling error will only be ignored here.

Addressing comment #61.

The patch fixes the fatal error issue.

I am however wondering why we are not simply ignoring unknown query parameters/values?
In several places in core where the "_format" parameter is handled there is comment indicating that the "html" value should be the default.
With that information I would assume it would be more logical to fallback to HTML when an unknown value is encountered?
Or to just completely ignore unknown query parameter/values, that would then also fallback to html.

What is the advantage of showing a custom error page instead?

This patch has logic to potentially make it a cacheable response, but I'm wondering what a site would have to do to make it actually cacheable, as it wasn't in my testing, i.e. adding _format=something is a reliable way to bypass the page cache and proxy cache.

I think the logic for that is just copied. For the 406 errors to be cacheable, \Drupal\Core\Routing\RequestFormatRouteFilter::filter() would need to throw a cacheable http exception, which feels like a different issue.

ok, and for posterity, looks like there are a couple other places where a cacheable http exception would need to be thrown - \Drupal\Core\EventSubscriber\RenderArrayNonHtmlSubscriber::onRespond() and \Drupal\Core\Routing\Enhancer\ParamConversionEnhancer::onException()

Reroll for D10.

Re #63: That too is a different issue. This isn't about whether or not core should throw such errors, it's how to handle them if it happens, and they are a valid HTTP response. As for _format throwing an exception on invalid values, that kind of makes sense as the client would expect a certain format and not returning in that would likely cause the client to fail.

1. +++ b/core/lib/Drupal/Core/EventSubscriber/FinalExceptionSubscriber.php
   @@ -138,10 +141,39 @@ public function onException(ExceptionEvent $event) {
   +  public function on4xx(ExceptionEvent $event) {
   +    $exception = $event->getThrowable();
   +    if ($exception && $exception instanceof HttpExceptionInterface && substr($exception->getStatusCode(), 0, 1) === '4') {
   +      $message = PlainTextOutput::renderFromHtml($exception->getMessage());
   

   Can this be str_starts_with() now we require PHP 8.1?

2. +++ b/core/tests/Drupal/KernelTests/Core/Routing/ExceptionHandlingTest.php
   @@ -42,6 +42,19 @@ public function test405() {
    
   +  /**
   +   * Tests on a route with a non-supported _format parameter.
   +   */
   

   Should this say "Tests a route"?

Overall looks good to me though.

Attaching #70 patch with updates from #71 review.

Can the issue summary be updated please? Mentions Drupal 8 are the steps still the same for D10?
What was the proposed solution?
Any remaining tasks?
etc.

I have updated the issue description with the standard template. Hope that helps!

So if the node exists I get

Not acceptable format: hal_json

If the node doesn't exist I get

The "node" parameter was not converted for the path "/node/{node}" (route name: "entity.node.canonical")

Is that expected?

Yes. See #45 from @alexpott --

@slip I think using the messages in \Drupal\system\Controller\Http4xxController is a very good idea. Those messages are indeed way better than The website encountered an unexpected error. Please try again later.

Ah thanks for the follow up!

Then I don't see any issue on this.

Committed 92fcdbf and pushed to 10.1.x. Thanks!

Debating whether to backport this due to the new event subscriber, it should not break anything and seems unlikely someone would have registered a competing exception subscriber, but since this is just improving an error message, going to leave it in 10.1.x - however if you've got strong objections re-open and we can probably backport with a change record.