MyLog logs to the Torch logging system

Fixed issue with labels not being transferred correctly when transpiling.

NLog.config

@@ -6,10 +6,12 @@
     <target xsi:type="File" name="main" layout="${time} [${level:uppercase=true}] ${logger}: ${message}" fileName="Logs\Torch-${shortdate}.log" />
     <target xsi:type="File" name="chat" layout="${longdate} ${message}" fileName="Logs\Chat.log" />
     <target xsi:type="ColoredConsole" name="console" layout="${time} [${level:uppercase=true}] ${logger}: ${message}" />
+    <target xsi:type="File" name="patch" layout="${message}" fileName="Logs\patch.log"/>
   </targets>
 
   <rules>
     <logger name="*" minlevel="Info" writeTo="main, console" />
     <logger name="Chat" minlevel="Info" writeTo="chat" />
+    <!--<logger name="Torch.Managers.PatchManager.*" minlevel="Trace" writeTo="patch"/>-->
   </rules>
 </nlog>

Torch/Managers/KeenLogManager.cs

@@ -0,0 +1,157 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Reflection;
+using System.Text;
+using System.Threading;
+using System.Threading.Tasks;
+using NLog;
+using Torch.API;
+using Torch.Managers.PatchManager;
+using Torch.Utils;
+using VRage.Utils;
+
+namespace Torch.Managers
+{
+    public class KeenLogManager : Manager
+    {
+        private static readonly Logger _log = LogManager.GetLogger("Keen");
+
+#pragma warning disable 649
+        [Dependency]
+        private PatchManager.PatchManager _patchManager;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.Log), Parameters = new[] { typeof(MyLogSeverity), typeof(StringBuilder) })]
+        private static MethodInfo _logStringBuilder;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.Log), Parameters = new[] { typeof(MyLogSeverity), typeof(string), typeof(object[]) })]
+        private static MethodInfo _logFormatted;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.WriteLine), Parameters = new[] { typeof(string) })]
+        private static MethodInfo _logWriteLine;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.AppendToClosedLog), Parameters = new[] { typeof(string) })]
+        private static MethodInfo _logAppendToClosedLog;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.WriteLine), Parameters = new[] { typeof(string), typeof(LoggingOptions) })]
+        private static MethodInfo _logWriteLineOptions;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.WriteLine), Parameters = new[] { typeof(Exception) })]
+        private static MethodInfo _logWriteLineException;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.AppendToClosedLog), Parameters = new[] { typeof(Exception) })]
+        private static MethodInfo _logAppendToClosedLogException;
+
+        [ReflectedMethodInfo(typeof(MyLog), nameof(MyLog.WriteLineAndConsole), Parameters = new[] { typeof(string) })]
+        private static MethodInfo _logWriteLineAndConsole;
+#pragma warning restore 649
+
+        private PatchContext _context;
+
+        public KeenLogManager(ITorchBase torchInstance) : base(torchInstance)
+        {
+        }
+
+        public override void Attach()
+        {
+            _context = _patchManager.AcquireContext();
+
+            _context.GetPattern(_logStringBuilder).Prefixes.Add(Method(nameof(PrefixLogStringBuilder)));
+            _context.GetPattern(_logFormatted).Prefixes.Add(Method(nameof(PrefixLogFormatted)));
+
+            _context.GetPattern(_logWriteLine).Prefixes.Add(Method(nameof(PrefixWriteLine)));
+            _context.GetPattern(_logAppendToClosedLog).Prefixes.Add(Method(nameof(PrefixAppendToClosedLog)));
+            _context.GetPattern(_logWriteLineAndConsole).Prefixes.Add(Method(nameof(PrefixWriteLine)));
+
+            _context.GetPattern(_logWriteLineException).Prefixes.Add(Method(nameof(PrefixWriteLineException)));
+            _context.GetPattern(_logAppendToClosedLogException).Prefixes.Add(Method(nameof(PrefixAppendToClosedLogException)));
+
+            _context.GetPattern(_logWriteLineOptions).Prefixes.Add(Method(nameof(PrefixWriteLineOptions)));
+
+            _patchManager.Commit();
+        }
+
+        public override void Detach()
+        {
+            _patchManager.FreeContext(_context);
+        }
+
+        private static MethodInfo Method(string name)
+        {
+            return typeof(KeenLogManager).GetMethod(name, BindingFlags.Static | BindingFlags.NonPublic | BindingFlags.Public);
+        }
+
+        [ReflectedMethod(Name = "GetThreadId")]
+        private static Func<MyLog, int> _getThreadId;
+
+        [ReflectedMethod(Name = "GetIdentByThread")]
+        private static Func<MyLog, int, int> _getIndentByThread;
+
+        private static readonly ThreadLocal<StringBuilder> _tmpStringBuilder = new ThreadLocal<StringBuilder>(() => new StringBuilder(32));
+
+        private static StringBuilder PrepareLog(MyLog log)
+        {
+            return _tmpStringBuilder.Value.Clear().Append(' ', _getIndentByThread(log, _getThreadId(log)) * 3);
+        }
+
+        private static bool PrefixWriteLine(MyLog __instance, string msg)
+        {
+            _log.Info(PrepareLog(__instance).Append(msg));
+            return false;
+        }
+        private static bool PrefixAppendToClosedLog(MyLog __instance, string text)
+        {
+            _log.Info(PrepareLog(__instance).Append(text));
+            return false;
+        }
+        private static bool PrefixWriteLineOptions(MyLog __instance, string message, LoggingOptions option)
+        {
+            if (__instance.LogFlag(option))
+                _log.Info(PrepareLog(__instance).Append(message));
+            return false;
+        }
+
+        private static bool PrefixAppendToClosedLogException(Exception e)
+        {
+            _log.Info(e);
+            return false;
+        }
+
+        private static bool PrefixWriteLineException(Exception ex)
+        {
+            _log.Info(ex);
+            return false;
+        }
+
+        private static bool PrefixLogFormatted(MyLog __instance, MyLogSeverity severity, string format, object[] args)
+        {
+            _log.Log(LogLevelFor(severity), PrepareLog(__instance).AppendFormat(format, args));
+            return false;
+        }
+
+        private static bool PrefixLogStringBuilder(MyLog __instance, MyLogSeverity severity, StringBuilder builder)
+        {
+            _log.Log(LogLevelFor(severity), PrepareLog(__instance).Append(builder));
+            return false;
+        }
+
+        private static LogLevel LogLevelFor(MyLogSeverity severity)
+        {
+            switch (severity)
+            {
+                case MyLogSeverity.Debug:
+                    return LogLevel.Debug;
+                case MyLogSeverity.Info:
+                    return LogLevel.Info;
+                case MyLogSeverity.Warning:
+                    return LogLevel.Warn;
+                case MyLogSeverity.Error:
+                    return LogLevel.Error;
+                case MyLogSeverity.Critical:
+                    return LogLevel.Fatal;
+                default:
+                    return LogLevel.Info;
+            }
+        }
+    }
+}

Torch/Managers/PatchManager/DecoratedMethod.cs

@@ -34,18 +34,21 @@ namespace Torch.Managers.PatchManager
 
             if (Prefixes.Count == 0 && Suffixes.Count == 0 && Transpilers.Count == 0)
                 return;
+            _log.Debug($"Begin patching {_method.DeclaringType?.FullName}#{_method.Name}({string.Join(", ", _method.GetParameters().Select(x => x.ParameterType.Name))})");
             var patch = ComposePatchedMethod();
 
             _revertAddress = AssemblyMemory.GetMethodBodyStart(_method);
             var newAddress = AssemblyMemory.GetMethodBodyStart(patch);
             _revertData = AssemblyMemory.WriteJump(_revertAddress, newAddress);
             _pinnedPatch = GCHandle.Alloc(patch);
+            _log.Debug($"Done patching {_method.DeclaringType?.FullName}#{_method.Name}({string.Join(", ", _method.GetParameters().Select(x => x.ParameterType.Name))})");
         }
 
         internal void Revert()
         {
             if (_pinnedPatch.HasValue)
             {
+                _log.Debug($"Revert {_method.DeclaringType?.FullName}#{_method.Name}({string.Join(", ", _method.GetParameters().Select(x => x.ParameterType.Name))})");
                 AssemblyMemory.WriteMemory(_revertAddress, _revertData);
                 _revertData = null;
                 _pinnedPatch.Value.Free();
@@ -113,29 +116,30 @@ namespace Torch.Managers.PatchManager
 
             var specialVariables = new Dictionary<string, LocalBuilder>();
 
-            Label? labelAfterOriginalContent = Suffixes.Count > 0 ? target.DefineLabel() : (Label?)null;
+            Label labelAfterOriginalContent = target.DefineLabel();
-            Label? labelAfterOriginalReturn = Prefixes.Any(x => x.ReturnType == typeof(bool)) ? target.DefineLabel() : (Label?)null;
+            Label labelAfterOriginalReturn = target.DefineLabel();
 
 
-            var returnType = _method is MethodInfo meth ? meth.ReturnType : typeof(void);
+            Type returnType = _method is MethodInfo meth ? meth.ReturnType : typeof(void);
-            var resultVariable = returnType != typeof(void) && (labelAfterOriginalReturn.HasValue || // If we jump past main content we need local to store return val
+            LocalBuilder resultVariable = null;
-                Prefixes.Concat(Suffixes).SelectMany(x => x.GetParameters()).Any(x => x.Name == RESULT_PARAMETER))
+            if (returnType != typeof(void))
-                ? target.DeclareLocal(returnType)
+            {
-                : null;
+                if (Prefixes.Concat(Suffixes).SelectMany(x => x.GetParameters()).Any(x => x.Name == RESULT_PARAMETER))
+                    resultVariable = target.DeclareLocal(returnType);
+                else if (Prefixes.Any(x => x.ReturnType == typeof(bool)))
+                    resultVariable = target.DeclareLocal(returnType);
+            }
             resultVariable?.SetToDefault(target);
 
             if (resultVariable != null)
                 specialVariables.Add(RESULT_PARAMETER, resultVariable);
 
             target.EmitComment("Prefixes Begin");
-            foreach (var prefix in Prefixes)
+            foreach (MethodInfo prefix in Prefixes)
             {
                 EmitMonkeyCall(target, prefix, specialVariables);
                 if (prefix.ReturnType == typeof(bool))
-                {
+                    target.Emit(OpCodes.Brfalse, labelAfterOriginalReturn);
-                    Debug.Assert(labelAfterOriginalReturn.HasValue);
-                    target.Emit(OpCodes.Brfalse, labelAfterOriginalReturn.Value);
-                }
                 else if (prefix.ReturnType != typeof(void))
                     throw new Exception(
                         $"Prefixes must return void or bool.  {prefix.DeclaringType?.FullName}.{prefix.Name} returns {prefix.ReturnType}");
@@ -145,30 +149,23 @@ namespace Torch.Managers.PatchManager
             target.EmitComment("Original Begin");
             MethodTranspiler.Transpile(_method, Transpilers, target, labelAfterOriginalContent);
             target.EmitComment("Original End");
-            if (labelAfterOriginalContent.HasValue)
+
-            {
+            target.MarkLabel(labelAfterOriginalContent);
-                target.MarkLabel(labelAfterOriginalContent.Value);
+            if (resultVariable != null)
-                if (resultVariable != null)
+                target.Emit(OpCodes.Stloc, resultVariable);
-                    target.Emit(OpCodes.Stloc, resultVariable);
+            target.MarkLabel(labelAfterOriginalReturn);
-            }
-            if (labelAfterOriginalReturn.HasValue)
-                target.MarkLabel(labelAfterOriginalReturn.Value);
 
             target.EmitComment("Suffixes Begin");
-            foreach (var suffix in Suffixes)
+            foreach (MethodInfo suffix in Suffixes)
             {
                 EmitMonkeyCall(target, suffix, specialVariables);
                 if (suffix.ReturnType != typeof(void))
                     throw new Exception($"Suffixes must return void.  {suffix.DeclaringType?.FullName}.{suffix.Name} returns {suffix.ReturnType}");
             }
             target.EmitComment("Suffixes End");
-
+            if (resultVariable != null)
-            if (labelAfterOriginalContent.HasValue || labelAfterOriginalReturn.HasValue)
+                target.Emit(OpCodes.Ldloc, resultVariable);
-            {
+            target.Emit(OpCodes.Ret);
-                if (resultVariable != null)
-                    target.Emit(OpCodes.Ldloc, resultVariable);
-                target.Emit(OpCodes.Ret);
-            }
         }
 
         private void EmitMonkeyCall(LoggingIlGenerator target, MethodInfo patch,

Torch/Managers/PatchManager/MSIL/MsilInstruction.cs

@@ -4,6 +4,7 @@ using System.Reflection;
 using System.Reflection.Emit;
 using System.Text;
 using Torch.Managers.PatchManager.Transpile;
+using Label = System.Windows.Controls.Label;
 
 namespace Torch.Managers.PatchManager.MSIL
 {
@@ -69,7 +70,7 @@ namespace Torch.Managers.PatchManager.MSIL
                     break;
                 case OperandType.ShortInlineI:
                     Operand = OpCode == OpCodes.Ldc_I4_S
-                        ? (MsilOperand) new MsilOperandInline.MsilOperandInt8(this)
+                        ? (MsilOperand)new MsilOperandInline.MsilOperandInt8(this)
                         : new MsilOperandInline.MsilOperandUInt8(this);
                     break;
                 case OperandType.ShortInlineR:
@@ -120,10 +121,23 @@ namespace Torch.Managers.PatchManager.MSIL
         /// <returns>This instruction</returns>
         public MsilInstruction InlineValue<T>(T o)
         {
-            ((MsilOperandInline<T>) Operand).Value = o;
+            ((MsilOperandInline<T>)Operand).Value = o;
             return this;
         }
 
+        /// <summary>
+        /// Makes a copy of the instruction with a new opcode.
+        /// </summary>
+        /// <param name="code">The new opcode</param>
+        /// <returns>The copy</returns>
+        public MsilInstruction CopyWith(OpCode code)
+        {
+            var result = new MsilInstruction(code) { Operand = this.Operand };
+            foreach (MsilLabel x in Labels)
+                result.Labels.Add(x);
+            return result;
+        }
+
         /// <summary>
         ///     Sets the inline branch target for this instruction.
         /// </summary>
@@ -131,7 +145,7 @@ namespace Torch.Managers.PatchManager.MSIL
         /// <returns>This instruction</returns>
         public MsilInstruction InlineTarget(MsilLabel label)
         {
-            ((MsilOperandBrTarget) Operand).Target = label;
+            ((MsilOperandBrTarget)Operand).Target = label;
             return this;
         }
 

Torch/Managers/PatchManager/Transpile/MethodContext.cs

@@ -34,8 +34,8 @@ namespace Torch.Managers.PatchManager.Transpile
         public MethodContext(MethodBase method)
         {
             Method = method;
-                _msilBytes = Method.GetMethodBody().GetILAsByteArray();
+            _msilBytes = Method.GetMethodBody().GetILAsByteArray();
-                TokenResolver = new NormalTokenResolver(method);
+            TokenResolver = new NormalTokenResolver(method);
         }
 
         public void Read()
@@ -56,7 +56,7 @@ namespace Torch.Managers.PatchManager.Transpile
                     var instructionValue = (short)memory.ReadByte();
                     if (Prefixes.Contains(instructionValue))
                     {
-                        instructionValue = (short) ((instructionValue << 8) | memory.ReadByte());
+                        instructionValue = (short)((instructionValue << 8) | memory.ReadByte());
                         count++;
                     }
                     if (!OpCodeLookup.TryGetValue(instructionValue, out OpCode opcode))
@@ -65,7 +65,7 @@ namespace Torch.Managers.PatchManager.Transpile
                         throw new Exception($"Opcode said it was {opcode.Size} but we read {count}");
                     var instruction = new MsilInstruction(opcode)
                     {
-                        Offset = (int) memory.Position
+                        Offset = (int)memory.Position
                     };
                     _instructions.Add(instruction);
                     instruction.Operand?.Read(this, reader);
@@ -106,9 +106,9 @@ namespace Torch.Managers.PatchManager.Transpile
                 var opcode = (OpCode)field.GetValue(null);
                 if (opcode.OpCodeType != OpCodeType.Nternal)
                     OpCodeLookup.Add(opcode.Value, opcode);
-                if ((ushort) opcode.Value > 0xFF)
+                if ((ushort)opcode.Value > 0xFF)
                 {
-                    Prefixes.Add((short) ((ushort) opcode.Value >> 8));
+                    Prefixes.Add((short)((ushort)opcode.Value >> 8));
                 }
             }
         }

Torch/Managers/PatchManager/Transpile/MethodTranspiler.cs

@@ -28,18 +28,19 @@ namespace Torch.Managers.PatchManager.Transpile
 
         private static IEnumerable<MsilInstruction> FixBranchAndReturn(IEnumerable<MsilInstruction> insn, Label? retTarget)
         {
-            foreach (var i in insn)
+            foreach (MsilInstruction i in insn)
             {
                 if (retTarget.HasValue && i.OpCode == OpCodes.Ret)
                 {
-                    var j = new MsilInstruction(OpCodes.Br);
+                    MsilInstruction j = new MsilInstruction(OpCodes.Br).InlineTarget(new MsilLabel(retTarget.Value));
-                    ((MsilOperandBrTarget)j.Operand).Target = new MsilLabel(retTarget.Value);
+                    foreach (MsilLabel l in i.Labels)
+                        j.Labels.Add(l);
                     yield return j;
                     continue;
                 }
                 if (_opcodeReplaceRule.TryGetValue(i.OpCode, out OpCode replaceOpcode))
                 {
-                    yield return new MsilInstruction(replaceOpcode) { Operand = i.Operand };
+                    yield return i.CopyWith(replaceOpcode);
                     continue;
                 }
                 yield return i;
@@ -62,6 +63,7 @@ namespace Torch.Managers.PatchManager.Transpile
                         _opcodeReplaceRule.Add(opcode, other.Value);
                 }
             }
+            _opcodeReplaceRule[OpCodes.Leave_S] = OpCodes.Leave;
         }
     }
 }

Torch/Torch.csproj

@@ -159,6 +159,7 @@
     <Compile Include="Managers\ChatManager\ChatManagerClient.cs" />
     <Compile Include="Managers\ChatManager\ChatManagerServer.cs" />
     <Compile Include="Managers\DependencyManager.cs" />
+    <Compile Include="Managers\KeenLogManager.cs" />
     <Compile Include="Managers\PatchManager\AssemblyMemory.cs" />
     <Compile Include="Managers\PatchManager\DecoratedMethod.cs" />
     <Compile Include="Managers\PatchManager\EmitExtensions.cs" />

Torch/TorchBase.cs

@@ -24,6 +24,7 @@ using Torch.API.Session;
 using Torch.Commands;
 using Torch.Managers;
 using Torch.Managers.ChatManager;
+using Torch.Managers.PatchManager;
 using Torch.Utils;
 using Torch.Session;
 using VRage.Collections;
@@ -119,6 +120,8 @@ namespace Torch
             sessionManager.AddFactory((x) => new EntityManager(this));
 
             Managers.AddManager(sessionManager);
+            Managers.AddManager(new PatchManager(this));
+            Managers.AddManager(new KeenLogManager(this));
             Managers.AddManager(new FilesystemManager(this));
             Managers.AddManager(new UpdateManager(this));
             Managers.AddManager(Plugins);