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.

We've moved the forum!

Please use forum.silverstripe.org for any new questions (announcement).
The forum archive will stick around, but will be read only.

You can also use our Slack channel or StackOverflow to ask for help.
Check out our community overview for more options to contribute.

Template Questions /

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

Testing Partial Caching - Notes


Go to End


6 Posts   3177 Views

Avatar
elgordo

Community Member, 70 Posts

26 April 2011 at 7:39pm

Edited: 26/04/2011 7:45pm

hi

There does not seem to be a huge amount of information out there regarding partial caching so here are a few notes from my experiences.

1) You can manually delete the cache manually from disk by deleting the contents of /tmp/silverstripe-name-of-install-path/cache

2) debug_profile is your friend. This shows the the length of time a method takes and how often it was called, those with high values are often a good candidate for partial caching.

As an example let us consider a template for a sitemap, which has to iterate through the entire site tree in order to form the sitemap.

Without caching the debug profile shows this:

============================================================================
                              PROFILER OUTPUT
============================================================================
Calls                    Time  Routine
-----------------------------------------------------------------------------
  1    525.6441 ms (73.30 %)  obj.SiteMap
  1    132.5247 ms (18.48 %)  all_execution
  2    28.6548 ms (4.00 %)  SSViewer::process
  1    6.3190 ms (0.88 %)  obj.Menu
  2    5.7511 ms (0.80 %)  obj.LastEdited
  1    2.8870 ms (0.40 %)  obj.Content
  1    2.8121 ms (0.39 %)  obj.Title
  2    2.3530 ms (0.33 %)  obj.TheCurrentLocale
  1    2.3081 ms (0.32 %)  SSViewer::process - compile
  3    1.3778 ms (0.19 %)  obj.Aggregate
  1    0.9809 ms (0.14 %)  DB::connect
  1    0.7699 ms (0.11 %)  main.php init
  2    0.4091 ms (0.06 %)  obj.ID
  2    0.3302 ms (0.05 %)  obj.ContentLocale
  1    0.3102 ms (0.04 %)  obj.Level
  1    0.3080 ms (0.04 %)  obj.Form
  3    0.3011 ms (0.04 %)  obj.IsLive
  1    0.2770 ms (0.04 %)  obj.isImageItem
  1    0.2739 ms (0.04 %)  obj.SectionPage
  1    0.1020 ms (0.01 %)  obj.Layout
  2    0.0880 ms (0.01 %)  Requirements::includeInHTML
  1    0.0250 ms (0.00 %)  unprofiled

       2.3386 ms (0.33 %)  Missed
============================================================================
       717.1459 ms (100.00 %)  OVERALL TIME
============================================================================

With caching, it is a different story:

============================================================================
                              PROFILER OUTPUT
============================================================================
Calls                    Time  Routine
-----------------------------------------------------------------------------
  1    139.0479 ms (75.54 %)  all_execution
  2    21.5411 ms (11.70 %)  SSViewer::process
  1    9.3021 ms (5.05 %)  obj.Menu
  2    3.9222 ms (2.13 %)  obj.LastEdited
  2    2.2361 ms (1.21 %)  obj.TheCurrentLocale
  3    1.5733 ms (0.85 %)  obj.Aggregate
  1    0.9320 ms (0.51 %)  DB::connect
  1    0.7181 ms (0.39 %)  main.php init
  1    0.5250 ms (0.29 %)  obj.Form
  1    0.4790 ms (0.26 %)  obj.SectionPage
  2    0.4361 ms (0.24 %)  obj.ContentLocale
  2    0.4070 ms (0.22 %)  obj.ID
  1    0.3579 ms (0.19 %)  obj.Level
  3    0.3407 ms (0.19 %)  obj.IsLive
  1    0.3231 ms (0.18 %)  obj.isImageItem
  1    0.1051 ms (0.06 %)  obj.Layout
  2    0.0911 ms (0.05 %)  Requirements::includeInHTML
  1    0.0269 ms (0.01 %)  unprofiled

       1.6961 ms (0.92 %)  Missed
============================================================================
       184.0608 ms (100.00 %)  OVERALL TIME
============================================================================

You can see here that the caching has ensured that the Site Tree was not traversed in the database, saving half a second.

Incidentally the template used was

<% cached 'Sitemap', Aggregate(Page).Max(LastEdited) %>

<h1 class="head">$Title</h1>
<span class="txt">
$Content
<div id="sitemap">
$SiteMap
</div>

</span><!--/txt-->

<% end_cached %>

$Form

Each time a page is saved, the sitemap cache is invalidated. Thus the sitemap is always rendered up to date, but if no editing is occurring then a cached version will be served.

3) Make sure your cache key contains all the input parameters. For example I initially cached a search result page by query, but then page 1, page 2 etc are the same.

4) Don't put $Form inside a cached/end_cached construct. i did this with the Page class template and then could not log in.

Cheers

Gordon

Avatar
elgordo

Community Member, 70 Posts

26 April 2011 at 7:42pm

A second example showing trace from the menu:

Uncached:

============================================================================
                              PROFILER OUTPUT
============================================================================
Calls                    Time  Routine
-----------------------------------------------------------------------------
  1    165.3121 ms (32.25 %)  all_execution
  2    132.0100 ms (25.75 %)  SSViewer::process
 15    79.0133 ms (15.41 %)  obj.Children
 35    68.0511 ms (13.28 %)  obj.Link
  3    20.8154 ms (4.06 %)  obj.Menu
  1    11.0559 ms (2.16 %)  obj.PagesWithAccessKeys
 35    7.7891 ms (1.52 %)  obj.Title
  3    5.4679 ms (1.07 %)  obj.LastEdited
 14    4.2307 ms (0.83 %)  obj.LinkOrSection
  5    2.1892 ms (0.43 %)  obj.LinkingMode
  2    1.9109 ms (0.37 %)  obj.AccessKey
  1    1.8830 ms (0.37 %)  obj.PageMenuCacheKey
  2    1.5960 ms (0.31 %)  obj.Aggregate
  1    0.8261 ms (0.16 %)  DB::connect
  1    0.7491 ms (0.15 %)  main.php init
  2    0.4711 ms (0.09 %)  obj.ID
  2    0.3660 ms (0.07 %)  obj.TheCurrentLocale
  1    0.3340 ms (0.07 %)  obj.Level
  1    0.3121 ms (0.06 %)  obj.SectionPage
  2    0.2999 ms (0.06 %)  obj.ContentLocale
  1    0.2980 ms (0.06 %)  obj.Form
  3    0.2520 ms (0.05 %)  obj.IsLive
  1    0.1280 ms (0.02 %)  obj.Layout
  2    0.0679 ms (0.01 %)  Requirements::includeInHTML
  1    0.0331 ms (0.01 %)  unprofiled

       7.1390 ms (1.39 %)  Missed
============================================================================
       512.6011 ms (100.00 %)  OVERALL TIME
============================================================================

Cached:

============================================================================
                              PROFILER OUTPUT
============================================================================
Calls                    Time  Routine
-----------------------------------------------------------------------------
  1    138.5639 ms (76.44 %)  all_execution
  2    17.5796 ms (9.70 %)  SSViewer::process
  1    10.1490 ms (5.60 %)  obj.Menu
  3    4.1497 ms (2.29 %)  obj.LastEdited
  1    1.9250 ms (1.06 %)  obj.PageMenuCacheKey
  2    1.4620 ms (0.81 %)  obj.Aggregate
  1    1.1699 ms (0.65 %)  DB::connect
  1    0.7579 ms (0.42 %)  main.php init
  2    0.5391 ms (0.30 %)  obj.ContentLocale
  2    0.3932 ms (0.22 %)  obj.ID
  3    0.3729 ms (0.21 %)  obj.IsLive
  2    0.3190 ms (0.18 %)  obj.TheCurrentLocale
  1    0.3111 ms (0.17 %)  obj.Form
  1    0.2971 ms (0.16 %)  obj.SectionPage
  1    0.2940 ms (0.16 %)  obj.Level
  1    0.1400 ms (0.08 %)  obj.Layout
  2    0.0780 ms (0.04 %)  Requirements::includeInHTML
  1    0.0279 ms (0.02 %)  unprofiled

       2.7518 ms (1.52 %)  Missed
============================================================================
       181.2809 ms (100.00 %)  OVERALL TIME
============================================================================

It should be immediately obvious that the number of calls to Link and Title are dramatically reduced, as the menu is cached as a partial

Avatar
Willr

Forum Moderator, 5523 Posts

26 April 2011 at 8:23pm

Hi Gordon,

Glad you found the partial caching functionality useful! For the forms there is an <% uncached %> tag you can use (so you can still cache the remainder) which I'm sure you found, just posting that in case anyone was wondering.

http://doc.silverstripe.org/sapphire/en/reference/partial-caching has quite a bit of documentation on it and examples.

It's all still pretty new so quite a few of the modules don't yet use partial caching but hopefully seeing those <% cached %> calls will be fairly standard pretty soon!

Debug_profile is useful, however there has been discussion whether to remove it. Tools like XHProf and xdebug profile much more accurate data and generally more sophisticated data reporting. Debug_profile won't be 100% accurate or will leave chucks unprofiled in bigger apps.

Avatar
elgordo

Community Member, 70 Posts

26 April 2011 at 8:34pm

Edited: 26/04/2011 8:35pm

hi Will

i did not now about the uncached tag, guess I am new to Silverstripe partial caching also :) I've used it in Rails many times, it is good to see the functionality in Silverstripe. Pages definitely feel 'snappier' now on the site I am working on.

Regarding documentation I think I was slightly confused by

<% cached 'loginblock', LastEdited, CurrentMember.isAdmin %>

I initially thought that that CurrentMember.isAdmin was a boolean conditional and that toggled whether or not the caching happened, but see now that is it just simply chaining a list of parameters together to make the cache key.

And thanks for the heads up regarding debug_profile - even if not 100% accurate it is useful in ascertaining whether or not partial caching is actually happening. I'll look into the other tools you mentioned when I get some time

Regards

Gordon

Avatar
elgordo

Community Member, 70 Posts

26 April 2011 at 8:36pm

hi Will

One other useful thing would be the ability to optionally log the cache keys being generated - e.g. by setting a condition in mysite/_config.php

Cheers

Gordon

Avatar
Plump

Community Member, 1 Post

20 February 2016 at 6:16am

Edited: 20/02/2016 6:17am

Definitely agree about point 4. I had a form inside a <% cached %> block and it stopped working as expected. I'm assuming it has something to do with the CSRF token. If the form is cached then I imagine several visitors all get the same token, which may well be invalid. If the idea is meant to be that each user gets a unique token per request then caching it would clearly break that. You could disable CSRF on the form but better to use <% uncached %> around the form or move it outside of the cached block.