在使用二這編文章中提到，可以以匯總形式查看日志，也可以通過圖表來查看。Perf4j跟log4j集成后，其實也可以以圖表的形式來查看性能狀況。

我們這篇文章還是使用前一篇文章中提到log4j.xml的配置，其他都一樣，只是在配置中加入了圖表的配置：

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

    <appender name="graphExecutionTimes"

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

        <!-- GraphType:Mean（平均值）, Min（最小值）, Max（最大值）, TPS（每秒事務(wù)數(shù)） -->

        <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配置多少時間間隔去做一次匯總寫入文件中

             默認(rèn)值是 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放到瀏覽器訪問下。

上面這種方式呢，需要自己登錄到服務(wù)器上，找到log文件，在放到瀏覽器中查看，總的過程還是比較麻煩。如果大家需要監(jiān)控的工程是一個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服務(wù)器下啟動，然后訪問下/perf4j這個uri。

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

<plugins>

           <!-- jetty插件, 設(shè)定端口與context path-->

           <plugin>

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

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

           </plugin>    

</plugins>

在控制臺中輸入：mvn jetty:run，即可。省去了打包發(fā)布，很省心喔。

第一次用http://localhost:8080/perf4j訪問查看圖表的時候沒有生成任何東西，那是因為內(nèi)存中沒有收集到最新的性能數(shù)據(jù)。所以我在index.jsp里調(diào)用下以便產(chǎn)生性能數(shù)據(jù)。然后重新訪問，這個時候就有圖表生成了。

Perf4j最主要的一個好處就是可以跟log4j或者logback來性能分析和監(jiān)控線上運行的程序。集成的方式主要是：自定義log4j的appenders通過標(biāo)準(zhǔn)的配置加入到log4j中去（后面會有配置的例子）。有一個要注意的地方就是需要使用log4j的1.2.14版本或者更高版本。由于我一般都是使用log4j，所以對于logback的集成我就不描述了，我覺得應(yīng)該差不多的。

Perf4j最重要的appender就是AsyncCoalescingStatisticsAppender，它會把一段時間內(nèi)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配置多少時間間隔去做一次匯總寫入文件中

             默認(rèn)值是 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設(shè)置成false主要因為是不想讓代碼運行時間的日志輸出給上游appenders，即不要在控制臺輸出。

    -->

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

        <level value="INFO"/>

        <appender-ref ref="CoalescingStatistics"/>

    </logger>

    <!-- 

       Root logger打印所有日志，但不包含perf4j的信息。原因是在TimingLogger配置中設(shè)置了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默認(rèn)使用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即可。

具體的參數(shù)請查看api。
下載工程

Perf4j使用一主要演示了性能監(jiān)控的日志直接打印在標(biāo)準(zhǔn)輸出流。那么使用二呢則主要來演示怎么來分析打印出來的日志文件。

由于我們還沒有跟log4j集成，日志文件打印在標(biāo)準(zhǔn)輸出流，我們需要把標(biāo)準(zhǔn)輸出流重定向到times.log文件中。重定向有兩種方式：直接copy到文件中，或者在eclipse里指定下輸出文件。我主要是用eclipse指定輸出文件。

然后運行代碼（Perf4j使用一的Example.java），控制臺會在第一句話中打出[Console output redirected to file:E:\yangpingyu\work\times.log]，這樣運行的結(jié)果會同時打印在文件中和標(biāo)準(zhǔn)輸出中。

有了times.log，我們就可以對日志文件進(jìn)行分析，以找出有問題的代碼。

分析日志命令：

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

以csv的格式來查看結(jié)果，命令如下：

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

以上都是以文本的格式進(jìn)行輸出，但文本沒有圖表更具有表達(dá)力。所以把結(jié)果以圖表形式輸出是必不可少，幸好perf4j也支持，命令如下：

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

執(zhí)行命令后，在控制臺輸出相應(yīng)的統(tǒng)計信息，相應(yīng)的在磁盤上也生成了一個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的內(nèi)容，里面最重要的信息就是兩個img標(biāo)簽，里面具體的圖片是google chart api生成。可以打開html直接查看圖表。

如果想要看更詳細(xì)的參數(shù)，可以使用—help來查看。java -jar perf4j-0.9.16.jar –help。

如果大家使用的是maven工程，那么現(xiàn)在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();

    }

    /**

     * 監(jiān)控一處代碼示例

     * @throws InterruptedException

     */

    private static void method1() throws InterruptedException{

       //創(chuàng)建一個監(jiān)控對象，這里使用LoggingStopWatch，它是把結(jié)果直接輸出到控制臺。我們也可以

       //使用StopWatch的其他子類，比如：Log4JStopWatch，CommonsLogStopWatch。不過這些子類需

       //要工程使用日志框架

       StopWatch stopWatch = new LoggingStopWatch("codeBlock1");

       //這里就是一些需要監(jiān)控的代碼，我們命名為codeBlock1

       //使用線程休眠是為了模擬代碼執(zhí)行時間

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

       //停止計算代碼性能

       stopWatch.stop();

    }

    /**

     * 一個方法多出代碼監(jiān)控

     * @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);

       }

    }

}

運行結(jié)果：

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主要的用途是計量代碼性能和分析性能數(shù)據(jù)。

為什么要使用這個工具呢？我們可以聯(lián)想下最早期java開發(fā)者調(diào)試代碼使用的方式，以前沒有日志框架，那java開發(fā)就使用System.out.println()來輸出自己想查看的變量。但是這樣項目上線的話，就要去掉這些打印語句以減少性能影響。那萬一在線上出問題了，調(diào)試哪里出問題就很麻煩，因為沒有輸出的日志可查。所以后來有人開發(fā)了日志框架，通過日志級別控制日志的輸出。

類似的，如果沒有perf4j，我們在查看代碼運行時間的話可以用以下代碼來實現(xiàn)：

long start = System.currentTimeMillis();

// execute the block of code to be timed

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

這種方式有幾個缺點：

1、 這種方式輸出內(nèi)容比較單一，就是代碼總的運行時間。但是我們代碼需要查看的性能指標(biāo)有更多，比如總的平均值，最小值，最大值，tps等等。

2、 也許我們的代碼在線上運行，我們想把這些值通過圖表的形式展示出來。或者把這些內(nèi)容通過jmx輸出。

3、 另外，我們可能把perf4j跟log4j，slf4j等日志框架和日志門面系統(tǒng)整合起來。

基于以上這些問題，所以開源社區(qū)就出現(xiàn)了perf4j（人多力量大，社區(qū)的力量就是強(qiáng)大）。

Perf4j一些特性：

l 簡單的停止查看機(jī)制來計算語句時間消耗輸出。

l 命令行解析log文件產(chǎn)生匯總數(shù)據(jù)和圖表。

l 簡單的集成日志框架和門面框架。

l 自定義log4j和logback的appenders來產(chǎn)生數(shù)據(jù)和圖表。

l 通過jmx查看性能指標(biāo)，并根據(jù)閾值發(fā)送消息。

l Web工程可以通過servlet來輸出性能指標(biāo)。

l Perf4j可以和aop等切面框架整合起來輸出性能指標(biāo)。

l Perf4j是一個可擴(kuò)展的架構(gòu)。