LogbackのAsyncAppenderがクラッシュしたときにキューに入れられたメッセージはどうなりますか？

Question

LogbackのAsyncAppenderを使用している場合、メッセージはそれらが が彼らの最終目的地（Appender これに応じて、あなたがAsyncAppenderで包まれた）に書き込まれる前に、キューに入れられます。ここまでは順調ですね。

私のプログラムまたはログバック自体がクラッシュしたときに、それらのキューに入れられたメッセージが失われる可能性はありますか？

Answer 1

はい、JVMがクラッシュしたり、通常のプログラムがシャットダウンしても、キューに入れられたメッセージは失われると思います。

AsyncAppenderを使用した場合、どれくらいの時間が改善されているか調査していました。

サンプルlogback.xml：
私は、通常のFILE_LOGとASYNC_FILE_LOGを持っています。

import java.util.concurrent.CountDownLatch; 
import org.slf4j.Logger; 
import org.slf4j.LoggerFactory; 

public class MultiThreadsExecutor { 
    private static final Logger asyncLOGGER = LoggerFactory.getLogger("ASYNC_FILE_LOG"); 
    private static final Logger normaLOGGER = LoggerFactory.getLogger("FILE_LOG"); 
    static CountDownLatch latch = null; // Java7 feature to ensure all threads ended execution. 

    public MultiThreadsExecutor() { 
    } 

    public void someMethod(String who, String loggerName) { 
     Thread backgroundThread = new Thread(new Runnable() { 
      public void run() { 
       getLogger(loggerName).warn(Thread.currentThread().getName() +": is Running in the background"); 
       for (int i=0; i<100; i++) { 
        getLogger(loggerName).info(Thread.currentThread().getName() +" counting: " + i); 
       } 
       latch.countDown(); 
      } 
     },"Background " + who + " Thread"); 
     backgroundThread.start(); 
    } 

    private Logger getLogger(String name) { 
     if (name.equals("ASYNC_FILE_LOG")) { 
      return asyncLOGGER; 
     } else if (name.equals("FILE_LOG")) { 
      return normaLOGGER; 
     } else { 
      System.out.println("Logger Undefined"); 
      return null; 
     } 
    } 

    public static void main(String[] args) { 
     long start; 
     MultiThreadsExecutor mte = new MultiThreadsExecutor(); 

     latch = new CountDownLatch(10); 
     start = System.currentTimeMillis(); 
     for (int i=0; i<10; i++) { 
      mte.someMethod(Integer.toString(i)," FILE_LOG"); 
     } 
     try { 
      latch.await(); 
      System.out.println("FILE_LOG ended - " + (System.currentTimeMillis() - start)); 
     } catch (InterruptedException e) { 
      e.printStackTrace(); 
     } 

     latch = new CountDownLatch(10); 
     start = System.currentTimeMillis(); 
     for (int i=0; i<10; i++) { 
      mte.someMethod(Integer.toString(i)," ASYNC_FILE_LOG"); 
     } 
     try { 
      latch.await(); 
      System.out.println("ASYNC_FILE_LOG ended - " + (System.currentTimeMillis() - start)); 
     } catch (InterruptedException e) { 
      e.printStackTrace(); 
     } 

     // Remove below to enable Testcase(2) 
     // try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } 
     System.out.println("END"); 
    } 
} 

テストケース（1）通常の実行：

<appender name="FILE0" class="ch.qos.logback.core.rolling.RollingFileAppender"> 
    <file>./file.log</file> 
    ... (not relevant) 
</appender> 

<appender name="FILE1" class="ch.qos.logback.core.rolling.RollingFileAppender"> 
    <file>./async_file.log</file> 
    ... (not relevant) 
</appender> 
<appender name="ASYNC_FILE1" class="ch.qos.logback.classic.AsyncAppender"> 
    <appender-ref ref="FILE1" /> 
    <discardingThreshold>0</discardingThreshold> 
</appender> 

<logger name="FILE_LOG" additivity="false"> 
    <appender-ref ref="FILE0" /> 
</logger> 

<logger name="ASYNC_FILE_LOG" additivity="false"> 
    <appender-ref ref="ASYNC_FILE1" /> 
</logger> 

サンプルMultiThreadsExecutorテスタープログラムは、それがログメッセージの1010行を生成する必要があります。

はFILE_LOGは終了 - 46
ASYNC_FILE_LOGは終了 - 16
END

ASYNC_FILE_LOGは確かにはるかに高速です。

line1 Background 1 Thread: is Running in the background 
line2 Background 3 Thread: is Running in the background 
line3 Background 6 Thread: is Running in the background 
line4 Background 8 Thread: is Running in the background 
... 
line1009 Background 0 Thread counting: 99 
line1010 Background 8 Thread counting: 99 

Async_File.logはメッセージのみを800+まで記録されます。しかし...

File.logは正しくメッセージの1010行を記録しました！

line1 Background 0 Thread: is Running in the background 
line2 Background 1 Thread: is Running in the background 
line3 Background 1 Thread counting: 0 
line4 Background 1 Thread counting: 1 
line5 Background 1 Thread counting: 2 
.... 
line811 Background 2 Thread counting: 95 
line812 Background 4 Thread counting: 66 
line813 Background 8 Thread counting: 46 

テストケースは、（2）、テスターは...キューをクリアするための時間が必要AsyncAppender場合にはENDの前に1秒を眠る

FILE_LOGは終了 - 47
ASYNC_FILE_LOGは終了 - 16
END

ASYNC_FILE_LOGはまだまだ高速です。今回は、ASYNC_FILE_LOGが1010行を正しく記録しました。

line1 Background 0 Thread: is Running in the background 
line2 Background 2 Thread: is Running in the background 
line3 Background 2 Thread counting: 0 
line4 Background 2 Thread counting: 1 
line5 Background 2 Thread counting: 2 
.... 
line1008 Background 5 Thread counting: 97 
line1009 Background 5 Thread counting: 98 
line1010 Background 5 Thread counting: 99 

結論は

上記のテスト時に、Javaプログラムのシャットダウン、AsyncAppenderがキューのログをクリアするのに十分な時間を持っていない、ということを証明しています。 JVMのクラッシュはもちろんのこと、Javaプログラムの終了は即時です。