• Kris Wallsmith
• 12 months ago
• Living on the edge
• 25

A few weeks ago I was surprised by a PHP out-of-memory error in the production environment for one of my symfony 1.2 powered sites. This error was being thrown by sfViewCacheManager, the class responsible for deciding whether to render a cached or freshly executed template. The particular line in question generated a "cache key" by running a template's variables through md5(serialize($vars)). This key is then included in a URI that is used to find a cached template.

These are very resource-intensive functions, particularly when passing them large model or form objects. The cause of my problem seemed apparent. I went through my application and added sf_cache_key variables to all my calls to include cached components and partials. With that variable provided by me, symfony would no longer have to run cached paritals' variables through md5(serialize($vars)). Problem solved, right?

No. The errors came back the next day. I dug into the symfony core once again found the root cause for these errors. When the cache was switched on in settings.yml a partial's variables were always passed through md5(serialize($vars)), regardless of whether the cache is enabled for that particular partial in cache.yml. This is why this error was only happening on servers with the cache enabled and why only adding a sf_cache_key variable to cached partials didn't solve the problem.

I wrote a custom partial view class for my application that made sure every partial had at least a random sf_cache_key variable, insuring that md5(serialize($vars)) would never have to be called. That was a temporary fix to keep this particular site online. Today I committed a more reliable fix to all versions of symfony and the performance improvement is quite stunning.

The Benchmarks

To benchmark this improvement I created a very simple project with one action and one partial:

$ mkdir ~/Sites/cache_key_fix
$ cd ~/Sites/cache_key_fix
$ symfony generate:project cache_key_fix
$ symfony generate:app frontend
$ symfony generate:module frontend main

The main/index action is very simple, although you can see I'm passing a very large object to my partial, the sfContext instance.

// apps/frontend/modules/main/actions/actions.class.php
class mainActions extends sfActions
{
  public function executeIndex()
  {
  }
}
 
// apps/frontend/modules/main/templates/indexSuccess.php
<?php for ($i = 0; $i < 100; $i++): ?>
  <?php include_partial('foo', array(
    'foo' => sfContext::getInstance(),
    'bar' => sfContext::getInstance())) ?>
<?php endfor; ?>
 
// apps/frontend/modules/main/templates/_foo.php
<p>foo</p>

The cache key is never generated when the sf_cache setting is disabled, so I enabled that:

# apps/frontend/config/settings.yml
prod:
  .settings:
    cache: on

Since I'm comparing two revisions of symfony, I also added a request variable to the project configuration to be able to switch between checkouts of the core.

// config/ProjectConfiguration.class.php
if (array_key_exists('before', $_GET))
{
  require_once dirname(__FILE__).'/../../sf_before/lib/autoload/sfCoreAutoload.class.php';
}
else
{
  require_once dirname(__FILE__).'/../../sf_after/lib/autoload/sfCoreAutoload.class.php';
}
sfCoreAutoload::register();
 
class ProjectConfiguration extends sfProjectConfiguration
{
}

If you want to run this benchmark comparison on your own project, checkout a before and after copy of the symfony core.

$ svn co http://svn.symfony-project.com/branches/1.2 -r16904 ~/Sites/sf_before
$ svn co http://svn.symfony-project.com/branches/1.2 -r16905 ~/Sites/sf_after

Once the project is in place, hit it once so the config cache is established:

$ curl http://localhost/cache_key_fix/web/index.php/main/index > /dev/null

Now you're ready for the actual benchmarking. Compare the output of the following commands:

$ ab -t 60 -n 20 http://localhost/cache_key_fix/web/index.php/main/index?before
$ ab -t 60 -n 20 http://localhost/cache_key_fix/web/index.php/main/index?after

You should see a significant difference. This is what I got on my MacBook:

Before

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:      289  319  19.4    321     365
Processing:   127  181  54.4    182     388
Waiting:      127  181  54.4    182     387
Total:        462  501  57.0    488     731

After

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:       72  112  60.9     96     308
Processing:     0  143  45.6    157     192
Waiting:        0  143  45.6    157     192
Total:        228  255  24.5    253     347

Whoa. The fastest "before" request (462 ms) is still longer than the slowest "after" request (347 ms), and the mean average shows nearly a 50% decrease in total response time (from 501 to 255 ms).

Of course, these numbers should be taken with a grain of salt. Not all applications pass large objects to partials, although the form object passed around the admin generator templates can be pretty big, depending on what you're storing in your model objects.

Please let us know if you notice any marked performance improvements in any of your applications!

Comments

• 

  #1 Yoni said 9 minutes later

  Hello,

  seem to be really great
  but how can we download this fix ?

  thx

  Yoni

• 

  #2 Fabian said 31 minutes later

  Kris,
  just upped my sites and I was able to see a noticeable improvement in memory and CPU. good work.

  Yoni,
  the change is in latest svn version which I would recommend to use anyway. I will release symfony 1.2.6 for example soon, but not having my sites running a few days after big changes. By doing so I avoid rereleasing too many versions

• 

  #3 Jan Markmann said about 1 hour later

  @Fabian:
  Well it might be an idea to release a special bugfix release, since this is a major issue.
  A version 1.2.5a wouldn hurt that much if it does not become a regular case. So far I would also vote for a 1.2.5a that does only add this patch to 1.2.5.
  Or at least release patches until new version come.
  Latest SVN is no option for people using externals that need to be as stable as a tag, not living like a branch.

• 

  #4 Jan Markmann said about 2 hours later

  @Kris:
  WOW, nice work, waited for that ticket to get closed. Fake cache keys look that ugly =)

• 

  #5 Yuriy Voziy said about 4 hours later

  Where can I get the patch?

• 

  #6 Kris said about 4 hours later

  @Yuriy If you're not using an svn:external and can't wait until the next release you can always download the patch from Trac: http://trac.symfony-project.org/changeset/16905/branches/1.2

• 

  #7 Ariel Arjona said about 13 hours later

  my sites feel way snappier (I do have fairly large forms).

• 

  #8 Christoph Hautzinger said about 14 hours later

  isn't it a good style to always pass a "sf_cache_key" parameter to your partials/components?

  but anyway... nice fix!

• 

  #9 Dejan Spasic said about 16 hours later

  Nice enhancement. Thanks a lot!

• 

  #10 Sylvio said about 17 hours later

  Waw big performance enhancement !

  Is this kind of enhancement could be apply to SF1.0 or SF1.0 works differently ?

• 

  #11 Kris said about 17 hours later

  @Christoph that's up to you, but passing the sf_cache_key var should have no effect if the partial is not cached, which is now the case

• 

  #12 jwage said about 21 hours later

  The benefit to Doctrine users from this fix is HUGE. Because Doctrine is extremely OOP and the objects are large and cyclic. In some very raw tests things do seem about twice as fast under dev mode. On a page with about 4-5 queries and a fairly large amount of Doctrine data objects being passed to templates before was about 700ms and is now 350ms consistently.

• 

  #13 halfer said about 22 hours later

  @Sylvio - a change for 1.0 is coming. The svn comments added by Kris indicate that a backport for this branch will be done in the future (presumably because the architecture is quite different).

  And, since we're still on 1.0, we look forward to this enormously. We're in no major rush - personally I am happy to wait a while for releases containing this fix.

• 

  #14 Kris said about 23 hours later

  @halfer @Sylvio This fix was backported to symfony 1.0 in r16907

• 

  #15 halfer said about 23 hours later

  @Kris - many thanks. We'll give this a try on our test server :o)

• 

  #16 Alex said 1 day later

  Hello,

  A few of us are having similar problem with memory usage. But this is not related to caching. Please see http://forum.symfony-project.org/index.php?t=rview&goto=76230#msg_76230

  Thanks.
  Alex.

• 

  #17 Daniel said 3 days later

  Is this likely to make its way to the 1.1 branch also?

• 

  #18 halfer said 4 days later

  @Daniel - already available for 1.1:

  http://trac.symfony-project.org/ticket/5814

• 

  #19 halfer said 4 days later

  @Alex - if you know your issue is unrelated please don't post it here. There is an ongoing discussion in the forum for that.

• 

  #20 Christian said 4 days later

  Great to read about these improvements, sounds like my questions raised in the forum (http://forum.symfony-project.org/index.php/m/76200 and http://forum.symfony-project.org/index.php/m/72996) got answered.

  It would be great to have an intermediate bugfix release, my site on production is regularly suffering from this malady.

• 

  #21 Fabian said 4 days later

  @all
  a version containing this stuff will come soon, however I had an issue on one of my test boxes, that I want to sort out before releasing. I take that responsibility for the stability of your boxes seriously and we have had a few nontrivial changes on the branch lately.
  Thanks for your understanding

• 

  #22 naholyr said 15 days later

  We updated our 1.0 project yesterday and made some tests but nothing seems to have changed :/

  Where are we supposed to see the changes ? With lazy_cache_key on or off (found in the SVN log, is there any documentation about this ?), there is no difference in the displayed execution time or memory in debug toolbar.

  More information about where there is a real difference ?

• 

  #23 Kris said 15 days later

  @naholyr You now need to turn the sf_cache_key setting on in order to see these improvements. This will be documented in the coming minor releases. You also need to have the cache turned on, as noted above.

• 

  #24 naholyr said 16 days later

  This may be a problem with the cache enabled I suppose (but I think it's ok as we have the "reload ignoring cache" button in the debug toolbar).

  I mean, are we supposed to notice some change in the times and/or memory displayed in the debug toolbar ? Or is it something that will be seen only in the server's stats ?

• 

  #25 Kris said 16 days later

  @naholyr The patch improves the performance of calls to render a template partial or component that is passed one or more large objects without a sf_cache_key parameter when the cache is on.