[jboss-jira] [JBoss JIRA] Commented: (JBAS-4514) CLONE -Deadlock when logging trace

[Vadim Kopichenko (JIRA)]

    [ https://issues.jboss.org/browse/JBAS-4514?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12620523#comment-12620523 ] 

Vadim Kopichenko commented on JBAS-4514:
----------------------------------------

A note for history and legacy users.

The deadlock is caused by known log4j 1.2.x multithread vulnerability.
See "Deadlock in Log4j when logging inside exception stack trace" http://issues.apache.org/bugzilla/show_bug.cgi?id=43568 and http://issues.apache.org/bugzilla/show_bug.cgi?id=24159.
JBoss 4.x has several places in code that do such nested logging while already logging exception stack trace that causes deadlock.
At least in classloading and org.jboss.util.NestedThrowable.

The workaround is to disable that logging in jboss-log4j.xml:

   <category name="org.jboss.mx.loading" additivity="false">
      <priority value="OFF"/>
   </category>
   <category name="org.jboss.util.NestedThrowable" additivity="false">
      <priority value="OFF"/>
   </category>


> CLONE -Deadlock when logging trace
> ----------------------------------
>
>                 Key: JBAS-4514
>                 URL: https://issues.jboss.org/browse/JBAS-4514
>             Project: Legacy JBoss Application Server 6 
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>            Reporter: chris effenberger
>            Assignee: David Lloyd
>             Fix For: 6.0.0.M3
>
>
> SourceForge Submitter: genman .
> This was caused when trace was enabled.  I imagine it
> was caused by the classloader trying to load a class
> while it was being rendered (?) to disk.  Probably not
> a big issue, unless trace-logging is enabled.
> Java stack information for the threads listed above:
> ===================================================
> "SMPP-TIMER-0":
>         at
> com.logica.smpp.util.ByteBuffer.getHexDump(ByteBuffer.java:379)
>         at
> com.logica.smpp.util.ByteBuffer.toString(ByteBuffer.java:387)
>         at
> org.apache.log4j.or.DefaultRenderer.doRender(DefaultRenderer.java:26)
>         at
> org.apache.log4j.or.RendererMap.findAndRender(RendererMap.java:70)
>         at
> org.apache.log4j.spi.LoggingEvent.getRenderedMessage(LoggingEvent.java:288)
>         at
> org.apache.log4j.helpers.PatternParser$BasicPatternConverter.convert(PatternParser.java:395)
>         at
> org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:56)
>         at
> org.apache.log4j.PatternLayout.format(PatternLayout.java:495)
>         at
> org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292)
>         at
> org.apache.log4j.WriterAppender.append(WriterAppender.java:150)
>         at
> org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221)
>         - locked <0x473874c8> (a
> org.apache.log4j.ConsoleAppender)
>         at
> org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57)
>         at
> org.apache.log4j.Category.callAppenders(Category.java:187)
>         - locked <0x46829180> (a
> org.apache.log4j.spi.RootCategory)
>         at
> org.apache.log4j.Category.forcedLog(Category.java:372)
>         at
> org.apache.log4j.Category.debug(Category.java:241)
>         at
> com.logica.smpp.debug.Log4JDebug.write(Log4JDebug.java:79)
>         at
> com.logica.smpp.TCPIPConnection.send(TCPIPConnection.java:301)
>         at
> com.logica.smpp.Transmitter.send(Transmitter.java:81)
>         at com.logica.smpp.Session.send(Session.java:983)
>         at com.logica.smpp.Session.bind(Session.java:452)
>         at 
> ...
> "SMSC-Accept-16910":
>         at
> org.apache.log4j.Category.callAppenders(Category.java:185)
>         - waiting to lock <0x46829180> (a
> org.apache.log4j.spi.RootCategory)
>         at
> org.apache.log4j.Category.forcedLog(Category.java:372)
>         at org.apache.log4j.Category.log(Category.java:864)
>         at
> org.jboss.logging.Log4jLoggerPlugin.trace(Log4jLoggerPlugin.java:96)
>         at org.jboss.logging.Logger.trace(Logger.java:113)
>         at
> org.jboss.mx.loading.UnifiedClassLoader3.attempt(UnifiedClassLoader3.java:242)
>         at
> org.jboss.mx.loading.UnifiedClassLoader3.loadClass(UnifiedClassLoader3.java:126)
>         - locked <0x472e2f38> (a
> org.jboss.mx.loading.UnifiedClassLoader3)
>         at
> java.lang.ClassLoader.loadClass(ClassLoader.java:255)
>         at
> java.lang.ClassLoader.loadClassInternal(ClassLoader.java:315)
>         - locked <0x472e2f38> (a
> org.jboss.mx.loading.UnifiedClassLoader3)
>         at
> com.proteusmobile.smsgw.server.ServerService.listen(ServerService.java:187)
>         at
> com.proteusmobile.smsgw.server.ServerService.access$3(ServerService.java:46)
>         at
> com.proteusmobile.smsgw.server.ServerService$Listener.run0(ServerService.java:163)
>         at
> com.proteusmobile.smsgw.server.ServerService$Listener.run(ServerService.java:154)
>         at java.lang.Thread.run(Thread.java:536)
> Found 1 deadlock.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira