Contents
どのロギングライブラリを使うか?
- Logback(SLF4J + Logback)
- Log4j2
がSpringBootでは選択できる。
SpringBootではLombokの@Logというアノテーションを付与することで、自動でフィールド logが生成されて、各層で使えます。
ところが、@Log関係のアノテーションは複数あるため、どれを使うか迷ってしまいます。
ログのレベルはどれを使うか?
現場で使用されるログレベル
現場で見るログレベルは下記3つ。
INFO | |
WARN | |
ERROR |
実際には、エラーログが出ていても垂れ流してることが多い。
ERRORは必ず何らかの処理が必要なもの。
- ログは少ない方が良い。
- 多いと見なくなる
- 本当に重要なログがどれか分かりにくくなる
- ログを出して知りたいことを明確にしておく
- ログに関する設計をしておく
- とりあえず出すはNG
- ログ出力は多少の時間がかかる
- ログを出しすぎるとレスポンスが遅くなることに留意
SpringBootでログレベルを設定するには?
ログレベルはapplication.yml(or .properties)で設定する。
# ログ設定
logging:
level:
root: WARN # INFO/WARN/ERROR
WARNレベルを設定した場合、WARN以上のログのみ出力する。つまり、INFOは出力されない。
@Controller
@Log4j2
public class ChildrenController {
@RequestMapping("/children")
public String index(Model model) { ;
logger.info("あああ");
logger.warn("いいい");
logger.error("ううう");
...
このようなコントローラーを作成し、アクセスした場合に出力されるログは次の通り。
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.6.3)
2022-02-23 08:17:40.128 WARN 1 --- [nio-8080-exec-1] c.s.o.p.children.ChildrenController : いいい
2022-02-23 08:17:40.131 ERROR 1 --- [nio-8080-exec-1] c.s.o.p.children.ChildrenController : ううう
次のようなSpring Bootの開始メッセージもINFOのため、出力されていないことがわかる。
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.6.3)
2022-02-23 08:22:13.963 INFO 1 --- [ main] c.s.o.OkozukaiSystemApplication : Starting OkozukaiSystemApplication using Java 11.0.14.1 on f7c372df0f97 with PID 1 (/okozukai-system.jar started by root in /)
2022-02-23 08:22:13.968 INFO 1 --- [ main] c.s.o.OkozukaiSystemApplication : No active profile set, falling back to default profiles: default
2022-02-23 08:22:15.118 INFO 1 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2022-02-23 08:22:15.122 INFO 1 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Redis repositories in DEFAULT mode.
2022-02-23 08:22:15.168 INFO 1 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 5 ms. Found 0 Redis repository interfaces.
2022-02-23 08:22:16.021 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2022-02-23 08:22:16.039 INFO 1 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2022-02-23 08:22:16.039 INFO 1 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.56]
2022-02-23 08:22:16.106 INFO 1 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2022-02-23 08:22:16.106 INFO 1 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2068 ms
2022-02-23 08:22:17.036 INFO 1 --- [ main] o.s.b.a.w.s.WelcomePageHandlerMapping : Adding welcome page template: index
2022-02-23 08:22:17.540 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2022-02-23 08:22:18.109 INFO 1 --- [ main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing
2022-02-23 08:22:18.116 INFO 1 --- [ main] c.s.o.OkozukaiSystemApplication : Started OkozukaiSystemApplication in 4.73 seconds (JVM running for 5.573)
このことから、通常、運用する場合はINFOで運用するのが良いだろう。
ログ出力のサンプルコード
Lombokを入れてない場合
Lombokを入れてない場合は、 LoggerFactoryからロガーを取得して使いましょう。
サンプルコード
検証のために、LoggerFactory#getLogger
の引数を変えたロガーを作っておきます。
@Controller
public class ChildrenController {
Logger logger = LoggerFactory.getLogger(this.getClass());
Logger loggerHoge = LoggerFactory.getLogger("hoge");
@RequestMapping("/children")
public String index(Model model) { ;
logger.info("あああ");
logger.warn("いいい");
logger.error("ううう");
loggerHoge.info("えええ");
loggerHoge.warn("おおお");
loggerHoge.error("あああ");
...
}
...
}
結果
2022-02-23 01:32:18.652 INFO 1 --- [nio-8080-exec-1] c.s.o.p.children.ChildrenController : あああ
2022-02-23 01:32:18.653 WARN 1 --- [nio-8080-exec-1] c.s.o.p.children.ChildrenController : いいい
2022-02-23 01:32:18.653 ERROR 1 --- [nio-8080-exec-1] c.s.o.p.children.ChildrenController : ううう
2022-02-23 01:32:18.653 INFO 1 --- [nio-8080-exec-1] hoge : えええ
2022-02-23 01:32:18.653 WARN 1 --- [nio-8080-exec-1] hoge : おおお
2022-02-23 01:32:18.653 ERROR 1 --- [nio-8080-exec-1] hoge : あああ
このように、LoggerFactory#getLogger
の引数は誰が出力したログかを表すものなので、ちゃんとthis.getCalss()
または XXX.class
の要領で指定する必要がありますね。
Lombokの@Log4j2を使う例(オススメ)
Lombokを入れてる場合は、@Log4j2
を使うとコードが減るのでオススメです。
サンプルコード
@Controller
@Log4j2
public class ChildrenController {
@RequestMapping("/children")
public String index(Model model) {
log.info("Log4j2 log.info");
log.warn("Log4j2 log.warn");
log.error("Log4j2 log.error");
}
}
結果
2022-02-23 00:56:25.689 INFO 1 --- [nio-8080-exec-2] c.s.o.p.children.ChildrenController : Log4j2 log.info
2022-02-23 00:56:25.690 WARN 1 --- [nio-8080-exec-2] c.s.o.p.children.ChildrenController : Log4j2 log.warn
2022-02-23 00:56:25.691 ERROR 1 --- [nio-8080-exec-2] c.s.o.p.children.ChildrenController : Log4j2 log.error
クラス名までちゃんと出ています。
SpringBootのログの見方・意味
2022-02-23 00:56:25.689 INFO 12345 --- [nio-8080-exec-2] c.s.o.p.children.ChildrenController : Log4j2 log.info
上記、ログの一行の意味を示す。
2022-02-23 00:56:25.689 | ログが出力された日時 |
INFO | ログレベル |
12345 | プロセスID |
--- | 単なるセパレータ |
[nio-8080-exec-2] | スレッド名 |
c.s.o.p.children.ChildrenController | ロガー名(通常、ソースクラス) |
Log4j2 log.info | ログの内容(任意の文字列) |
ログをファイルに出力するには?
SpringBootではデフォルトではログを標準出力(コンソール)に出力する。
ファイルに吐き出すには設定を加える必要があります。