Created attachment 32575 [details] Thread Dump Hi, We found the below issue in our Thread Dumps. Please let us know your thoughts if this is a known issue with log4j. The JVM that we use is 'BEA JRockit(R) R27.6.5-32_o-121899-1.6.0_14-20091001-2113-linux-x86_64'. The JDK is - 1.6.0_14 and the Java Vendor is BEA Systems, Inc. The OS is Linux-x86_64. Because of this issue other threads are getting struck in the JVM forming too many blocked-threads. We have attached our thread-dumps as well. In the thread-dumps, we can see the blocked chains pointing to this below struck thread - ExecuteThread: '3'. We are using the following jars for logging: 1. log4j-1.2.17.jar 2. slf4j-api-1.7.5.jar 3. slf4j-log4j12-1.7.5.jar Please let us know if any information that needs to be shared. "[STUCK] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'" id=43 idx=0xb0 tid=6731 prio=1 alive, in native, native_waiting, daemon at jrockit/vm/RNI.generateFixedCode(J)J(Native Method) at org/apache/log4j/spi/ThrowableInformation.getThrowableStrRep(ThrowableInformation.java:0) at org/apache/log4j/spi/LoggingEvent.getThrowableStrRep(LoggingEvent.java:413) at org/apache/log4j/WriterAppender.subAppend(WriterAppender.java:313) at org/apache/log4j/RollingFileAppender.subAppend(RollingFileAppender.java:276) at org/apache/log4j/WriterAppender.append(WriterAppender.java:162) at org/apache/log4j/AppenderSkeleton.doAppend(AppenderSkeleton.java:251) ^-- Holding lock: org/apache/log4j/RollingFileAppender@0x553f0ab8[thin lock] at org/apache/log4j/helpers/AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66) at org/apache/log4j/Category.callAppenders(Category.java:206) ^-- Holding lock: org/apache/log4j/spi/RootLogger@0x553efbf8[thin lock] at org/apache/log4j/Category.forcedLog(Category.java:391) at org/apache/log4j/Category.log(Category.java:856) at org/slf4j/impl/Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:575)
All new development work is happening on Log4j 2. I would recommend you use 1. slf4j-api-1.7.5.jar 2. log4j-slf4j-impl-2.2.jar 3. log4j-api-2.2.jar 4. log4j-core-2.2.jar Then change your log4j configuration to match the format used by Log4j 2. See http://logging.apache.org/log4j/2.x/manual/configuration.html.
Thank you Ralph. But I have one concern, which is, how can we be sure if its gonna solve our problem? Has this sort of issue been reported earlier or anything similar? I am asking this question because we between two minds here since we are seeing this line - 'jrockit/vm/RNI.generateFixedCode(J)J(Native Method)' in our thread-dumps. Our eyes are on Jrockit JVM too because that seems to be the root cause as seen in the stack trace. Please share your thoughts on this. Thanks a lot in advance. Regards, -Sawan.Patwari
Log4j 2 does not lock when processing the appenders collection. Individual appenders may hold locks while writing to streams, sockets, etc. where you wouldn't see same sort of behavior as below. Also, in general processing a stack trace in Log4j 2 is going to be more efficient than in Log4j 1. You may also want to take advantage of Asynchronous Loggers in Log4j 2 as that should keep your application threads from being hindered by logging.
Are you hinting by saying that we may perhaps not see the below issue in future with log4j 2? The below information is gotten from Thread-Dumps. ExecuteThread: '22' and like others are all struck due to ExecuteThread: '3' in the below fashion. Likewsie, there are 23 other Blocked-Chains in thread-dumps with the same issue. Chain 24: "[STUCK] ExecuteThread: '22' for queue: 'weblogic.kernel.Default (self-tuning)'" id=415 idx=0x368 tid=10747 waiting for org/apache/log4j/spi/RootLogger@0x553efbf8 held by: "[STUCK] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'" id=43 idx=0xb0 tid=6731 in chain 1 Thank you again. Regards, -Sawan.Patwari
Yes, I am saying that the code in Log4j 2 is much different and locking is handled much differently. There is no lock on the root logger or on the appender loop.
Thank you Ralph. Appreciate your inputs. Regards, -Sawan.Patwari
Hi Team, I am facing issue with log4j root logger. RootLogger is getting blocked. Below are the thread dumps from our managed server. Could you please help me to resolve the issue. ###<Jul 21, 2015 9:23:58 AM IST> <Info> <Server> <aukpczbr.dc-dublin.de> <aukpczbr_p2> <[ACTIVE] ExecuteThread: '13' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1437467038573> <BEA-002634> <The server "pci_p2_ad_admin" disconnected from this server.> ####<Jul 21, 2015 9:23:58 AM IST> <Error> <WebLogicServer> <aukpczbr.dc-dublin.de> <aukpczbr_p2> <[STANDBY] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1437467038600> <BEA-000337> <[STUCK] ExecuteThread: '16' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "652" seconds working on the request "weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl@58887aee", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace: Thread-3471 "[STUCK] ExecuteThread: '16' for queue: 'weblogic.kernel.Default (self-tuning)'" <alive, suspended, blocked, priority=1, DAEMON> { -- Blocked trying to get lock: org.apache.log4j.spi.RootLogger@21cb1369[not locked] org.apache.log4j.Category.callAppenders(Category.java:204) org.apache.log4j.Category.forcedLog(Category.java:391) org.apache.log4j.Category.log(Category.java:856) org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:541) com.vodafone.pciadaptor.core.emis.HttpConnectionProbe.onRun(HttpConnectionProbe.java:105) com.vodafone.pciadaptor.core.scheduling.AbstractScheduledTask.run(AbstractScheduledTask.java:42) org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51) java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439) java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317) java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150) org.springframework.scheduling.commonj.TimerManagerTaskScheduler$TimerScheduledFuture.timerExpired(TimerManagerTaskScheduler.java:112) org.springframework.scheduling.commonj.TimerManagerTaskScheduler$ReschedulingTimerListener.timerExpired(TimerManagerTaskScheduler.java:165) weblogic.timers.internal.commonj.ListenerWrap.timerExpired(ListenerWrap.java:37) weblogic.timers.internal.TimerImpl.run(TimerImpl.java:273) weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:528) weblogic.work.ExecuteThread.execute(ExecuteThread.java:207) weblogic.work.ExecuteThread.run(ExecuteThread.java:176) } >
FYI: https://blogs.apache.org/foundation/entry/apache_logging_services_project_announces
Could you please help with a temporary solution for this. As this is creating issue on production server with business impact. Thanks in advance
Hi Gary, Could you please help with a temporary solution for resolving this issue. Also will upgrading log4j 1.x to log4j2 resolve this issue?
There is no temporary fix for this issue and is one of the reasons Log4j 2 came about. The only fix is to upgrade to Log4j 2.
Thanks a lot Ralph. Appreciate your quick response.
As stated in the reference link provided by you, we have two solutions for upgrading lo4j 1.x to log4j2.At this point of time we wont be able to upgrade to log4j2 completely as this application deals with live transactions. So please suggest if we can can go with migrating to log4j 2 with the help of log4j 1.2 Bridge.Also let me know the latest and and stable version log4j1.2 bridge Can you also confirm if this solution is going to resolve this issue as it is affecting the live transactions. Many thanks.
Your stack trace shows you are calling Log4j1 via the SLF4J API. You can use Log4J 2's sLF4J binding instead of the Binding to Log4j 1 provided by the SLF4J project. Log4j 2 does not have this issue with locking.
Many Thanks Ralph. Currently I am using log4j version 1.2.16 and slf4j version 1.6.1. Which is the stable version that can be used to resolve this issue.
Stable version for migrating using logging Bridge 1.x
*** Bug 58218 has been marked as a duplicate of this bug. ***
Hi Ralph I have replaced the existing log4j 1.2.16 jar with log4j1.2-api jar version 2.3.Am I replacing with the right jar for using bridge for migrating from log4j1.x to log4j 2. Could you please help. Thanks in advance.
Please see https://logging.apache.org/log4j/2.x/manual/migration.html