Why is Symfony2 app spending 70-90% of its time parsing YAML?

Question

As shown in the Webgrind output below, my app is spending most of its processing time on YAML parsing.

Note: the Webgrind output is in "percent". So, adding up the "Total Self Cost" shows 83.63 percent of the total time is spent processing YAML.

I've seen this related thread:

Symfony2 Application Parses YML On Every Request

However, my implementation is using the ApcClassLoader class as seen below:

$loader = new ApcClassLoader('odr_dev', $loader);
$loader->register(true);

Additionally, I've checked the APC system using apc.php and my classes and pages are found in the APC cache and are being hit. This takes place on either PROD or DEV on any request even after the caches are populated.

My theory is that we have a circular entity reference and the system can't successfully parse the YAML in order to cache it. So, it ends up trying to parse the YAML on every request.

However, I don't see any errors about being unable to parse YAML or anything in the logs and am unsure how to determine if this could be the case or where to look next.

Answer 1

I think your issue is probably recursive YAML resources (or similar). You are seeing 4000+ invocations of Yaml\Parser::parse. In a test of my own app (which is fairly complex) on a page load with a completely empty cache I only see 166 invocations. And that drops to 2 invocations for page loads with a warm cache.

I don't think your use of a class loader cache would have any impact on YAML parsing, as you discovered. I suspect the ticket you link to is probably wrong)

Answer 2

After stepping through every line of code involved in this process, I found that Doctrine is using the default "array" cache which is only valid for a single page load.

I think myself and many others assumed that when we turned on APC it would also be used by Doctrine for metadata caching. In fact, Doctrine defaults to its array cache unless otherwise specified.

This page lists the Doctrine configuration options:

http://symfony.com/doc/2.3/reference/configuration/doctrine.html

After adding cache driver options to my /app/config/config.yml as shown below:

doctrine:
    dbal:
        driver:   %database_driver%
        host:     %database_host%
        port:     %database_port%
        dbname:   %database_name%
        user:     %database_user%
        password: %database_password%
        charset:  UTF8
    orm:
        auto_generate_proxy_classes: %kernel.debug%
        auto_mapping: true
        result_cache_driver:
            type: memcached
            host: 127.0.0.1
            port: 11211
            instance_class: Memcached
        metadata_cache_driver:
            type: memcached
            host: 127.0.0.1
            port: 11211
            instance_class: Memcached
        query_cache_driver:
            type: memcached
            host: 127.0.0.1
            port: 11211
            instance_class: Memcached

After the fix, the same page shows no YAML parser interaction and loads in 302ms vs. 5851ms for a total speedup of 19X. Additionally, the cachegrind file went from 121MB to 3.4MB and these results are generally consistent over a number of trials.

Here is the same Webgrind showing the difference:

So, basically, it was a configuration issue. From what I've seen in StackOverflow questions and other forums, it seems there is a disconnect here about how caching works. Essentially, you need to explicitly turn it on for Doctrine caching as outlined above or it uses a basically useless default.

Symfony2 can sometimes be too "configurable" and this is one instance where it never occurred to me that it would be separately configurable. In that regard, it's a powerful feature (being able to use separate caches for things), but until you figure this out, the system is totally compromised as far as speed is concerned.