chore: Add debug logs and make callbacks more stable.

Author: freezy

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

@@ -39,9 +39,10 @@ namespace VisualPinball.Engine.PinMAME
 	[DisallowMultipleComponent]
 	[RequireComponent(typeof(AudioSource))]
 	[AddComponentMenu("Pinball/Gamelogic Engine/PinMAME")]
-	public class PinMameGamelogicEngine : MonoBehaviour, IGamelogicEngine
+	public class PinMameGamelogicEngine : MonoBehaviour, IGamelogicEngine, IGamelogicInputThreading
 	{
 		public string Name { get; } = "PinMAME Gamelogic Engine";
+		public GamelogicInputDispatchMode SwitchDispatchMode => GamelogicInputDispatchMode.SimulationThread;
 
 		public const string DmdPrefix = "dmd";
 		public const string SegDispPrefix = "display";
@@ -148,8 +149,9 @@ public GamelogicEngineLamp[] RequestedLamps {
 
 		public bool _solenoidsEnabled;
 		public long _solenoidDelayStart;
-		private Dictionary<int, PinMameMechComponent> _registeredMechs = new();
-		private HashSet<int> _mechSwitches = new();
+		private Dictionary<int, PinMameMechComponent> _registeredMechs = new();
+		private Dictionary<int, string> _registeredMechNames = new();
+		private HashSet<int> _mechSwitches = new();
 
 		private bool _toggleSpeed = false;
 		private Keyboard _keyboard;
@@ -186,10 +188,16 @@ private void Update()
 			}
 
 			lock (_dispatchQueue) {
-				while (_dispatchQueue.Count > 0) {
-					_dispatchQueue.Dequeue().Invoke();
-				}
-			}
+				while (_dispatchQueue.Count > 0) {
+					var callback = _dispatchQueue.Dequeue();
+					try {
+						callback.Invoke();
+					}
+					catch (Exception e) {
+						Logger.Error(e, "[PinMAME] Exception while processing main-thread dispatch callback.");
+					}
+				}
+			}
 
 			// lamps
 			_pinMame.GetChangedLamps(_changedLamps);
@@ -922,13 +930,13 @@ private void OnSolenoidUpdated(int id, bool isActive)
 
 				var coil = _coils[_pinMameIdToCoilIdMapping[id]];
 
-				if (_solenoidsEnabled) {
-					Logger.Info($"[PinMAME] <= coil {coil.Id} : {isActive} | {coil.Description}");
-
-					lock (_dispatchQueue) {
-						_dispatchQueue.Enqueue(() => OnCoilChanged?.Invoke(this, new CoilEventArgs(coil.Id, isActive)));
-					}
-				}
+				if (_solenoidsEnabled) {
+					Logger.Info($"[PinMAME] <= coil {coil.Id} : {isActive} | {coil.Description}");
+
+					lock (_dispatchQueue) {
+						_dispatchQueue.Enqueue(() => OnCoilChanged?.Invoke(this, new CoilEventArgs(coil.Id, isActive)));
+					}
+				}
 				else {
 					Logger.Info($"[PinMAME] <= solenoids disabled, coil {coil.Id} : {isActive} | {coil.Description}");
 				}
@@ -1011,11 +1019,13 @@ public bool GetSwitch(string id)
 
 		#region Mechs
 
-		public void RegisterMech(PinMameMechComponent mechComponent)
-		{
-			var id = _numMechs++;
-			_registeredMechs[id] = mechComponent;
-		}
+		public void RegisterMech(PinMameMechComponent mechComponent)
+		{
+			// PinMAME mech numbers are 1-based.
+			var id = ++_numMechs;
+			_registeredMechs[id] = mechComponent;
+			_registeredMechNames[id] = mechComponent ? mechComponent.name : "<null-mech>";
+		}
 
 		private void OnMechAvailable(int mechNo, PinMameMechInfo mechInfo)
 		{
@@ -1034,21 +1044,25 @@ private void OnMechUpdated(int mechNo, PinMameMechInfo mechInfo)
 			}
 		}
 
-		private void SendMechs()
-		{
-			var max = _pinMame.GetMaxMechs();
-			foreach (var (id, mech) in _registeredMechs) {
-				if (id > max) {
-					Logger.Error($"PinMAME only supports up to {max} custom mechs, ignoring {mech.name}.");
-					return;
-				}
-				var mechConfig = mech.Config(_player.SwitchMapping, _player.CoilMapping, _switchIdToPinMameIdMappings, _coilIdToPinMameIdMapping);
-				_pinMame.SetMech(id, mechConfig);
-				foreach (var c in mechConfig.SwitchList) {
-					_mechSwitches.Add(c.SwNo);
-				}
-			}
-		}
+		private void SendMechs()
+		{
+			var max = _pinMame.GetMaxMechs();
+			Logger.Info($"[PinMAME] Registering {_registeredMechs.Count} mech(s). PinMAME reports max mech slots={max}.");
+			foreach (var (id, mech) in _registeredMechs) {
+				var mechName = _registeredMechNames.TryGetValue(id, out var name) ? name : $"mech#{id}";
+				// GetMaxMechs() returns the count of available slots and valid mech numbers are 1..max.
+				if (id > max) {
+					Logger.Error($"PinMAME supports {max} custom mech slot(s). Cannot register mech id={id} ({mechName}).");
+					continue;
+				}
+				var mechConfig = mech.Config(_player.SwitchMapping, _player.CoilMapping, _switchIdToPinMameIdMappings, _coilIdToPinMameIdMapping);
+				Logger.Info($"[PinMAME] Registering mech id={id}, name={mechName}, switches={mechConfig.SwitchList.Count}.");
+				_pinMame.SetMech(id, mechConfig);
+				foreach (var c in mechConfig.SwitchList) {
+					_mechSwitches.Add(c.SwNo);
+				}
+			}
+		}
 
 		#endregion
 

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

@@ -134,10 +134,10 @@ public PinMameMechConfig Config(List<SwitchMapping> switchMappings, List<CoilMap
 
 			foreach (var mark in Marks) {
 				var switchMapping = switchMappings.FirstOrDefault(sm => ReferenceEquals(sm.Device, this) && sm.DeviceItem == mark.SwitchId);
-				if (switchMapping == null) {
-					Logger.Error($"Switch \"{mark.Name}\" for mech {name} is not mapped in the switch manager, ignoring.");
-					continue;
-				}
+				if (switchMapping == null) {
+					Logger.Error($"Switch \"{mark.Name}\" for mech {_cachedName} is not mapped in the switch manager, ignoring.");
+					continue;
+				}
 
 				switch (mark.Type) {
 					case MechMarkSwitchType.EnableBetween:
@@ -159,7 +159,8 @@ public PinMameMechConfig Config(List<SwitchMapping> switchMappings, List<CoilMap
 			return mechConfig;
 		}
 
-		private static readonly Logger Logger = LogManager.GetCurrentClassLogger();
+		private static readonly Logger Logger = LogManager.GetCurrentClassLogger();
+		private string _cachedName = "<unnamed-mech>";
 
 		private const string EventNameSpeed = "Mech Speed";
 		private const string EventNamePosition = "Mech Position";
@@ -223,11 +224,12 @@ public IEnumerable<GamelogicEngineCoil> AvailableCoils {
 
 		private PinMameGamelogicEngine _gle;
 
-		private void Awake()
-		{
-			_gle = GetComponentInParent<PinMameGamelogicEngine>();
-			if (_gle && enabled) {
-				_gle.RegisterMech(this);
+		private void Awake()
+		{
+			_cachedName = gameObject.name;
+			_gle = GetComponentInParent<PinMameGamelogicEngine>();
+			if (_gle && enabled) {
+				_gle.RegisterMech(this);
 			}
 		}