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/BrowserLog.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(OnlyOnceErrorHandle
> > r.java:69)
> > > >
> > > >         at
> > > >org.apache.log4j.helpers.OnlyOnceErrorHandler.error(OnlyOnceErrorHandle
> > 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.appendLoopOnAppenders(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(PersistentLocator.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(ServerEng
> > ineImpl.java:248)
> > > >
> > > >         at
> > > >com.inprise.vbroker.GIOP.GiopProtocolAdapter.doRequest(GiopProtocolAdap
> > ter.java:390)
> > > >
> > > >         at
> > > >com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(GiopProtoc
> > olAdapter.java:527)
> > > >
> > > >         at
> > > >com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(TPDispatcherI
> > 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(GiopProtocolAdap
> > ter.java:469)
> > > >
> > > >         at
> > > >com.inprise.vbroker.GIOP.GiopProtocolAdapter.dispatchMessage(GiopProtoc
> > olAdapter.java:527)
> > > >
> > > >         at
> > > >com.inprise.vbroker.orb.TPDispatcherImpl$TPDispatcher.run(TPDispatcherI
> > 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]>

--
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]>

Reply via email to