Performance analysis

Saxon comes with a simple tool allowing profiling of the execution time in a query.

To run this tool, first execute the query with the -TP:filename option, which will gather timed tracing information and create a profile report to the specified file (or to the standard error output if no filename is given). For example:

java net.sf.saxon.Query   -TP:profile.html   -q:queryfile  

Then view the resulting profile.html file in your browser.

The output identifies functions and global variables in the original query by their name, line number, and the last few characters of the URI of their module. For each instruction it gives the number of times the instruction was executed, the average time in milliseconds of each execution, and the total time. Timings are given both gross (the time for a function including all the functions it calls recursively), and net (the time for a function excluding time in its called functions). The table is sorted according to a weighting function that attempts to put the dominant functions and global variables at the top. These will not necessarily be those with the greatest time, which tend to be instructions that were only executed once but remained active for the duration of the query.

In addition, the option -TPxsl:filename can be provided, where filename is the URI or filename of a stylesheet to be used for formatting the results. This allows you to output the results as XML or JSON, allowing further analysis. To get the results as raw XML (or to inspect the format supplied as input), supply an identity stylesheet. The data consists primarily of elements such as:

<fn name="fp:localization" construct="xsl:function" file="****.xq" line="61" count="18" t-sum-net="2.7411305" t-avg-net="0.15228502777777778" t-sum="20.292764" t-avg="1.1273757777777778"/> <fn match="phase-1-result" construct="xsl:variable" file="****.xq" count="49" t-sum-net="89.4315515" t-avg-net="1.8066980101010102" line="41" t-sum="90.9251545" t-avg="1.836871808080808"/>

Here:

  • construct identifies the type of construct (function or global variable)
  • file and line identify the location of the component
  • count gives the number of times it was executed
  • t-sum and t-sum-net give the total gross and net execution time (net time excludes time spent executing invoked components)
  • t-avg and t-avg-net give the average gross and net execution time (net time excludes time spent executing invoked components)

Note that in the case of a recursive function, the total time spent in the component may exceed the total time of the transformation. "Net time" is generally a more useful metric.