Unreal Insights Interaction with Unreal Engine 5 from a Source Code Perspective

While reading the source code of Unreal Engine 5, I often came across the mysterious UE_TRACE_LOG macro (for example, the use of this macro can be seen in the UE_LOG code). In this article, I would like to explain why the UE_TRACE_LOG macro is needed and how it is related to Unreal Insights.

Unreal Insights

Let's start with what Unreal Insights is.

Unreal Insights is a separate program that collects various useful information as the game progresses and structures it. For example, in Unreal Insights you can see the number of frames at different points in time, memory consumption, network performance, etc.

UE_TRACE_EVENT

Trace event is some structure that contains fields of type TField (1*). They are used to understand how much memory is required to store the types of data for which the TField is created in some buffer, and also to implement the FieldName method, in which the Impl function of the FFieldSet class is called. (2*).

In general, the Trace event specifies the total size of the specified data types to be stored in some buffer, and also controls in what order exactly this data should be placed in the buffer.

Trace Event Announcement:

To declare a Trace event, you need to call two macros: UE_TRACE_EVENT_BEGIN and UE_TRACE_EVENT_END; and insert one or more UE_TRACE_EVENT_FIELD macros between them.

The UE_TRACE_EVENT_BEGIN(LoggerName, EventName, …) macro declares a structure of the F##LoggerName##EventName##Fields (3*) type, which is the Trace event itself.
Macro UE_TRACE_EVENT_FIELD(FieldType, FieldName) adds a new field of type TField to Trace event.
The UE_TRACE_EVENT_END() macro serves as the end of the declaration of the F##LoggerName##EventName##Fields structure.

Example of Trace event declaration:

UE_TRACE_EVENT_BEGIN(Logging, LogMessageSpec, NoSync|Important)
	UE_TRACE_EVENT_FIELD(const void*, LogPoint)
	UE_TRACE_EVENT_FIELD(const void*, CategoryPointer)
	UE_TRACE_EVENT_FIELD(int32, Line)
	UE_TRACE_EVENT_FIELD(uint8, Verbosity)
	UE_TRACE_EVENT_FIELD(UE::Trace::AnsiString, FileName)
	UE_TRACE_EVENT_FIELD(UE::Trace::WideString, FormatString)
UE_TRACE_EVENT_END()

In summary, the purpose of the F##LoggerName##EventName##Fields structure is to store fields of the TField type, which in turn store information about a certain type (selected by us by the UE_TRACE_EVENT_FIELD macro).

To write values of a certain type to the buffer, you need to call functions named FieldName (we pass the FieldName parameter to the UE_TRACE_EVENT_FIELD macro when declaring the Trace event), and pass some values to them. It is important to understand that you need to call these functions in the same order in which the TField fields are located in the Trace event (from top to bottom).

The trace event is not used directly for storing data.

(1*) TField is a structure that has defined Index, Offset and Size fields (which are set depending on the type passed to this structure). These fields are used in one way or another when writing data to the buffer via the Impl function.

For example, one specialization of the FFieldSet structure uses the Offset field to offset the buffer pointer when writing:

template <typename FieldMeta, typename Type>
struct FLogScope::FFieldSet
{
	static void Impl(FLogScope* Scope, const Type& Value)
	{
		uint8* Dest = (uint8*)(Scope->Ptr) + FieldMeta::Offset;
		::memcpy(Dest, &Value, sizeof(Type));
	}
};

Here TField is passed as a template type to FieldMeta.

(2*) FFieldSet is a structure that contains the Impl method, which is used to say how exactly a particular type of data should be written to the buffer. That is, depending on the specific data type, FFieldSet may have a certain specialization. Accordingly, the Impl method will differ.

Implementation of the standard FFieldSet structure, where the Impl method performs the usual copying of data into the buffer via the memcpy function:

template <typename FieldMeta, typename Type>
struct FLogScope::FFieldSet
{
	static void Impl(FLogScope* Scope, const Type& Value)
	{
		uint8* Dest = (uint8*)(Scope->Ptr) + FieldMeta::Offset;
		::memcpy(Dest, &Value, sizeof(Type));
	}
};

(3*) The full code of the F##LoggerName##EventName##Fields structure:

struct F##LoggerName##EventName##Fields \
	{ \
		enum \
		{ \
			Important			= UE::Trace::Private::FEventInfo::Flag_Important, \
			NoSync				= UE::Trace::Private::FEventInfo::Flag_NoSync, \
			Definition8bit		= UE::Trace::Private::FEventInfo::Flag_Definition8, \
			Definition16bit		= UE::Trace::Private::FEventInfo::Flag_Definition16, \
			Definition32bit		= UE::Trace::Private::FEventInfo::Flag_Definition32, \
			Definition64bit		= UE::Trace::Private::FEventInfo::Flag_Definition64, \
			DefinitionBits		= UE::Trace::Private::FEventInfo::DefinitionBits, \
			PartialEventFlags	= (0, ##__VA_ARGS__), \
		}; \
		enum : bool { bIsImportant = ((0, ##__VA_ARGS__) & Important) != 0, bIsDefinition = ((0, ##__VA_ARGS__) & DefinitionBits) != 0,\
		bIsDefinition8 = ((0, ##__VA_ARGS__) & Definition8bit) != 0, \
		bIsDefinition16 = ((0, ##__VA_ARGS__) & Definition16bit) != 0,\
		bIsDefinition32 = ((0, ##__VA_ARGS__) & Definition32bit) != 0, \
		bIsDefinition64 = ((0, ##__VA_ARGS__) & Definition64bit) != 0,}; \
		typedef std::conditional_t<bIsDefinition8, UE::Trace::FEventRef8, std::conditional_t<bIsDefinition16, UE::Trace::FEventRef16 , std::conditional_t<bIsDefinition64, UE::Trace::FEventRef64, UE::Trace::FEventRef32>>> DefinitionType;\
		static constexpr uint32 GetSize() { return EventProps_Meta::Size; } \ - сумма размеров всех типов полей TField (то есть сумма типов, которые хранит TField).
		static uint32 TSAN_SAFE GetUid() { static uint32 Uid = 0; return (Uid = Uid ? Uid : Initialize()); } \ - ID данного инвента
		static uint32 FORCENOINLINE Initialize() \ генерирует ID для нашего ивента и определяет информацию о ивенте (UE::Trace::Private::FEventInfo Info), а так же вписывает инфу и ID в экземпляр FEventNode.
		{ \
			static const uint32 Uid_ThreadSafeInit = [] () \
			{ \
				using namespace UE::Trace; \
				static F##LoggerName##EventName##Fields Fields; \
				static UE::Trace::Private::FEventInfo Info = \
				{ \
					FLiteralName(#LoggerName), \
					FLiteralName(#EventName), \
					(FFieldDesc*)(&Fields), \
					EventProps_Meta::NumFields, \
					uint16(EventFlags), \
				}; \
				return LoggerName##EventName##Event.Initialize(&Info); \
			}(); \
			return Uid_ThreadSafeInit; \
		} \
		typedef UE::Trace::TField<0 /*Index*/, 0 /*Offset*/,

Macro code UE_TRACE_EVENT_FIELD:

#define TRACE_PRIVATE_EVENT_FIELD(FieldType, FieldName) \
		FieldType> FieldName##_Meta; \
		FieldName##_Meta const FieldName##_Field = UE::Trace::FLiteralName(#FieldName); \
		template <typename... Ts> auto FieldName(Ts... ts) const { \
			LogScopeType::FFieldSet<FieldName##_Meta, FieldType>::Impl((LogScopeType*)this, Forward<Ts>(ts)...); \ - информация записывается поверх полей TField.
			return true; \
		} \
		typedef UE::Trace::TField< \
			FieldName##_Meta::Index + 1, \
			FieldName##_Meta::Offset + FieldName##_Meta::Size,

As you can see, the UE_TRACE_EVENT_FIELD macro extends the F##LoggerName##EventName##Fields structure, thereby declaring a new TField.

UE_TRACE_LOG

A macro that logs our event (writes the information we enter via the << operator into some buffer. This buffer is eventually passed to Unreal Insights).

Example of using UE_TRACE_LOG:

UE_TRACE_LOG(Logging, LogCategory, LogChannel, NameLen * sizeof(ANSICHAR))
		<< LogCategory.CategoryPointer(Category)
		<< LogCategory.DefaultVerbosity(DefaultVerbosity)
		<< LogCategory.Name(Name, NameLen);

The Logging and LogCategory parameters are attributes of the F##LoggerName##EventName##Fields structure. The LogChannel parameter is also an “instance” of the F##LoggerName##EventName##Fields structure. The last parameter NameLen * sizeof(ANSICHAR) is the size that must be allocated in the buffer to store the transferred data.

Hidden text

Full code of UE_TRACE_LOG:

#define UE_TRACE_LOG(LoggerName, EventName, ChannelsExpr, ...) \
	TRACE_PRIVATE_LOG_PRELUDE(Enter, LoggerName, EventName, ChannelsExpr, ##__VA_ARGS__) \
		TRACE_PRIVATE_LOG_EPILOG()

Full code of TRACE_PRIVATE_LOG_PRELUDE:

#define TRACE_PRIVATE_LOG_PRELUDE(EnterFunc, LoggerName, EventName, ChannelsExpr, ...) \
	if (TRACE_PRIVATE_CHANNELEXPR_IS_ENABLED(ChannelsExpr)) \
		if (auto LogScope = F##LoggerName##EventName##Fields::LogScopeType::EnterFunc<F##LoggerName##EventName##Fields>(__VA_ARGS__)) \ - создание экземпляра класса FLogScope, который будет хранить всю вносимую информацию нашего ивента.
			if (const auto& __restrict EventName = *UE_LAUNDER((F##LoggerName##EventName##Fields*)(&LogScope))) \ - получаем указатель на начало буффера и читаем его как структуру F##LoggerName##EventName##Fields(ивент), для того чтобы инициализировать память буффера нашими значениями (тут важно сказать, что мы не инициализируем объект F##LoggerName##EventName##Fields, так как он тут и не нужен. Мы просто пользуемся его функционалом для выделения памяти)
				((void)EventName), - возможно некоторые компиляторы выдают сообщение о неиспользованной переменной => кастим EventName к void, чтобы предупреждения не выдавало

Full code of TRACE_PRIVATE_LOG_EPILOG:

#define TRACE_PRIVATE_LOG_EPILOG() \
	LogScope += LogScope - оператор+=: сохранение указателя на буффер в некоторое хранилище для того чтобы в дальнейшем иметь в нему доступ.

FLogScope

FLogScope is a class that stores some buffer. FLogScope also has tools for writing various data to this buffer (via overloads of the += and << operators).

Operator <<:

const FLogScope&	operator << (bool) const	{ return *this; }

Operator +=:

template <bool bMaybeHasAux>
inline void TLogScope<bMaybeHasAux>::operator += (const FLogScope&) const
{
	if constexpr (bMaybeHasAux)
	{
		FWriteBuffer* LatestBuffer = Writer_GetBuffer();
		LatestBuffer->Cursor[0] = uint8(EKnownEventUids::AuxDataTerminal << EKnownEventUids::_UidShift);
		LatestBuffer->Cursor++;

		Commit(LatestBuffer);
	}
	else
	{
		Commit();
	}
}

The Commit method, in turn, simply assigns the Commited field of the buffer the desired address in memory (where the data was unloaded: namely the Cursor field of the buffer).

In the future, Unreal Insights will refer specifically to the Commited field (the Commited field is also marked with the volatile keyword).

Results

That is, first we write information to the buffer of the right LogScope (operator<<) (it will also be displayed for the left LogScope, since when passed to the operator+=, the LogScope is not copied), and then this information is saved in the buffer of this LogScope.

It is also worth mentioning here that before recording the main information in FLogScope, information about the ID of the current Trace event and the size of the filled packet (current buffer) is first recorded. That is, it is by the transmitted ID of the Trace event that Unreal Insights understands in which tab (Log, Frame, …) to include the information coming from memory.