diff --git a/CLAUDE.md b/CLAUDE.md index 597e814..1f1eb76 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -28,7 +28,18 @@ template; the plain template classes are `ATemplate*` and are the placeholder bo depend on them. Four Fab asset packs sit in `Content/` (`HouseForge_01`, `Medieval_Weapons`, `Elite_RockyMeadows`, `RPGEnvironmentVFX`); none is referenced yet, and a pack is used only when a step's spec names the asset. -Next: step 2, the telemetry seam. Update this section when a step closes: what exists, what the next step is. +Step 2 is built: `UTelemetrySubsystem` on the game instance with the null, log and JSON Lines sinks +(`-telemetry` or `telemetry.File 1` writes `Saved/Telemetry/session_*.jsonl`), the four session events, +`ASaltyGameMode` minting the session id into `ASaltyGameState`, and `bs.TelemetryTest` in +`Source/Salty/Core/SaltyCheats.cpp`, the home of every later `bs.*` command. Emit with a name from +`TelemetryEvents` and a `FTelemetryPayload`. + +The editor serves the engine's MCP plugin on `127.0.0.1:8000/mcp` while it is open (D-43); `.mcp.json` points +Claude Code at it. Reconnect with `/mcp` once the editor is up. Close the editor and its Live Coding console +before a shell build. + +Next: step 3, the body, the camera, the input map and the gym. Step 1's PIE proof (two clients, dedicated +server, two pawns in the gym) is still a person's to tick. Update this section when a step closes. ## Layout diff --git a/Docs/Decisions.md b/Docs/Decisions.md index c31f186..81b88cd 100644 --- a/Docs/Decisions.md +++ b/Docs/Decisions.md @@ -7,6 +7,13 @@ say so. Status: `Decided` · `Supersedes` (contradicts an earlier decision, names it) · `Deferred` (deliberately not now, with a trigger) +## 2026-09-16 — Step 2, the telemetry seam + +| # | Decision | Where | +| --- | --- | --- | +| D-43 | **The editor serves the engine's MCP plugin on `127.0.0.1:8000/mcp` whenever it is open.** `bAutoStartServer` in `Config/DefaultEditorPerProjectUserSettings.ini`, the port `.mcp.json` points Claude Code at, plus the `EditorToolset`, `AutomationTestToolset`, `GameplayTagsToolset`, `ConfigSettingsToolset` and `LiveCodingToolset` plugins. Loopback only; nothing listens when the editor is closed. Everything the plugin sends to an LLM is Licensed Technology under the UE EULA §6(e). | [CLAUDE.md](../CLAUDE.md) | +| D-42 | **The build string is `FApp::GetBuildVersion()` plus the git short hash read by `Salty.Build.cs` at build time.** A commit changes the definition and rebuilds the gameplay module; that cost is accepted so a telemetry file never lies about which build wrote it. `nogit` when git is unavailable. | [Telemetry](Spec/Telemetry.md) | + ## 2026-09-16 — Step 1 closes the two open decisions Taken when the project was created from the engine's Third Person template. diff --git a/Docs/Spec/Telemetry.md b/Docs/Spec/Telemetry.md index f02c0bf..81091cf 100644 --- a/Docs/Spec/Telemetry.md +++ b/Docs/Spec/Telemetry.md @@ -178,3 +178,30 @@ does not. settings pass, not before. - **Q4. Typed payloads.** A JSON object per event is convenient and unsafe. A typed struct per event name is the later answer if typos in payload keys start costing analysis time. + +## What was built, and where it differs + +Step 2, 2026-09-16. + +- **Layout as specified.** `SaltyCore/Telemetry/` holds `TelemetryEvent.h` (event, envelope, the `FTelemetryPayload` + builder and the pure `Telemetry::ToJsonLine`), `TelemetrySink.h` (the interface and the three sinks) and + `TelemetryEvents.h` (the four session names; the catalogue grows with each emit call). `Salty/Core/` holds + `UTelemetrySubsystem`, `ASaltyGameMode`, `ASaltyGameState` and `SaltyCheats.cpp`. +- **The serialisation is one pure function** the sinks share, so the tests check the envelope without a sink. + The JSON Lines sink is an `FRunnable` draining an MPSC queue every two seconds and on `Flush`; `Emit` only + builds the line. Files are `Saved/Telemetry/session__<8 hex>.jsonl`, the hex being a per-instance id so + two PIE instances started in the same second never share a file. +- **Sink choice:** `-telemetry` or `telemetry.File 1` wins everywhere, including the editor, so a PIE session + with a dedicated server writes one file per instance; the log sink is the editor default; null otherwise. +- **The session id** is minted in `ASaltyGameMode::InitGameState`, written to `ASaltyGameState::SessionId` + (replicated, `OnRep` adopts it) and begun on the server directly. `ATemplateGameMode` now derives from + `ASaltyGameMode` so the template Blueprint game mode mints a session until step 3 replaces it. +- **`MarkCheatUsed` takes an optional command name** and puts it in the `cheat_used` payload; the spec's + no-argument signature still works. `bs.TelemetryTest` is that call, so it emits and taints in one. +- **`player_id` is empty on every peer** until step 3 mints one on the player state; `party_size` is the game + state's player count and is zero at `session_started` because the join has not happened yet. +- **The build string** is `FApp::GetBuildVersion()` plus the git short hash read by `Salty.Build.cs` (D-42). +- **Proved:** four `Salty.Core.Telemetry.*` tests; a standalone `-telemetry` run wrote `app_started`, + `session_started`, `session_ended`; a headless `-server` and a `-game` client each wrote a file carrying the + same `session_id` with `is_server` true and false; `bs.TelemetryTest` wrote `cheat_used` and every later line + carried `cheats_used: true`. diff --git a/Docs/Steps.md b/Docs/Steps.md index de292eb..7d59909 100644 --- a/Docs/Steps.md +++ b/Docs/Steps.md @@ -26,7 +26,7 @@ Status: `☐` not started · `◐` in progress · `☑` done · `⊘` dropped · | # | Step | Proves | Status | | --- | --- | --- | --- | | 1 | The project, two modules, tests, a dedicated server in the editor | It builds, tests run headless, and the server posture is real from the first commit | ◐ | -| 2 | The telemetry seam | Every later step can emit into something | ☐ | +| 2 | The telemetry seam | Every later step can emit into something | ☑ | | 3 | A body, a camera, an input map and the gym | You can walk, in both camera modes, on a server | ☐ | | 4 | The feel pass | The written checklist passes with a person at the keyboard | ☐ | | 5 | The ability foundation and the stat block, proved on dodge, blink and mud | Abilities predict cleanly, and every body has the one set of numbers every effect changes | ☐ | diff --git a/Docs/Worklog.md b/Docs/Worklog.md index d16fed0..49d5c29 100644 --- a/Docs/Worklog.md +++ b/Docs/Worklog.md @@ -5,6 +5,14 @@ the reasoning lives in the specs, this is the memory. ## Done +- 2026-09-16 — Step 2: `ITelemetrySink` with null, log and JSON Lines sinks; `FTelemetryEvent`, the envelope and + `Telemetry::ToJsonLine`; `TelemetryEvents` with the four session names; `UTelemetrySubsystem`; `ASaltyGameMode` + minting the session id into `ASaltyGameState`; `bs.TelemetryTest`; the git hash in the build string (D-42); + four Core tests. Proved standalone, and with a headless `-server` plus `-game` client sharing one session id. +- 2026-09-16 — The editor's MCP: the engine's experimental plugin only listens when `bAutoStartServer` is set, so + `.mcp.json` refused until `DefaultEditorPerProjectUserSettings.ini` set it (D-43). Enabled the Editor, + AutomationTest, GameplayTags, ConfigSettings and LiveCoding toolsets; before that the only toolset was skills. + Reconnect with `/mcp` after the editor is up. Live Coding must be closed before a shell build. - 2026-09-16 — Step 1: `Salty.uproject` (UE 5.8) at the root from the Third Person template, renamed from `ProjectSomething` with class redirects; `SaltyCore` and `Salty` modules; `SaltyServer.Target.cs` (unbuildable on the launcher, OD-04); `USaltyAssetManager` calling `InitGlobalData`; `Config/Tags/` with 23 root namespaces; diff --git a/Salty.uproject b/Salty.uproject index 9ba2c85..0931f87 100644 --- a/Salty.uproject +++ b/Salty.uproject @@ -58,6 +58,26 @@ { "Name": "MCPClientToolset", "Enabled": true + }, + { + "Name": "EditorToolset", + "Enabled": true + }, + { + "Name": "AutomationTestToolset", + "Enabled": true + }, + { + "Name": "GameplayTagsToolset", + "Enabled": true + }, + { + "Name": "ConfigSettingsToolset", + "Enabled": true + }, + { + "Name": "LiveCodingToolset", + "Enabled": true } ] } \ No newline at end of file diff --git a/Source/Salty/Core/SaltyCheats.cpp b/Source/Salty/Core/SaltyCheats.cpp new file mode 100644 index 0000000..109c547 --- /dev/null +++ b/Source/Salty/Core/SaltyCheats.cpp @@ -0,0 +1,28 @@ +// The bs.* console commands. Every one marks the session as cheated through the telemetry subsystem, so a +// playtest file that had a cheat in it can be filtered out later. Each step adds its own commands here. + +#include "Core/TelemetrySubsystem.h" +#include "Engine/GameInstance.h" +#include "Engine/World.h" +#include "HAL/IConsoleManager.h" + +namespace +{ + UTelemetrySubsystem* TelemetryFor(UWorld* World) + { + const UGameInstance* GameInstance = World ? World->GetGameInstance() : nullptr; + return GameInstance ? GameInstance->GetSubsystem() : nullptr; + } + + // bs.TelemetryTest: proves the seam end to end from the console. Emits cheat_used and taints the session. + FAutoConsoleCommandWithWorld CmdTelemetryTest( + TEXT("bs.TelemetryTest"), + TEXT("Emits a cheat_used telemetry event and marks the session as cheated."), + FConsoleCommandWithWorldDelegate::CreateLambda([](UWorld* World) + { + if (UTelemetrySubsystem* Telemetry = TelemetryFor(World)) + { + Telemetry->MarkCheatUsed(TEXT("bs.TelemetryTest")); + } + })); +} diff --git a/Source/Salty/Core/SaltyGameMode.cpp b/Source/Salty/Core/SaltyGameMode.cpp new file mode 100644 index 0000000..2ee021f --- /dev/null +++ b/Source/Salty/Core/SaltyGameMode.cpp @@ -0,0 +1,23 @@ +#include "Core/SaltyGameMode.h" +#include "Core/SaltyGameState.h" +#include "Salty.h" + +ASaltyGameMode::ASaltyGameMode() +{ + GameStateClass = ASaltyGameState::StaticClass(); +} + +void ASaltyGameMode::InitGameState() +{ + Super::InitGameState(); + + ASaltyGameState* SaltyGameState = GetGameState(); + if (!SaltyGameState) + { + // A Blueprint child that overrode GameStateClass with something else. Loud, because every telemetry + // file of this session would then be sessionless. + UE_LOG(LogSalty, Error, TEXT("%s: GameStateClass is not an ASaltyGameState; no session id will be minted"), *GetName()); + return; + } + SaltyGameState->SetSessionId(FGuid::NewGuid()); +} diff --git a/Source/Salty/Core/SaltyGameMode.h b/Source/Salty/Core/SaltyGameMode.h new file mode 100644 index 0000000..d05f032 --- /dev/null +++ b/Source/Salty/Core/SaltyGameMode.h @@ -0,0 +1,19 @@ +#pragma once + +#include "CoreMinimal.h" +#include "GameFramework/GameModeBase.h" +#include "SaltyGameMode.generated.h" + +// The server's game mode. Exists only on the server, which makes it the one place a session is minted. Step 3 +// adds login and spawning; until then the template's Blueprint game mode derives from it through +// ATemplateGameMode and inherits the session. +UCLASS() +class SALTY_API ASaltyGameMode : public AGameModeBase +{ + GENERATED_BODY() + +public: + ASaltyGameMode(); + + virtual void InitGameState() override; +}; diff --git a/Source/Salty/Core/SaltyGameState.cpp b/Source/Salty/Core/SaltyGameState.cpp new file mode 100644 index 0000000..85e6821 --- /dev/null +++ b/Source/Salty/Core/SaltyGameState.cpp @@ -0,0 +1,37 @@ +#include "Core/SaltyGameState.h" +#include "Core/TelemetrySubsystem.h" +#include "Engine/GameInstance.h" +#include "Engine/World.h" +#include "Net/UnrealNetwork.h" + +void ASaltyGameState::GetLifetimeReplicatedProps(TArray& OutLifetimeProps) const +{ + Super::GetLifetimeReplicatedProps(OutLifetimeProps); + DOREPLIFETIME(ASaltyGameState, SessionId); +} + +void ASaltyGameState::SetSessionId(const FGuid& InSessionId) +{ + if (!HasAuthority()) + { + return; + } + SessionId = InSessionId; + AdoptSessionId(); +} + +void ASaltyGameState::OnRep_SessionId() +{ + AdoptSessionId(); +} + +void ASaltyGameState::AdoptSessionId() +{ + if (const UGameInstance* GameInstance = GetGameInstance()) + { + if (UTelemetrySubsystem* Telemetry = GameInstance->GetSubsystem()) + { + Telemetry->BeginSession(SessionId); + } + } +} diff --git a/Source/Salty/Core/SaltyGameState.h b/Source/Salty/Core/SaltyGameState.h new file mode 100644 index 0000000..694c8ba --- /dev/null +++ b/Source/Salty/Core/SaltyGameState.h @@ -0,0 +1,31 @@ +#pragma once + +#include "CoreMinimal.h" +#include "GameFramework/GameStateBase.h" +#include "SaltyGameState.generated.h" + +// Replicated session facts. Step 2 carries the session id the server minted so every client's telemetry file +// belongs to the same session (Docs/Spec/Networking.md, Telemetry over the wire). +UCLASS() +class SALTY_API ASaltyGameState : public AGameStateBase +{ + GENERATED_BODY() + +public: + virtual void GetLifetimeReplicatedProps(TArray& OutLifetimeProps) const override; + + // Server only. Writes the id and starts the server's own telemetry session. + void SetSessionId(const FGuid& InSessionId); + + FGuid GetSessionId() const { return SessionId; } + +protected: + UFUNCTION() + void OnRep_SessionId(); + +private: + UPROPERTY(ReplicatedUsing = OnRep_SessionId) + FGuid SessionId; + + void AdoptSessionId(); +}; diff --git a/Source/Salty/Core/TelemetrySubsystem.cpp b/Source/Salty/Core/TelemetrySubsystem.cpp new file mode 100644 index 0000000..7745838 --- /dev/null +++ b/Source/Salty/Core/TelemetrySubsystem.cpp @@ -0,0 +1,137 @@ +#include "Core/TelemetrySubsystem.h" +#include "Salty.h" +#include "SaltyCore.h" +#include "Telemetry/TelemetryEvents.h" +#include "Telemetry/TelemetrySink.h" +#include "Engine/GameInstance.h" +#include "Engine/World.h" +#include "GameFramework/GameStateBase.h" +#include "HAL/IConsoleManager.h" +#include "Misc/App.h" +#include "Misc/CommandLine.h" +#include "Misc/Paths.h" + +#ifndef SALTY_GIT_HASH +#define SALTY_GIT_HASH "nogit" +#endif + +namespace +{ + // telemetry.File 1 installs the file sink on the next game instance (set it in the editor console before + // Play In Editor to get one file per PIE instance); -telemetry on the command line does the same. + TAutoConsoleVariable CVarTelemetryFile( + TEXT("telemetry.File"), 0, + TEXT("1: write telemetry to Saved/Telemetry/session_*.jsonl. Read when a game instance starts."), + ECVF_Default); +} + +void UTelemetrySubsystem::Initialize(FSubsystemCollectionBase& Collection) +{ + Super::Initialize(Collection); + + BuildString = FString::Printf(TEXT("%s+%s"), FApp::GetBuildVersion(), TEXT(SALTY_GIT_HASH)); + Sink = MakeDefaultSink(); + Emit(TelemetryEvents::AppStarted, FTelemetryPayload().Set(TEXT("engine"), FEngineVersion::Current().ToString())); +} + +void UTelemetrySubsystem::Deinitialize() +{ + if (HasSession()) + { + Emit(TelemetryEvents::SessionEnded); + } + if (Sink) + { + Sink->Flush(); + Sink.Reset(); + } + Super::Deinitialize(); +} + +TUniquePtr UTelemetrySubsystem::MakeDefaultSink() const +{ + const bool bFileRequested = FParse::Param(FCommandLine::Get(), TEXT("telemetry")) || CVarTelemetryFile.GetValueOnGameThread() != 0; + if (bFileRequested) + { + // One file per peer; the instance id keeps two PIE instances started in the same second apart. + const FString FileName = FString::Printf(TEXT("session_%s_%s.jsonl"), + *FDateTime::UtcNow().ToString(TEXT("%Y%m%d_%H%M%S")), + *FGuid::NewGuid().ToString(EGuidFormats::Digits).Left(8)); + const FString Path = FPaths::ProjectSavedDir() / TEXT("Telemetry") / FileName; + UE_LOG(LogTelemetry, Log, TEXT("Telemetry file sink: %s"), *Path); + return MakeUnique(Path); + } +#if WITH_EDITOR + if (GIsEditor) + { + return MakeUnique(); + } +#endif + return MakeUnique(); +} + +void UTelemetrySubsystem::SetSink(TUniquePtr InSink) +{ + if (Sink) + { + Sink->Flush(); + } + Sink = MoveTemp(InSink); + if (!Sink) + { + Sink = MakeUnique(); + } +} + +void UTelemetrySubsystem::Emit(FName Name, TSharedPtr Payload) +{ + if (!Sink) + { + return; + } + FTelemetryEvent Event; + Event.Name = Name; + Event.Payload = MoveTemp(Payload); + Sink->Emit(StampEnvelope(), Event); +} + +void UTelemetrySubsystem::BeginSession(FGuid InSessionId) +{ + if (!InSessionId.IsValid() || InSessionId == SessionId) + { + return; + } + SessionId = InSessionId; + Emit(TelemetryEvents::SessionStarted); +} + +void UTelemetrySubsystem::MarkCheatUsed(FName Command) +{ + bCheatsUsed = true; + Emit(TelemetryEvents::CheatUsed, FTelemetryPayload().Set(TEXT("command"), Command)); +} + +FTelemetryEnvelope UTelemetrySubsystem::StampEnvelope() const +{ + FTelemetryEnvelope Envelope; + Envelope.EventId = FGuid::NewGuid(); + Envelope.TimestampUtc = FDateTime::UtcNow(); + Envelope.SessionId = SessionId; + Envelope.Build = BuildString; + Envelope.bCheatsUsed = bCheatsUsed; + // PlayerId stays empty until step 3 mints one on the player state (Docs/Spec/Networking.md, Identity). + + const UGameInstance* GameInstance = GetGameInstance(); + const UWorld* World = GameInstance ? GameInstance->GetWorld() : nullptr; + if (World) + { + Envelope.GameTime = World->GetTimeSeconds(); + Envelope.bIsServer = World->GetNetMode() != NM_Client; // standalone is its own authority + Envelope.Map = UWorld::RemovePIEPrefix(World->GetMapName()); + if (const AGameStateBase* GameState = World->GetGameState()) + { + Envelope.PartySize = GameState->PlayerArray.Num(); + } + } + return Envelope; +} diff --git a/Source/Salty/Core/TelemetrySubsystem.h b/Source/Salty/Core/TelemetrySubsystem.h new file mode 100644 index 0000000..1136273 --- /dev/null +++ b/Source/Salty/Core/TelemetrySubsystem.h @@ -0,0 +1,45 @@ +#pragma once + +#include "CoreMinimal.h" +#include "Subsystems/GameInstanceSubsystem.h" +#include "Telemetry/TelemetryEvent.h" +#include "Telemetry/TelemetrySink.h" +#include "TelemetrySubsystem.generated.h" + +// The one seam gameplay emits through. Owns the sink, stamps the envelope, exposes Emit. Gameplay code resolves it +// from its game instance once and keeps the pointer; there is no static helper and there will not be one +// (Docs/Spec/Telemetry.md). Every peer has its own subsystem and its own file; nothing is forwarded. +UCLASS() +class SALTY_API UTelemetrySubsystem : public UGameInstanceSubsystem +{ + GENERATED_BODY() + +public: + virtual void Initialize(FSubsystemCollectionBase& Collection) override; + virtual void Deinitialize() override; + + // Stamps the envelope and hands the event to the sink. Name comes from TelemetryEvents, never a literal. + void Emit(FName Name, TSharedPtr Payload = nullptr); + + // The server mints the id in ASaltyGameMode; a client adopts the id replicated through ASaltyGameState. + void BeginSession(FGuid InSessionId); + + // Log in the editor, Jsonl with -telemetry or telemetry.File 1, Null otherwise. Public so a test can substitute. + void SetSink(TUniquePtr InSink); + + // Called by every bs.* console command. Sticky for the session: tainted sessions are filterable, not deleted. + void MarkCheatUsed(FName Command = NAME_None); + + bool HasSession() const { return SessionId.IsValid(); } + FGuid GetSessionId() const { return SessionId; } + bool WereCheatsUsed() const { return bCheatsUsed; } + +private: + FTelemetryEnvelope StampEnvelope() const; + TUniquePtr MakeDefaultSink() const; + + TUniquePtr Sink; + FGuid SessionId; + bool bCheatsUsed = false; + FString BuildString; +}; diff --git a/Source/Salty/Salty.Build.cs b/Source/Salty/Salty.Build.cs index 24cb66e..ea76c77 100644 --- a/Source/Salty/Salty.Build.cs +++ b/Source/Salty/Salty.Build.cs @@ -27,7 +27,11 @@ public class Salty : ModuleRules "Slate" }); - PrivateDependencyModuleNames.AddRange(new string[] { }); + PrivateDependencyModuleNames.AddRange(new string[] { "Json" }); + + // The telemetry envelope's build string carries the git hash. Read here at build time; a new commit + // changes the definition and rebuilds this module, which is the price of never lying about the build. + PrivateDefinitions.Add("SALTY_GIT_HASH=\"" + ReadGitHash() + "\""); PublicIncludePaths.AddRange(new string[] { "Salty", @@ -55,4 +59,32 @@ public class Salty : ModuleRules // To include OnlineSubsystemSteam, add it to the plugins section in your uproject file with the Enabled attribute set to true } + + private string ReadGitHash() + { + try + { + var StartInfo = new System.Diagnostics.ProcessStartInfo("git", "rev-parse --short HEAD") + { + WorkingDirectory = ModuleDirectory, + RedirectStandardOutput = true, + RedirectStandardError = true, + UseShellExecute = false, + CreateNoWindow = true + }; + using (var Process = System.Diagnostics.Process.Start(StartInfo)) + { + string Output = Process.StandardOutput.ReadToEnd().Trim(); + Process.WaitForExit(); + if (Process.ExitCode == 0 && Output.Length > 0) + { + return Output; + } + } + } + catch (System.Exception) + { + } + return "nogit"; + } } diff --git a/Source/Salty/TemplateGameMode.h b/Source/Salty/TemplateGameMode.h index ba4dada..2d35ead 100644 --- a/Source/Salty/TemplateGameMode.h +++ b/Source/Salty/TemplateGameMode.h @@ -3,14 +3,15 @@ #pragma once #include "CoreMinimal.h" -#include "GameFramework/GameModeBase.h" +#include "Core/SaltyGameMode.h" #include "TemplateGameMode.generated.h" /** - * Simple GameMode for a third person game + * Simple GameMode for a third person game. Derives from ASaltyGameMode so BP_ThirdPersonGameMode, the placeholder + * until step 3, mints a telemetry session like the real one will. */ UCLASS(abstract) -class ATemplateGameMode : public AGameModeBase +class ATemplateGameMode : public ASaltyGameMode { GENERATED_BODY() diff --git a/Source/SaltyCore/SaltyCore.Build.cs b/Source/SaltyCore/SaltyCore.Build.cs index 361d794..f3daea3 100644 --- a/Source/SaltyCore/SaltyCore.Build.cs +++ b/Source/SaltyCore/SaltyCore.Build.cs @@ -13,7 +13,8 @@ public class SaltyCore : ModuleRules "CoreUObject", "Engine", // UPrimaryDataAsset, FGameplayTag "GameplayTags", - "GameplayAbilities" // FGameplayAttribute in the damage maths + "GameplayAbilities", // FGameplayAttribute in the damage maths + "Json" // the telemetry payload and the JSON Lines sink }); PrivateDependencyModuleNames.AddRange(new string[] { }); diff --git a/Source/SaltyCore/SaltyCore.cpp b/Source/SaltyCore/SaltyCore.cpp index e388129..0036793 100644 --- a/Source/SaltyCore/SaltyCore.cpp +++ b/Source/SaltyCore/SaltyCore.cpp @@ -4,3 +4,4 @@ IMPLEMENT_MODULE(FDefaultModuleImpl, SaltyCore); DEFINE_LOG_CATEGORY(LogSaltyCore); +DEFINE_LOG_CATEGORY(LogTelemetry); diff --git a/Source/SaltyCore/SaltyCore.h b/Source/SaltyCore/SaltyCore.h index fbf3cf8..41ca27a 100644 --- a/Source/SaltyCore/SaltyCore.h +++ b/Source/SaltyCore/SaltyCore.h @@ -4,3 +4,5 @@ #include "Logging/LogMacros.h" SALTYCORE_API DECLARE_LOG_CATEGORY_EXTERN(LogSaltyCore, Log, All); +// Every event the log sink emits, one JSON line each (Docs/Spec/Telemetry.md). +SALTYCORE_API DECLARE_LOG_CATEGORY_EXTERN(LogTelemetry, Log, All); diff --git a/Source/SaltyCore/Telemetry/TelemetryEvent.cpp b/Source/SaltyCore/Telemetry/TelemetryEvent.cpp new file mode 100644 index 0000000..bc590e2 --- /dev/null +++ b/Source/SaltyCore/Telemetry/TelemetryEvent.cpp @@ -0,0 +1,28 @@ +#include "Telemetry/TelemetryEvent.h" +#include "Serialization/JsonSerializer.h" +#include "Serialization/JsonWriter.h" +#include "Policies/CondensedJsonPrintPolicy.h" + +FString Telemetry::ToJsonLine(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event) +{ + TSharedRef Root = MakeShared(); + Root->SetNumberField(TEXT("schema_version"), Envelope.SchemaVersion); + Root->SetStringField(TEXT("event_id"), Envelope.EventId.ToString(EGuidFormats::DigitsWithHyphensLower)); + Root->SetStringField(TEXT("timestamp_utc"), Envelope.TimestampUtc.ToIso8601()); + Root->SetNumberField(TEXT("game_time"), Envelope.GameTime); + Root->SetStringField(TEXT("session_id"), Envelope.SessionId.ToString(EGuidFormats::DigitsWithHyphensLower)); + Root->SetStringField(TEXT("player_id"), Envelope.PlayerId); + Root->SetBoolField(TEXT("is_server"), Envelope.bIsServer); + Root->SetNumberField(TEXT("party_size"), Envelope.PartySize); + Root->SetStringField(TEXT("build"), Envelope.Build); + Root->SetStringField(TEXT("map"), Envelope.Map); + Root->SetBoolField(TEXT("cheats_used"), Envelope.bCheatsUsed); + Root->SetStringField(TEXT("name"), Event.Name.ToString()); + Root->SetObjectField(TEXT("payload"), Event.Payload.IsValid() ? Event.Payload : MakeShared()); + + FString Line; + TSharedRef>> Writer = + TJsonWriterFactory>::Create(&Line); + FJsonSerializer::Serialize(Root, Writer); + return Line; +} diff --git a/Source/SaltyCore/Telemetry/TelemetryEvent.h b/Source/SaltyCore/Telemetry/TelemetryEvent.h new file mode 100644 index 0000000..3cd6365 --- /dev/null +++ b/Source/SaltyCore/Telemetry/TelemetryEvent.h @@ -0,0 +1,59 @@ +#pragma once + +#include "CoreMinimal.h" +#include "Dom/JsonObject.h" + +// One emission. Call sites fill Name (from TelemetryEvents) and Payload; the subsystem stamps the envelope. +struct SALTYCORE_API FTelemetryEvent +{ + FName Name; + TSharedPtr Payload; +}; + +// Stamped by the subsystem onto every event. Serialised with snake_case keys; see Telemetry::ToJsonLine. +struct SALTYCORE_API FTelemetryEnvelope +{ + int32 SchemaVersion = 1; + FGuid EventId; // unique per emission, for de-duplication + FDateTime TimestampUtc; + float GameTime = 0.f; // seconds since the world began; zero when there is no world yet + FGuid SessionId; // minted by the server, adopted by clients on join; invalid before a session + FString PlayerId; // hashed server-minted id; empty on the server + bool bIsServer = false; // authoritative events versus observed ones + int32 PartySize = 0; + FString Build; // FApp::GetBuildVersion() plus the git hash + FString Map; + bool bCheatsUsed = false; // sticky true after the first cheat this session +}; + +// A small fluent builder for payloads, so a call site reads as one expression: +// Telemetry->Emit(TelemetryEvents::CheatUsed, FTelemetryPayload().Set(TEXT("command"), Command)); +class SALTYCORE_API FTelemetryPayload +{ +public: + FTelemetryPayload() : Object(MakeShared()) {} + + FTelemetryPayload& Set(const FString& Key, const FString& Value) { Object->SetStringField(Key, Value); return *this; } + FTelemetryPayload& Set(const FString& Key, const TCHAR* Value) { Object->SetStringField(Key, Value); return *this; } + FTelemetryPayload& Set(const FString& Key, FName Value) { Object->SetStringField(Key, Value.ToString()); return *this; } + FTelemetryPayload& Set(const FString& Key, const FGuid& Value) { Object->SetStringField(Key, Value.ToString(EGuidFormats::DigitsWithHyphensLower)); return *this; } + FTelemetryPayload& Set(const FString& Key, double Value) { Object->SetNumberField(Key, Value); return *this; } + FTelemetryPayload& Set(const FString& Key, float Value) { Object->SetNumberField(Key, Value); return *this; } + FTelemetryPayload& Set(const FString& Key, int32 Value) { Object->SetNumberField(Key, Value); return *this; } + FTelemetryPayload& Set(const FString& Key, int64 Value) { Object->SetNumberField(Key, static_cast(Value)); return *this; } + FTelemetryPayload& Set(const FString& Key, bool Value) { Object->SetBoolField(Key, Value); return *this; } + + TSharedPtr Build() const { return Object; } + operator TSharedPtr() const { return Object; } + +private: + TSharedPtr Object; +}; + +namespace Telemetry +{ + // The one serialisation of an event: the envelope's fields as snake_case keys, then "name" and "payload" + // (an empty object when the event has none), condensed to a single line with no trailing newline. Pure, so + // the sinks share it and the tests can check it without a sink. + SALTYCORE_API FString ToJsonLine(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event); +} diff --git a/Source/SaltyCore/Telemetry/TelemetryEvents.h b/Source/SaltyCore/Telemetry/TelemetryEvents.h new file mode 100644 index 0000000..3b4a366 --- /dev/null +++ b/Source/SaltyCore/Telemetry/TelemetryEvents.h @@ -0,0 +1,15 @@ +#pragma once + +#include "CoreMinimal.h" + +// The event names. Every call site passes one of these to UTelemetrySubsystem::Emit; a literal at a call site is a +// typo waiting for the analysis to find it. A name is added here, to the catalogue in Docs/Spec/Telemetry.md and to +// the feature spec's Telemetry section in the same change as its first emit call, so the three never disagree. +namespace TelemetryEvents +{ + // Session (step 2) + inline const FName AppStarted(TEXT("app_started")); + inline const FName SessionStarted(TEXT("session_started")); + inline const FName SessionEnded(TEXT("session_ended")); + inline const FName CheatUsed(TEXT("cheat_used")); +} diff --git a/Source/SaltyCore/Telemetry/TelemetrySink.cpp b/Source/SaltyCore/Telemetry/TelemetrySink.cpp new file mode 100644 index 0000000..c38d3f9 --- /dev/null +++ b/Source/SaltyCore/Telemetry/TelemetrySink.cpp @@ -0,0 +1,119 @@ +#include "Telemetry/TelemetrySink.h" +#include "SaltyCore.h" +#include "HAL/PlatformFileManager.h" +#include "HAL/RunnableThread.h" +#include "HAL/Event.h" +#include "GenericPlatform/GenericPlatformFile.h" +#include "Misc/CoreDelegates.h" +#include "Misc/Paths.h" + +void FLogTelemetrySink::Emit(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event) +{ + UE_LOG(LogTelemetry, Log, TEXT("%s"), *Telemetry::ToJsonLine(Envelope, Event)); +} + +FJsonlTelemetrySink::FJsonlTelemetrySink(const FString& InFilePath, double InDrainIntervalSeconds) + : FilePath(InFilePath) + , DrainIntervalSeconds(FMath::Max(InDrainIntervalSeconds, 0.01)) +{ + WakeEvent = FPlatformProcess::GetSynchEventFromPool(false); + DrainedEvent = FPlatformProcess::GetSynchEventFromPool(false); + Thread = FRunnableThread::Create(this, TEXT("TelemetryJsonlSink"), 0, TPri_BelowNormal); + + OnExitHandle = FCoreDelegates::OnExit.AddRaw(this, &FJsonlTelemetrySink::Flush); + OnSystemErrorHandle = FCoreDelegates::OnHandleSystemError.AddRaw(this, &FJsonlTelemetrySink::Flush); +} + +FJsonlTelemetrySink::~FJsonlTelemetrySink() +{ + FCoreDelegates::OnExit.Remove(OnExitHandle); + FCoreDelegates::OnHandleSystemError.Remove(OnSystemErrorHandle); + + bStopping = true; + WakeEvent->Trigger(); + if (Thread) + { + Thread->WaitForCompletion(); // Run drains once more on its way out + delete Thread; + Thread = nullptr; + } + Drain(); // anything queued after the thread's last pass + File.Reset(); + + FPlatformProcess::ReturnSynchEventToPool(WakeEvent); + FPlatformProcess::ReturnSynchEventToPool(DrainedEvent); +} + +void FJsonlTelemetrySink::Emit(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event) +{ + // The whole cost on the caller's thread: one string and one enqueue. + Queue.Enqueue(Telemetry::ToJsonLine(Envelope, Event)); +} + +void FJsonlTelemetrySink::Flush() +{ + if (!Thread || bStopping) + { + Drain(); + return; + } + + const uint64 Ticket = ++FlushesRequested; + WakeEvent->Trigger(); + // Bounded wait: a flush from the crash handler must not hang the process on a wedged disk. + const double Deadline = FPlatformTime::Seconds() + 5.0; + while (FlushesCompleted.Load() < Ticket && FPlatformTime::Seconds() < Deadline) + { + DrainedEvent->Wait(50); + } +} + +uint32 FJsonlTelemetrySink::Run() +{ + const uint32 IntervalMs = static_cast(FMath::Clamp(DrainIntervalSeconds * 1000.0, 10.0, 3600.0 * 1000.0)); + while (!bStopping) + { + WakeEvent->Wait(IntervalMs); + const uint64 Ticket = FlushesRequested.Load(); + Drain(); + FlushesCompleted.Store(Ticket); + DrainedEvent->Trigger(); + } + Drain(); + return 0; +} + +void FJsonlTelemetrySink::Stop() +{ + bStopping = true; + WakeEvent->Trigger(); +} + +void FJsonlTelemetrySink::Drain() +{ + // Single consumer: the worker while it runs, the destructor after it has joined. Never both. + FString Line; + bool bWroteAnything = false; + while (Queue.Dequeue(Line)) + { + if (!File) + { + IPlatformFile& PlatformFile = FPlatformFileManager::Get().GetPlatformFile(); + PlatformFile.CreateDirectoryTree(*FPaths::GetPath(FilePath)); + File.Reset(PlatformFile.OpenWrite(*FilePath, /*bAppend*/ true, /*bAllowRead*/ true)); + if (!File) + { + UE_LOG(LogTelemetry, Warning, TEXT("Cannot open telemetry file %s; dropping events"), *FilePath); + continue; + } + } + Line.AppendChar(TEXT('\n')); + const FTCHARToUTF8 Utf8(*Line); + File->Write(reinterpret_cast(Utf8.Get()), Utf8.Length()); + bWroteAnything = true; + } + if (File && bWroteAnything) + { + File->Flush(); + } +} diff --git a/Source/SaltyCore/Telemetry/TelemetrySink.h b/Source/SaltyCore/Telemetry/TelemetrySink.h new file mode 100644 index 0000000..124585b --- /dev/null +++ b/Source/SaltyCore/Telemetry/TelemetrySink.h @@ -0,0 +1,69 @@ +#pragma once + +#include "CoreMinimal.h" +#include "Containers/Queue.h" +#include "HAL/Runnable.h" +#include "Telemetry/TelemetryEvent.h" + +class FRunnableThread; +class FEvent; +class IFileHandle; + +// Where events go. The emitter never knows. Three implementations on day one; a fourth adapts an analytics +// provider when there is one (Docs/Spec/Telemetry.md, Q2). +class SALTYCORE_API ITelemetrySink +{ +public: + virtual ~ITelemetrySink() = default; + virtual void Emit(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event) = 0; + virtual void Flush() {} +}; + +// Does nothing. The shipping default until there is somewhere to send anything. +class SALTYCORE_API FNullTelemetrySink : public ITelemetrySink +{ +public: + virtual void Emit(const FTelemetryEnvelope&, const FTelemetryEvent&) override {} +}; + +// One line of JSON to the output log under LogTelemetry. Verifies a step emitted what it claims. +class SALTYCORE_API FLogTelemetrySink : public ITelemetrySink +{ +public: + virtual void Emit(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event) override; +}; + +// Appends one line per event to a JSON Lines file. Emit only builds the line and queues it; a worker thread +// drains the queue to disk every DrainIntervalSeconds and on Flush, so the calling thread never touches the +// file. Flushed on quit and from the unhandled-exception handler, so a crash loses at most one interval. +class SALTYCORE_API FJsonlTelemetrySink : public ITelemetrySink, private FRunnable +{ +public: + explicit FJsonlTelemetrySink(const FString& InFilePath, double DrainIntervalSeconds = 2.0); + virtual ~FJsonlTelemetrySink() override; + + virtual void Emit(const FTelemetryEnvelope& Envelope, const FTelemetryEvent& Event) override; + virtual void Flush() override; + + const FString& GetFilePath() const { return FilePath; } + +private: + // FRunnable + virtual uint32 Run() override; + virtual void Stop() override; + + void Drain(); + + FString FilePath; + double DrainIntervalSeconds; + TQueue Queue; + TUniquePtr File; + FEvent* WakeEvent = nullptr; + FEvent* DrainedEvent = nullptr; + FRunnableThread* Thread = nullptr; + TAtomic bStopping{ false }; + TAtomic FlushesRequested{ 0 }; + TAtomic FlushesCompleted{ 0 }; + FDelegateHandle OnExitHandle; + FDelegateHandle OnSystemErrorHandle; +}; diff --git a/Source/SaltyCore/Tests/PlaceholderTest.cpp b/Source/SaltyCore/Tests/PlaceholderTest.cpp deleted file mode 100644 index c72862e..0000000 --- a/Source/SaltyCore/Tests/PlaceholderTest.cpp +++ /dev/null @@ -1,16 +0,0 @@ -#include "Misc/AutomationTest.h" - -#if WITH_DEV_AUTOMATION_TESTS - -// Proves the test pipeline itself: Scripts/run-tests.sh finds the Salty.Core filter, runs it headless, and reports. -// Replaced by real rule tests from step 2 onwards; it may be deleted once another Salty.Core.* test exists. -IMPLEMENT_SIMPLE_AUTOMATION_TEST(FSaltyCorePlaceholderTest, "Salty.Core.Placeholder.Compiles", - EAutomationTestFlags::ProductFilter | EAutomationTestFlags_ApplicationContextMask) - -bool FSaltyCorePlaceholderTest::RunTest(const FString& Parameters) -{ - TestTrue(TEXT("The core module compiles and its tests run"), true); - return true; -} - -#endif diff --git a/Source/SaltyCore/Tests/TelemetryTests.cpp b/Source/SaltyCore/Tests/TelemetryTests.cpp new file mode 100644 index 0000000..9cfb10b --- /dev/null +++ b/Source/SaltyCore/Tests/TelemetryTests.cpp @@ -0,0 +1,154 @@ +#include "Misc/AutomationTest.h" +#include "Telemetry/TelemetryEvent.h" +#include "Telemetry/TelemetryEvents.h" +#include "Telemetry/TelemetrySink.h" +#include "Dom/JsonObject.h" +#include "Serialization/JsonSerializer.h" +#include "Serialization/JsonReader.h" +#include "HAL/FileManager.h" +#include "Misc/FileHelper.h" +#include "Misc/Paths.h" + +#if WITH_DEV_AUTOMATION_TESTS + +namespace +{ + FTelemetryEnvelope MakeEnvelope() + { + FTelemetryEnvelope Envelope; + Envelope.EventId = FGuid::NewGuid(); + Envelope.TimestampUtc = FDateTime::UtcNow(); + Envelope.GameTime = 12.5f; + Envelope.SessionId = FGuid::NewGuid(); + Envelope.PlayerId = TEXT("abc123"); + Envelope.bIsServer = true; + Envelope.PartySize = 2; + Envelope.Build = TEXT("test+deadbeef"); + Envelope.Map = TEXT("L_Gym"); + Envelope.bCheatsUsed = true; + return Envelope; + } + + FString TempJsonlPath() + { + return FPaths::ProjectSavedDir() / TEXT("Automation/Telemetry") / FGuid::NewGuid().ToString(EGuidFormats::Digits) + TEXT(".jsonl"); + } + + bool ParseObject(const FString& Line, TSharedPtr& OutObject) + { + const TSharedRef> Reader = TJsonReaderFactory<>::Create(Line); + return FJsonSerializer::Deserialize(Reader, OutObject) && OutObject.IsValid(); + } +} + +IMPLEMENT_SIMPLE_AUTOMATION_TEST(FTelemetryEnvelopeCarriesEveryFieldTest, "Salty.Core.Telemetry.Envelope.CarriesEveryField", + EAutomationTestFlags::ProductFilter | EAutomationTestFlags_ApplicationContextMask) + +bool FTelemetryEnvelopeCarriesEveryFieldTest::RunTest(const FString& Parameters) +{ + const FTelemetryEnvelope Envelope = MakeEnvelope(); + FTelemetryEvent Event; + Event.Name = TelemetryEvents::SessionStarted; + Event.Payload = FTelemetryPayload().Set(TEXT("answer"), 42).Set(TEXT("tag"), TEXT("x")); + + TSharedPtr Object; + if (!TestTrue(TEXT("the line parses"), ParseObject(Telemetry::ToJsonLine(Envelope, Event), Object))) + { + return false; + } + + TestEqual(TEXT("schema_version"), static_cast(Object->GetNumberField(TEXT("schema_version"))), Envelope.SchemaVersion); + TestEqual(TEXT("event_id"), Object->GetStringField(TEXT("event_id")), Envelope.EventId.ToString(EGuidFormats::DigitsWithHyphensLower)); + TestEqual(TEXT("timestamp_utc"), Object->GetStringField(TEXT("timestamp_utc")), Envelope.TimestampUtc.ToIso8601()); + TestEqual(TEXT("game_time"), static_cast(Object->GetNumberField(TEXT("game_time"))), Envelope.GameTime); + TestEqual(TEXT("session_id"), Object->GetStringField(TEXT("session_id")), Envelope.SessionId.ToString(EGuidFormats::DigitsWithHyphensLower)); + TestEqual(TEXT("player_id"), Object->GetStringField(TEXT("player_id")), Envelope.PlayerId); + TestEqual(TEXT("is_server"), Object->GetBoolField(TEXT("is_server")), Envelope.bIsServer); + TestEqual(TEXT("party_size"), static_cast(Object->GetNumberField(TEXT("party_size"))), Envelope.PartySize); + TestEqual(TEXT("build"), Object->GetStringField(TEXT("build")), Envelope.Build); + TestEqual(TEXT("map"), Object->GetStringField(TEXT("map")), Envelope.Map); + TestEqual(TEXT("cheats_used"), Object->GetBoolField(TEXT("cheats_used")), Envelope.bCheatsUsed); + TestEqual(TEXT("name"), Object->GetStringField(TEXT("name")), TelemetryEvents::SessionStarted.ToString()); + TestEqual(TEXT("payload.answer"), static_cast(Object->GetObjectField(TEXT("payload"))->GetNumberField(TEXT("answer"))), 42); + TestEqual(TEXT("payload.tag"), Object->GetObjectField(TEXT("payload"))->GetStringField(TEXT("tag")), FString(TEXT("x"))); + return true; +} + +IMPLEMENT_SIMPLE_AUTOMATION_TEST(FTelemetryEventNoPayloadTest, "Salty.Core.Telemetry.Event.NoPayloadIsEmptyObject", + EAutomationTestFlags::ProductFilter | EAutomationTestFlags_ApplicationContextMask) + +bool FTelemetryEventNoPayloadTest::RunTest(const FString& Parameters) +{ + FTelemetryEvent Event; + Event.Name = TelemetryEvents::AppStarted; + const FString Line = Telemetry::ToJsonLine(MakeEnvelope(), Event); + + TSharedPtr Object; + if (!TestTrue(TEXT("the line parses"), ParseObject(Line, Object))) + { + return false; + } + const TSharedPtr* Payload = nullptr; + TestTrue(TEXT("payload is an object"), Object->TryGetObjectField(TEXT("payload"), Payload)); + TestTrue(TEXT("payload is empty"), Payload && (*Payload)->Values.Num() == 0); + TestTrue(TEXT("the line is a single line"), !Line.Contains(TEXT("\n"))); + return true; +} + +IMPLEMENT_SIMPLE_AUTOMATION_TEST(FTelemetryJsonlOneLinePerEventTest, "Salty.Core.Telemetry.Jsonl.OneValidLinePerEvent", + EAutomationTestFlags::ProductFilter | EAutomationTestFlags_ApplicationContextMask) + +bool FTelemetryJsonlOneLinePerEventTest::RunTest(const FString& Parameters) +{ + const FString Path = TempJsonlPath(); + constexpr int32 Count = 25; + { + FJsonlTelemetrySink Sink(Path, /*DrainIntervalSeconds*/ 3600.0); + for (int32 Index = 0; Index < Count; ++Index) + { + FTelemetryEvent Event; + Event.Name = TelemetryEvents::CheatUsed; + Event.Payload = FTelemetryPayload().Set(TEXT("index"), Index); + Sink.Emit(MakeEnvelope(), Event); + } + Sink.Flush(); + } + + TArray Lines; + TestTrue(TEXT("the file exists after Flush"), FFileHelper::LoadFileToStringArray(Lines, *Path)); + TestEqual(TEXT("one line per event"), Lines.Num(), Count); + for (int32 Index = 0; Index < Lines.Num(); ++Index) + { + TSharedPtr Object; + if (!TestTrue(FString::Printf(TEXT("line %d parses"), Index), ParseObject(Lines[Index], Object))) + { + continue; + } + TestEqual(FString::Printf(TEXT("line %d is in order"), Index), static_cast(Object->GetObjectField(TEXT("payload"))->GetNumberField(TEXT("index"))), Index); + } + IFileManager::Get().Delete(*Path); + return true; +} + +IMPLEMENT_SIMPLE_AUTOMATION_TEST(FTelemetryJsonlEmitDoesNotTouchFileTest, "Salty.Core.Telemetry.Jsonl.EmitDoesNotTouchTheFile", + EAutomationTestFlags::ProductFilter | EAutomationTestFlags_ApplicationContextMask) + +bool FTelemetryJsonlEmitDoesNotTouchFileTest::RunTest(const FString& Parameters) +{ + // The rule is "never blocks the caller longer than building the object". The observable form of that rule: + // Emit does no file work at all; only the worker's drain (here deferred by the interval) or Flush writes. + const FString Path = TempJsonlPath(); + { + FJsonlTelemetrySink Sink(Path, /*DrainIntervalSeconds*/ 3600.0); + FTelemetryEvent Event; + Event.Name = TelemetryEvents::AppStarted; + Sink.Emit(MakeEnvelope(), Event); + TestFalse(TEXT("no file after Emit alone"), IFileManager::Get().FileExists(*Path)); + Sink.Flush(); + TestTrue(TEXT("the file exists after Flush"), IFileManager::Get().FileExists(*Path)); + } + IFileManager::Get().Delete(*Path); + return true; +} + +#endif