Logging

Logging モジュールは、計算の履歴と進行状況をイベントのログとして記録する方法を提供します。イベントは、ソースコードにログ記録ステートメントを挿入することによって作成されます。例えば：

@warn "Abandon printf debugging, all ye who enter here!"
┌ Warning: Abandon printf debugging, all ye who enter here!
└ @ Main REPL[1]:1

システムは、ソースコードにprintln()の呼び出しを散りばめることに対していくつかの利点を提供します。まず、ソースコードを編集することなく、メッセージの可視性と表示を制御できる点です。たとえば、上記の@warnとは対照的に

@debug "The sum of some values $(sum(rand(100)))"

デフォルトでは出力を生成しません。さらに、このようなデバッグステートメントをソースコードに残しておくのは非常に安価です。なぜなら、システムはメッセージが後で無視される場合、評価を回避するからです。この場合、sum(rand(100)) と関連する文字列処理は、デバッグログが有効になっていない限り、決して実行されることはありません。

第二に、ログツールを使用すると、各イベントに任意のデータをキーと値のペアのセットとして添付できます。これにより、後で分析するためにローカル変数や他のプログラムの状態をキャプチャできます。たとえば、ローカル配列変数 A とベクトル v の合計をキー s として添付するには、次のようにします。

A = ones(Int, 4, 4)
v = ones(100)
@info "Some variables"  A  s=sum(v)

# output
┌ Info: Some variables
│   A =
│    4×4 Matrix{Int64}:
│     1  1  1  1
│     1  1  1  1
│     1  1  1  1
│     1  1  1  1
└   s = 100.0

すべてのロギングマクロ @debug、@info、@warn および @error は、より一般的なマクロ @logmsg のドキュメントで詳細に説明されている共通の機能を共有しています。

Log event structure

各イベントは、ユーザーによって提供されたデータと自動的に抽出されたデータのいくつかのデータを生成します。まず、ユーザー定義のデータを見てみましょう：

• ログレベルは、早期フィルタリングに使用されるメッセージの広範なカテゴリです。標準のレベルはいくつかあり、タイプはLogLevelです。ユーザー定義のレベルも可能です。それぞれの目的は異なります：

  • Logging.Debug (ログレベル -1000) はプログラムの開発者向けの情報です。これらのイベントはデフォルトで無効になっています。
  • Logging.Info (ログレベル 0) は、ユーザーへの一般的な情報のためのものです。これを println を直接使用する代替手段として考えてください。
  • Logging.Warn（ログレベル1000）は、何か問題が発生しており、対処が必要な可能性が高いことを意味しますが、現時点ではプログラムはまだ動作しています。
  • Logging.Error（ログレベル2000）は、何かが間違っていることを意味し、このコードの部分では回復する可能性は低いです。このログレベルはしばしば不要であり、例外をスローすることで必要な情報をすべて伝えることができます。

• メッセージ はイベントを説明するオブジェクトです。慣例として、メッセージとして渡される AbstractString はマークダウン形式であると見なされます。他のタイプは、テキストベースの出力には print(io, obj) または string(obj) を使用して表示され、インストールされたロガーで使用される他のマルチメディア表示にはおそらく show(io,mime,obj) が使用されます。

• オプショナルな キー–バリュー ペア は、各イベントに任意のデータを添付することを可能にします。一部のキーには、イベントの解釈に影響を与える慣習的な意味があります（@logmsg を参照）。

システムは各イベントに対していくつかの標準情報も生成します：

• ログマクロが展開されたmodule。
• ソースコード内でログマクロが発生するfileとline。
• メッセージ id は、ロギングマクロが出現する ソースコードステートメント のユニークで固定された識別子です。この識別子は、ファイルのソースコードが変更されても比較的安定しているように設計されており、ロギングステートメント自体が同じである限り、変わりません。
• イベントのための group は、デフォルトで拡張子なしのファイルの基本名に設定されます。これは、ログレベルよりも細かくメッセージをカテゴリにグループ化するために使用できます（例えば、すべての非推奨警告はグループ :depwarn を持ちます）、またはモジュール間または内部で論理的なグループに分けるために使用できます。

注意すべきは、イベントの時間などの有用な情報がデフォルトでは含まれていないことです。これは、そのような情報を抽出するのが高コストであり、現在のロガーに対して動的に利用可能であるためです。必要に応じて、イベントデータを時間、バックトレース、グローバル変数の値、およびその他の有用な情報で補強するために、custom loggerを定義するのは簡単です。

Processing log events

例に示されているように、ログステートメントはログイベントがどこに行くのか、またはどのように処理されるのかについて言及していません。これは、システムを構成可能で同時使用に自然なものにする重要な設計機能です。これは、2つの異なる関心事を分離することによって実現されています：

• ログイベントの作成は、イベントがトリガーされる場所と含める情報を決定する必要があるモジュールの著者の関心事です。
• ログイベントの処理 — つまり、表示、フィルタリング、集約、記録 — は、複数のモジュールを協力するアプリケーションに統合する必要があるアプリケーション作成者の関心事です。

Loggers

イベントの処理は logger によって行われ、これはイベントを見る最初のユーザー設定可能なコードです。すべてのロガーは AbstractLogger のサブタイプでなければなりません。

イベントがトリガーされると、適切なロガーはグローバルロガーをフォールバックとして使用し、タスクローカルロガーを探すことで見つけられます。ここでの考え方は、アプリケーションコードがログイベントをどのように処理すべきかを知っており、コールスタックの上部のどこかに存在するということです。したがって、ロガーを発見するためにコールスタックを上に向かって探る必要があります。つまり、ロガーは動的スコープであるべきです。（これは、ロガーが字句的スコープであるロギングフレームワークとの対比のポイントです。モジュールの著者によって明示的に提供されるか、単純なグローバル変数として提供されます。そのようなシステムでは、複数のモジュールから機能を構成しながらロギングを制御するのが難しいです。）

グローバルロガーは global_logger で設定できます。また、タスクローカルロガーは with_logger を使用して制御されます。新しく生成されたタスクは親タスクのロガーを継承します。

ライブラリによって提供されるロガータイプは3つあります。 ConsoleLogger は、REPLを起動したときに表示されるデフォルトのロガーです。これは、イベントを読みやすいテキスト形式で表示し、フォーマットやフィルタリングに対してシンプルでユーザーフレンドリーな制御を提供しようとします。 NullLogger は、必要に応じてすべてのメッセージをドロップする便利な方法です。これは、 devnull ストリームのロギングに相当します。 SimpleLogger は、非常にシンプルなテキストフォーマットのロガーで、主にロギングシステム自体のデバッグに役立ちます。

カスタムロガーは、reference sectionで説明されている関数のオーバーロードを備えている必要があります。

Early filtering and message handling

イベントが発生すると、破棄されるメッセージを生成しないように、いくつかの初期フィルタリングステップが行われます：

1. メッセージログレベルは、グローバル最小レベル（disable_loggingを介して設定）に対してチェックされます。これは粗雑ですが、非常に安価なグローバル設定です。
2. 現在のロガーの状態が調べられ、メッセージレベルがロガーのキャッシュされた最小レベルと照合されます。これは Logging.min_enabled_level を呼び出すことで見つけられます。この動作は環境変数を介してオーバーライドすることができます（この後詳しく説明します）。
3. Logging.shouldlog 関数は、現在のロガーとともに呼び出され、いくつかの最小限の情報（レベル、モジュール、グループ、ID）が静的に計算されます。最も便利なのは、shouldlog にイベント id が渡され、キャッシュされた述語に基づいて早期にイベントを破棄するために使用できることです。

すべてのチェックが通過した場合、メッセージとキー–バリューのペアは完全に評価され、Logging.handle_message 関数を介して現在のロガーに渡されます。 handle_message() は、必要に応じて追加のフィルタリングを行い、イベントを画面に表示したり、ファイルに保存したりします。

ログイベントを生成する際に発生する例外は、デフォルトでキャプチャされ、ログに記録されます。これにより、個々の壊れたイベントがアプリケーションをクラッシュさせるのを防ぎ、運用システムであまり使用されないデバッグイベントを有効にする際に役立ちます。この動作は、Logging.catch_exceptionsを拡張することで、ロガータイプごとにカスタマイズできます。

Testing log events

ログイベントは通常のコードを実行する副作用ですが、特定の情報メッセージや警告をテストしたい場合があるかもしれません。Testモジュールは、ログイベントストリームに対してパターンマッチングを行うために使用できる@test_logsマクロを提供します。

Environment variables

メッセージフィルタリングは、JULIA_DEBUG 環境変数を通じて影響を受けることができ、ファイルやモジュールのデバッグログを有効にする簡単な方法として機能します。JULIA_DEBUG=loading でジュリアをロードすると、loading.jl 内の @debug ログメッセージがアクティブになります。例えば、Linux シェルでは:

$ JULIA_DEBUG=loading julia -e 'using OhMyREPL'
┌ Debug: Rejecting cache file /home/user/.julia/compiled/v0.7/OhMyREPL.ji due to it containing an incompatible cache header
└ @ Base loading.jl:1328
[ Info: Recompiling stale cache file /home/user/.julia/compiled/v0.7/OhMyREPL.ji for module OhMyREPL
┌ Debug: Rejecting cache file /home/user/.julia/compiled/v0.7/Tokenize.ji due to it containing an incompatible cache header
└ @ Base loading.jl:1328
...

Windowsでは、最初に set JULIA_DEBUG="loading" を実行することで CMD で同じことを達成でき、Powershell では $env:JULIA_DEBUG="loading" を使用します。

同様に、環境変数を使用して、Pkgのようなモジュールやモジュールのルートのデバッグログを有効にすることができます（Base.modulerootを参照）。すべてのデバッグログを有効にするには、特別な値allを使用します。

REPLからデバッグログをオンにするには、ENV["JULIA_DEBUG"]を興味のあるモジュールの名前に設定します。REPLで定義された関数はモジュールMainに属しており、それらのログは次のように有効にできます：

julia> foo() = @debug "foo"
foo (generic function with 1 method)

julia> foo()

julia> ENV["JULIA_DEBUG"] = Main
Main

julia> foo()
┌ Debug: foo
└ @ Main REPL[1]:1

複数のモジュールのデバッグを有効にするには、カンマ区切りを使用します: JULIA_DEBUG=loading,Main。

Examples

Example: Writing log events to a file

時には、ログイベントをファイルに書き込むことが役立つ場合があります。以下は、タスクローカルおよびグローバルロガーを使用して情報をテキストファイルに書き込む方法の例です：

# Load the logging module
julia> using Logging

# Open a textfile for writing
julia> io = open("log.txt", "w+")
IOStream(<file log.txt>)

# Create a simple logger
julia> logger = SimpleLogger(io)
SimpleLogger(IOStream(<file log.txt>), Info, Dict{Any,Int64}())

# Log a task-specific message
julia> with_logger(logger) do
           @info("a context specific log message")
       end

# Write all buffered messages to the file
julia> flush(io)

# Set the global logger to logger
julia> global_logger(logger)
SimpleLogger(IOStream(<file log.txt>), Info, Dict{Any,Int64}())

# This message will now also be written to the file
julia> @info("a global log message")

# Close the file
julia> close(io)

Example: Enable debug-level messages

ここに、ConsoleLoggerを作成する例があります。これは、ログレベルがLogging.Debug以上または等しいメッセージを通過させます。

julia> using Logging

# Create a ConsoleLogger that prints any log messages with level >= Debug to stderr
julia> debuglogger = ConsoleLogger(stderr, Logging.Debug)

# Enable debuglogger for a task
julia> with_logger(debuglogger) do
           @debug "a context specific log message"
       end

# Set the global logger
julia> global_logger(debuglogger)

Reference

Logging module

Creating events

@debug message  [key=value | value ...]
@info  message  [key=value | value ...]
@warn  message  [key=value | value ...]
@error message  [key=value | value ...]

@logmsg level message [key=value | value ...]

情報の `message` を持つログ記録を作成します。便利のために、標準の重大度レベル `Debug`、`Info`、`Warn`、`Error` でログを記録するために、4つのロギングマクロ `@debug`、`@info`、`@warn`、`@error` が定義されています。`@logmsg` は、`level` をプログラム的に任意の `LogLevel` またはカスタムログレベルタイプに設定することを可能にします。

`message` は、ログイベントの人間が読み取れる説明である文字列に評価される式である必要があります。慣例として、この文字列は提示されるときにマークダウンとしてフォーマットされます。

オプションの `key=value` ペアのリストは、ログ記録の一部としてログバックエンドに渡される任意のユーザー定義メタデータをサポートします。`value` 式のみが提供される場合、式を表すキーが [`Symbol`](@ref) を使用して生成されます。例えば、`x` は `x=x` になり、`foo(10)` は `Symbol("foo(10)")=foo(10)` になります。キー値ペアのリストをスプラットするには、通常のスプラット構文 `@info "blah" kws...` を使用します。

自動生成されたログデータをオーバーライドするためのいくつかのキーがあります：

  * `_module=mod` は、メッセージのソース位置から異なる発信モジュールを指定するために使用できます。
  * `_group=symbol` は、メッセージグループをオーバーライドするために使用できます（これは通常、ソースファイルのベース名から派生します）。
  * `_id=symbol` は、自動生成された一意のメッセージ識別子をオーバーライドするために使用できます。これは、異なるソース行で生成されたメッセージを非常に密接に関連付ける必要がある場合に便利です。
  * `_file=string` と `_line=integer` は、ログメッセージの明らかなソース位置をオーバーライドするために使用できます。

慣習的な意味を持ついくつかのキー値ペアもあります：

  * `maxlog=integer` は、メッセージが `maxlog` 回以上表示されないようにバックエンドにヒントを与えるために使用されるべきです。
  * `exception=ex` は、ログメッセージと共に例外を輸送するために使用されるべきで、通常は `@error` と共に使用されます。関連するバックトレース `bt` は、タプル `exception=(ex,bt)` を使用して添付できます。

# 例

LogLevel(level)

julia> Logging.LogLevel(0) == Logging.Info
true

デバッグ

情報

Warn

エラー

BelowMinLevel

AboveMaxLevel

Processing events with AbstractLogger

イベント処理は、AbstractLogger に関連付けられた関数をオーバーライドすることによって制御されます:

handle_message(logger, level, message, _module, group, id, file, line; key1=val1, ...)

shouldlog(logger, level, _module, group, id)

min_enabled_level(logger)

catch_exceptions(logger)

disable_logging(level)

Logging.disable_logging(Logging.Info) # デバッグと情報を無効にする

Using Loggers

ロガーのインストールと検査:

global_logger()

global_logger(logger)

with_logger(function, logger)

function test(x)
    @info "x = $x"
end

with_logger(logger) do
    test(1)
    test([1,2])
end

current_logger()

システムに供給されるロガー：

NullLogger()

ConsoleLogger([stream,] min_level=Info; meta_formatter=default_metafmt,
              show_limited=true, right_justify=0)

SimpleLogger([stream,] min_level=Info)