对于 C# 日志记录，如何以最小的开销获得调用堆栈深度？答案

【问题标题】：For C# logging, how do I obtain the call stack depth with minimal overhead?对于 C# 日志记录，如何以最小的开销获得调用堆栈深度？
【发布时间】：2011-08-25 08:16:51
【问题描述】：

我已经为Log4net 创建了一个包装器（我可能会放弃它以支持 NLog；我还没有决定），并且我缩进了记录的消息结果以给出调用结构的概念。例如：

2011-04-03 00:20:30,271 [CT] DEBUG  -     Merlinia.ProcessManager.CentralThread.ProcessAdminCommand - ProcStart - User Info Repository
2011-04-03 00:20:30,271 [CT] DEBUG  -      Merlinia.ProcessManager.CentralThread.StartOneProcess - User Info Repository
2011-04-03 00:20:30,411 [CT] DEBUG  -       Merlinia.ProcessManager.CentralThread.SetProcessStatus - Process = User Info Repository, status = ProcStarting
2011-04-03 00:20:30,411 [CT] DEBUG  -        Merlinia.ProcessManager.CentralThread.SendProcessStatusInfo
2011-04-03 00:20:30,411 [CT] DEBUG  -         Merlinia.CommonClasses.MhlAdminLayer.SendToAllAdministrators - ProcessTable
2011-04-03 00:20:30,411 [CT] DEBUG  -          Merlinia.CommonClasses.MReflection.CopyToBinary
2011-04-03 00:20:30,411 [CT] DEBUG  -           Merlinia.CommonClasses.MReflection.CopyToBinary - False
2011-04-03 00:20:30,411 [CT] DEBUG  -          Merlinia.CommonClasses.MhlBasicLayer.SendToAllConnections - 228 - True - False
2011-04-03 00:20:30,411 [CT] DEBUG  -           Merlinia.CommonClasses.MmlNonThreaded.SendObject - 228
2011-04-03 00:20:30,411 [CT] DEBUG  -            Merlinia.CommonClasses.MllTcpSocket.SendMessage - 228 - True
2011-04-03 00:20:32,174 [10] DEBUG  -    Merlinia.CommonClasses.MReflection.CreateFromBinary
2011-04-03 00:20:32,174 [10] DEBUG  -     Merlinia.CommonClasses.MReflection.CopyFromBinary - Bytes = 71
2011-04-03 00:20:32,174 [CT] DEBUG  - Merlinia.ProcessManager.CentralThread.MessagingCallback - User Info Repository - ProcessInfoAndRequests
2011-04-03 00:20:32,174 [CT] DEBUG  -  Merlinia.ProcessManager.CentralThread.ProcessProcessInfoAndRequests - User Info Repository

我使用 System.Diagnostics.StackTrace 并计算 StackFrames 来执行此操作。

现在的问题是：有没有更有效的方法来做到这一点？我只需要确定（相对）调用堆栈深度，即当前深度加上或减去上次调用日志包装器时的深度。（请注意，我实际上并没有使用 StackFrame 对象 - 否则我会得到方法名称。）

我希望有一些简单的高性能方法来查询调用堆栈深度或堆栈使用情况。

【问题讨论】：

标签： c# logging callstack

【解决方案1】：

如果您对相同的方法进行递归，并且只想知道您在当前方法中的深度，我正在使用这种检查，尽管它可能对性能不太好。我猜new StackTrace() 可以存储在某个地方以避免每次都娱乐，但在我的情况下它并不重要，所以我这样使用它：

var callDepth = new StackTrace().GetFrames().Count(_ => _.GetMethod().Name == nameof(CallingMethod))

只需将CallingMethod 替换为您的方法名称

【讨论】：

【解决方案2】：

Environment.StackTrace.Split(Environment.NewLine).Length

【讨论】：

【解决方案3】：

经过六年半的可靠服务后，我突然发现我的许多程序在 2017 年底崩溃，因为我应用了 Microsoft 的更新，其中包括对 .Net Framework 4.5 的更改。这就是编写依赖于 mscorlib.dll 中内部未记录数据结构的代码的结果。

此版本的代码再次运行，并且在面对 mscorlib.dll 未来可能的更新时，它还被设计为更加健壮 - 希望它只是优雅地失败并始终返回零。但是仍然不能保证将来对 mscorlib.dll 的更改会导致此代码将来崩溃。

   /// <summary>
   /// This test program demonstrates a faster way of getting call stack depth by avoiding getting a 
   /// StackTrace object. But you can't get the calling method names this way.
   ///
   /// See http://stackoverflow.com/questions/5999177/for-c-logging-how-to-obtain-call-stack-depth-with-minimal-overhead
   /// and http://ayende.com/blog/3879/reducing-the-cost-of-getting-a-stack-trace
   ///
   /// Update, late 2017, .Net mscorlib.dll has been changed for .Net 4.5. In the code below the two 
   /// possibilities are called "old .Net" and "new .Net". The two versions can be tested by setting 
   /// the target for this project to either .Net Framework 2.0 or .Net Framework 4.5.
   /// </summary>
   class TestProgram
   {
      static void Main()
      {
         OneTimeSetup();

         int i = GetCallStackDepth();  // i = 10 on my test machine for old .Net, 12 for new .Net
         int j = AddOneToNesting();
         Console.WriteLine(j == i + 1 ? "Test succeeded!" : "Test failed!!!!!!!!");
         Console.ReadKey();
      }


      private delegate object DGetStackFrameHelper();

      private static DGetStackFrameHelper _getStackFrameHelper = null;

      private static FieldInfo _frameCount = null;


      private static void OneTimeSetup()
      {
         try
         {
            Type stackFrameHelperType =
                             typeof(object).Assembly.GetType("System.Diagnostics.StackFrameHelper");

            // ReSharper disable once PossibleNullReferenceException
            MethodInfo getStackFramesInternal =
               Type.GetType("System.Diagnostics.StackTrace, mscorlib").GetMethod(
                            "GetStackFramesInternal", BindingFlags.Static | BindingFlags.NonPublic);
            if (getStackFramesInternal == null)
               return;  // Unknown mscorlib implementation

            DynamicMethod dynamicMethod = new DynamicMethod(
                      "GetStackFrameHelper", typeof(object), new Type[0], typeof(StackTrace), true);

            ILGenerator generator = dynamicMethod.GetILGenerator();
            generator.DeclareLocal(stackFrameHelperType);

            bool newDotNet = false;

            ConstructorInfo constructorInfo =
                     stackFrameHelperType.GetConstructor(new Type[] {typeof(bool), typeof(Thread)});
            if (constructorInfo != null)
               generator.Emit(OpCodes.Ldc_I4_0);
            else
            {
               constructorInfo = stackFrameHelperType.GetConstructor(new Type[] {typeof(Thread)});
               if (constructorInfo == null)
                  return; // Unknown mscorlib implementation
               newDotNet = true;
            }

            generator.Emit(OpCodes.Ldnull);
            generator.Emit(OpCodes.Newobj, constructorInfo);
            generator.Emit(OpCodes.Stloc_0);
            generator.Emit(OpCodes.Ldloc_0);
            generator.Emit(OpCodes.Ldc_I4_0);

            if (newDotNet)
               generator.Emit(OpCodes.Ldc_I4_0);  // Extra parameter

            generator.Emit(OpCodes.Ldnull);
            generator.Emit(OpCodes.Call, getStackFramesInternal);
            generator.Emit(OpCodes.Ldloc_0);
            generator.Emit(OpCodes.Ret);

            _getStackFrameHelper =
                  (DGetStackFrameHelper) dynamicMethod.CreateDelegate(typeof(DGetStackFrameHelper));

            _frameCount = stackFrameHelperType.GetField("iFrameCount", 
                                                    BindingFlags.NonPublic | BindingFlags.Instance);
         }
         catch
         {}  // _frameCount remains null, indicating unknown mscorlib implementation
      }


      private static int GetCallStackDepth()
      {
         if (_frameCount == null)
            return 0;  // Unknown mscorlib implementation
         return (int)_frameCount.GetValue(_getStackFrameHelper());
      }


      private static int AddOneToNesting()
      {
         return GetCallStackDepth();
      }
   }

【讨论】：

【解决方案4】：

感谢 Teoman Soygul，尤其是 Oren Eini，他的博客 Teoman 提供了一个链接。

以下是一些“概念验证”代码，我认为这是我将使用的解决方案 - 尽管我必须承认我没有进行任何时序测试。

   class TestProgram
   {
      static void Main(string[] args)
      {
         OneTimeSetup();

         int i = GetCallStackDepth();   // i = 10 on my test machine
         i = AddOneToNesting();         // Now i = 11
      }


      private delegate object DGetStackFrameHelper();

      private static DGetStackFrameHelper _getStackFrameHelper;

      private static FieldInfo _frameCount;


      private static void OneTimeSetup()
      {
         Type stackFrameHelperType =
            typeof(object).Assembly.GetType("System.Diagnostics.StackFrameHelper");


         MethodInfo getStackFramesInternal =
            Type.GetType("System.Diagnostics.StackTrace, mscorlib").GetMethod(
                            "GetStackFramesInternal", BindingFlags.Static | BindingFlags.NonPublic);


         DynamicMethod dynamicMethod = new DynamicMethod(
                      "GetStackFrameHelper", typeof(object), new Type[0], typeof(StackTrace), true);

         ILGenerator generator = dynamicMethod.GetILGenerator();
         generator.DeclareLocal(stackFrameHelperType);
         generator.Emit(OpCodes.Ldc_I4_0);
         generator.Emit(OpCodes.Ldnull);
         generator.Emit(OpCodes.Newobj,
                  stackFrameHelperType.GetConstructor(new Type[] { typeof(bool), typeof(Thread) }));
         generator.Emit(OpCodes.Stloc_0);
         generator.Emit(OpCodes.Ldloc_0);
         generator.Emit(OpCodes.Ldc_I4_0);
         generator.Emit(OpCodes.Ldnull);
         generator.Emit(OpCodes.Call, getStackFramesInternal);
         generator.Emit(OpCodes.Ldloc_0);
         generator.Emit(OpCodes.Ret);


         _getStackFrameHelper =
                   (DGetStackFrameHelper)dynamicMethod.CreateDelegate(typeof(DGetStackFrameHelper));


         _frameCount = stackFrameHelperType.GetField(
                                     "iFrameCount", BindingFlags.NonPublic | BindingFlags.Instance);
      }


      private static int GetCallStackDepth()
      {
         return (int)_frameCount.GetValue(_getStackFrameHelper());
      }


      private static int AddOneToNesting()
      {
         return GetCallStackDepth();
      }
   }

编辑：在 Microsoft 于 2017 年底更新 mscorlib.dll 后，此版本不适用于 .Net Framework 4.5。请参阅我发布的更新版本的另一个答案。（为了后代，我留下这个答案 - 它仍然适用于 .Net Framework 2.0 和 3.5。）

【讨论】：

不是真的，它几乎 100% 是 Oren Eini 的代码，只是回归到 .Net 2。

【解决方案5】：

只需使用StackTrace.FrameCount 属性，并将其与之前记录的FrameCount 进行比较。仅供参考，FrameCount 可能是检索实际帧数的最快方法，因为它只返回内部 m_iNumOfFrames 字段给您。

【讨论】：

感谢您的回答。我可能错了，但我假设当您创建一个 StackTrace 对象时，也会创建所有 StackFrame 对象。你是说这不是事实？
new StackFrame() 对象如果你不使用它并没有那么昂贵，但如果你真的需要顶级性能，请继续阅读一些扭曲的 Reflection.Emit 内容：ayende.com/blog/3879/reducing-the-cost-of-getting-a-stack-trace
哇，我印象深刻。也感觉我的能力无法理解你所做的事情。以后有时间我会尝试分析和理解。但是“Func
这是一个 C# 3.0 特性，它是一个速记的通用委托。 Func<object> 类似于 public delegate object MyDelegate(object o) 这样的旧式委托。顺便说一句，我没有写代码 sn-p，感谢原作者。
@Teoman，对，我误以为那是你的博客，但仍然感谢你为我指明了方向。我现在可以运行代码，并进行了一些研究，我认为这可能是我正在寻找的解决方案。但我还有一个问题。我需要访问 StackFrameHelper.iFrameCount 字段。现在，Visual Studio 调试器知道这个字段并愿意显示它，没问题。但是 Visual Studio C# 编译器拒绝让我访问，因为 StackFrameHelper 是“内部的”。您对我应该如何访问该字段有什么建议吗？谢谢。