check() failure/crash when logging warning+ outside of gamethread
ElodieDJ opened this issue · 2 comments
Environment
How do you use Sentry?
Sentry SaaS (sentry.io)
How did you install the package?
From github
Which version of Unreal?
5.4.1
Is this happening in Unreal (editor) or on a player like Android, iOS, Windows?
My example happened in editor, but this would happen on all platforms.
Steps to Reproduce
Reproduction: On a thread that isn't the gamethread, use UE_LOG() at Warning or higher severity while the main thread is garbage collecting. This timing makes it tricky to reproduce, but the call stack and code should be sufficient to explain the issue.
Expected Result
check() failure wouldn't happen, and there wouldn't be a crash.
Actual Result
This results in a check() failure, which causes a crash when not attached with a debugger.
Call stack:
>UnrealEditor-CoreUObject.dll!StaticAllocateObject(const UClass * InClass, UObject * InOuter, FName InName, EObjectFlags InFlags, EInternalObjectFlags InternalSetFlags, bool bCanRecycleSubobjects, bool * bOutRecycledSubobject, UPackage * ExternalPackage) Line 3358C++
UnrealEditor-CoreUObject.dll!StaticConstructObject_Internal(const FStaticConstructObjectParameters & Params) Line 4449C++
UnrealEditor-Sentry-Win64-DebugGame.dll!NewObject<USentryBreadcrumb>(UObject * Outer) Line 1764C++
UnrealEditor-Sentry-Win64-DebugGame.dll!USentrySubsystem::AddBreadcrumbWithParams(const FString & Message, const FString & Category, const FString & Type, const TMap<FString,FString,FDefaultSetAllocator,TDefaultMapHashableKeyFuncs<FString,FString,0>> & Data, ESentryLevel Level) Line 177C++
UnrealEditor-Sentry-Win64-DebugGame.dll!FSentryOutputDevice::Serialize(const wchar_t * V, ELogVerbosity::Type Verbosity, const FName & Category) Line 59C++
UnrealEditor-Sentry-Win64-DebugGame.dll!FOutputDevice::Serialize(const wchar_t * V, ELogVerbosity::Type Verbosity, const FName & Category, const double Time) Line 152C++
[Inline Frame] UnrealEditor-Core.dll!FOutputDeviceRedirector::Serialize::__l2::<lambda>(FOutputDevice * &) Line 681C++
[Inline Frame] UnrealEditor-Core.dll!Invoke(FOutputDeviceRedirector::Serialize::__l2::void <lambda>(void) &) Line 47C++
[Inline Frame] UnrealEditor-Core.dll!UE::Private::FOutputDeviceRedirectorState::BroadcastTo(const unsigned int) Line 210C++
UnrealEditor-Core.dll!FOutputDeviceRedirector::Serialize(const wchar_t * Data, ELogVerbosity::Type Verbosity, const FName & Category, const double Time) Line 680C++
[Inline Frame] UnrealEditor-Core.dll!FOutputDeviceRedirector::Serialize(const wchar_t *) Line 720C++
UnrealEditor-Core.dll!FFeedbackContext::Serialize(const wchar_t * V, ELogVerbosity::Type Verbosity, const FName & Category) Line 42C++
[Inline Frame] UnrealEditor-Core.dll!FMsg::LogV::__l5::<lambda>() Line 80C++
[Inline Frame] UnrealEditor-Core.dll!AutoRTFM::Open::__l2::<lambda>(void *) Line 438C++
[Inline Frame] UnrealEditor-Core.dll!AutoRTFM::Open::__l2::void <lambda>(void)::<lambda_invoker_cdecl>(void *) Line 438C++
[Inline Frame] UnrealEditor-Core.dll!autortfm_open(void(*)(void *)) Line 179C++
[Inline Frame] UnrealEditor-Core.dll!AutoRTFM::Open(const FMsg::LogV::__l5::void <lambda>(void) &) Line 437C++
UnrealEditor-Core.dll!FMsg::LogV(const char * File, int Line, const FName & Category, ELogVerbosity::Type Verbosity, const wchar_t * Fmt, char * Args) Line 85C++
UnrealEditor-Core.dll!UE::Logging::Private::BasicLog(const FLogCategoryBase & Category, const UE::Logging::Private::FStaticBasicLogRecord * Log, ...) Line 1078C++
UnrealEditor-WwiseProjectDatabase-Win64-DebugGame.dll!FWwiseDataStructureScopeLock::GetCurrentPlatformData() Line 436C++
UnrealEditor-WwiseProjectDatabase-Win64-DebugGame.dll!FWwiseDataStructureScopeLock::GetEvent(const FWwiseEventInfo & InInfo) Line 192C++
UnrealEditor-AkAudio-Win64-DebugGame.dll!GetInfoErrorMessageTranslatorFunction(AkErrorMessageTranslator::TagInformation * in_pTagList, unsigned int in_uCount, unsigned int & out_uTranslated) Line 276C++
UnrealEditor-AkAudio-Win64-DebugGame.dll!UE::Core::Private::Function::TFunctionRefCaller<bool (__cdecl*)(AkErrorMessageTranslator::TagInformation *,unsigned int,unsigned int &),bool __cdecl(AkErrorMessageTranslator::TagInformation *,unsigned int,unsigned int &)>::Call(void * Obj, AkErrorMessageTranslator::TagInformation * & <Params_0>, unsigned int & <Params_1>, unsigned int & <Params_2>) Line 397C++
UnrealEditor-WwiseSoundEngine-Win64-DebugGame.dll!UE::Core::Private::Function::TFunctionRefBase<UE::Core::Private::Function::TFunctionStorage<0>,bool __cdecl(AkErrorMessageTranslator::TagInformation *,unsigned int,unsigned int &)>::operator()(AkErrorMessageTranslator::TagInformation * <Params_0>, unsigned int <Params_1>, unsigned int & <Params_2>) Line 556C++
UnrealEditor-WwiseSoundEngine-Win64-DebugGame.dll!FWwiseSoundEngineAPI_2023_1::FErrorTranslator::GetInfo(AkErrorMessageTranslator::TagInformation * in_pTagList, unsigned int in_uCount, unsigned int & out_uTranslated) Line 2392C++
Suggested fix
This is caused by the creation of USentryBreadcrumb from a logged warning+ message on a non-game thread, while the game thread is garbage collecting. Previously, Unreal didn't support creating objects outside of the game thread. While Unreal does now support creating objects (i.e. using NewObject) on threads that aren't the game thread, it's still not allowed during garbage collection. In addition, objects created outside of the game thread need to be specially managed (e.g. using FGCCSyncObject, clearing EInternalObjectFlags::Async). More info on these requirements can be found on UDN, which I don't think I'm allowed to link to publicly.
Given these caveats on using objects, it seems like USentryBreadcrumb should be replaced by TSharedPtr<FSentryBreadcrumb>. This was the route I intended to go down, but decided to make a simpler change for now just to avoid the crash: don't create breadcrumbs during garbage collection. I did that by adding this snippet to the start of USentryLibrary::CreateSentryBreadcrumb() and USentrySubsystem::AddBreadcrumbWithParams():
// Avoid crash when used outside of game thread. Game thread may be garbage collecting, object creation is not allowed during that time.
// ref: StaticAllocateObject() in UObjectGlobals.cpp
if (IsGarbageCollectingAndLockingUObjectHashTables())
{
return;
}
It seems like this would be a simple change to put in for now to fix the crash, and refactoring of breadcrumbs can be considered for the future.
@ElodieDJ Thank you for reaching out and comprehensively describing this issue! We've encountered the exact same problem recently which I believe was addressed in #559. Basically, this fix allows us to capture breadcrumbs without instantiating a new UObject whenever printing to logs relying only on the internal APIs.
@ElodieDJ Thank you for reaching out and comprehensively describing this issue! We've encountered the exact same problem recently which I believe was addressed in #559. Basically, this fix allows us to capture breadcrumbs without instantiating a new
UObjectwhenever printing to logs relying only on the internal APIs.
Thank you! That fix looks exactly like what I was thinking :-) I'll make sure to pull the new update to our integration of Sentry. Feel free to resolve this issue, since you've already fixed it.