为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));

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
>

    <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
>

<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);
}

@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"
/>

<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
>

<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
>

<?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;
}

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 。

 

 

 

来自：http://eddysheng.iteye.com/blog/434913