Logback永久掛起

我正在編寫一個Java應用程序來路由大量的併發消息。應用程序使用Logback框架進行日誌記錄，並且在應用程序掛起時看到令人驚訝的行爲。在一個堆棧跟蹤，我可以看到，應用程序線程都停留在記錄來電：Logback永久掛起

"New I/O client worker #1-1" #125 prio=5 os_prio=0 tid=0x00007f0524017000 nid=0x29f3 waiting on condition [0x00007f052ecea000] 
    java.lang.Thread.State: WAITING (parking) 
     at sun.misc.Unsafe.park(Native Method) 
     - parking to wait for <0x00007f089c4a7e88> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) 
     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) 
     at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836) 
     at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870) 
     at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199) 
     at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209) 
     at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285) 
     at java.util.concurrent.ArrayBlockingQueue.remainingCapacity(ArrayBlockingQueue.java:468) 
     at ch.qos.logback.core.AsyncAppenderBase.isQueueBelowDiscardingThreshold(AsyncAppenderBase.java:152) 
     at ch.qos.logback.core.AsyncAppenderBase.append(AsyncAppenderBase.java:144) 
     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.application.ClientListener$6.operationComplete(***.java:514) 
     - locked <0x00007f089c372b60> (a com.application.ClientListener) 
     at org.jboss.netty.channel.DefaultChannelFuture.notifyListener(DefaultChannelFuture.java:381) 
     at org.jboss.netty.channel.DefaultChannelFuture.notifyListeners(DefaultChannelFuture.java:372) 
     at org.jboss.netty.channel.DefaultChannelFuture.setSuccess(DefaultChannelFuture.java:316) 
     at org.jboss.netty.channel.socket.nio.NioWorker$RegisterTask.run(NioWorker.java:776) 
     at org.jboss.netty.channel.socket.nio.NioWorker.processRegisterTaskQueue(NioWorker.java:257) 
     at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:199) 
     at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) 
     at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46) 
     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 
     at java.lang.Thread.run(Thread.java:745) 

    Locked ownable synchronizers: 
     - <0x00007f08a80fc118> (a java.util.concurrent.ThreadPoolExecutor$Worker)

看來，日誌記錄呼叫被封鎖試圖收購AsyncAppenderBase使用java.util.concurrent.ArrayBlockingQueue實例內部的鎖<0x00007f089c4a7e88> 。

在堆棧跟蹤，我可以看到鎖<0x00007f089c4a7e88>被另一個線程的線程池空閒舉行：

"dispatcher-3" #90 prio=5 os_prio=0 tid=0x00007f04d0004800 nid=0x29d2 waiting on condition [0x00007f0534ed3000] 
    java.lang.Thread.State: WAITING (parking) 
     at sun.misc.Unsafe.park(Native Method) 
     - parking to wait for <0x00007f089cbbaae8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) 
     at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) 
     at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081) 
     at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809) 
     at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) 
     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) 
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 
     at java.lang.Thread.run(Thread.java:745) 

    Locked ownable synchronizers: 
     - <0x00007f089c4a7e88> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

它看起來像ArrayBlockingQueue的內部鎖由該線程持有並隨後發佈未發佈。

這是怎麼回事？ java.util.concurrent.ArrayBlockingQueue的競賽條件？ Logback中的錯誤？

我正在使用Java 8u40和Logback 1.2.1。

來源

2017-06-13 glerup

你有沒有想過這個？你有沒有使用Spring Boot或JBoss？ –

你可以使用discardingThreshold「當阻塞隊列中有20％的產能剩餘，它將丟棄級別的跟蹤，調試和INFO的事件，保持水平的唯一事件WARN和ERROR」

樣品

<appender name="ASYNCFile" class="ch.qos.logback.classic.AsyncAppender"> 
     <queueSize>50</queueSize> 
     <discardingThreshold>2</discardingThreshold> 
     <appender-ref ref="fileAppender" /> 
    </appender>

來源

2017-11-01 03:58:37 Mohannad

Logback永久掛起

回答

相關問題