Skip to content

Commit 110aed3

Browse files
committed
fix: Remove hot-path logging and wall-clock calls from PinMAME callbacks.
The solenoid-delay timing check now uses a monotonic `Stopwatch`-based timestamp instead of `DateTimeOffset.Now`, and high-frequency coil callback logs were downgraded behind `Logger.IsDebugEnabled` so normal runtime no longer pays string-format/logging cost on every coil edge.
1 parent 863cd99 commit 110aed3

File tree

1 file changed

+21
-13
lines changed

1 file changed

+21
-13
lines changed

VisualPinball.Engine.PinMAME.Unity/Runtime/PinMameGamelogicEngine.cs

Lines changed: 21 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -225,6 +225,7 @@ public void ApplySharedState(in SimulationState.Snapshot snapshot)
225225
private bool _dispatchQueueWarningIssued;
226226
private bool _simulationCoilQueueWarningIssued;
227227
private bool _simulationCoilQueueDropWarningIssued;
228+
private long _solenoidDelayStartTimestampUsec;
228229
private const int MaxSimulationCoilDispatchQueueSize = 8192;
229230
private const int DispatchQueueWarningThreshold = 512;
230231
private const double PerfSampleWindowSeconds = 0.25;
@@ -239,7 +240,7 @@ public void ApplySharedState(in SimulationState.Snapshot snapshot)
239240
private bool _sharedLampPlaybackActive;
240241
private readonly Queue<float[]> _audioQueue = new();
241242

242-
private int _audioFilterChannels;
243+
private int _audioFilterChannels;
243244
private PinMameAudioInfo _audioInfo;
244245
private float[] _lastAudioFrame = {};
245246
private int _lastAudioFrameOffset;
@@ -259,6 +260,8 @@ public void ApplySharedState(in SimulationState.Snapshot snapshot)
259260
private bool _toggleSpeed = false;
260261
private Keyboard _keyboard;
261262

263+
private static long TimestampUsec => (Stopwatch.GetTimestamp() * 1_000_000) / Stopwatch.Frequency;
264+
262265
private static readonly SemaphoreSlim PinMameStartStopGate = new SemaphoreSlim(1, 1);
263266
private int _onInitCalled;
264267
private int _stopRequested;
@@ -733,7 +736,8 @@ private void OnGameStarted()
733736
Logger.Info("[PinMAME] Game started.");
734737
_isRunning = true;
735738

736-
_solenoidDelayStart = DateTimeOffset.Now.ToUnixTimeMilliseconds();
739+
_solenoidDelayStartTimestampUsec = TimestampUsec;
740+
_solenoidDelayStart = _solenoidDelayStartTimestampUsec / 1000;
737741

738742
try {
739743
SendInitialSwitches();
@@ -1141,13 +1145,13 @@ private void OnSolenoidUpdated(int id, bool isActive)
11411145
MarkPinMameCallbackActivity();
11421146

11431147
if (_pinMameIdToCoilIdMapping.ContainsKey(id)) {
1144-
if (!_solenoidsEnabled) {
1145-
_solenoidsEnabled = DateTimeOffset.Now.ToUnixTimeMilliseconds() - _solenoidDelayStart >= SolenoidDelay;
1146-
1147-
if (_solenoidsEnabled) {
1148-
Logger.Info($"Solenoids enabled, {SolenoidDelay}ms passed");
1149-
}
1150-
}
1148+
if (!_solenoidsEnabled) {
1149+
_solenoidsEnabled = TimestampUsec - _solenoidDelayStartTimestampUsec >= (long)(SolenoidDelay * 1000f);
1150+
1151+
if (_solenoidsEnabled) {
1152+
Logger.Info($"Solenoids enabled, {SolenoidDelay}ms passed");
1153+
}
1154+
}
11511155

11521156
var coil = _coils[_pinMameIdToCoilIdMapping[id]];
11531157

@@ -1156,7 +1160,9 @@ private void OnSolenoidUpdated(int id, bool isActive)
11561160
_sharedCoilStates[id] = isActive;
11571161
}
11581162

1159-
Logger.Info($"[PinMAME] <= coil {coil.Id} : {isActive} | {coil.Description}");
1163+
if (Logger.IsDebugEnabled) {
1164+
Logger.Debug($"[PinMAME] <= coil {coil.Id} : {isActive} | {coil.Description}");
1165+
}
11601166
if (ShouldDispatchSimulationCoil(coil.Id)) {
11611167
_simulationCoilDispatchQueue.Enqueue(new CoilEventArgs(coil.Id, isActive));
11621168
var simulationCoilQueueSize = Interlocked.Increment(ref _simulationCoilDispatchQueueSize);
@@ -1179,9 +1185,11 @@ private void OnSolenoidUpdated(int id, bool isActive)
11791185

11801186
EnqueueMainThreadDispatch(() => OnCoilChanged?.Invoke(this, new CoilEventArgs(coil.Id, isActive)));
11811187
}
1182-
else {
1183-
Logger.Info($"[PinMAME] <= solenoids disabled, coil {coil.Id} : {isActive} | {coil.Description}");
1184-
}
1188+
else {
1189+
if (Logger.IsDebugEnabled) {
1190+
Logger.Debug($"[PinMAME] <= solenoids disabled, coil {coil.Id} : {isActive} | {coil.Description}");
1191+
}
1192+
}
11851193
}
11861194
else {
11871195
Logger.Warn($"[PinMAME] <= coil UNMAPPED {id}: {isActive}");

0 commit comments

Comments
 (0)