0

我有一个多线程应用程序,我使用 log4j 进行日志记录。当我在 Windows 7/intel 笔记本电脑上测试我的应用程序时,它工作得很好。但是当我将相同的应用程序部署到生产服务器(solaris/sparc)时,它工作了 10 分钟,然后开始变慢(非常慢)。我使用分析器查看线程状态。由于线程转储中的 log4j 操作,有很多线程被阻塞。我也在使用异步追加器,但无法获得任何成功的结果。有什么猜测吗?

这里有一些转储:

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

4

2 回答 2

2

所以试图记录的线程被阻塞了。为什么?因为日志线程当前被阻塞在java.io.FileOutputStream.writeBytes(Native Method). 这强烈表明日志记录的内容(文件或其他)无法跟上正在完成的日志记录量。

解决此问题的方法是首先查看您的日志记录的去向。如果要写入文件,该文件是否位于快速的本地文件系统上?磁盘 I/O 有问题吗?

您可能希望使用不会阻塞 I/O 的日志记录方案。它不必——当一个线程正在执行磁盘 I/O 时,其他线程可以登录到一个内部队列。但是,如果日志记录速率超过 I/O 速率,最终您必须以某种方式停止在内存中建立日志记录,这需要阻塞线程或丢弃日志条目。也就是说,这不应该是一个问题,除非您记录太多,有严重的 I/O 性能问题(例如在拥挤的网络上通过 NFS 登录),或者以某种方式禁用了文件缓冲。

于 2013-01-18T09:02:31.690 回答
2

从堆栈转储来看,有些东西正在调用 flush() ......所以这将否定使用 BufferedOutputStream 的许多“优点”。如果您能弄清楚如何避免刷新,吞吐量将会提高。

大卫施瓦茨这样评论:

Windows 因没有真正将文件刷新作为提高其性能的一种方式而臭名昭著。Solaris 和 Linux 确实可以完全刷新。这可能有助于解释平台相关的性能差异。

(我不知道。是的,它会的。)

在 WriterAppender 中关闭immediateFlush可能会有所帮助

很好的建议。

于 2013-01-18T09:08:53.073 回答