1. ホーム
2. Playの操作
3. Scala開発者向けのPlay
4. 主な概念
5. ロギング

§ロギングAPI

アプリケーションでのロギングの使用は、監視、デバッグ、エラー追跡、およびビジネスインテリジェンスに役立ちます。Playは、Loggerオブジェクトを介してアクセスされるロギング用のAPIを提供し、デフォルトのロギングエンジンとしてLogbackを使用します。

§ロギングアーキテクチャ

ロギングAPIは、効果的なロギング戦略を実装するのに役立つ一連のコンポーネントを使用します。

§Logger

アプリケーションは、ログメッセージリクエストを送信するためにLoggerインスタンスを定義できます。各Loggerには、ログメッセージに表示され、構成に使用される名前があります。Logger APIはSLF4Jに基づいており、したがってLoggerはorg.slf4j.Loggerインターフェースに基づいています。

ロガーは、命名に基づく階層的な継承構造に従います。ロガーの名前の後にドットが続き、それが子孫ロガーの名前のプレフィックスである場合、そのロガーは別のロガーの祖先であると言われます。たとえば、「com.foo」という名前のロガーは、「com.foo.bar.Baz」という名前のロガーの祖先です。すべてのロガーはルートロガーから継承します。ロガーの継承により、共通の祖先を構成することで一連のロガーを構成できます。

クラスごとに個別の名前のロガーを作成することをお勧めします。この規約に従って、Playライブラリは「play」の下に名前空間化されたロガーを使用し、多くのサードパーティライブラリはクラス名に基づいたロガーを持っています。

§ログレベル

ログレベルは、ログメッセージの重大度を分類するために使用されます。ログ要求ステートメントを記述するときは、重大度を指定し、これは生成されたログメッセージに表示されます。

これは、重大度の降順で使用可能なログレベルのセットです。

• OFF - メッセージ分類としてではなく、ロギングをオフにするために使用されます。
• ERROR - ランタイムエラー、または予期しない状態。
• WARN - 非推奨のAPIの使用、APIの不適切な使用、「ほとんど」エラー、望ましくないまたは予期しないが、必ずしも「間違っている」とは限らないその他のランタイム状況。
• INFO - アプリケーションの起動やシャットダウンなどの興味深いランタイムイベント。
• DEBUG - システムを通るフローに関する詳細情報。
• TRACE - 最も詳細な情報。

メッセージを分類することに加えて、ログレベルは、ロガーとアペンダーの重大度しきい値を構成するために使用されます。たとえば、レベルINFOに設定されたロガーは、レベルINFO以上のリクエスト（INFO、WARN、ERROR）をログに記録しますが、より低い重大度（DEBUG、TRACE）のリクエストは無視します。OFFを使用すると、すべてのログリクエストが無視されます。

§アペンダー

ロギングAPIを使用すると、ログリクエストを「アペンダー」と呼ばれる1つまたは複数の出力先に印刷できます。アペンダーは構成で指定され、コンソール、ファイル、データベース、その他の出力にオプションがあります。

アペンダーをロガーと組み合わせることで、ログメッセージのルーティングとフィルタリングに役立ちます。たとえば、分析に役立つデータをログに記録するロガーに1つのアペンダーを使用し、運用チームが監視するエラーに別のアペンダーを使用できます。

注：アーキテクチャの詳細については、Logbackドキュメントを参照してください。

§ロガーの使用

まず、Loggerクラスとコンパニオンオブジェクトをインポートします

import play.api.Logger

§ロガーの作成

name引数を持つLogger.applyファクトリメソッドを使用して新しいロガーを作成できます。

val accessLogger: Logger = Logger("access")

アプリケーションイベントをログに記録するための一般的な戦略は、クラス名を使用してクラスごとに個別のロガーを使用することです。ロギングAPIは、クラス引数を取るファクトリメソッドでこれをサポートします

val logger: Logger = Logger(this.getClass())

また、これを自動的に実行し、protected val loggerを公開するLoggingトレイトもあります

import play.api.Logging

class MyClassWithLogging extends Logging {
  logger.info("Using the trait")
}

Loggerを設定したら、それを使用してログステートメントを記述できます

// Log some debug info
logger.debug("Attempting risky calculation.")

try {
  val result = riskyCalculation

  // Log result if successful
  logger.debug(s"Result=$result")
} catch {
  case t: Throwable => {
    // Log error with message and Throwable.
    logger.error("Exception with riskyCalculation", t)
  }
}

Playのデフォルトのロギング構成を使用すると、これらのステートメントは次のようなコンソール出力を生成します

[debug] c.e.s.MyClass - Attempting risky calculation.
[error] c.e.s.MyClass - Exception with riskyCalculation
java.lang.ArithmeticException: / by zero
    at controllers.Application.riskyCalculation(Application.java:20) ~[classes/:na]
    at controllers.Application.index(Application.java:11) ~[classes/:na]
    at Routes$$anonfun$routes$1$$anonfun$applyOrElse$1$$anonfun$apply$1.apply(routes_routing.scala:69) [classes/:na]
    at Routes$$anonfun$routes$1$$anonfun$applyOrElse$1$$anonfun$apply$1.apply(routes_routing.scala:69) [classes/:na]
    at play.core.Router$HandlerInvoker$$anon$8$$anon$2.invocation(Router.scala:203) [play_2.10-2.3-M1.jar:2.3-M1]

メッセージには、ログレベル、ロガー名（この場合はクラス名、省略形で表示）、メッセージ、およびログリクエストでThrowableが使用された場合はスタックトレースが含まれていることに注意してください。

また、applicationという名前のロガーにアクセスできるplay.api.Loggerシングルトンオブジェクトもありますが、Play 2.7.0以降ではその使用は非推奨です。上記で定義されたいずれかの戦略を使用して、独自のロガーインスタンスを宣言する必要があります。

§マーカーとマーカーコンテキストの使用

SLF4J APIには、ログメッセージを充実させ、メッセージを特に関心のあるものとしてマークするマーカーの概念があります。マーカーは、トリガーやフィルタリングに特に役立ちます。たとえば、OnMarkerEvaluatorはマーカーが見られるとメールを送信したり、特定のフローを独自のアペンダーにマークアウトしたりできます。

Logger APIは、play.api.MarkerContextトレイトを通じてマーカーへのアクセスを提供します。

MarkerContext.applyメソッドを使用して、LoggerでMarkerContextを作成できます。

val marker: org.slf4j.Marker = MarkerFactory.getMarker("SOMEMARKER")
val mc: MarkerContext        = MarkerContext(marker)

また、DefaultMarkerContextから拡張することで、型付きのMarkerContextを提供することもできます。

val someMarker: org.slf4j.Marker = MarkerFactory.getMarker("SOMEMARKER")
case object SomeMarkerContext extends play.api.DefaultMarkerContext(someMarker)

MarkerContextが作成されると、ログステートメントで明示的に使用できます

// use a typed marker as input
logger.info("log message with explicit marker context with case object")(SomeMarkerContext)

// Use a specified marker.
val otherMarker: Marker               = MarkerFactory.getMarker("OTHER")
val otherMarkerContext: MarkerContext = MarkerContext(otherMarker)
logger.info("log message with explicit marker context")(otherMarkerContext)

または暗黙的に

val marker: Marker             = MarkerFactory.getMarker("SOMEMARKER")
implicit val mc: MarkerContext = MarkerContext(marker)

// Use the implicit MarkerContext in logger.info...
logger.info("log message with implicit marker context")

便宜上、MarkerからMarkerContextへの暗黙の変換が利用可能です。

val mc: MarkerContext = MarkerFactory.getMarker("SOMEMARKER")

// Use the marker that has been implicitly converted to MarkerContext
logger.info("log message with implicit marker context")(mc)

マーカーは、MDCが利用できない可能性があるスレッド間でコンテキスト情報を伝達できるため、非常に役立ちます。ロギングコンテキストを提供するために、MarkerContextをメソッドへの暗黙のパラメーターとして使用します。たとえば、Logstash Logback Encoderと暗黙の変換チェーンを使用すると、リクエスト情報をログステートメントに自動的にエンコードできます

trait RequestMarkerContext {
  // Adding 'implicit request' enables implicit conversion chaining
  // See http://docs.scala-lang.org/tutorials/FAQ/chaining-implicits.html
  implicit def requestHeaderToMarkerContext(implicit request: RequestHeader): MarkerContext = {
    import net.logstash.logback.marker.LogstashMarker
    import net.logstash.logback.marker.Markers._

    val requestMarkers: LogstashMarker = append("host", request.host)
      .and(append("path", request.path))

    MarkerContext(requestMarkers)
  }
}

その後、コントローラーで使用され、異なる実行コンテキストを使用する可能性のあるFutureを介して伝達されます

def asyncIndex = Action.async { implicit request =>
  Future {
    methodInOtherExecutionContext() // implicit conversion here
  }(otherExecutionContext)
}

def methodInOtherExecutionContext()(implicit mc: MarkerContext): Result = {
  logger.debug("index: ") // same as above
  Ok("testing")
}

マーカーコンテキストは、「トレーサーバレット」スタイルのロギングにも非常に役立ち、ログレベルを明示的に変更せずに特定のリクエストでログを記録できます。たとえば、特定の条件が満たされた場合にのみマーカーを追加できます

trait TracerMarker {
  import TracerMarker._

  implicit def requestHeaderToMarkerContext(implicit request: RequestHeader): MarkerContext = {
    val marker = org.slf4j.MarkerFactory.getDetachedMarker("dynamic") // base do-nothing marker...
    if (request.getQueryString("trace").nonEmpty) {
      marker.add(tracerMarker)
    }
    marker
  }
}

object TracerMarker {
  private val tracerMarker = org.slf4j.MarkerFactory.getMarker("TRACER")
}

class TracerBulletController @Inject() (cc: ControllerComponents) extends AbstractController(cc) with TracerMarker {
  private val logger = play.api.Logger("application")

  def index = Action { implicit request: Request[AnyContent] =>
    logger.trace("Only logged if queryString contains trace=true")

    Ok("hello world")
  }
}

次に、logback.xmlで次のTurboFilterを使用してロギングをトリガーします

<turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
  <Name>TRACER_FILTER</Name>
  <Marker>TRACER</Marker>
  <OnMatch>ACCEPT</OnMatch>
</turboFilter>

この時点で、入力に応じて動的にデバッグステートメントを設定できます。

ロギングでのマーカーの使用に関する詳細については、LogbackマニュアルのTurboFilterおよびマーカーベースのトリガーセクションを参照してください。

§ロギングパターン

ロガーを効果的に使用すると、同じツールで多くの目標を達成できます

import scala.concurrent.Future
import play.api.Logger
import play.api.mvc._
import javax.inject.Inject

class AccessLoggingAction @Inject() (parser: BodyParsers.Default)(implicit ec: ExecutionContext)
    extends ActionBuilderImpl(parser) {
  val accessLogger = Logger("access")
  override def invokeBlock[A](request: Request[A], block: (Request[A]) => Future[Result]) = {
    accessLogger.info(s"method=${request.method} uri=${request.uri} remote-address=${request.remoteAddress}")
    block(request)
  }
}

class Application @Inject() (val accessLoggingAction: AccessLoggingAction, cc: ControllerComponents)
    extends AbstractController(cc) {
  val logger = Logger(this.getClass())

  def index = accessLoggingAction {
    try {
      val result = riskyCalculation
      Ok(s"Result=$result")
    } catch {
      case t: Throwable => {
        logger.error("Exception with riskyCalculation", t)
        InternalServerError("Error in calculation: " + t.getMessage())
      }
    }
  }
}

この例では、アクション合成を使用して、リクエストデータを「access」という名前のロガーに記録するAccessLoggingActionを定義します。Applicationコントローラーはこのアクションを使用し、アプリケーションイベントにも独自のロガー（クラスにちなんで名付けられた）を使用します。構成では、これらのロガーを、アクセスログやアプリケーションログなど、異なるアペンダーにルーティングできます。

上記のような設計は、特定のアクションに対してのみリクエストデータをログに記録する場合にうまく機能します。すべてのリクエストをログに記録するには、フィルターを使用することをお勧めします

import javax.inject.Inject
import org.apache.pekko.stream.Materializer
import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.Future
import play.api.Logger
import play.api.mvc._
import play.api._

class AccessLoggingFilter @Inject() (implicit val mat: Materializer) extends Filter {
  val accessLogger = Logger("access")

  def apply(next: (RequestHeader) => Future[Result])(request: RequestHeader): Future[Result] = {
    val resultFuture = next(request)

    resultFuture.foreach(result => {
      val msg = s"method=${request.method} uri=${request.uri} remote-address=${request.remoteAddress}" +
        s" status=${result.header.status}";
      accessLogger.info(msg)
    })

    resultFuture
  }
}

フィルターバージョンでは、Future[Result]が完了したときにログに記録することで、リクエストに対するレスポンスステータスをログリクエストに追加しました。

§構成

構成の詳細については、ロギングの構成を参照してください。

次へ：高度なトピック

このドキュメントにエラーを見つけましたか？このページのソースコードはこちらにあります。 ドキュメントガイドラインをお読みになった後、お気軽にプルリクエストを送信してください。質問や共有するアドバイスはありますか？ コミュニティフォーラムに参加して、コミュニティとの会話を始めましょう。