ランタイムトレース¶
Crystalランタイムには、低レベル機能のためのトレース機能があります。ランタイム内部に関する診断情報を表示します。
トレースをサポートするには、プログラムを-Dtracing
フラグでビルドする必要があります。実行時には、環境変数CRYSTAL_TRACE
を使用して、個々のトレースコンポーネントを有効にすることができます。コンマ区切りのセクションリストを受け取ります。
CRYSTAL_TRACE=none
トレースを無効にする(デフォルト)CRYSTAL_TRACE=gc
: ガベージコレクタのトレースを有効にするCRYSTAL_TRACE=sched
: スケジューラのトレースを有効にするCRYSTAL_TRACE=gc,sched
: ガベージコレクタとスケジューラのトレースを有効にするCRYSTAL_TRACE=all
すべてのトレースを有効にする(gc,sched
と同等)
例
$ crystal build -Dtracing hello-world.cr
$ CRYSTAL_TRACE=sched ./hello-world
sched.spawn 70569399740240 thread=0x7f48d7dc9740:? fiber=0x7f48d7cd0f00:main fiber=0x7f48d7cd0dc0:Signal Loop
sched.enqueue 70569399831716 thread=0x7f48d7dc9740:? fiber=0x7f48d7cd0f00:main fiber=0x7f48d7cd0dc0:Signal Loop duration=163
Hello World
トレースはデフォルトで標準エラー出力に出力されます。これは、実行時にCRYSTAL_TRACE_FILE
環境変数を使用して変更できます。
たとえば、CRYSTAL_TRACE_FILE=trace.log
は、すべてのトレース出力をtrace.log
ファイルに出力します。
トレース形式¶
各トレースエントリは1行にあり、改行で終了し、最大512バイトです。
各エントリは、セクション名と操作名がドットで区切られた識別子(例:gc.malloc
)で始まります。次に、ナノ秒単位の整数で表されるタイムスタンプが続きます。最後に、key=value
形式のメタデータプロパティのリストがスペースで区切られます。
最初の2つのプロパティは常に発信元のthread
とfiber
です。どちらもIDと名前で区切られています(例:0x7f48d7cd0f00:main
)。
- スレッドIDはOSハンドルであるため、たとえばデバッガセッションにスレッドを一致させることができます。
- ファイバーIDはCrystalランタイムの内部アドレスです。名前はオプションであり、必ずしも一意ではありません。
ランタイムの起動初期のトレース項目には、ファイバーメタデータとスレッド名が欠けている場合があります。
特定のトレースエントリによっては、さらにメタデータプロパティが続く場合があります。
たとえば、gc.malloc
は、どのくらいのメモリが割り当てられているかを示します。
報告された値は、通常、次のセマンティクスを持つ整数として表されます。
- 時間と期間は、オペレーティングシステムの単調時計によるナノ秒単位です(例:
123
は123ns
、5000000000
は5s
)。 - メモリサイズはバイト単位です(例:
1024
は1KB
)。