Critical performance regression due to config schema + TypedData lookups in installer

Nope there's no caching of config schema - so we can try this. Which appears to help BUT also the sheer number of objects created to parse a views schema seems to be what is really taking the time as this only shaves a couple of seconds off enabling the views module for me.

Let's see what breaks.

The problem is our schema are dynamic - that is to say that the schema of view is made up of lots of other bits of schema and which exact schemas these are depend on values with the view entity. This means that in order to create the schema for the view we have to parse every value within the view and create a schema object for each one. This turns out to not be cheap.

Testbot was borked when I submitted the last patch

Okay found a large part of the slow down is due unnecessary re getting of the same schema due to nested keys and recursion in Config::getSchemaForKey()

HEAD

Pre using schema in save

Patch

I'm not 100% happy with the patch as it stands since we are caching every level of schema and this is unecessary but its a start

EDIT: the xhprof runs are comparisons of config_install_default_config() whilst enabling Views module through drush.

Ok I'm getting happier - more code moving from the Config class to the schema system which is a good thing. The most important line in the patch is

diff --git a/core/lib/Drupal/Core/Config/Schema/Sequence.php b/core/lib/Drupal/Core/Config/Schema/Sequence.php
index 44dbe1d..6333349 100644
--- a/core/lib/Drupal/Core/Config/Schema/Sequence.php
+++ b/core/lib/Drupal/Core/Config/Schema/Sequence.php
@@ -60,7 +60,7 @@ public function onChange($delta) {
    *   Typed configuration element.
    */
   public function get($key) {
-    $elements = $this->parse();
+    $elements = $this->getElements();
     return $elements[$key];
   }

Since this is the line that ensures the array schema elements populate $this->elements and therefore don't need to recreate the elements every time.

Profiling enabling of views: the inclusive wall time when enabling views is 10,098,144 microsec (HEAD is 21,285,766)

No interdiff with #6 since the approach is completely different.

I was trying to do profiling, but could not figure out how to get xhprof results for a: drush -y en views. Opened issue: #2163693: xhprof run results not saved and no id given after xhprof enabled for drush in devel

@beejeebus pointed out that I'd left an used property in the patch from the previous solution.

Do we really need an extra cache bin for this? I'd think the existing config cache bin would be fine as long as no chance of collisions.

Logic in the patch looks good but yeah it'd be good to see profiling.

I noticed the same bug in Sequence::get() (the result is now consistent with ArrayElement::offsetGet() when re-rolling #2110467: Add first(), get($index) and possibly other methods to ListInterface. It could also simply call to parent::offsetGet(), that's what my patch used to to when I added the get() method.

Doing some profiling with xhprof and running a web test:

Before/After:
Number of Function Calls 3,809,248 3,493,216 -316,032 -8.3%
Incl. Wall Time (microsec) 19,470,149 16,325,501 -3,144,648 -16.2%
Incl. MemUse (bytes) 17,509,800 16,797,416 -712,384 -4.1%
Incl. PeakMemUse (bytes) 20,086,152 20,028,912 -57,240 -0.3%

While that's pretty nice and all, I did notice that it also results in 600 additional queries, caused by using CachedSchema for the config schema stuff and not actually being much faster in there (in case of a test) as it mostly just passes through to the file storage + cache set calls and if it doesn't, then resulting in tons of separate cache requests. A simple improvement is using readMultiple() there, although it would be nice to have CacheBackendInterface::setMultiple() here and for cached config in general: #1167248: Add CacheBackendInterface::setMultiple(). See interdiff.

While this doesn't result in a large difference, it saves ~270 queries and the setMultiple() would to the same for the insert queries, this should however improve quite a bit when the cache is warm. #2155635: Allow plugin managers to opt in to cache clear during module install might also be related.

What I'm wondering is why we even mess with the config values at all in config_install_default_config(), aren't we just copying stuff from a module folder to the active storage? If there is no reason, could we inject a null implementation there, so that the validation is skipped?

For the typed data/content entity validation API, we explicitly do not validate automatically on save but made it a separate API, #2085071: Auto validate fields on $entity->save(), but allow opt-out is related. But this is also just casting stuff around and not actually validating it :)

Also running some tests to compare the affect on test run time for the bot with php ./core/scripts/run-tests.sh --concurrency 8 --url http://d8/ Node:

Test run duration:
HEAD: 7 min 44 sec
With the patch: 6 min 56 sec

Not that much of a difference. Noticed that NodeTranslationUITest took by far the most time, so not sure how meaningful those numbers are, but to compare that, I did also run that as a standalone test:

HEAD: 4 min 37 sec
With the patch: 4 min 9 sec

So I mostly just compared that test in the run above ;)

Also planning on doing a comparison with before the commit of the issue that caused this.

For comparison, i did a quick check with an empty typed config manager implementation in that function and it's another 1.2s faster. Note that this doesn't affect saved config entities, saving those was now actually 1s (40%) slower (as it were those calls that triggered the parsing), so that's another 1s that we could save if we'd skip that casting stuff there as well.

More numbers, I did run the test with xhprof enabled, running them without gives me the following:

HEAD: 15s
last patch: 13s
empty typed config manager: 12s

Great improvement #12! Is it possible to measure the effect of growing cache entries? small chunks means more read, bigger means more deserializaton, is not it?

I see no reason in skiping casting when saving, core implementation of saving should be the same for install and runtime.

If we are simply copying in the default value, I don't see why it would make sense to validate it?

That is what I understand yes, we're taking the values from file A and write them to file B, we're not changing anything, so we don't need to cast/validate anything? If I'm missing something, tell me :)

@andypost: Yeah not sure, might be better to maintain a single cache directly in TypedConfigManager, that's a single get and write on miss, and we always read everything. The only problem could be to clear the cache at the right time, but I don't see where we do trhat right now anyway. And the mentioned #2155635: Allow plugin managers to opt in to cache clear during module install would help.

#11 I don't think we can reuse the config cache bin as there is no way we can guarantee that there is no chance of collisions.

Here's a version that implements the caching directly in the typed config manager.

Timed drush si -y a bit:

HEAD 46.7s
Previous patch: 32.5s
This patch: 29.802s

Results vary only marginally, did three installs with this patch and the other results were 29.7 and 29.9.

This should fix the installer.

@Berdir - this looks like you are using a cache rather than just copying them across?

@pwolanin: I'm not changing anything related to to that, the caching has nothing to do with how that works. We want caching anyway for normal config saves, I'm just wondering why default config installation goes through the same API.

Looks like a very minor fix needed.

The approach of having a single cache entry for all definitions looks great. Minor update to use a constant instead of a property for the cache ID.

The only issue I can think about with having a single cache entry is the potential size of the value. Memcache has a hard limit of 1mb and the current schemas in core add up to 116895 utf-8 characters so this could be in the region of 450k already (utf-8 characters use up to 3 bytes)

2. That's not how the API works. It does a listAll() + loadMultiple() of everything. Creating a single cache entry of that is actually less overhead because we only need a single cache object with a large $data array and a single unseralize() call on that and not 200 cache objects, each of those with a separate small $data array and 200 unseralize() calls. More specific caching would first require an API to load specific definitions.

3. Well, yes. In case of module enable/disable, #2155635: Allow plugin managers to opt in to cache clear during module install would take care of it. As for changes, that's the same as with anything else, if you change your entity type definition or routes or table schema, then you will need to make sure it's updated/the necessary caches are cleared. I don't see how we could avoid this. We need to cache this.

4. Haven't touched that part but after a quick look, this does seem to explain why the complete schema config is parsed, not just enabled modules, which probably also explains why there were never any cache clear problems. So yes, limiting that to actually enabled modules should help a lot with test performance, where usually only a small subset of modules is enabled.

I would prefer to get this in as is and address the fact that all schema are cached regardless of whether its provided by an enabled module in another issue. We also use the InstallStorage in ExtensionInstallStorage which is currently used to config_install_default_config because it offers a handy way to get config from all the enabled modules. ExtensionInstallStorage overrides a function to limit only to enabled extensions.

I really think we should use the config cache bin, and just add a prefix to the cache keys if that's really necessary to avoid collisions.

The memcache project gzips items that are going to be too big to fit in the 1mb limit, so the practical limit is actually quite a bit more than 1mb. On the other hand it's not good to rely on that - max_allowed_packet also defaults to 1mb.

If the InstallStorage is a different issue, it'd be good to open that as another critical follow-up.

I'm also wondering a bit how much of a performance issue the lack of caching is if using the PECL YAML parser - it's not impossible that it'd be quicker than hitting the db.

https://drupal.org/requirements/database documents that max_allowed_packet should be at least 16MB.

I think the cache is still a lot faster than pecl, we're not talking about a single file but non-cached (due to the InstallStorage usage) directory content lookup for every existing (not just enabled, again, thanks to InstallStorage) module and then parsing all those files (~70 right now) one by one. Compared to a single cache get + unseralize.

I'll try to provide numbers for my thinking tonight :)

+++ b/core/lib/Drupal/Core/Config/Schema/SchemaIncompleteException.php
@@ -2,7 +2,7 @@
 /**
  * @file
- * Definition of Drupal\Core\Config\Schema\SchemaIncompleteException.
+ * Definition of \Drupal\Core\Config\Schema\SchemaIncompleteException.
  */

Both are wrong, actually :) Should be Contains \Drupal\...

Lol

And using the CID of 'config_typed_definitons' can never clash with a key from the config cache of regular configuration since config names always have to have a period.

Compared/combined this with #1920902: Add a Drupal Yaml wrapper so we can default to PECL Yaml component if it is available but wasn't able to detect a big difference with and without this issue.

Awesome! Great work, all.

Committed and pushed to 8.x. Let's hope this gets our testbot run time back under 2 hours again. Look forward to further improvements. :)