在使用二这编文章中提到，可以以汇总形式查看日志，也可以通过图表来查看。Perf4j跟log4j集成后，其实也可以以图表的形式来查看性能状况。

我们这篇文章还是使用前一篇文章中提到log4j.xml的配置，其他都一样，只是在配置中加入了图表的配置：

<!-- 生成firstBlock,secondBlock的平均值的图表 -->

    <appender name="graphExecutionTimes"

              class="org.perf4j.log4j.GraphingStatisticsAppender">

        <!-- GraphType:Mean（平均值）, Min（最小值）, Max（最大值）, TPS（每秒事务数） -->

        <param name="GraphType" value="Mean"/>

        <param name="TagNamesToGraph" value="firstBlock,secondBlock"/>

        <appender-ref ref="graphsFileAppender"/>

    </appender>

    <!-- 生成firstBlock,secondBlock的tps的图表 -->

    <appender name="graphExecutionTPS"

              class="org.perf4j.log4j.GraphingStatisticsAppender">

        <param name="GraphType" value="TPS"/>

        <param name="TagNamesToGraph" value="firstBlock,secondBlock"/>

        <appender-ref ref="graphsFileAppender"/>

    </appender>

    <!-- 记录图表生成url的log文件 -->

    <appender name="graphsFileAppender" class="org.apache.log4j.FileAppender">

        <param name="File" value="/home/perfGraphs.log"/>

        <layout class="org.apache.log4j.PatternLayout">

            <param name="ConversionPattern" value="%m%n"/>

        </layout>

</appender>

另外还需要改一个地方，就是CoalescingStatistics的配置：

<appender name="CoalescingStatistics"

              class="org.perf4j.log4j.AsyncCoalescingStatisticsAppender">

        <!--

             TimeSlice配置多少时间间隔去做一次汇总写入文件中

             默认值是 30000 ms

        -->

        <param name="TimeSlice" value="10000"/>

        <appender-ref ref="fileAppender"/>

        <appender-ref ref="graphExecutionTimes"/>

        <appender-ref ref="graphExecutionTPS"/>

    </appender>

黄色那段配置的意思就是把日志写入到图表日志去。

运行代码Perf4JAppenderExample，我们在perfGraphs.log文件中生成了图表的url：

http://chart.apis.google.com/chart?cht=lxy&chtt=Mean&chs=750x400&chxt=x,x,y&chd=t:0.0,100.0|45.2,78.1|0.0,100.0|98.1,100.0&chco=ff0000,00ff00&chm=d,ff0000,0,-1,5.0|d,00ff00,1,-1,5.0&chdl=firstBlock|secondBlock&chxr=2,0,828.6&chxl=0:|13:23:50|13:24:00|1:|Time&chxp=0,0.0,100.0|1,50&chg=50.0,10

http://chart.apis.google.com/chart?cht=lxy&chtt=TPS&chs=750x400&chxt=x,x,y&chd=t:0.0,100.0|100.0,100.0|0.0,100.0|100.0,100.0&chco=ff0000,00ff00&chm=d,ff0000,0,-1,5.0|d,00ff00,1,-1,5.0&chdl=firstBlock|secondBlock&chxr=2,0,0.5&chxl=0:|13:23:50|13:24:00|1:|Time&chxp=0,0.0,100.0|1,50&chg=50.0,10

大家可以把url放到浏览器访问下。

上面这种方式呢，需要自己登录到服务器上，找到log文件，在放到浏览器中查看，总的过程还是比较麻烦。如果大家需要监控的工程是一个web工程的话，那就更方便了，直接配置一个servlet来查看。Web.xml的配置如下：

<!DOCTYPE web-app PUBLIC

 "-//Sun Microsystems, Inc.//DTD Web Application 2.3//EN"

 "http://java.sun.com/dtd/web-app_2_3.dtd" >

<web-app>

    <display-name>Archetype Created Web Application</display-name>

    <servlet>

       <servlet-name>perf4j</servlet-name>

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

       <!-- graphExecutionTimes和graphExecutionTPS就是我们在log4j中配置的名称 -->

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

</web-app>

大家可以打包工程，并放到web服务器下启动，然后访问下/perf4j这个uri。

Maven有一个jetty插件，可以方便启动web工程，只要大家在pom.xml文件中加入如下配置：

<plugins>

           <!-- jetty插件, 设定端口与context path-->

           <plugin>

              <groupId>org.mortbay.jetty</groupId>

              <artifactId>jetty-maven-plugin</artifactId>

           </plugin>    

</plugins>

在控制台中输入：mvn jetty:run，即可。省去了打包发布，很省心喔。

第一次用http://localhost:8080/perf4j访问查看图表的时候没有生成任何东西，那是因为内存中没有收集到最新的性能数据。所以我在index.jsp里调用下以便产生性能数据。然后重新访问，这个时候就有图表生成了。

Perf4j最主要的一个好处就是可以跟log4j或者logback来性能分析和监控线上运行的程序。集成的方式主要是：自定义log4j的appenders通过标准的配置加入到log4j中去（后面会有配置的例子）。有一个要注意的地方就是需要使用log4j的1.2.14版本或者更高版本。由于我一般都是使用log4j，所以对于logback的集成我就不描述了，我觉得应该差不多的。

Perf4j最重要的appender就是AsyncCoalescingStatisticsAppender，它会把一段时间内StopWatch的信息汇总到一个独立的GroupedTimingStatistics日志信息，然后把这个独立的信息传给下游的appenders，比如fileappenders，这样就可以写到文件中去了。也可以传给per4j的其他自定义appenders。

接下来我们看一个log4j.xml的例子，有一个限制，如果要使用AsyncCoalescingStatisticsAppender就只能使用xml文件而不能使用properties文件。

<?xml version="1.0" encoding="UTF-8" ?>

<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration debug="false" xmlns:log4j="http://jakarta.apache.org/log4j/">

    <!--

         配置控制台输出

    -->

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

    <!--

       AsyncCoalescingStatisticsAppender收集StopWatch的日志信息并传送到下游的文件appenders。

    -->

    <appender name="CoalescingStatistics"

              class="org.perf4j.log4j.AsyncCoalescingStatisticsAppender">

        <!--

             TimeSlice配置多少时间间隔去做一次汇总写入文件中

             默认值是 30000 ms

        -->

        <param name="TimeSlice" value="10000"/>

        <appender-ref ref="fileAppender"/>

    </appender>

    <!-- 把汇总的perf4j的日志信息写到perfStats.log文件中去 -->

    <appender name="fileAppender" class="org.apache.log4j.FileAppender">

        <param name="File" value="/home/perfStats.log"/>

        <layout class="org.apache.log4j.PatternLayout">

            <param name="ConversionPattern" value="%m%n"/>

        </layout>

    </appender>

    <!-- Loggers -->

    <!-- 

       配置perf4j logger

       Additivity设置成false主要因为是不想让代码运行时间的日志输出给上游appenders，即不要在控制台输出。

    -->

    <logger name="org.perf4j.TimingLogger" additivity="false">

        <level value="INFO"/>

        <appender-ref ref="CoalescingStatistics"/>

    </logger>

    <!-- 

       Root logger打印所有日志，但不包含perf4j的信息。原因是在TimingLogger配置中设置了additivity为false

    -->

    <root>

        <level value="INFO"/>

        <appender-ref ref="console"/>

    </root>

</log4j:configuration>

黄色背景是perf4j的配置信息。其他都是log4j的基本配置。下面是测试perf4j与log4j集成的代码。

package com.baowu.perf4j;

import org.apache.log4j.Logger;

import org.perf4j.StopWatch;

import org.perf4j.log4j.Log4JStopWatch;

public class Perf4JAppenderExample {

    public static void main (String[] args) throws Exception {

        Logger rootLogger = Logger.getRootLogger();

        for (int i = 0; i < 10; i++) {

            // Log4JStopWatch默认使用org.perf4j.TimingLogger这个类

            StopWatch stopWatch = new Log4JStopWatch();

            //模拟代码运行时间

            Thread.sleep((long) (Math.random() * 1000L));

            //打印到控制台

            rootLogger.info("Normal logging messages only go to the console");

            stopWatch.lap("firstBlock");

            Thread.sleep((long) (Math.random() * 2000L));

            stopWatch.stop("secondBlock");

        }

    }

}

运行代码。

控制台输出：

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

INFO root - Normal logging messages only go to the console

文件输出：

输出格式也可以改成CSV格式。配置：

<appender name="fileAppender" class="org.apache.log4j.FileAppender">

        <param name="File" value="/home/perfStats.log"/>

        <layout class="org.apache.log4j.PatternLayout">

            <param name="ConversionPattern" value="%m%n"/>

        </layout>

</appender>

org.apache.log4j.PatternLayout改成org.perf4j.log4j.StatisticsCsvLayout即可。

具体的参数请查看api。
下载工程

Perf4j使用一主要演示了性能监控的日志直接打印在标准输出流。那么使用二呢则主要来演示怎么来分析打印出来的日志文件。

由于我们还没有跟log4j集成，日志文件打印在标准输出流，我们需要把标准输出流重定向到times.log文件中。重定向有两种方式：直接copy到文件中，或者在eclipse里指定下输出文件。我主要是用eclipse指定输出文件。

然后运行代码（Perf4j使用一的Example.java），控制台会在第一句话中打出[Console output redirected to file:E:\yangpingyu\work\times.log]，这样运行的结果会同时打印在文件中和标准输出中。

有了times.log，我们就可以对日志文件进行分析，以找出有问题的代码。

分析日志命令：

E:\yangpingyu\work>java -jar perf4j-0.9.16.jar times.log

以csv的格式来查看结果，命令如下：

java -jar perf4j-0.9.16.jar -f csv times.log

以上都是以文本的格式进行输出，但文本没有图表更具有表达力。所以把结果以图表形式输出是必不可少，幸好perf4j也支持，命令如下：

java -jar perf4j-0.9.16.jar --graph perfGraphs.html times.log

执行命令后，在控制台输出相应的统计信息，相应的在磁盘上也生成了一个html，html里包含平均值图表和tps图表。

<html>

<head><title>Perf4J Performance Graphs</title></head>

<body>

<br/><br/><img src="http://chart.apis.google.com/chart?cht=lxy&chtt=Mean&chs=750x400&chxt=x,x,y&chd=t:0.0,50.0,100.0|56.3,60.1,6.0|0.0,50.0|88.5,94.5|50.0,100.0|43.2,7.2|0.0,50.0,100.0|71.8,57.4,8.0|0.0,50.0,100.0|100.0,61.2,59.6|0.0,50.0,100.0|63.9,62.0,18.7|0.0,50.0,100.0|34.4,72.1,30.1&chco=ff0000,00ff00,0000ff,00ffff,ff00ff,ffff00,000000&chm=d,ff0000,0,-1,5.0|d,00ff00,1,-1,5.0|d,0000ff,2,-1,5.0|d,00ffff,3,-1,5.0|d,ff00ff,4,-1,5.0|d,ffff00,5,-1,5.0|d,000000,6,-1,5.0&chdl=codeBlock1|codeBlock2.failure|codeBlock2.success|codeBlock3|codeBlock4|codeBlock5|codeBlock6&chxr=2,0,748.5&chxl=0:|18:12:00|18:12:30|18:13:00|1:|Time&chxp=0,0.0,50.0,100.0|1,50&chg=50.0,10"/>

<br/><br/><img src="http://chart.apis.google.com/chart?cht=lxy&chtt=TPS&chs=750x400&chxt=x,x,y&chd=t:0.0,50.0,100.0|36.4,90.9,9.1|0.0,50.0|27.3,63.6|50.0,100.0|36.4,9.1|0.0,50.0,100.0|36.4,90.9,9.1|0.0,50.0,100.0|36.4,90.9,9.1|0.0,50.0,100.0|36.4,90.9,9.1|0.0,50.0,100.0|27.3,100.0,9.1&chco=ff0000,00ff00,0000ff,00ffff,ff00ff,ffff00,000000&chm=d,ff0000,0,-1,5.0|d,00ff00,1,-1,5.0|d,0000ff,2,-1,5.0|d,00ffff,3,-1,5.0|d,ff00ff,4,-1,5.0|d,ffff00,5,-1,5.0|d,000000,6,-1,5.0&chdl=codeBlock1|codeBlock2.failure|codeBlock2.success|codeBlock3|codeBlock4|codeBlock5|codeBlock6&chxr=2,0,0.4&chxl=0:|18:12:00|18:12:30|18:13:00|1:|Time&chxp=0,0.0,50.0,100.0|1,50&chg=50.0,10"/>

</body></html>

以上是html的内容，里面最重要的信息就是两个img标签，里面具体的图片是google chart api生成。可以打开html直接查看图表。

如果想要看更详细的参数，可以使用—help来查看。java -jar perf4j-0.9.16.jar –help。

如果大家使用的是maven工程，那么现在pom文件中加入perf4j的依赖。

<dependency>

<groupId>org.perf4j</groupId>

<artifactId>perf4j</artifactId>

<version>0.9.16</version>

<scope>compile</scope>

</dependency>

如果用的是普通工程，那么直接下载jar包放入lib目录下即可。

例子：

package com.baowu.per4j;

import org.perf4j.LoggingStopWatch;

import org.perf4j.StopWatch;

public class Example1 {

    public static void main(String[] args) throws InterruptedException{

       method1();

       method2();

       method3();

    }

    /**

     * 监控一处代码示例

     * @throws InterruptedException

     */

    private static void method1() throws InterruptedException{

       //创建一个监控对象，这里使用LoggingStopWatch，它是把结果直接输出到控制台。我们也可以

       //使用StopWatch的其他子类，比如：Log4JStopWatch，CommonsLogStopWatch。不过这些子类需

       //要工程使用日志框架

       StopWatch stopWatch = new LoggingStopWatch("codeBlock1");

       //这里就是一些需要监控的代码，我们命名为codeBlock1

       //使用线程休眠是为了模拟代码执行时间

       Thread.sleep((long)(Math.random() * 1000L));

       //停止计算代码性能

       stopWatch.stop();

    }

    /**

     * 一个方法多出代码监控

     * @throws InterruptedException

     */

    private static void method2() throws InterruptedException{

       StopWatch stopWatch = new LoggingStopWatch();

       Thread.sleep((long)(Math.random() * 1000L));

       stopWatch.lap("codeBlock3");

       Thread.sleep((long)(Math.random() * 1000L));

       stopWatch.lap("codeBlock4");

       Thread.sleep((long)(Math.random() * 1000L));

       stopWatch.lap("codeBlock5");

       Thread.sleep((long)(Math.random() * 1000L));

       stopWatch.stop("codeBlock6");

    }

    /**

     * stop方法可以加入一些说明信息

     */

    private static void method3(){

       StopWatch stopWatch = new LoggingStopWatch();

       try {

           // the code block being timed - this is just a dummy example

           long sleepTime = (long)(Math.random() * 1000L);

           Thread.sleep(sleepTime);

           if (sleepTime > 500L) {

               throw new Exception("Throwing exception");

           }

           stopWatch.stop("codeBlock2.success", "Sleep time was < 500 ms");

       } catch (Exception e) {

           stopWatch.stop("codeBlock2.failure", "Exception was: " + e);

       }

    }

}

运行结果：

start[1334457619937] time[355] tag[codeBlock1]

start[1334457620296] time[152] tag[codeBlock3]

start[1334457620453] time[138] tag[codeBlock4]

start[1334457620593] time[598] tag[codeBlock5]

start[1334457621187] time[700] tag[codeBlock6]

start[1334457621890] time[619] tag[codeBlock2.failure] message[Exception was: java.lang.Exception: Throwing exception]

Perf4j主要的用途是计量代码性能和分析性能数据。

为什么要使用这个工具呢？我们可以联想下最早期java开发者调试代码使用的方式，以前没有日志框架，那java开发就使用System.out.println()来输出自己想查看的变量。但是这样项目上线的话，就要去掉这些打印语句以减少性能影响。那万一在线上出问题了，调试哪里出问题就很麻烦，因为没有输出的日志可查。所以后来有人开发了日志框架，通过日志级别控制日志的输出。

类似的，如果没有perf4j，我们在查看代码运行时间的话可以用以下代码来实现：

long start = System.currentTimeMillis();

// execute the block of code to be timed

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

这种方式有几个缺点：

1、 这种方式输出内容比较单一，就是代码总的运行时间。但是我们代码需要查看的性能指标有更多，比如总的平均值，最小值，最大值，tps等等。

2、 也许我们的代码在线上运行，我们想把这些值通过图表的形式展示出来。或者把这些内容通过jmx输出。

3、 另外，我们可能把perf4j跟log4j，slf4j等日志框架和日志门面系统整合起来。

基于以上这些问题，所以开源社区就出现了perf4j（人多力量大，社区的力量就是强大）。

Perf4j一些特性：

l 简单的停止查看机制来计算语句时间消耗输出。

l 命令行解析log文件产生汇总数据和图表。

l 简单的集成日志框架和门面框架。

l 自定义log4j和logback的appenders来产生数据和图表。

l 通过jmx查看性能指标，并根据阈值发送消息。

l Web工程可以通过servlet来输出性能指标。

l Perf4j可以和aop等切面框架整合起来输出性能指标。

l Perf4j是一个可扩展的架构。