【案例58】WebSphere输出日志输出慢导致线程被阻塞

问题现象

系统非常卡顿

问题分析

分析javacore文件，寻找关键字，Flat locked by

3LKMONOBJECT       org/apache/logging/log4j/core/appender/OutputStreamManager@0x000000060FB6B3C0: Flat locked by "WebContainer : 3" (J9VMThread:0x0000000007C55A00), entry count 1
3LKWAITERQ            Waiting to enter:
3LKWAITER                "WorkManager.MulticastWM : 19" (J9VMThread:0x000000000380D000)
3LKWAITER                "WebContainer : 8" (J9VMThread:0x0000000007EF2000)
3LKWAITER                "WebContainer : 10" (J9VMThread:0x0000000008B53E00)
3LKWAITER                "WorkManager.MulticastWM : 49" (J9VMThread:0x00000000089A7600)
3LKWAITER                "WebContainer : 16" (J9VMThread:0x0000000008EB8D00)

3号线程阻塞8、10、16、19号线程，发现相关线程，查看3号线程具体信息，非NCC代码原因造成。

3XMTHREADBLOCK     Blocked on: org/apache/logging/log4j/core/appender/OutputStreamManager@0x000000060FB6B3C0 Owned by: "WebContainer : 3" (J9VMThread:0x0000000007C55A00, java/lang/Thread:0x00000006152DF108)
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=24576 (0x6000)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at org/apache/logging/log4j/core/appender/OutputStreamManager.writeBytes(OutputStreamManager.java:352(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/layout/TextEncoderHelper.writeEncodedText(TextEncoderHelper.java:96(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/layout/TextEncoderHelper.encodeText(TextEncoderHelper.java:65(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/layout/StringBuilderEncoder.encode(StringBuilderEncoder.java:68(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/layout/StringBuilderEncoder.encode(StringBuilderEncoder.java:32(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/layout/PatternLayout.encode(PatternLayout.java:228(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/layout/PatternLayout.encode(PatternLayout.java:60(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/appender/AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/appender/AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/appender/AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/AppenderControl.tryCallAppender(AppenderControl.java:161(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/AppenderControl.callAppender0(AppenderControl.java:134(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/AppenderControl.callAppender(AppenderControl.java:89(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/LoggerConfig.callAppenders(LoggerConfig.java:542(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/LoggerConfig.processLogEvent(LoggerConfig.java:500(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/LoggerConfig.log(LoggerConfig.java:483(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/LoggerConfig.log(LoggerConfig.java:417(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/config/AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/core/Logger.log(Logger.java:161(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/spi/AbstractLogger.tryLogMessage(AbstractLogger.java:2205(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/spi/AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2159(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/spi/AbstractLogger.logMessageSafely(AbstractLogger.java:2142(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/spi/AbstractLogger.logMessage(AbstractLogger.java:1994(Compiled Code))
4XESTACKTRACE                at org/apache/logging/log4j/spi/AbstractLogger.logIfEnabled(AbstractLogger.java:1852(Compiled Code))
4XESTACKTRACE                at nc/bs/logging/impl/log4j2/Log4j2LoggerPlugin.log(Log4j2LoggerPlugin.java:103(Compiled Code))
4XESTACKTRACE                at nc/bs/logging/impl/log4j2/Log4j2LoggerPlugin.log(Log4j2LoggerPlugin.java:119(Compiled Code))
4XESTACKTRACE                at nc/bs/logging/Logger.debug(Logger.java:182(Compiled Code))
4XESTACKTRACE                at nc/bs/framework/rmi/server/RMIHandlerImpl$1.run(RMIHandlerImpl.java:80(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/Executors$RunnableAdapter.call(Executors.java:522(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/FutureTask.runAndReset(FutureTask.java:319(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:191(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
4XESTACKTRACE                at nc/bs/framework/execute/server/SecureRunnable.run(SecureRunnable.java:46)
4XESTACKTRACE                at org/granite/commonj/CommonjWork.run(CommonjWork.java:31)
4XESTACKTRACE                at com/ibm/ws/asynchbeans/J2EEContext.run(J2EEContext.java:1046)
4XESTACKTRACE                at com/ibm/ws/asynchbeans/WorkWithExecutionContextImpl.go(WorkWithExecutionContextImpl.java:199)
4XESTACKTRACE                at com/ibm/ws/asynchbeans/CJWorkItemImpl.run(CJWorkItemImpl.java:237)
4XESTACKTRACE                at com/ibm/ws/util/ThreadPool$Worker.run(ThreadPool.java:1909(Compiled Code))

org/apache/logging/log4j/core/appender/OutputStreamManager日志输出慢导致线程被阻塞，解决办法，加大was SystemOut.log 日志大小

解决方案

调整WebSphere的SystemOut.log日志大小。日常如果想要多保留相关日志信息，也可以在这里调整。（下图为个人测试环境，仅供参考）

进到WebSphere控制台，IP:9060/admin，进到【故障诊断节点】选择【日志和跟踪】，选择需要调整的具体server（每个server都需改。）

选择JVM日志

 调整文件大小和个数

保存后重启整个was集群即可。