Jump to:

3439 Posts in 1028 Topics by 869 members

Template Questions

SilverStripe Forums » Template Questions » Testing Partial Caching - Notes

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

Page: 1
Go to End
Author Topic: 1121 Views
  • elgordo
    Avatar
    Community Member
    70 Posts

    Testing Partial Caching - Notes Link to this post

    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

  • elgordo
    Avatar
    Community Member
    70 Posts

    Re: Testing Partial Caching - Notes Link to this post

    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

  • Willr
    Avatar
    Forum Moderator
    5497 Posts

    Re: Testing Partial Caching - Notes Link to this post

    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.

  • elgordo
    Avatar
    Community Member
    70 Posts

    Re: Testing Partial Caching - Notes Link to this post

    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

  • elgordo
    Avatar
    Community Member
    70 Posts

    Re: Testing Partial Caching - Notes Link to this post

    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

    1121 Views
Page: 1
Go to Top

Want to know more about the company that brought you SilverStripe? Then check out SilverStripe.com

Comments on this website? Please give feedback.