8

最初にいくつかの背景。DOSバッチスクリプトからバッチタイプのJavaプロセスを実行しています。すべてのJavaログはstdoutに送られ、バッチスクリプトはstdoutをファイルにリダイレクトします。（スクリプトからECHOを実行でき、ログファイルに格納されるため、これは私にとっては良いことです。したがって、デバッグに最適なすべてのjava JVMコマンドライン引数を確認できます。）

私はslf4jAPIを使用しており、バックエンドにはlog4jを使用していましたが、最近logback-classicに切り替えました。

私のアプリケーションコードはすべてslf4jを使用していますが、stdoutにも書き込まれる独自のロギング（標準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をログバックエンドとして使用しても問題は発生しなかったようです。したがって、ログバックは別のことをしている必要があります。

問題は、同期されているものの、呼び出された唯一の書き込みメソッドPrintStream.write(byte buf[], int off, int len)であることがわかります。ch.qos.logback.core.joran.spi.ConsoleTarget that System.out.write(int b)

したがって、各バイトを出力するログバックの間に、サードパーティライブラリは文字列全体をstdoutに書き込むことができます。（これは私に問題を引き起こすだけでなく、少し非効率的であるに違いありませんか？）

他の書き込みメソッドを実装するようにコードを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>

私はJava1.6.0_07でlogback0.9.20を使用しています。

4

3 に答える 3

2

結局、根本的な問題を修正することは、どの回避策よりも簡単でした。

修正パッチ: http://gist.github.com/434516

logback jira でのバグの発生: http://jira.qos.ch/browse/LBCORE-158

于 2010-06-11T14:22:59.680 に答える
2

そのような場合、動作しない特定のサードパーティ ライブラリに対して System.setOut(PrintStream out) を実行します。このログ ストリームを読み取るスレッドを実装し、それを改行で分割して、使用するロギング ソリューションに吐き出します。同じスレッドに対して読み取りと書き込みを開始しないように注意してください :-) これがあなたがすることです:

  • System.out ストリームを取得し、それを脇に保存します
  • このストリームを使用するようにロガーを構成します。OutputStreamAppender を参照してください。
  • 新しい System.out として割り当てるストリームを排出するスレッドを作成し (サードパーティのライブラリがそこに書き込みます)、適切にフォーマットされた出力をログに送信します。

システムで起こっていることと多かれ少なかれ同期しているきれいなログを取得しました

于 2010-06-06T22:54:59.733 に答える
0

に書き込む2つの異なるログ構成があるようですSTDOUT。混乱をデコードしようとすると、これら2つのパターンは大きく異なるようです。

2010-05-28 18: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
05/28/10 18:02:20.236 INFO: [ServiceEvent] SubmittedTask:BC-STRESS_04_FZBC-2010-05-21-545024448189310126-23

2行目は、定義の代わりにデフォルトのパターンを使用しているようです。XML構成の代わりにデフォルト構成を使用するロガーがどこかにロードされていますか？

于 2010-06-06T12:41:32.460 に答える