From 6dd84ae1040c65597d1dbf9655d64d7443b18107 Mon Sep 17 00:00:00 2001 From: Phantomical Date: Thu, 26 Feb 2026 15:25:48 -0800 Subject: [PATCH] Add new patch to automatically add tracing spans to stock events When looking at KSP within the unity profiler the event handlers are completely invisible. This is a shame, because a lot of frame hangs or stutter happen because an event was fired and event handlers end up running unnecessarily. This commit introduces a new disabled-by-default patch that automatically adds two sets of profiler spans every time the event is fired: - One wraps the whole event and contains the event name - We wrap each individual function call with another span that contains the full name (i.e. `typename.methodname`) of the method being called. That way you can see right away which events and and which callback specifically are slow. Actually implementing this is a bit messy. EventVoid is easy, it can just use a regular harmony patch, but the remaining EventData types are all generics. Patching generics in general is difficult. You lose class type parameters and you need to separately patch each instantiation for value type parameters. Making this actually work in practice for stock is somewhat involved - We declare `Fire0` through `Fire4`. These are instantiated with the actual type parameters dynamically are basically just a copy-paste of the stock event handling code with the extra spans added. - We declare `EventDataN_Fire_Override` variants, these are the calls that actually get patched into the resulting method. Their generic parameters will match for value types but not for class types. These assign the arguments to an array and use reflection to call the correct FireN overload. - At patch time we dynamically construct a new lambda that calls into the appropriate `EventDataN_Fire_Override` call. Harmony does not support using generic methods for patches so we use runtime generation instead. Using `LambdaExpression.Compile` does not result in a method with the right signature, so we instead directly use `Reflection.Emit` and `LambdaExpression.CompileToMethod` to create the method we need. We then apply the appropriate patch for every known EventData instantiation in the stock game. If there are important events in mods that use known types then we can add those at a later date. --- GameData/KSPCommunityFixes/Settings.cfg | 5 + KSPCommunityFixes/BasePatch.cs | 11 +- KSPCommunityFixes/KSPCommunityFixes.csproj | 1 + .../Modding/EventProfilerMarkers.cs | 595 ++++++++++++++++++ 4 files changed, 608 insertions(+), 4 deletions(-) create mode 100644 KSPCommunityFixes/Modding/EventProfilerMarkers.cs diff --git a/GameData/KSPCommunityFixes/Settings.cfg b/GameData/KSPCommunityFixes/Settings.cfg index 006f839..861c30c 100644 --- a/GameData/KSPCommunityFixes/Settings.cfg +++ b/GameData/KSPCommunityFixes/Settings.cfg @@ -547,6 +547,11 @@ KSP_COMMUNITY_FIXES // the examples and documentation in the patch source. BaseFieldListUseFieldHost = true + // Adds Unity Profiler markers to EventData.Fire() methods, making game event dispatch and + // individual subscriber callbacks visible in the Unity Profiler. Useful for identifying + // expensive event handlers. + EventProfilerMarkers = false + // ########################## // Localization tools // ########################## diff --git a/KSPCommunityFixes/BasePatch.cs b/KSPCommunityFixes/BasePatch.cs index 8b361c2..0bf9bb2 100644 --- a/KSPCommunityFixes/BasePatch.cs +++ b/KSPCommunityFixes/BasePatch.cs @@ -191,6 +191,11 @@ protected void AddPatch(PatchType patchType, Type patchedMethodType, string patc patches.Add(new PatchInfo(patchType, AccessTools.Method(patchedMethodType, patchedMethodName, patchedMethodArgs), patchMethodName, patchPriority)); } + protected void AddPatch(PatchInfo patch) + { + patches.Add(patch); + } + public bool IsVersionValid => KSPCommunityFixes.KspVersion >= VersionMin && KSPCommunityFixes.KspVersion <= VersionMax; private bool ApplyHarmonyPatch() @@ -209,10 +214,8 @@ private bool ApplyHarmonyPatch() continue; } - if (patch.patchMethodName == null) - patch.patchMethodName = patch.patchedMethod.DeclaringType.Name + "_" + patch.patchedMethod.Name + "_" + patch.patchType; - - patch.patchMethod = AccessTools.Method(GetType(), patch.patchMethodName); + patch.patchMethodName ??= patch.patchedMethod.DeclaringType.Name + "_" + patch.patchedMethod.Name + "_" + patch.patchType; + patch.patchMethod ??= AccessTools.Method(GetType(), patch.patchMethodName); if (patch.patchMethod == null) { diff --git a/KSPCommunityFixes/KSPCommunityFixes.csproj b/KSPCommunityFixes/KSPCommunityFixes.csproj index 17604dc..a96fdd5 100644 --- a/KSPCommunityFixes/KSPCommunityFixes.csproj +++ b/KSPCommunityFixes/KSPCommunityFixes.csproj @@ -222,6 +222,7 @@ + diff --git a/KSPCommunityFixes/Modding/EventProfilerMarkers.cs b/KSPCommunityFixes/Modding/EventProfilerMarkers.cs new file mode 100644 index 0000000..0ffa5d5 --- /dev/null +++ b/KSPCommunityFixes/Modding/EventProfilerMarkers.cs @@ -0,0 +1,595 @@ +using System; +using System.Collections.Generic; +using System.Reflection; +using Contracts; +using Expansions.Missions; +using Expansions.Serenity; +using Expansions.Serenity.DeployedScience.Runtime; +using FinePrint; +using HarmonyLib; +using KSP.UI.Screens; +using KSP.UI.Screens.Settings.Controls; +using KSPAchievements; +using Unity.Profiling; +using Upgradeables; +using UnityEngine; +using UnityEngine.Profiling; +using static GameEvents; +using System.Linq.Expressions; +using System.Linq; +using System.Reflection.Emit; + +namespace KSPCommunityFixes.Modding +{ + public class EventProfilerMarkers : BasePatch + { + protected override void ApplyPatches() + { + AddPatch(PatchType.Override, typeof(EventVoid), nameof(EventVoid.Fire), nameof(EventVoid_Fire_Override)); + + foreach (var type in ValueTypeEventData1) + AddPatch(CreatePatch(type)); + + foreach (var type in ValueTypeEventData2) + AddPatch(CreatePatch(type)); + + foreach (var type in ValueTypeEventData3) + AddPatch(CreatePatch(type)); + + foreach (var type in ValueTypeEventData4) + AddPatch(CreatePatch(type)); + } + + #region CreatePatchOverride + static readonly ModuleBuilder PatchModule; + + static EventProfilerMarkers() + { + var assemblyBuilder = AssemblyBuilder.DefineDynamicAssembly( + new AssemblyName("KSPCommunityFixes_EventProfilerPatches"), + AssemblyBuilderAccess.Run); + PatchModule = assemblyBuilder.DefineDynamicModule("PatchModule"); + } + + static int patchCounter; + + static string PatchName(string baseName, Type[] tparams) + { + return baseName + "<" + string.Join(", ", tparams.Select(t => t.Name)) + ">"; + } + + static PatchInfo CreatePatch(Type type) + { + var tparams = type.GenericTypeArguments; + var instance = Expression.Parameter(type, "__instance"); + + var fparams = new ParameterExpression[tparams.Length + 1]; + fparams[0] = instance; + for (int i = 0; i < tparams.Length; ++i) + fparams[i + 1] = Expression.Parameter(tparams[i], $"data{i}"); + + MethodInfo generic = tparams.Length switch + { + 1 => SymbolExtensions.GetMethodInfo(() => EventData1_Fire_Override(null, null)), + 2 => SymbolExtensions.GetMethodInfo(() => EventData2_Fire_Override(null, null, null)), + 3 => SymbolExtensions.GetMethodInfo(() => EventData3_Fire_Override(null, null, null, null)), + 4 => SymbolExtensions.GetMethodInfo(() => EventData4_Fire_Override(null, null, null, null, null)), + _ => throw new NotImplementedException() + }; + + var method = generic + .GetGenericMethodDefinition() + .MakeGenericMethod(tparams); + + var body = Expression.Call(null, method, fparams); + var lambda = Expression.Lambda(body, fparams); + + var patchName = PatchName(generic.Name, tparams); + var typeBuilder = PatchModule.DefineType($"Patch_{patchCounter++}", TypeAttributes.Public | TypeAttributes.Abstract | TypeAttributes.Sealed); + var paramTypes = fparams.Select(p => p.Type).ToArray(); + var methodBuilder = typeBuilder.DefineMethod(patchName, MethodAttributes.Public | MethodAttributes.Static, typeof(void), paramTypes); + + for (int i = 0; i < fparams.Length; i++) + methodBuilder.DefineParameter(i + 1, ParameterAttributes.None, fparams[i].Name); + + lambda.CompileToMethod(methodBuilder); + var builtType = typeBuilder.CreateType(); + var compiled = builtType.GetMethod(patchName); + + return new PatchInfo(PatchType.Override, AccessTools.Method(type, "Fire"), patchName) + { + patchMethod = compiled + }; + } + #endregion + + static readonly Dictionary EventMarkers = new Dictionary(); + static readonly Dictionary MethodMarkers = new Dictionary(); + + static readonly Dictionary FireMethods = new Dictionary(); + + static ProfilerMarker GetTypeMarker(BaseGameEvent evt) + { + if (EventMarkers.TryGetValue(evt.GetType(), out var marker)) + return marker; + + marker = new ProfilerMarker(evt.EventName); + EventMarkers.Add(evt.GetType(), marker); + return marker; + } + + static ProfilerMarker GetMethodMarker(Delegate del) + { + var method = del.Method; + if (MethodMarkers.TryGetValue(method, out var marker)) + return marker; + + marker = new ProfilerMarker($"{method.DeclaringType}.{method.Name}"); + MethodMarkers.Add(method, marker); + return marker; + } + + static MethodInfo GetConcreteFireMethod(BaseGameEvent evt) + { + if (FireMethods.TryGetValue(evt.GetType(), out var method)) + return method; + + method = GetConcreteFireMethodSlow(evt); + FireMethods.Add(evt.GetType(), method); + return method; + } + + static MethodInfo GetConcreteFireMethodSlow(BaseGameEvent evt) + { + var type = evt.GetType(); + + if (type == typeof(EventVoid)) + return SymbolExtensions.GetMethodInfo(evt => Fire0(evt)); + if (!type.IsGenericType) + throw new Exception($"Unsupported event data type {type.Name}"); + + var generic = type.GetGenericTypeDefinition(); + var tparams = type.GenericTypeArguments; + + if (generic == typeof(EventData<>)) + { + return SymbolExtensions + .GetMethodInfo>(evt => Fire1(evt, null)) + .GetGenericMethodDefinition() + .MakeGenericMethod(tparams); + } + + if (generic == typeof(EventData<,>)) + { + return SymbolExtensions + .GetMethodInfo>(evt => Fire2(evt, null, null)) + .GetGenericMethodDefinition() + .MakeGenericMethod(tparams); + } + + if (generic == typeof(EventData<,,>)) + { + return SymbolExtensions + .GetMethodInfo>(evt => Fire3(evt, null, null, null)) + .GetGenericMethodDefinition() + .MakeGenericMethod(tparams); + } + + if (generic == typeof(EventData<,,,>)) + { + return SymbolExtensions + .GetMethodInfo>(evt => Fire4(evt, null, null, null, null)) + .GetGenericMethodDefinition() + .MakeGenericMethod(tparams); + } + + throw new NotSupportedException($"Cannot get the correct method for event type {type.Name}"); + } + + static void Fire0(EventVoid instance) + { + using var scope = GetTypeMarker(instance).Auto(); + + Profiler.BeginSample(instance.eventName); + + if (instance.debugEvent || GameEventsBase.debugEvents) + Debug.Log("EventManager: Firing event '" + instance.eventName + "'"); + + instance.numEventsFiring++; + instance.eventsClone.Clear(); + instance.eventsClone.AddRange(instance.events); + int count = instance.eventsClone.Count; + + while (count-- > 0) + { + var evt = instance.eventsClone[count]; + if (evt.originator is null) + { + Debug.Log("EventManager: Removing event '" + instance.eventName + "'for object of type '" + instance.events[count].originatorType + "' as object is null."); + instance.events.Remove(instance.eventsClone[count]); + instance.eventsClone.RemoveAt(count); + continue; + } + + try + { + using var method = GetMethodMarker(evt.evt).Auto(); + evt.evt(); + } + catch (Exception ex) + { + Debug.LogError($"Exception handling event {instance.eventName} in class {instance.eventsClone[count].originatorType}:" + ex); + Debug.LogException(ex); + } + } + + instance.numEventsFiring--; + if (instance.numEventsFiring <= 0) + { + instance.eventsClone.Clear(); + instance.numEventsFiring = 0; + } + } + + static void Fire1(EventData instance, T data) + { + using var scope = GetTypeMarker(instance).Auto(); + + Profiler.BeginSample(instance.eventName); + + if (instance.debugEvent || GameEventsBase.debugEvents) + Debug.Log("EventManager: Firing event '" + instance.eventName + "'"); + + instance.numEventsFiring++; + instance.eventsClone.Clear(); + instance.eventsClone.AddRange(instance.events); + int count = instance.eventsClone.Count; + + while (count-- > 0) + { + var evt = instance.eventsClone[count]; + if (evt.originator is null) + { + Debug.Log("EventManager: Removing event '" + instance.eventName + "'for object of type '" + instance.events[count].originatorType + "' as object is null."); + instance.events.Remove(instance.eventsClone[count]); + instance.eventsClone.RemoveAt(count); + continue; + } + + try + { + using var method = GetMethodMarker(evt.evt).Auto(); + evt.evt(data); + } + catch (Exception ex) + { + Debug.LogError($"Exception handling event {instance.eventName} in class {instance.eventsClone[count].originatorType}:" + ex); + Debug.LogException(ex); + } + } + + instance.numEventsFiring--; + if (instance.numEventsFiring <= 0) + { + instance.eventsClone.Clear(); + instance.numEventsFiring = 0; + } + } + + static void Fire2(EventData instance, T1 arg1, T2 arg2) + { + using var scope = GetTypeMarker(instance).Auto(); + + Profiler.BeginSample(instance.eventName); + + if (instance.debugEvent || GameEventsBase.debugEvents) + Debug.Log("EventManager: Firing event '" + instance.eventName + "'"); + + instance.numEventsFiring++; + instance.eventsClone.Clear(); + instance.eventsClone.AddRange(instance.events); + int count = instance.eventsClone.Count; + + while (count-- > 0) + { + var evt = instance.eventsClone[count]; + if (evt.originator is null) + { + Debug.Log("EventManager: Removing event '" + instance.eventName + "'for object of type '" + instance.events[count].originatorType + "' as object is null."); + instance.events.Remove(instance.eventsClone[count]); + instance.eventsClone.RemoveAt(count); + continue; + } + + try + { + using var method = GetMethodMarker(evt.evt).Auto(); + evt.evt(arg1, arg2); + } + catch (Exception ex) + { + Debug.LogError($"Exception handling event {instance.eventName} in class {instance.eventsClone[count].originatorType}:" + ex); + Debug.LogException(ex); + } + } + + instance.numEventsFiring--; + if (instance.numEventsFiring <= 0) + { + instance.eventsClone.Clear(); + instance.numEventsFiring = 0; + } + } + + static void Fire3(EventData instance, T1 arg1, T2 arg2, T3 arg3) + { + using var scope = GetTypeMarker(instance).Auto(); + + Profiler.BeginSample(instance.eventName); + + if (instance.debugEvent || GameEventsBase.debugEvents) + Debug.Log("EventManager: Firing event '" + instance.eventName + "'"); + + instance.numEventsFiring++; + instance.eventsClone.Clear(); + instance.eventsClone.AddRange(instance.events); + int count = instance.eventsClone.Count; + + while (count-- > 0) + { + var evt = instance.eventsClone[count]; + if (evt.originator is null) + { + Debug.Log("EventManager: Removing event '" + instance.eventName + "'for object of type '" + instance.events[count].originatorType + "' as object is null."); + instance.events.Remove(instance.eventsClone[count]); + instance.eventsClone.RemoveAt(count); + continue; + } + + try + { + using var method = GetMethodMarker(evt.evt).Auto(); + evt.evt(arg1, arg2, arg3); + } + catch (Exception ex) + { + Debug.LogError($"Exception handling event {instance.eventName} in class {instance.eventsClone[count].originatorType}:" + ex); + Debug.LogException(ex); + } + } + + instance.numEventsFiring--; + if (instance.numEventsFiring <= 0) + { + instance.eventsClone.Clear(); + instance.numEventsFiring = 0; + } + } + + static void Fire4(EventData instance, T1 arg1, T2 arg2, T3 arg3, T4 arg4) + { + using var scope = GetTypeMarker(instance).Auto(); + + Profiler.BeginSample(instance.eventName); + + if (instance.debugEvent || GameEventsBase.debugEvents) + Debug.Log("EventManager: Firing event '" + instance.eventName + "'"); + + instance.numEventsFiring++; + instance.eventsClone.Clear(); + instance.eventsClone.AddRange(instance.events); + int count = instance.eventsClone.Count; + + while (count-- > 0) + { + var evt = instance.eventsClone[count]; + if (evt.originator is null) + { + Debug.Log("EventManager: Removing event '" + instance.eventName + "'for object of type '" + instance.events[count].originatorType + "' as object is null."); + instance.events.Remove(instance.eventsClone[count]); + instance.eventsClone.RemoveAt(count); + continue; + } + + try + { + using var method = GetMethodMarker(evt.evt).Auto(); + evt.evt(arg1, arg2, arg3, arg4); + } + catch (Exception ex) + { + Debug.LogError($"Exception handling event {instance.eventName} in class {instance.eventsClone[count].originatorType}:" + ex); + Debug.LogException(ex); + } + } + + instance.numEventsFiring--; + if (instance.numEventsFiring <= 0) + { + instance.eventsClone.Clear(); + instance.numEventsFiring = 0; + } + } + + static void EventVoid_Fire_Override(EventVoid instance) => Fire0(instance); + + static readonly object[] Args1 = new object[2]; + public static void EventData1_Fire_Override(EventData instance, T data) + { + try + { + Args1[0] = instance; + Args1[1] = data; + + var method = GetConcreteFireMethod(instance); + method.Invoke(null, Args1); + } + finally + { + Array.Clear(Args1, 0, Args1.Length); + } + } + + static readonly object[] Args2 = new object[3]; + public static void EventData2_Fire_Override(EventData instance, T data0, U data1) + { + try + { + Args2[0] = instance; + Args2[1] = data0; + Args2[2] = data1; + + var method = GetConcreteFireMethod(instance); + method.Invoke(null, Args2); + } + finally + { + Array.Clear(Args2, 0, Args2.Length); + } + } + + static readonly object[] Args3 = new object[4]; + public static void EventData3_Fire_Override(EventData instance, T data0, U data1, V data2) + { + try + { + Args3[0] = instance; + Args3[1] = data0; + Args3[2] = data1; + Args3[3] = data2; + + var method = GetConcreteFireMethod(instance); + method.Invoke(null, Args3); + } + finally + { + Array.Clear(Args3, 0, Args3.Length); + } + } + + static readonly object[] Args4 = new object[5]; + public static void EventData4_Fire_Override(EventData instance, T data0, U data1, V data2, W data3) + { + try + { + Args4[0] = instance; + Args4[1] = data0; + Args4[2] = data1; + Args4[3] = data2; + Args4[4] = data3; + + var method = GetConcreteFireMethod(instance); + method.Invoke(null, Args4); + } + finally + { + Array.Clear(Args4, 0, Args4.Length); + } + } + + #region EventData Overloads + static readonly Type[] ValueTypeEventData1 = + { + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + typeof(EventData>), + }; + + static readonly Type[] ValueTypeEventData2 = + { + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + }; + + static readonly Type[] ValueTypeEventData3 = + { + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData>), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + }; + + static readonly Type[] ValueTypeEventData4 = + { + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + typeof(EventData), + }; + #endregion + } +}