Which version of log4j?
At 19:19 08.10.2002 +0100, you wrote: >Hi all, > >I was wondering if anyone could give me their opinion on this deadlock >that we've encountered when using log4j. The process that is using the >logger is a multithreaded messaging service running on the VisiBroker >orb. Log4j is configured to "catch" any output so it tries to print out >the stack trace of an exception that has been thrown by the orb. At the >same time, we are debugging some information to the log. The two calls >seem to colide. > >As I understand it, the object 0x43a0eca8 has been locked by the first >thread, which is debugging that a call is being invoked on a remote >object. The first thread is waiting for the stream (object 0x43a0b278) >to become free so it can write the message to the log. The second thread >is waiting for object 0x43a0eca8 and has the stream object 0x43a0b0278 >locked. The result is this deadlock. I can provide a full threaddump of >the process if required. > >I am looking for advice in two areas : > >1) If anyone has seen this before, or knows what the problem could be >then any information will be greatly appreciated. >2) I am attempting to recreate the problem with a simple multithreaded >program that logs messages to a file at the same time as throwing >exceptions and printing their stack traces. The problem doesn't occur in >my test program, despite the expectation that this deadlock would be >more likely to occur in a program with a higher density of calls. Any >ideas? > >Deadlock information from java >Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.1_04-b02) >Java HotSpot(TM) Client VM (build 1.3.1_04-b02, mixed mode) >------------------------------------------------------------------------------------- > >FOUND A JAVA LEVEL DEADLOCK: >---------------------------- >"VBJ ThreadPool Worker": > waiting to lock monitor 0x8090784 (object 0x43a0b278, a >java.io.PrintStream), > which is locked by "VBJ ThreadPool Worker" >"VBJ ThreadPool Worker": > waiting to lock monitor 0x809074c (object 0x43a0eca8, a >org.apache.log4j.spi.RootCategory), > which is locked by "VBJ ThreadPool Worker" > >JAVA STACK INFORMATION FOR THREADS LISTED ABOVE: >------------------------------------------------ >Java Stack for "VBJ ThreadPool Worker": >========== > at java.io.PrintStream.println(PrintStream.java:544) > - waiting to lock <43a0b278> (a java.io.PrintStream) > at org.apache.log4j.helpers.LogLog.error(LogLog.java:134) > at >org.apache.log4j.helpers.OnlyOnceErrorHandler.error(OnlyOnceErrorHandler.java:69) > > at >org.apache.log4j.helpers.OnlyOnceErrorHandler.error(OnlyOnceErrorHandler.java:59) > > at >org.apache.log4j.helpers.QuietWriter.write(QuietWriter.java:41) > 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) > at >org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57) > > at org.apache.log4j.Category.callAppenders(Category.java:187) > at org.apache.log4j.Category.forcedLog(Category.java:372) > at org.apache.log4j.Category.debug(Category.java:241) > at com.prismt.util.Debug.debug(Debug.java:143) > at >com.prismt.orb.portable.PersistentLocator.preinvoke(PersistentLocator.java:39) > > at >com.inprise.vbroker.poa.POAImpl.preinvokeLocator(POAImpl.java:1906) > at com.inprise.vbroker.poa.POAImpl.preinvoke(POAImpl.java:2104) > at >com.inprise.vbroker.ProtocolEngine.ServerEngineImpl.preinvoke(ServerEngineImpl.java:248) > > at >com.inprise.vbroker.GIOP.GiopProtocolAdapter.doRequest(GiopProtocolAdapter.java:390) > > at >com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(GiopProtocolAdapter.java:527) > > at >com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(TPDispatcherImpl.java:100) > > at >com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(ThreadPool.java:76) >Java Stack for "VBJ ThreadPool Worker": >========== > at org.apache.log4j.Category.callAppenders(Category.java:185) > at org.apache.log4j.Category.forcedLog(Category.java:372) > at org.apache.log4j.Category.error(Category.java:286) > at com.prismt.util.Debug$DiagStream.write(Debug.java:266) > - locked <43a0b238> (a com.prismt.util.Debug$DiagStream) > at java.io.PrintStream.write(PrintStream.java:217) > - locked <43a0b278> (a java.io.PrintStream) > at java.io.OutputStreamWriter.write(OutputStreamWriter.java:179) > > at java.io.BufferedWriter.flushBuffer(BufferedWriter.java:109) > - locked <43a0b728> (a java.io.OutputStreamWriter) > at java.io.BufferedWriter.write(BufferedWriter.java:204) > - locked <43a0b728> (a java.io.OutputStreamWriter) > at java.io.Writer.write(Writer.java:124) > at java.io.PrintStream.write(PrintStream.java:262) > - locked <43a0b278> (a java.io.PrintStream) > at java.io.PrintStream.print(PrintStream.java:421) > at java.io.PrintStream.println(PrintStream.java:558) > - locked <43a0b278> (a java.io.PrintStream) > at java.lang.Throwable.printStackTrace(Throwable.java:176) > - locked <43a0b278> (a java.io.PrintStream) > at >com.inprise.vbroker.GIOP.GiopProtocolAdapter.doRequest(GiopProtocolAdapter.java:469) > > at >com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(GiopProtocolAdapter.java:527) > > at >com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(TPDispatcherImpl.java:100) > > at >com.inprise.vbroker.orb.ThreadPool$PoolWorker.run(ThreadPool.java:76) > >Found 1 deadlock. > >Thanks, > >Paul >-- >Paul Graham >Software Engineer >Prismtech Ltd, UK >http://www.prismtechnologies.com > > > >-- >To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]> >For additional commands, e-mail: <mailto:[EMAIL PROTECTED]> -- Ceki TCP implementations will follow a general principle of robustness: be conservative in what you do, be liberal in what you accept from others. -- Jon Postel, RFC 793 -- To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]> For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>
