Skip to main content

This site requires you to update your browser. Your browsing experience maybe affected by not having the most up to date version.

General Questions /

General questions about getting started with SilverStripe that don't fit in any of the categories above.

Moderators: martimiz, Sean, biapar, Willr, Ingo, swaiba, simon_w

As the cache fills up, the CMS slows down. Why?


Reply


5 Posts   851 Views

Avatar
inCharge

Community Member, 102 Posts

20 October 2011 at 5:08am

Edited: 20/10/2011 5:10am

Browsing a site while logged in, the time taken to add the SilverStripeNavigator to the bottom of pages increases as the cache (i.e. silverstripe-cache/cache) fills up. And in the CMS, clicking between different pages also slows down by a similar amount. With an empty cache, it's fine, but with 800 files in the cache, it takes 10 seconds.

Why does the number of files in the cache slow down the CMS so much? Is it opening & reading all the files?

See the SS profiler stats below. All tests are for the home page, but with more and more files in the cache. Apparently the profiler is not that accurate, but you can see the trend. SilverStripeNavigator takes longer with more files in the cache, while everything else takes roughtly the same amount of time.

The reason there are so many files in the cache is that I'm using partial cacheing, with nested cache statements. But even if there was one cache statement per page, you could easily end up with hundreds of cached files.

With 46 files in the cache

1 243.4239 ms (47.75 %) obj.SilverStripeNavigator
1 155.2176 ms (30.44 %) all_execution
3 60.3511 ms (11.84 %) SSViewer::process
1 12.3971 ms (2.43 %) obj.SearchForm
3 10.9773 ms (2.15 %) Requirements::includeInHTML

With 68 files in the cache

1 497.4611 ms (53.87 %) obj.SilverStripeNavigator
1 286.8311 ms (31.06 %) all_execution
3 53.2906 ms (5.77 %) SSViewer::process
1 33.5441 ms (3.63 %) obj.SearchForm
1 16.5172 ms (1.79 %) DB::connect
15 11.9231 ms (1.29 %) obj.LastEdited
3 10.8979 ms (1.18 %) Requirements::includeInHTML

With 112 files in the cache

1 559.7022 ms (64.71 %) obj.SilverStripeNavigator
1 191.7541 ms (22.17 %) all_execution
3 54.7309 ms (6.33 %) SSViewer::process
1 16.2411 ms (1.88 %) obj.SearchForm
3 11.6217 ms (1.34 %) Requirements::includeInHTML
15 10.8404 ms (1.25 %) obj.LastEdited

With 178 files in the cache

1 1716.6369 ms (78.37 %) obj.SilverStripeNavigator
1 193.6250 ms (8.84 %) all_execution
1 168.0191 ms (7.67 %) DB::connect
3 60.2496 ms (2.75 %) SSViewer::process
1 16.5620 ms (0.76 %) obj.SearchForm
15 11.2576 ms (0.51 %) obj.LastEdited
3 10.5321 ms (0.48 %) Requirements::includeInHTML

With 376 files in the cache

1 2744.0882 ms (91.65 %) obj.SilverStripeNavigator
1 156.5731 ms (5.23 %) all_execution
3 45.2673 ms (1.51 %) SSViewer::process
1 12.2089 ms (0.41 %) obj.SearchForm
3 10.2072 ms (0.34 %) Requirements::includeInHTML
15 8.8062 ms (0.29 %) obj.LastEdited

Avatar
inCharge

Community Member, 102 Posts

20 October 2011 at 8:32am

Edited: 20/10/2011 8:35am

> Why does the number of files in the cache slow down the CMS so much?
> Is it opening & reading all the files?

Oh no. SilverStripeNavigator opens, reads and unserianlses every metadata file (so half the files) in the cache.

This happens in the function Zend_Cache_Backend_File->_clean ...

   $glob = @glob($dir . $prefix . '--*');
   if ($glob === false) {
      return true;
   }
   foreach ($glob as $file) {
      if (is_file($file)) {
         $fileName = basename($file);
         if ($this->_isMetadatasFile($fileName)) {

Putting a SS_Backtrace::backtrace() in there shows it is called by SilverStripeNavigatorItem_ArchiveLink->getHTML i.e. every time the navigator is shown.

It's a massive stack, but the crucial bit is...

Line 429 of Core.php
Zend_Cache_Core->clean(matchingAnyTag,Array)

Line 53 of Aggregate.php
Aggregate::flushCache(SiteTree)

Line 2828 of DataObject.php
DataObject->flushCache()

Line 763 of Versioned.php
Versioned::get_one_by_stage(SiteTree,Draft,"SiteTree"."ID" = 31)

Line 162 of SilverStripeNavigatorItem.php
SilverStripeNavigatorItem_ArchiveLink->getHTML(Page)

This is a real problem for partial cacheing. We had to abandon a training session earlier today. With 4 users accessing the CMS simultaneously, web server CPU usage was at 100% and requests were timing out. Changing all the 'cached' statements to 'uncached' and emptying the cache fixed the problem.

Avatar
Willr

Forum Moderator, 5513 Posts

20 October 2011 at 8:24pm

inCharge, nice debugging. Could you post your findings to open.silverstripe.org so that the core devs can keep track of that. Patches to solve that welcome though I wonder what archive link is used for anyway.

Avatar
Miroke

Community Member, 9 Posts

21 October 2011 at 2:21am

If any developer confirm this, it's a serious problem.

I think i'll disable Static Publisher by now.

Avatar
inCharge

Community Member, 102 Posts

21 October 2011 at 2:40am

Ticket raised: http://open.silverstripe.org/ticket/6749

> I wonder what archive link is used for anyway

It creates the links in the navigator where it says Page view: CMS, Draft Site, Published Site

For each link, a different subclass of SilverStripeNavigatorItem is used, but they all result in a call to DataObject:flushCache

> I think i'll disable Static Publisher by now.

I don't think this affects Static Publisher because it works in a different way, by generating complete files, not using the Zend cache to cache parts of files.

The problem with the Static Publisher is that if there is ANY dynamic content on the page, you can't use it.

Even if I'm right, partial cacheing is still good for small sites, or where per-page cacheing is avoided e.g. cache common HTML like menu & footer, and a few expensive pages like sitemap.