Dropwizard Logback asynchrone Log-Rotation verursacht Anwendung Threads zu warten

Question

Die Anwendung Threads stecken bleiben, wenn die Protokolldatei rotiert, verursacht Spitze in Latenz der API Ich bin mit einem Async Appender, nicht sicher, warum während der Rotation der Anwendung Threads sind warten.

logback.xml

<configuration debug="true"> 
<property name="async.discardingThreshold" value="0"/> 
<property name="async.queueSize" value="500"/> 
<property name="log.dir" value="/var/log"/> 
<property name="log.pattern" value="%highlight(%-5level) [%date] [%thread] [%X{id}] [%cyan(%logger{0})]: %message%n"/> 
<property name="errorLog.pattern" value="%highlight(%-5level) [%date] [%thread] [%X{id}] [%red(%logger{0})]: %message%n"/> 
<property name="log.maxHistory" value="200"/> 
<property name="log.default.maxFileSize" value="100MB"/> 
<property name="log.error.maxFileSize" value="10MB"/> 


<appender name="INFO" class="ch.qos.logback.core.rolling.RollingFileAppender"> 
    <File>${log.dir}/default.log</File> 
    <Append>true</Append> 
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy"> 
     <fileNamePattern>${log.dir}/default.%i.log.gz</fileNamePattern> 
     <maxIndex>${log.maxHistory}</maxIndex> 
    </rollingPolicy> 
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy"> 
     <maxFileSize>${log.default.maxFileSize}</maxFileSize> 
    </triggeringPolicy> 
    <encoder> 
     <pattern>%replace(${log.pattern}){'"pin":"\d+"','"pin":"XXXX"'}%n</pattern> 
    </encoder> 
</appender> 

<appender name="ASYNC-INFO" class="ch.qos.logback.classic.AsyncAppender"> 
    <discardingThreshold>${async.discardingThreshold}</discardingThreshold> 
    <queueSize>${async.queueSize}</queueSize> 
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> 
     <OnMismatch>DENY</OnMismatch> 
     <OnMatch>NEUTRAL</OnMatch> 
    </filter> 
    <appender-ref ref="INFO"/> 
</appender> 

<appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender"> 
    <file>${log.dir}/error.log</file> 
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy"> 
     <fileNamePattern>${log.dir}/error.%i.log.gz</fileNamePattern> 
     <maxIndex>${log.maxHistory}</maxIndex> 
    </rollingPolicy> 
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy"> 
     <maxFileSize>${log.error.maxFileSize}</maxFileSize> 
    </triggeringPolicy> 
    <encoder> 
     <pattern>%replace(${errorLog.pattern}){'"pin":"\d+"','"pin":"XXXX"'}%n</pattern> 
    </encoder> 
</appender> 

<appender name="ASYNC-ERROR" class="ch.qos.logback.classic.AsyncAppender"> 
    <discardingThreshold>${async.discardingThreshold}</discardingThreshold> 
    <queueSize>${async.queueSize}</queueSize> 
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> 
     <level>ERROR</level> 
    </filter> 

    <appender-ref ref="ERROR"/> 
</appender> 


<root level="INFO"> 
    <appender-ref ref="ASYNC-ERROR"/> 
    <appender-ref ref="ASYNC-INFO"/> 
</root> 

Answer 1

In unserem logback.xml wir angegeben haben,

<property name="async.discardingThreshold" value="0"/> 

Nun ein kurzer Blick auf den Quellcode schlägt vor, was möglicherweise passieren könnte, dass ist verursacht die Verzögerung zum Zeitpunkt der Drehung

@Override 
    protected void append(E eventObject) { 
    if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) { 
     return; 
    } 
    preprocess(eventObject); 
    put(eventObject); 
    } 
    private boolean isQueueBelowDiscardingThreshold() { 
    return (blockingQueue.remainingCapacity() < discardingThreshold); 
    } 

blockingQueue.remainingCapacity() < discardingThreshold, diese Bedingung wird niemals als wahr ausgewertet, wenn der Verwerfungsschwellenwert 0 ist, was bedeutet, dass der async-appender-Thread versucht, in eine bereits vollständige blockierende Warteschlange zu pushen warte darauf, dass der Anwendungsthread ebenfalls wartet. Wenn Sie diesen Wert auf einen Wert über 0 setzen, treten keine Timeouts auf, jedoch können einige Ereignisse verloren gehen. Die andere Option, alle Ereignisse ohne Verwerfen zu behalten, wäre, die Warteschlangengröße so weit zu erhöhen, dass zum Zeitpunkt der Dateirotation nicht mehr als die Größe des Warteschlangenelements in der Warteschlange ist. In diesem Fall wartet der async-appender-Thread nicht auf die blockierende Warteschlange.

So ist meine Erkenntnis logback AsyncAppender ist nicht so Async wenn Nachricht eingehende Rate die Rate und die Rate ist 0.

Verwerfen Warteschlange Verbrauch überschreitet