http4sで実行時例外の詳細なログを出す

http4sでは、ルーティングされた先で例外を投げても安全に握り潰されるので、アプリが落ちることも他の接続に影響したりすることもない。

例として、触れるもの全てを傷付けてしまうcrashEverythingRoutesを用意した。

def crashEverythingRoutes(): HttpRoutes[IO] = HttpRoutes.of { _ =>
  throw new Exception("Boom!!")
}

これを呼び出してもhttp4sはびくともしないし、特段サーバの動作に影響を与えることはない。だが、素の状態では例外は握り潰されて何も表示されない。

`org.http4s.server.middleware.Logger`

標準のLoggerミドルウェアでも例外の捕捉は可能だが、Exception.getMessage()の内容までは表示されず、投げられた例外のクラスのみがINFOレベルで表示される。

val finalHttpApp = Logger.httpApp(true, true)(crashEverythingRoutes)

root [io-compute-12] INFO  o.h.s.m.Logger - service raised an error: class java.lang.Exception

運悪くライブラリの例外分類がおおざっぱだと、何が発生しているのか分からなくて途方に暮れることになる。

ミニマルなミドルウェアを書く

さてどうするかというと、ErrorHandlingを使って自分でエラーハンドリングを行うミドルウェアを書くことで、例外に直接アクセスしてより細やかな情報を表示する。

import org.http4s.server.middleware.ErrorHandling
import org.http4s.server.middleware.ErrorAction

val withErrorLogging = ErrorHandling.Recover.total(
  ErrorAction.log(
    crashEverythingRoutes,
    messageFailureLogAction = (t, msg) =>
      IO.println(msg) >>
      IO.println(t),
    serviceErrorLogAction = (t, msg) =>
      IO.println(msg) >>
      IO.println(t)
  )
)

Error servicing request: GET / from ::1
java.lang.Exception: Boom!!

slf4jを使う

Scala/Javaの標準的なロギング用インターフェイスであるslf4jを使ってLoggerを経由すると見た目も良い。ログレベルはお好みだが、エラーなのだからErrorでよいだろう。

import org.slf4j

val logger = slf4j.LoggerFactory.getLogger(this.getClass())
val withErrorLogging = ErrorHandling.Recover.total(
  ErrorAction.log(
    crashEverythingRoutes,
    messageFailureLogAction = (t, msg) =>
      IO { logger.error(msg) } >>
      IO { logger.error(t.toString()) },
    serviceErrorLogAction = (t, msg) =>
      IO { logger.error(msg) } >>
      IO { logger.error(t.toString()) }
  )
)

今回はログの実装としてlogbackを使っているが、なんでもよい。

root [io-compute-8] ERROR server.Server$ - Error servicing request: GET / from ::1 
root [io-compute-8] ERROR server.Server$ - java.lang.Exception: Boom!!

http4sの実行時例外をより細やかに把握するテクニックを紹介した。