Problem/Motivation

I've spent too many hours debugging that LogicException and finding the root cause now, so I thought it's time to open this issue.

Finding the root cause for that is very hard and frustrating, and there really isn't a good reason to die hard, since all the information is there that we need, it's just not done 100% properly.

To give some ideas what I had to do:
* In Monitoring in a rest service, I'm calling hook_requirements() and because system_requirements() creates a URL for the cron link, I have to add 10+ lines of code to execute it in my own render execution wrapper. I've also helped 2+ people in IRC that did run into similar problems
* In a payment response processing, I'm saving a node, that node is indexed by search API, and then the solr backend generates a URL to figure out the current domain, so it can index for that. I couldn't care less what it does there, but it completely breaks my page and I have no way of fixing that except changing search_api_solr or executing my node save in such a render execution wrapper.

The exception does not give *any* information about what the missing cacheability it is, where it is coming from and how to fix it. You need to debug that yourself, for example by figuring out what max-age/context/tag bubbled up and then break on Cache::merge*() or similar places and then backtracking. Not many developers will figure that out, you need to know lots of internal stuff.

Also, all the required information *is* present, and for render arrays, we happy accept it and move on, only in case of Response objects, we die with an exception.

Workaround

- See change record All rendering must happen in a render context, early rendering's metadata no longer lost
- #19
- #20
- Matt Oliveira @ https://www.lullabot.com/articles/early-rendering-a-lesson-in-debugging-...
-#33
-#47

Proposed resolution

Remove the exception, just add the cacheability metadata, or ignore it with a warning log message or so if that's not possible.

And if the response object is *not* cacheable, then the exception is completely pointless anyway. This is also related to #2626298: REST module must cache only responses to GET requests and would fix that in a more generic way.

Maybe we could introduce some sort of check again later, as an assert or so.

Remaining tasks

User interface changes

API changes

Data model changes

Issue fork drupal-2638686

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

Comments

Berdir created an issue. See original summary.

dawehner’s picture

So yeah instead of the exception we could maybe provide some logging or warning, which at least doesn't have any runtime potential breakage.

* In Monitoring in a rest service, I'm calling hook_requirements() and because system_requirements() creates a URL for the cron link, I have to add 10+ lines of code to execute it in my own render execution wrapper. I've also helped 2+ people in IRC that did run into similar problems

For some reasons I even had issues generating some URL in tests, which is, pretty crazy, to say the least.

In general we need a general improvement of the DX of the non trivial bits of the rendering layer.

wim leers’s picture


The problem described in #2626298: REST module must cache only responses to GET requests, which can be generalized to sending an e-mail from any random place in the code should not trigger exceptions just points to plain sloppiness in code. It doesn't make sense to do blocking I/O very very deep in function call stacks. E-mails should be generated and sent in a queue/job runner/batch/cron job/something that does it outside of the request/response flow. And if you really want to do that, then you just have to wrap the sending of an e-mail in a render context.


* In Monitoring in a rest service, I'm calling hook_requirements() and because system_requirements() creates a URL for the cron link, I have to add 10+ lines of code to execute it in my own render execution wrapper. I've also helped 2+ people in IRC that did run into similar problems

Well, yes, if you're calling hooks, and particularly hooks that are full of legacy code, then you indeed need to execute it in its own render context. Those hook implementations rely on global state. If they had their dependencies injected, state/context isolated, this would not be necessary. So, yes, when you need to call poorly written code from your controller, it's better to execute that in its own render context.
The exception is only thrown in the first place if the response meets this condition: $response instanceof AttachmentsInterface || $response instanceof CacheableResponseInterface || $response instanceof CacheableDependencyInterface. Which means it's capable of having cacheability metadata. Which means it may be cached. Which means that if it includes the return value of hook_requirements(), that the response may need to vary by the cache context that the hook_requirements() invocation bubbled. Otherwise you'll get incorrect results.

Yes, all of this is annoying. Yes, I wish we wouldn't have this wrapper. But it's there for correctness.

* In a payment response processing, I'm saving a node, that node is indexed by search API, and then the solr backend generates a URL to figure out the current domain, so it can index for that. I couldn't care less what it does there, but it completely breaks my page and I have no way of fixing that except changing search_api_solr or executing my node save in such a render execution wrapper.

It seems fishy to me that reindexing for search is happening in the same request. It appears that should also be done out-of-band, i.e. through some queue/cron job/…. And if not, then yes, it should be wrapped in a render context.


All of these examples share one theme: they are about doing things other than creating a response, that happen to be triggered due to historical architectural choices.

I totally agree it's annoying. I totally agree it's unfortunate. I totally wish it could've been avoided. But this was necessary for correctness.

Therefore, I very strongly disagree with:

Remove the exception, just add the cacheability metadata, or ignore it with a warning log message or so if that's not possible.

… but I'd be happy to improve the exception message or help the developer in some other way with tracking down the root cause.

wim leers’s picture

Berdir replied in IRC:

<berdir> WimLeers: I don't get it. You have the render context there. And you *have* the cacheability metadata available. Why not just use it? We are relying on the fact that we *can* catch that metadata there. If we couldn't, we also couldn't detect that something is missing

See:

berdir’s picture

I've read those, but I still don't agree with the conclusion there :)

* You said "The quoted part means that controllers returning Response objects — which did not exist in D7, so there is no actual transition easing there — would be allowed to be equally messy as render arrays.". Just because there are no Response objects in D7 doesn't mean that there is code that doesn't conceptually the same (by simply printing out the response) and has to be ported to D8 by using a response object.
* As a result of that, there is plenty of legacy code being called that then results in Response objects. It's not like that's all fancy new code that you can actually do anything about.
* REST plugins for example have no way of opting out from caching since the one and only class implements CacheableResponse and its usage is hardcoded, no interface.
* As said, at least for POST and other uncacheable responses, this really is pointless because nothing will be cached. Ever. I thought we already discussed and agreed on that part in Barcelona?
* Your feedback re when to send mails and indexing is not very realistic :) We can't change how those mails are sent. For indexing, in many cases yes, but sometimes you need it to be indexed asap. search_api experimented a lot with queues and delayed indexing and AFAIK eventually gave up on those things (for immediate index).
* In that other issue, you just talked about drupal_render(). That's one thing. If it's your own code, then you can just use renderPlain() and then we can't even detect anymore if you're doing it wrong. If it's not your own code then it's already harder. But the real problem and source for pretty much all my examples is actually generating URL's. Even if you can fix the code with those URL's, the workaround is pretty arcane and requires you to trick the system: You claim to handle cacheability metadata yourself but then ignore it.
* Fabianx in #115 there says "Any such advanced controller can easily do" in regards to executing something in a render context. But it really isn't that easy. And the exception doesn't mention it. As I said, It took me a long time find out the root cause for both the monitoring and payment examples and find an appropriate workaround. And if it takes me hours to resolve something, then I really don't want to think about how it will be for less experienced developers.
* I'm also not sure I buy the "When returning a response object, it's the final thing that we don't change/alter anymore". We do that in many places. We ignore redirect responses if a ?destination is given, FinishResponseSubscriber is doing all kinds of cache-related changes on response objects, AnonymousUserResponseSubscriber adds cacheable metadata and more. Why do all those things but not this? As you said yourself: If you return a CacheableResponse then you opt in to the default caching behaviors/logic. Only if you don't, then we don't change your response for cache-related things.

To summarize, I think the current behavior ignores the reality of our current code/situation and what you can and can't fix as a developer. If the exception would be helpful and tell you what to do, then it might be OK. But the current exception message is really useless :)

Which is why I still think we should change it.

Version: 8.0.x-dev » 8.1.x-dev

Drupal 8.0.6 was released on April 6 and is the final bugfix release for the Drupal 8.0.x series. Drupal 8.0.x will not receive any further development aside from security fixes. Drupal 8.1.0-rc1 is now available and sites should prepare to update to 8.1.0.

Bug reports should be targeted against the 8.1.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.2.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

dawehner’s picture

I totally agree that this is a MAJOR pain point. Not necessarily for core/contrib development but for actual sites and custom code. Its so easy to have leaking of metadata that you don't even see where this is coming from, especially because enabling a module can cause code to start leaking metadata. For example every node_access module causes additional leaking via #2729137: NodeStorage::loadByProperties should avoid adding node access query tags for example.

Something like

In order to debug the problem, first figure out which cache contexts/tags are added to $early_rendering_bubbleable_metadata.
The next step is to figure out which code adds those. Therefore look at the backtrace in \Drupal\Core\Render\RenderContext::update. For better experience, just look at the backtraces which include your leaking cache contexts / tags.

this would help everyone to at least get started.

catch’s picture

I think to start with should trigger_error() here rather than throw an exception. This happens due to interactions between code which might work independently when being developed, but not when combined on a site, with #2729137: NodeStorage::loadByProperties should avoid adding node access query tags being a good example.

damiankloip’s picture

I also ran into the same problem recently, and yes, rather painful to debug. During a POST request too.

...just points to plain sloppiness in code. It doesn't make sense to do blocking I/O very very deep in function call stacks. E-mails should be generated and sent in a queue/job runner/batch/cron job/something that does it outside of the request/response flow

It's totally feasible that someone would just send an email after some action during a request. Not all sites will be implementing queues and such. It is certainly not necessarily indicative of 'sloppiness' in code. Doing stuff like this has not been a problem for years. I don't think anyone would assume this would cause a problem with their response.

I agree with berdir here. Assuming that we will only ever be doing things to do with generating the response is unrealistic.

Could this be mitigated by doing things like e.g. executing mail() calls inside their own render context? Conceptually it's questionable but it seems like that ship has sailed and the DX tradeoff is worth it.

berdir’s picture

Could this be mitigated by doing things like e.g. executing mail() calls inside their own render context? Conceptually it's questionable but it seems like that ship has sailed and the DX tradeoff is worth it.

Not questionable at all IMHO: #2663270: MailManager::mail() should run inside its own render context: it sends e-mails, not (cacheable) responses

Forgot to add that as a related issue. Together with #2663638: Avoid checking the render context to detect early rendering for Non-GET requests. and #2626298: REST module must cache only responses to GET requests, we can cover many problematic cases (in fact, the rest user save problem that was the reasion for creating the now fixed REST/GET issue would be fixed by any of them.

It doesn't cover everything yet, #2729137: NodeStorage::loadByProperties should avoid adding node access query tags is an example for that. trigger_error() sounds like an improvement to me as well, but only if we can also actually provide more information. A trigger_error() that is as hard to resolve as the exception isn't really an improvement, it will just fill up logs.

This happens due to interactions between code which might work independently when being developed, but not when combined on a site, with #2729137: NodeStorage::loadByProperties should avoid adding node access query tags being a good example.

Yes, this!

damiankloip’s picture

I had a feeling there might already be an issue like that, thanks berdir.

catch’s picture

#2744715: Generated URLs should only have cache contexts on GET/HEAD.

URL generation had a rocky ride during 8.x to say the least, one aspect of which was its relationship to the render system in general.

There are not that many places we added cacheability metadata implicitly, so one or two more patches like this ought to cut things down a lot.

Version: 8.1.x-dev » 8.2.x-dev

Drupal 8.1.9 was released on September 7 and is the final bugfix release for the Drupal 8.1.x series. Drupal 8.1.x will not receive any further development aside from security fixes. Drupal 8.2.0-rc1 is now available and sites should prepare to upgrade to 8.2.0.

Bug reports should be targeted against the 8.2.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.3.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

Version: 8.2.x-dev » 8.3.x-dev

Drupal 8.2.6 was released on February 1, 2017 and is the final full bugfix release for the Drupal 8.2.x series. Drupal 8.2.x will not receive any further development aside from critical and security fixes. Sites should prepare to update to 8.3.0 on April 5, 2017. (Drupal 8.3.0-alpha1 is available for testing.)

Bug reports should be targeted against the 8.3.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.4.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

skyredwang’s picture

I also ran into this problem. Same situation. I was confused that there was one debugging hint a 'url.site' was added to the cache context. Then, I read #12, and commented out my URI related generation feature, and the problem was gone.

Version: 8.3.x-dev » 8.4.x-dev

Drupal 8.3.6 was released on August 2, 2017 and is the final full bugfix release for the Drupal 8.3.x series. Drupal 8.3.x will not receive any further development aside from critical and security fixes. Sites should prepare to update to 8.4.0 on October 4, 2017. (Drupal 8.4.0-alpha1 is available for testing.)

Bug reports should be targeted against the 8.4.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.5.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

grasmash’s picture

Can you reference an example snippet where you do the following?

the workaround is pretty arcane and requires you to trick the system: You claim to handle cacheability metadata yourself but then ignore it.

grasmash’s picture

This workaround was effective:

   $options['absolute'] = TRUE;
    $url = $this->getUrlGenerator()->generateFromRoute('entity.node.canonical', ['node' => $nid], $options, TRUE);
    $response = new CacheableRedirectResponse($url->getGeneratedUrl());
ohthehugemanatee’s picture

Happened to me in a controller where I used the output of Entity::toUrl in building a redirect. I agree with @berdir: the biggest problem here is the unhelpful message! Secondarily, it doesn't make any sense to fatal on a recoverable problem. This should be a warning level log message IMO. +1 for trigger_error .

For anyone running into this again: you are receiving this fatal because you use a method which counts as rendering, without adding its cache metadata to the render context. The common case (that I keep bumping into, at least), is if you're generating a Url string somewhere. Rendering a Url counts as rendering, and has cache metadata that you should preserve. Instead of:

    $url = $node->toUrl()->toString();

Use:

    $url = $node->toUrl()->toString(TRUE);
    // The generated URL string, as before.
    $url_string = $url->getGeneratedUrl();
    // Add the $url object as a dependency of whatever you're returning. Probably a response.
   $response = new CacheableResponse($url_string, Response::HTTP_OK);
   $response->addCacheableDependency($url);
   return $response;

Or if you're doing something that's uncacheable anyways, just passing TRUE to toString() claims that you're handling the metadata, and will stop the error. So technically $node->toUrl()->toString(TRUE)->getGeneratedUrl() is enough.

mikejw’s picture

I had an issue from calling normalize on an entity. Current fix I am using is to wrap it ala other patches (posting for #lazyweb):

    $data = $this->renderer->executeInRenderContext(new RenderContext(), function () use ($user) {
      return $this->serializer->normalize($user);
    });

Version: 8.4.x-dev » 8.5.x-dev

Drupal 8.4.4 was released on January 3, 2018 and is the final full bugfix release for the Drupal 8.4.x series. Drupal 8.4.x will not receive any further development aside from critical and security fixes. Sites should prepare to update to 8.5.0 on March 7, 2018. (Drupal 8.5.0-alpha1 is available for testing.)

Bug reports should be targeted against the 8.5.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.6.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

gogowitsch’s picture

Issue summary: View changes
mstills’s picture

Ran into this same issue because we were generating image style URLs as part of a function that was being called to assemble a much larger JSON response. It was extremely time consuming to track down due to the unhelpful error message. Solutions on Stack Overflow that mention the error will not work in general. The only workaround that was viable for our situation without having to do a massive amount of refactoring was already suggested in #20 - using another render context. Unsure of the performance implications of doing this any time we need to generate a URL

A better error message could at least help people determine what needs to be done in a separate render context without having to trace through dozens and dozens of core classes. Is this issue still getting any attention?

mxh’s picture

Due to the growing trend of decoupled web apps, I guess this issue is increasing in its relevance, as more developers might try to build a "simple" controller delivering some rendered content as Json feeds. I guess there's more documentation needed, both regards that exception mentioned here and how to properly build Json feed controllers (yep, devs might still want to write their own).

mpp’s picture

Hi @Berdir, I assume you still prefer to remove the exception alltogether or would #12 make sense to fix these issues?

Referencing another issue that seems to be related: RedirectDestination->getAsArray()/get() leaks cacheablity metadata.

davidwhthomas’s picture

This error is probably the biggest DX pain for me at the moment, quite obtuse error msg and takes hours to debug and fix.
Currently have this problem loading a comment in a REST response, but only if the comment has a parent comment...
Doesn't help adding cache tags for both the comment and the parent comment, I guess something else related to the render, probably url...
Would be nice if this could be fixed!

Version: 8.5.x-dev » 8.6.x-dev

Drupal 8.5.6 was released on August 1, 2018 and is the final bugfix release for the Drupal 8.5.x series. Drupal 8.5.x will not receive any further development aside from security fixes. Sites should prepare to update to 8.6.0 on September 5, 2018. (Drupal 8.6.0-rc1 is available for testing.)

Bug reports should be targeted against the 8.6.x-dev branch from now on, and new development or disruptive changes should be targeted against the 8.7.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

clemens.tolboom’s picture

Issue summary: View changes

Added workaround section adding #19 and #20 plus the excellent debug/workaround blog by Matt Oliveira https://www.lullabot.com/articles/early-rendering-a-lesson-in-debugging-...

roderik’s picture

g.jordan’s picture

How do you workaround this issue when POSTing to the JSON:API from outside applications? Anytime I POST to a route like /jsonapi/{node}/*, I get this error. The POST is successful, but the error is logged. I'm POSTing and PATCHing 1000s of nodes nightly, so it's unacceptable to wake up to a 3.5 gigabyte log every morning.

roderik’s picture

g.jordan[]uky.edu - at the moment, you can only fix the issue by fixing whatever code is responsible for indirectly generating the error.

davidwhthomas - do you still get this error? I can match your description about parent comment, to code I see in rdf_comment_storage_load() and which I've probably addressed in #2335487: Remove the multiple comment optimization from rdf.module. I can't get core to throw the exception by itself, so I am guessing you have custom code doing this. If you can create a test (or alternatively upload a stripped-down version of your controller which I could make into a test) to contribute to that issue... it has a better chance of going RTBC.

blainelang’s picture

I have a custom REST endpoint that's creates a couple content nodes and then returns a very basic response but I am now getting this error. I had this part of the project working a month ago and I would have done a Drupal 8 core update since then so I'm thinking there was a core change that now does not like my REST Response.

$response_status = ['status' => 200];
$response = new ResourceResponse($response_status);
LogicException: The controller result claims to be providing relevant cache metadata, but leaked metadata was detected. Please ensure you are not rendering content too early. Returned object class: Drupal\rest\ResourceResponse. in Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->wrapControllerExecutionInRenderContext() (line 154 of /home/onlinetech/public_html/web/core/lib/Drupal/Core/EventSubscriber/EarlyRenderingControllerWrapperSubscriber.php).

I've checked and am not rendering anything in the code and even removed this code in case that was triggering a render internally with no change

    $url = Url::fromRoute('gbstudent-profile.edit', ['node' => $student_node->id()]);
    $token = \Drupal::csrfToken()->get($url->getInternalPath());

What should I be doing to return a basic array response?

blainelang’s picture

Well I found a solution but definitely went down the rabbit hole on this one. Another useful blog article was https://blog.dcycle.com/blog/2018-01-24/caching-drupal-8-rest-resource/ which was helpful but it also linked to other resources including https://spinningcode.org/2017/05/cached-json-responses-in-drupal-8 which is much closer to what I needed.

In the end this was all I needed

use ...
use Drupal\Core\Cache\CacheableJsonResponse;

class StudentRegisterResource extends ResourceBase {

     .. other methods as needed

    public function post($post_data) {
     $context = new RenderContext();
     $response_with_context = \Drupal::service('renderer')->executeInRenderContext($context, function () use ($post_data) {
           ..... code that creates multiple nodes based on $post_date from remote application

           // Prepare response 
           $response_status = [
               'status' => 200,
               'student_id' => $student_node->id(),
                'confirmation_access_token' => $token,
            ];

            return $response_status;
      }

     $response = CacheableJsonResponse::create($response_with_context);
     return $response;
   }
}
clemens.tolboom’s picture

kfritsche’s picture

As we having a similar problem then discussed in the last comments I created now a follow up ticket (#3080634: Catch EarlyRendering Exception for REST-Resources) for REST calls explicitly (extending ResourceBase), as this seems a special pain point there.

With the attached patch there its not need anymore to always wrap everything around executeInRenderContext().

hchonov’s picture

This might be a very stupid question, but why instead of throwing an exception we don't retrieve the cacheable metadata from the context and add it to the response before returning it? Wouldn't that let the page and the dynamic page cache to properly cache the response?

According to the change record 2513810 All rendering must happen in a render context, early rendering's metadata no longer lostthis should be possible automatically, but we want that

Since you're returning responses, you want to fully control what is sent, so you should also be a responsible citizen and not do any early rendering.

But it looks like there are cases where it is not possible to prevent early rendering and one cannot really add a wrapper around so many places where this could happen like the one described in #3080634: Catch EarlyRendering Exception for REST-Resources:

Doing a query which is altered, which adds a cache context (see node_query_node_access_alter)

garphy’s picture

Version: 8.6.x-dev » 8.8.x-dev
StatusFileSize
new996 bytes

From #36 :

This might be a very stupid question, but why instead of throwing an exception we don't retrieve the cacheable metadata from the context and add it to the response before returning it? Wouldn't that let the page and the dynamic page cache to properly cache the response?

I also thought of that lately, wondering why it's not the case. I hope it's not a so stupid suggestion so I decided to take that route (for CacheableResponseInterface in my case as it is in JSON:API use case).
I'm hoping it'll solves issues related to the combined use of advanced node permission (i.e. node access records & grants) alongside JSON:API which is currently kinda broken. (see #3077302: JSON:API Logic exception caused by leaked metadata, #3040603: QueryAccessHandlerBase should document a workaround for leaking metadata, #3028976: Enable an entity query's return value to carry cacheability & possibly others)

Here's a patch in case you want to try it out.

garphy’s picture

Instead of the patch in #37, which was a quick & dirty attempt to find a workaround to be able to "go live" on some of our projects, I came up with an independent contrib which does the same thing without hacking the core.
It's a more elegant way of solving the issue for most of our JSON:API based decoupled project (YMMV) while preserving the conservative behavior of the core.

https://www.drupal.org/project/jsonapi_earlyrendering_workaround

Version: 8.8.x-dev » 8.9.x-dev

Drupal 8.8.0-alpha1 will be released the week of October 14th, 2019, which means new developments and disruptive changes should now be targeted against the 8.9.x-dev branch. (Any changes to 8.9.x will also be committed to 9.0.x in preparation for Drupal 9’s release, but some changes like significant feature additions will be deferred to 9.1.x.). For more information see the Drupal 8 and 9 minor version schedule and the Allowed changes during the Drupal 8 and 9 release cycles.

lexsoft00’s picture

Hi @garphy,

Thank you ever so much for the module workaround. It works for me.
Drupal Version
8.7.8

Version: 8.9.x-dev » 9.1.x-dev

Drupal 8.9.0-beta1 was released on March 20, 2020. 8.9.x is the final, long-term support (LTS) minor release of Drupal 8, which means new developments and disruptive changes should now be targeted against the 9.1.x-dev branch. For more information see the Drupal 8 and 9 minor version schedule and the Allowed changes during the Drupal 8 and 9 release cycles.

narendra.rajwar27’s picture

@garphy, awesome... patch solution works for me in drupal8.9.3... but patch was not applied.
I was facing issue while creating node of a particular content type via JSON:API, for that content type there was some playaround with drupal cache tags.

For other content type JSON:API was working fine while creating node.
Thanks a lot..!!!!

Error was:

"title": "Internal Server Error",
            "status": "500",
            "detail": "The controller result claims to be providing relevant cache metadata, but leaked metadata was detected. Please ensure you are not rendering content too early. Returned object class: Drupal\\jsonapi\\ResourceResponse.",

More detailed:
"exception": "LogicException: The controller result claims to be providing relevant cache metadata, but leaked metadata was detected. Please ensure you are not rendering content too early. Returned object class: Drupal\\jsonapi\\ResourceResponse. in {{project}}/core/lib/Drupal/Core/EventSubscriber/EarlyRenderingControllerWrapperSubscriber.php:154\nStack trace:\n#0 {{project}}/core/lib/Drupal/Core/EventSubscriber/EarlyRenderingControllerWrapperSubscriber.php(97): Drupal\\Core\\EventSubscriber\\EarlyRenderingControllerWrapperSubscriber->wrapControllerExecutionInRenderContext(Array, Array)\n#1 {{project}}/vendor/symfony/http-kernel/HttpKernel.php(151): Drupal\\Core\\EventSubscriber\\EarlyRenderingControllerWrapperSubscriber->Drupal\\Core\\EventSubscriber\\{closure}()\n#2 {{project}}/vendor/symfony/http-kernel/HttpKernel.php(68): Symfony\\Component\\HttpKernel\\HttpKernel->handleRaw(Object(Symfony\\Component\\HttpFoundation\\Request), 1)\n#3 {{project}}/core/lib/Drupal/Core/StackMiddleware/Session.php(57): Symfony\\Component\\HttpKernel\\HttpKernel->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#4 {{project}}/core/lib/Drupal/Core/StackMiddleware/KernelPreHandle.php(47): Drupal\\Core\\StackMiddleware\\Session->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#5 {{project}}/core/modules/page_cache/src/StackMiddleware/PageCache.php(106): Drupal\\Core\\StackMiddleware\\KernelPreHandle->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#6 {{project}}/core/modules/page_cache/src/StackMiddleware/PageCache.php(85): Drupal\\page_cache\\StackMiddleware\\PageCache->pass(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#7 {{project}}/core/lib/Drupal/Core/StackMiddleware/ReverseProxyMiddleware.php(47): Drupal\\page_cache\\StackMiddleware\\PageCache->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#8 {{project}}/core/lib/Drupal/Core/StackMiddleware/NegotiationMiddleware.php(52): Drupal\\Core\\StackMiddleware\\ReverseProxyMiddleware->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#9 {{project}}/vendor/stack/builder/src/Stack/StackedHttpKernel.php(23): Drupal\\Core\\StackMiddleware\\NegotiationMiddleware->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#10 {{project}}/core/lib/Drupal/Core/DrupalKernel.php(708): Stack\\StackedHttpKernel->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#11 {{project}}/index.php(19): Drupal\\Core\\DrupalKernel->handle(Object(Symfony\\Component\\HttpFoundation\\Request))\n#12 {main}\n\nNext Symfony\\Component\\HttpKernel\\Exception\\HttpException: The controller result claims to be providing relevant cache metadata, but leaked metadata was detected. Please ensure you are not rendering content too early. Returned object class: Drupal\\jsonapi\\ResourceResponse. in {{project}}/core/modules/jsonapi/src/EventSubscriber/DefaultExceptionSubscriber.php:48\nStack trace:\n#0 [internal function]: Drupal\\jsonapi\\EventSubscriber\\DefaultExceptionSubscriber->onException(Object(Symfony\\Component\\HttpKernel\\Event\\GetResponseForExceptionEvent), 'kernel.exceptio...', Object(Drupal\\Component\\EventDispatcher\\ContainerAwareEventDispatcher))\n#1 {{project}}/core/lib/Drupal/Component/EventDispatcher/ContainerAwareEventDispatcher.php(111): call_user_func(Array, Object(Symfony\\Component\\HttpKernel\\Event\\GetResponseForExceptionEvent), 'kernel.exceptio...', Object(Drupal\\Component\\EventDispatcher\\ContainerAwareEventDispatcher))\n#2 {{project}}/vendor/symfony/http-kernel/HttpKernel.php(227): Drupal\\Component\\EventDispatcher\\ContainerAwareEventDispatcher->dispatch('kernel.exceptio...', Object(Symfony\\Component\\HttpKernel\\Event\\GetResponseForExceptionEvent))\n#3 {{project}}/vendor/symfony/http-kernel/HttpKernel.php(79): Symfony\\Component\\HttpKernel\\HttpKernel->handleException(Object(LogicException), Object(Symfony\\Component\\HttpFoundation\\Request), 1)\n#4 {{project}}/core/lib/Drupal/Core/StackMiddleware/Session.php(57): Symfony\\Component\\HttpKernel\\HttpKernel->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#5 {{project}}/core/lib/Drupal/Core/StackMiddleware/KernelPreHandle.php(47): Drupal\\Core\\StackMiddleware\\Session->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#6 {{project}}/core/modules/page_cache/src/StackMiddleware/PageCache.php(106): Drupal\\Core\\StackMiddleware\\KernelPreHandle->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#7 {{project}}/core/modules/page_cache/src/StackMiddleware/PageCache.php(85): Drupal\\page_cache\\StackMiddleware\\PageCache->pass(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#8 {{project}}/core/lib/Drupal/Core/StackMiddleware/ReverseProxyMiddleware.php(47): Drupal\\page_cache\\StackMiddleware\\PageCache->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#9 {{project}}/core/lib/Drupal/Core/StackMiddleware/NegotiationMiddleware.php(52): Drupal\\Core\\StackMiddleware\\ReverseProxyMiddleware->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#10 {{project}}/vendor/stack/builder/src/Stack/StackedHttpKernel.php(23): Drupal\\Core\\StackMiddleware\\NegotiationMiddleware->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#11 {{project}}/core/lib/Drupal/Core/DrupalKernel.php(708): Stack\\StackedHttpKernel->handle(Object(Symfony\\Component\\HttpFoundation\\Request), 1, true)\n#12 {{project}}/index.php(19): Drupal\\Core\\DrupalKernel->handle(Object(Symfony\\Component\\HttpFoundation\\Request))\n#13 {main}"

narendra.rajwar27’s picture

StatusFileSize
new992 bytes

Adding re-rolled patch from comment #37 for drupal 9.1.x

clemens.tolboom’s picture

Status: Active » Needs review
claudfernandes’s picture

#37 works for me, thanks for that

Version: 9.1.x-dev » 9.2.x-dev

Drupal 9.1.0-alpha1 will be released the week of October 19, 2020, which means new developments and disruptive changes should now be targeted for the 9.2.x-dev branch. For more information see the Drupal 9 minor version schedule and the Allowed changes during the Drupal 9 release cycle.

roderik’s picture

As a followup on generating URLs for responses:

Use:

    $url = $node->toUrl()->toString(TRUE);
    $url_string = $url->getGeneratedUrl();
    $response = new CacheableResponse($url_string, Response::HTTP_OK);
   (...)

I figured this would always be safe. As it turns out, even though the code itself is good, a toString() call can cause code in other modules to be invoked... which can do unsafe things.
Example: have content_moderation enabled, upgrade to Rules 8.x-3.0-alpha6 -> the above starts throwing the "early rendering" exception (because Rules does an Url::fromRoute(...)->toString() during your call to toString(TRUE), and leaks metadata). #3161036-6: CurrentPathContext inadvertently bubbles up 'route' cache context

This makes things more tedious: to fully protect against 'outside' code causing the exception, even all Url::from*() and Url::toString() calls need to be wrapped inside a render context.

For those interested: here's a method which executes a callable (i.e. any potentially-endangered code which you'd execute during a request) plus the URL generation, into a render context and returns a TrustedRedirectResponse: https://git.drupalcode.org/project/samlauth/blob/8.x-3.x/src/Controller/...
Call example:

  public function myRoute() {
    // The callable must return a Url object that will be used for the redirect.
    $function = function () {
      do_stuff();
      do_more_stuff();
      return Url::fromUri('http://i.want.to/redirect/here');
    };
    // Redirect to '<front>' displaying an error, if $function throws an exception.
    // (If left empty, no exception handling is done.)
    return $this->getTrustedRedirectResponse($function, 'executing myRoute', '<front>');
  }
roderik’s picture

Also, half related: just stumbled onto #2528598: Opt out of cacheablity protection on route level. (I wish I'd know of its existence years ago - I didn't know if it made sense to propose this myself.)

mxr576’s picture

Wow! The documentation in samlauth/blob/8.x-3.x/src/Controller/ExecuteInRenderContextTrait.php is very insightful and well-detailed. It is actual learning material :) Kudos to @roderik

roderik’s picture

Thanks :) All the info in the trait's code comments is from other sources (issue comments from Wim Leers/Berdir/Crell/..., the Lullabot article). But it's been quite a challenge to form an opinion on how different pain points relate, and which to highlight in a concise summary. (4 multi-day sessions between 2017 and now, so far. I respect that experienced core developers have had no time for this and needed to rush things to get Drupal 8 out the door - but... by now I also get that it hasn't been easy for anyone else to make progress on this.)

In case anyone's wondering why this is in a trait hidden away in a random contrib module, and not made into a patch on this issue: in my estimation, this issue is explicitly stalled since January 2016 / comment #4. The last few patches ignore the comments made around there.

(If I could put my own spin on making a short summary: the best single-comment summary for the rationale behind the current implementation is in #2450993-133: Rendered Cache Metadata created during the main controller request gets lost. Unfortunately, a large part of the points summarized (1, 3, 5) there is untrue. I assume that was harder to see in January 2016 but it's clear now - now that the remaining pain points are hidden behavior of Url::toString() calls, Drupal Core implicitly forcing developers to use cacheable responses in at least a subset of redirect responses, and lack of help/documentation pointing these things out.)

If anyone wants to form a mini initiative / task force around getting URL stuff resolved: feel free to contact me. I think this will need the following steps:

  • Talk to people behind the current implementation, outside of the issue queues, to make sure we have an overview of the whole scope and buy-in on plans. Because several related issues haven't seen real action since 2016 and we don't want to start producing work that goes against / will be stalled by other goals we don't know about. Or that won't get reviewed/committed.
  • Probably: fall into a swamp of interconnected issues we weren't fully aware of.
  • Gather thoughts; set goals/scope.

My own idea for a minimum scope to work on, is to get clarifying help text into Url::toString() and/or other places in documentation, making people aware of the risks of outputting URLs. (Because we're not doing that, thereby letting people introduce new fatal bugs unwittingly.) Last time I set that goal was February 2019, which devolved into working on #2735575-66: Make Url::toString(TRUE) explicit by having a Url::generate() method, as well as having GeneratedUrl::toString for more than a month and then being distracted by other things. Now, after spending time on building that new trait with fresh thoughts... I'll de-prioritize this again for a while... unless other people want to join forces.

Version: 9.2.x-dev » 9.3.x-dev

Drupal 9.2.0-alpha1 will be released the week of May 3, 2021, which means new developments and disruptive changes should now be targeted for the 9.3.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

Version: 9.3.x-dev » 9.4.x-dev

Drupal 9.3.0-rc1 was released on November 26, 2021, which means new developments and disruptive changes should now be targeted for the 9.4.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

loziju made their first commit to this issue’s fork.

Version: 9.4.x-dev » 9.5.x-dev

Drupal 9.4.0-alpha1 was released on May 6, 2022, which means new developments and disruptive changes should now be targeted for the 9.5.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

proweb.ua’s picture

#43 works

wombatbuddy’s picture

The patch #43 does the job.

kasperbasse91’s picture

#43 works

bradjones1’s picture

Is anyone at DrupalCon Europe/Prague (2022) interested in discussing #50?

Version: 9.5.x-dev » 10.1.x-dev

Drupal 9.5.0-beta2 and Drupal 10.0.0-beta2 were released on September 29, 2022, which means new developments and disruptive changes should now be targeted for the 10.1.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

smustgrave’s picture

Status: Needs review » Needs work
Issue tags: +Needs Review Queue Initiative, +Needs tests

The last patch seemed to have failures. Which makes me think it will need it's own tests as it's breaking the existing ones.

Version: 10.1.x-dev » 11.x-dev

Drupal core is moving towards using a “main” branch. As an interim step, a new 11.x branch has been opened, as Drupal.org infrastructure cannot currently fully support a branch named main. New developments and disruptive changes should now be targeted for the 11.x branch, which currently accepts only minor-version allowed changes. For more information, see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

anisha786’s picture

Drupal :9.5.9

Module : Rest Block Layout

Issue when Api call /block-layout?_format=json&path=/test It is giving error Previously on drupal 8.7.5 it is working fine but after version updation it is giving error

Error Message
: LogicException: The controller result claims to be providing

relevant cache metadata, but leaked metadata was detected. Please
ensure you are not rendering content too early. Returned object class:
Drupal\rest\ResourceResponse. in
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->wrapControllerExecutionInRenderContext()
(line 158 of
\core\lib\Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber.php).
I have applied below #43 mentioned patch but from below patch error is gone , but in my website if user view multiple pages in separate tabs it is showing wrong node content data. It shows data which was latest cached.
. Let me know if anyone has solution how to fix it .

leksat’s picture

#43 still works 🎉 The nightmare is over for me 😅

damien laguerre’s picture

Idem, #43 solved my problem.
I'm experiencing this problem in a REST resource. The context user.node_grants:view throws this error.

solideogloria’s picture

Issue tags: -D8 cacheability +caching
solideogloria’s picture

Patch #43 still applies to 10.3.x. However, it should probably be converted to a merge request.

Also, the result after patching is this:

      elseif ($response instanceof CacheableResponseInterface) {
        $response->addCacheableDependency($early_rendering_bubbleable_metadata);
      }
      // If a non-Ajax Response or domain object is returned and it cares about
      // attachments or cacheability, then throw an exception: early rendering
      // is not permitted in that case. It is the developer's responsibility
      // to not use early rendering.
      elseif ($response instanceof AttachmentsInterface || $response instanceof CacheableResponseInterface || $response instanceof CacheableDependencyInterface) {
        throw new \LogicException(sprintf('The controller result claims to be providing relevant cache metadata, but leaked metadata was detected. Ensure you are not rendering content too early. Returned object class: %s.', get_class($response)));
      }

The || $response instanceof CacheableResponseInterface check should be removed from the second else-if shown.

solideogloria changed the visibility of the branch 2638686-exception-in-earlyrenderingcontrollerwrappersubscriber to hidden.

solideogloria’s picture

The new merge request targets 11.x and has the changes from patch #43, as well as the change I mentioned in #66.

solideogloria’s picture

Status: Needs work » Needs review
Issue tags: -Needs tests

I fixed the broken test. It just needed to be updated, since the code changes result in a success response instead of an HTTP 500.

This means that the changes have test coverage. All tests are passing successfully now.

solideogloria’s picture

Please review the changes and check whether the test coverage for early rendering needs to be expanded to handle more cases.

See EarlyRenderingControllerTest::testEarlyRendering. The changed test case is the one from lines 75-78

smustgrave changed the visibility of the branch 11.x to hidden.

smustgrave changed the visibility of the branch 10.3.x to hidden.

smustgrave changed the visibility of the branch 10.1.x to hidden.

smustgrave changed the visibility of the branch 10.2.x to hidden.

smustgrave’s picture

Status: Needs review » Reviewed & tested by the community

Hiding patches and empty branches

Ran test-only feature to confirm coverage

1) Drupal\Tests\system\Functional\Common\EarlyRenderingControllerTest::testEarlyRendering
Behat\Mink\Exception\ExpectationException: Current response status code is 500, but 200 expected.
/builds/issue/drupal-2638686/vendor/behat/mink/src/WebAssert.php:888
/builds/issue/drupal-2638686/vendor/behat/mink/src/WebAssert.php:145
/builds/issue/drupal-2638686/core/modules/system/tests/src/Functional/Common/EarlyRenderingControllerTest.php:76
/builds/issue/drupal-2638686/vendor/phpunit/phpunit/src/Framework/TestResult.php:729
ERRORS!
Tests: 1, Assertions: 27, Errors: 1.

believe the issue summary proposed solution lines up with moving the CacheableResponseInterface up to it's own check.

Believe this is good and has gotten a few comments about it working for others.

dww’s picture

I landed here chasing various things. For how long this issue has been open, how many comments, patches and effort went into this, I was amazed / shocked / delighted / heartbroken that the diffstat on the changes tab in the MR is: +7 / - 3. 😂 Thrilled to see it's actually RTBC at this point, and hopefully going to land soon. +1 to the RTBC. The code changes are great. The test change is that we now get to check for better outcomes to a common DX problem. 🚀 it!

Thanks,
-Derek

p.s. Starting to save credit. Could use a closer look before commit.

dww’s picture

Hate to ask, but do we need a change record for this?

quietone’s picture

Status: Reviewed & tested by the community » Needs work
Issue tags: +Needs title update

The title of this does not match what I read in the patch, it is not removing an exception. I went to improve that using information in the proposed resolution. However, that describes some options. So, I am sadly setting back to NW for a descriptive title and a tweak to the proposed resolution so that it what is being changed.

dww’s picture

Title: Exception in EarlyRenderingControllerWrapperSubscriber is a DX nightmare, remove it » Correctly handle cache data instead of throwing an Exception in EarlyRenderingControllerWrapperSubscriber()
Status: Needs work » Needs review
Issue tags: -Needs title update

I opened an MR thread to document how the diff is removing an exception. I'm a little sad to change the title at all, but how's this?

solideogloria’s picture

I think the new title is acceptable.

smustgrave’s picture

Status: Needs review » Reviewed & tested by the community

Title update seems good.

catch’s picture

Version: 11.x-dev » 10.3.x-dev
Status: Reviewed & tested by the community » Fixed

I reread this a fair bit.

I think given we have all the information here, and a way to apply it to the response, it's fine to do that and not throw the exception. As discussed in the issue, if we were able to inform developers at development time via an assertion or useful error message that stuff isn't being passed around correctly, that might be better, but there's no solution for this in several years now. The exception hitting on runtime with no obvious way to debug doesn't help anyone.

I wonder how many people will hit the remaining exception here, but I guess we'll find out whether that's an issue or not down the line.

Tried to do my best with issue credit but it's a very long issue so apologies if anyone was overlooked.

Committed/pushed to 11.x and cherry-picked to 10.3.x, thanks!

  • catch committed bd2add4c on 10.3.x
    Issue #2638686 by solideogloria, garphy, loziju, smustgrave, roderik,...

  • catch committed c0d8b4bb on 11.x
    Issue #2638686 by solideogloria, garphy, loziju, smustgrave, roderik,...

  • catch committed c0d8b4bb on 11.0.x
    Issue #2638686 by solideogloria, garphy, loziju, smustgrave, roderik,...

Status: Fixed » Closed (fixed)

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