トレース

Trace は、実行中のプロセスからインストルメンテーション イベントをトレースするための構造化されたログ フレームワークです。

Choose your operating system:

Windows

macOS

Linux

Trace は、実行中のプロセスからインストルメンテーション イベントをトレースするための構造化されたログ フレームワークです。このフレームワークは、高頻度でトレースされるイベントのストリームを生成するように設計されおり、自己記述型で、簡単に消費して、簡単に共有できます。TraceLog および TraceAnalysis は、このフレームワークの主要な構成モジュールです。Trace は、Unreal Insights で主に利用されています。

Trace の概要

イベント

この完全なシステムは、ランタイム時の発行からその後の解析中の消費までのパイプラインを形成する要素で構成されています。最初の要素は、以下のように定義されるトレース イベントです。

UE_TRACE_EVENT_BEGIN(LoggerName, EventName[, Flags])
    UE_TRACE_EVENT_FIELD(Type, FieldName)
UE_TRACE_EVENT_END()

EventName パラメータおよび FieldName パラメータの内容は明白であるため、説明の必要はないでしょう。イベントは "loggers"(ロガー) によってグループ化されています。これはセマンティックのみの概念で、イベントの名前空間を作成し、トレース ストリームを分析する際のサブスクリプションを容易にします。オプションの Flags は、イベントのトレース方法を変更します。

イベント マーク

説明

NoSync

デフォルトでは、イベントは他のスレッドでトレースされているイベントと同期されます。"NoSync"(同期なし) とマークされているイベントはこの同期をスキップします。分析時に他のスレッドとの一貫性が失われますが、サイズを抑えて、より迅速にトレースすることができます。

Important

一部のイベントは、一度のみ送信され、後続のトレース イベントを解釈するために必要になります (例えば、名前を識別された整数にマッピングするなど)。このようなイベントは "important"(重要) とマークされており、保持して、後で再送することができます。

これは、Unreal Engine 5 向けです。

フィールド型には、標準の整数型または浮動小数点プリミティブ型 (uint32、float など) のほか、配列型や文字列型を使用できます (配列や文字列については後述します)。フィールドとしてネストされた構造体/イベントはサポートされていません。

イベントは、通常、.cpp ファイルのグローバル スコープで定義されます。複数の翻訳ユニットからイベントをトレースする必要がある場合は、 UE_TRACE_EVENT_BEGIN_[EXTERN|DEFINE] ペアを使用することができます。

ランタイム時のイベントのログは、次のように実行されます。

UE_TRACE_LOG(RainbowLogger, ZippyEvent, ItvChannel)
    << ZippyEvent.Field0(Value0)
    << ZippyEvent.Field1(BundleValue)
    << ZippyEvent.Field2(Data, Num);
    << ZippyEvent.Field3(String[, Num]);

チャンネル "ItvChannel" が有効になっている場合、トレース ストリームに "RainbowLogger.ZippyEvent" イベントが追加されます。フィールドに値を割り当てる際には、特にログ サイトが再入可能ではないため、追加のイベントをトレースするなどの、サイド エフェクトがないように注意してください。

イベントがトレースされる際は、差分圧縮や連長圧縮は行われません。特定の UE_TRACE_LOG() 呼び出しで書き込まれていない場合でも、定義されたフィールドはすべて存在します。トレースされたイベントは本質的に #pragma pack(1) で宣言された構造体に似ています。これらのビットを最大限活用する方法を戦略的に考えることをお勧めします。

なお、マクロスープの使用の基盤となる考え方には 2 通りあります。1 つは、コンパイル時にオフセットなどの詳細が判明している単純なものの背後に多くの定型文を隠ぺいすることです。もう 1 つは、Trace がオフの時に #if/end をあちこちに指定することなく、定義やログ サイトがコンパイルを行っても何も得られないようにすることです。

チャンネル

チャンネルという概念は、イベントのストリームをユーザーが興味を持っているものに制限するために存在します。これは、CPU およびメモリのリソースを、実行中の観察に重要なものに集中させるのに役立ちます。チャネルは次のように簡単に定義できます。

UE_TRACE_CHANNEL(ItvChannel);

より具体的なユースケース向けには EXTERN/DEFINE ペアがあります。デフォルトでは、チャンネルは無効になっており、 -trace=itv コマンド ライン オプションか Trace::ToggleChannel() API を使用して明示的に選択する必要があります。

チャンネルは、ログ サイトと組み合わせて複数のチャンネルでイベントのトレースを制御できるように、ビット単位の OR 演算子をオーバーライドします。 UE_TRACE_LOG(..., ItvChannel|BbcChannel) は、"Itv" と "Bbc" の両方のチャンネルが有効になっている場合にのみイベントを発生させます。するどい方は、少し混乱するかもしれません。これは、ビット演算 OR に求められている処理とは反対の処理であるためです。

分析

新しいイベントを定義し、チャンネル追加して、有効にし、チャンネルのキーをオフにして、1 つまたは 2 つのログ サイトを追加したので、イベントを消費して分析したいと思います。これは TraceAnalysis モジュールを使用して実行されています。

アナライザーは、 IAnalyzer から派生して、2 つの主要なメソッド (イベントをサブスクライブする OnAnalysisBegin() およびそのサブスクリプションを受信する OnEvent() ) を実装することで作成されます。

分析で、アナライザーがサブスクライブしたイベントが発生すると、アナライザーの OnEvent() メソッドが呼び出されます。イベントのデータへのアクセスは、 FEventContext.EventData.Get*() メソッドを使用して行います。この API はトレース ストリームの自己記述型の性質、すなわち、トレース ストリームの解釈をバイナリやランタイムコードに依存しないという性質を反映しています。受信した各イベントは、関連付けられているスレッド情報と (非常にまれな状況では) 複数のタイミング情報も含んでいます。

トレース セッションでの分析の実行は、使用するアナライザーを記述し、作成された分析セッションにトレース データを供給することで、簡単に行えます。

struct :IInDataStream { ... } TraceData;
FGeorgeAnalyzer GeorgeAnalyzer;
FAnalysisContext Context;
Context.AddAnalyzer(GeorgeAnalyzer);
FAnalysisProcessor Processor = Context.Process(TraceData)
Processor.Wait();

システム ID は使用可能であるものの、重要なスレッド ID はシステム スレッド ID とまったく同じではありません。これは、OS がスレッド ID を再利用する可能性がある場合における処理をより確実に防ぐためです。そのため、システム ID は特定のスレッドから次のスレッドへと再利用されることを前提としてください。トレースの ID はこのように再利用されないか、少なくともその可能性はかなり低くなります。

レコーダー / ストア

TraceAnalysis モジュールは、トレース データを受信、格納、取得するための 1 つのサービスを形成する 2 つのコンポーネントで構成されています。実装では非同期 IO を使用しているため、多くのクライアント (主にインバウンドのトレース データ) に簡単に拡張することができます。ストアを設定して実行するのも次のように、簡単に行えます。

FStoreService::FDesc Desc = {
    StoreDir,     /* directory path on disk */
    RecorderPort, /* -1=off, 0=auto-assign */
    1,            /* No. of IOCP threads */
};
auto Store = TUniquePtr<FStoreService>(FStoreService::Create(Desc));

Recorder (レコーダー) は、トレース受信用の TCP ポートをリッスンします。ランタイムがレコーダーに接続すると、レコーダーはストアで新しいトレースを作成して、受信したデータをこの新しいトレースに中継し始めます。デフォルトではポート 1980 が使用されます。ただし、短いポートを割り当てるように OS に求めることもできます。

ストアの主な役割は、トレースのディレクトリを管理することです。ディレクトリを管理することにより、トレースの新規作成、利用可能なトレースの列挙、特定のトレースのデータの取得を行うことができます。ストアと通信するために構築された REST ライクなプロトコルがあります。このプロトコルは相互運用性を実現するため CBOR に基づいています。 FStoreClient は、このプロトコルの実装です。

const auto* Store = GetWellKnownTraceStoreServer();
if (auto Client = FStoreClient::Connect(Store->Ip, Store->Port))
{
    for (int i = 0, n = Client.GetTraceCount(); i < n; ++i)
    {
        const auto* Info = Client.GetTraceInfo(i);
        /* ... */
    }
}

recorder-store コンポーネントは当然ながらオプションです。ファイルへのトレースをランタイムに求めることができます。場合によっては、Python でレコーダーのようなスクリプトを記述して、ソケット経由でトレース データを受け取る方が便利なことがあります。

ランタイムの詳細

通常のイベント

イベントが UE_TRACE_LOG() サイトでトレースされると、小さなヘッダとイベントのフィールドの値が現在のスレッドのローカル バッファに書き込まれます。これらの TLS バッファは適度にサイズ設定され、1 つのリストにまとめてリンクされています。Trace のワーカー スレッドはバッファのリストをトラバースし、コミットされたイベント データを送信します (そのため、完璧かつ完全に参照可能です)。

TLS を使用するメリットは、トレースしているスレッド同士が互いを阻害しない点です。ほぼ阻害することはありません。スレッド間の順序は、一部のイベント タイプでは重要で、トレース データの解析時に再構築する必要があります (アドレスの再利用が可能な割り当てイベントやフリー イベントなど)。トレースでは、同期化のためにアトミックに増分する整数、すなわち、各イベントの先頭に付いている 24 ビットのシリアル番号を使用します。当然ながら、これには負荷が伴うため、オプトアウトできます。すべてのイベント タイプは同期化をオプトアウトすることが理想です (ただし、多くの場合、TSC の読み取りを犠牲にすることはできません!)。

重要なイベント

これは、Unreal Engine 5 向けです。

"Important" という名称のイベント タイプの追加クラスが UE5 で導入されました。このタイプのイベントは、一度だけトレースされるイベントですが、(通常) 他の後続のトレース データの解釈に必要です。Important イベントは他とは異なる処理が必要です。これは、見落されがちであるためです (ランタイムのトレース データの接続を解除して、再接続する場合、Important イベントは両方のトレース データ ストリームに存在する必要があるものの、最初のストリームでしかトレースされなかったなど)。

Important タイプのイベントは、すべてのスレッドで共有される単一のバッファに書き込まれます。これには 2 つ理由があります。1 つ目の理由は、Important タイプのイベントは、トレースされたデータを解釈したり、分離する必要がなく複雑でないため、通常のイベントとは異なるためです。2 つ目の理由は、トレースされた Important イベントの総数は限りがある必要があるため、メモリ使用量を抑えるのに役立つためです。

Trace (トレース) のワーカー スレッドは、コミットされたデータの共有バッファをポーリングし、一時的に格納するリザーバ バッファにその共有バッファコピーします。Important イベントのリザーバが満杯になると、データは LZ4 形式で圧縮されキャッシュに格納されます。このキャッシュは、トレース データに新しい接続が確立されるたびに送信されます。この処理により、Important イベントが失われず、ストリームの先頭に確実に配置できます。

なお、Important イベントは、スレッド関連のコンテキストがすべて失われているため、解析時には関連するスレッド情報がまったくありません。

ワーカー スレッド

ワーカー スレッドは、TLS や共有バッファリング スキームからトレースされたイベントを収集したり、重要イベントを圧縮してキャッシュしたり、コマンド制御通信を処理したり、宛先 IO (ソケットやファイル) を管理したりするために使用されます。これは、一定の間隔で実行され、フリー スレッド (例: エンジンのループの一部として開始されるジョブやタスクではないスレッド) です。

場合によっては、ワーカー スレッドでトレース イベントを消費してディスパッチさせる (つまり、Linux でのフォーク) のが適切ではない場合があります。これは、初期化時に bUseWorkerThread をオプトアウトすることができます。これは、デフォルトで FPlatformProcess::SupportsMultithreading() から返された値になります。無効になっている場合、 Trace::Update() でイベントが消費されるようにトレースを更新するのは、ユーザーが行う必要があります。なお、更新が頻繁でない場合、トレースされたイベントをバッファリングするためのメモリ使用量が増大するので注意してください。通常、これはすべて Core の TraceAuxiliary によって処理されます。

Transport (トランスポート)

トレースデータは "Transport" という名称のパケットで送信されます。各パケットには、イベントがどのスレッドに由来するかを示す内部識別子 (Important イベントの場合は 0) とサイズがプレフィックスとして付いています。ほとんどのパケットは LZ4 形式で圧縮されています。ただし、この記式で圧縮されていない場合は、容量が小さすぎて LZ4 形式で圧縮してもメリットがありません。

これらのパケットは、ランタイムによって 2 つの場所のいずれかに送信されます。つまり、 -tracefile= 引数を指定するかまたは`Trace::WriteTo() でプロシージャルにファイルに送信されるか、または TCP ソケット経由で ( -tracehost= / Trace::SendTo()`) ホストに送信されます。デフォルトの TCP ポートは 1980 です。

トレース ストリームの先頭には、非構造化メタデータのブロックとともに送信されるハンドシェイク データの小さなブロックがあります。

Command-Control (コマンドコントロール) および Late-connect (遅延接続)

Unreal Insights などのツールでは、データを受信しているトレース システムを制御する必要がある場合があります。このために、ランタイムは初歩的なコマンド/コントロール サーバーを実行します。これはほぼ Trace:: パブリック API を反映しています。TraceAnalysis には、通信を容易に実行できるようにするための次のような単純なクラスがあります。

FControlClient ControlClient;
if (ControlClient.Connect(Bungle.GetHostName())
{
    ControlClient.SendToggleChannel(L"ItvChannel", true);
    ControlClient.SendWriteTo(L"X:/Rainbow.utrace");
}

このシンプルなサーバーは、ポート 1985 をリッスンします。これは、1985 といえば、名作映画『バック・トゥ・ザ・フューチャー』が公開された年だからです。なお、デフォルト ポートが利用できない場合には、ポートをホップできます。ポート番号は、ストリームのハンドシェイクに続くメタデータに埋め込まれています (TraceAnalysis のレコーダーからアクセスできる)。

ポートは (少なくともデフォルトでは) 既知の値であるため、実行中のタイトルに遅延接続し、任意の場所でデータのトレースを開始するように指示することができます。この処理は遅延接続として知られています。

その他

配列

アタッチメント

トレースでは当初、可変長フィールドはサポートされていませんでした。不透明型のバイナリ ブロブをトレースされたイベントに追加することができるアタッチメントの概念が導入されました。アタッチメントの使用は推奨されていません。代わりに、解析時に構造化および反映される利点のある配列型のフィールドを使用してください。さらに、アタッチメントのサポートは、すべてのログされたイベントで負荷が生じるため、このオーバーヘッドを最適化するために、将来的にはオプトイン コンポーネントに変更される可能性があります。

文字列

トレース イベントでは、 UE_TRACE_EVENT_FIELD() でイベント フィールドを宣言する際に、 Trace::AnsiString 型または Trace::WideString 型を使用する文字列型フィールドをサポートしています。

UE_TRACE_EVENT_BEGIN(MyLogger, MyEvent)
    UE_TRACE_EVENT_FIELD(Trace::AnsiString, MyFieldA)
    UE_TRACE_EVENT_FIELD(Trace::WideString, MyFieldW)
UE_TRACE_EVENT_END()

文字列型フィールドはプリミティブ型フィールドとほぼ同じように記述されます。ただし、いくつかの追加要素があります。ASCII 型フィールドはワイド文字列を自動的に 7 ビット文字に切り捨て、オプションで文字列長を指定することができます (文字列長が既知である方がパフォーマンスのために望ましい) ます。

UE_TRACE_LOG(MyLogger, MyEvent)
    << MyFieldA(AnAnsiBuffer, [, ExplicitStringLen])
    << MyFieldW(WideName)

制限事項

トレース システムはグローバルであり、一度に 1 つの要素しかトレースできません。エディタで利用できるツールの一部がトレース システムを使用するようになったため、エディタが Unreal Insights の実行中に自動的に接続してトレースすることはなくなりました。エディタをプロファイリングする場合は、エディタ (または、プロジェクトのプラグインによっては trace.start インエディタの場合もある) の起動時に -tracehost=127.0.0.1 引数を指定する必要があります。

Unreal Engine 4 に関する注意事項

トレースされるイベントには、ワンショット イベントもあります。ワンショット イベントは一度のみトレースされます。これは、CPU イベントの名前など、名前に ID を割り当てるのが一般的です。残念ながら、このことにより、トレースを停止して後で再開することができなくなります。これは、一度しかトレースされないイベントのコンテキスト情報は失われるためです。このシナリオでは、一般的なインジケーターは、Unreal Insights の "unknown"(不明な) CPU イベントやスレッドとなります。この制限を緩和するため、 trace.stop は、実際には、チャンネルを停止ではなく、無効にしています。エンジンの今後のバージョンでは、"Important Events" (重要イベント) という概念が導入されます。ワンタイム イベントはキャッシュされ、トレース接続が確立されると再送信されるため、ドロップ イン/アウトのプロファイリング ワークフローをシームレスにサポートします。

Unreal Engine のドキュメントを改善するために協力をお願いします!どのような改善を望んでいるかご意見をお聞かせください。
調査に参加する
閉じる