JBoss deadlocks on PrintStream and Category

Solution Verified - Updated

Environment

  • JBoss Enterprise Application Platform (EAP)
    • 4.3.x
    • 5.x

Issue

  • Our JBoss server becomes unresponsive due to the following deadlock between a log4j Category and java.io.PrintStream:
"http-localhost%2F127.0.01-8080-1":
	at org.apache.log4j.Category.callAppenders(Category.java:201)
	- waiting to lock <0xfffffffe8e89dc78> (a org.apache.log4j.spi.RootLogger)
	at org.apache.log4j.Category.forcedLog(Category.java:388)
	at org.apache.log4j.Category.log(Category.java:835)
	at org.jboss.logging.util.LoggerStream.write(LoggerStream.java:156)
	at atg.core.io.TeeOutputStream.write(TeeOutputStream.java:159)
	at java.io.PrintStream.write(PrintStream.java:430)
	- locked <0xfffffffe838530b0> (a java.io.PrintStream)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)
	at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:85)
	- locked <0xfffffffe83853118> (a java.io.OutputStreamWriter)
	at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:168)
	at java.io.PrintStream.write(PrintStream.java:477)
	- locked <0xfffffffe838530b0> (a java.io.PrintStream)
	at java.io.PrintStream.print(PrintStream.java:619)

"Thread-10":
	at java.io.PrintStream.write(PrintStream.java:428)
	- waiting to lock <0xfffffffe838530b0> (a java.io.PrintStream)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)
	at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:276)
	at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:122)
	- locked <0xfffffffea715aeb8> (a java.io.OutputStreamWriter)
	at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:212)
	at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:57)
	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:315)
	at org.apache.log4j.WriterAppender.append(WriterAppender.java:159)
	at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:230)
	- locked <0xfffffffea7158798> (a org.apache.log4j.ConsoleAppender)
	at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:65)
	at org.apache.log4j.Category.callAppenders(Category.java:203)
	- locked <0xfffffffe8e89dc78> (a org.apache.log4j.spi.RootLogger)
	at org.apache.log4j.Category.forcedLog(Category.java:388)
	at org.apache.log4j.Category.log(Category.java:853)

Resolution

  • As a workaround disable STDOUT and STDERR redirection through log4j with the following properties:

      -Dorg.jboss.logging.Log4jService.catchSystemOut=false
  -Dorg.jboss.logging.Log4jService.catchSystemErr=false

  • As a workaround, disable the ConsoleAppender in your conf/jboss-log4j.xml

  • Fix the exception resulting in the dispatcher thread death

Root Cause

  • One thread is using and locking the PrintStream directly through STDOUT or STDERR. This PrintStreams pipes back in to log4j and tries to lock its Category. Meanwhile, another thread has locked the Category and is now trying to lock the PrintStream to log through the ConsoleAppender. This results in reverse lock grabbing for a potential deadlock.

Diagnostic Steps

  • Capture a heap dump from this state and analyze to try to get further details on the exception causing the dispatcher death
SBR
Product(s)
Components
Category
Tags

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.