为spring2.5中的jpetstore增加perf4j监控

perf4j是一款类似于log4j的性能检测工具.

 

它的基本操作就是封装我们常用的通过System.currentTimeMillis();来计算执行时间.如下:

long start = System.currentTimeMillis();

// execute the block of code to be timed

System.out.println("ms for block n was: " + (System.currentTimeMillis() - start));

 

它的最大优势是可以根据这些数据对要检测的代码块的执行进行数字以及图形化统计.

 

下面是通过AOP方式为jpetstore添加的perf4j步骤.

 

1.在pom文件中增加如下依赖

 

    <dependency>
        <groupId>org.perf4j</groupId>
        <artifactId>perf4j</artifactId>
        <version>0.9.12-SNAPSHOT</version>
    </dependency>
    <dependency>
        <groupId>commons-jexl</groupId>
        <artifactId>commons-jexl</artifactId>
        <version>1.1</version>
        <type>jar</type>
    </dependency>
    <dependency>
        <groupId>log4j</groupId>
        <artifactId>log4j</artifactId>
        <version>1.2.14</version>
        <type>jar</type>
    </dependency>

 

 

2.增加编译插件如下:

<build>
    <finalName>jpetstore</finalName>
    <defaultGoal>package</defaultGoal>
	<plugins>
		<plugin>
			<groupId>org.apache.maven.plugins</groupId>
			<artifactId>maven-compiler-plugin</artifactId>
			<version>2.0.2</version>
			<configuration>
				<source>1.5</source>
				<target>1.5</target>
				<encoding>UTF-8</encoding>
			</configuration>
		</plugin>
	</plugins>
  </build>

 3.为需要进行检测的方法增加注解@Profiled

  譬如PetStoreImpl类中

@Profiled
public Category getCategory(String categoryId) {
	return this.categoryDao.getCategory(categoryId);
}

 4.在spring配置文件中增加Aspectj的支持以及perf4j的支持

<aop:aspectj-autoproxy/>

<bean id="timingAspect" class="org.perf4j.log4j.aop.TimingAspect"/>

 5.为了能够在页面上进行定制统计图表的实时查看,需要在web.xml中增加如下配置

<servlet>
        <servlet-name>perf4j</servlet-name>
        <servlet-class>org.perf4j.log4j.servlet.GraphingServlet</servlet-class>

        <init-param>
            <param-name>graphNames</param-name>
            <param-value>graphExecutionTimes,graphExecutionTPS</param-value>
        </init-param>
    </servlet>

    <servlet-mapping>
        <servlet-name>perf4j</servlet-name>
        <url-pattern>/perf4j</url-pattern>
    </servlet-mapping>

 此处定义的graphExecutionTimes,graphExecutionTPS为log4j配置文件中定义的appender,可增加可删除.

6.现在最重要的一步就是log4j中的设置了.

    首先将jpetstore的log4j配置文件log4j.properties更换为log4j.xml。内容如下

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration debug="false" xmlns:log4j="http://jakarta.apache.org/log4j/">
    <!--
      This default ConsoleAppender is used to log all NON perf4j messages
      to System.out
    -->
    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-5p %c{1} - %m%n"/>
        </layout>
    </appender>

    <!-- Perf4J appenders -->
    <!--
      This AsyncCoalescingStatisticsAppender groups StopWatch log messages
      into GroupedTimingStatistics messages which it sends on the
      file appender defined below
    -->
    <appender name="CoalescingStatistics"
              class="org.perf4j.log4j.AsyncCoalescingStatisticsAppender">
        <!--
          The TimeSlice option is used to determine the time window for which
          all received StopWatch logs are aggregated to create a single
          GroupedTimingStatistics log. Here we set it to 10 seconds, overriding
          the default of 30000 ms
        -->
        <param name="TimeSlice" value="10000"/>
        <appender-ref ref="fileAppender"/>
        <!--
          Note how the GraphingStatisticsAppenders have been attached to the
          CoalescingStatistics here.
        -->
        <appender-ref ref="graphExecutionTimes"/>
        <appender-ref ref="graphExecutionTPS"/>
    </appender>

    <!-- This file appender is used to output aggregated performance statistics -->
    <appender name="fileAppender" class="org.apache.log4j.FileAppender">
        <param name="File" value="${petstore.root}/WEB-INF/perfStats.log"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%m%n"/>
        </layout>
    </appender>

    <!--
      This first GraphingStatisticsAppender graphs Mean execution times for the
      firstBlock and secondBlock tags
    -->
    <appender name="graphExecutionTimes"
              class="org.perf4j.log4j.GraphingStatisticsAppender">
        <!-- Possible GraphTypes are Mean, Min, Max, StdDev, Count and TPS -->
        <param name="GraphType" value="Mean"/>
        <!-- The tags of the timed execution blocks to graph are specified here -->
        <param name="TagNamesToGraph" value="getCategory,getItem,getItemListByProduct,getProduct,getProductListByCategory,searchProductList"/>
        <appender-ref ref="graphsFileAppender"/>
    </appender>

    <!--
      This second GraphingStatisticsAppender graphs transactions per second
      for the firstBlock and secondBlock tags
    -->
    <appender name="graphExecutionTPS"
              class="org.perf4j.log4j.GraphingStatisticsAppender">
        <param name="GraphType" value="TPS"/>
        <param name="TagNamesToGraph" value="getCategory,getItem,getItemListByProduct,getProduct,getProductListByCategory,searchProductList"/>
        <appender-ref ref="graphsFileAppender"/>
    </appender>

    <!--
      This file appender is used to output the graph URLs generated
      by the GraphingStatisticsAppenders
    -->
    <appender name="graphsFileAppender" class="org.apache.log4j.FileAppender">
        <param name="File" value="${petstore.root}/WEB-INF/perfGraphs.log"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%m%n"/>
        </layout>
    </appender>

    <!-- Loggers -->
    <!--
      The Perf4J logger. Note that org.perf4j.TimingLogger is the value of the
      org.perf4j.StopWatch.DEFAULT_LOGGER_NAME constant. Also, note that
      additivity is set to false, which is usually what is desired - this means
      that timing statements will only be sent to this logger and NOT to
      upstream loggers.
    -->
    <logger name="org.perf4j.TimingLogger" additivity="false">
        <level value="DEBUG"/>
        <appender-ref ref="CoalescingStatistics"/>
    </logger>

    <!--
      The root logger sends all log statements EXCEPT those sent to the perf4j
      logger to System.out.
    -->
    <root>
        <level value="INFO"/>
        <appender-ref ref="console"/>
    </root>
</log4j:configuration>

 

最后启动服务器，点击petstore上面的链接，就可以看到项目WEB-INF/下面的perfStats.log，perfGraphs.log已经有数据了。

现在查看http://localhost:8080/jpetstore/perf4j，就可以查看perf4j对各个检测方法的图形统计了，如下：

 

上面我们是采用的AOP方式，另外也可以采用更具侵入性的方法来实现，在SqlMapProductDao代码块的开始和结尾增加如下代码：

public List searchProductList(String keywords) throws DataAccessException {
	StopWatch stopWatch = new LoggingStopWatch();
    Object parameterObject = new ProductSearch(keywords);
    List aaa = getSqlMapClientTemplate().queryForList("searchProductList", parameterObject);
    stopWatch.stop("searchProductList");
    return aaa;
}

 

最后，perf4j在检测方式上还提供其他一些特性，譬如可以自定义TAG。。。可以查阅其相关文档http://perf4j.codehaus.org/devguide.html 。

 

效果很不错。