前段時間有幾個同行跟我吐槽說系統響應越來越慢，優化不知道從何入手！今天寫寫使用spring的aop來實現方法級的執行時間的記錄監控，以此來評估方法的性能以及針對性的對已存在的方法進行優化。
對於監控，我們比較關注監控的可靠性和性能，准確，高效，這才能在不影響整體性能的情況下對我們的系統性能有個較准確的認識。
對於spring aop這個我就不多介紹了，網上一搜一大把，使用過spring的人都知道spring的ioc和aop。ioc我們常用，但在我們自己的系統中，aop的使用幾乎為零，除了這個監控的小功能應用到了，其他的基本上沒有使用到。
我們使用BeanNameAutoProxyCreator，指定bean的名稱，以及被通知bean的名稱，指定名稱時可以使用通配符自動代理它們，配置如下
<bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
<property name="proxyTargetClass">
<value>true</value>
</property>
<property name="interceptorNames">
<list>
<idref bean="profilerInterceptor" />
</list>
</property>
<property name="beanNames">
<list>
<value>*Service</value>
<value>*ServiceImpl</value>
<value>*Manager</value>
<value>*ManagerImpl</value>
<value>*Dao</value>
</list>
</property>
</bean>
上面的配置文件我們配置了一個idref bean，這個就是我們需要寫的監控邏輯的代碼。interceptor是個攔截器，上面的這個配置的所反應出來的內容是，寫自己的一個攔截器來攔截後綴為Service,ServiceImpl,Manager,ManagerImpl,Dao的類，至於是類攔截還是方法級別的攔截，那就要看我們的攔截器的邏輯和代碼了。
說說攔截器的實現。我們希望攔截器在對方法的執行時間進行記錄的同時，還要進行日志的輸出，如，執行時間超過500ms的方法，我們要打印出內部執行每個方法的耗時，這樣我們可以對執行的慢的方法一目了然，優化時也不需要耗很多的時間去logger到底是哪裡執行的慢了。所以在攔截器中，我們增加一個整形的屬性，這個屬性用來配置需要打印到日志中超過配置時間的執行方法的耗時情況。得到像下面一樣的一個日志輸出:
[4359, 2, 100%, 0]com.profile.service.impl.OrderServiceImpl.findRecentlyProfile
+---[4357, 4357, 99%, 1]com.profile.dao.GenericMybatisDao.queryPage
第一行表示整個方法執行的總耗時，下一行表示在這個方法中存在的其他受監控的方法耗時。這就很容易讓我們知道，是執行SQL所耗的時間，需要對SQL進行優化。
那到底該怎麼樣去實現，展示攔截器中的部分代碼。攔截器繼承AbstractMonitoringInterceptor類，它是一個方法級別的攔截器，實現了 MethodInterceptor 接口。
protected Object invokeUnderTrace(MethodInvocation invocation, Log logger) throws Throwable {
String name = createInvocationTraceName(invocation);
//是否委托了注解的攔截
boolean isExistsPrintProfiler = PrintProfilerHelper.isMethodExistsPrintProfiler(invocation.getMethod());
try {
if (!isExistsPrintProfiler) {
Profiler.start(name, monitorTime);
}
return invocation.proceed();
} finally {
if (!isExistsPrintProfiler) {
Profiler.stop(name);
}
}
}
public int getMonitorTime() {
return monitorTime;
}
public void setMonitorTime(int monitorTime) {
this.monitorTime = monitorTime;
}
攔截器中的代碼非常簡單，簡單到10幾行代碼。這對我們來說是件好事。在Profiler這個類中，我們進行了一些監控，鑒於我們輸出上面所描述的日志的tree格式的日志文件，我們在Profiler中使用了TheadLocal來對執行的方法進行管理，這樣會將代碼變的非常簡單。Profiler的start方法也就10行代碼
private final static ThreadLocal<ExecData> dataHolder = new ThreadLocal<ExecData>();
public static void start(String logName) {
start(logName, ELAPSE_TIME_MS_TO_LOG);
}
public static void start(String logName, int elapseTimeMsToLog) {
ExecData execData = dataHolder.get();
ExecNode currentNode = new ExecNode(logName, System.currentTimeMillis(), elapseTimeMsToLog);
if (execData == null) {
execData = new ExecData();
execData.root = currentNode;
dataHolder.set(execData);
} else {
ExecNode parent = execData.currentNode;
currentNode.setParent(parent);
parent.getChildList().add(currentNode);
}
execData.currentNode = currentNode;
execData.level++;
}
這樣，我們就把方法的層級關系記錄下來了，在執行完被監控的方法之後，我們使用stop的方法來記錄執行結束時間，並對符合條件的方法進行日志的輸出。就這麼幾十行代碼，我們非常簡單的把這個監控寫完了，部署到我們自己的應用中來監控方法的性能，從此，我們不用再去猜到底是哪個方法執行太慢了，到底是哪一步慢了。性能，監控，盡在掌握中。
