86c38a9f3a
Option -LPTraceScriptEx/-LPTraceLocals/-LPTraceMax, inactive par defaut. Valide en -game (releve et reecriture des piles d'appel). Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
341 lines
12 KiB
C++
341 lines
12 KiB
C++
// Portage UE 5.5 - lot L3 (journalisation). Voir LPSessionLogSubsystem.h.
|
|
|
|
#include "LPSessionLogSubsystem.h"
|
|
|
|
#include "LifePlay.h"
|
|
#include "GeneralProjectSettings.h"
|
|
#include "HAL/FileManager.h"
|
|
#include "HAL/IConsoleManager.h"
|
|
#include "Engine/GameInstance.h"
|
|
#include "Misc/App.h"
|
|
#include "Misc/CommandLine.h"
|
|
#include "Misc/Parse.h"
|
|
#include "UObject/UnrealType.h"
|
|
#include "UObject/Script.h"
|
|
#include "UObject/Stack.h"
|
|
#include "Blueprint/BlueprintExceptionInfo.h"
|
|
#include "Misc/EngineVersion.h"
|
|
#include "Misc/OutputDevice.h"
|
|
#include "Misc/Paths.h"
|
|
#include "Misc/ScopeLock.h"
|
|
|
|
namespace
|
|
{
|
|
// Au-dela, les nouvelles signatures sont comptees ensemble : la memoire reste bornee
|
|
// meme si un Blueprint emet des messages tous differents pendant des heures.
|
|
constexpr int32 MaxSignatures = 4000;
|
|
constexpr int32 SignatureLength = 240;
|
|
constexpr int32 TopSignatures = 25;
|
|
|
|
// Remplace chaque suite de chiffres par '#' : "Person_C_2147482340" et
|
|
// "index 12 ... length 12" se regroupent sous une seule signature. Les sauts de ligne
|
|
// deviennent " | " : la pile d'appel Blueprint ("Script call stack:") reste lisible.
|
|
FString MakeSignature(const TCHAR* Message)
|
|
{
|
|
FString Out;
|
|
Out.Reserve(SignatureLength);
|
|
bool bInDigits = false;
|
|
for (const TCHAR* C = Message; *C && Out.Len() < SignatureLength; ++C)
|
|
{
|
|
if (*C == TEXT('\r') || *C == TEXT('\n') || *C == TEXT('\t'))
|
|
{
|
|
if (!Out.EndsWith(TEXT(" | ")) && !Out.IsEmpty()) { Out += TEXT(" | "); }
|
|
bInDigits = false;
|
|
}
|
|
else if (FChar::IsDigit(*C))
|
|
{
|
|
if (!bInDigits) { Out.AppendChar(TEXT('#')); }
|
|
bInDigits = true;
|
|
}
|
|
else
|
|
{
|
|
Out.AppendChar(*C);
|
|
bInDigits = false;
|
|
}
|
|
}
|
|
return Out;
|
|
}
|
|
|
|
// Une seule commande console pour le processus, portee par la premiere instance de jeu
|
|
// (en PIE plusieurs GameInstances peuvent coexister).
|
|
FAutoConsoleCommand* SummaryCommand = nullptr;
|
|
const void* SummaryCommandOwner = nullptr;
|
|
}
|
|
|
|
/** Compte les messages du journal. N'ecrit jamais dans le journal lui-meme. */
|
|
class FLPLogCounter : public FOutputDevice
|
|
{
|
|
public:
|
|
virtual void Serialize(const TCHAR* V, ELogVerbosity::Type Verbosity, const FName& Category) override
|
|
{
|
|
const ELogVerbosity::Type Level = (ELogVerbosity::Type)(Verbosity & ELogVerbosity::VerbosityMask);
|
|
if (Category == LogLifePlay.GetCategoryName())
|
|
{
|
|
return;
|
|
}
|
|
|
|
FScopeLock Lock(&Mutex);
|
|
++PerCategory.FindOrAdd(FString::Printf(TEXT("%s %s"), *Category.ToString(), ToString(Level)));
|
|
|
|
if (Level <= ELogVerbosity::Warning)
|
|
{
|
|
const FString Key = FString::Printf(TEXT("[%s %s] %s"), *Category.ToString(), ToString(Level), *MakeSignature(V));
|
|
if (int32* Count = Signatures.Find(Key))
|
|
{
|
|
++*Count;
|
|
}
|
|
else if (Signatures.Num() < MaxSignatures)
|
|
{
|
|
Signatures.Add(Key, 1);
|
|
}
|
|
else
|
|
{
|
|
++Overflow;
|
|
}
|
|
}
|
|
}
|
|
|
|
virtual bool CanBeUsedOnAnyThread() const override { return true; }
|
|
virtual bool CanBeUsedOnMultipleThreads() const override { return true; }
|
|
|
|
void Snapshot(TArray<TPair<FString, int32>>& OutCategories, TArray<TPair<FString, int32>>& OutSignatures, int32& OutOverflow) const
|
|
{
|
|
FScopeLock Lock(&Mutex);
|
|
for (const auto& It : PerCategory) { OutCategories.Emplace(It.Key, It.Value); }
|
|
for (const auto& It : Signatures) { OutSignatures.Emplace(It.Key, It.Value); }
|
|
OutOverflow = Overflow;
|
|
}
|
|
|
|
private:
|
|
mutable FCriticalSection Mutex;
|
|
TMap<FString, int32> PerCategory;
|
|
TMap<FString, int32> Signatures;
|
|
int32 Overflow = 0;
|
|
};
|
|
|
|
void ULPSessionLogSubsystem::Initialize(FSubsystemCollectionBase& Collection)
|
|
{
|
|
Super::Initialize(Collection);
|
|
|
|
StartTime = FPlatformTime::Seconds();
|
|
Counter = MakeShared<FLPLogCounter>();
|
|
GLog->AddOutputDevice(Counter.Get());
|
|
|
|
if (!SummaryCommand)
|
|
{
|
|
SummaryCommand = new FAutoConsoleCommand(
|
|
TEXT("LifePlay.LogSummary"),
|
|
TEXT("Ecrit dans le journal le bilan de session LifePlay (messages par categorie, signatures les plus frequentes)."),
|
|
FConsoleCommandDelegate::CreateWeakLambda(this, [this]() { LogSessionSummary(); }));
|
|
SummaryCommandOwner = this;
|
|
}
|
|
|
|
LogStartupSummary();
|
|
DumpRequestedVariables(TEXT("demarrage"));
|
|
StartScriptExceptionTrace();
|
|
}
|
|
|
|
void ULPSessionLogSubsystem::StartScriptExceptionTrace()
|
|
{
|
|
FString Filter;
|
|
if (!FParse::Value(FCommandLine::Get(), TEXT("LPTraceScriptEx="), Filter, false) || Filter.IsEmpty())
|
|
{
|
|
return;
|
|
}
|
|
FString LocalsList;
|
|
FParse::Value(FCommandLine::Get(), TEXT("LPTraceLocals="), LocalsList, false);
|
|
TArray<FString> Keywords;
|
|
LocalsList.ParseIntoArray(Keywords, TEXT(","), true);
|
|
int32 Max = 3;
|
|
FParse::Value(FCommandLine::Get(), TEXT("LPTraceMax="), Max);
|
|
|
|
UE_LOG(LogLifePlay, Display, TEXT("Trace des exceptions de script : filtre '%s', variables [%s], %d releve(s) au plus"), *Filter, *LocalsList, Max);
|
|
|
|
TSharedRef<int32> Count = MakeShared<int32>(0);
|
|
ScriptExceptionHandle = FBlueprintCoreDelegates::OnScriptException.AddLambda(
|
|
[Filter, Keywords, Max, Count](const UObject* ActiveObject, const FFrame& StackFrame, const FBlueprintExceptionInfo& Info)
|
|
{
|
|
// Brancher un ecouteur supprime la pile d'appel que le moteur ecrit d'ordinaire :
|
|
// on la reecrit pour toutes les exceptions, pas seulement celles relevees.
|
|
const FString StackTrace = StackFrame.GetStackTrace();
|
|
UE_LOG(LogScript, Warning, TEXT("%s"), *StackTrace);
|
|
|
|
const FString Description = Info.GetDescription().ToString();
|
|
if (*Count >= Max || !Description.Contains(Filter) || !StackFrame.Node || !StackFrame.Locals)
|
|
{
|
|
return;
|
|
}
|
|
++*Count;
|
|
|
|
UE_LOG(LogLifePlay, Warning, TEXT("[trace %d/%d] %s | objet %s | fonction %s | offset %d"),
|
|
*Count, Max, *Description, *GetNameSafe(ActiveObject), *StackFrame.Node->GetName(),
|
|
StackFrame.Code && StackFrame.Node->Script.Num() ? (int32)(StackFrame.Code - StackFrame.Node->Script.GetData()) : -1);
|
|
|
|
int32 Shown = 0;
|
|
for (TFieldIterator<FProperty> It(StackFrame.Node); It && Shown < 200; ++It)
|
|
{
|
|
const FProperty* Prop = *It;
|
|
FString TypeName = Prop->GetCPPType();
|
|
if (const FStructProperty* SP = CastField<FStructProperty>(Prop)) { TypeName = SP->Struct->GetName(); }
|
|
if (const FArrayProperty* AP = CastField<FArrayProperty>(Prop))
|
|
{
|
|
if (const FStructProperty* ISP = CastField<FStructProperty>(AP->Inner)) { TypeName = TEXT("TArray<") + ISP->Struct->GetName() + TEXT(">"); }
|
|
}
|
|
|
|
const FString PropName = Prop->GetName();
|
|
const bool bMatch = Keywords.ContainsByPredicate([&](const FString& K)
|
|
{ return PropName.Contains(K) || TypeName.Contains(K); });
|
|
if (!bMatch)
|
|
{
|
|
continue;
|
|
}
|
|
|
|
FString Value;
|
|
Prop->ExportTextItem_Direct(Value, Prop->ContainerPtrToValuePtr<void>(StackFrame.Locals), nullptr, nullptr, PPF_None);
|
|
UE_LOG(LogLifePlay, Warning, TEXT("[trace %d] %s (%s) = %s"), *Count, *PropName, *TypeName, *Value.Left(500));
|
|
++Shown;
|
|
}
|
|
});
|
|
}
|
|
|
|
void ULPSessionLogSubsystem::DumpRequestedVariables(const TCHAR* When) const
|
|
{
|
|
FString List;
|
|
if (!FParse::Value(FCommandLine::Get(), TEXT("LPDumpVars="), List, false))
|
|
{
|
|
return;
|
|
}
|
|
const UGameInstance* GI = GetGameInstance();
|
|
if (!GI)
|
|
{
|
|
return;
|
|
}
|
|
|
|
TArray<FString> Names;
|
|
List.ParseIntoArray(Names, TEXT(","), true);
|
|
for (const FString& Name : Names)
|
|
{
|
|
const FProperty* Prop = GI->GetClass()->FindPropertyByName(FName(*Name));
|
|
if (!Prop)
|
|
{
|
|
UE_LOG(LogLifePlay, Warning, TEXT("[dump %s] %s : variable introuvable sur %s"), When, *Name, *GI->GetClass()->GetName());
|
|
continue;
|
|
}
|
|
|
|
if (const FArrayProperty* ArrayProp = CastField<FArrayProperty>(Prop))
|
|
{
|
|
FScriptArrayHelper Helper(ArrayProp, ArrayProp->ContainerPtrToValuePtr<void>(GI));
|
|
UE_LOG(LogLifePlay, Display, TEXT("[dump %s] %s : %d element(s)"), When, *Name, Helper.Num());
|
|
for (int32 i = 0; i < Helper.Num(); ++i)
|
|
{
|
|
FString Text;
|
|
ArrayProp->Inner->ExportTextItem_Direct(Text, Helper.GetRawPtr(i), nullptr, const_cast<UGameInstance*>(GI), PPF_None);
|
|
UE_LOG(LogLifePlay, Display, TEXT("[dump %s] %s[%d] = %s"), When, *Name, i, *Text.Left(600));
|
|
}
|
|
}
|
|
else
|
|
{
|
|
FString Text;
|
|
Prop->ExportTextItem_Direct(Text, Prop->ContainerPtrToValuePtr<void>(GI), nullptr, const_cast<UGameInstance*>(GI), PPF_None);
|
|
UE_LOG(LogLifePlay, Display, TEXT("[dump %s] %s = %s"), When, *Name, *Text.Left(600));
|
|
}
|
|
}
|
|
}
|
|
|
|
void ULPSessionLogSubsystem::Deinitialize()
|
|
{
|
|
DumpRequestedVariables(TEXT("fin"));
|
|
if (ScriptExceptionHandle.IsValid())
|
|
{
|
|
FBlueprintCoreDelegates::OnScriptException.Remove(ScriptExceptionHandle);
|
|
ScriptExceptionHandle.Reset();
|
|
}
|
|
LogSessionSummary();
|
|
|
|
if (Counter.IsValid())
|
|
{
|
|
GLog->RemoveOutputDevice(Counter.Get());
|
|
// Un autre thread peut encore etre dans Serialize : on vide la file avant liberation.
|
|
GLog->Flush();
|
|
Counter.Reset();
|
|
}
|
|
if (SummaryCommandOwner == this)
|
|
{
|
|
delete SummaryCommand;
|
|
SummaryCommand = nullptr;
|
|
SummaryCommandOwner = nullptr;
|
|
}
|
|
|
|
Super::Deinitialize();
|
|
}
|
|
|
|
void ULPSessionLogSubsystem::LogStartupSummary() const
|
|
{
|
|
const UGeneralProjectSettings* Project = GetDefault<UGeneralProjectSettings>();
|
|
UE_LOG(LogLifePlay, Display, TEXT("===== LifePlay : demarrage ====="));
|
|
UE_LOG(LogLifePlay, Display, TEXT("Jeu %s %s | moteur %s | configuration %s"),
|
|
*Project->ProjectName, *Project->ProjectVersion,
|
|
*FEngineVersion::Current().ToString(), LexToString(FApp::GetBuildConfiguration()));
|
|
|
|
// Meme racine que ModdingExtra::LoadTxt : ProjectContentDir()/Modules
|
|
const FString ModulesDir = FPaths::Combine(FPaths::ProjectContentDir(), TEXT("Modules"));
|
|
IFileManager& FM = IFileManager::Get();
|
|
if (!FM.DirectoryExists(*ModulesDir))
|
|
{
|
|
UE_LOG(LogLifePlay, Error, TEXT("Dossier de donnees absent : %s (verifier DirectoriesToAlwaysStageAsNonUFS)"),
|
|
*FPaths::ConvertRelativePathToFull(ModulesDir));
|
|
return;
|
|
}
|
|
|
|
TArray<FString> ModFiles;
|
|
FM.FindFilesRecursive(ModFiles, *ModulesDir, TEXT("*.lpmod"), true, false);
|
|
ModFiles.Sort();
|
|
UE_LOG(LogLifePlay, Display, TEXT("Donnees : %s | %d module(s) | ModLauncher.config %s"),
|
|
*FPaths::ConvertRelativePathToFull(ModulesDir), ModFiles.Num(),
|
|
FM.FileExists(*FPaths::Combine(ModulesDir, TEXT("ModLauncher.config"))) ? TEXT("present") : TEXT("absent (tous les modules par defaut)"));
|
|
|
|
for (const FString& ModFile : ModFiles)
|
|
{
|
|
const FString ModDir = FPaths::GetPath(ModFile);
|
|
TArray<FString> Files;
|
|
FM.FindFilesRecursive(Files, *ModDir, TEXT("*.*"), true, false);
|
|
|
|
TMap<FString, int32> PerExt;
|
|
for (const FString& F : Files) { ++PerExt.FindOrAdd(FPaths::GetExtension(F).ToLower()); }
|
|
PerExt.ValueSort([](int32 A, int32 B) { return A > B; });
|
|
|
|
FString Detail;
|
|
for (const auto& It : PerExt) { Detail += FString::Printf(TEXT(" %s=%d"), *It.Key, It.Value); }
|
|
UE_LOG(LogLifePlay, Display, TEXT(" %-22s %5d fichier(s) :%s"), *FPaths::GetBaseFilename(ModFile), Files.Num(), *Detail);
|
|
}
|
|
}
|
|
|
|
void ULPSessionLogSubsystem::LogSessionSummary() const
|
|
{
|
|
if (!Counter.IsValid())
|
|
{
|
|
return;
|
|
}
|
|
|
|
TArray<TPair<FString, int32>> Categories, Signatures;
|
|
int32 Overflow = 0;
|
|
Counter->Snapshot(Categories, Signatures, Overflow);
|
|
|
|
const auto ByCountDesc = [](const TPair<FString, int32>& A, const TPair<FString, int32>& B) { return A.Value > B.Value; };
|
|
Categories.Sort(ByCountDesc);
|
|
Signatures.Sort(ByCountDesc);
|
|
|
|
UE_LOG(LogLifePlay, Display, TEXT("===== LifePlay : bilan de session (%.0f s) ====="), FPlatformTime::Seconds() - StartTime);
|
|
UE_LOG(LogLifePlay, Display, TEXT("Messages par categorie et verbosite (20 premieres) :"));
|
|
for (int32 i = 0; i < FMath::Min(20, Categories.Num()); ++i)
|
|
{
|
|
UE_LOG(LogLifePlay, Display, TEXT(" %8d %s"), Categories[i].Value, *Categories[i].Key);
|
|
}
|
|
|
|
UE_LOG(LogLifePlay, Display, TEXT("Avertissements et erreurs : %d signature(s) distincte(s)%s ; les %d plus frequentes :"),
|
|
Signatures.Num(), Overflow ? *FString::Printf(TEXT(", %d message(s) hors plafond"), Overflow) : TEXT(""), TopSignatures);
|
|
for (int32 i = 0; i < FMath::Min(TopSignatures, Signatures.Num()); ++i)
|
|
{
|
|
UE_LOG(LogLifePlay, Display, TEXT(" %8d %s"), Signatures[i].Value, *Signatures[i].Key);
|
|
}
|
|
}
|