Skip to content

Add plugin-side OTel metrics instrumentation #65

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
simsteward wants to merge 1 commit into
base: main
Choose a base branch
from
Open

Add plugin-side OTel metrics instrumentation #65

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
167 changes: 165 additions & 2 deletions src/SimSteward.Plugin/PluginMetricsTelemetry.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,18 +18,39 @@ public sealed class PluginMetricsTelemetry : IDisposable
private readonly MeterProvider _meterProvider;
private readonly Meter _meter;
private readonly Func<SystemMetricsSample> _getSample;
private readonly Func<double> _getDataUpdateHz;
private readonly Func<int> _getClientCount;
private readonly Func<double> _getReplayBuildProgressPct;
private readonly KeyValuePair<string, object>[] _baseTags;

private readonly Histogram<double> _dataUpdateTickIntervalMs;
private readonly Counter<long> _broadcastsSent;
private readonly Counter<long> _broadcastsSkippedThrottle;
private readonly Counter<long> _broadcastsSkippedNoClients;
private readonly Histogram<double> _broadcastDurationMs;
private readonly Counter<long> _sendErrors;
private readonly Histogram<double> _incidentDetectionDurationMs;
private readonly Histogram<double> _actionDurationMs;
private readonly Histogram<double> _replayIndexBuildDurationMs;
private readonly Counter<long> _replayIndexBuildsTotal;

private PluginMetricsTelemetry(
MeterProvider meterProvider,
Meter meter,
Func<SystemMetricsSample> getSample,
Func<double> getDataUpdateHz,
Func<int> getClientCount,
Func<double> getReplayBuildProgressPct,
KeyValuePair<string, object>[] baseTags)
{
_meterProvider = meterProvider;
_meter = meter;
_getSample = getSample;
_getDataUpdateHz = getDataUpdateHz;
_getClientCount = getClientCount;
_getReplayBuildProgressPct = getReplayBuildProgressPct;
_baseTags = baseTags;

_meter.CreateObservableGauge(
"simsteward.plugin.ready",
ObserveReady,
Expand All @@ -45,12 +66,80 @@ private PluginMetricsTelemetry(
ObserveWs,
unit: "MiBy",
description: "SimHub process working set.");

// --- DataUpdate loop health (real achieved tick rate vs. the ~60Hz game-tick target) ---
_meter.CreateObservableGauge(
"simsteward.dataupdate.hz",
ObserveDataUpdateHz,
unit: "Hz",
description: "Achieved DataUpdate() tick rate (EMA), vs. the ~60Hz game-tick target.");
_dataUpdateTickIntervalMs = _meter.CreateHistogram<double>(
"simsteward.dataupdate.tick_interval_ms",
unit: "ms",
description: "Distribution of inter-tick intervals for DataUpdate() — jitter/stall detection.");

// --- WebSocket dashboard broadcast path ---
_meter.CreateObservableGauge(
"simsteward.ws.clients",
ObserveClientCount,
unit: "1",
description: "Connected dashboard WebSocket clients.");
_broadcastsSent = _meter.CreateCounter<long>(
"simsteward.ws.broadcasts_sent",
unit: "1",
description: "State broadcasts successfully sent to dashboard clients.");
_broadcastsSkippedThrottle = _meter.CreateCounter<long>(
"simsteward.ws.broadcasts_skipped_throttle",
unit: "1",
description: "DataUpdate ticks where a broadcast was skipped due to the 200ms/5Hz throttle.");
_broadcastsSkippedNoClients = _meter.CreateCounter<long>(
"simsteward.ws.broadcasts_skipped_no_clients",
unit: "1",
description: "Broadcasts skipped because no dashboard client was connected.");
_broadcastDurationMs = _meter.CreateHistogram<double>(
"simsteward.ws.broadcast_duration_ms",
unit: "ms",
description: "Wall-clock time to build the state snapshot and send it to all connected clients.");
_sendErrors = _meter.CreateCounter<long>(
"simsteward.ws.send_errors",
unit: "1",
description: "Per-client WebSocket send failures.");

// --- Incident detection ---
_incidentDetectionDurationMs = _meter.CreateHistogram<double>(
"simsteward.incident_detection.duration_ms",
unit: "ms",
description: "Duration of a single incident-detection pass, tagged by path (live | replay_sweep).");

// --- Dashboard action dispatch ---
_actionDurationMs = _meter.CreateHistogram<double>(
"simsteward.action.duration_ms",
unit: "ms",
description: "Duration of a dispatched dashboard action, tagged by action name.");

// --- Replay incident index build (the >2s long-running operation) ---
_meter.CreateObservableGauge(
"simsteward.replay_index_build.progress_pct",
ObserveReplayBuildProgress,
unit: "%",
description: "Current replay-index fast-forward sweep completion percentage (0 when idle).");
_replayIndexBuildDurationMs = _meter.CreateHistogram<double>(
"simsteward.replay_index_build.duration_ms",
unit: "ms",
description: "Total wall-clock duration of a replay incident index build, tagged by completion_reason.");
_replayIndexBuildsTotal = _meter.CreateCounter<long>(
"simsteward.replay_index_build.builds_total",
unit: "1",
description: "Replay incident index builds completed, tagged by completion_reason.");
}

/// <summary>Returns null if OTLP is not configured (no endpoint env vars).</summary>
public static PluginMetricsTelemetry TryCreate(
PluginLogger logger,
Func<SystemMetricsSample> getSample)
Func<SystemMetricsSample> getSample,
Func<double> getDataUpdateHz = null,
Func<int> getClientCount = null,
Func<double> getReplayBuildProgressPct = null)
{
var endpoint = FirstNonEmpty(
Environment.GetEnvironmentVariable("OTEL_EXPORTER_OTLP_ENDPOINT"),
Expand Down Expand Up @@ -95,7 +184,12 @@ public static PluginMetricsTelemetry TryCreate(
})
.Build();

var telemetry = new PluginMetricsTelemetry(provider, meter, getSample, baseTags);
var telemetry = new PluginMetricsTelemetry(
provider, meter, getSample,
getDataUpdateHz ?? (() => 0),
getClientCount ?? (() => 0),
getReplayBuildProgressPct ?? (() => 0),
baseTags);

logger?.Structured("INFO", "simhub-plugin", "otel_metrics_started",
"OTLP metrics export enabled (OpenTelemetry → collector).",
Expand Down Expand Up @@ -137,6 +231,75 @@ private IEnumerable<Measurement<double>> ObserveWs()
yield return new Measurement<double>(v, _baseTags);
}

private IEnumerable<Measurement<double>> ObserveDataUpdateHz()
{
yield return new Measurement<double>(_getDataUpdateHz(), _baseTags);
}

private IEnumerable<Measurement<int>> ObserveClientCount()
{
yield return new Measurement<int>(_getClientCount(), _baseTags);
}

private IEnumerable<Measurement<double>> ObserveReplayBuildProgress()
{
yield return new Measurement<double>(_getReplayBuildProgressPct(), _baseTags);
}

// --- Imperative recording (histograms/counters, called from the hot paths that measure them) ---

public void RecordDataUpdateTickIntervalMs(double ms) =>
_dataUpdateTickIntervalMs.Record(ms, _baseTags);

public void RecordBroadcastSent(double durationMs)
{
_broadcastsSent.Add(1, _baseTags);
_broadcastDurationMs.Record(durationMs, _baseTags);
}

public void RecordBroadcastSkippedThrottle() =>
_broadcastsSkippedThrottle.Add(1, _baseTags);

public void RecordBroadcastSkippedNoClients() =>
_broadcastsSkippedNoClients.Add(1, _baseTags);

public void RecordSendError() =>
_sendErrors.Add(1, _baseTags);

/// <param name="path">Bounded label: "live" or "replay_sweep".</param>
public void RecordIncidentDetectionDuration(string path, double ms)
{
var tags = new[]
{
_baseTags[0],
new KeyValuePair<string, object>("path", path ?? "unknown"),
};
_incidentDetectionDurationMs.Record(ms, tags);
}

/// <param name="action">Bounded label: dashboard action name (~24 distinct values).</param>
public void RecordActionDuration(string action, double ms)
{
var tags = new[]
{
_baseTags[0],
new KeyValuePair<string, object>("action", action ?? "unknown"),
};
_actionDurationMs.Record(ms, tags);
}

/// <param name="completionReason">Bounded label: "success" | "cancelled" | "error" etc.</param>
public void RecordReplayIndexBuildCompleted(string completionReason, double durationMs)
{
var tags = new[]
{
_baseTags[0],
new KeyValuePair<string, object>("completion_reason", completionReason ?? "unknown"),
};
_replayIndexBuildDurationMs.Record(durationMs, tags);
_replayIndexBuildsTotal.Add(1, tags);
}

public void Dispose()
{
try
Expand Down
22 changes: 22 additions & 0 deletions src/SimSteward.Plugin/SimStewardPlugin.ReplayIncidentIndexBuild.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -80,7 +80,10 @@ private void OnIrsdkTelemetryDataForReplayIndex()

try
{
var __sw = System.Diagnostics.Stopwatch.StartNew();
ProcessReplayIncidentIndexBuildTelemetry();
__sw.Stop();
_metricsTelemetry?.RecordIncidentDetectionDuration("replay_sweep", __sw.Elapsed.TotalMilliseconds);
}
catch (Exception ex)
{
Expand All @@ -98,7 +101,10 @@ private void OnIrsdkTelemetryDataForReplayIndex()

try
{
var __sw = System.Diagnostics.Stopwatch.StartNew();
ProcessLiveIncidentDetectionTick();
__sw.Stop();
_metricsTelemetry?.RecordIncidentDetectionDuration("live", __sw.Elapsed.TotalMilliseconds);
}
catch (Exception ex)
{
Expand Down Expand Up @@ -709,6 +715,19 @@ private void ProcessYamlIncidentDiffLocked(double replaySessionTimeSec, int repl
/// </summary>
private void BroadcastReplaySweepProgressIfDueLocked(int replayFrame, double replaySessionTimeSec)
{
// Progress % feeds the simsteward.replay_index_build.progress_pct gauge unconditionally —
// independent of whether a dashboard client happens to be connected (the WS broadcast below is gated
// on client count, but the metrics gauge must reflect real build progress regardless).
{
int frameEndForMetrics = _replayIndexReplayFrameNumEndSnapshot > 0
? _replayIndexReplayFrameNumEndSnapshot
: SafeGetInt("ReplayFrameNumEnd");
double pctForMetrics = frameEndForMetrics > 0 ? (100.0 * replayFrame / frameEndForMetrics) : 0.0;
if (pctForMetrics < 0) pctForMetrics = 0;
if (pctForMetrics > 100) pctForMetrics = 100;
_replayIndexBuildProgressPctForMetrics = pctForMetrics;
}

if (_bridge == null || _bridge.ClientCount <= 0) return;
var nowUtc = DateTime.UtcNow;
if ((nowUtc - _lastSweepProgressTickAt).TotalMilliseconds < 1000)
Expand Down Expand Up @@ -989,6 +1008,9 @@ private void ProcessFastForwardingLocked()
_logger.Structured("INFO", "simhub-plugin", ReplayIncidentIndexBuild.EventFastForwardComplete,
"Replay incident index: fast-forward complete (TR-010/011).", done, "lifecycle", null);

_metricsTelemetry?.RecordReplayIndexBuildCompleted(reason, wallMs);
_replayIndexBuildProgressPctForMetrics = 0;

_replayIndexFfWallClock = null;
_replayIndexLastValidationBlock = BuildReplayIndexValidationBlockLocked(_replayIndexIncidentSamples);
FinalizeReplayIndexBuildLocked();
Expand Down
50 changes: 48 additions & 2 deletions src/SimSteward.Plugin/SimStewardPlugin.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -68,6 +68,9 @@ public partial class SimStewardPlugin
private int _resourceSampleIntervalSec = 60;
private SystemMetricsSample _lastResourceSample;
private PluginMetricsTelemetry _metricsTelemetry;
private DateTime _lastDataUpdateTickUtc = DateTime.MinValue;
private double _dataUpdateEmaHz;
private double _replayIndexBuildProgressPctForMetrics;

#if SIMHUB_SDK
private IRacingSdk _irsdk;
Expand Down Expand Up @@ -754,6 +757,20 @@ private System.Collections.Generic.Dictionary<string, object> BuildCaptureIncide
}

private (bool success, string result, string error) DispatchAction(string action, string arg, string correlationId)
{
var __actionSw = System.Diagnostics.Stopwatch.StartNew();
try
{
return DispatchActionCore(action, arg, correlationId);
}
finally
{
__actionSw.Stop();
_metricsTelemetry?.RecordActionDuration(action, __actionSw.Elapsed.TotalMilliseconds);
}
}

private (bool success, string result, string error) DispatchActionCore(string action, string arg, string correlationId)
{
if (string.IsNullOrEmpty(action))
return (false, null, "missing_action");
Expand Down Expand Up @@ -1751,9 +1768,14 @@ public void Init(PluginManager pluginManager)
OnLog,
_logger,
OnDashboardStructuredLog,
onSendError: (ex, payloadType) => WriteBroadcastError("Send:" + payloadType, ex),
onSendError: (ex, payloadType) =>
{
_metricsTelemetry?.RecordSendError();
WriteBroadcastError("Send:" + payloadType, ex);
},
onNoClients: () =>
{
_metricsTelemetry?.RecordBroadcastSkippedNoClients();
var n = DateTime.UtcNow;
lock (_broadcastErrorLock)
{
Expand Down Expand Up @@ -1840,7 +1862,12 @@ public void Init(PluginManager pluginManager)

try
{
_metricsTelemetry = PluginMetricsTelemetry.TryCreate(_logger, () => _lastResourceSample);
_metricsTelemetry = PluginMetricsTelemetry.TryCreate(
_logger,
() => _lastResourceSample,
() => _dataUpdateEmaHz,
() => _bridge != null ? _bridge.ClientCount : 0,
() => _replayIndexBuildProgressPctForMetrics);
}
catch (Exception ex)
{
Expand All @@ -1860,6 +1887,19 @@ public void DataUpdate(PluginManager pluginManager, ref GameData data)
{
try
{
var __tickNowUtc = DateTime.UtcNow;
if (_lastDataUpdateTickUtc != DateTime.MinValue)
{
double __intervalMs = (__tickNowUtc - _lastDataUpdateTickUtc).TotalMilliseconds;
_metricsTelemetry?.RecordDataUpdateTickIntervalMs(__intervalMs);
if (__intervalMs > 0)
{
double __instHz = 1000.0 / __intervalMs;
_dataUpdateEmaHz = _dataUpdateEmaHz <= 0 ? __instHz : (_dataUpdateEmaHz * 0.9 + __instHz * 0.1);
}
}
_lastDataUpdateTickUtc = __tickNowUtc;

_dataUpdateTick++;
if (_dataUpdateTick % DependencyCheckIntervalTicks == 0)
RefreshDependencyChecks();
Expand Down Expand Up @@ -2004,11 +2044,17 @@ public void DataUpdate(PluginManager pluginManager, ref GameData data)
var now = DateTime.UtcNow;

if ((now - _lastBroadcastAt).TotalMilliseconds < BroadcastThrottleMs)
{
_metricsTelemetry?.RecordBroadcastSkippedThrottle();
return;
}
_lastBroadcastAt = now;

var __broadcastSw = System.Diagnostics.Stopwatch.StartNew();
var snapshot = BuildPluginSnapshot();
_bridge.BroadcastState(BuildStateJson(snapshot));
__broadcastSw.Stop();
_metricsTelemetry?.RecordBroadcastSent(__broadcastSw.Elapsed.TotalMilliseconds);
}
catch (Exception ex)
{
Expand Down
Loading