I can also imagine that you have synchronization, directly or indirectly on methods that are used to "compose" the logger messages, and that those logger messages are inside synchronized sections.
If so, you are in the domain of synchronization patterns, instead of log4j, and separate topic. But then again, I may be worng. Niclas On Wednesday 09 October 2002 03:18, Paul Graham wrote: > Hi Ceki, > > We don't use a log4j config file, per se. We specify all the properties > that our service needs at startup in an xml file, which is configured by a > GUI. The properties below are the log4j properties that we specify. > > log4j.appender.Default.SyslogHost=localhost > log4j.appender.Default=org.apache.log4j.FileAppender > log4j.appender.Default.File=/home/orbtest1/TudorTests/distrib/etc/log/Brows >erLog.log > > log4j.rootLogger=Debug, Default > log4j.appender.Default.Append=true > log4j.appender.Default.layout=org.apache.log4j.SimpleLayout > > Your other reply makes sense, although all our logging is done to a file. > In the deadlock report from the JVM the deadlock indicates that the first > thread is waiting for the stream to the file and the second has this stream > locked. This backs up your theory about the logger wanting to write to a > locked object, however, the first thread should just wait for the lock to > be released, which never happens. We think that this is because the second > thread is waiting for a lock to an object which the first thread already > has locked. The thing is that the second thread isn't a thread in our > service, it's an orb thread that has had it's attempt to peform console > output error reporting intercepted and re-routed to our service log. > > Thanks for your attention and swift responses. > > Paul > > Ceki Gülcü wrote: > > Can you also supply your log4j config file? > > > > At 19:36 08.10.2002 +0100, you wrote: > > >Sorry, > > > > > >1.2.5 is the version that we are experiencing the problem with. As an > > >additional point, the service hangs > > >after it has dealt with about 3 million messages and 160000 clients. The > > >service lasts about a week and > > >then hangs, not very recreatable. > > > > > >Thanks, > > > > > >Paul > > > > > >Ceki Gülcü wrote: > > > > 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(OnlyOnceErrorHan > > > > >dle > > > > > > r.java:69) > > > > > > > > at > > > > >org.apache.log4j.helpers.OnlyOnceErrorHandler.error(OnlyOnceErrorHan > > > > >dle > > > > > > r.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.appendLoopOnAppender > > > > >s(A > > > > > > ppenderAttachableImpl.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(PersistentLocato > > > > >r.j > > > > > > ava: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(Server > > > > >Eng > > > > > > ineImpl.java:248) > > > > > > > > at > > > > >com.inprise.vbroker.GIOP.GiopProtocolAdapter.doRequest(GiopProtocolA > > > > >dap > > > > > > ter.java:390) > > > > > > > > at > > > > >com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(GiopPro > > > > >toc > > > > > > olAdapter.java:527) > > > > > > > > at > > > > >com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(TPDispatch > > > > >erI > > > > > > mpl.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(GiopProtocolA > > > > >dap > > > > > > ter.java:469) > > > > > > > > at > > > > >com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(GiopPro > > > > >toc > > > > > > olAdapter.java:527) > > > > > > > > at > > > > >com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(TPDispatch > > > > >erI > > > > > > mpl.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]> > > > > > >-- > > >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]> -- To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]> For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>
