Problem/Motivation

On my local site with render caching and dynamic page cache enabled, but page cache off - I'm seeing metatag_entity_view_alter take 8% of the page load time. Most of that is spent in _metatag_remove_duplicate_entity_tags

Proposed resolution

Profile and see if we can improve

Remaining tasks

User interface changes

API changes

Data model changes

Release notes snippet

Comments

larowlan created an issue. See original summary.

larowlan’s picture

Category: Bug report » Task
Status: Active » Needs review
StatusFileSize
new4.06 KB

A lot of the time is spent in token generation.

There is a static cache, so even if we don't generate these now, we're going to have to re-generate them later, but I wonder if those are cached in the page cache and these aren't because its running in a pre_render callback.

With this attached, metatag_entity_view_alter no longer shows up in my call stack

larowlan’s picture

StatusFileSize
new65.32 KB

With primed render cache, this no longer shows up at all.

Status: Needs review » Needs work

The last submitted patch, 2: 3039650.patch, failed testing. View results

larowlan’s picture

Issue tags: +D8 cacheability
larowlan’s picture

Assigned: Unassigned » larowlan

Will try to address the fails

larowlan’s picture

Status: Needs work » Needs review
StatusFileSize
new4.87 KB

ah, so there is a plugin id/name mismatch so we just need to map canonical url

larowlan’s picture

So I think perhaps something in token generation was resulting in the render caching being bypassed for the entity view.

Because with this patch, the entity view alter hook doesn't seem to run at all on a warmed cache, before it did

Status: Needs review » Needs work

The last submitted patch, 7: 3039650-2.patch, failed testing. View results
- codesniffer_fixes.patch Interdiff of automated coding standards fixes only.

larowlan’s picture

Status: Needs work » Needs review
StatusFileSize
new478 bytes
new4.78 KB
berdir’s picture

  1. +++ b/metatag.module
    @@ -234,25 +234,25 @@ function _metatag_remove_duplicate_entity_tags(array &$build) {
    +      $duplicates = array_intersect_key($name_map , $duplicates);
    +      foreach ($build['#attached']['html_head_link'] as $key => $item) {
    +        if (!$duplicates) {
    +          // We've found all items.
    +          return;
    

    why is the !duplicates check inside the foreach?

  2. +++ b/metatag.module
    @@ -415,18 +415,27 @@ function metatag_preprocess_html(&$variables) {
    + * @param null $entity
    + *   Entity being viewed if appropriate.
    

    that doesn't seem right :) (null)

  3. +++ b/metatag.module
    @@ -415,18 +415,27 @@ function metatag_preprocess_html(&$variables) {
    -function metatag_get_tags_from_route($entity = NULL) {
    +function _metatag_get_metatag_info_from_route($entity = NULL, array &$context = []) {
    +  $metatags = &drupal_static(__FUNCTION__);
    +  if (!is_null($metatags)) {
    +    return $metatags;
    +  }
    

    this gets $entity and $context, but the static cache doesn't consider those arguments.

    Also, isn't renaming this function a BC break?

  4. +++ b/metatag.module
    @@ -452,7 +461,27 @@ function metatag_get_tags_from_route($entity = NULL) {
    +/**
    + * Load the meta tags by processing the route parameters.
    + *
    + * @return mixed
    + *   Array of meta tags or NULL.
    + */
    +function metatag_get_tags_from_route($entity = NULL) {
    +  $metatag_manager = \Drupal::service('metatag.manager');
    

    Ah, the old function is readed down here, that's a bit confusing, can we move this up to have an easier to read patch?

  5. +++ b/metatag.module
    @@ -452,7 +461,27 @@ function metatag_get_tags_from_route($entity = NULL) {
    +  $context = [
    +    'entity' => &$entity,
    +  ];
    +  $metatags = _metatag_get_metatag_info_from_route($entity, $context);
    

    this seems like a pretty strange API, entity is passed in twice?

wim leers’s picture

With primed render cache, this no longer shows up at all.

🥳

So I think perhaps something in token generation was resulting in the render caching being bypassed for the entity view.

That's a very good hunch!!! See #2525910: Ensure token replacements have cacheability + attachments metadata and that it is bubbled in any case. That added

   * @param \Drupal\Core\Render\BubbleableMetadata|null $bubbleable_metadata
   *   (optional) An object to which static::generate() and the hooks and
   *   functions that it invokes will add their required bubbleable metadata.
   *
   *   To ensure that the metadata associated with the token replacements gets
   *   attached to the same render array that contains the token-replaced text,
   *   callers of this method are encouraged to pass in a BubbleableMetadata
   *   object and apply it to the corresponding render array. For example:
   *   @code
   *     $bubbleable_metadata = new BubbleableMetadata();
   *     $build['#markup'] = $token_service->replace('Tokens: [node:nid] [current-user:uid]', ['node' => $node], [], $bubbleable_metadata);
   *     $bubbleable_metadata->applyTo($build);
   *   @endcode
   *
   *   When the caller does not pass in a BubbleableMetadata object, this
   *   method creates a local one, and applies the collected metadata to the
   *   Renderer's currently active render context.
…
    // If a local $bubbleable_metadata object was created, apply the metadata
    // it collected to the renderer's currently active render context.
    if (!$bubbleable_metadata_is_passed_in && $this->renderer->hasRenderContext()) {
      $build = [];
      $bubbleable_metadata->applyTo($build);
      $this->renderer->render($build);
    }

to \Drupal\Core\Utility\Token::replace(), and as you can see, it automatically bubbles the cacheability to the global render context if the optional parameter is not provided.

And … \Drupal\metatag\MetatagManager::generateRawElements() does not provide it:

        $processed_value = PlainTextOutput::renderFromHtml(htmlspecialchars_decode($this->tokenService->replace($tag->value(), $token_replacements, ['langcode' => $langcode])));

Except that $this->tokenService is not \Drupal\Core\Utility\Token, but \Drupal\metatag\MetatagToken, but that's effectively just a decorator:

  public function replace($string, array $data = [], array $options = [], BubbleableMetadata $bubbleable_metadata = NULL) {
…
    $replaced = $this->token->replace($string, $data, $options, $bubbleable_metadata);

So, yes, I think your hunch was onto something 👏: \Drupal\metatag\MetatagManager::generateRawElements() should be passing in that optional parameter.


I don't have time to dig in more right now, but it's of course interesting that you solved your problem without addressing that. Perhaps that's because there's multiple invocations of that method and your static cache prevents the invocation that is happening in head while executing \metatag_page_attachments(), hence indirectly also avoiding the bubbling onto the current render context?

damienmckenna’s picture

Assigned: larowlan » Unassigned
Status: Needs review » Needs work

This needs additional work, right? Reading #11 and #12 it seems like the test coverage might need to be expanded slightly to ensure that meta tags output correctly on the second page request, not just the first request, right?

larowlan’s picture

Yep, putting it back on my list

larowlan’s picture

Status: Needs work » Needs review
Issue tags: +needs profiling
StatusFileSize
new7.31 KB
new2.49 KB

generateRawElements is public (probably shouldn't be, but that's a 2.x API break).

So here's a go at handling the cache metadata properly, adds a BC layer in case there's someone calling that method somewhere.

Needs profiling to ensure the issue is fixed.

larowlan’s picture

StatusFileSize
new2.56 KB

Here's a version against 8.x-1.11

The last submitted patch, 15: 3039650-15.patch, failed testing. View results

larowlan’s picture

StatusFileSize
new614 bytes
new2.43 KB
new2.36 KB

->applyTo

with bubbleablemetadata clobbers #attached

Status: Needs review » Needs work

The last submitted patch, 18: 3039650-18.patch, failed testing. View results

damienmckenna’s picture

Any thoughts on the test failures?

wim leers’s picture

#20: The test expectations are not yet cache-aware, and hence need updating.

larowlan’s picture

Assigned: Unassigned » larowlan

working on test changes

larowlan’s picture

Priority: Normal » Major
Status: Needs work » Needs review
StatusFileSize
new3.03 KB
new4.61 KB

This is actually pretty major, 8% performance hit on any site that has any tokens that use cache metadata. Coupled with up to 11% for sites with paragraphs (or any entity without a canonical route) we got in the other issue, these are some nice wins for a lot of Drupal sites out there.
Added a new test to go with it demonstrating what we didn't have here.

larowlan’s picture

Looks like there is a fail in HEAD now, restui module isn't in the module's test dependencies

larowlan’s picture

Title: Improve metatag_entity_view_alter performance » Metatag discards cacheability metadata, results in a performance hit

Status: Needs review » Needs work

The last submitted patch, 23: 3039650-23.patch, failed testing. View results

larowlan’s picture

Status: Needs work » Needs review

That's the same fail as in HEAD, so this is ready for 👀 now

damienmckenna’s picture

I pushed up a fix for the restui thing, I must have committed the wrong patch or something as the one I uploaded to the issue (#3123578) didn't have that line. Sorry about that.

larowlan’s picture

thanks! I'll kick off another run

larowlan’s picture

🎉green

berdir’s picture

+++ b/src/MetatagManager.php
@@ -493,11 +496,16 @@ class MetatagManager implements MetatagManagerInterface {
+    if (!$cache) {
+      @trigger_error('Calling ::generateRawElements without cacheability metadata is deprecated in 8.x-1.13 and is removed from 8.x-2.x. @see https://www.drupal.org/node/3123628');
+    }

I find deprecation messages for contrib hard as there are usualy no clear rules when and if at all there will be a 2.x branch :) Probably should be 2.0.0 now? And following the new naming, should this be metatag:8.x-1.13 and metatag:2.0.0 respectively?

I don't quite understand how this affects caching. I'll try to do some profiling on my own over the next days.

berdir’s picture

@larowlan: Something just doesn't quite add up to me here :)

For me, despite having 45 calls to this function, it's only 3.6% (24ms) of the total page request with the current stable version of metatag. I see the red warning icon in your screenshot about xdebug being enabled, that *massively* slows down everything, the whole page was 2x as fast for me after disabling xdebug (this function was 38ms). Note that many small function calls also tend to be over-reported with blackfire, due to the overhead that each function call has.

What scenario are you measuring exactly, authenticated or not, render caches enabled?

Are you using any special tokens or so with special cacheability? Are you using property tokens ([node:field:value] instead of [node:field])? That can massively speed up token generation because the non-property tokens actually render the field into HTML through a formatter and then remove that again.

What I can reproduce on my site here is that the entity view alter hook *is* being called on what should be a render-cached page, so there is indeed something interesting going on.

But, I don't quite see why collecting the metadata like that would change whether or not elements are cached. We are currently in a pre render callback, so it should IMHO more or less end up in the same place. Unless we collect it but then lose the metadata as a result of this change, which would explain it being faster, but would also defeat the purpose of doing it :) Looking at it a bit closer, I'm pretty sure that's exactly what's happening. In _metatag_remove_duplicate_entity_tags(), it then has $metatag_attachments['#cache'] but the function has no return value, it only uses that to unset stuff in $build. If you'd actually merge things over into $build then I'm quite certain you'd end up right where you started.

I suspect that the reason you and I don't see render caching happening for the node is a different one. For you, it actually might be a token, and if that's the case, it would be the correct and expected behavior. For me, it's something else (possibly around access/translation stuff, aware of some issues there on this project), so this patch doesn't actually improve anything :)

What cacheability metadata do you see with this patch in your $cache? You might want to set a breakpoint on the foreach that does the token replace and detect which token causes that and make it use a different token :)

so, I'm reasonably certain this is a won't fix and your problem is somewhere else, in a specific token.

damienmckenna’s picture

Status: Needs review » Needs work

Thank you for the really detailed review, Berdir.

Putting this back to Needs Work as it seems this needs some further analysis.

johnwebdev’s picture

On cool cache the time spent in metatag_entity_view_alter was ~700ms for me. However, as suggested in #32

Are you using any special tokens or so with special cacheability? Are you using property tokens ([node:field:value] instead of [node:field])? That can massively speed up token generation because the non-property tokens actually render the field into HTML through a formatter and then remove that again.

That led to a 37% improvement. We also have a special token that I'll need to check as well. Will report back.

berdir’s picture

mbovan’s picture

As suggested by @Berdir, I created a separate issue to focus on extending the generateRawElements(). This includes related parts from #23.

See #3175269: Pass optional bubbleable metadata parameter to generateRawElements to avoid issues with early rendering and JSON:API.

singularo’s picture

StatusFileSize
new3.23 KB

Re-rolled patch to work with latest release.

kim.pepper’s picture

Issue tags: +#pnx-sprint
joseph.olstad’s picture

Status: Needs work » Needs review
berdir’s picture

Status: Needs review » Needs work

See #32, the patch isn't correct and shouldn't be used. No need to reroll and you shouldn't use it. See my suggestions and related issue if you're looking for a performance improvement around metatags.

hemlata99’s picture

StatusFileSize
new3.37 KB

Updated patch based on 8.x-1.x with correct bubbleable metadata handling.

hemlata99’s picture

StatusFileSize
new3.46 KB

this comment been deleted

hemlata99’s picture

StatusFileSize
new3.46 KB

this comment has been deleted

hemlata99’s picture

StatusFileSize
new3.24 KB

Updated patch based on 2.1.x with correct bubbleable metadata handling.