Zuerst etwas Hintergrund. Ich habe einen Batch-Java-Prozess von einem DOS-Batch-Skript ausgeführt. Die gesamte Java-Protokollierung wird auf "stdout" gesetzt und das Stapel-Skript leitet die stdout-Datei in eine Datei um. (Dies ist gut für mich, weil ich ECHO aus dem Skript kann und es in die Protokolldatei, so dass ich alle Java JVM Befehlszeilenargumente sehen kann, die für das Debuggen ist.) Ich kann nichtLog-back und ThirdParty Schreiben auf stdout. Wie man sie stoppt, verschachtelt zu erhalten
Ich benutze slf4j API, und für das Backend verwendete ich log4j, aber vor kurzem zu Logback-Classic gewechselt.
Obwohl alle meine Anwendung Code slf4j verwendet, habe ich eine Drittanbieter-Bibliothek, die ihre eigene Protokollierung (nicht mit einer Standard-API), die auch in stdout geschrieben wird.
Das Problem ist, dass manchmal Protokollzeilen durcheinander geraten und nicht sauber in separaten Zeilen angezeigt werden. Hier ist ein Beispiel von etwas verkorksten Ausgabe:
2010-05-28 18:00:44.783 [thread-1 ] INFO CreditCorrelationElementBuilderImpl - Bump parameters exist for scenario, now attempting bumping. [indexDisplayName=STANDARD_S1_v300]
2010-05-28 18:01:43.517 [thread-1 ] INFO CreditCorrelationElementBuilderImpl - Found adjusted point in data, now applying bump. [point=0.144040000000000]
2010-05-28 18:01:58.642 [thread-1 ] DEBUG com.company.request.Request - Generated request for [dealName=XXX_20050225_01[5],dealType=GENERIC_XXX,correlationType=2,copulaType=1] in 73.8 s, Simon Stopwatch: [sys1.batchpricer.reqgen.gen INHERIT] total 1049 s, counter 24, max 74.1 s, min 212 ms
2010-05-28 18:05/28/10 18:02:20.236 INFO: [ServiceEvent] SubmittedTask:BC-STRESS_04_FZBC-2010-05-21-545024448189310126-23
01:58.658 [req-writer-2b ] INFO .c.g.r.o.OptionalFileDocumentOutput - Writing request XML to \\filserver\dir\file1.xml - write time: 21.4 ms - Simon Stopwatch: [sys1.batchpricer.reqgen.writeinputfile INHERIT] total 905 ms, counter 24, max 109 ms, min 10.8 ms
2010-05-28 18:02:33.626 [ResponseCallbacks-1: DriverJobSpace$TakeJobRunner$1] ERROR c.c.s.s.D.CalculatorCallback - Id:23 no deal found !!
2010-0505/28/10 18:02:50.267 INFO: [ServiceEvent] CompletedTask:BC-STRESS_04_FZBC-2010-05-21-545024448189310126-23:Total:24
Nun zurück zu älteren Protokolldateien zu vergleichen, wie es scheint das Problem nicht auftreten, wenn log4j als Logging-Backend verwenden. Logback muss also etwas anderes machen.
Das Problem scheint zu sein, dass zwar PrintStream.write(byte buf[], int off, int len) synchronisiert ist, aber ich kann in ch.qos.logback.core.joran.spi.ConsoleTarget that System.out.write(int b) sehen ist die einzige Schreibmethode genannt.
Da zwischen logback Logging jedes Byte ausgibt, verwaltet die ThirdParty-Bibliothek eine ganze Zeichenfolge in den Stdout. (Das ist nicht nur ein Problem, sondern auch ein wenig ineffizient?)
Gibt es eine andere Lösung für dieses Interleaving-Problem, als den Code an ConsoleTarget zu patchen, damit er die anderen Schreibmethoden unterstützt? Irgendwelche netten Arbeitsumgebungen. Oder sollte ich einfach einen Fehlerbericht einreichen?
Hier ist meine logback.xml:
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%-16thread] %-5level %-35.35logger{30} - %msg%n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="STDOUT" />
</root>
</configuration>
Ich verwende logback 0.9.20 mit Java 1.6.0_07.
Hmm, kommen meine vorformatierte Codeblöcke als eine Zeile durch, waren aber in der Vorschau in Ordnung! Hump! –
David, Sie können diese Frage erneut bearbeiten, verwenden Sie wörtlich, wenn Sie müssen. –
Haben Sie eine Referenz oder ein Beispiel im Verbatim? Meinst du einen Nicht-Code-Block? –