Unreal Engine 5 Documentation has been moved to the Epic Developer Community

While cooking a project, Unreal Engine 4 creates a number of detailed logs. One of these is the Stats.csv file. This document details how to read this file to hunt down cooking performance issues.

Reading the Log

When you cook your project, statistics are always created. You can find them saved into:

<projectdirectory>\Saved\Stats

The Stats.csv file contains a number of lines each with a set of comma separated values. The first value is a unique key which describes that line. Which, is followed by a tag that can have a value associated with it, using a '=' to separate. Example:

DDCTransactionId2154470643B07308C1979DA468F3EA48_0,StartTime=2015.07.14-17.09.19

The key is the first parameter, so in this example, this is the first parameter:

DDCTransactionId2154470643B07308C1979DA468F3EA48_0

And the first tag is:

StartTime=2015.07.14-17.09.19

The first tag can then be split into a tag name and value pair

TagName: StartTime
Value: 2015.07.14-17.09.19

These keys and tags can help you solve issues in the cooking pipeline.

Debugging Cooking Performance Issues

Most time variations are caused by the Derived Data Cache being invalidated and needing to rebuild textures for platforms.

If repeated cooks are still slow, this can indicate there is a large amount of data being cooked. Consider using iterative cooking (experimental) or if cooking for testing / development purposes, only cook what is required.

Derived Data Cache (DDC) Stats

DDC stats are recognizable in the stats.CSV file as their key will begin with DDCTransactionId.

DDC stats are in a hierarchical format to reflect how the DDC searches for content in the cache.

Review the 3 entries for DCC stats in, (tag lines edited for clarity)

DDCTransactionId2154470643B07308C1979DA468F3EA48_86
 GetCachedData
 CacheKey=MATSM_984afa3849534faa8491540b994bd32e_SF_PS4_15493__BC5N_DEV_SL_NoDBufF7646F9__526E4F887A3482CE276E9E40861788C0F9774343
 StartTime=2015.07.14-17.09.30
DDCTransactionId2154470643B07308C1979DA468F3EA48_87
 CachedDataProbablyExists
 Parent=DDCTransactionId2154470643B07308C1979DA468F3EA48_86
 StartTime=2015.07.14-17.09.30
DDCTransactionId2154470643B07308C1979DA468F3EA48_88 
 GetCachedData
 Parent=DDCTransactionId2154470643B07308C1979DA468F3EA48_86
 StartTime=2015.07.14-17.09.30

The second two transactions are linked to the first through the use of the "Parent" tag. The parent tag specifies the first transaction as the source for the DDC request. The first transaction also specifies the tag "GetCachedData" which is the entry point on the transaction. We can also see the CacheKey which was specified. Each transaction has a start time and a duration. The duration is in milliseconds, all duration's are inclusive time. The exclusive time for a parent transaction can be determined by subtracting the child transactions duration.

Save Package Stats

Save package is a large part of cooking, and each save package stats key starts with "SavePackageTransactionId":

SavePackageTransactionId830D62FB4EE90050FDB33BBDAA57A9A7_124
 Filename=D:/Builds/UE4/QAGame/Saved/Cooked/PS4/Engine/Plugins/Runtime/LeapMotionController/Content/LM_SampleDistortion.uasset
 FlushAsyncLoading=0.019673ms  FlushStreamingFunc=0.007272ms
 BlockTillAllRequestsFinished=0.006843ms
 ResetLoadersForSaveUnMarkAllObjects=0.158671ms
 TagPackageExports=0.222396ms  BeginCacheForCookedPlatformData=0.086393ms
 SerializeImports=0.120610ms  GatherLocalizableTextData=0.005558ms
 MarkNames=0.007700ms  SerializeSummary=0.016678ms
 SerializeNames=0.027802ms  SerializeGatherableTextData=0.004277ms
 BuildExportMap=0.017535ms  SortExportsNonSeekfree=0.008553ms
 SortExportsSeekfreeConstructor=0.019245ms
 SortExportsSeekfreeInner=0.327609ms  SortExportsSeekfree=0.005133ms
 BuildDependencyMap=0.010692ms  SerializeImportMap=0.005562ms
 SerializeExportMap=0.004705ms  SerializeDependencyMap=0.004277ms
 SerializeStringAssetReferenceMap=0.004277ms
 SaveThumbNailsAssetRegistryDataWorldLevelInfo=0.022668ms
 SerializeExports=0.109062ms  SerializeBulkData=0.015821ms
 AsyncWrite=4.576687ms  UnaccountedTime=0.307079ms
 RunGuid=RunID7F4E40464DE38EF1DECAF5A385FBDB1E

The tags in save package are broken up into sections of the save. Debugging issues in save package requires specific knowledge of the different sections of save package.

Cooking Package Stats

Cooking Package Stats let you know how the cooker is processing the packages (from the cooker side). They give you an idea of how long each package takes to process.

Cooking package stats key is the standard package name.

../../../WorkingWithContent/EditorMaterials/Cascade/CASC_Cross.uasset
 AllOfLoadPackage_Duration=0.115048ms  AllOfLoadPackage_HitCount=5
 ResolveRedirectors_Duration=0.001281ms  ResolveRedirectors_HitCount=5
 CacheForCookedPlatformData_Duration=5.137812ms
 CacheForCookedPlatformData_HitCount=1
 UnsolicitedMarkup_Duration=0.065863ms  UnsolicitedMarkup_HitCount=1
 SavePackageCacheForCookedPlatformData_Duration=0.146270ms
 SavePackageCacheForCookedPlatformData_HitCount=2
 SaveCookedPackage_Duration=1.683380ms  SaveCookedPackage_HitCount=1
 RunGuid=RunID2062A4FA4DBD3833D4A026A94B8970BB

Each stat has the hitcount and also the duration recorded. For example:

• AllOfLoadPackage is a single stat, but has two tags associated with it:

  • AllOfLoadPackage_Duration is the time taken to run all of load package.

  • AllOfLoadPackage_HitCount is the number of times load package was hit.

Different sections of the cooker can be hit multiple times due to the cooker trying to optimize the cooking process. The most common situation is that the cooker loads a package and the content is missing from DDC so needs to be regenerated (slow process), In this case the cooker will try and opportunistically cook other packages which have their content ready and come back to this package. This doesn't necessarily mean that the package was loaded 5 times, the cooker will early out if the package is already loaded and try and keep the package in memory if it isn't saved yet.