-
-
Save debraj-manna/d3b8de557ae3514368ab66b947d0ed14 to your computer and use it in GitHub Desktop.
Logback thread stuck
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
I am observing logback 1.2.3 getting stuck with stacktrace like below . In case the email gets truncated I am also placing the above logs in the below gist | |
``` | |
Schedule_CISCON9K_10.22.8.7_config_OpMgr-0" #874742 prio=5 os_prio=0 tid=0x00007fff54789000 nid=0x31f0 waiting for monitor entry [0x00007fff0e323000] | |
java.lang.Thread.State: BLOCKED (on object monitor) | |
at ch.qos.logback.core.util.CachingDateFormatter.format(CachingDateFormatter.java:45) | |
- waiting to lock <0x00000006488ca358> (a ch.qos.logback.core.util.CachingDateFormatter) | |
at ch.qos.logback.classic.pattern.DateConverter.convert(DateConverter.java:61) | |
at ch.qos.logback.classic.pattern.DateConverter.convert(DateConverter.java:23) | |
at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36) | |
at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:115) | |
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:141) | |
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:39) | |
at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(LayoutWrappingEncoder.java:115) | |
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:230) | |
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) | |
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) | |
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) | |
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) | |
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) | |
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) | |
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383) | |
at ch.qos.logback.classic.Logger.info(Logger.java:579) | |
at com.van.dataproviders.core.impl.cas.n5k.tasks.N5KSynchronousTask.doRun(N5KSynchronousTask.java:63) | |
at com.van.dataproviders.core.common.impl.dataprovider.tasks.AbstractTask.run(AbstractTask.java:104) | |
at com.van.dataproviders.tasker.Tasker$ScheduledTaskWrapper.run(Tasker.java:359) | |
at com.google.common.util.concurrent.MoreExecutors$ScheduledListeningDecorator$NeverSuccessfulListenableFutureTask.run(MoreExecutors.java:678) | |
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) | |
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) | |
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) | |
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) | |
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) | |
``` | |
Most thread trying to write to log are blocked on a `synchronize(this)` lock in `CachingDateFormatter` of logback. | |
But another thread, which actually has the above lock (thus blocking the other threads) is itself blocked as follows: | |
``` | |
"Schedule_CISCON9K_10.22.8.149_metric_OpMgr-0" #871618 prio=5 os_prio=0 tid=0x00007fff54740800 nid=0x7e56 waiting for monitor entry [0x00007fff15f1a000] | |
java.lang.Thread.State: BLOCKED (on object monitor) | |
at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1333) | |
at java.util.ResourceBundle.getBundle(ResourceBundle.java:899) | |
at sun.util.resources.LocaleData$1.run(LocaleData.java:167) | |
at sun.util.resources.LocaleData$1.run(LocaleData.java:163) | |
at java.security.AccessController.doPrivileged(Native Method) | |
at sun.util.resources.LocaleData.getBundle(LocaleData.java:163) | |
at sun.util.resources.LocaleData.getDateFormatData(LocaleData.java:127) | |
at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:710) | |
at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:145) | |
at sun.util.locale.provider.DateFormatSymbolsProviderImpl.getInstance(DateFormatSymbolsProviderImpl.java:85) | |
at java.text.DateFormatSymbols.getProviderInstance(DateFormatSymbols.java:364) | |
at java.text.DateFormatSymbols.getInstance(DateFormatSymbols.java:340) | |
at java.util.Calendar.getDisplayName(Calendar.java:2110) | |
at java.text.SimpleDateFormat.subFormat(SimpleDateFormat.java:1125) | |
at java.text.SimpleDateFormat.format(SimpleDateFormat.java:966) | |
at java.text.SimpleDateFormat.format(SimpleDateFormat.java:936) | |
at java.text.DateFormat.format(DateFormat.java:345) | |
at ch.qos.logback.core.util.CachingDateFormatter.format(CachingDateFormatter.java:48) | |
- locked <0x00000006488ca358> (a ch.qos.logback.core.util.CachingDateFormatter) | |
at ch.qos.logback.classic.pattern.DateConverter.convert(DateConverter.java:61) | |
Loback.xml | |
``` | |
<configuration scan="true" debug="true"> | |
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> | |
<Target>System.out</Target> | |
<encoder> | |
<pattern>%p [%d{yyyy-MM-dd HH:mm:ss,SSS}] %c{3}:[%C{1}:%M:%L] - [%t] - %replace(%.-20480m){'[^A-Za-z0-9=<>:@/.,"\'\-\[\]\{\}\(\)\n\s!|]','_'}%n</pattern> | |
</encoder> | |
</appender> | |
<root level="INFO"> | |
<appender-ref ref="CONSOLE"/> | |
</root> | |
</configuration> | |
``` |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment