Diagnosing an elusive build problem

After a day of pair programming, we ended up with a lot of new code and blueprints in our project. We submitted all code to our VCS, and waited for the inevitable “OK” from the build automation. Sadly, it never came; instead, we went from 0 errors (and a few warnings–more on that later) to 127 errors! Seeing 127 errors, we first suspected a bug in our automation driver, 127 is a really suspicious number. Sadly, even running the automation scripts on our development machines produced the same error.

C:\'Program Files\Epic Games\UE_5.0\Engine\Build\BatchFiles'\RunUAT.bat 
    BuildCookRun 
    -installed 
    -nop4 
    -build 
    -project="...\Talisker.uproject" 
    -cook
    -CookAll 
    -ForceMonolithic
    -stage
    -archive
    -pak
    -archivedirectory="..." 
    -package
    -map=/Game/Maps/L_World+/Game/Maps/L_MainMenu
    -ddc=InstalledDerivedDataBackendGraph
    -nullrhi 
    -prereqs 
    -targetplatform=Win64 
    -target=Talisker
    -configuration=Shipping 
    -serverconfig=Shipping       
    -clientconfig=Shipping         
    -utf8output

Produced an error? But what about the remaining 126 errors? Well, it turns out that it was all just one error, but with lots and lots of lines which all counted towards the scary number.

...
Warning/Error Summary (Unique only)
-----------------------------------
Error: begin: stack for UAT
Error: === Handled ensure: ===
Error:
Error: Ensure condition failed: !GIsDuplicatingClassForReinstancing || InClass->HasAnyClassFlags(CLASS_Native) [...\UObjectGlobals.cpp] [Line: 2446]
Error: Stack:
Error: [Callstack] 0x00007ffb595740bc UnrealEditor-CoreUObject.dll!StaticAllocateObject() [...\UObjectGlobals.cpp:2446]
Error: [Callstack] 0x00007ffb592ac2f8 UnrealEditor-CoreUObject.dll!UClass::CreateDefaultObject() [...\Class.cpp:3882]
...
Error: [Callstack] 0x00007ffb5955eed0 UnrealEditor-CoreUObject.dll!FObjectInitializer::PostConstructInit() [...\UObjectGlobals.cpp:3012]
Error: [Callstack] 0x00007ffb5952d79a UnrealEditor-CoreUObject.dll!FObjectInitializer::~FObjectInitializer() [...\UObjectGlobals.cpp:2885]
...
LogInit: Display: NOTE: Only first 50 errors displayed.

Unpicking !GIsDuplicatingClassForReinstancing || InClass->HasAnyClassFlags(CLASS_Native)

LogInit: Display: NOTE: Only first 50 errors displayed. sic! Searching the web revealed a post on Blueprint circular dependencies, which looked like it could be describing our problem. We deduced that it was caused by a blueprint, but which one?! It was a very productive day, and we had lots of new blueprints added; we verified that the previous revision builds successfully, so it had to be one of the newly added blueprints. We opened the blueprints in the editor to look for dependencies between them–even though we were certain we did not create any dependency loops. And surely, we did not discover anything suspicious.

Unfortunately, the error in the build does not provide any hints. So, we turned to Unreal Engine’s source code. Our first attempt was to modify the StaticAllocateObject in UObjectGlobals.cpp:2446 to log more details about what was causing the problem.

UObject* StaticAllocateObject
(
    const UClass*    InClass,
    UObject*        InOuter,
    FName            InName,
    EObjectFlags    InFlags,
    EInternalObjectFlags InternalSetFlags,
    bool bCanRecycleSubobjects,
    bool* bOutRecycledSubobject,
    UPackage* ExternalPackage
)
{
    ...

    if (bCreatingCDO)
    {
        check(InClass->GetClass());

        // Debugging help vvv
        checkf(!GIsDuplicatingClassForReinstancing || InClass->HasAnyClassFlags(CLASS_Native), 
            TEXT("Possible Blueprint compilation cycle detected in %s."), 
            *GetNameSafe(InClass));
        // Debugging help ^^^

        ensure(!GIsDuplicatingClassForReinstancing || InClass->HasAnyClassFlags(CLASS_Native));
        InName = InClass->GetDefaultObjectName();
        // never call PostLoad on class default objects
        InFlags &= ~(RF_NeedPostLoad|RF_NeedPostLoadSubobjects);
    }

    ...
}

We built the engine, and ran our automation command locally again. We got the same error (good!–at least we knew that the error was consistently there), but the name of the class was in our case a BP_TextStyle_Generic_C. That was a little strange: while BP_TextStyle_Generic_C is indeed one of our blueprints, but it was not modified in the failing revision, and it is a subclass of UCommonTextStyle. And it naturally has no circular dependencies. So, this debugging addition did not help. The next method that looked like a good debugging point was FBlueprintCompileReinstancer::MoveCDOToNewClass. We added a simple warning log message

UClass* FBlueprintCompileReinstancer::MoveCDOToNewClass(UClass* OwnerClass, const TMap<UClass*, UClass*>& OldToNewMap, bool bAvoidCDODuplication)
{
    GIsDuplicatingClassForReinstancing = true;
    OwnerClass->ClassFlags |= CLASS_NewerVersionExists;

    UE_LOG(LogBlueprint, Warning, TEXT("MoveCDOToNewClass: %s."), *GetNameSafe(OwnerClass));

    ...
}

This finally produced something more reasonable:

Warning: MoveCDOToNewClass: WBP_TransitionWidget_C
Warning:

Script Stack (0 frames):

Error: begin: stack for UAT
Error: === Critical error: ===
Error:
Error: Assertion failed: !GIsDuplicatingClassForReinstancing || InClass->HasAnyClassFlags(CLASS_Native) [...\UObjectGlobals.cpp] [Line: 2450]
Error: [Callstack] 0x00007ffa3b7e5f6f UnrealEditor-CoreUObject.dll!StaticAllocateObject() [...\UObjectGlobals.cpp:2448]
...

The MoveCDOToNewClass: WBP_TransitionWidget_C was immediately followed by the !GIsDuplicatingClassForReinstancing || InClass->HasAnyClassFlags(CLASS_Native) hard error. The WBP_TransitionWidget extends UTransitionWidget (if you excuse the Blueprint and C++ notation) was indeed one of the added blueprints. Deleting it resolved the error. We were able to delete it because it was only referenced by a C++ class, and the reference was a UPROPERTY(Config) TSubclassOf<UTransitionWidget> field. It was only a very small blueprint with some trivial animation, so re-creating it won’t be a problem. We recreated it in another blueprint and built the project. Success! Then we remembered to also change the configuration property, and the error was back!

The cause

It turned out that saying that the error was in the blueprint was not accurate. We ultimately traced it down to the UPROPERTY(Config) field in the UAsyncAction_Transition class. Removing the configuration and loading the class explictly in UAsyncAction_Transition::Activate() resolved the build problem.

UCLASS(Config=Game)
class TALISKER_API UAsyncAction_Transition : public UBlueprintAsyncActionBase {
    ...
    UPROPERTY(Config) // <-- this was the culprit
    TSubclassOf<UTransitionWidget> DefaultTransitionWidgetClass;
}

Summary

The golden bullet that helped us find the problem was the additional log message in FBlueprintCompileReinstancer::MoveCDOToNewClass in Unreal Engine source code Source\Editor\UnrealEd\Kismet2\KismetReinstanceUtilities.cpp:1698. (Line numbers are valid for Unreal Engine 5.0.3.) From that, we knew where to focus, and resolving the problem then only took a few tens of minutes.