C# StackFrame 的性能如何？

How performant is StackFrame?

提问by

I am considering using something like StackFrame stackFrame = new StackFrame(1)to log the executing method, but I don't know about its performance implications. Is the stack trace something that is build anyway with each method call so performance should not be a concern or is it something that is only build when asked for it? Do you recommend against it in an application where performance is very important? If so, does that mean I should disable it for the release?

我正在考虑使用类似StackFrame stackFrame = new StackFrame(1)记录执行方法的东西，但我不知道它的性能影响。堆栈跟踪是在每个方法调用中构建的，因此性能不应该成为问题，还是仅在需要时构建？您是否建议在性能非常重要的应用程序中使用它？如果是这样，这是否意味着我应该在发布时禁用它？

采纳答案by STW

edit:Some background

编辑：一些背景

---

---

We have a similar feature which is disabled 99% of the time; we were using an approach like:

我们有一个类似的功能，在 99% 的情况下都被禁用；我们使用的方法是：

public void DoSomething()
{
    TraceCall(MethodBase.GetCurrentMethod().Name);
    // Do Something
}

public void TraceCall(string methodName)
{
    if (!loggingEnabled) { return; }
    // Log...
}

TraceCall(MethodBase.GetCurrentMethod().Name)

It was simple, but regardless of whether or not tracing was enabled we were incurring the performance hit of using Reflection to lookup the method name.

这很简单，但无论是否启用跟踪，我们都会因使用反射查找方法名称而导致性能下降。

Our options were to either require more code in every method (and risk simple mistakes or refusal) or to switch to using StackFrameto determine the calling method onlywhen logging was enabled.

我们的选择是要么在每个方法中都需要更多的代码（并冒着简单的错误或拒绝的风险），要么切换到仅在启用日志记录时使用StackFrame来确定调用方法。

Option A:

选项A：

public void DoSomething()
{
    if (loggingEnabled)
    {
        TraceCall(MethodBase.GetCurrentMethod().Name);
    }
    // Do Something
}

public void TraceCall(string methodName)
{
    if (!loggingEnabled) { return; }
    // Log...
}

Option B:

选项 B：

public void DoSomething()
{
    TraceCall();
    // Do Something
}

public void TraceCall()
{
    if (!loggingEnabled) { return; }
    StackFrame stackFrame = new StackFrame(1);
    // Log...
}

We opted for Option B. It offers significant performance improvements over Option A when logging is disabled, 99% of the timeand is very simple to implement.

我们选择了选项 B。当禁用日志记录时，它比选项 A 提供了显着的性能改进，99% 的时间并且非常容易实现。

Here's an alteration of Michael's code, to display the cost / benefit of this approach

这是迈克尔代码的更改，以显示这种方法的成本/收益

using System;
using System.Diagnostics;
using System.Reflection;

namespace ConsoleApplication
{
    class Program
    {
        static bool traceCalls;

        static void Main(string[] args)
        {
            Stopwatch sw;

            // warm up
            for (int i = 0; i < 100000; i++)
            {
                TraceCall();
            }

            // call 100K times, tracing *disabled*, passing method name
            sw = Stopwatch.StartNew();
            traceCalls = false;
            for (int i = 0; i < 100000; i++)
            {
                TraceCall(MethodBase.GetCurrentMethod());
            }
            sw.Stop();
            Console.WriteLine("Tracing Disabled, passing Method Name: {0}ms"
                             , sw.ElapsedMilliseconds);

            // call 100K times, tracing *enabled*, passing method name
            sw = Stopwatch.StartNew();
            traceCalls = true;
            for (int i = 0; i < 100000; i++)
            {
                TraceCall(MethodBase.GetCurrentMethod());
            }
            sw.Stop();
            Console.WriteLine("Tracing Enabled, passing Method Name: {0}ms"
                             , sw.ElapsedMilliseconds);

            // call 100K times, tracing *disabled*, determining method name
            sw = Stopwatch.StartNew();
            traceCalls = false;
            for (int i = 0; i < 100000; i++)
            {
                TraceCall();
            }
            Console.WriteLine("Tracing Disabled, looking up Method Name: {0}ms"
                       , sw.ElapsedMilliseconds);

            // call 100K times, tracing *enabled*, determining method name
            sw = Stopwatch.StartNew();
            traceCalls = true;
            for (int i = 0; i < 100000; i++)
            {
                TraceCall();
            }
            Console.WriteLine("Tracing Enabled, looking up Method Name: {0}ms"
                       , sw.ElapsedMilliseconds);

            Console.ReadKey();
        }

        private static void TraceCall()
        {
            if (traceCalls)
            {
                StackFrame stackFrame = new StackFrame(1);
                TraceCall(stackFrame.GetMethod().Name);
            }
        }

        private static void TraceCall(MethodBase method)
        {
            if (traceCalls)
            {
                TraceCall(method.Name);
            }
        }

        private static void TraceCall(string methodName)
        {
            // Write to log
        }
    }
}

The Results:

结果：

Tracing Disabled, passing Method Name: 294ms
Tracing Enabled,  passing Method Name: 298ms
Tracing Disabled, looking up Method Name: 0ms
Tracing Enabled,  looking up Method Name: 1230ms

回答by Paul Williams

From the MSDN documentation, it seems like StackFrames are being created all the time:

从 MSDN 文档中，似乎一直在创建 StackFrames：

A StackFrame is created and pushed on the call stack for every function call made during the execution of a thread. The stack frame always includes MethodBase information, and optionally includes file name, line number, and column number information.

在线程执行期间，每次函数调用都会创建一个 StackFrame 并将其推送到调用堆栈上。堆栈帧始终包含 MethodBase 信息，并可选择包含文件名、行号和列号信息。

The constructor new StackFrame(1)you'd call would do this:

new StackFrame(1)您要调用的构造函数将执行以下操作：

private void BuildStackFrame(int skipFrames, bool fNeedFileInfo)
{
    StackFrameHelper sfh = new StackFrameHelper(fNeedFileInfo, null);
    StackTrace.GetStackFramesInternal(sfh, 0, null);
    int numberOfFrames = sfh.GetNumberOfFrames();
    skipFrames += StackTrace.CalculateFramesToSkip(sfh, numberOfFrames);
    if ((numberOfFrames - skipFrames) > 0)
    {
        this.method = sfh.GetMethodBase(skipFrames);
        this.offset = sfh.GetOffset(skipFrames);
        this.ILOffset = sfh.GetILOffset(skipFrames);
        if (fNeedFileInfo)
        {
            this.strFileName = sfh.GetFilename(skipFrames);
            this.iLineNumber = sfh.GetLineNumber(skipFrames);
            this.iColumnNumber = sfh.GetColumnNumber(skipFrames);
        }
    }
}

GetStackFramesInternalis an external method. CalculateFramesToSkiphas a loop that operates exactly once, since you specified only 1 frame. Everything else looks pretty quick.

GetStackFramesInternal是一种外部方法。 CalculateFramesToSkip有一个只运行一次的循环，因为您只指定了 1 帧。其他一切看起来都很快。

Have you tried measuring how long it would take to create, say, 1 million of them?

你有没有试过测量创建 100 万个它们需要多长时间？

回答by Michael Petrotta

A quick and naive test indicates that for performance-sensitive code, yes, you want to pay attention to this:

一个快速而幼稚的测试表明，对于性能敏感的代码，是的，您要注意这一点：

Don't generate 100K frames: 3ms

Generate 100K frames: 1805ms

不生成 100K 帧：3ms

生成 100K 帧：1805ms

About 20 microseconds per generated frame, on my machine. Not a lot, but a measurable difference over a large number of iterations.

在我的机器上，每个生成的帧大约需要 20 微秒。不是很多，但在大量迭代中存在可测量的差异。

Speaking to your later questions ("Should I disable StackFrame generation in my application?"), I'd suggest you analyze your application, do performance tests like the one I've done here, and see if the performance difference amounts to anything with your workload.

谈到你后来的问题（“我应该在我的应用程序中禁用 StackFrame 生成吗？”），我建议你分析你的应用程序，像我在这里所做的那样进行性能测试，看看性能差异是否与你的工作量。

using System;
using System.Diagnostics;

namespace ConsoleApplication
{
    class Program
    {
        static bool generateFrame;

        static void Main(string[] args)
        {
            Stopwatch sw;

            // warm up
            for (int i = 0; i < 100000; i++)
            {
                CallA();
            }

            // call 100K times; no stackframes
            sw = Stopwatch.StartNew();
            for (int i = 0; i < 100000; i++)
            {
                CallA();
            }
            sw.Stop();
            Console.WriteLine("Don't generate 100K frames: {0}ms"
                                 , sw.ElapsedMilliseconds);

            // call 100K times; generate stackframes
            generateFrame = true;
            sw = Stopwatch.StartNew();
            for (int i = 0; i < 100000; i++)
            {
                CallA();
            }
            Console.WriteLine("Generate 100K frames: {0}ms"
                           , sw.ElapsedMilliseconds);

            Console.ReadKey();
        }

        private static void CallA()
        {
            CallB();
        }

        private static void CallB()
        {
            CallC();
        }

        private static void CallC()
        {
            if (generateFrame)
            {
                StackFrame stackFrame = new StackFrame(1);
            }
        }
    }
}

回答by Michael Stum

I am considering using something like StackFrame stackFrame = new StackFrame(1) to log the executing method

我正在考虑使用 StackFrame stackFrame = new StackFrame(1) 之类的东西来记录执行方法

Out of interest: Why? If you only want the current method, then

出于兴趣：为什么？如果你只想要当前的方法，那么

string methodName = System.Reflection.MethodBase.GetCurrentMethod().Name;

seems better. Maybe not more performant (I didn't compare, but Reflection shows that GetCurrentMethod() does not simply create a StackFrame but does some "magic"), but clearer in it's intent.

似乎更好。也许不是更高效（我没有比较，但反射表明 GetCurrentMethod() 不只是创建一个 StackFrame 而是做了一些“魔术”），但它的意图更清晰。

回答by farley13

I think Paul Williams hit the nail on the head with the work being done. If you dig deeper into StackFrameHelperyou'll find that fNeedFileInfois actually the performance killer - especially in debug mode. Try setting it falseif performance is important. You won't get much useful information in release mode anyway.

我认为保罗威廉姆斯在完成这项工作时一针见血。如果您深入研究，StackFrameHelper您会发现这fNeedFileInfo实际上是性能杀手——尤其是在调试模式下。如果性能很重要，请尝试将其设置为false。无论如何，在发布模式下您不会获得太多有用的信息。

If you pass falsein here you'll still get method names when doing a ToString()and without outputting any information, just moving stack pointers around, it's very fast.

如果你在这里传递false你仍然会在执行 a 时获得方法名称ToString()并且不输出任何信息，只是移动堆栈指针，它非常快。

回答by Jeroen

I know what you mean, but this example result is overshoot. Executing the GetCurrentMethod even when logging is turned off is a waste. It should be something like:

我知道你的意思，但这个例子的结果是超调的。即使在关闭日志记录时执行 GetCurrentMethod 也是一种浪费。它应该是这样的：

if (loggingEnabled) TraceCall(MethodBase.GetCurrentMethod());  

Or if you want the TraceCall always executed:

或者，如果您希望 TraceCall 始终执行：

TraceCall(loggingEnabled ? MethodBase.GetCurrentMethod() : null);

回答by user4468091

I know this is an old post, but just in case anyone comes across it there is another alternative if you are targeting .Net 4.5

我知道这是一篇旧帖子，但以防万一有人遇到它，如果您的目标是 .Net 4.5，还有另一种选择

You can use the CallerMemberName attribute to identify the calling method name. It is far faster than reflection or StackFrame. Here are the results from a quick test iterating a million times. StackFrame is extremely slow compared to reflection, and the new attribute makes both look like they are standing still. This was ran in the IDE.

您可以使用 CallerMemberName 属性来标识调用方法名称。它比反射或 StackFrame 快得多。以下是迭代一百万次的快速测试的结果。与反射相比，StackFrame 非常慢，并且新属性使两者看起来都静止不动。这是在IDE中运行的。

Reflection Result: 00:00:01.4098808

反射结果：00:00:01.4098808

StackFrame Result 00:00:06.2002501

堆栈帧结果 00:00:06.2002501

CallerMemberName attribute Result: 00:00:00.0042708

CallerMemberName 属性结果：00:00:00.0042708

Done

完毕

The following is from the compiled exe:Reflection Result: 00:00:01.2136738 StackFrame Result 00:00:03.6343924 CallerMemberName attribute Result: 00:00:00.0000947Done

以下来自编译的 exe：Reflection Result: 00:00:01.2136738 StackFrame Result 00:00:03.6343924 CallerMemberName attribute Result: 00:00:00.0000947Done

        static void Main(string[] args)
    {

        Stopwatch sw = new Stopwatch();

        sw.Stop();

        Console.WriteLine("Reflection Result:");

        sw.Start();
        for (int i = 0; i < 1000000; i++)
        {
            //Using reflection to get the current method name.
            PassedName(MethodBase.GetCurrentMethod().Name);
        }
        Console.WriteLine(sw.Elapsed);

        Console.WriteLine("StackFrame Result");

        sw.Restart();

        for (int i = 0; i < 1000000; i++)
        {
            UsingStackFrame();
        }

        Console.WriteLine(sw.Elapsed);

        Console.WriteLine("CallerMemberName attribute Result:");

        sw.Restart();
        for (int i = 0; i < 1000000; i++)
        {
            UsingCallerAttribute();
        }

        Console.WriteLine(sw.Elapsed);

        sw.Stop();



        Console.WriteLine("Done");
        Console.Read();
    }


    static void PassedName(string name)
    {

    }

    static void UsingStackFrame()
    {
        string name = new StackFrame(1).GetMethod().Name;
    }


    static void UsingCallerAttribute([CallerMemberName] string memberName = "")
    {

    }