Add various performance tracking / improvements

MonkeyLoader.Resonite.Integration/BrotliPatcher.cs

@@ -17,7 +17,7 @@ internal sealed class BrotliPatcher : Monkey<BrotliPatcher>
         protected override IEnumerable<IFeaturePatch> GetFeaturePatches() => Enumerable.Empty<IFeaturePatch>();
 
         [HarmonyPrefix]
-        [HarmonyPatch("Brotli.NativeLibraryLoader", "GetPossibleRuntimeDirectories")]
+        [HarmonyPatch("Brotli.NativeLibraryLoader, Brotli.Core", "GetPossibleRuntimeDirectories")]
         private static bool GetPossibleRuntimeDirectoriesPrefix(ref string[] __result)
         {
             __result = new[] { Mod.Loader.GameAssemblyPath };

MonkeyLoader.Resonite.Integration/Converters/ResonitePrimitiveConverter.cs

@@ -6,47 +6,74 @@
 using System.Collections.Generic;
 using System.Reflection;
 
-namespace ResoniteModLoader.JsonConverters
+namespace MonkeyLoader.Resonite.Converters
 {
     /// <summary>
     /// Converts a Resonite Primitive to and from json.
     /// </summary>
     public sealed class ResonitePrimitiveConverter : JsonConverter
     {
-        private static readonly Dictionary<Type, MethodInfo> encodeMethods = new();
-        private static readonly Assembly primitivesAssembly = typeof(colorX).Assembly;
+        private static readonly Dictionary<Type, CoderMethods> _coderMethods = new();
+        private static readonly Assembly _primitivesAssembly = typeof(colorX).Assembly;
 
         /// <inheritdoc/>
         public override bool CanConvert(Type objectType)
         {
             // handle all non-enum Resonite Primitives
-            return !objectType.IsEnum && primitivesAssembly.Equals(objectType.Assembly) && Coder.IsEnginePrimitive(objectType);
+            return !objectType.IsEnum && _primitivesAssembly.Equals(objectType.Assembly) && Coder.IsEnginePrimitive(objectType);
         }
 
         /// <inheritdoc/>
         public override object ReadJson(JsonReader reader, Type objectType, object? existingValue, JsonSerializer serializer)
         {
-            if (reader.Value is string serialized)
-            {
-                // use Resonite's built-in decoding if the value was serialized as a string
-                return typeof(Coder<>).MakeGenericType(objectType).GetMethod("DecodeFromString").Invoke(null, new object[] { serialized });
-            }
+            if (reader.Value is not string serialized)
+                throw new ArgumentException($"Could not deserialize primitive type [{objectType}] from reader type [{reader?.Value?.GetType()}]!");
 
-            throw new ArgumentException($"Could not deserialize primitive type [{objectType}] from reader type [{reader?.Value?.GetType()}]!");
+            // use Resonite's built-in decoding if the value was serialized as a string
+            return GetCoderMethods(objectType).Decode(serialized);
         }
 
         /// <inheritdoc/>
         public override void WriteJson(JsonWriter writer, object? value, JsonSerializer serializer)
         {
-            if (!encodeMethods.TryGetValue(value!.GetType(), out var encodeMethod))
+            var serialized = GetCoderMethods(value!.GetType()).Encode(value);
+
+            writer.WriteValue(serialized);
+        }
+
+        private static CoderMethods GetCoderMethods(Type type)
+        {
+            if (!_coderMethods.TryGetValue(type, out var coderMethods))
             {
-                encodeMethod = typeof(Coder<>).MakeGenericType(value!.GetType()).GetMethod(nameof(Coder<colorX>.EncodeToString));
-                encodeMethods.Add(value!.GetType(), encodeMethod);
+                coderMethods = new CoderMethods(type);
+                _coderMethods.Add(type, coderMethods);
             }
 
-            var serialized = (string)encodeMethod.Invoke(null, new[] { value });
+            return coderMethods;
+        }
 
-            writer.WriteValue(serialized);
+        private readonly struct CoderMethods
+        {
+            private static readonly Type _coderType = typeof(Coder<>);
+            private static readonly string _decodeFromString = nameof(Coder<colorX>.DecodeFromString);
+            private static readonly string _encodeToString = nameof(Coder<colorX>.EncodeToString);
+
+            private readonly MethodInfo _decode;
+            private readonly MethodInfo _encode;
+
+            public CoderMethods(Type type)
+            {
+                var specificCoder = _coderType.MakeGenericType(type);
+
+                _encode = specificCoder.GetMethod(_encodeToString);
+                _decode = specificCoder.GetMethod(_decodeFromString);
+            }
+
+            public object Decode(string serialized)
+                => _decode.Invoke(null, new[] { serialized });
+
+            public string Encode(object? value)
+                => (string)_encode.Invoke(null, new[] { value });
         }
     }
 }

MonkeyLoader.Resonite.Integration/EngineInitHook.cs

@@ -5,6 +5,7 @@
 using MonkeyLoader.Resonite.Features.FrooxEngine;
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.IO;
 using System.Linq;
 using System.Text;
@@ -29,30 +30,46 @@ protected override IEnumerable<IFeaturePatch> GetFeaturePatches()
         [HarmonyPrefix]
         private static void InitializePrefix(Engine __instance)
         {
-            Info(() => "Adding ResoniteMonkey hooks!");
+            Info(() => "Engine started initializing! Adding engine hooks and executing EngineInit hooks on ResoniteMonkeys!");
 
             Mod.Loader.LoggingHandler += ResoniteLoggingHandler.Instance;
 
             __instance.OnReady += OnEngineReady;
             __instance.OnShutdownRequest += OnEngineShutdownRequested;
             __instance.OnShutdown += OnEngineShutdown;
 
+            var resoniteMonkeys = ResoniteMonkeys.ToArray();
+            Logger.Trace(() => "Running EngineInit hooks in this order:");
+            Logger.Trace(resoniteMonkeys.Select(rM => new Func<object>(() => $"{rM.Mod.Title}/{rM.Name}")));
+
+            // Have to add 3 phases because the indicator
+            // will immediately disappear upon entering the last one
             LoadProgressIndicator.AddFixedPhases(3);
             LoadProgressIndicator.AdvanceFixedPhase("Executing EngineInit Hooks...");
-            Info(() => "Engine started initializing! Calling OnEngineInit on ResoniteMonkeys!");
+
+            var sw = Stopwatch.StartNew();
 
             foreach (var resoniteMonkey in ResoniteMonkeys)
             {
                 LoadProgressIndicator.SetSubphase(resoniteMonkey.Name);
                 resoniteMonkey.EngineInit();
                 LoadProgressIndicator.ExitSubphase();
             }
+
+            Info(() => $"Done executing EngineInit hooks on ResoniteMonkeys in {sw.ElapsedMilliseconds}ms!");
         }
 
         private static void OnEngineReady()
         {
+            // Potentially move this to be a postfix of init or run as Task as otherwise it's blocking.
+            Info(() => "Engine is ready! Executing EngineReady hooks on ResoniteMonkeys!");
+
+            var resoniteMonkeys = ResoniteMonkeys.ToArray();
+            Logger.Trace(() => "Running EngineReady hooks in this order:");
+            Logger.Trace(resoniteMonkeys.Select(rM => new Func<object>(() => $"{rM.Mod.Title}/{rM.Name}")));
+
             LoadProgressIndicator.AdvanceFixedPhase("Executing EngineReady Hooks...");
-            Info(() => "Engine initialized! Calling OnEngineReady on ResoniteMonkeys!");
+            var sw = Stopwatch.StartNew();
 
             foreach (var resoniteMonkey in ResoniteMonkeys)
             {
@@ -61,15 +78,31 @@ private static void OnEngineReady()
                 LoadProgressIndicator.ExitSubphase();
             }
 
+            Info(() => $"Done executing EngineReady hooks on ResoniteMonkeys in {sw.ElapsedMilliseconds}ms!");
             LoadProgressIndicator.AdvanceFixedPhase("Mods Fully Loaded");
         }
 
-        private static void OnEngineShutdown() => Mod.Loader.Shutdown();
+        private static void OnEngineShutdown()
+        {
+            Info(() => "Engine shutdown has been triggered! Passing shutdown through to MonkeyLoader!");
+
+            Mod.Loader.Shutdown();
+        }
 
         private static void OnEngineShutdownRequested(string reason)
         {
-            foreach (var resoniteMonkey in Mod.Loader.Monkeys.SelectCastable<IMonkey, IResoniteMonkeyInternal>())
+            Info(() => "Engine shutdown has been requested! Executing EngineShutdownRequested hooks on ResoniteMonkeys!");
+
+            var resoniteMonkeys = ResoniteMonkeys.ToArray();
+            Logger.Trace(() => "Running EngineShutdownRequested hooks in this order:");
+            Logger.Trace(resoniteMonkeys.Select(rM => new Func<object>(() => $"{rM.Mod.Title}/{rM.Name}")));
+
+            var sw = Stopwatch.StartNew();
+
+            foreach (var resoniteMonkey in resoniteMonkeys)
                 resoniteMonkey.EngineShutdownRequested(reason);
+
+            Info(() => $"Done executing EngineShutdownRequested hooks on ResoniteMonkeys in {sw.ElapsedMilliseconds}ms!");
         }
     }
-}
+}

MonkeyLoader.Resonite.Integration/InstantResoniteLog.cs

@@ -0,0 +1,23 @@
+using HarmonyLib;
+using MonkeyLoader.Patching;
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+
+namespace MonkeyLoader.Resonite
+{
+    [HarmonyPatchCategory(nameof(InstantResoniteLog))]
+    [HarmonyPatch("FrooxEngineBootstrap+<>c, Assembly-CSharp", "<Start>b__10_1")]
+    internal class InstantResoniteLog : Monkey<InstantResoniteLog>
+    {
+        public override string Name { get; } = "Instant Resonite Log";
+
+        protected override IEnumerable<IFeaturePatch> GetFeaturePatches() => Enumerable.Empty<IFeaturePatch>();
+
+        [HarmonyPostfix]
+        private static void WriteLinePostfix()
+            => FrooxEngineBootstrap.LogStream.Flush();
+    }
+}

MonkeyLoader.Resonite.Integration/LoadProgressIndicator.cs

@@ -177,8 +177,8 @@ public static bool SetSubphase(string subphase)
             if (!Available)
                 return false;
 
-            lock (_loadProgress)
-                _loadProgress.SetSubphase(subphase);
+            //lock (_loadProgress)
+            _loadProgress.SetSubphase(subphase);
 
             Trace(() => $"Set EngineLoadProgress subphase to: {subphase}");
 
@@ -203,20 +203,17 @@ protected override bool OnFirstSceneReady(Scene scene)
 
         [HarmonyPostfix]
         [HarmonyPatch(nameof(EngineLoadProgress.SetFixedPhase))]
-        private static void SetFixedPhasedPostfix(EngineLoadProgress __instance, string phase)
+        private static void SetFixedPhasedPostfix(string phase, ref string ____showSubphase)
         {
             _phase = phase;
-
-            lock (__instance)
-                __instance.SetSubphase(phase);
+            ____showSubphase = phase;
         }
 
         [HarmonyPostfix]
         [HarmonyPatch(nameof(EngineLoadProgress.SetSubphase))]
-        private static void SetSubphasePostfix(EngineLoadProgress __instance, string subphase)
+        private static void SetSubphasePostfix(string subphase, ref string ____showSubphase)
         {
-            lock (__instance)
-                __instance.SetSubphase($"{_phase}   {subphase}");
+            ____showSubphase = $"{_phase}   {subphase}";
         }
 
         // Returned true means success, false means something went wrong.

MonkeyLoader.Resonite.Integration/MonkeyLoader.Resonite.Integration.csproj

@@ -11,6 +11,14 @@
     </MSBuild>
   </Target>
 
+  <ItemGroup>
+    <Compile Remove="InstantResoniteLog.cs" />
+  </ItemGroup>
+
+  <ItemGroup>
+    <None Include="InstantResoniteLog.cs" />
+  </ItemGroup>
+
   <ItemGroup>
     <PackageReference Include="MonkeyLoader" Version="0.3.0-beta" />
     <PackageReference Include="MonkeyLoader.GamePacks.Unity" Version="0.3.0-beta" />