MoveNext instead of actual method/task name

Question

Using log4net declared as:

private readonly ILog log = 
       LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType());

In an async method or task, like this one:

public async void CheckSomething()
{
    log.Info(null);
    //....
}

logs MoveNext instead of CheckSomething. Any idea how to make it log an actual method name?

Answer 1

All async methods are rewritten into a state machine to satisfy potential await values within the method. The final method in which the code lives is the MoveNext method which is what log4net is reporting.

There is really no good way at runtime to transition from MoveNext to the actual method in which the code was originally written. They are somewhat disconnected at a metadata level. You may just have to resort to logging the name directly

Answer 2

Short: given the MoveNext() method, try this:

private static MethodBase GetRealMethodFromAsyncMethod(MethodBase asyncMethod)
{
    var generatedType = asyncMethod.DeclaringType;
    var originalType = generatedType.DeclaringType;
    var matchingMethods = 
        from methodInfo in originalType.GetMethods() 
        let attr = methodInfo.GetCustomAttribute<AsyncStateMachineAttribute>() 
        where attr != null && attr.StateMachineType == generatedType 
        select methodInfo;

    // If this throws, the async method scanning failed.
    var foundMethod = matchingMethods.Single();
    return foundMethod;
}

Long (Disclaimer)

Don't use this in production. It relies on compiler behavior, which may likely change in a future version without notice. The following assumptions about compiler are made:

1. The actual running async method is generated inside a generated type.
2. The generated type is a nested type of the original type containing the original, hand-written method.
3. The original method gets a compiler-generated attribute AsyncStateMachine with the generated type supplied in it.

It works in my code, where I use it for runtime code analysis during debug/tests only. Again, please, don't use it in production code.

Answer 3

With thanks to the answer from Jacek Gorgoń, here is the utility I came up. It has a couple of improvements but still has a long way to go to work nicely with anonymous or lambda methods.

static string GetMethodContextName() {
    var name = new StackTrace().GetFrame(1).GetMethod().GetMethodContextName();
}

static string GetMethodContextName(this MethodBase method) {
    if (method.DeclaringType.GetInterfaces().Any(i => i == typeof(IAsyncStateMachine))) {
        var generatedType = method.DeclaringType;
        var originalType = generatedType.DeclaringType;
        var foundMethod = originalType.GetMethods(Instance | Static | Public | NonPublic | DeclaredOnly)
            .Single(m => m.GetCustomAttribute<AsyncStateMachineAttribute>()?.StateMachineType == generatedType);
        return foundMethod.DeclaringType.Name + "." + foundMethod.Name;
    } else {
        return method.DeclaringType.Name + "." + method.Name;
    }
}

Here's an example usage:

class Program { 
    static void Main(string[] args) {
        // outputs Program.Main
        Console.WriteLine(GetMethodContextName());
        Test().Wait();
    }
    static async Task Test() { 
        // outputs Program.Test
        Console.WriteLine(GetMethodContextName());
        await Task.CompletedTask;
    }
}

Answer 4

I wrote a simple wrapper around log4net.

public class Logger
{
    private ILog _Log { get; set; }

    public Logger(Type declaringType)
    {
        _Log = LogManager.GetLogger(declaringType);
    }

    public void Error(Exception exception, [CallerMemberName] string callerMemberName = "")
    {
        _Log.Error(callerMemberName, exception);
    }
}

In the code that is doing the logging, just do:

private Logger Log = new Logger(MethodBase.GetCurrentMethod().DeclaringType);

Of course if you want to do things like Info, Debug, etc, you can just add it to the wrapper class.

NOTE
this utilizes the c# 5.0 [CallerMemberName]