Thread BLOCKED on org.apache.log4j.Category.callAppenders, but not waiting for any lock

Question

My web application(delpoyed on weblogic) went down, when I check the jstack info, I found most threads are BLOCKED on a org.apache.log4j.spi.RootLogger. The thread owning this lock is also BLOCKED and stucked for at least 20min until i kill the process, but it's not waiting on any other lock, how does this happen?

here is the jstack info:

the BLOCKED thread owning lock <783b8910>, but not waiting on other locks:

"[STUCK] ExecuteThread: '58' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=7 tid=02e45400 nid=86 lwp_id=7959740 waiting for monitor entry [61cff000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
- locked <783b8910> (a org.apache.log4j.spi.RootLogger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.error(Category.java:302)

other threads waiting to lock <783b8910>:

"[STUCK] ExecuteThread: '36' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=7 tid=02e0ea00 nid=64 lwp_id=7959717 waiting for monitor entry [62d7f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
- waiting to lock <783b8910> (a org.apache.log4j.spi.RootLogger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.error(Category.java:319)

and

"[STUCK] ExecuteThread: '34' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=7 tid=02e0a200 nid=62 lwp_id=7959715 waiting for monitor entry [62eff000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
- waiting to lock <783b8910> (a org.apache.log4j.spi.RootLogger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.info(Category.java:663)

and so on, total 64 threads are waiting to lock <783b8910>

this happens about 1-3 times a month, I cannot find a solution because I don't know why the thread owning the lock is BLOCKED while not waiting for other locks.

the log4j version is 1.2.13

Who is owning <61cff000> and how long it's blocked for this thread? — SMA
– SMA, Commented Jan 4, 2015 at 6:51
no one is owning 61cff000, at least i cannot find in jstack ouput. the thread is blocked for at least 20min — kelgon
– kelgon, Commented Jan 4, 2015 at 7:00
My suspicion would be that the actual file-write call got stuck for some reason, such as a hung NFS mount. — chrylis -cautiouslyoptimistic-
– chrylis -cautiouslyoptimistic-, Commented Jan 4, 2015 at 7:04
I'd just like to point out that Log4j 1.2.13 was released in 2005 and was essentially "replaced" by the same author, due to inherent flaws in the log4j design, in the form of slf4j and logback, see en.wikipedia.org/wiki/Log4j — Alex
– Alex, Commented Jan 5, 2015 at 1:14

Aamir · Accepted Answer · 2020-12-15 12:59:33Z

0

On Java Command Windows, if you have clicked to stop printing logs then this thread blocking occurs at printing logs, so thread goes on Blocked state while printing logs.

So if this is the issue you can use AsyncAppender.

answered Dec 15, 2020 at 12:59

Aamir

666 bronze badges

Sign up to request clarification or add additional context in comments.

Comments

Gray · Accepted Answer · 2024-02-24 22:08:15Z

0

... total 64 threads are waiting to lock <783b8910>

The threads are all trying to write log4j messages in Category.callAppenders(LoggingEvent event). You should download the log4j source and then specifically look at the code lines corresponding to your thread stacktrace lines. The lines around there are:

for(Category c = this; c != null; c=c.parent) {
  // Protected against simultaneous call to addAppender, removeAppender,...
  synchronized(c) {
     if(c.aai != null) {
        writes += c.aai.appendLoopOnAppenders(event);

I susepct that one of the threads is actually holding the lock. If you carefully look at all of the thread stacktraces, some other thread's stack is in org.apache.log4j.Category but is not blocked at line 201. Maybe it is calling org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(LoggingEvent) which is blocking for some reason.

Take a look at the actual appender implementation in question. Any chance it is writing to a network drive that is offline or something?

WARNING: Now in 2024, log4j version 1 has significant security holes in it. You should find and fix the problem your locking issue with your code but afterwards you should consider upgrading to log4j v2.

edited Feb 24, 2024 at 22:08

answered Feb 20, 2024 at 23:53

Gray

117k24 gold badges305 silver badges360 bronze badges

2 Comments

Piotr P. Karwasz Over a year ago

This question predates the EOL announcement of Log4j 1.x. Log4j 1.x had also known locking issues that required an architecture change.

Gray Over a year ago

You are correct @PiotrP.Karwasz. No idea why it showed this message to me to answer. I've edited my warning. Thanks.

Collectives™ on Stack Overflow

Thread BLOCKED on org.apache.log4j.Category.callAppenders, but not waiting for any lock

2 Answers 2

Comments

2 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

2 Answers 2

Comments

2 Comments

Your Answer

Sign up or log in

Post as a guest

Related