スポンサーサイト

上記の広告は1ヶ月以上更新のないブログに表示されています。
新しい記事を書く事で広告が消せます。

Spring MVC SLF4JとLogbackを使ってpatternタグを検証する

Spring MVCのロガーにSLF4JとLogbackが使われていることもあり、ログの出力パターンについて検証してみた。

◎動作検証にあたっての各バージョンは以下の通り
  • SpringFramework 3.2.3.RELEASE
  • Java 1.7
  • Tomcat 7.0

1.Mavenのpom.xml
STSで「Simple Spring Web Maven」を選択すると、デフォルトで以下の定義がされており、そのまま使用する。




org.slf4j
slf4j-api
${slf4j.version}
compile


ch.qos.logback
logback-classic
${logback.version}
runtime



2.Controllerにロガーを設定

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

@Controller
@RequestMapping("book")
public class BookController {

private static Logger logger = LoggerFactory.getLogger(BookController.class);

@Autowired
protected BookService bookService;

@RequestMapping(method = RequestMethod.GET)
public String index(BookForm form) {
logger.error("bookId: {}",form.getBookId());
logger.warn("bookName: {}",form.getBookName());
logger.info("price: {}",form.getPrice());
logger.debug("bookId: {}, bookName: {}",form.getBookId(), form.getBookName());
logger.trace("BookForm: {}",form.toString());
    return "newBook";
}

loggerはLoggerFactory#getLoggerメソッドより取得する。
ログレベルについては、レベルの高いものより順に記載している。「fatal」が用意されていない点がlog4jとは異なる。
また、ログメッセージの変数へのバインドは、{ }を使って行える。複数バインドさせる場合は、 logger.debugの例のように記載する。

3.logback.xmlの設定







true








%d{HH:mm:ss.SSS} %-10level %logger{32}#%M - %msg%n












デフォルトのpatternタグは「%-5level %logger{0} - %msg%n」となっていたが、検証用に「%d{HH:mm:ss.SSS} %-10level %logger{32}#%M - %msg%n」と変更した。

説明は以下の通り。
%d{HH:mm:ss.SSS}・・・予想がつくように、時:分:秒.ミリ秒である。
%-10level・・・「level」の頭に付いている「-」と数字であるが、「-」を付けると左揃えとなり、その後の数値は桁数を表す。サンプルでは「-10」としているので、ログレベルは左寄せで10桁となる。デフォルトの「5」はログレベルの最大文字数(error等)に合せていると推測できる。また、「-」がなければ右寄せとなる。
%logger{32}・・・BookControllerクラスのFQCNは「jp.co.sample.book.controller.BookController」となるが、文字数はドットも入れて、全部で43文字となる。デフォルトの「%logger{0}」の場合、「0」はクラス名「BookController」のみ出力するが、「1」以上の場合パッケージも含めて出力する。そのパッケージの出力形式が、各パッケージの先頭1文字をドットで繋げており、「jp.co.sample.book.controller.BookController」は最も省略した形式で「j.c.s.b.c.BookController」となる。そして{ }内の数値に応じて、「j.c.s.b.controller.BookController」、「j.c.s.book.controller.BookController」・・・「jp.co.sample.book.controller.BookController」と各パッケージが後ろから復元されていく形となる。この後ろからというのがポイントで、「32」は「jp.co.sample.book.controller.BookController」を後ろから文字を数えた結果、「controller」が復元できる文字数になく、「j.c.s.b.controller.BookController」で出力されることになる。
%M・・・メソッド名。
%msg・・・ログメッセージ(BookControllerのlogger.info他、引数の設定値)。
%n・・・改行。
その他変更点として、デフォルトのroot levelは「info」であるが、「trace」に変更して、すべてのログレベルを出力するようにしている。
実際に出力されたログは以下の通り。


23:35:06.944 ERROR j.c.s.b.c.BookController#index - bookId: null
23:35:06.944 WARN j.c.s.b.c.BookController#index - bookName: null
23:35:06.958 INFO j.c.s.b.c.BookController#index - price: null
23:35:06.958 DEBUG j.c.s.b.c.BookController#index - bookId: null, bookName: null
23:35:06.958 TRACE j.c.s.b.c.BookController#index - BookForm: jp.co.sample.book.form.BookForm@141d983

せっかくなので、もう1パターン実行してみる。

4.logback.xmlのpatternタグ内を変更


(変更前)%d{HH:mm:ss.SSS} %-10level %logger{32}#%M - %msg%n

(変更後)%d{HH:mm:ss.SSS} %10level %logger{33}#%M - %msg%n

実際に出力されたログは以下の通り。

23:39:20.930 ERROR j.c.s.b.controller.BookController#index - bookId: null
23:39:20.930 WARN j.c.s.b.controller.BookController#index - bookName: null
23:39:20.934 INFO j.c.s.b.controller.BookController#index - price: null
23:39:20.934 DEBUG j.c.s.b.controller.BookController#index - bookId: null, bookName: null
23:39:20.934 TRACE j.c.s.b.controller.BookController#index - BookForm: jp.co.sample.book.form.BookForm@7a7759

「-」を削除したことにより、ログレベルが右寄せとなった。
また、「%logger{33}」にしたことにより、「controller」パッケージが復元され、「j.c.s.b.controller.BookController」と出力された。文字数を数えると33文字で、「controller」パッケージを出力するためには33文字必要なことが分かる。

数字は何を表しているのか、知っていないと分かりづらいですね。

■過去のSpring関連記事
Spring関連記事 Index

スポンサーサイト

コメントの投稿

非公開コメント

プロフィール

bookmount8

Author:bookmount8
システムエンジニア。サーバーサイドでjavaを扱うことが多い。最近は、ミドルやフロント周りも関心あり。

最新記事
カテゴリ
検索フォーム
最新コメント
月別アーカイブ
これまでの訪問者数
ブロとも申請フォーム

この人とブロともになる

RSSリンクの表示
上記広告は1ヶ月以上更新のないブログに表示されています。新しい記事を書くことで広告を消せます。