CODEWITHSUNDEEP
c#performancereflectionmethodbase
Ioannis
Ioannis

Reputation: 3045

MethodBase.GetCurrentMethod() Performance?

I have written a log class and a function as in the following code:

Log(System.Reflection.MethodBase methodBase, string message)

Every time I log something I also log the class name from the methodBase.Name and methodBase.DeclaringType.Name.

I read the following post Using Get CurrentMethod and I noticed that this method is slow.

Should I use the this.GetType() instead of System.Reflection.MethodBase or I should manually log the class/method name in my log e.g. Log("ClassName.MethodName", "log message)? What is the best practice?

Upvotes: 12

Views: 15802

Answers (2)

Edwin de Koning
Edwin de Koning

Reputation: 14387

It really depends.

If you use the this.GetType() approach you will lose the method information, but you will have a big performance gain (apparently a factor of 1200, according to your link).

If you offer an interface that lets the caller supply strings (e.g. Log("ClassName.MethodName", "log message"), you will probably gain even better performance, but this makes your API less friendly (the calling developer has to supply the class name and method name).

Upvotes: 11

Xaiter
Xaiter

Reputation: 147

I know this is an old question, but I figured I'd throw out a simple solution that seems to perform well and maintains symbols

static void Main(string[] args)
    {
        int loopCount = 1000000; // 1,000,000 (one million) iterations
        var timer = new Timer();

        timer.Restart();
        for (int i = 0; i < loopCount; i++)
            Log(MethodBase.GetCurrentMethod(), "whee");
        TimeSpan reflectionRunTime = timer.CalculateTime();

        timer.Restart();
        for (int i = 0; i < loopCount; i++)
            Log((Action<string[]>)Main, "whee");
        TimeSpan lookupRunTime = timer.CalculateTime();

        Console.WriteLine("Reflection Time: {0}ms", reflectionRunTime.TotalMilliseconds);
        Console.WriteLine("    Lookup Time: {0}ms", lookupRunTime.TotalMilliseconds);
        Console.WriteLine();
        Console.WriteLine("Press Enter to exit");
        Console.ReadLine();

    }

    public static void Log(Delegate info, string message)
    {
        // do stuff
    }

    public static void Log(MethodBase info, string message)
    {
        // do stuff
    }

    public class Timer
    {
        private DateTime _startTime;

        public void Restart()
        {
            _startTime = DateTime.Now;
        }

        public TimeSpan CalculateTime()
        {
            return DateTime.Now.Subtract(_startTime);
        }
    }

Running this code gives me the following results:

Reflection Time: 1692.1692ms
    Lookup Time: 19.0019ms

Press Enter to exit

For one million iterations, that's not bad at all, especially compared to straight up reflection. The method group is being cast to a Delegate type, you maintain a symbolic link all the way into the logging. No goofy magic strings.

Upvotes: 6

Related Questions