Сначала немного предыстории. У меня есть процесс java пакетного типа, запущенный из пакетного сценария DOS. Все журналы Java отправляются на стандартный вывод, а пакетный скрипт перенаправляет стандартный вывод в файл. (Это хорошо для меня, потому что я могу ЭХО из сценария, и он попадает в файл журнала, поэтому я могу видеть все аргументы командной строки java JVM, что отлично подходит для отладки.) Я не могу
Я использую slf4j API, а для бэкенда раньше использовал log4j, но недавно перешел на logback-classic.
Хотя весь код моего приложения использует slf4j, у меня есть сторонняя библиотека, которая ведет собственный журнал (без использования стандартного API), который также записывается в стандартный вывод.
Проблема в том, что иногда строки журнала смешиваются и не отображаются четко на отдельных строках. Вот пример некоторого испорченного вывода:
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
Теперь, сравнивая старые файлы журналов, кажется, что проблема не возникала при использовании log4j в качестве серверной части ведения журнала. Поэтому logback должен делать что-то другое.
Кажется, проблема в том, что хотя PrintStream.write(byte buf[], int off, int len)
синхронизирован, однако я вижу, что в ch.qos.logback.core.joran.spi.ConsoleTarget that System.out.write(int b)
вызывается единственный метод записи.
Таким образом, между выводом каждого байта из журнала сторонней библиотеке удается записать целую строку в стандартный вывод. (Это не только вызывает у меня проблемы, но и должно быть немного неэффективно?)
Есть ли какое-либо другое решение этой проблемы чередования, кроме исправления кода для ConsoleTarget, чтобы он реализовывал другие методы записи? Любая хорошая работа вокруг. Или я должен просто отправить отчет об ошибке?
Вот мой 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>
Я использую logback 0.9.20 с java 1.6.0_07.