How can I add a Trace() to every method call in C#?

Question

I am having a hard time tracking down a lock issue, so I would like to log every method call's entry and exit. I've done this before with C++ without having to add code to every method. Is this possible with C#?

Solution 1

Probably your best bet would be to use an AOP (aspect oriented programming) framework to automatically call tracing code before and after a method execution. A popular choice for AOP and .NET is PostSharp.

Solution 2

If your primary goal is to log function entry/exit points and occasional information in between, I've had good results with an Disposable logging object where the constructor traces the function entry, and Dispose() traces the exit. This allows calling code to simply wrap each method's code inside a single using statement. Methods are also provided for arbitrary logs in between. Here is a complete C# ETW event tracing class along with a function entry/exit wrapper:

using System;
using System.Diagnostics;
using System.Diagnostics.Tracing;
using System.Reflection;
using System.Runtime.CompilerServices;

namespace MyExample
{
    // This class traces function entry/exit
    // Constructor is used to automatically log function entry.
    // Dispose is used to automatically log function exit.
    // use "using(FnTraceWrap x = new FnTraceWrap()){ function code }" pattern for function entry/exit tracing
    public class FnTraceWrap : IDisposable
    {
        string methodName;
        string className;

        private bool _disposed = false;

        public FnTraceWrap()
        {
            StackFrame frame;
            MethodBase method;

            frame = new StackFrame(1);
            method = frame.GetMethod();
            this.methodName = method.Name;
            this.className = method.DeclaringType.Name;

            MyEventSourceClass.Log.TraceEnter(this.className, this.methodName);
        }

        public void TraceMessage(string format, params object[] args)
        {
            string message = String.Format(format, args);
            MyEventSourceClass.Log.TraceMessage(message);
        }

        public void Dispose()
        {
            if (!this._disposed)
            {
                this._disposed = true;
                MyEventSourceClass.Log.TraceExit(this.className, this.methodName);
            }
        }
    }

    [EventSource(Name = "MyEventSource")]
    sealed class MyEventSourceClass : EventSource
    {
        // Global singleton instance
        public static MyEventSourceClass Log = new MyEventSourceClass();

        private MyEventSourceClass()
        {
        }

        [Event(1, Opcode = EventOpcode.Info, Level = EventLevel.Informational)]
        public void TraceMessage(string message)
        {
            WriteEvent(1, message);
        }

        [Event(2, Message = "{0}({1}) - {2}: {3}", Opcode = EventOpcode.Info, Level = EventLevel.Informational)]
        public void TraceCodeLine([CallerFilePath] string filePath = "",
                                  [CallerLineNumber] int line = 0,
                                  [CallerMemberName] string memberName = "", string message = "")
        {
            WriteEvent(2, filePath, line, memberName, message);
        }

        // Function-level entry and exit tracing
        [Event(3, Message = "Entering {0}.{1}", Opcode = EventOpcode.Start, Level = EventLevel.Informational)]
        public void TraceEnter(string className, string methodName)
        {
            WriteEvent(3, className, methodName);
        }

        [Event(4, Message = "Exiting {0}.{1}", Opcode = EventOpcode.Stop, Level = EventLevel.Informational)]
        public void TraceExit(string className, string methodName)
        {
            WriteEvent(4, className, methodName);
        }
    }
}

Code that uses it will look something like this:

public void DoWork(string foo)
{
    using (FnTraceWrap fnTrace = new FnTraceWrap())
    {
        fnTrace.TraceMessage("Doing work on {0}.", foo);
        /*
        code ...
        */
    }
}

Solution 3

A profiler is great for looking at your running code during development but if you're looking for the ability to do custom traces in production, then, as Denis G. mentionned, PostSharp is the perfect tool: you don't have to change all your code and you can easily switch it on/off.

It's also easy to set-up in a few minutes and Gaël Fraiteur, the creator of PostSharp even has videos that shows you how easy it is to add tracing to an existing app.
You will find examples and tutorials in the documentation section.

Solution 4

Use ANTS Profiler from Red Gate would be your best bet. Failing that, look into interceptors in Castle Windsor. That does assume you're loading your types via IoC though.

Reflection is another way, you can use the System.Reflection.Emit methods to "write" code into memory. That code could replace your method's code, and execute it but with appropriate logging. Good luck on that one, though... Easier would be to use an Aspect Oriented Programming framework like Aspect#.

Solution 5

It might be waiting for the lock issue to take hold, doing a memory dump and analysing the call stack on various threads. You can use DebugDiag or the adplus script (hang mode, in this case) that comes with Debugging Tools for Windows.

Tess Ferrandez also has an excellent lab series on learning to debug various issues using .NET memory dumps. I highly recommend it.

View more solutions