I'm working on a solution that contains some quite advanced XSLT. And in some places performance is really starting to hurt!
But how do I go about figuring out what to optimize? Both internally in the individual XSLT macros, but also across entire pages (figure out which macro is running slowly).
Can ?umbDebugShowTrace=true be used for this? Are the "From first" and "From last" columns timing values, and how do I read them?
Any hints on how to figure out where I should concentrate my efforts will be greatly appreciated.
So you can debug anything that takes more than a second.
What I did, (which was nuts, but still), was just remove parts of the XSLT and looked at the timing difference.
Also, one tip: the FIRST time that you load a page with an XSLT that has changed, there will be some overhead. The timings are only correct from the second reload of the page.
Start by setting all macro cache values to 0 to disable caching (we
can add it later but for now we want to see the real performance not the
awesome cached performance).
Load your page with the
?umbDebugShowTrace=true querystring.
You'll see a bunch of
output. Look for a block for each of your macros. The entire process of
the macro will have about 10 lines from the time the macro is called to
the time it is fully rendered. Look for any large numbers in the last
column (that is, anything more than a tenth of a second, for example).
Macro loaded from cache (ID: 24, Nav Main) Rendering started (macro: Nav Main, type: 1, cacheRate: 0) Before adding extensions Extension added: ..... After adding extensions Before performing transformation After performing transformation
Usually
the 'After performing transformation' is the biggie... there's where
the actual xslt is processed.
Usually you can speed things up by better xpath statements that have to traverse less of the content tree, or which return fewer nodes to cycle through in a for-each statement.
First of all, add ?umbDebugShowTrace=true to your page.
Then look through the "From Last(s)" column and search for any high values. When you find one, you can read which macro has issues a bit above that. Here's an example:
Notice the highlighted values/lines, this is where the issue is (the "Product Lister" macro).
Now for debuging the XSLT macro itself, I just started commenting out lines trying to narrow down the specific lines that was causing the suffering. Or, use Sebastiaans method if you can't comment out anything.
But thanks a lot guys! Once again, the excellent Umbraco community comes to the rescue :-)
* Declare variables outside of loops if possible * Don't use the nasty "//" at the start of your xpaths it hammers performance as it has to search every node * Avoid loops within loops
Its the second one that tends to cause all the performance issues. Searching a huge XML tree numerous times can soon add up.
Then I have a macro that pulls out all products in a given category based on that XML file. No performance issues here, even in large categories with 800+ products.
My issues was with a method of pulling out all unique sizes in a given category. See this page for two methods on how to do that.
Originally I was using the [not(.=preceeding::size)] method, and that was taking 9+ seconds.After rewriting it to use the other method where you generate a key, it is down to below 1 second for large categories.
Hopes it make sense. Anyway it solved my problem :-)
XSLT Performance, figuring out where it hurts
Hi fellow Umbracians,
I'm working on a solution that contains some quite advanced XSLT. And in some places performance is really starting to hurt!
But how do I go about figuring out what to optimize? Both internally in the individual XSLT macros, but also across entire pages (figure out which macro is running slowly).
Can ?umbDebugShowTrace=true be used for this? Are the "From first" and "From last" columns timing values, and how do I read them?
Any hints on how to figure out where I should concentrate my efforts will be greatly appreciated.
Best regards,
Soeren S.
"From last" is the difference between the current action and the previous action.
The problem with debugging XSLT is that timing is kind of difficult to display, but you could always go oldschool and put something in there like:
<xsl:value-of select="Exslt.ExsltDatesAndTimes:datetime()" />So you can debug anything that takes more than a second.
What I did, (which was nuts, but still), was just remove parts of the XSLT and looked at the timing difference.
Also, one tip: the FIRST time that you load a page with an XSLT that has changed, there will be some overhead. The timings are only correct from the second reload of the page.
Start by setting all macro cache values to 0 to disable caching (we can add it later but for now we want to see the real performance not the awesome cached performance).
Load your page with the ?umbDebugShowTrace=true querystring.
You'll see a bunch of output. Look for a block for each of your macros. The entire process of the macro will have about 10 lines from the time the macro is called to the time it is fully rendered. Look for any large numbers in the last column (that is, anything more than a tenth of a second, for example).
Usually the 'After performing transformation' is the biggie... there's where the actual xslt is processed.
Usually you can speed things up by better xpath statements that have to traverse less of the content tree, or which return fewer nodes to cycle through in a for-each statement.
cheers,
doug.
Thanks guys, you're both spot on!
Here's what I did:
First of all, add ?umbDebugShowTrace=true to your page.
Then look through the "From Last(s)" column and search for any high values. When you find one, you can read which macro has issues a bit above that. Here's an example:
umbracoMacro Macro loaded from cache (ID: 29, Product Lister) 0,170354612108522 0,000075
renderMacro Rendering started (macro: Product Lister, type: 1, cacheRate: 0) 0,17038506290604 0,000030
umbracoMacro Before adding extensions 0,241016944891041 0,070632
umbracoXsltExtension Extension added: urn:Exslt.ExsltCommon, ExsltCommon 0,241648589415694 0,000632
umbracoXsltExtension Extension added: urn:Exslt.ExsltDatesAndTimes, ExsltDatesAndTimes 0,241677084657408 0,000028
umbracoXsltExtension Extension added: urn:Exslt.ExsltMath, ExsltMath 0,241701948152628 0,000025
umbracoXsltExtension Extension added: urn:Exslt.ExsltRegularExpressions, ExsltRegularExpressions 0,241726252917619 0,000024
umbracoXsltExtension Extension added: urn:Exslt.ExsltStrings, ExsltStrings 0,241750278317496 0,000024
umbracoXsltExtension Extension added: urn:Exslt.ExsltSets, ExsltSets 0,241774303717372 0,000024
umbracoXsltExtension Extension added: urn:CommerceLibrary, Library 0,241809503721842 0,000035
umbracoXsltExtension Extension added: urn:Filabel.library, library 0,241834367217063 0,000025
umbracoMacro After adding extensions 0,241857275156479 0,000023
umbracoMacro Before performing transformation 0,241888564049341 0,000031
umbracoMacro After performing transformation 10,5846703980534 10,342782
Notice the highlighted values/lines, this is where the issue is (the "Product Lister" macro).
Now for debuging the XSLT macro itself, I just started commenting out lines trying to narrow down the specific lines that was causing the suffering. Or, use Sebastiaans method if you can't comment out anything.
But thanks a lot guys! Once again, the excellent Umbraco community comes to the rescue :-)
Best regards,
SoerenS
Usual coding optimising tips work for XSLT too.
* Declare variables outside of loops if possible
* Don't use the nasty "//" at the start of your xpaths it hammers performance as it has to search every node
* Avoid loops within loops
Its the second one that tends to cause all the performance issues. Searching a huge XML tree numerous times can soon add up.
TEN SECONDS? How many gigabytes is your XML file man? ;-)
Is anything in CommerceLibrary or Filabel.library causing this? I've never ever seen something take this long, good luck with finding it!
After seeing the 10 second load, I agree with Sebastiaan... its got to be related to the XSLT extensions? (CommerceLibrary, Filabel.library)
Hehe, yup. 10 seconds is a great deal :-)
I have a huge (1.3MB) external XML file with 2.000+ products (clothes, shoes etc.) structured like this:
<category name="Womens clothing">
<product name="Shirt" sku="1234">
<size>S</size>
<size>M</size>
</product>
</category>
etc.
Then I have a macro that pulls out all products in a given category based on that XML file. No performance issues here, even in large categories with 800+ products.
My issues was with a method of pulling out all unique sizes in a given category. See this page for two methods on how to do that.
Originally I was using the [not(.=preceeding::size)] method, and that was taking 9+ seconds.After rewriting it to use the other method where you generate a key, it is down to below 1 second for large categories.
Hopes it make sense. Anyway it solved my problem :-)
Best regards,
SoerenS
If you feel like tweaking more, then there are a few different ways of doing the Muenchian grouping that you are using (the key stuff)
In .Net 1.1 there were some major performance differences depending on which method you used (http://www.tkachenko.com/blog/archives/000638.html)
The three different methods in the article are described here: http://www.tkachenko.com/blog/archives/000401.html
Should be simple enough to test them out and see what performs best in an Umbraco context.
is working on a reply...