2010-04-15 63 views
0

我在我的代碼中設置了一些stop watch來測量一些代碼塊,所有的消息都進入我的主日誌而不是進入定時日誌。 perfStats.log文件被創建得很好,但是所有的消息都轉到根日誌中,根據我讀過的文檔,我認爲這根本不應該發生。有什麼明顯的我在這裏失蹤?Perf4j Not Logging Correctly

的Perf4教程link

實施例代碼

import org.apache.log4j.Logger; 
import org.perf4j.LoggingStopWatch; 
import org.perf4j.StopWatch; 

public class PerfLogger { 

    /** 
    * @param args 
    */ 
    public static void main(String[] args) 
    { 
     Logger logger = Logger.getLogger(PerfLogger.class.getName()); 

     logger.info("Starting perf log test"); 

     StopWatch stopWatch = new LoggingStopWatch("test time"); 

     try { 
      Thread.sleep(1000); 
     } catch (InterruptedException e) { 
      // TODO Auto-generated catch block 
      e.printStackTrace(); 
     } 
     stopWatch.stop(); 

    } 

} 

實施例的log4j.xml

<log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>  

    <appender name="STDOUT-DEBUG" class="org.apache.log4j.ConsoleAppender"> 
     <layout class="org.apache.log4j.PatternLayout"> 
      <param name="ConversionPattern" value="%d %-5p [%t]%x %M (%F:%L) - %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"/> 
    </appender> 


    <!-- This file appender is used to output aggregated performance statistics --> 
    <appender name="fileAppender" class="org.apache.log4j.FileAppender"> 
     <param name="File" value="perfStats.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="INFO"/> 
     <appender-ref ref="CoalescingStatistics"/> 
    </logger> 

    <root> 
     <priority value="info"/> 
     <appender-ref ref="STDOUT-DEBUG"/> 
    </root> 

</log4j:configuration> 

回答

1

我檢查罐和沒有在的Perf4罐子命名TimingLogger類,這在這裏也可以看到searching their code repository,這將解釋消息不會去文件,你會期望他們。如果您使用默認的LoggingStopWatch類,它們在示例中顯示它看起來像它唯一會做的是打印到std err,您可以看到here。我試着改變我的代碼中的記錄器來改爲使用他們的Log4JStopWatch類,並將xml文件中的記錄器更改爲org.perf4j.log4j.Log4JStopWatch,但是這些消息是stdout而不是文件,這可能是因爲它不是文件, t使用log4j.xml中指定的配置我猜。我會嘗試跟進維護該項目的團隊,看他們是否有更新的示例或錯誤修復。

+0

您肯定需要使用Log4JStopWatch,並且您需要手動調用start(),雖然示例中顯示了其他情況。但是我注意到,當你的時間測量值大於你指定的時間片時,即你進行了5分鐘的測量,並且定義了10秒的時間片,那麼測量就不會記錄到日誌中。 – jtruelove 2010-04-20 14:51:51

0

問題是您正在使用LoggingStopWatch,默認情況下它將其所有輸出發送到stderr。你想要使用Log4JStopWatch。 LoggingStopWatch的每個直接子類都是爲不同的框架設計的(請參見http://perf4j.codehaus.org/apidocs/org/perf4j/LoggingStopWatch.html)。

+0

是的,我提到已經在下面,但該網站上的開發人員教程已過時,因爲它們表明這是相反的。此外,僅使用Log4JStopWatch也不會將其記錄到單獨的文件,它似乎默認爲根記錄器,而不是指定的記錄器。 – jtruelove 2010-04-15 17:49:52

0

org.log4j.TimingLogger不是類名,而是Perf4j使用的默認記錄器名稱。如果您正在使用Log4j,則應使用org.perf4j.log4j.Log4JStopWatch類,並且在創建時不要忘記使用正確的標記,因爲統計信息將按其分組。

按照你的例子:

import org.apache.log4j.Logger; 
import org.perf4j.LoggingStopWatch; 
import org.perf4j.StopWatch; 

public class PerfLogger { 

    /** 
    * @param args 
    */ 
    public static void main(String[] args) 
    { 

     StopWatch stopWatch = new LoggingStopWatch("main(..)"); 

     try { 
      Thread.sleep(1000); 
     } catch (InterruptedException e) { 
      // TODO Auto-generated catch block 
      e.printStackTrace(); 
     } 
     stopWatch.stop(); 

    } 
} 

有了,執行工作和你相同的配置文件,你得到像下面這樣的輸出:

Performance Statistics 2012-07-03 22:13:20 - 2012-07-03 22:13:30 
Tag      Avg(ms)   Min   Max Std Dev  Count 
main(..)     999.0   999   999  0.0   1 

希望這澄清了這個問題。