Crash when printing inside function

TriNityGER · July 19, 2019, 1:24am

EDIT: Solved! I was using a TArray of Dynamic Delegates instead of a Dynamic Multicast delegate. For whatever reason this seemingly caused the crash I experienced.

I implemented a simple message bus and it works perfectly fine inside Blueprints. But when I subscribe to a message via C++ and the callback gets called, the editor crashes if I try to output stuff via the log. Interestingly, the message I wanted to print actually prints but thats it. Why is this happening?


[2019.07.19-00.43.30:042][489]LogAresMessageBus: ON ACTOR SPAWNED!
[2019.07.19-00.43.33:078][489]LogWindows: Error: === Critical error: ===
[2019.07.19-00.43.33:078][489]LogWindows: Error:
[2019.07.19-00.43.33:078][489]LogWindows: Error: Fatal error!
[2019.07.19-00.43.33:078][489]LogWindows: Error:
[2019.07.19-00.43.33:078][489]LogWindows: Error: Unhandled Exception: EXCEPTION_ACCESS_VIOLATION reading address 0x00000001
[2019.07.19-00.43.33:078][489]LogWindows: Error:
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffc07e92ebd ucrtbase.dll!UnknownFunction ]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffc07e7f10c ucrtbase.dll!UnknownFunction ]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffc07e7eac7 ucrtbase.dll!UnknownFunction ]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba85398a7 UE4Editor-Core.dll!FMsg::Logf_InternalImpl() [d:\build\++ue4\sync\engine\source\runtime\core\private\logging\logmacros.cpp:99]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffb918d55bf UE4Editor-Ares.dll!UAresMessageBus::Publish() [A:\Projekte\Unreal-Engine-4-Projekte\Ares\Source\Ares\Core\AresMessageBus.cpp:61]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffb918d6b84 UE4Editor-Ares.dll!UAresMessageBus::execPublish() [A:\Projekte\Unreal-Engine-4-Projekte\Ares\Source\Ares\Core\AresMessageBus.h:26]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba91bbac8 UE4Editor-CoreUObject.dll!UFunction::Invoke() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\class.cpp:4643]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93b00e2 UE4Editor-CoreUObject.dll!UObject::CallFunction() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:904]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93ccbc1 UE4Editor-CoreUObject.dll!UObject::ProcessContextOpcode() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:2314]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93ce98d UE4Editor-CoreUObject.dll!ProcessLocalScriptFunction() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:974]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93a5efb UE4Editor-CoreUObject.dll!ProcessScriptFunction<void (__cdecl*)(UObject *,FFrame &,void *)>() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:809]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93ce6a9 UE4Editor-CoreUObject.dll!ProcessLocalFunction() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:1033]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93ce98d UE4Editor-CoreUObject.dll!ProcessLocalScriptFunction() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:974]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93ce378 UE4Editor-CoreUObject.dll!UObject::ProcessInternal() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:1058]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba91bbac8 UE4Editor-CoreUObject.dll!UFunction::Invoke() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\class.cpp:4643]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba93cdf07 UE4Editor-CoreUObject.dll!UObject::ProcessEvent() [d:\build\++ue4\sync\engine\source\runtime\coreuobject\private\uobject\scriptcore.cpp:1464]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5bb9ff3 UE4Editor-Engine.dll!AActor::ProcessEvent() [d:\build\++ue4\sync\engine\source\runtime\engine\private\actor.cpp:769]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba6cb5bf9 UE4Editor-Engine.dll!AActor::ReceiveActorBeginOverlap() [d:\build\++ue4\sync\engine\intermediate\build\win64\ue4editor\inc\engine\actor.gen.cpp:909]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5f6dd49 UE4Editor-Engine.dll!UPrimitiveComponent::BeginComponentOverlap() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\primitivecomponent.cpp:2510]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5fa97ef UE4Editor-Engine.dll!UPrimitiveComponent::UpdateOverlapsImpl() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\primitivecomponent.cpp:2926]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5fd41a1 UE4Editor-Engine.dll!USceneComponent::EndScopedMovementUpdate() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\scenecomponent.cpp:840]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5fbba43 UE4Editor-Engine.dll!FScopedMovementUpdate::~FScopedMovementUpdate() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\scenecomponent.cpp:3421]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5f30e0a UE4Editor-Engine.dll!UCharacterMovementComponent::PerformMovement() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\charactermovementcomponent.cpp:2364]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5f54441 UE4Editor-Engine.dll!UCharacterMovementComponent::TickComponent() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\charactermovementcomponent.cpp:1257]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5eef3fa UE4Editor-Engine.dll!FActorComponentTickFunction::ExecuteTickHelper<<lambda_04d8ef4b869923d6312932fb3543d049> >() [d:\build\++ue4\sync\engine\source\runtime\engine\classes\gameframework\actor.h:3109]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba5f15464 UE4Editor-Engine.dll!FActorComponentTickFunction::ExecuteTick() [d:\build\++ue4\sync\engine\source\runtime\engine\private\components\actorcomponent.cpp:816]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba6b572bc UE4Editor-Engine.dll!TGraphTask<FTickFunctionTask>::ExecuteTask() [d:\build\++ue4\sync\engine\source\runtime\core\public\async	askgraphinterfaces.h:842]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba83e22d8 UE4Editor-Core.dll!FNamedTaskThread::ProcessTasksNamedThread() [d:\build\++ue4\sync\engine\source\runtime\core\private\async	askgraph.cpp:686]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba83e2563 UE4Editor-Core.dll!FNamedTaskThread::ProcessTasksUntilQuit() [d:\build\++ue4\sync\engine\source\runtime\core\private\async	askgraph.cpp:582]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba83f2309 UE4Editor-Core.dll!FTaskGraphImplementation::WaitUntilTasksComplete() [d:\build\++ue4\sync\engine\source\runtime\core\private\async	askgraph.cpp:1457]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba6b9f9e3 UE4Editor-Engine.dll!FTickTaskSequencer::ReleaseTickGroup() [d:\build\++ue4\sync\engine\source\runtime\engine\private	icktaskmanager.cpp:557]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba6babd12 UE4Editor-Engine.dll!FTickTaskManager::RunTickGroup() [d:\build\++ue4\sync\engine\source\runtime\engine\private	icktaskmanager.cpp:1505]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba63cdc4f UE4Editor-Engine.dll!UWorld::RunTickGroup() [d:\build\++ue4\sync\engine\source\runtime\engine\private\leveltick.cpp:789]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba63d7e28 UE4Editor-Engine.dll!UWorld::Tick() [d:\build\++ue4\sync\engine\source\runtime\engine\private\leveltick.cpp:1568]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba3ee02f7 UE4Editor-UnrealEd.dll!UEditorEngine::Tick() [d:\build\++ue4\sync\engine\source\editor\unrealed\private\editorengine.cpp:1618]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffba46fd396 UE4Editor-UnrealEd.dll!UUnrealEdEngine::Tick() [d:\build\++ue4\sync\engine\source\editor\unrealed\private\unrealedengine.cpp:403]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ff6ba396bb1 UE4Editor.exe!FEngineLoop::Tick() [d:\build\++ue4\sync\engine\source\runtime\launch\private\launchengineloop.cpp:3967]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ff6ba3a554c UE4Editor.exe!GuardedMain() [d:\build\++ue4\sync\engine\source\runtime\launch\private\launch.cpp:168]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ff6ba3a55ca UE4Editor.exe!GuardedMainWrapper() [d:\build\++ue4\sync\engine\source\runtime\launch\private\windows\launchwindows.cpp:145]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ff6ba3b316c UE4Editor.exe!WinMain() [d:\build\++ue4\sync\engine\source\runtime\launch\private\windows\launchwindows.cpp:275]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ff6ba3b5b8e UE4Editor.exe!__scrt_common_main_seh() [d:\agent\_work\3\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl:288]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffc093a7bd4 KERNEL32.DLL!UnknownFunction ]
[2019.07.19-00.43.33:078][489]LogWindows: Error: [Callstack] 0x00007ffc0a1ece71 ntdll.dll!UnknownFunction ]
[2019.07.19-00.43.33:078][489]LogWindows: Error:
[2019.07.19-00.43.33:083][489]LogExit: Executing StaticShutdownAfterError
[2019.07.19-00.43.33:085][489]LogWindows: FPlatformMisc::RequestExit(1)
[2019.07.19-00.43.33:118][489]Log file closed, 07/19/19 02:43:33

Callback:


void UGameEntityManager::OnActorSpawned(UAresMessage* message)
{
    UE_LOG(LogAresMessageBus, Log, TEXT("ON ACTOR SPAWNED!"))

}

MessageBus Publish():


void UAresMessageBus::Publish(UAresMessage* msg)
{
    FMessageFunctionDelegates* delegateArray = MessageDelegates.Find(msg->GetClass());
    if (delegateArray && delegateArray->Delegates.Num() > 0)
    {
        for (const FMessageFunctionDelegate& dlg : delegateArray->Delegates)
        {
            dlg.ExecuteIfBound(msg);
        }
        UE_LOG(LogAresMessageBus, Log, TEXT("Executed all delegates of message %s"), *msg->GetClass()->GetName());
        return;
    }
    UE_LOG(LogAresMessageBus, Log, TEXT("No delegates found for message %s"), *msg->GetClass()->GetName());
}

The-Cowboy · July 19, 2019, 1:38am

Could you show the code in logmacros.cpp around line 99? Seems like segmentation fault.

TriNityGER · July 19, 2019, 1:47am


void FMsg::Logf_InternalImpl(const ANSICHAR* File, int32 Line, const FName& Category, ELogVerbosity::Type Verbosity, const TCHAR* Fmt, ...)
{
#if !NO_LOGGING
    QUICK_SCOPE_CYCLE_COUNTER(STAT_FMsgLogf);
    CSV_CUSTOM_STAT(FMsgLogf, FMsgLogfCount, 1, ECsvCustomStatOp::Accumulate);

    if (Verbosity != ELogVerbosity::Fatal)
    {
        // SetColour is routed to GWarn just like the other verbosities and handled in the
        // device that does the actual printing.
        FOutputDevice* LogDevice = NULL;
        switch (Verbosity)
        {
        case ELogVerbosity::Error:
        case ELogVerbosity::Warning:
        case ELogVerbosity::Display:
        case ELogVerbosity::SetColor:
            if (GWarn)
            {
                LogDevice = GWarn;
                break;
            }
        default:
        {
            LogDevice = GLog;
        }
        break;
        }
        GROWABLE_LOGF(LogDevice->Log(Category, Verbosity, Buffer)) // <--------------------------------------------Our culprit
    }
    else
    {
        // Keep Message buffer small, in some cases, this code is executed with 16KB stack.
        TCHAR Message[4096];
        {
            // Simulate Sprintf_s
            // @todo: implement platform independent sprintf_S
            // We're using one big shared static buffer here, so guard against re-entry
            FScopeLock MsgLock(&MsgLogfStaticBufferGuard);
            // Print to a large static buffer so we can keep the stack allocation below 16K
            GET_VARARGS(MsgLogfStaticBuffer, ARRAY_COUNT(MsgLogfStaticBuffer), ARRAY_COUNT(MsgLogfStaticBuffer) - 1, Fmt, Fmt);
            // Copy the message to the stack-allocated buffer)
            FCString::Strncpy(Message, MsgLogfStaticBuffer, ARRAY_COUNT(Message) - 1);
            Message[ARRAY_COUNT(Message) - 1] = '\0';
        }

        const int32 NumStackFramesToIgnore = 1;
        StaticFailDebug(TEXT("Fatal error:"), File, Line, Message, false, NumStackFramesToIgnore);
    }
#endif
}

BrUnO_XaVIeR · July 19, 2019, 1:53am

Do not execute delegate objects from outside game thread. You usually get crashes because of engine code related to “ExecuteIfBound()”.
Also not sure why you built this, a message bus the engine already have in C++ land.

TriNityGER · July 19, 2019, 8:07am

The delegate is executed in the game thread, at least it should be! All I did was to call Publish inside my OnActorBeginOverlap.

Also I built my own to simply for fun

BrUnO_XaVIeR · July 19, 2019, 2:54pm

Hmm… overlap events can be fired many times in same frame.
Try making sure your message is firing once per frame and see if helps.

ExtraLifeMatt · July 19, 2019, 3:03pm

It’s a null pointer somewhere. Check that msg is valid, that msg->GetClass() is valid, etc. Also make sure the UObject you are using to call this message is valid.

TriNityGER · July 23, 2019, 1:45am

Actually I’m surprised…

This code works fine:


void UGameEntityManager::OnActorSpawned(UAresMessage* message)
{
    auto msg = Cast<UActorSpawnedMessage>(message);
    if(IsValid(msg) && IsValid(msg->StaticClass()) && IsValid(msg->Instigator) && IsValid(msg->Actor))
    {
        _actors.Add(msg->Actor);
    }

}

Maybe its just the UE_LOG macro simply not working there? I can live with that but it still feels… fishy.

Also [USER=“434”]BrUnO XaVIeR[/USER] I checked out the IMessageBus/Endpoint/EndpointBuilder again. They look very sophisticated but are totally unusable with blueprints, so using them is not an option.
I tried building a wrapper class but most of the code uses Templates. I got around that for most of the time but I got stuck at the function pointer parameter… No idea how to translate that to blueprints aka Delegates.

BrUnO_XaVIeR · July 23, 2019, 3:03am

Shouldn’t Instigator be optional tho?!

TriNityGER · July 23, 2019, 8:19am

One could also say Sender instead of Instigator.
Theoretically the check is optional as you usually don’t access it but I wanted to double check as it shouldn’t be null in almost every case.

As for the segfault: I’ll try to use the log again later and do some more error checking.

illYay · July 23, 2019, 8:24am

At first glance it looks like you’re trying to broadcast to multiple listeners? Have you tried using a Multicast Delegate? It takes care of the whole thing for you.

DECLARE_DYNAMIC_MULTICAST_DELEGATE

Component overlap events are an example.

TriNityGER · July 27, 2019, 11:20pm

Just implemented this and it works fine! I also can print via GEngine->AddOnScreenDebugMessage!