Optimize cacheability bubbling (Cache::mergeTags(), ::mergeContexts(), BubbleableMetadata)

Yes, I can definitely see this too, although I'm not quite sure how much of that is overhead, especially if you look at a patch with a cold render cache, there are hundreds to thousands of those method calls.

+1 to not sorting/validating during merge.

I'm also seeing BubbleableMetadata::createFromRenderArray() and BubbleableMetadata::merge() quite high in the list, but that was done on a a bit older core version, we might have already refactored/optimized some of that.

https://www.drupal.org/node/2342045#comment-9707699 contains the profiling where I saw those methods.

Hm, so now we also have a service call to validate contexts in mergeContexts().

I'm not sure I understand why we bother with that there? it just means we validate them over and over again. Why not just validate where we actually use them, which is somewhere in Renderer?

I think the point was that the error should happen as early as possible, so its easier to find the code causing it.

Yes, I can see that, but that only works partially, when you merge with something else, it might also be what has already been set by someone else.

AFAIK you're adding a new API that allows to set those things through the renderer service, maybe we could additionally add it there instead?

The question IMHO is, is the improved DX worth that additional performance cost. I'll try to do some tests of the next days. In recent profiling runs that I did, multiple of those methods where listed high when sorted by exclusive run time. And IIRC, a large amount of the calls were caused by the renderer itself, due to the stacked rendering. Maybe we can introduce a mergeNoValidation() or something version of those and call them there, because it won't really help anyway when an exception is thrown there.

Ok, so here are a few numbers. The profiling overhead is definitely high because those methods are called a lot, but still, there's a lot going on.

I've tested this with a disabled render cache to simulate a cold cache. Of course, when that is enabled, then there are a lot less calls. Comparison numbers of that below. Tested on the frontpage of my installation profile, with beta8, so without the cache context validation.

HEAD:
Total wall time 1.6s
90% of that is in doRender(), which is both good and bad.
BubbleableMetadata::merge() is 5.2%, 2.3k calls
Cache::mergeTags() is 3.4%, 6k calls
Cache::mergeContexts is 1%, 2.3k calls
Cache::mergeMaxAges() is 2.1%, 5.9k calls

Those calls are overlapping of course, a large part of the Cache::merge* calls are from merge() (40-50%, most of the other half is AccessResult)

With the attached patch, we save a bit (around 1% of the total wall time). And maybe other improvements are possible too. mergeMaxAges() for example, I think we can make it a bit faster by doing a simple loop instead of fancy array_filter() functions. Again, the numbers come with considerable overhead, but it should still be worth doing some micro-optimization here.

With enabled render cache, I'm down to 600ms on that page. And there are still 700 calls to BubbleableMetadata::merge(), still 5%.

And comparing the same when the profiler is disabled, numbers based on ab -n 50 -c 1

Render cache fully enabled: 140ms
Completely disabled: 700ms
(that's an even bigger difference than I expected, also the result I saw in the browser were a bit higher, 960ms and 200ms, ab also went up to those numbers)

Given those numbers, I'm not sure how much we can actually trust those improvements. I tried to compare it with ab, but for some reason, it behaved very strange.

Would also love to compare that with PHP7 too, but that will probably have to wait until I can update to beta9.

Ok, different approach for testing this.

xhprof and xdebug disabled.

use Drupal\Core\Cache\Cache;

$before = microtime(TRUE);
for ($i = 0; $i < 5000; $i++) {
  Cache::mergeTags(['node:1'], ['node_list', 'node:1']);
}

$after = microtime(TRUE);

var_dump(($after - $before) * 1000);

PHP 5.5: 16-17ms
PHP 7: 4-5ms (yeah. Can I haz php7 today plz?)

Without validate + unique + sort:
PHP 5.5: 8ms
PHP 7: 2ms

This was fixed in #2471232: Optimize Cache::merge*(), by only accepting 2 instead of N arguments.