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

Question

我已经为 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 对象 - 否则我会得到方法名称。）

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

Answer 1

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

Answer 2

经过六年半的可靠服务后，在应用了 Microsoft 的更新（其中包括对 .Net Framework 4.5 的更改）后，我突然发现我的许多程序在 2017 年底崩溃了。这就是编写依赖于 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();
      }
   }

Answer 3

感谢 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。）

Answer 4

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

Answer 5

如果您递归到相同的方法并且只想知道当前方法的深度，我正在使用这种检查，尽管它可能对性能不太好。我猜 new StackTrace() 可以存储在某个地方以避免每次重新创建，但就我而言，这并不重要，所以我这样使用它：

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

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