Sometimes you need to know where an application is spending time and how long things take to finish.
In situations with sources at hand, you may have applied the intuitive straight forward approach wrapping doHeavyLifting() calls in System.currentTimeMillis() to compute the duration. The obvious drawback is the fact that instrumentation code is mixed in code doing what needs to be done. The encapsulation concern can of course be addressed using AOP.
Another less obvious disadvantage is the fact that you need sources and a compiler to get the instrumentation code into the application.
Spring Instrumentation without Source and Compiler
Today, all a lot of java based applications are built on top of Spring dependency injection. A few months ago me and a colleague were faced with the challenge to analyze an application showing massive performance problems. We did not have the source code, but we were at least lucky with the fact, that this application was built with Spring. This provided us with possibilities to drop-in Spring bean definitions like org.springframework.jmx.support.MBeanServerFactoryBean and
org.hibernate.jmx.StatisticsService allowing us to export instrumentation data for analysis.
A few weeks ago, another colleague was wondering about Alfresco performance. I was immediately asking myself whether an approach similiar to the one taken before could be applied to gather Alfresco performance data. Sure, the situation was a little different in that we have Alfresco sources, but I wanted a more clean solution without touching sources.
Proof of Concept with Alfresco
Even though I had no concrete performance problem with Alfresco, I wanted to find out how far I’d get. Looking at all the *-context.xml files, I felt Alfresco must be the ultimate Spring application on the planet. My out of-the-box installation has roughly 2000 Spring bean definitions with nested application contexts and seems to use each and every feature Spring has to offer.
First I got hurt learning that using the aop namespace in Alfresco Spring beans xml yields all kind of weird errors. Fortunately, the good old bean elements proved to provide the features I needed and work just fine. The basic proof of concept was successful – interceptors, advisors and pointcuts et al. did what I wanted them to do without touching Alfresco code.
Next steps
As the basic building blocks were working. The bean definitions looked like the following code:
<bean id="methodNamePointcut"
class="org.springframework.aop.support.NameMatchMethodPointcut">
<property name="mappedNames">
<list>
<!--
public ResultSet executeQuery(SearchParameters searchParameters, String language)
-->
<value>executeQuery</value>
</list>
</property>
</bean>
<bean id="profileAdvice"
class="de.contentreich.instrumentation.ProfileMethodInterceptor" />
<bean id="profilingAdvisor"
class="org.springframework.aop.support.DefaultPointcutAdvisor">
<property name="pointcut" ref="methodNamePointcut" />
<property name="advice" ref="profileAdvice" />
</bean>
<bean id="profilingAutoProxyCreator"
class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
<property name="proxyTargetClass" value="true" />
<property name="beanNames">
<list>
<!-- id=solr, id=lucene - core-services-context.xml -->
<!--
classpath*:alfresco/extension/subsystems/Search/solr/solr/*-context.xml
-->
<value>search.solrQueryHTTPCLient</value>
</list>
</property>
<property name="interceptorNames">
<list>
<value>profilingAdvisor</value>
</list>
</property>
</bean>
Questings then coming up were
- What (objects/methods) is actually available for instrumentation ?
- How do I get decent presentation of the data quickly ?
- What is a decent foundation to build performance gathering upon ?
To address the first question, I built a webscript to browse the (nested) Spring contexts and their beans including method signatures.
Regarding the second and third question, I found perf4j addressing them fairly well. As the Servlet shipping with perf4j does not really fit in the Alfresco repository context, I wrote a replacement webscript to get the graphical view of the gathered data. Perf4j is based on log4j and out-of-the box, Alfresco does not support log4j.xml files needed (due to AppenderAttachables). Hence, I extended Log4JHierarchyInit to implement the support for XML based syntax. The final challenge left with perf4js was the fact that AgnosticTimingAspect is based on annotation code, so I wrote an alternative working without.
One special “pointcut” with Alfresco are the webscripts it hosts. I implemented a special path based pointcut (DynamicMethodMatcherPointcut) allowing me to match and instrument them. Yes, I know AbstractWebScript already has timing code, but I wanted graphs. ;)
Below are screenshots showing beans, bean signature and a simple graph displaying execution times of a few solr webscript.
Source can be found at github and there is also a tarball with the binary amp file ready to deploy and sample extension code which should be dropped in tomcats shared/classes folder.
Finally I’d like to emphasize that the basic injection code is not dependent on Alfresco at all. It should work in just about any Spring based application.
Download Alfresco Instrumentation Repository Extension