Log4j Solaris中的多線程處理

Question

我有一個多線程應用程序，使用log4j進行日誌記錄。當我在我的Windows 7/intel筆記本電腦上測試我的應用程序時，它工作得很好。但是，當我將相同的應用程序部署到生產服務器（solaris/sparc）時，它可以工作10分鐘，然後開始減慢（非常慢）。我使用分析器來查看線程狀態。由於線程轉儲中的log4j操作，阻塞了很多線程。我也使用異步appender，但沒有設法得到任何成功的結果。任何猜測？

這裏有一些轉儲：

"pool-7-thread-105" - Thread t@22939 
    java.lang.Thread.State: BLOCKED 
    at org.apache.log4j.Category.callAppenders(Category.java:204) 
    - waiting to lock <794f2dae> (a org.apache.log4j.spi.RootLogger) owned by "pool-7-thread-112" t@22946 
    at org.apache.log4j.Category.forcedLog(Category.java:391) 
    at org.apache.log4j.Category.info(Category.java:666) 

"pool-7-thread-112" - Thread t@22946 
    java.lang.Thread.State: RUNNABLE 
    at java.io.FileOutputStream.writeBytes(Native Method) 
    at java.io.FileOutputStream.write(Unknown Source) 
    at java.io.BufferedOutputStream.flushBuffer(Unknown Source) 
    at java.io.BufferedOutputStream.flush(Unknown Source) 
    - locked <5fcbc329> (a java.io.BufferedOutputStream) 
    at java.io.PrintStream.write(Unknown Source) 
    - locked <19e9d0c5> (a java.io.PrintStream) 
    at sun.nio.cs.StreamEncoder.writeBytes(Unknown Source) 
    at sun.nio.cs.StreamEncoder.implFlushBuffer(Unknown Source) 
    at sun.nio.cs.StreamEncoder.implFlush(Unknown Source) 
    at sun.nio.cs.StreamEncoder.flush(Unknown Source) 
    - locked <3680c465> (a java.io.OutputStreamWriter) 
    at java.io.OutputStreamWriter.flush(Unknown Source) 
    at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:59) 
    at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:324) 
    at org.apache.log4j.WriterAppender.append(WriterAppender.java:162) 
    at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) 
    - locked <3fddded7> (a org.apache.log4j.ConsoleAppender) 
    at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66) 
    at org.apache.log4j.Category.callAppenders(Category.java:206) 
    - locked <794f2dae> (a org.apache.log4j.spi.RootLogger) 
    at org.apache.log4j.Category.forcedLog(Category.java:391) 
    at org.apache.log4j.Category.info(Category.java:666) 

另外的log4j.xml - 版本1.2.17

<appender name="scripts" class="org.apache.log4j.DailyRollingFileAppender"> 
    <param name="threshold" value="INFO"/> 
    <param name="file" value="log/script.log"/> 
    <param name="DatePattern" value="'.'yyyy-MM-dd"/> 
    <layout class="org.apache.log4j.EnhancedPatternLayout"> 
     <param name="ConversionPattern" 
       value="%-6p[%-d{ISO8601}] [%t] %m (%F:%L) %n"/> 
    </layout> 
</appender> 

<appender name="stdout" class="org.apache.log4j.ConsoleAppender"> 
    <param name="threshold" value="INFO"/> 
    <layout class="org.apache.log4j.PatternLayout"> 
     <param name="ConversionPattern" value="%-6p[%-d{ISO8601}] [%t] %m (%F:%L) %n"/> 
    </layout> 
</appender> 

<appender name="ASYNC" class="org.apache.log4j.AsyncAppender"> 
    <param name="BufferSize" value="5000"/> 
    <appender-ref ref="scripts"/> 
</appender> 

<root> 
    <priority value="debug"/> 
    <appender-ref ref="stdout"/> 
    <appender-ref ref="ASYNC"/> 
</root> 

Answer 1

所以正試圖線程登錄被阻止。爲什麼？因爲日誌線程當前被阻止在java.io.FileOutputStream.writeBytes(Native Method)。這強烈表明，日誌記錄將要發生的事情（文件或其他）無法跟上正在進行的日誌記錄的數量。

排除故障的方法是從查看日誌記錄的位置開始。如果它要轉到一個文件，那麼這個文件是在一個快速的本地文件系統上？磁盤I/O是否有問題？

您可能希望使用不會阻止I/O的日誌記錄方案。它不需要 - 當線程正在執行磁盤I/O時，其他線程可以登錄到內部隊列。但是，如果日誌記錄速率超過I/O速率，那麼最終必須停止以某種方式在內存中建立日誌，這需要阻止線程或將日誌條目丟棄。也就是說，這不應該是一個問題，除非你記錄方式太多，有嚴重的I/O性能問題（例如在擁擠的網絡上記錄NFS），或者以某種方式禁用文件緩衝。

Answer 2

從堆棧轉儲判斷，某事正在調用flush（）...因此這將取消使用BufferedOutputStream的很多「優點」。如果你能弄清楚如何避免沖洗，吞吐量將會提高。因此

大衛·施瓦茨評論：

的Windows是臭名昭著的不是真正履行文件刷新，以改善其性能的方式。 Solaris和Linux真的做了全面的沖洗。這可能有助於解釋依賴於平臺的性能差異。

（我不知道。是的它會。）

在WriterAppender關閉immediateFlush可能有助於

優秀建議。