Did some profiling on #1828642: Convert as many Views tests as possible to DrupalUnitTestBase to see where we are losing so much time compared to other (Drupal)UnitTests.

Turns out most time is actually spent in loading default config. Of the 20s it took to run Field: Unit Tests (with 7 test methods), 14s (70%) is spent in config_install_default_config(), 8s in views_config_import_create(), almost 10s is spent in Symfony\Component\Yaml\Parser::parse(), with 1250 calls to it. Note: Those times overlap of course :)

Then I remembered that profiling slows function calls down a lot (and w'ere talking about 13 million function calls here... o.0) so, I tested it without xhprof and the total test time went down to 7s.

Still, it's something that's worth checking, I think there are two separate ways to improve the speed of these tests.

- Load fewer default config files by splitting up views_test_config into multiple modules. That's probably the easiest way but it will only help with the tests and the downside is that the number of modules is going up, so it's more time spent in parsing .info files :) (which might become yaml files too ;))

- Speed up the actual yaml parsing. Installed the yaml extension, did some tests and came up with this:

<?php
$start
= microtime(TRUE);
$extension = yaml_parse_file('core/modules/views/tests/views_test_config/config/views.view.test_destroy.yml');
dpm($extension, 'extension');
dpm(round((microtime(TRUE) - $start) * 1000, 3), 'extension ms');

use
Symfony\Component\Yaml\Parser;
$parser = new Parser();
$start = microtime(TRUE);
$symfony =$parser->parse(file_get_contents('core/modules/views/tests/views_test_config/config/views.view.test_destroy.yml'));
dpm($symfony, 'symfony');
dpm(round((microtime(TRUE) - $start) * 1000, 3), 'symfony ms');

dpm($symfony == $extension, 'result is equal');
?>

The dpm at the end confirms that the end result, at least in this case is the same, so it looks like it might actually be able to use it as a replacement if available. I did run that with and without xhprof, to also learn more about how much that is exactly slowed down.

Without xhprof:
extension ms => 2.911
symfony ms => 9.355

With xhprof:
extension ms => 4.321
symfony ms => 29.101

The exact numbers vary a bit, but the trend is that extension ms without xprof = 1x, symfony ms without xhprof = 3x, and symfony ms with xhprof is 10x. So according to these numbers, we might be able to make the actual parsing ~3x times faster when using the yaml extension, if we can actually ensure that they result in the same structure.

Files: 
CommentFileSizeAuthor
#18 1851234.18.patch15.67 KBalexpott
PASSED: [[SimpleTest]]: [MySQL] 64,713 pass(es).
[ View ]
#17 1851234.17.patch14.9 KBalexpott
PASSED: [[SimpleTest]]: [MySQL] 64,761 pass(es).
[ View ]
#13 1851234.13.patch6.62 KBalexpott
PASSED: [[SimpleTest]]: [MySQL] 64,587 pass(es).
[ View ]
#10 xhprof-still-woah.png90.83 KBalexpott
#9 xhprof-woah.png197.36 KBalexpott
#9 d8.symfony-yaml-perf-improvements.patch4.8 KBalexpott
PASSED: [[SimpleTest]]: [MySQL] 64,567 pass(es).
[ View ]

Comments

Berdir’s picture

Title:Slow yaml parsing considerably slows down tests which load/save many config files (e.g. views)» Slow yaml parsing slows down tests which load/save many config files (e.g. views)
heyrocker’s picture

Issue tags:+Configuration system
dawehner’s picture

- Load fewer default config files by splitting up views_test_config into multiple modules. That's probably the easiest way but it will only help with the tests and the downside is that the number of modules is going up, so it's more time spent in parsing .info files :) (which might become yaml files too ;))

As discussed with tim we will introduce some kind of parameter similar to protected $modules on tests, which specifies the needed views config
and move the config files to another directory so they are not loaded on each test.

sun’s picture

Issue tags:+Performance

1) Yes, it has always been the intention to allow sites to use the php-yaml extension for parsing and dumping instead of the user-space Symfony Yaml component. My original plan was actually to bake a conditional check right into Config\FileStorage and simply/automatically use the php-yaml extension if it is available.

2) The effort on 1) only got side-tracked and blocked on research whether YAML 1.1 is sufficiently compatible with YAML 1.2 - limited to the configuration system's usage. php-yaml internally uses LibYAML, which implements the YAML 1.1 spec. Symfony's Yaml component implements the latest and stable YAML 1.2 spec.

3) When executed in C code, I even wonder how much of a gain the additional cache backend layer in front of the FileStorage is, or whether that wouldn't be superfluous. But of course, evaluating that would only be a follow-up step to 2) and 1).

Berdir’s picture

1) Yes, it has always been the intention to allow sites to use the php-yaml extension for parsing and dumping instead of the user-space Symfony Yaml component. My original plan was actually to bake a conditional check right into Config\FileStorage and simply/automatically use the php-yaml extension if it is available.

2) The effort on 1) only got side-tracked and blocked on research whether YAML 1.1 is sufficiently compatible with YAML 1.2 - limited to the configuration system's usage. php-yaml internally uses LibYAML, which implements the YAML 1.1 spec. Symfony's Yaml component implements the latest and stable YAML 1.2 spec.

Yes, exactly, that's what I've been wondering about too, making it swapable will require us to verify that the array returned by the parsers is actually equal. The views example that I used was.

A conditional check in FileStorage is one option, having two implementations and configure the service based on the existence of the extension would be another. This should even be possible in a contrib module.

3) When executed in C code, I even wonder how much of a gain the additional cache backend layer in front of the FileStorage is, or whether that wouldn't be superfluous. But of course, evaluating that would only be a follow-up step to 2) and 1).

Depends on a lot of things, I'm quite sure it's still worth to have the caching layer, especially if we can improve it to do better caching than a single cache get/set*. But removing it would just be a matter of configuring the container services differently, which again, is a thing that a contrib module can now do.

* Maybe not by default, but I guess it's going to be really useful for large sites to have custom cache implementations which can e.g. cache the stuff that's loaded on all pages in a single cache entry and so on.

tim.plunkett’s picture

See also #1856272: Speed up tests by only installing the views used by that tests, the exciting parts are in ViewTestData::importTestViews().

Berdir’s picture

@msonnabout created a pretty neat test script here: https://gist.github.com/msonnabaum/5052884

My results based on that are here: https://gist.github.com/Berdir/5052940

alexpott’s picture

See #1920902: Add a Drupal Yaml wrapper so we can default to PECL Yaml component if it is available for an implementation of a wrapper to use PECL extension or Symfony's php land implementation if the extension is not available.

alexpott’s picture

Status:Active» Needs review
StatusFileSize
new4.8 KB
PASSED: [[SimpleTest]]: [MySQL] 64,567 pass(es).
[ View ]
new197.36 KB

Looking at the Symfony code I think there are some optimisations we can do here - will submit an upstream PR in a bit.

The xhprof for this looks very promising - although as @Berdir has said Symfony's YAML parser is noticeably slowed by xhprof.

alexpott’s picture

StatusFileSize
new90.83 KB

Disabling cpu and memory flags in XHProf so the profiling as less of an impact - still shows a massive improvement.

alexpott’s picture

Using https://gist.github.com/msonnabaum/5052884

HEAD

---
extension:
  min: "0.0432"
  max: "16.3412"
  mean: "0.5542"
  median: "0.4959"
  95th: "1.0169"
...
---
symfony:
  min: "0.0720"
  max: "91.5120"
  mean: "2.8574"
  median: "0.7825"
  95th: "11.4605"

Patch applied

---
extension:
  min: "0.0391"
  max: "2.8601"
  mean: "0.1332"
  median: "0.0739"
  95th: "0.3619"
...
---
symfony:
  min: "0.0701"
  max: "86.2439"
  mean: "2.4967"
  median: "0.5456"
  95th: "10.4421"
...

So this patch definitely is an optimisation.

alexpott’s picture

alexpott’s picture

StatusFileSize
new6.62 KB
PASSED: [[SimpleTest]]: [MySQL] 64,587 pass(es).
[ View ]

https://github.com/symfony/symfony/pull/10312 got merged!
Created another one already :) https://github.com/symfony/symfony/pull/10317

With this https://gist.github.com/msonnabaum/5052884 now looks like

---
extension:
  min: "0.0379"
  max: "2.3031"
  mean: "0.1239"
  median: "0.0720"
  95th: "0.3443"
...
---
symfony:
  min: "0.0710"
  max: "67.1241"
  mean: "2.1525"
  median: "0.5441"
  95th: "8.7903"
...
alexpott’s picture

Considering both https://github.com/symfony/symfony/pull/10312 and https://github.com/symfony/symfony/pull/10317 have now been merged - we could commit the fixes directly to our /vendor to get the benefits early?

catch’s picture

I think we should do that - but can we do it via updating composer to point to the hash?

alexpott’s picture

Not really - we're already on 2.4.* and fabpot merged to 2.3-dev (no idea why) so it is not in 2.4.* or 2.4-dev yet.

alexpott’s picture

StatusFileSize
new14.9 KB
PASSED: [[SimpleTest]]: [MySQL] 64,761 pass(es).
[ View ]

So what we can do is update

-    "symfony/yaml": "2.4.*",
+    "symfony/yaml": "2.4.*@dev",

and then $ composer update symfony/yaml

alexpott’s picture

StatusFileSize
new15.67 KB
PASSED: [[SimpleTest]]: [MySQL] 64,713 pass(es).
[ View ]

Or we can fix to a specific commit...

sun’s picture

Component:cache system» base system
Status:Needs review» Reviewed & tested by the community

Thanks! That appears to be in line with some of our other dev dependencies:

+    "symfony/yaml": "dev-master#e49a47d60348665261f6e279ba383241deb73cab",
...
     "doctrine/common": "dev-master#a45d110f71c323e29f41eb0696fa230e3fa1b1b5",

Might be a good idea to file an issue to lock down those other dependencies that are currently using 2.4.*, too...

RTBC if bot agrees.

catch’s picture

Status:Reviewed & tested by the community» Fixed

Looks great. We can get back on the next point release but I'd rather pin to a commit than handle local patches.

Status:Fixed» Closed (fixed)

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