SpringBootのログ出力プラクティス
SpringBootはお手軽にWebアプリケーションを作成できる反面、カスタマイズしたい場合にAutoConfigurationやConfigurationPropertiesの仕組みを理解していないと、各種設定がデフォルト値で隠ぺいされているため、やりたいことを実現するのに手間取る場合があります。
起動ログの抑止
SpringBootをrunすると出力される例のアレです。本番環境で起動時毎回出ると考えると出力抑止したいですよね。
logging.level.root=WARNとかにすればそりゃ消えるんですが、正規のプロパティで消せるものなら消したい。
で、調べたところspring.main.log-startup-info=offを使うらしいが消えてくれないので検証してみました。
検証バージョン
- SpringBoot 2.4.9
spring-boot-starter-actuatorspring-boot-starter-validationspring-boot-starter-webmybatis-spring-boot-starter
初めにpropertiesとyml論争
好みの問題なので正直どちらでもよいと思ってますが、コンテナ実行環境においてはymlを使うケースが多くなってきていると感じていますので私はyml派です。
本文中はxxx.yyy.zzzの表記をしますがサンプルはymlなので適宜読み替えてください。
ただし、公式ドキュメントではアプリケーション内で統一すべしとあるので、ライブラリによってpropertiesでかかなければいけない設定などがある場合はpropertiesを選択しましょう。
設定値
出力されるログについて、順番に見ていきます。
spring.main.banner-mode
default: console
offにすると、\デェェェェン/と偉そうに出てくる以下バナーが消えます。
spring:
main:
banner-mode: off
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.4.9)
外部ファイルを読み込むことができたり、意外と設定が豊富で、twitterで本番環境でうちはこんなバナー出してるぜ!っていうイカしたバナーを見かけたことがあるので個人開発するときには将来面白いのに置き換えてみたい。
今回は抑止が目的なのでoffります。
少し古い記事だと、spring.main.show-bannerの記載がありますが、SpringBoot1.3から非推奨となっています。
spring.main.log-startup-info
default: console
falseにします。
このプロパティで抑止できるのは 起動エントリーポイントであるSpringApplicationにより出力されるログのみ です。
各種starterのdependency追加によりAutoConfigされて引き込まれた設定たちはこの設定により出力抑止されません。
spring:
main:
log-startup-info: false
[NEW!抑止対象]> 2021-07-27 16:14:56.376 INFO 17768 --- [ main] com.example.demo.DemoApplication : Starting DemoApplication using Java 11.0.5 on kuma with PID 17768 (C:\workspace\demo\target\classes started by kuma in C:\workspace\demo)
[NEW!抑止対象]> 2021-07-27 16:14:56.380 INFO 17768 --- [ main] com.example.demo.DemoApplication : No active profile set, falling back to default profiles: default
2021-07-27 16:14:57.291 WARN 17768 --- [ main] o.m.s.mapper.ClassPathMapperScanner : No MyBatis mapper was found in '[com.example.demo]' package. Please check your configuration.
2021-07-27 16:14:57.669 INFO 17768 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2021-07-27 16:14:57.697 INFO 17768 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2021-07-27 16:14:57.697 INFO 17768 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.50]
2021-07-27 16:14:57.820 INFO 17768 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2021-07-27 16:14:57.821 INFO 17768 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1366 ms
2021-07-27 16:14:58.652 INFO 17768 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 2 endpoint(s) beneath base path '/actuator'
2021-07-27 16:14:58.713 INFO 17768 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
[NEW!抑止対象]> 2021-07-27 16:14:58.737 INFO 17768 --- [ main] com.example.demo.DemoApplication : Started DemoApplication in 2.796 seconds (JVM running for 3.582)
2021-07-27 16:14:59.058 INFO 17768 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-07-27 16:14:59.058 INFO 17768 --- [ main] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2021-07-27 16:14:59.060 INFO 17768 --- [ main] o.s.web.servlet.DispatcherServlet : Completed initialization in 2 ms
2021-07-27 16:14:59.075 INFO 17768 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2021-07-27 16:14:59.250 INFO 17768 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
logging.group
個別にパッケージ名を設定しなくても良いように、ロググループという機能が用意されています。
デフォルトで利用できる1のはlogging.level.webとlogging.level.sqlです。
-
TomcatWebServerもwebっぽく見えますが、FQCNはorg.springframework.boot.web.embedded.tomcat.TomcatWebServerであり残念ながらlogging.level.webのグループには含まれていません。
| Name | Loggers |
|---|---|
web |
org.springframework.core.codec, org.springframework.http, org.springframework.web, org.springframework.boot.actuate.endpoint.web, org.springframework.boot.web.servlet.ServletContextInitializerBeans
|
sql |
org.springframework.jdbc.core, org.hibernate.SQL, org.jooq.tools.LoggerListener
|
公式ドキュメントにはtomcatの例が載っているのでありがたく使いましょう。
logging:
group:
# tomcat: "org.apache.catalina,org.apache.coyote,org.apache.tomcat"
tomcat:
- org.apache.catalina
- org.apache.coyote
- org.apache.tomcat
- org.springframework.boot.web.embedded.tomcat
公式ドキュメントでは、カンマ区切り、ダブルクォーテーションで定義していますがymlなので配列表記にしました。
まとめ
ここまでの設定を取り込んだファイルは以下となります。
spring:
main:
banner-mode: off
log-startup-info: false
logging:
group:
tomcat:
- org.apache.catalina
- org.apache.coyote
- org.apache.tomcat
- org.springframework.boot.web.embedded.tomcat
level:
web: WARN
tomcat: WARN
2021-07-27 22:35:13.846 WARN 18224 --- [ main] o.m.s.mapper.ClassPathMapperScanner : No MyBatis mapper was found in '[com.example.demo]' package. Please check your configuration.
2021-07-27 22:35:14.267 INFO 18224 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1124 ms
2021-07-27 22:35:15.300 INFO 18224 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2021-07-27 22:35:15.412 INFO 18224 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
大分スッキリしました。
-
ClassPathMapperScannerのWARNログは@MapperやMybatisの定義ファイルがないだけなので割愛。 -
org.springframework.boot.web.servlet.context.ServletWebServerApplicationContextだけは個別に設定しないといけないようです。。 - DataSourceは今度追記するかも。
Appendix
ログ定義ファイル
ログ出力内容をデフォルトから変更したい場合(Trace-IdやX-Forward-ForのIPアドレスを出力したいなど)は素直にlogback-spring.xmlで定義するが良いでしょう。
デフォルトで使用される定義ファイル
logging.pattern.consoleというプロパティがあるので、xmlファイルが親の仇の方はapplication.propertiesにも書けますが、他の設定値の見通しが悪くなるので別ファイル化をお勧めします。
spring:
config:
import:
- logback-config.yml
logging:
level:
root: WARN
pattern:
console: "%d{yyyy/MM/dd HH:mm:ss.SSS} -%5p [%15.15t] %-40.40logger{39} : %m%n"
References
Qiita - Spring Bootの外部設定値の扱い方を理解する
Qiita - Spring Boot でロギングライブラリをLog4j2にする