Ich habe ein Testprogramm geschrieben, um die Leistungsverbesserungen von logback über log4j zu überprüfen. Aber zu meiner Überraschung stieß ich auf dieses seltsame Problem. Ich schreibe einige 200k Protokollnachrichten in einer Schleife in eine Datei unter Verwendung ihrer asynchronen und Dateianhänge. Aber jedes Mal werden nur etwa 140.000 Nachrichten protokolliert und danach gestoppt. Es gibt nur meine letzte Protokollanweisung aus, die angibt, dass alles in den Puffer geschrieben wurde und das Programm beendet wird. Wenn ich nur das gleiche Programm mit Log4j laufen lasse, kann ich alle 200k Meldungen in der Protokolldatei sehen. Gibt es grundlegende architektonische Unterschiede, die dies bewirken? Gibt es sowieso, um das zu vermeiden? Wir überlegen, von log4j zu logback zu wechseln, und das bringt mich nun zum Nachdenken.

Das ist meine Logback Konfiguration:

<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
        </pattern>
    </encoder>
</appender>

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>logback.log</file>
<encoder>
  <pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
</encoder>
 </appender>

<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="FILE" />
</appender>

<root level="info">
    <appender-ref ref="ASYNC" />
</root>
 </configuration>

Das ist mein Code ------------------

      public static void main(String[] args) throws InterruptedException {
        org.slf4j.Logger logbackLogger = LoggerFactory
                .getLogger(LogbackTest.class);

        List<Integer> runs = Arrays.asList(1000, 5000, 50000, 200000);
        ArrayList<Long> logbackRuntimes = new ArrayList<>(4);

        for (int run = 0; run < runs.size(); run++) {
            logbackLogger.info("------------------------>Starting run: "
                    + (run + 1));
            // logback test
            long stTime = System.nanoTime();
            int i = 0;
            for (i = 1; i <= runs.get(run); i++) {
                Thread.sleep(1);
                logbackLogger
                .info("This is a Logback test log, run: {},     iter: {}",
                                run, i);
            }
            logbackRuntimes.add(System.nanoTime() - stTime);
            logbackLogger.info("logback run - " + (run + 1) + " " + i);
        }
        Thread.sleep(5000);
        // print results
        logbackLogger.info("Run times:");
        logbackLogger
            .info("Run\tNoOfMessages\tLog4j Time(ms)\tLogback Time(ms)");
        for (int run = 0; run < runs.size(); run++) {
            logbackLogger.info((run + 1) + "\t" + runs.get(run) + "\t"
                    + logbackRuntimes.get(run) / 10e6d);
        }
    }