使用@Profiled注解简化性能日志
在代码中增加性能记录语句(通常的日志语句)的一个缺点是降低了代码的“信噪比”,难以在特定代码块中遵循严格的业务逻辑。为了改善这一不足,Perf4J提供了@Profiled注解,可以添加在需要记录执行时间的方法上,允许方法本身不添加StopWatch代码:
public void profiledExample(String tagSuffix) {
... business logic only here
}
一旦添加了@Profiled注解,Perf4J的计时切面会通过一个面向切面的编程框架如AspectJ或者Spring AOP启用。这个切面在方法调用周围加入建立和停止StopWatch实例的字节码。计时切面甚至可以有选择的使用AspectJ的加载时编织(load-time weaving)功能。因此,通过使用加载时编织你可以保证那些没有启用性能监控的方法绝没有额外的负担。
一个简单的示例:基于Web的质数生成器
本示例将带你感受如何创建一个使用Perf4J库大多数功能的真实应用。你可以下载perf4jPrimes.war文件,然后Servlet容器中运行它。在war包中也包含该应用的源代码。
一切从简,本例子只包含两个主要的代码文件:primes.jsp用于显示生成的质数和接受用户指定的参数,PrimeNumberGenerator类包含真正的生成代码(大部分委托给java.math.BigInteger类)。其中有三处使用了Perf4J计时代码块:
1.在primes.jsp创建Log4JStopWatch统计整个页面的生成时间。
2.PrimeNumberGenerator.generatePrime()方法具有一个Profiled注解。
3.PrimeNumberGenerator.randomFromRandomDotOrg()也含有Profiled注解。
如果查看WEB-INF/classes/log4j.xml文件,你会看到启用了下面的Perf4功能:
1.所有单独的stop watch日志都被写入标准输出(请注意你的servlet容器可能把标准输出定向到磁盘的某个文件中)。如果需要的话,你可以直接使用LogParser。
2.AsyncCoalescingStatisticsAppender被创建以汇总stop watch日志并传递给下游的GraphingStatisticsAppenders和JmxAttributeStatisticsAppender。
3.两个GraphingStatisticsAppender被创建,其中一个表示平均执行时间,另一个输出每秒事务数。
一旦在Web服务器上启动了该Web应用,你就可以通过http://servername/
1.原始的标准输出日志。
2.通过http://servername/
3.JMX监控也启用了。你可以通过Java SDK附带的jconsole应用查看Perf4J MBean值。这需要在启动Web服务器时,使用-Dcom.sun.management.jmxremote命令行参数。然后,如果在运行Web服务 器的同一台机器上启动jconsole就可以在“MBeans”标签中看到 “org.perf4j.StatisticsExposingMBean.Perf4J”的数据值。
因为到现在为止你还没有启用任何TimingAspects支持@Profiled注解,你能够看到的唯一stop watch输出就是“fullPageGeneration”标记。如果要启用TimingAspects,你可以使用AspectJ加载时编织。你需要做的是,在启动Web服务器时使用AspectJ weaving代理命令行参数:
你可以在这里下载jar包:http://mirrors.ibiblio.org/pub/mirrors/maven2/org/aspectj/aspectjweaver/1.6.1/aspectjweaver-1.6.1.jar
当代理启用时,你可以在“generatePrime”和“randomFromRandomDotOrg”标记中看到stop watch的输出。