9月に入社しました、サーバーサイド開発部 Scala チームの立野（@exoego）です。
ふだんは長野県の古民家から週5で在宅勤務しています。

弊社 Chatwork では現在、HTTP ベースの製品開発に Scala を用いるときは Akka HTTP というモジュールを採用しています。
最近、担当製品にログを追加するにあたり、この Akka HTTP でのログ出力の仕組みを初めて使いました。

従来のログ出力に不満に思っていた点をいくつか解消できて、なかなかおもしろく感じました。
ただ、使うにあたって社内でもノウハウとしてまとまっておらず、国内外でもどう使ってるかを書いたブログ記事が見当たらず、少し困りました。
そんなわけで、社内外の役に立てばと書きたいと思います。

本記事執筆時のシステム構成

Akka 2.5.31
Akka-HTTP 10.2.1

よくあるログ出力コード

ソフトウェアが出力するログは、開発チームの必要に応じて、さまざまな制御をしたくなります。

本番環境では、あるレベル未満のログは省いて、必要最小限のログにしたい
分析しやすいフォーマットにしたい（例えば JSON で、プロパティ名は〜〜）
ログは logstash 経由で Elasticsearch や S3 に書き込みたい

Scala での println や JavaScript での console.log のような単純なコンソール出力でログを出してしまうと、このような関心事に対応するのは一苦労です。
こうした関心事は、Scala に限らずロギングライブラリ（ログにまつわる様々な機能を提供してくれるライブラリ）を使って実現することが多いでしょう。

よくあるログ出力は、ライブラリを使うとこんな感じになると思います。

class Foo {
  private val logger = LoggerFactory.getLogger(this.getClass)

  def hello(input: String): String = {
    logger.info(s"入力は ${input} ")

    val result = Try {
      // 何らかのビジネスロジック
      ??? 
    }

    result match {
      case Success(value) =>
        logger.info(s"大成功! 結果は ${value}")
        v
      case Failure(err) =>
        logger.error(s"エラーです...  ${err}")
        throw err
    }
  }
}

よくあるログ出力コードの不満なところ

このようなログ出力は、さまざまなプログラミング言語とロギングライブラリで長年よく使われてきて、見慣れているかと思います。
ただ、慣れてはいるものの、少し不満を感じることがありませんか？

ソースコードがロガーに汚染されてしまう。あちこちで、ロガーを生成したり、外部から受け取るコードが広がっていく。
共通化の見逃しに気づきにくい。複数ソースコードで共通のログを追加するには、あちこちでログコードを追加しないといけないが、追加し忘れたところでは当然ログが出ない。
他の人の改修とコンフリクトしやすい。あるビジネスロジックに何らかのログを追加しようとしているとき、他の開発者がちょうど同じ部分のロジックを別の開発で修正していると、変更箇所がぶつかって、どちらかが修正する羽目になる。

今回 Akka HTTP で出したくなった共通ログ

さて今回、ぼくの担当システムでは、提供している複数の HTTP API に対して、仕様に「違反」した HTTP リクエストがたびたび来ているようでした。
「違反」とは言ったものの、必ずしも API クライアントがミスをしているわけではなく、API 側の実装がまずい可能性も捨てきれませんでした。
というのも、これら API は、過去に PHP で開発されてきた API を Scala で再実装したものだったからです。

PHP で長年かけて挙動が修正されてきたが、ドキュメントやテストコードで引き継ぎがされず、はぐれ仕様になってしまった
本来の仕様としては API クライアントが間違っているが、PHP 実装にも考慮漏れがあり、その積み重ねでたまたま動いていた

といったことがありえるからです（どちらも実際ありました）。

そこで、次のようなログを HTTP API に追加して調査することになりました。

どんな HTTP リクエストなのか: 問題があったときの具体的なリクエストボディ、ユーザーエージェントなど。
どんな違反があったのか: リクエストボディの項目の欠落、あるいは項目の型エラー、など。

Akka HTTP でも、ロガーオブジェクトを生成してログを書き込む従来の手法が使えます。
そんな使い慣れたログ出力コードでさっさと実装してもよかったのですが、そうすると、先ほど挙げたような「共通化の見逃しに気づきにくい」とか「他の人の改修とコンフリクトしやすい」といった問題が出てくることもあります。
このような共通ログを仕込みたい Scala 移植済み HTTP API はいくつもあり、しかもこれから増やそうとしている最中です。
こうした問題を避けたいのですが、こんなとき、皆さんならどうするでしょうか。

Akka HTTP のルーティング DSL で共通ログを実現する

Akka HTTP のドキュメントを読んでいくと、「共通化の見逃し」や「他の人の改修とコンフリクト」を防いでログを実装するのに良さそうな仕組みや使用例を見つけられたので、それらを使うことにしました。

ログ実装の前に、Akka HTTP のルーティングの概要

Akka HTTP は、HTTP サーバーのエンドポイントを定義するための Routing DSL を提供しています。
この Routing DSL を使うと、

URL やクエリパラメータはどんなもので、どの Scala クラスにデコードするか
エンティティ（リクエストボディ）をどの Scala クラスにデコードするか
各エンドポイントではどのような認証やエラー処理を行うか

といった、エンドポイントにまつわるさまざまな関心を、次のような階層構造で定義できます。

object MyHttpServer {
  def main(args: Array[String]): Unit = {
    implicit val system = ActorSystem("hello-world")
    implicit val executionContext = system.dispatcher

    val route = {
      path("") {
        get {
          complete(HttpEntity(ContentTypes.`text/html(UTF-8)`, s"<h1>Hello, world !</h1>"))
        }
      } ~
      pathPrefix("my-api") {
        pathPrefix("foo") {
          get(parameters("id".as[Long], "hoge".withDefault("abc")) { (fooId, hoge) =>
            ???
          } ~
          post {
            entitiy(as[PostFooRequest]) { entity =>
              ???
            }
          }
        } ~
        pathPrefix("bar") {
          get(parameters("id".as[Long], "fuga".withDefault("xyz")) { (barId, fuga) =>
            ???
          }
          post {
            entitiy(as[PostBarRequest]) { entity =>
              ???
            }
          }
        }
      }
    }

    val bindingFuture = Http().newServerAt("localhost", 8080).bind(route)
    bindingFuture.flatMap(_.unbind()).onComplete(_ => system.terminate())
  }
}

ここで、complete、entity、path、pathPrefix などは、どのようなルーティングにしたいかを指示する Directivesと総称されています。
定義するエンドポイントが増えていくとルーティングが巨大になってしまうので、理解しやすい単位で分割し、組み合わせることもできます。

var fooRoute = pathPrefix("foo") { ... }
var barRoute = pathPrefix("bar") { ... }
var buzRoute = pathPrefix("buz") { ... }

val route = path("my-api") {
  fooRotue ~
  barRoute ~
  buzRoute ~
  MyExternalRouting.route // もちろん別ファイルでも OK
}

選択肢 1. 汎用的な Logging Directives での実装

Routing DSL には、本題のログ出力に関しても Directives がいくつか用意されていました。

extractLog Akka HTTP のロガーを直接呼び出してログを書きたいときに使える、プリミティブな Directive
logRequest、logResult などの Debugging Directives [:embed:cite] HTTP リクエストやレスポンスに関するログを書くときに使える Directives

これら Directives を使うことで、複数エンドポイントに共通するログをこんな風に定義できました。

def myLogging(request: HttpRequest)(result: RouteResult): Option[LogEntry] = {
  Some(LogEntry(s"${request} と ${result} から欲しいものを抜き出す", LogLevels.Warning))
}

val route =  {
  path("") { ... } ~
  // この Directive で囲まれた範囲では共通ログが有効になる
  logRequestResult(myLogging _) {
    pathPrefix("my-api") {
      pathPrefix("foo") { ... } ~
      pathPrefix("bar") { ... }
    }
  }
}

どのエンドポイントに共通ログ実装 logRequestResult(myLogging _) が適用されているか、一目瞭然になりました。
新しいエンドポイントを追加するときも、この Directive の内側に追加するだけで共通ログが適用されるので、実装漏れもカンタンに防げそうです。
また、各エンドポイントの個別実装では共通ログを意識しなくていいのも、うれしいところです。

選択肢 2. エラー時だけのログはエラーハンドラーで実装

さきほどの Directive は、HTTP リクエストの処理に成功したとき、失敗したとき、あるいは両方でも使えます。
ただ実際には成功時のログには関心がなく、失敗時だけログを出したいというケースが多いと思います。
そんなときは、Akka HTTP のエラー処理の仕組みを使うと、よりカンタンに共通ログを出すことができます。

Akka HTTP では、エラーを大きく 2 つに分類しています。
1 つは Rejection です。
これは言わば、HTTP リクエストを送ったクライアント起因のエラーです。
以下のような Rejection が Akka HTTP に実装されており、自分で実装することもできます。

未対応の HTTP メソッドが使用されたとき
未対応のスキーマが使用されたとき
予期せぬクエリパラメータが渡ってきたとき
必須の HTTP ヘッダーが存在しないとき

もう 1 つは、Exception です。
こちらは Rejection に対をなすサーバー起因のエラーで、Exception という名前から想像できるように Java 標準ライブラリの Exception に対応しています。

Routing DSL では、handleRejections や handleExceptions という Directive で、エラー処理方法をハンドラーを渡すことで指定できます。
例えば、先ほど定義した route のあらゆるエンドポイントで共通のエラー処理をしたい場合、このようにエラーハンドラーを渡せます。

val route = ???

val newRoute = 
  handleExceptions(MyExceptionHandler.get) {
    handleRejections(MyRejectionHandler.get) {
      route
    }
  }

そして、エラーハンドラー側で共通のエラー処理（今回はログ）を実装すれば OK です！

object MyRejectionHandler {
  def get: RejectionHandler = {
    RejectionHandler
      .newBuilder()
      .handle {
        case MyAuthRejection =>
          dropEntityAndComplete(NotFound, s"Unauthorized !!")
        case MalformedQueryParamRejection(name, errMsg, _) =>
          dropEntityAndComplete(BadRequest, s"$errMsg on $name")
      }
      .result()
  }

  def dropEntityAndComplete(status: StatusCode, errorMessage: String) = {
    logRequest(myUsefulLog(errorMessage) _) {
      extractRequest { request =>
        extractMaterializer { implicit mat =>
          request.discardEntityBytes()
          complete(status)
        }
      }
    }
  }

  def myUsefulLog(errorMessage: String)(request: HttpRequest): LogEntry = {
    val content =
      s"""request: ${request} から必要な情報を抜き出す !!
         |errorMessage: ${errorMessage}
         |""".stripMargin
    LogEntry(content, Logging.WarningLevel)
  }
}

このエラーハンドラーでも、エラー時の HTTP レスポンスやリダイレクト先などを構築するために、Routing DSL の Directives が使われています。
さきほど紹介したログ用 Directives が使うことができます。

まとめ

Akka HTTP で複数の HTTP エンドポイントに共通するログを追加するには、

いつでも使える汎用的な仕組み
- ログ用 Directive: extractLog や logRequestResult など
エラー時だけに特化した仕組み
- handleRejections に登録する RejectionHandler
- handleExceptions に登録する ExceptionHandler

という、Routing DSL の 3 つの機能が使えることをご紹介しました。

Chatwork Creator's Note

ビジネスチャット「Chatwork」のエンジニアとデザイナーのブログです。

Akka HTTP で複数エンドポイントに共通するログを Routing DSL で実装