Floyd Pink Floyd Pink - 2 months ago 20
C# Question

Intercept the call to an async method using DynamicProxy

Below is the code from the

Intercept
method on a custom type that implements
IInterceptor
of the Castle Dynamic Proxy library. This snippet is from an AOP based logging proof-of-concept console app that is posted here.

public void Intercept(IInvocation invocation)
{
if (Log.IsDebugEnabled) Log.Debug(CreateInvocationLogString("Called", invocation));
try
{
invocation.Proceed();
if (Log.IsDebugEnabled)
if (invocation.Method.ReturnType != typeof(void))
Log.Debug("Returning with: " + invocation.ReturnValue);
}
catch (Exception ex)
{
if (Log.IsErrorEnabled) Log.Error(CreateInvocationLogString("ERROR", invocation), ex);
throw;
}
}


This is working as expected on regular method calls, but not when tried with
async
methods (using the
async/await
keywords from C# 5.0). And I believe, I understand the reasons behind this as well.

For the
async/await
to work, the compiler adds the functional body of the method into a state machine behind the scenes and the control will return to the caller, as soon as the first
awaitable
expression that cannot be completed synchronously, is encountered.

Also, we can interrogate the return type and figure out whether we are dealing with an
async
method like this:

if (invocation.Method.ReturnType == typeof(Task) ||
(invocation.Method.ReturnType.IsGenericType &&
invocation.Method.ReturnType.GetGenericTypeDefinition() == typeof(Task<>)))
Log.Info("Asynchronous method found...");


This works for only those
async
methods that returns either
Task
or
Task<>
and not
void
but I am fine with that.

What changes have to made within the
Intercept
method so that the
awaiter
would return to there rather than the original caller?

Answer

Presumably the "problem" is that it's just logging that it's returning a task - and you want the value within that task?

Assuming that's the case, you still have to return the task to the caller, immediately - without waiting for it to complete. If you break that, you're fundamentally messing things up.

However, before you return the task to the caller, you should add a continuation (via Task.ContinueWith) which will log the result (or failure) when the task completes. That will still give the result information, but of course you'll be logging it potentially after some other logging. You may also want to log immediately before returning, leading to a log something like this:

Called FooAsync
Returned from FooAsync with a task
Task from FooAsync completed, with return value 5

The business of getting the result out of the task (if it completed successfully) would have to be done with reflection, which is a bit of a pain - or you could use dynamic typing. (Either way it will be a bit of a performance hit.)