You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by je...@hsbcgroup.com on 2002/07/10 16:52:58 UTC

Log4j hanging application...

We have been using log4j (v113) successfully for some time now with
Weblogic 6.1and J2SE 1.3.1_02 on Sun Solaris.
We have just started experiencing what appears to be a log4j problem (!!)
in one of our environments.
At startup time log4j is configured successfully , but when a call is made
to isDebugEnabled control never returns and so weblogic hangs.
This only happens when we start using anything other than DEBUG.
I have tried using the most basic properties files but as long as it is set
at anything other than DEBUG, it will hang.
There is a way round it... start with everything at DEBUG, then use a
servlet to reconfigure log4j at INFO/WARN etc -- but not very clever
I noticed a similar problem mentioned here some time ago but it was never
resolved (mail from Thomas Porschberg "loop due to getInstance" May 2002)
Does anyone have any ideas?
Thanks
Jenny

PS. Here is an edited ( I took out all waiting threads) thread dump after
it hung:
Starting WebLogic Server ....
<Jul 10, 2002 10:56:55 AM UTC> <Notice> <Management> <Loading configuration file ./config/config.xml ...>
[Full GC 32784K->3382K(2096000K), 0.4124035 secs]
[GC 33836K->4511K(2096000K), 0.0516093 secs]
log4j: Parsing for [root] with value=[INFO,CONSOLE,TESTLOG].
log4j: Priority token is [INFO].
log4j: Category root set to INFO
log4j: Parsing appender named "CONSOLE".
log4j: Parsing layout options for "CONSOLE".
log4j: Setting property [conversionPattern] to [%d %p [%t] %c - %m%n].
log4j: End of parsing for "CONSOLE".
log4j: Parsed "CONSOLE" options.
log4j: Parsing appender named "TESTLOG".
log4j: Parsing layout options for "TESTLOG".
log4j: Setting property [conversionPattern] to [%d %p [%t] %c - %m%n].
log4j: End of parsing for "TESTLOG".
log4j: Setting property [immediateFlush] to [true].
log4j: Setting property [maxBackupIndex] to [10].
log4j: Setting property [file] to [/opt/config/logs/TEST.log].
log4j: Setting property [maxFileSize] to [20MB].
log4j: Parsed "TESTLOG" options.
log4j: Finished configuring.
Full thread dump:

"ExecuteThread: '9' for queue: '__weblogic_admin_rmi_queue'" daemon prio=5 tid=0x3c9760 nid=0x52 waiting on monitor [0x6af01000..0x6af019d8]
      at java.lang.Object.wait(Native Method)
      at java.lang.Object.wait(Object.java:420)
      at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:94)
      at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:118)

.... (Lots more of similar waiting threads)...
..............................................
..............................................


"ExecuteThread: '0' for queue: 'default'" daemon prio=5 tid=0x532f78 nid=0xd waiting on monitor [0x6f401000..0x6f4019d8]
      at java.lang.Object.wait(Native Method)
      at java.lang.Object.wait(Object.java:420)
      at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:94)
      at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:118)

"Thread-0" daemon prio=10 tid=0x530650 nid=0xc waiting on monitor [0x71101000..0x711019d8]
      at java.lang.Thread.sleep(Native Method)
      at weblogic.transaction.internal.TransactionManagerImpl$1.run(TransactionManagerImpl.java:1546)
      at java.lang.Thread.run(Thread.java:484)

"Signal Dispatcher" daemon prio=10 tid=0x168e78 nid=0xa waiting on monitor [0..0]

"Finalizer" daemon prio=8 tid=0x165b80 nid=0x7 waiting on monitor [0xfe201000..0xfe2019d8]
      at java.lang.Object.wait(Native Method)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:108)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:123)
      at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:162)

"Reference Handler" daemon prio=10 tid=0x164258 nid=0x6 waiting on monitor [0xfe301000..0xfe3019d8]
      at java.lang.Object.wait(Native Method)
      at java.lang.Object.wait(Object.java:420)
      at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:110)

"main" prio=5 tid=0x298f8 nid=0x1 runnable [0xffbed000..0xffbee63c]
      at org.apache.log4j.Category.isDebugEnabled(Category.java:753)
      at com.myapp.foundation.base.security.connectionfilter.MyAppConnectionFilter.<init>(MyAppConnectionFilter.java:59)
      at java.lang.Class.newInstance0(Native Method)
      at java.lang.Class.newInstance(Class.java:237)
      at weblogic.security.SecurityService.initializeConnectionFilter(SecurityService.java:217)
      at weblogic.security.SecurityService.initialize(SecurityService.java:113)
      at weblogic.t3.srvr.T3Srvr.initialize(T3Srvr.java:402)
      at weblogic.t3.srvr.T3Srvr.run(T3Srvr.java:202)
      at weblogic.Server.main(Server.java:35)

"VM Thread" prio=5 tid=0x156c98 nid=0x4 runnable

"VM Periodic Task Thread" prio=10 tid=0x168098 nid=0x8 runnable
"Suspend Checker Thread" prio=10 tid=0x168988 nid=0x9 runnable






The HSBC Group's website is at http://www.hsbc.com
_____________________________________________________

HSBC Bank Plc, which is regulated in the UK by FSA, has issued the 
information contained in this message (including any attached 
documents) for its institutional and professional customers only. 
It is not intended for private customers. This message and any 
attachments are not an invitation to buy or sell securities or related 
financial instruments, are confidential to the named recipient and may 
also be privileged. The information should not be reproduced and / or 
distributed to any other person. Internet communications are not secure 
and HSBC Bank Plc makes no representation and accepts no 
responsibility or liability as to the completeness and accuracy of the 
information contained in this message. Each page attached hereto 
must be read in conjunction with any disclosure which forms part of it.


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>


Re: Log4j hanging application...

Posted by Ceki Gülcü <ce...@qos.ch>.
Is this problem reproducible?

By the way, in 1.1.3. line 753 in Category.java is javadoc not an
executable java statement. So the following line

     at org.apache.log4j.Category.isDebugEnabled(Category.java:753)

is somewhat suspicious. Can you check what line 753 corresponds to in
your copy of log4j? Nevertheless, the fact that it seems to hang
within log4j code is very alarming.

At 15:52 10.07.2002 +0100, jenny.hunt@hsbcgroup.com wrote:
>We have been using log4j (v113) successfully for some time now with
>Weblogic 6.1and J2SE 1.3.1_02 on Sun Solaris.
>We have just started experiencing what appears to be a log4j problem (!!)
>in one of our environments.
>At startup time log4j is configured successfully , but when a call is made
>to isDebugEnabled control never returns and so weblogic hangs.
>This only happens when we start using anything other than DEBUG.
>I have tried using the most basic properties files but as long as it is set
>at anything other than DEBUG, it will hang.
>There is a way round it... start with everything at DEBUG, then use a
>servlet to reconfigure log4j at INFO/WARN etc -- but not very clever
>I noticed a similar problem mentioned here some time ago but it was never
>resolved (mail from Thomas Porschberg "loop due to getInstance" May 2002)
>Does anyone have any ideas?
>Thanks
>Jenny
>
>PS. Here is an edited ( I took out all waiting threads) thread dump after
>it hung:
>Starting WebLogic Server ....
><Jul 10, 2002 10:56:55 AM UTC> <Notice> <Management> <Loading 
>configuration file ./config/config.xml ...>
>[Full GC 32784K->3382K(2096000K), 0.4124035 secs]
>[GC 33836K->4511K(2096000K), 0.0516093 secs]
>log4j: Parsing for [root] with value=[INFO,CONSOLE,TESTLOG].
>log4j: Priority token is [INFO].
>log4j: Category root set to INFO
>log4j: Parsing appender named "CONSOLE".
>log4j: Parsing layout options for "CONSOLE".
>log4j: Setting property [conversionPattern] to [%d %p [%t] %c - %m%n].
>log4j: End of parsing for "CONSOLE".
>log4j: Parsed "CONSOLE" options.
>log4j: Parsing appender named "TESTLOG".
>log4j: Parsing layout options for "TESTLOG".
>log4j: Setting property [conversionPattern] to [%d %p [%t] %c - %m%n].
>log4j: End of parsing for "TESTLOG".
>log4j: Setting property [immediateFlush] to [true].
>log4j: Setting property [maxBackupIndex] to [10].
>log4j: Setting property [file] to [/opt/config/logs/TEST.log].
>log4j: Setting property [maxFileSize] to [20MB].
>log4j: Parsed "TESTLOG" options.
>log4j: Finished configuring.
>Full thread dump:
>
>"ExecuteThread: '9' for queue: '__weblogic_admin_rmi_queue'" daemon prio=5 
>tid=0x3c9760 nid=0x52 waiting on monitor [0x6af01000..0x6af019d8]
>       at java.lang.Object.wait(Native Method)
>       at java.lang.Object.wait(Object.java:420)
>       at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:94)
>       at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:118)
>
>.... (Lots more of similar waiting threads)...
>..............................................
>..............................................
>
>
>"ExecuteThread: '0' for queue: 'default'" daemon prio=5 tid=0x532f78 
>nid=0xd waiting on monitor [0x6f401000..0x6f4019d8]
>       at java.lang.Object.wait(Native Method)
>       at java.lang.Object.wait(Object.java:420)
>       at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:94)
>       at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:118)
>
>"Thread-0" daemon prio=10 tid=0x530650 nid=0xc waiting on monitor 
>[0x71101000..0x711019d8]
>       at java.lang.Thread.sleep(Native Method)
>       at 
> weblogic.transaction.internal.TransactionManagerImpl$1.run(TransactionManagerImpl.java:1546)
>       at java.lang.Thread.run(Thread.java:484)
>
>"Signal Dispatcher" daemon prio=10 tid=0x168e78 nid=0xa waiting on monitor 
>[0..0]
>
>"Finalizer" daemon prio=8 tid=0x165b80 nid=0x7 waiting on monitor 
>[0xfe201000..0xfe2019d8]
>       at java.lang.Object.wait(Native Method)
>       at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:108)
>       at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:123)
>       at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:162)
>
>"Reference Handler" daemon prio=10 tid=0x164258 nid=0x6 waiting on monitor 
>[0xfe301000..0xfe3019d8]
>       at java.lang.Object.wait(Native Method)
>       at java.lang.Object.wait(Object.java:420)
>       at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:110)
>
>"main" prio=5 tid=0x298f8 nid=0x1 runnable [0xffbed000..0xffbee63c]
>       at org.apache.log4j.Category.isDebugEnabled(Category.java:753)
>       at 
> com.myapp.foundation.base.security.connectionfilter.MyAppConnectionFilter.<init>(MyAppConnectionFilter.java:59)
>       at java.lang.Class.newInstance0(Native Method)
>       at java.lang.Class.newInstance(Class.java:237)
>       at 
> weblogic.security.SecurityService.initializeConnectionFilter(SecurityService.java:217)
>       at 
> weblogic.security.SecurityService.initialize(SecurityService.java:113)
>       at weblogic.t3.srvr.T3Srvr.initialize(T3Srvr.java:402)
>       at weblogic.t3.srvr.T3Srvr.run(T3Srvr.java:202)
>       at weblogic.Server.main(Server.java:35)
>
>"VM Thread" prio=5 tid=0x156c98 nid=0x4 runnable
>
>"VM Periodic Task Thread" prio=10 tid=0x168098 nid=0x8 runnable
>"Suspend Checker Thread" prio=10 tid=0x168988 nid=0x9 runnable

--
Ceki


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>