[logback-dev] [JIRA] (LOGBACK-1394) TimeBasedRollingPolicy LogbackLock deadlock at 23:59:59

[QOS.CH (JIRA)]

calonlan created LOGBACK-1394:
---------------------------------

             Summary: TimeBasedRollingPolicy LogbackLock deadlock at 23:59:59
                 Key: LOGBACK-1394
                 URL: https://jira.qos.ch/browse/LOGBACK-1394
             Project: logback
          Issue Type: Bug
    Affects Versions: 1.1.2
         Environment: *JDK：*
java version "1.8.0_162"
Java(TM) SE Runtime Environment (build 1.8.0_162-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.162-b12, mixed mode)

*logback.xml：*

<configuration scan="true" scanPeriod="180 seconds" debug="true">
    

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
 <file>../log/test.log</file>
 <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
 <fileNamePattern>../log/test.%d\{yyyy-MM-dd}.log.zip</fileNamePattern>
 </rollingPolicy>

 <encoder>
 <pattern>%d\{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
 </encoder>
</appender>

</configuration>
            Reporter: calonlan
            Assignee: Logback dev list
            Priority: Blocker


*threaddump ：*
Found one Java-level deadlock:
=============================

"async-task-thread-pool-1-tid-59197-huoqiu-685270909":
 waiting to lock Monitor at 0x00007f140c0282f8 (Object at 0x00000000e802a3b0, a ch/qos/logback/core/rolling/TimeBasedRollingPolicy),
 which is held by "async-task-thread-pool-1-tid-59195-huoqiu-685270900"
"async-task-thread-pool-1-tid-59195-huoqiu-685270900":
 waiting to lock Monitor at 0x00007f13fc061b08 (Object at 0x00000000e8035950, a ch/qos/logback/core/spi/LogbackLock),
 which is held by "async-task-thread-pool-1-tid-59197-huoqiu-685270909"

Found a total of 1 deadlock.

Thread 20382: (state = BLOCKED)
 - ch.qos.logback.core.rolling.RollingFileAppender.subAppend(java.lang.Object) @bci=6, line=176 (Compiled frame)
 - ch.qos.logback.core.OutputStreamAppender.append(java.lang.Object) @bci=10, line=103 (Compiled frame)
 - ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) @bci=123, line=88 (Compiled frame)
 - ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(java.lang.Object) @bci=33, line=48 (Compiled frame)
 - ch.qos.logback.classic.Logger.appendLoopOnAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=12, line=273 (Compiled frame)
 - ch.qos.logback.classic.Logger.callAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=11, line=260 (Compiled frame)
 - ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=27, line=442 (Compiled frame)
 - ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=57, line=396 (Compiled frame)
 - ch.qos.logback.classic.Logger.info(java.lang.String) @bci=11, line=600 (Compiled frame)
 - com.bj58.spat.gaea.server.contract.log.LogbackLogger.info(java.lang.String) @bci=9, line=101 (Compiled frame)
 - com.bj58.spat.gaea.server.filter.ExecuteTimeFilter.filter(com.bj58.spat.gaea.server.contract.context.GaeaContext) @bci=121, line=72 (Compiled frame)
 - com.bj58.spat.gaea.server.core.proxy.AsyncInvokerHandle$1.run() @bci=203, line=99 (Compiled frame)
 - com.bj58.spat.gaea.server.util.async.AsyncWorker$1.run() @bci=84, line=157 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1149 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=624 (Compiled frame)
 - java.lang.Thread.run() @bci=11, line=748 (Compiled frame)


Thread 20380: (state = BLOCKED)
 - ch.qos.logback.core.rolling.RollingFileAppender.subAppend(java.lang.Object) @bci=6, line=176 (Compiled frame)
 - ch.qos.logback.core.OutputStreamAppender.append(java.lang.Object) @bci=10, line=103 (Compiled frame)
 - ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) @bci=123, line=88 (Compiled frame)
 - ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(java.lang.Object) @bci=33, line=48 (Compiled frame)
 - ch.qos.logback.classic.Logger.appendLoopOnAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=12, line=273 (Compiled frame)
 - ch.qos.logback.classic.Logger.callAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=11, line=260 (Compiled frame)
 - ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=27, line=442 (Compiled frame)
 - ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=57, line=396 (Compiled frame)
 - ch.qos.logback.classic.Logger.info(java.lang.String) @bci=11, line=600 (Compiled frame)
 - com.bj58.spat.gaea.server.contract.log.LogbackLogger.info(java.lang.String) @bci=9, line=101 (Compiled frame)
 - com.bj58.spat.gaea.server.filter.ExecuteTimeFilter.filter(com.bj58.spat.gaea.server.contract.context.GaeaContext) @bci=121, line=72 (Compiled frame)
 - com.bj58.spat.gaea.server.core.proxy.AsyncInvokerHandle$1.run() @bci=203, line=99 (Compiled frame)
 - com.bj58.spat.gaea.server.util.async.AsyncWorker$1.run() @bci=84, line=157 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1149 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=624 (Compiled frame)
 - java.lang.Thread.run() @bci=11, line=748 (Compiled frame)


Thread 20378: (state = BLOCKED)
 - ch.qos.logback.core.rolling.RollingFileAppender.subAppend(java.lang.Object) @bci=6, line=176 (Compiled frame)
 - ch.qos.logback.core.OutputStreamAppender.append(java.lang.Object) @bci=10, line=103 (Compiled frame)
 - ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) @bci=123, line=88 (Compiled frame)
 - ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(java.lang.Object) @bci=33, line=48 (Compiled frame)
 - ch.qos.logback.classic.Logger.appendLoopOnAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=12, line=273 (Compiled frame)
 - ch.qos.logback.classic.Logger.callAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=11, line=260 (Compiled frame)
 - ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=27, line=442 (Compiled frame)
 - ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=57, line=396 (Compiled frame)
 - ch.qos.logback.classic.Logger.info(java.lang.String) @bci=11, line=600 (Compiled frame)
 - com.bj58.spat.gaea.server.contract.log.LogbackLogger.info(java.lang.String) @bci=9, line=101 (Compiled frame)
 - com.bj58.spat.gaea.server.filter.ExecuteTimeFilter.filter(com.bj58.spat.gaea.server.contract.context.GaeaContext) @bci=121, line=72 (Compiled frame)
 - com.bj58.spat.gaea.server.core.proxy.AsyncInvokerHandle$1.run() @bci=203, line=99 (Compiled frame)
 - com.bj58.spat.gaea.server.util.async.AsyncWorker$1.run() @bci=84, line=157 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1149 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=624 (Compiled frame)
 - java.lang.Thread.run() @bci=11, line=748 (Compiled frame)


Thread 20377: (state = BLOCKED)
 - ch.qos.logback.core.rolling.RollingFileAppender.subAppend(java.lang.Object) @bci=6, line=176 (Compiled frame)
 - ch.qos.logback.core.OutputStreamAppender.append(java.lang.Object) @bci=10, line=103 (Compiled frame)
 - ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) @bci=123, line=88 (Compiled frame)
 - ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(java.lang.Object) @bci=33, line=48 (Compiled frame)
 - ch.qos.logback.classic.Logger.appendLoopOnAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=12, line=273 (Compiled frame)
 - ch.qos.logback.classic.Logger.callAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=11, line=260 (Compiled frame)
 - ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=27, line=442 (Compiled frame)
 - ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=57, line=396 (Compiled frame)
 - ch.qos.logback.classic.Logger.info(java.lang.String) @bci=11, line=600 (Compiled frame)
 - com.bj58.spat.gaea.server.contract.log.LogbackLogger.info(java.lang.String) @bci=9, line=101 (Compiled frame)
 - com.bj58.spat.gaea.server.filter.ExecuteTimeFilter.filter(com.bj58.spat.gaea.server.contract.context.GaeaContext) @bci=121, line=72 (Compiled frame)
 - com.bj58.spat.gaea.server.core.proxy.AsyncInvokerHandle$1.run() @bci=203, line=99 (Compiled frame)
 - com.bj58.spat.gaea.server.util.async.AsyncWorker$1.run() @bci=84, line=157 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1149 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=624 (Compiled frame)
 - java.lang.Thread.run() @bci=11, line=748 (Compiled frame)



--
This message was sent by Atlassian JIRA
(v7.3.1#73012)