Macros to help analyze performance issues in template.

Rhythmyx Technical Discussion
1

Hi, I have created a couple of macros that may help diagnosing assembly performance in a velocity page.

Using this just call macro #markTime(“label”) anywhere in the template. Then at the bottom of the global (or page template if not using global) put the macro #ouputTimes() usually just before the </body>. This will display a table of results displaying the number of milliseconds between each call and elapsed time. The macro has been written to make the values available between templates. The global template is always called after the page template is complete, so putting the #outputTimes() call at the end of the global template it will list all results from the page and global template. Values will also be passed into snippet templates but any markers placed into the snippet may not be avaliable after the snippet is complete, so you may need to put #outputTimes() in the snippet if you want to record these.

Using this you may be able to locate specific functionality that is causing the biggest performance issue to the page and focus on improving that functionality, which will therefore improve assembly and publish times. The structure also means you do not have to affect the rendering of the whole page to output the results. The name passed to markTime could be a generated value. e.g. you could append $velocityCount if in a loop.

outputTimes has been made to not write out on publish, but you could remove this condition, or change the condition so you only see the table if you manually put a specific parameter in the url.

Hope this helps

#macro(markTime $name)##
#if("$!{timeList}" == "")##
#set($timeList = [] )##
#set($timeNameList = [] )##
$sys.assemblyItem.getBindings().put('$timeList',$timeList)
$sys.assemblyItem.getBindings().put('$timeNameList',$timeNameList)
#end##
#set($currentTime=$tools.date.getSystemTime())##
#set($dummy = $timeList.add($currentTime))##
#set($dummy = $timeNameList.add($name))##
#end


#macro(outputTimes)##
#if($tools.list.get($sys.params.get('sys_context'), 0) == "0")##
<table border="1">##
#set($startTime = $timeList.get(0))##
#set($lastTime = $timeList.get(0))##
<tr><td>Marker Name</td><td>Time Difference (ms)</td><td>elapsed time (ms)</td></tr>##
#foreach($time in $timeList)
<tr>##
#set($diffTime = $time - $lastTime)##
#set($runTime = $time - $startTime)##
<td>$timeNameList.get($tools.math.sub($velocityCount,1))</td><td>$diffTime</td><td>$runTime</td>##
</tr>##
#set($lastTime = $time)##
#end##
</table>
#end##
#end
2

The following macros have been fixed up and also allow you to add &showTimes=true to the html parameters of the page to enable showing the table. You can use the bindings in snippet templates and the mark macro in snippet velocity code and the times should show in the table created by output times at the end of the global template.

## Macros to track page performance
#macro(markTime $name)##
#if($tools.list.get($sys.params.get('showTimes'), 0) == "true")##
#if("$!{timeList}" == "")##
#set($timeList = [] )##
#set($dummy = $sys.assemblyItem.getBindings().put('$timeList',$timeList))##
#end##
#set($currentTime=$tools.date.getSystemTime())##
#set($dummy = $timeList.add($user.psoListTools.asPair("$name",$currentTime)))##
##
#end


#macro(outputTimes)##
#if($tools.list.get($sys.params.get('showTimes'), 0) == "true")##
<table border="1">
#set($startTime = $timeList.get(0).getSecond())##
#set($lastTime = $timeList.get(0).getSecond())##
<tr><td>Marker Name</td><td>Time Difference (ms)</td><td>elapsed time (ms)</td></tr>
#foreach($time in $timeList)
<tr>##
#set($diffTime = $time.getSecond() - $lastTime)##
#set($runTime = $time.getSecond() - $startTime)##
<td>$time.getFirst()</td><td>$diffTime</td><td>$runTime</td>##
</tr> 
#set($lastTime = $time.getSecond() )##
#end##
</table>
#end##
#end


## End performance macros

Also if you want to add timing to bindings you can put the following as the first binding $timeList

if ($timeList==null) {  $user.psoListTools.asList($user.psoListTools.asPair("Start Bindings - " + $sys.assemblyItem.getTemplate().getName(), $tools.date.getSystemTime()));  } else {  $timeList.add($user.psoListTools.asPair("Start Bindings - " + $sys.assemblyItem.getTemplate().getName(), $tools.date.getSystemTime())); };

put the following as the last binding to $newMark

$timeList.add($user.psoListTools.asPair("End Bindings - "  + $sys.assemblyItem.getTemplate().getName(), $tools.date.getSystemTime()));

and put the following between bindings you want to test with whatever name you want.

$timeList.add($user.psoListTools.asPair("Name of marker", $tools.date.getSystemTime()));
3

These are excellent. Thanks for sharing.

PS. You might be missing a #end at the end of the markTime macro in the code above.