ランタイムトレース¶
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)。