同僚氏のPRレビューをするにあたって、ロギング、Exceptionハンドリングよくわかってないなって思って再入門してみた。 「@ExceptionHandlerのメソッドでハンドリングしたときのレスポンスをログ出力する」というのがPRの内容だった。
「1.どこでアクセス（リクエスト）ログを出力するのがよいのか」、「2.どうやってExceptionハンドリングが行われているのか」について調べたことをまとめる。
※本記事の環境はJava 11, Spring Boot 2.4.4
ロギング
Spring Bootは、Commons Loggingを使ってログ出力をしている。デフォルト設定としては、Java Util Logging、Log4j2、Logbackを提供している。
spring-boot-starter-loggingを依存関係に追加している場合は、Logbackが使われる。 spring-boot-starter-loggingには、Logback、Log4j、Slf4jが依存関係に追加されている。
ログのファイル出力
Spring Bootは、デフォルトでコンソールのみにだけログを出力してファイルには出力しない。ファイルに出力したい場合は、application.properties(yml)にlogging.file.pathでパスを指定するだけでよい。デフォルトのファイル名はspring.logなので、変更したい場合はlogging.file.nameでファイル名を指定する。
Logbackを使ったログ出力
howto-logginをそのままマネするだけで、Logbackを使ってログ出力が可能。
このように書けば、ファイルとコンソールにログを出力できる。
| <?xml version="1.0" encoding="UTF-8"?> | |
| <configuration> | |
| <include resource="org/springframework/boot/logging/logback/defaults.xml"/> | |
| <include resource="org/springframework/boot/logging/logback/console-appender.xml" /> | |
| <property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH/}spring.log}" /> | |
| <include resource="org/springframework/boot/logging/logback/file-appender.xml" /> | |
| <root level="INFO"> | |
| <appender-ref ref="CONSOLE" /> | |
| <appender-ref ref="FILE" /> | |
| </root> | |
| </configuration> |
ログレベルで出力するファイルを分ける
logback-spring.xmlでfilter要素を指定すれば、出力ログのフィルタリングができる。
| <?xml version="1.0" encoding="UTF-8"?> | |
| <configuration> | |
| <include resource="org/springframework/boot/logging/logback/defaults.xml"/> | |
| <!-- 標準出力はデフォルト --> | |
| <include resource="org/springframework/boot/logging/logback/console-appender.xml" /> | |
| <property name="APPLICATION_LOG_FILE" value="${LOG_PATH}/application.log" /> | |
| <appender name="FILE_INFO" class="ch.qos.logback.core.rolling.RollingFileAppender"> | |
| <encoder> | |
| <pattern>${FILE_LOG_PATTERN}</pattern> | |
| <charset>${FILE_LOG_CHARSET}</charset> | |
| </encoder> | |
| <filter class="ch.qos.logback.classic.filter.LevelFilter"> | |
| <level>INFO</level> | |
| <onMatch>ACCEPT</onMatch> | |
| <onMismatch>DENY</onMismatch> | |
| </filter> | |
| <file>${APPLICATION_LOG_FILE}</file> | |
| <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"> | |
| <fileNamePattern>${APPLICATION_LOG_FILE}.%d{yyyy-MM-dd}.%i.gz</fileNamePattern> | |
| <maxFileSize>10MB</maxFileSize> | |
| </rollingPolicy> | |
| </appender> | |
| <property name="ERROR_LOG_FILE" value="${LOG_PATH}/error.log" /> | |
| <appender name="FILE_ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender"> | |
| <encoder> | |
| <pattern>${FILE_LOG_PATTERN}</pattern> | |
| <charset>${FILE_LOG_CHARSET}</charset> | |
| </encoder> | |
| <filter class="ch.qos.logback.classic.filter.LevelFilter"> | |
| <level>ERROR</level> | |
| <onMatch>ACCEPT</onMatch> | |
| <onMismatch>DENY</onMismatch> | |
| </filter> | |
| <file>${ERROR_LOG_FILE}</file> | |
| <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"> | |
| <fileNamePattern>${ERROR_LOG_FILE}.%d{yyyy-MM-dd}.%i.gz</fileNamePattern> | |
| <maxFileSize>10MB</maxFileSize> | |
| </rollingPolicy> | |
| </appender> | |
| <root level="INFO"> | |
| <appender-ref ref="CONSOLE" /> | |
| <appender-ref ref="FILE_INFO" /> | |
| <appender-ref ref="FILE_ERROR" /> | |
| </root> | |
| </configuration> |
-
appender name=“FILE_INFO”
- ログレベルINFOのログを${LOG_PATH}/application.logに出力
-
appender name=“FILE_ERROR”
- ログレベルERRORのログを${LOG_PATH}/error.logに出力
アクセスログの出力
Spring MVCで用意されているCommonsRequestLoggingFilter.javaを使ってアクセスログを出力してみる。
まず、CommonsRequestLoggingFilter.javaをBean登録する。
| @Configuration(proxyBeanMethods = false) | |
| public class RequestLoggingFilterConfig { | |
| @Bean | |
| public CommonsRequestLoggingFilter logFilter() { | |
| CommonsRequestLoggingFilter filter = new CommonsRequestLoggingFilter(); | |
| filter.setIncludeQueryString(true); | |
| filter.setIncludePayload(true); | |
| filter.setMaxPayloadLength(10000); | |
| filter.setIncludeHeaders(false); | |
| filter.setAfterMessagePrefix("Request data : "); | |
| return filter; | |
| } | |
| } |
次に、application.ymlでログレベルDEBUGのログを出力するように設定する。
| logging: | |
| level: | |
| org.springframework.web.filter.CommonsRequestLoggingFilter: debug |
サンプルのREST APIに対してリクエストを送ると、このような感じでログ出力される。
2021-03-21 21:17:10.364 DEBUG 24133 --- [nio-8080-exec-2] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /users]
2021-03-21 21:17:10.396 DEBUG 24133 --- [nio-8080-exec-2] o.s.w.f.CommonsRequestLoggingFilter : Request data : GET /users]
2021-03-21 21:17:14.724 DEBUG 24133 --- [nio-8080-exec-3] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /users/1]
2021-03-21 21:17:14.735 DEBUG 24133 --- [nio-8080-exec-3] o.s.w.f.CommonsRequestLoggingFilter : Request data : GET /users/1]
2021-03-21 21:17:17.829 DEBUG 24133 --- [nio-8080-exec-4] o.s.w.f.CommonsRequestLoggingFilter : Before request [GET /users/5]
2021-03-21 21:17:17.837 DEBUG 24133 --- [nio-8080-exec-4] o.s.w.f.CommonsRequestLoggingFilter : Request data : GET /users/5]
2021-03-21 21:17:31.881 DEBUG 24133 --- [nio-8080-exec-5] o.s.w.f.CommonsRequestLoggingFilter : Before request [POST /users]
2021-03-21 21:17:31.904 DEBUG 24133 --- [nio-8080-exec-5] o.s.w.f.CommonsRequestLoggingFilter : Request data : POST /users, payload={
"name": "test"
}]単にリクエスト情報を知りたい場合は、用意されているクラスを使えば簡単にできる。
ここで、冒頭の「どこでアクセス（リクエスト）ログを出力するのがよいのか」について考えてみる。 先ほど利用した、CommonsRequestLoggingFilter.javaは、AbstractRequestLoggingFilter.javaを継承しておりこのクラスは、OncePerRequestFilter.javaを継承している。
これを踏まえると、OncePerRequestFilter.javaを継承してアクセスログを出力するのが正しいそう。
Exceptionハンドリング
Spring MVCで、Controller以降の処理で発生した例外をハンドリングするコンポーネントとして、org.springframework.web.servlet.HandlerExceptionResolverインターフェースといくつかの実装クラスを提供している。
デフォルトで適用されるHandlerExceptionResolverの実装クラスと呼び出される順序は、「1.ExceptionHandlerExceptionResolver.java」、「2.ResponseStatusExceptionResolver.java」、「3.DefaultHandlerExceptionResolver.java」である。
-
ExceptionHandlerExceptionResolver.java
@ExceptionHandlerを指定したメソッドのためのExceptionハンドラ
-
ResponseStatusExceptionResolver.java
@ResponseStatusを付与した例外クラスのためのExceptionハンドラ
-
DefaultHandlerExceptionResolver.java
- Spring MVCのコントローラの処理で発生する例外をハンドリングするためのExceptionハンドラ