toolbar_pre_render() runs on every page and is responsible for ~15ms/17000 function calls

In the process, I've discovered a new set of problems previously undiscovered:

1. in theory, we should have a single drupal_render() call to render the entire page. However, in practice, DefaultHtmlFragmentRenderer renders the special page_top and page_bottom regions first, and only then renders everything else. This causes #post_render_cache callbacks inside those two special regions to be executed again when rendering everything else.
2. drupal_render_collect_post_render_cache() was running too early
3. drupal_render_children() by definition is a recursive call, but it was pretending to be the root call every time it rendered a child, therefore executing #post_render_cache callbacks far too early (toolbar.module uses drupal_render_children(), hence I discovered this)

Agreed.

Working on #2241235: Shortcut/ShortcutSet entity types should use cache tags in the mean time, that will allow this patch to make an even bigger impact, because it'll allow us to render cache the shortcuts as well!

#2099131: Use #pre_render pattern for entity render caching landed, but let's get #2241235: Shortcut/ShortcutSet entity types should use cache tags done first.

#7: I had left it marked as postponed as per #6 ;)

#8:

1. The toolbar is a rendered piece of HTML. Rendering it is pretty expensive, because of the top-level menu that needs to be looked up, the shortcuts that need to be looked up, and so on. Replacing that with a single render cache get is much cheaper. What's abusive about that?
2. What is session-specific about the toolbar? It's the same on a per-role basis, with user-specific things in there.

#2241235: Shortcut/ShortcutSet entity types should use cache tags landed! Now let's get this one done :)

Rerolled, now that both #2099131: Use #pre_render pattern for entity render caching and #2241235: Shortcut/ShortcutSet entity types should use cache tags have landed. No interdiff; too many changes, and this is the first patch up for review anyway.

Now, instead of re-rendering the shortcut links on every page load, they're also render cached.

So, overall, in a Standard profile install with this patch:

• toolbar is render cached per role, theme and language, and contains two placeholders
• the first placeholder is for the contents of the Shortcut module tray, a #post_render_cache callback replaces this with the shortcut tray contents, which are render cached themselves as well (to prevent all shortcut entities from being loaded on every page load)
• the second placeholder is for the contents of the User module tray, a #post_render_cache callback replaces this with the user tray contents, which are not cheap to render but are user-specific

The difference has become even slightly more stark now (D8 @ a0961ff65b273483f1a1d2f92318b1d21bfaceae): at /contact without this patch, 136 DB queries are performed (down from 139 when this issue was opened), and with this patch, 103 DB queries are performed (down from 108 when this issue was opened)… so a difference of 33 DB queries!.

There's only one special hunk in this patch, which is the one for DefaultHtmlFragmentRenderer::render(). Instead of the crazy hacks I applied in #1, I propose a much saner approach here: don't let DefaultHtmlFragmentRenderer::render() abuse the renderable page array and drupal_render() in unintended ways.
DefaultHtmlFragmentRenderer::render() must create a HtmlPage, and HtmlPage expects both "top-content" (setBodyTop()) and "bottom-content" (setBodyBottom()) to be separate things, and both of those most already be rendered HTML. But page_bottom and page_top are part of the renderable array like all other regions, even though they should be rendered separately. So the fix is simple: we pull them out of the renderable page array and treat them separately, just like HtmlPage expects us to do.
Without this change, any #post_render_cache callback that was applied for $page->setBodyTop(drupal_render($page_array['page_top'])); would be re-applied for $page->setContent(drupal_render($page_array));, because $page_array is a superset of $page_array['page_top'], hence drupal_render() re-applies #post_render_cache callbacks.

(Yes, we're still cleaning up the half-baked mess that was introduced in [#2170551]…)

1. Yes :)
2. drupal_render() has some things that descend down subtrees that have been marked as 'printed'. This sidesteps that problem. Plus, it's conceptually more honest: we have three parts of the page that must be rendered independently, so then let's do it truly independently.
3. Kind of. The exact reason is explained in #11, below the horizontal rule.

Sadly, the promises of this patch were too good to be true.

I made a HUGE mistake: I failed to consider the "menu" tray (called toolbar_administration in code)… which is of course rendered menu tree. I was caching this with the rest of the toolbar, so render cached per role, theme and language, instead of creating another post-render cache placeholder for it (hence the test failures). If I fix that, and render that tray in another #post_render_cache callback, the deltas look like this:

• -3 DB queries
• +1.5 MB memory
• +2 cache gets
• -4 config gets

That's of course not great.

The only sane solution is to finally fix #1805054: Cache localized, access filtered, URL resolved, and rendered menu trees. So I'm going to work on that now.

What this patch does overall is still valid, because the different parts of the toolbar have different personalization aspects (for menu trees, see #1805054: Cache localized, access filtered, URL resolved, and rendered menu trees; for the shortcuts tray: each user may have a different shortcut set, but many have the same; for the user tray: this is obviously per-user, but is cheap to render).

So, this is now postponed on #1805054, once that is done, we can reroll this patch and it should still be a net win. But the huge win lies in #1805054.

Lots of blockers for #1805054: Cache localized, access filtered, URL resolved, and rendered menu trees went in, I'm currently rerolling #1805054: Cache localized, access filtered, URL resolved, and rendered menu trees. I rerolled this patch as well to get a sense of the performance improvements of this in *today*'s HEAD with #1805054's patch (WIP) applied.

This can save an additional 6 DB queries per page, ~8 ms, and 5000 function calls.

I might merge this into #1805054, we'll see how that evolves. In the mean time, uploading an updated patch. The majority of the changes in toolbar.module from the above patches has already been committed to Drupal core, hence this patch is about half as big.

#1805054: Cache localized, access filtered, URL resolved, and rendered menu trees is moving forward again, and once that lands, we'll be able to do this too.

#1805054: Cache localized, access filtered, URL resolved, and rendered menu trees landed, so this is now finally unblocked!

To decide whether this is still relevant, I did some profiling and benchmarking. The answer is a resounding "YES", this is still worth doing.

Testing as UID 1, the root user. The costs for other authenticated users would be even higher.

If the solution for this turns out to be impossible to do in 8.1, this will therefore be bumped to critical as per the guidelines in #1744302: [meta] Resolve known performance regressions in Drupal 8

The patch to solve this is completely different than previous patches. It is much simpler. Because we now have #2429257: Bubble cache contexts, so we let the system take care of it instead of making hook_toolbar() complicating implementations.

The performance difference is very stark.

This is profiled as UID 1 on the frontpage, using the Standard install profile. Fresh install. UID 1 because that is *cheaper* in terms of access checking (lots of things return early for UID 1) and because that user can access the toolbar.

In other words: the numbers below present the minimum expected improvement, for more complex set-ups and for non-admin users, the improvement will be much bigger.

Profiling (XHProf)

Before

Function calls: 63,109

Mem: 20.53 MB

Peak mem: 20.75 MB

After

Function calls: 48,284 (-15K, -23.5%)

Mem: 19.56 MB (-1 MB, -5%)

Peak mem: 19.74 MB (-1 MB, -5%)

Benchmarking (ab -n 1000 -c 1)

Before

Requests per second:    9.58 [#/sec] (mean)
Time per request:       104.428 [ms] (mean)
Time per request:       104.428 [ms] (mean, across all concurrent requests)
Transfer rate:          169.78 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       1
Processing:   100  104   1.3    104     112
Waiting:       90   94   1.3     93     102
Total:        100  104   1.3    104     113

After

Requests per second:    11.07 [#/sec] (mean)
Time per request:       90.358 [ms] (mean)
Time per request:       90.358 [ms] (mean, across all concurrent requests)
Transfer rate:          189.48 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:    87   90   1.2     90      96
Waiting:       77   80   1.2     80      86
Total:         87   90   1.2     90      96

Before vs. after

IS updated. Also marking this as critical, because AFAICT this would be considered an API break in Drupal 8.x.0, and it exceeds the ">=10 ms faster for warm caches" requirement.

Oh, and as a bonus, this should also reduce the number of failures in #2429617: Make D8 2x as fast: Dynamic Page Cache: context-dependent page caching (for *all* users!).

Easy fix, that points to another bug in the cacheability metadata.

Obviously, all of this still needs test coverage. The toolbar module has test coverage, but not for this area.

#26 Thanks for the review!

1. Indeed :)
2. Yep! Then this could be much more elegant.
3. Good call. Fixed.
4. Yes.

Is there any value to creating a 'current users's shortcut set' cache context? Then if a single shortcut set is used across the site, we'd not need to vary per-user.

Hahaha! Glad you asked! This is exactly what crossed my mind as well :) I figured to not bring it up to not distract the discussion :)

Reasons to not do that here:

1. the point you already made: such a cache context would still cause shortcut set entity storage to be initialized; right now we avoid that altogether
2. user_toolbar() is already per-user anyway.
3. it'd only actually benefit sites that either have: A) many administrators, B) granted a non-admin role permission to use the toolbar. In other words: it'd benefit relatively few sites. Most sites will have few users using the toolbar, in which case per-user caching is fine. Any further improvements in this area can IMHO therefore be deferred to 8.1.0.

Also, fun fact: see #1805054-144: Cache localized, access filtered, URL resolved, and rendered menu trees, which contains the perf numbers for the issue that was blocking this one. It is that issue that brought down the UID1 front page load time down to 105 ms. This one is bringing that 105 ms down to 90 ms. They're adding up quite nicely!

Unassigning. I'm working on other performance patches now, hopefully somebody else can write the test coverage.

#34: no, that's impossible, because what you're seeing is NOT a render array, but the value for the #links property.

#36: Well, it's the route parameter that is being set to the current user:

      'account_edit' => array(
        'title' => t('Edit profile'),
        'url' => Url::fromRoute('entity.user.edit_form', ['user' => $user->id()]),
        'attributes' => array(
          'title' => t('Edit user account'),
        ),
      ),

So, no, the link itself could not have this, because this is not a MenuLinkInterface object. It's just a simple Url object.

1. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -0,0 +1,151 @@
   +      'languages:language_interface',
   +      'theme',
   

   We repeat this everywhere. Let's put that in a $required_cache_contexts variable and merge that with the other arrays. That'll allow us to remove repetition, and will hence make it clearer what the actual expectations for each specific thing are.

   In fact… why not create something like:

   $expectations = [
     [['toolbar, contextual'], ['user.permissions']]
     [['toolbar', 'shortcut'], …]
     …
   ];
   

   So that we can iterate over the various toolbar + other module combinations and define the expectations?

2. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -0,0 +1,151 @@
   +    // Test without user menu. User module is required so we have to
   

   s/menu/toolbar tab+tray/

3. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -0,0 +1,151 @@
   +    // manually remove the user toolbar.
   

   s/toolbar/toolbar tab+tray/

4. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -0,0 +1,151 @@
   +  /**
   +   * Tests toolbar cache contexts with contextual toolbar.
   +   *
   +   * @param array $anonymous_cache_contexts
   +   *   Expected cache contexts for anonymous user.
   +   * @param array $authenticated_cache_contexts
   +   *   Expected cache contexts for authenticated user.
   +   */
   +  private function testToolbarCacheContexts(array $anonymous_cache_contexts, array $authenticated_cache_contexts) {
   

   This is not testing the right thing yet. Anonymous users never get to see the toolbar, which is why they have the same expected cache contexts across all situations!

   What this really needs to be testing is that if one authenticated user has the "access contextual links" permissions and another does not, that for both of those users the user.permissions cache context is present.

We could clean up the $links_cache_context stuff if we land #2495779: Make #theme => links take cacheability metadata as an argument. That has a patch now.

Yes, they are, but the anonymous user doesn't see the toolbar at all, so those tests as the anonymous user don't really test anything :)

This looks vastly better! IMO this is RTBC-worthy. What did you plan to do later on? (It sounds like you still wanted to make some changes, but I'm not sure what still needs to be improved?)

1. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -27,125 +27,98 @@
   +    $this->adminUser2 = $this->drupalCreateUser(array_merge($this->perms, ['access contextual links']));
   ...
   +    $this->adminUser2 = $this->drupalCreateUser(array_merge($this->perms, ['access tour']));
   ...
   +    $this->adminUser2 = $this->drupalCreateUser(array_merge($this->perms, ['access shortcuts', 'administer shortcuts']));
   

   Granting additional permissions would be slightly better, but wouldn't actually matter here.

2. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -27,125 +27,98 @@
   +   * @param array $cache_contexts
   

   Nit: string[].

3. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -27,125 +27,98 @@
   +    // Caches has to be rebuilt since modules might have added some routes.
   

   s/has/have/

4. +++ b/core/modules/toolbar/src/Tests/ToolbarCacheContextsTest.php
   @@ -27,125 +27,98 @@
   +    $cache_contexts = array_merge($default_cache_contexts, $cache_contexts);
   

   Cache::mergeContexts()

To address #49, use Cache::mergeContexts().

CR created. This reminds me: we must also update the documentation for hook_toolbar().

#71.1: Oops! I should've caught that.

#74: +1, please rename it to assert*, which is the convention. i.e. in this case assertToolbarCacheContexts().

Perhaps "verify"is better, then.

We have a strange test system.

NW for #84.

Awesome! Thanks :) :)