Visual logger FlushThreadEntries container changes during ranged for iteration

Development Character & Animation
, ,
1

It’s not a blocker and it doesn’t seem to cause further issues. I just wanted to check if this is a known issue and if there’s a known workaround.

Here’s the callstack:

> [Inline Frame] UnrealEditor-Engine.dll!TSparseArray<TSetElement<TTuple<FObjectKey,FVisualLogEntry>>,TSparseArrayAllocator<TSizedDefaultAllocator<32>,FDefaultBitArrayAllocator>>::TRangedForIterator::!=::__l2::<lambda_1>::operator()() Line 976 C++

[Inline Frame] UnrealEditor-Engine.dll!TSparseArray<TSetElement<TTuple<FObjectKey,FVisualLogEntry>>,TSparseArrayAllocator<TSizedDefaultAllocator<32>,FDefaultBitArrayAllocator>>::TRangedForIterator::operator!=(const TSparseArray<TSetElement<TTuple<FObjectKey,FVisualLogEntry>>,TSparseArrayAllocator<TSizedDefaultAllocator<32>,FDefaultBitArrayAllocator>>::TRangedForIterator &) Line 976 C++

[Inline Frame] UnrealEditor-Engine.dll!TSet<TTuple<FObjectKey,FVisualLogEntry>,TDefaultMapHashableKeyFuncs<FObjectKey,FVisualLogEntry,0>,FDefaultSetAllocator>::TBaseIterator<0,1>::operator!=(const TSet<TTuple<FObjectKey,FVisualLogEntry>,TDefaultMapHashableKeyFuncs<FObjectKey,FVisualLogEntry,0>,FDefaultSetAllocator>::TBaseIterator<0,1> &) Line 1635 C++

[Inline Frame] UnrealEditor-Engine.dll!TMapBase<FObjectKey,FVisualLogEntry,FDefaultSetAllocator,TDefaultMapHashableKeyFuncs<FObjectKey,FVisualLogEntry,0>>::TBaseIterator<0,1>::operator!=(const TMapBase<FObjectKey,FVisualLogEntry,FDefaultSetAllocator,TDefaultMapHashableKeyFuncs<FObjectKey,FVisualLogEntry,0>>::TBaseIterator<0,1> &) Line 862 C++

UnrealEditor-Engine.dll!FVisualLogger::FlushThreadsEntries() Line 614 C++

UnrealEditor-Engine.dll!FVisualLogger::Flush() Line 634 C++

UnrealEditor-Engine.dll!FVisualLogger::Cleanup(UWorld * OldWorld, bool bReleaseMemory) Line 853 C++

UnrealEditor-Engine.dll!UWorld::CleanupWorldInternal(bool bSessionEnded, bool bCleanupResources, bool bWorldChanged) Line 5519 C++

UnrealEditor-Engine.dll!UWorld::CleanupWorld(bool bSessionEnded, bool bCleanupResources, UWorld * NewWorld) Line 5446 C++

UnrealEditor-UnrealEd.dll!UEditorEngine::TeardownPlaySession(FWorldContext & PieWorldContext) Line 879 C++

UnrealEditor-UnrealEd.dll!UEditorEngine::EndPlayMap() Line 343 C++

UnrealEditor-UnrealEd.dll!UEditorEngine::Tick(float DeltaSeconds, bool bIdleMode) Line 2348 C++

UnrealEditor-UnrealEd.dll!UUnrealEdEngine::Tick(float DeltaSeconds, bool bIdleMode) Line 550 C++

UnrealEditor.exe!FEngineLoop::Tick() Line 6041 C++

[Inline Frame] UnrealEditor.exe!EngineTick() Line 61 C++

UnrealEditor.exe!GuardedMain(const wchar_t * CmdLine) Line 180 C++

UnrealEditor.exe!LaunchWindowsStartup(HINSTANCE__ * hInInstance, HINSTANCE__ * hPrevInstance, char * __formal, int nCmdShow, const wchar_t * CmdLine) Line 247 C++

UnrealEditor.exe!WinMain(HINSTANCE__ * hInInstance, HINSTANCE__ * hPrevInstance, char * pCmdLine, int nCmdShow) Line 298 C++

[External Code]

Thanks

2

Steps to Reproduce

  • Enable auto detach on rewind debugger
  • Enable auto record on rewind debugger
  • PIE
  • Stop PIE
  • Ensure is hit
3

Hi Sergio,

I am not seeing this happening in our latest main stream. So it seems it may have been fixed at some point since 5.4. We have had some reports around it, but never were able to reproduce this internally. A few thread safety improvements were added (CL 38336184), and we added some more/better MT access detectors (CL 38249957). Both of those changes will be in 5.6.

-James

4

There could likely be other CLs that are needed. There has been lots of work around RewindDebugger and Visual Logger support. If you are fine to wait for 5.6, that would be the easiest path, but if there are other concerns that require staying on a previous version, I can ask around the team for other CLs that might be needed for this.

-James

5

Hi James, when trying to add those two CLs I get an undefined FTransactionallySafe… object, I replaced it with FReadScopeLock. However, with these two CLs I got an assertion

Assertion failed: !ErrorDetected || GIsAutomationTesting [File:F:\P4Workspaces\…\Engine\Source\Runtime\Core\Public\Misc\MTAccessDetector.h] [Line: 94]

Acquiring a write access while there are ongoing read or write access

A breakpoint instruction (__debugbreak() statement or a similar call) was executed in UnrealEditor.exe.

with this callstack:

```

> [Inline Frame] UnrealEditor-Engine.dll!FRWAccessDetector::AcquireWriteAccess() Line 94 C++

[Inline Frame] UnrealEditor-Engine.dll!FRWRecursiveAccessDetector::AcquireWriteAccess() Line 139 C++

[Inline Frame] UnrealEditor-Engine.dll!TScopedWriterDetector<FRWRecursiveAccessDetector>::{ctor}(FRWRecursiveAccessDetector &) Line 252 C++

[Inline Frame] UnrealEditor-Engine.dll!MakeScopedWriterAccessDetector(FRWRecursiveAccessDetector &) Line 266 C++

UnrealEditor-Engine.dll!FVisualLogger::GetEntryToWrite(const UObject * Object, double TimeStamp, ECreateIfNeeded ShouldCreate) Line 454 C++

[Inline Frame] UnrealEditor-Engine.dll!FVisualLogger::CheckVisualLogInputInternal(const UObject *) Line 250 C++

UnrealEditor-Engine.dll!FVisualLogger::LocationLogfImpl(const UObject * Object, const FName & CategoryName, ELogVerbosity::Type Verbosity, const UE::Math::TVector<double> & Location, unsigned short Thickness, const FColor & Color, const wchar_t * Fmt, …) Line 117 C++

[Inline Frame] UnrealEditor-NTTraversal.dll!FVisualLogger::LocationLogf(const UObject *) Line 353 C++

UnrealEditor-NTTraversal.dll!UNTPathPredictionComponent::DrawDebug_Common(ANTHUD * HUD, FVisualLogStatusCategory * Category) Line 1904 C++

UnrealEditor-NTTraversal.dll!UNTPathPredictionComponent::GrabDebugSnapshot(FVisualLogEntry * Snapshot) Line 2099 C++

UnrealEditor-Engine.dll!FVisualLogger::GetEntryToWriteInternal(const UObject * Object, double TimeStamp, ECreateIfNeeded ShouldCreate) Line 608 C++

UnrealEditor-Engine.dll!FVisualLogger::FlushThreadsEntries() Line 676 C++

UnrealEditor-Engine.dll!FVisualLogger::Flush() Line 691 C++

[Inline Frame] UnrealEditor-Engine.dll!FVisualLogger::Tick(float) Line 649 C++

UnrealEditor-Engine.dll!FVisualLogger::{ctor}::__l2::<lambda_1>::operator()(const float DeltaTime) Line 849 C++

[Inline Frame] UnrealEditor-Core.dll!UE::Core::Private::Function::TFunctionRefBase<UE::Core::Private::Function::TFunctionStorage<0>,bool __cdecl(float)>::operator()(float <Params_0>) Line 555 C++

[Inline Frame] UnrealEditor-Core.dll!Invoke(TFunction<bool __cdecl(float)> &) Line 47 C++

[Inline Frame] UnrealEditor-Core.dll!UE::Core::Private::Tuple::TTupleBase<TIntegerSequence<unsigned int>>::ApplyAfter(TFunction<bool __cdecl(float)> &) Line 309 C++

UnrealEditor-Core.dll!TBaseFunctorDelegateInstance<bool __cdecl(float),FDefaultDelegateUserPolicy,TFunction<bool __cdecl(float)>>::Execute(float <Params_0>) Line 863 C++

[Inline Frame] UnrealEditor-Core.dll!TDelegate<bool __cdecl(float),FDefaultDelegateUserPolicy>::Execute(float) Line 549 C++

UnrealEditor-Core.dll!FTSTicker::FElement::Fire(float DeltaTime) Line 157 C++

UnrealEditor-Core.dll!FTSTicker::Tick(float DeltaTime) Line 110 C++

UnrealEditor.exe!FEngineLoop::Tick() Line 6282 C++

[Inline Frame] UnrealEditor.exe!EngineTick() Line 61 C++

UnrealEditor.exe!GuardedMain(const wchar_t * CmdLine) Line 180 C++

UnrealEditor.exe!LaunchWindowsStartup(HINSTANCE__ * hInInstance, HINSTANCE__ * hPrevInstance, char * __formal, int nCmdShow, const wchar_t * CmdLine) Line 247 C++

UnrealEditor.exe!WinMain(HINSTANCE__ * hInInstance, HINSTANCE__ * hPrevInstance, char * pCmdLine, int nCmdShow) Line 298 C++

[External Code]

```

Not sure if we’re lacking other CLs or if we have code that may be triggering this. In any case it looks like it’ll be difficult to pin down this issue. If you have any clues from the original callstack I posted or this one please let me know so we can investigate.

Otherwise I think I’ll wait and see since so far it’s only an ensure that happens once. It happens with 100% repro rate the first time you pause the game with the rewind debugger attached (auto eject and auto record).

Thank you

6

Hi James,

Since the only issue it this ensure I guess we can wait for a bit. If we find any more serious or blocking bugs I may open a new thread to ask for extra CLs.

Thanks