언리얼 엔진 5 문서가 에픽 디벨로퍼 커뮤니티로 이전되었습니다

Trace is a structured logging framework for tracing instrumentation events from a running process. The framework is designed to produce a stream of high-frequency traced events that is self-describing and easily consumed and easily shared. The modules TraceLog and TraceAnalysis are the principal modules that constitute the framework. Unreal Insights is Trace's primary customer.

A Tour of Trace

Events

The complete system is composed of elements that form a pipeline from emission at runtime through to later consumption during analysis. The first of which is a trace event which are defined as follows.

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

The EventName and FieldName parameters should hopefully be self-explanatory. Events are grouped by "loggers", a semantic-only concept that helps to namespace events and ease subscription when analyzing a trace stream. The optional Flags modify how events are traced.

Field types can be the standard integer or floating-point primitives (for example, uint32, float, etc.), as well as arrays and strings (see below for more information on the latter two). There is no support for nested structures/events as fields.

Events are usually defined at a global scope in a .cpp file. If events need to be traced from multiple translation units the UE_TRACE_EVENT_BEGIN_[EXTERN|DEFINE] pair can be used.

The logging of an event at runtime is done like this:

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

Provided the channel "ItvChannel" is enabled this will add a "RainbowLogger.ZippyEvent" event to the trace stream. Care should be taken when assigning values to fields such that they have no side effects, ones that trace additional events in particular as a log site is not reentrant.

There is no delta or run-length compression happening when events are traced. All defined fields are present too even if they were not written to at a particular UE_TRACE_LOG() call. A traced event is essentially analogous to a #pragma pack(1) -declared struct. It is advisable to think strategically as to how those bits are used to their fullest.

Side note; The thought process behind the use of a macro-soup was two fold; to hide a lot of boilerplate behind simple where details like offsets are known at compile time, and secondly so that definitions and log sites compile to nothing when Trace is off without littering #if/end everywhere.

Channels

In order to constrain the stream of events to what the user is interested in there is the concept of channels. This helps to focus CPU and memory resources on what is important to the observations being made. Channels are easily defined like this:

UE_TRACE_CHANNEL(ItvChannel);

There is a EXTERN/DEFINE pair for more specific use cases. By default channels are disabled and must be explicitly opted into either via the -trace=itv command line option or the Trace::ToggleChannel() API.

Channels override the bitwise OR operator such that they can be combined with log sites to control the tracing of an event with multiple channels. A UE_TRACE_LOG(..., ItvChannel|BbcChannel) will only emit an event if both the "Itv" and "Bbc" channels are enabled. The astute reader will notice that this is, somewhat confusingly, the opposite of what one might expect from a bitwise OR.

Analysis

Now that we have defined a new event, added enabled the channel(s) they're keyed off, and added a log site or two, we will want to consume and analyze the events. This is done using the TraceAnalysis module.

Analyzers are created by deriving from IAnalyzer and implementing two primary methods; the OnAnalysisBegin() to subscribe to events, and OnEvent() to receive those subscriptions.

When analysis encounters an event that the analyzer has subscribed to the analyzer's OnEvent() method is called. Access to the event's data is done via FEventContext.EventData.Get*() methods. This API reflects the self-describing nature of trace streams — there is no binary or runtime-code dependency on interpreting trace streams. Each received event also has associated thread information and (in some very rare circumstances) some timing information.

Running analysis on a trace session is straightforward by describing the analyzers to use and feeding the created analysis session the trace data.

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

Recorder/Store

• async-io
  

• optional

Runtime Details

Normal Events

• tls

  • fixed size buffers, linked list

• synchronised, nosync opt-out

Important Events

• shared buffer

• collected by worker thread

• cached, lz4 compressed

Worker Thread

A worker thread is used to collect traced events from the TLS and shared buffering schemes, compress and cache important events, handle command-control communications, and manage the destination IO (socket or file). This runs at a fixed interval and is a free thread (for example, not a job or task kicked as part of the engine's loop).

In some cases it may not be suitable to have trace events consumed and dispatched by a worker thread (i.e. forking on Linux). This can be opted-out of bUseWorkerThread during initialization which defaults to the value returned from FPlatformProcess::SupportsMultithreading() . When disabled it is the user's responsibility to update trace so that events are consumed with Trace::Update() . Note that lower frequency updates will result in higher memory use buffering traced events. Ordinarily this is all taken care of by Core's TraceAuxiliary.

Transport

• wire, port 1980

• file

Command-control/Late-connect

• command/control on port 1985

Miscellaneous

Arrays

Attachments

In the early days of trace there was no support for variable length fields. A concept of attachments was introduced where opaque binary blobs could be appended to traced events. The use of attachments is discouraged — array-type fields should be used instead which benefit from being structured and reflected at analysis time. Furthermore, attachment support incurs a cost that every logged event has to pay so it is possible that it may be changed to be an opt-in component in the future to optimize away this overhead.

Strings

Trace events support string-type fields using the Trace::AnsiString or Trace::WideString types when declaring events' fields with UE_TRACE_EVENT_FIELD() .

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

String-type fields are written much the same as primitive-type fields, with a few additional extras; ASCII-type fields will automatically truncate wide strings to 7-bit characters, and an optional string length can be given (preferable for performance if string length is already known).

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

Limitations

The trace system is global and can only trace to one thing at once. Because some tools available in the editor are now using the trace system, the editor no longer automatically connects to and traces to a running Unreal Insights. If you wish to profile the editor the -tracehost=127.0.0.1 argument must be given when starting the editor (or possibly the trace.start in-editor depending on a project's plugins).

Unreal Engine 4 Notes

Some of the events traced are one-shots — they are only ever traced once. This is common to assign IDs to names, CPU events' names for example. Unfortunately this makes it impossible to stop tracing and later restart it as contextual information from trace-once events is lost. A common indicator of this scenario are "unknown" CPU events or threads in Unreal Insights. The trace.stop is in fact not really a stop but a disablement of channels as a mitigation to this limitation. Future versions of the engine have a concept of "Important Events". One-time events are cached and resent them when a trace connection is established, thus seamlessly supporting drop-in/out profiling workflows.