JPAを使用してMySQLデータベースに接続する簡単なコンソールアプリを作成しました。実際のデータの読み取り/書き込みは機能していますが、ロギングが台無しになっているようです。私が作成した各EntityManagerインスタンスは、独自のlog4jアペンダーをコンソールに追加しているようです。つまり、アプリには3つのEntityManagerインスタンスがあるので、必要な「実際の」コンソール出力行に加えて、コンソール出力に3つの追加行が表示されます。これが例です。最初の行は私の「実際の」アペンダーからのもので、他の3つはEntityManagerのアペンダーからのもののようです。
08:31:58,970 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:169 - geoEntityDao.getByCompositeKey took 81 milliseconds
0 [main] DEBUG foobar - geoEntityDao.getByCompositeKey took 81 milliseconds
0 [main] DEBUG foobar - geoEntityDao.getByCompositeKey took 81 milliseconds
0 [main] DEBUG foobar - geoEntityDao.getByCompositeKey took 81 milliseconds
これが私のlog4j構成です：
log4j.rootCategory=WARN, mylog
log4j.appender.mylog=org.apache.log4j.ConsoleAppender
log4j.appender.mylog.layout=org.apache.log4j.PatternLayout
log4j.appender.mylog.layout.ConversionPattern=%d{ABSOLUTE} %C %5p %t %c{2}:%L - %m%n
log4j.category.foobar=DEBUG
この動作をオフにして、必要なコンソール行を取得できるようにしたいと思います。私はそれを行う方法について「コードを解読する」ことができないようです-どんな助けもいただければ幸いです...
追加情報：ここでは2つのことが起こっているようです。1つ目は、log4jアペンダーの加算性設定です。これはデフォルトでtrueです。まばらなlog4jドキュメント（http://logging.apache.org/log4j/1.2/manual.html）を読み直して、私はこれに出くわしました：
特定のロガーに対して有効になっている各ロギング要求は、そのロガー内のすべてのアペンダーと、階層の上位にあるアペンダーに転送されます。
言及されていないのは、階層の上位のロガーの設定に関係なく、明らかにこれを実行するということです。
これが意味する、または私の場合は意味するように思われるのは、ルートロガーがWARNに設定されていても、HibernateクラスによってそれにアタッチされたアペンダーがまだDEBUGレベルのメッセージによって使用されていたということです。これは私が期待することの反対です。これがHibernate4.0.1JPA実装のバグなのか、log4j側のドキュメントの欠如なのか、log4jとslf4j（Hibernateで使用）間の不具合なのかはわかりません。
次に、EntityManagerオブジェクトを作成するたびに、log4jロギングツリーにアペンダーが追加されるように見えるため、複数のEntityManagerがある場合は、複数のロギングメッセージが表示されます。これは、Hibernateロギングのバグであると確信しています。
この「加法性」が実際にlog4jでどのように機能するかについての説明または例をまだ探しています。これは、限られたドキュメントから期待するものとは逆に機能しているようです。つまり、アペンダーは、ログイベントがUPに渡されるのではなく、ロギングツリーに渡されるように見えます。
これが私の（改訂された）log4jプロパティファイルについてこれまでに持っているものであり、それは機能しているように見えます：
log4j.rootCategory=WARN, mylog
# logger "root" logs at WARN level to appender "mylog"
log4j.appender.mylog=org.apache.log4j.ConsoleAppender
log4j.appender.mylog.layout=org.apache.log4j.PatternLayout
# Logger "foobar" logs at DEBUG level to appender "bootylog"
log4j.category.foobar=DEBUG, bootylog
log4j.appender.bootylog=org.apache.log4j.ConsoleAppender
log4j.appender.bootylog.layout=org.apache.log4j.PatternLayout
log4j.appender.bootylog.layout.ConversionPattern=%d{ABSOLUTE} %C %5p %t %c{2}:%L - %m%n
# additivity is off
log4j.additivity.foobar=false
log4j.additivity.org.hibernate=false
これにより、次の出力が得られます。これはまさに私が望むものです。
11:15:43,622 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:152 - geoDataItemDao.create took 5 milliseconds
11:15:43,624 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:166 - geoEntityDao.getByCompositeKey took 2 milliseconds
11:15:43,626 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:159 - dataEntityDao.getDataEntityByFieldCode took 1 milliseconds
最後に、log4jで問題が発生している場合は、アプリを実行するときにこのコマンドラインオプションをオンにすることを強くお勧めします。
-Dlog4j.debug