1. ロギングの設定と使用

ロギングの設定と使用 

以前に実行されたコマンドのログ出力を表示する 

コマンドを実行すると、より詳細なログ出力が画面ではなくファイルに送信されます(デフォルト)。 この出力は、`last` コマンドを実行することで、直前に実行されたコマンドについて呼び出すことができます。

たとえば、ソースが最新のときに `run` の出力は次のようになります。

> run
[info] Running A
Hi!
[success] Total time: 0 s, completed Feb 25, 2012 1:00:00 PM

この実行の詳細は、`last` を実行することで呼び出すことができます。

> last
[debug] Running task... Cancelable: false, max worker threads: 4, check cycles: false
[debug]
[debug] Initial source changes:
[debug]     removed:Set()
[debug]     added: Set()
[debug]     modified: Set()
[debug] Removed products: Set()
[debug] Modified external sources: Set()
[debug] Modified binary dependencies: Set()
[debug] Initial directly invalidated sources: Set()
[debug]
[debug] Sources indirectly invalidated by:
[debug]     product: Set()
[debug]     binary dep: Set()
[debug]     external source: Set()
[debug] Initially invalidated: Set()
[debug] Copy resource mappings:
[debug]
[info] Running A
[debug] Starting sandboxed run...
[debug] Waiting for threads to exit or System.exit to be called.
[debug]   Classpath:
[debug]     /tmp/e/target/scala-2.9.2/classes
[debug]     /tmp/e/.sbt/0.12.0/boot/scala-2.9.2/lib/scala-library.jar
[debug] Waiting for thread runMain to exit
[debug]     Thread runMain exited.
[debug] Interrupting remaining threads (should be all daemons).
[debug] Sandboxed run complete..
[debug] Exited with code 0
[success] Total time: 0 s, completed Jan 1, 2012 1:00:00 PM

コンソールとバッキングファイルのログレベルの設定については、以下のセクションで説明します。

特定のタスクの以前のログ出力を表示する 

タスクを実行すると、より詳細なログ出力が画面ではなくファイルに送信されます(デフォルト)。 この出力は、`last <task>` コマンドを実行することで、特定のタスクについて呼び出すことができます。 たとえば、`compile` を初めて実行すると、出力は次のようになります。

> compile
[info] Updating {file:/.../demo/}example...
[info] Resolving org.scala-lang#scala-library;2.9.2 ...
[info] Done updating.
[info] Compiling 1 Scala source to .../demo/target/scala-2.9.2/classes...
[success] Total time: 0 s, completed Jun 1, 2012 1:11:11 PM

出力は、依存関係の解決とコンパイルの両方を実行したことを示しています。 これらのそれぞれを個別に呼び出すことができます。 例えば、

> last compile
[debug]
[debug] Initial source changes:
[debug]     removed:Set()
[debug]     added: Set(/home/mark/tmp/a/b/A.scala)
[debug]     modified: Set()
...

そして

> last update
[info] Updating {file:/.../demo/}example...
[debug] post 1.3 ivy file: using exact as default matcher
[debug] :: resolving dependencies :: example#example_2.9.2;0.1-SNAPSHOT
[debug]     confs: [compile, runtime, test, provided, optional, compile-internal, runtime-internal, test-internal, plugin, sources, docs, pom]
[debug]     validate = true
[debug]     refresh = false
[debug] resolving dependencies for configuration 'compile'
...

前回のコンパイルからの警告を表示する 

Scala コンパイラは、デフォルトでは警告の詳細をすべて出力しません。 Predef から非推奨の `error` メソッドを使用するコードをコンパイルすると、次の出力が生成される可能性があります。

> compile
[info] Compiling 1 Scala source to <...>/classes...
[warn] there were 1 deprecation warnings; re-run with -deprecation for details
[warn] one warning found

詳細は提供されないため、コンパイラ(`scalacOptions`)に渡されるオプションに `-deprecation` を追加して再コンパイルする必要があります。 Scala 2.10 以降を使用する場合の代替手段は、`printWarnings` を実行することです。 このタスクは、前回のコンパイルからのすべての警告を表示します。 例えば、

> printWarnings
[warn] A.scala:2: method error in object Predef is deprecated: Use sys.error(message) instead
[warn]  def x = error("Failed.")
[warn]          ^

ログレベルをグローバルに変更する 

ログレベルを変更する最も簡単な方法は、`error`、`warn`、`info`、または `debug` コマンドを使用することです。 これらは、コマンドとタスクのデフォルトのログレベルを設定します。 例えば、

> warn

はデフォルトで警告とエラーのみを表示します。 起動時にコマンドが実行される前にログレベルを設定するには、ログレベルの前に `--` を使用します。 例えば、

$ sbt --warn
> compile
[warn] there were 2 feature warning(s); re-run with -feature for details
[warn] one warning found
[success] Total time: 4 s, completed ...
>

ログレベルは、より細かい粒度でオーバーライドできます。これについては、次に説明します。

特定のタスク、設定、またはプロジェクトのログレベルを変更する 

ログの量は、`logLevel` 設定によって制御されます。この設定は、`Level` 列挙体から値を取得します。有効な値は、冗長性の低い順に `Error`、`Warn`、`Info`、`Debug` です。 ログレベルは、前のセクションで説明したようにグローバルに設定することも、特定のプロジェクト、設定、またはタスクに適用することもできます。 たとえば、コンパイルのログレベルを変更して警告とエラーのみを表示するには、次のようにします。

> set Compile / compile / logLevel := Level.Warn

現在のプロジェクトのすべてのタスクでデバッグログを有効にするには、次のようにします。

> set logLevel := Level.Warn

一般的なシナリオは、タスクを実行した後に、デフォルトで表示されたよりも多くの情報が必要になることです。 `logLevel` ベースのソリューションでは、通常、ログレベルを変更してタスクを再実行する必要があります。 ただし、これが不要な場合があります。 まず、前回のコンパイルからの警告は、メインソースの場合は `printWarnings`、テストソースの場合は `Test/printWarnings` を使用して表示できます。 第二に、前回の実行からの出力は、単一のタスクに対して、または全体で利用できます。 printWarnings のセクションと 以前の出力 のセクションを参照してください。

スタックトレースの印刷を設定する 

デフォルトでは、sbt は実行中にスローされたほとんどの例外のスタックトレースを非表示にします。 例外を表示する方法を示すメッセージが出力されます。 ただし、デフォルトでスタックトレースをもっと表示したい場合があります。

設定する設定は `traceLevel` で、これは Int 値を持つ設定です。 `traceLevel` が負の値に設定されている場合、スタックトレースは表示されません。 ゼロの場合、スタックトレースは最初の sbt スタックフレームまで表示されます。 正の場合、スタックトレースはその数のスタックフレームまで表示されます。

たとえば、sbt が最初の sbt フレームまでのスタックトレースを表示するように設定するには、次のようにします。

> set every traceLevel := 0

`every` 部分は、すべてのスコープで設定をオーバーライドすることを意味します。 単一のプロジェクト、設定、またはタスクのトレース印刷動作を変更するには、`traceLevel` のスコープを適切に設定します。

> set Test / traceLevel := 5
> set update / traceLevel := 0
> set ThisProject / traceLevel := -1

テストの出力をバッファリングせずにすぐに印刷する 

デフォルトでは、sbt はクラス全体が終了するまでテストのログ出力をバッファリングします。 これは、並列実行時に出力が混在しないようにするためです。 バッファリングを無効にするには、`logBuffered` 設定を false に設定します。

logBuffered := false

カスタムロガーを追加する 

設定 `extraLoggers` を使用して、カスタムロガーを追加できます。 内部的には、sbt は log4j2 ライブラリ を使用しているため、カスタムロガーは `org.apache.logging.log4j.core.Appender` を実装する必要があります。通常は `AbstractAppender` を拡張します。

`extraLoggers` は関数 `ScopedKey[_] => Seq[Appender]` です。 これは、ロガーを要求するタスクに基づいて異なるログを提供できることを意味します。

extraLoggers := {
  val currentFunction = extraLoggers.value
    (key: ScopedKey[_]) => {
        myCustomLogger(key) +: currentFunction(key)
    }
}

ここでは、設定の現在の関数 `currentFunction` を取得し、新しい関数を指定します。 新しい関数は、カスタムロガーを古い関数によって提供されたロガーの前に追加します。

log4j2 の `Appender` は、`LogEvent` を追加します。そのコアは内部的には `Message` です。 Message には多くの種類がありますが、sbt は `ObjectMessage` のインスタンスを含むイベントを生成します。これには、`getParameter()` を呼び出すことによって取得できるペイロードが含まれています。

sbt ロギングによって出力されるペイロードは、`StringEvent` のインスタンスです。これには、`message` や `level` などの `String` フィールドが含まれています。

これらをすべてまとめると、タスクからのメッセージをコンソールに逆順にログに記録する(完全に役に立たない!)追加のロガーの例を次に示します。

extraLoggers := {
  import org.apache.logging.log4j.core.LogEvent;
  import org.apache.logging.log4j.core.appender.AbstractAppender
  import org.apache.logging.log4j.message.{Message,ObjectMessage}

  import sbt.internal.util.StringEvent

  def loggerNameForKey( key : sbt.Def.ScopedKey[_] ) = s"""reverse.${key.scope.task.toOption.getOrElse("<unknown>")}"""

  class ReverseConsoleAppender( key : ScopedKey[_] ) extends AbstractAppender (
    loggerNameForKey( key ), // name : String
    null,                    // filter : org.apache.logging.log4j.core.Filter
    null,                    // layout : org.apache.logging.log4j.core.Layout[ _ <: Serializable]
    false                    // ignoreExceptions : Boolean
  ) {

    this.start() // the log4j2 Appender must be started, or it will fail with an Exception

    override def append( event : LogEvent ) : Unit = {
      val output = {
        def forUnexpected( message : Message ) = s"[${this.getName()}] Unexpected: ${message.getFormattedMessage()}"
        event.getMessage() match {
	   case om : ObjectMessage => { // what we expect
	     om.getParameter() match {
	       case se : StringEvent => s"[${this.getName()} - ${se.level}] ${se.message.reverse}"
	       case other            => forUnexpected( om )
	     }
	   }
	   case unexpected : Message => forUnexpected( unexpected )
	}
      }
      System.out.synchronized { // sbt adopts a convention of acquiring System.out's monitor printing to the console
         println( output )
      }
    }
  }

  val currentFunction = extraLoggers.value
  (key: ScopedKey[_]) => {
     new ReverseConsoleAppender(key) +: currentFunction(key)
  }
}

これで、メッセージをログに記録するタスクを実行すると、ロガーが呼び出されるはずです。

sbt:sbt-logging-example> update
[info] Updating ...
[reverse.update - info] ... gnitadpU
[info] Done updating.
[reverse.update - info] .gnitadpu enoD
[success] Total time: 0 s, completed Oct 16, 2019 5:22:22 AM

タスクにメッセージを記録する 

特別なタスク `streams` は、Streams インスタンスを介してタスクごとのログと I/O を提供します。 ログに記録するには、タスクは `streams` タスクの `log` メンバーを使用します。 `log` を呼び出すと、Logger が提供されます。

import sbt.Keys.streams

myTask := {
  val log = streams.value.log
  log.warn("A warning.")
}

設定にメッセージを記録する 

設定はタスクを参照できないため、特別なタスク `streams` を使用して設定の初期化中にログを提供することはできません。推奨される方法は、`sLog` を使用することです。 `sLog.value` を呼び出すと、Logger が提供されます。

mySetting := {
  val log = sLog.value
  log.warn("A warning.")
}