CODEWITHSUNDEEP
c#async-awaitautofacinterception
Callum Linington
Callum Linington

Reputation: 14417

Autofac Interception async execution order

So I have this class:

public class MappingBootstrap : IMappingBootstrap
{
    public virtual async Task Map()
    {
        // Order is very important

        await this.mapper1.Map();

        await this.mapper2.Map();

        await this.mapper3.Map();

        await this.mapper4.Map();
    }
}

I have Autofac Interceptor:

public class LoggingInterceptor : IInterceptor
{
    public void Intercept(IInvocation invocation)
    {
        var methodReference = Guid.NewGuid();
        Console.WriteLine($"Calling {invocation?.Method?.DeclaringType?.Name}.{invocation?.Method?.Name} : {methodReference}");

        var startNew = Stopwatch.StartNew();

        invocation?.Proceed();

        startNew.Stop();

        Console.WriteLine($"{methodReference} : Done, time taken: {startNew.ElapsedMilliseconds}ms");
    }
}

This produces the output:

Calling IMapperBootstrap.Map : 54425559-71fe-4f23-ab47-d0f3371ec819
Calling IMapper1.Map : 51babb34-fa83-42ed-84e7-a1e979528116
51babb34-fa83-42ed-84e7-a1e979528116 : Done, time taken: 219ms
54425559-71fe-4f23-ab47-d0f3371ec819 : Done, time taken: 221ms
Calling IMapper2.Map : 41c812a2-d82d-48f6-9b8d-139b52eb28e3
41c812a2-d82d-48f6-9b8d-139b52eb28e3 : Done, time taken: 9ms
Calling IMapper3.Map : c91bed04-8f86-47d3-a35a-417e354c2c5f
c91bed04-8f86-47d3-a35a-417e354c2c5f : Done, time taken: 994ms
Calling IMapper4.Map : 035cad27-1ba8-4bd1-b85f-396f64998d97
035cad27-1ba8-4bd1-b85f-396f64998d97 : Done, time taken: 18ms

As you can see, the MappingBoostrap.Map finishes after the first Mapper1.Map rather than what I expect which is when all the functions have completed. Why?

Autofac Config:

builder.Register(context => new LoggingInterceptor());

builder
    .RegisterAssemblyTypes(typeof(Bootstrapper).Assembly)
    .Where(x => x.Namespace.Contains("Mapping"))
    .AsImplementedInterfaces()
    .EnableInterfaceInterceptors()
    .InterceptedBy(typeof(LoggingInterceptor));

Upvotes: 1

Views: 2411

Answers (1)

Stephen Cleary
Stephen Cleary

Reputation: 456587

Why?

When you call an asynchronous method like this:

mapping.Map();

it only starts the method. This is how asynchronous methods work (as I explain on my blog). If you await the task returned by the asynchronous method, then the current method will pause until the asynchronous method completes:

await mapping.Map();

In the case of interception, the ideal solution would be to have the Proceed and Intercept methods asynchronous:

public async Task InterceptAsync(IInvocation invocation)
{
  ...
  await invocation?.ProceedAsync();
  ...
}

Unfortunately, Autofac has no built-in understanding of asynchronous methods, so this isn't possible. Instead, you have to call Proceed, which just starts the asynchronous method. The asynchronous method returns a Task, which represents the execution of that method. To hook into the completion of the method, you should replace that Task with one of your own.

For a plain Task-returning method, you can use something like this:

public void Intercept(IInvocation invocation)
{
  var methodReference = Guid.NewGuid();
  Console.WriteLine($"Calling {invocation?.Method?.DeclaringType?.Name}.{invocation?.Method?.Name} : {methodReference}");

  var startNew = Stopwatch.StartNew();

  invocation.Proceed();
  invocation.ReturnValue = WatchAsync(methodReference, startNew, (Task)invocation.ReturnValue);
}

private static async Task WatchAsync(Guid methodReference,
    Stopwatch stopwatch, Task methodExecution)
{
  try
  {
    await methodExecution.ConfigureAwait(false);
  }
  finally
  {
    stopwatch.Stop();
    Console.WriteLine($"{methodReference} : Done, time taken: {stopwatch.ElapsedMilliseconds}ms");
  }
}

Upvotes: 7

Related Questions