遇到生产环境锁死的问题,nginx 出现大量的 502。以前也偶尔出现,都是快速重启恢复服务。今天又出现了,抓了下日志,发现居然是 logback 锁死的,坑爹。
[root@host ~]# grep 0x000000008683cf68 catalina.out.bak
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- locked <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
- waiting to lock <0x000000008683cf68> (a ch.qos.logback.core.util.CachingDateFormatter)
实际锁死线程:
"http-nio-8080-exec-188" #671375 daemon prio=5 os_prio=0 tid=0x00007ff239512000 nid=0x7519 runnable [0x00007ff18ceae000]
java.lang.Thread.State: RUNNABLE
at java.util.Arrays.copyOf(Arrays.java:3181)
at java.text.DateFormatSymbols.copyMembers(DateFormatSymbols.java:850)
at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:758)
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 <0x000000008683cf68> (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.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
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_2(Logger.java:414)
at ch.qos.logback.classic.Logger.warn(Logger.java:700)
at com.xxx.common.cache.Cache.cancel(Cache.java:140)
at com.xxx.common.cache.Cache.schedule(Cache.java:84)
at com.xxx.common.cache.Cache.expireIn(Cache.java:238)
at com.xxx.common.cache.Cache.setObject(Cache.java:216)
at com.xxx.platform.cache.CacheManager.setObject(CacheManager.java:66)
at com.xxx.platform.session.SessionUtil.setUserInfo(SessionUtil.java:415)
at com.xxx.platform.session.SessionUtil.setUserInfo(SessionUtil.java:356)
at com.xxx.platform.session.SessionUtil.setUserInfo(SessionUtil.java:340)
at com.xxx.platform.interceptor.ServletInterceptor.increaseActivities(ServletInterceptor.java:128)
at com.xxx.platform.interceptor.ServletInterceptor.before(ServletInterceptor.java:57)
at com.xxx.web.ActionServlet.__do_service__(ActionServlet.java:321)
at com.xxx.web.ActionServlet.service(ActionServlet.java:287)
logback作者说1.2.x已经解决死锁的问题了,然而我们用的是1.2.3,貌似并没有解决,照样锁死。具体原因是什么,暂时不知道,先记录一下问题。