Design low-overhead PFE performance observability and correct tick telemetry

Planning discussion requested by user while production deployment is unavailable for several hours. Improve continuous visibility into CPU, managed/native memory, allocation/GC/allocator pressure, world load and actual tick health; make long-range dashboards usable without Prometheus timeouts. User now authorizes implementation and a localhost-only Prometheus/Grafana validation stack using synthetic fixtures. Implementation worktree /home/mathias/Projects/worktrees/engines-observability, branch feature/pfe-performance-observability from origin/develop94a816246. No production deployment, restart, profiler attachment or production configuration change authorized. Local fixture tests must clearly distinguish synthetic gameplay signals from real process/runtime/allocator measurements. Evidence/reuse - Current MetricsService pf_tick_rate_milliseconds histogram has27 finite buckets plus +Inf, with playfield_id and static engine/environment labels. Playfield.SetupBackgroundTasks measures DateTime.Now elapsed work before timer wait, maintains last100 samples and observes their rolling average every iteration: not actual tick frequency or raw tail distribution. Several instances share playfield labels; gauges such as online players are set independently by instances and can overwrite rather than aggregate. - Repository observability/prometheus.yaml scrapes/evaluates15s and has no recording rules. Only market dashboard is versioned here; exact production tick PromQL/dashboard step/TSDB cardinality/resource limits remain unknown, so bucket count alone is not a proven timeout cause. - Existing GC cumulative pause gauge, native query histograms, logical navmesh live/alloc/free counts and collision-mesh byte proxy can be extended. Bepu proxy is not full BufferPool capacity. Five-minute GC diagnostic log subtracts private process bytes minus managed committed bytes as NativeMb: heuristic, not measured native live allocation. GetGCMemoryInfo reflects last-GC snapshots, not current rooted live bytes. Navigation allocator byte counters are presently PRK_NAVIGATION_TESTING-only. - Link earlier true CPU analysis tsk_nka9m9gvx8 and managed/native memory investigation tsk_dx96mv5x98; retain on-CPU vs wall-clock and mapped/committed vs resident distinctions. Researched system design (implemented and locally validated below) 1. Correct monotonic-clock raw tick execution and start-to-start timing; counters for completed ticks, execution time, budget violations, active-instance time and expected tick slots. Separate active/sleeping work and bounded indoor/outdoor/mission cohorts; aggregate instance gauges centrally instead of last-writer-wins. Internal bounded per-instance diagnostics for worst tickers without unbounded Prometheus instance-ID labels. 2. Recording rules for fleet/per-engine/cohort tick means, actual/target throughput and budget-violation ratios plus sparse histogram bucket rates for tails. Long dashboards consume fixed-window precomputed series with bounded points; arbitrary-range percentiles require bucket-preserving aggregation, never averaged p99s. Investigate actual slow PromQL, sample counts/cardinality and Grafana step before replacing storage. 3. Reuse existing runtime/process/container/node telemetry where present. Export CPU seconds/rate, quota/throttling/threadpool pressure, allocation bytes/rate, collections and GC pause, last-GC committed/heap/fragmentation generations, process RSS/anonymous/swap and cgroup/file-cache distinctions; host PSI/swap faults and CPU saturation. 4. Bounded, infrequent background allocator snapshots (glibc mallinfo2 with caveats; expensive malloc_info only diagnostic) cached for scrape; exact owned navmesh/Bepu live capacity and allocation/free/churn counters where practical. Never force GC/malloc_trim or walk native heaps on heartbeat/scrape threads. No RSS-minus-managed label presented as exact native memory. 5. Unified dashboard and bounded overload diagnostics correlated to deployment/world size, with explicit telemetry CPU/allocation/lock and cardinality budgets. Continuous/scheduled profiles need verified true on-CPU semantics and overhead on kernel5.15; keep dumps/deep tracing exceptional. Proposed acceptance gates for implementation: fixed contracts and label allowlist; <=2,000 incremental raw series/PFE with computed series inventory; <=1% measured aggregate CPU overhead under production-shaped serial/parallel/churn load with no material p99 regression; fixed telemetry memory cap16MiB/PFE;24h overview queries<2s and7d<5s cold/warm on representative TSDB, <=1,000 points/series; collector/rule/export freshness and drop counters visible. These are proposed budgets, not measured production guarantees. Migration and rollback must be validated with restart/reset/idle/sleep/wake/stall/GC/parallel/disposal/error/backend-outage fixtures. Implementation items must not be marked complete during planning. User supplied current query: histogram_quantile(0.50, sum by (server_tag, le) (rate(pf_tick_rate_milliseconds_bucket[5m]))). User explicitly requests deep research and a fresh metrics/dashboard/system design, without inspecting existing Grafana dashboards; include actionable attribution explaining why a tick is slow. Research official Prometheus/Grafana/OpenTelemetry/.NET/Linux references and actual engine tick ownership before proposing architecture. Existing query syntactically follows rate-before-sum but computes environment-wide median of already-smoothed execution durations, hiding per-PFE/instance tails. Actual production TSDB/resource limits remain unverified; do not claim a proven timeout cause. Deliver design in chat unless standalone document requested; no implementation or deployment. Research conclusions and metric contract - Existing environment-wide median query is valid histogram PromQL but wrong health contract: p50 hides unhealthy minority PFs/engines, observation is rolling100tick work average not cadence/raw duration, sampled population is iteration-weighted, and engine/instance identity disappears.28 bucket series plus sum/count =30 series per labelset; bucket count alone not evidence of a one-hour timeout. Start fresh semantic families in seconds/bytes with stable environment/PFE-role/host/cohort labels; cohort outdoor/static_indoor/mission; deployment commit only on one build_info metric. Player/NPC names, random instances, per-tick IDs and arbitrary failure text prohibited in metrics (and Loki indexed labels). - Root timing from monotonic clock: execution elapsed seconds, positive start-to-start interval seconds, completed/failed tick counters, expected slots computed from active enabled lifecycle time and configured target (current16ms =62.5Hz), budget overruns using actual configured budget, gap/stall counts with documented tolerance, independent watchdog running/last-completion age and overdue-instance aggregate. Pause expected-time accounting on deliberate sleep/disable, distinguish maintenance/sleep work; reset interval baseline at wake and initialization. Slow loop emits fewer observations: combine tick-weighted histogram with instance-health/watchdog counts, not just percentiles. - Replace current rolling average histogram; sparse classic execution/interval distributions (candidate finite boundaries .001/.002/.004/.008/.012/.016/.024/.032/.05/.1/.25/1seconds,12 finite +Inf +sum/count =15series per labelset). Evaluate native histogram/NHCB ingestion as separately version/compatibility-gated optimization, not requirement: prometheus-net8.2.1 README documents classic histograms/exemplars but no native histogram API. Keep explicit overrun counters for exact target compliance if target changes. Counters and full distributions preserved; never average percentiles or per-PF averages. Slow-tick attribution architecture - Extend existing PfSystemManager timing boundary rather than a second timer path. Replace100-element Lists/RemoveAt(0)/locks with owner-local numeric accumulators and bounded fixed circular records. Record root mutually exclusive phases playfield_systems/players/maintenance, plus nested per-system OnTick durations: Indoor/OutdoorCellManagement includes NPC work, so show a hierarchy, not stacked double-counted sums. Exceptions included in finally. Existing NPC/player hook methods are not timed; selective rotating sampled hook/cell/NPC details and rate-limited temporary diagnostic bursts fill this gap instead of all-NPC/all-span instrumentation. - Capture compact primitive slow-tick records with PFE/cohort/private instanceID, sequence, UTC +monotonic durations, start gap, largest system/cell phase, workload counts, explicit measured lock/query waits where instrumentation exists, GC pause counter advancement and timestamped process pressure context. No retained Character/Playfield/Session/Activity graphs, no process-wide syscall CPU samples per NPC, no per-NPC Prometheus labels. Parallel-cell worker measurements owner-local and merged with explicit semantics: worker-time sums may exceed wall critical path and are not CPU time. - Critical waits currently hidden: NPC TickLock and synchronous OnCharacterTick.WaitAndUnwrapException, pathfinding _queryLock and Bepu ReaderWriterLockSlim. Existing native query timers start AFTER acquiring locks, so split acquire-wait from held/work time. Include relevant external/DB/queue waits but do not assign all unaccounted time to GC. GC pause advancement overlaps all concurrent playfields; process pause seconds are not additive per-instance CPU. Longer elapsed than on-CPU can be lock/off-CPU/runtime scheduling; exact GC overlap/CPU attribution requires event/profile evidence. - Always keep cheap top-level/system timings so the first slow tick has useful context. Sample deeper healthy-path details; a slow incident arms bounded increased detail for subsequent ticks and stores the actual available evidence for the first. Default every1000th Activity misses rare incidents: tail sampler cannot recover Activities never created/head-dropped. Do not record/export every NPC span for tail sampling. Export compact rate-limited structured SlowTick records to Loki; optional retained trace exemplars point only to real exported traces; record IDs/instance IDs in log body/structured metadata, not indexed labels. Suggested export1slow record/s/PFE burst5 with suppression counts, local worst reports kept within16MiBcap; counters track all slow ticks despite dropped/export-suppressed records. Existing .pf detail view can read same snapshots; authenticated bounded diagnostic access reuses staff authorization. Process, memory and allocator contract - Reuse allowlisted prometheus-net MeterAdapter/EventCounter defaults. Version8.2.1 enables both by default; validate exported names/types and choose one source per metric. .NET9 built-in System.Runtime CPU mode counters, total allocated bytes, GC collections/pause, last-collection heap/committed/fragmentation by generation, threadpool queue/thread/completions, contention and JIT metrics cover most needs. .NET8 fallback only where necessary; no duplicated collectors. Allocation is approximate managed bytes; committed/sizes/fragmentation are last-GC snapshots with explicit snapshot index/timestamp/age, not exact current rooted live bytes. Pause fraction does not equal GC CPU. - Host/node +container exporters provide CPU quota/throttle/PSI/major faults/swapin-out and memory current/anon/file/swap/events/limits; process RSS/RssAnon/private virtual not conflated. PSI reports stalls, not utilization, with capability detection for cgroup2/kernel support. Allocator free-retained capacity is not itself pressure; alert on PSI/swap/headroom/latency or sustained growth normalized to uptime/world churn. - Bepu full pool capacity/body/static/simulation counts, navmesh tile/query/pool owned bytes and alloc/free/churn complement process/runtime stats. Existing collision-triangle metric is only proxy; nav live counts cannot detect skipped child destruction. Production native wrapper currently counts allocation bytes only in PRK_NAVIGATION_TESTING. Exact wrapper counters cover only instrumented owned allocations, not all native libc/JIT/thread/file mappings. - glibc man-page all-arenas claim is inconsistent with actual glibc2.35 and2.36 source (__libc_mallinfo2 iterates all arenas under mutex, traverses free bins; keepcost only main top). Verify actual production container libc before use. mallinfo2 uordblks includes allocator overhead/tcache state, not semantic live objects; arena/hblkhd mapped-space statistics are not RSS or generic process mmap totals. Collect off-heartbeat/off-scrape no faster than60s initially, benchmark duration/contention, cache sample +age/errors; disable future collection if costly. malloc_info XML includes all arena detail but is also locked/expensive: on-demand or much slower cadence with bounded output, no automatic trim/forcedGC/tuning. Use allocator diagnostics for category separation, not fabricated owner attribution. Dashboard/query design - Fresh versioned Grafana dashboards: fleet health, per-PFE/tick drilldown, memory/allocator, gameplay queues/latency, telemetry pipeline health. Overview lists four PFE rows with CPU cores, tick attainment/budget violation, p95/p99 raw durations, overdue instances, allocation/GC pause, RSS/anon/swap and world size; no environment-only median as primary health. Tick drilldown combines exclusive root phase +inclusive system hierarchy and time-linked slow-tick reports/profiles. Memory distinguishes mapped/committed/resident/owned and freshness. Queue latency exposes player-impact even when tick work cheap. Telemetry page shows scrape payload/samples/duration/errors, label series/churn, native collector duration/age, ring saturation/drops, rule duration/missed evaluations, exporters backlog/drop metrics. - Prometheus remains primary metrics store.15s scrape initially,30s5minute recording groups for count/sum/bucket rates, ratios, CPU/allocation/GC and system elapsed costs at engine/cohort/fleet levels. Rate original series before aggregation, aggregate numerator/denominator separately; idle denominators produce no-data, not false healthy0. Record p95/p99 for standard rolling5m dashboards. Whole-selected-range quantiles derive from preserved bucket increments, never avg_over_time(p99); label standard plots explicitly rolling5m. Recording rules move repeated computation, not downsampling or magic cure for high cardinality; monitor them. Grafana Range only for trends, Instant only for summary tables, cap~1000points and use recorded series with appropriate long-range steps. Scope environment/PFE, avoid unbounded repeated panels. Raw buckets only narrow-time diagnostic views. Pin dependency versions and provision dashboards/rules in repo. Validation evidence (research prototypes only) - /tmp/pfe-observability-research/rules.yml defines6 illustrative recording rules; promtool3.5.0 check passes. tests.yml covers correctly weighted two-engine means (5ms/20ms at2:1counts ->10ms, not12.5ms), idle cohort missing-data semantics, and reset handling before aggregation. promtool test rules passes using fuzzy_compare for one-bit float rounding. No representative TSDB24h/7d performance test yet, no app instrumentation implemented. - Repository git status remains clean; all research/prototype files outside repo. Sources: prometheus.io/docs/practices/{instrumentation,histograms,naming,rules}/; prometheus.io/docs/prometheus/latest/{configuration/recording_rules,configuration/unit_testing_rules,querying/api}/; grafana.com/docs/grafana/latest/datasources/prometheus/query-editor/; learn.microsoft.com/en-us/dotnet/core/diagnostics/built-in-metrics-runtime; docs.kernel.org/accounting/psi.html; opentelemetry.io/docs/concepts/sampling/; github.com/prometheus-net/prometheus-net/blob/v8.2.1/README.md; man7.org mallinfo/malloc_info and bminor/glibc release/2.35 and2.36 malloc source. Verified implementation and local validation - Worktree /home/mathias/Projects/worktrees/engines-observability, branch feature/pfe-performance-observability from94a816246. No production changes. Pull request - #2596: feature: Add PFE performance telemetry and dashboards - https://git.project-rk.com/prk/engines/pulls/2596 - Head feature/pfe-performance-observability -> develop; ready for review, no conflicts reported. Upstream established; worktree clean. - Commits c82c0cc6c (engine telemetry) and8767a2eae (local dashboards/validation). User /open-pr explicitly authorized staging, commits, push and creation. Generated caches/publish outputs excluded. - Final PR preparation repeated warnings-as-errors engine build (zero warnings/errors),28focused telemetry/pump tests (allpass),45dashboard queries and12historical range checks. Earlier broader353+118passing suites and7asset/capture-dependent skips preserved as separate validation evidence. No task status change merely for PR creation. Dedicated PfePerformanceTelemetry registry owns bounded primitive tick/queue/physics sources, cached metric children, fixed histories, independent aggregation and slow-export threads. Tick sources record raw monotonic execution/cadence, expected active slots even when stalled, failures/overruns/gaps, centralized population/queue gauges and watchdog age. Root phases are exclusive; all per-tick OnTick system durations/failures are retained in immutable slow snapshots. Sampled/burst waits cover character Monitor acquisition, synchronous async waiting, navigation Monitor and physics RW-lock entry. Explicit thread-local context/sequence guards support cell workers without retaining entities/Activity graphs. Staff .pf performance view reads the recorder. - New runtime/process/cgroup/PSI collectors use canonical cached runtime APIs and capability/freshness/error/duration signals; PFE automatic default adapters suppressed to avoid duplicate sources. Other engines retain their defaults. GC generation counts are disjoint maximum-generation collections; last-GC freshness is explicit. glibc sampling opt-in (off in production by default), one dedicated sampler per minute, >20ms disables future collection; no forcedGC/trim/tuning. Navigation allocator headers provide aligned production live/total-byte accounting and lifetime tests; Bepu full capacity uses public GetCapacityForPower owner-side caching, without reflection. Session queues use timestamped value entries, preserve original pump-cycle hooks, add isolated queue-change/wait hooks, aggregate live session sources and unregister on disconnect. - Local stack under observability/pfe/ provisions four synthetic workload roles plus pinned Prometheus3.5.0, Grafana12.2.0, Loki3.4.2 and node-exporter1.9.1. All published ports bind127.0.0.1; Grafana anonymous Viewer only, no Docker socket, no production resources. URLs Grafana http://127.0.0.1:13000/d/pfe-fleet and Prometheus http://127.0.0.1:19090. Five versioned readable dashboards cover fleet, tick investigation, memory/allocators, queues and telemetry health, with clear synthetic/elapsed/CPU/freshness caveats. Fixture references real production telemetry and actual runtime/native allocations; gameplay/populations/causes deliberately synthetic. Protected production APIs not introduced; scenario/JSON endpoints exist only in harness. Registry/rule/stack/rollout docs and helper scripts are included. Validation - Final TheThreeEngines Release build TreatWarningsAsErrors=true:zero warnings/errors. Relevant engine/session/telemetry/regression suite:353 passes,6 asset-dependent skips,0failures (359total). Native suite:118passes,1 capture-dependent skip (119total); new20cycle native-query allocation lifetime/churn test verifies live bytes/count return to baseline and allocated/freed totals balance. Focused tests cover raw versus rolling timing, expected/stalled/sleep/wake behavior, registry/slow-ring caps, max-catalog cardinality/retained-memory budget, healthy warmed zero allocation, parallel wait merge, real Monitor acquisition ownership, caught system failures, session/pool aggregation/disposal, exporter-outage isolation and tabbed Linux /proc parsing. - Expanded30-system synthetic two-ms/tick CPU A/B benchmark:0.0–0.4% incremental process CPU in3rounds (off5.03/5.04/5.04s vs on5.05/5.04/5.04s). This validates that kernel shape, not production-wide load/profiler overhead. Max-catalog registry retained memory<16MiB and<2000series tests pass. Live fixture387raw series/PFE. Six actual collector categories report success; local sampler costs observed tens/hundreds of microseconds, not production contention guarantees. - promtool21rules and unit fixtures pass, including weighted means, idle/no-data, counter resets. Local API validator passes45PromQL panel queries and12historical range queries. Full7day explicitly synthetic overview/resource history:24h queries~2–5ms,7d~5–35ms across first/repeat passes,960–961points/series andfull24/168h coverage. These are bounded synthetic-dataset/host-cache measurements, not true cold-disk production TSDB guarantees. Diagnostic phase/wait/event history is real since fixture startup; it is not fabricated for past days. - Historical import initially scanned1.6GB for~4min and was interrupted; selected local importer was stopped and Prometheus restored. Reworked to bounded two-hour staging files with per-import20s limits/progress, no live outage during generation/import. Remaining14batches loaded in~8sec. Found/corrected default data/ path mismatch; Compose now explicitly uses /prometheus/data. New reusable loader protects volume identity, clips before head, refuses overlapping existing blocks and restarts local Prometheus in finally. No production touched. Large initial source file is outside repo. - Chrome acceptance: all5dashboards provisioned, roles/cohort filtering, populated phases/queues/runtime/native data and expandable slow records verified at1920x1080 and1100x900. First pass found blank scrape/rule legends, percent axis0–10000%, clipped banner, empty native-query data and RSS0 due tab parsing. Corrected all and added parser regression. Final focused browser pass verifies2-column PFE/CPU table, live-versus-historical resident legends, unclipped transparent history banner, no rendered query errors. Per-system timings/failure flags and sampled waits verified. Screenshot attachments available from browser sessions, filesystem paths not exposed. Updated fixtures run final built source image. - Evidence /tmp/pfe-observability-validation/: final-build/tests/benchmark.txt, native-tests.txt, stack-query-final.json, cardinailty/metrics/targets JSON/text, history-generation/import-tail logs and fixture image/up logs. git diff --check and compose/python syntax checks pass; generated Avalonia scratch dirs cleaned. Only intended session changes remain; primary checkout unchanged. Verified cleanup and PR continuation User clarified PR #2596 was closed accidentally. Same PR reopened and updated; no duplicate. Removed Tools/PfeObservabilityHarness, fixture Dockerfiles, generator/history/import/API-validation scripts, fixture-only dashboard content/tags and all root-owned local build outputs. Removed only this harness's stopped local images and its three Docker data volumes; unrelated containers/images/volumes and production captures untouched. Retained production telemetry, unit/native tests, five Grafana JSON dashboard definitions, dashboard/datasource YAML provisioning, rules + promtool fixtures, Prometheus/Loki config and infrastructure-only Compose. Production hardening added in 022c9fdfe (`chore: Prepare PFE observability for deployment`): stable AOEMU_ENGINE_ROLE assignments in base/Ergo/Ithaca Kamal configs; bounded engine.role on log/trace/Pyroscope resources and structured SlowTick records; file-based real PFE target discovery with empty safe default; authenticated Grafana (required admin password, no anonymous/signup), loopback default binds, explicit persistent TSDB path; production interpretation text/selectors and no synthetic series. README contains staged canary, ABI, target, auth/storage, Loki mapping, legacy-dashboard migration and allocator-off requirements. Post-cleanup validation: warnings-as-errors three-engine build zero warnings/errors;28focused telemetry/pump tests pass; native allocation lifetime test passes; promtool checks21rules and unit fixtures; Compose config succeeds with required validation password; deployment/Prometheus targets YAML parse; all5dashboard JSONs parse; git diff --check passes. The pre-cleanup browser/query/benchmark evidence remains historical validation of dashboard/telemetry behavior but harness is deliberately absent. PR #2596 body updated to distinguish that evidence and current retained scope; branch pushed, worktree clean, no deployment. Rollout/follow-ups (not authorized or claimed) - Configure stable AOEMU_ENGINE_ROLE, production auth/targets/storage/retention and bounded Loki SlowTick event label mapping through existing logger/OTel exporter. The local direct Loki fixture transport is not a production collector deployment. Audit legacy game/stat cardinality independently. Enable allocator metrics only after deployed-container overhead/compatibility validation. True CPU profiling remains separately authorized; none added automatically. Broader real-world serial/parallel/churn overhead and cold-disk TSDB sizing remain production rollout measurements, not synthetic claims.