Getting the caller method name - Reflection and CallerInfo attribute

Question

Just bench-marked the performance of using StackTrace and CallerInfo Attributes.

Shockingly I found that using StackTrace is much faster though every where I read that To get the caller method name, the preferred approach is CallerInfo attributes.

public class Program
    {
        public static void Main(string[] args)
        {
          Method1();  
        }

         static void Method1([CallerMemberName]string memberName = "")
         {
            double stackTraceTimings = 0;
            var sw = new Stopwatch();

            foreach(var item in Enumerable.Range(1,1000).ToList())
            {
               sw.Start();
               var callerName = new StackFrame(1).GetMethod().Name;
               sw.Stop();
               stackTraceTimings += sw.Elapsed.TotalMilliseconds;
            }

            Console.WriteLine("Elapsed Time for retrieving the caller name using StackFrame in 1000 iterations ={0}",stackTraceTimings/1000);

            stackTraceTimings = 0;
            foreach(var item in Enumerable.Range(1,1000).ToList())
            {
                sw.Start();
                var callerName = (memberName);
                sw.Stop();
                stackTraceTimings += sw.Elapsed.TotalMilliseconds;
            }

            Console.WriteLine("Elapsed Time for retrieving the caller name using callerInfo Attribute in 1000 iterations ={0}",stackTraceTimings/1000);
        }

OUTPUT: Elapsed Time for retrieving the caller name using StackFrame in 1000 iterations =9.48074760000001

Elapsed Time for retrieving the caller name using callerInfo Attribute in 1000 iterations =21.7074064

Did I misunderstood anything ? Using CallerInfo attributes is the preferred approach right ?

Thanks to the below answer for pointing out.

I have to re-start the timer every time in the loop.

So, who wins ? As the below answer says, CallerInfo. Because, it is a compile-time feature and is faster.

Elapsed Time for retrieving the caller name using StackFrame in 1000 iterations =0.00762619999999992

Elapsed Time for retrieving the caller name using callerInfo Attribute in 1000 iterations =0.00639420000000002

I used the below code (revised) and got the above results.

 public class Program
    {
        public static void Main(string[] args)
        {
          Method1();  
        }

         static void Method1([CallerMemberName]string memberName = "")
         {
            double stackTraceTimings = 0;
            var sw = new Stopwatch();

            foreach(var item in Enumerable.Range(1,1000).ToList())
            {
               sw.Start();
               var callerName = new StackFrame(1).GetMethod().Name;
               sw.Stop();
               Console.Write(callerName);
               sw.Restart();
               stackTraceTimings += sw.Elapsed.TotalMilliseconds;
            }

            Console.WriteLine("Elapsed Time for retrieving the caller name using StackFrame in 1000 iterations ={0}",stackTraceTimings/1000);


            stackTraceTimings = 0;
            foreach(var item in Enumerable.Range(1,1000).ToList())
            {
                sw.Start();
                var callerName = (memberName);
                Console.Write(callerName);
                sw.Stop();
                sw.Restart();

                stackTraceTimings += sw.Elapsed.TotalMilliseconds;
            }

            Console.WriteLine("Elapsed Time for retrieving the caller name using callerInfo Attribute in 1000 iterations ={0}",stackTraceTimings/1000);
        }
    }

Answer 1

You have to reset timer before second loop. sw.Start starts Stopwatch from state it was after first loop, so second result is actually time for both StackTrace and Attribute-based solutions summed together.

CallerMethodName is compile-type feature, it should definitely be faster.

With fixed code timing for CallerMethodName from your results is:

21.7074064 - (9.48074760000001 * 2) = 2.7459111999999806

That's much faster, isn't it?

subtracted first time twice: once for lack of Reset call and once for += instead of =.

Update

These results seems to be much too big. Are you sure you're using Release build, run from outside Visual Studio? I think not, because otherwise you'd get exact same results for both: callerName is never used and will probably be optimized to no-op (at least for second case).