同僚氏の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ハンドラ