Async Void Methods Can Crash Your Process

October 30, 2013

no comments

Last time I told you an async log4net appender got me in trouble. After resolving that issue, I remained with an appender that directly implements IAppender, that looked something like this:

   1: public class SplunkAppender : IAppender

   2:     {        

   3:         public async void DoAppend(log4net.Core.LoggingEvent loggingEvent)

   4:         {

   5:             var clientIp = _clientIpRetriever.GetClientIp();

   6:             var message = new SplunkMessage(loggingEvent.Level, loggingEvent.ExceptionObject, clientIp);

   7:             var success = await _splunkLogger.Report(message);

   8:             //do something unimportant

   9:         }

  10:  

  11:         public void Close() { }

  12:         public string Name {get; set;}        

  13:     }

Pretty simple, yes? Now, as you can see, I also added the client’s IP to Splunk’s report, because why not (this is a self-hosted WCF service we’re talking about)? A few hours after this was deployed to production, BOOM. A few of the servers crashed. Well, at least it’s not a deadlock this time. Still, the exception is pretty weird, and looked something like –

   1: Unhandled Exception: System.Exception: Exception of type 'System.Exception' was thrown.

   2:    at ConsoleApplication1.ClientIpRetriever.GetClientIp() in d:\Projects\Blog\ConsoleApplication1\Program.cs:line 25

   3:    at ConsoleApplication1.SplunkAppender.<DoAppend>d__0.MoveNext() in d:\Projects\Blog\ConsoleApplication1\Program.cs:line 34

   4: --- End of stack trace from previous location where exception was thrown ---

   5:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.<ThrowAsync>b__5(Object state)

   6:    at System.Threading.QueueUserWorkItemCallback.WaitCallback_Context(Object state)

   7:    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)

   8:    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)

   9:    at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()

  10:    at System.Threading.ThreadPoolWorkQueue.Dispatch()

  11:    at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()

Hmm. Pretty obvious. GetClientIp Throws an exception, which is not caught, erm, anywhere. But wait a minute, surely log4net handles exceptions thrown by appenders, right? And even if it doesn’t it should make a single request fail, not the entire-freaking-process?!

Then I looked at the stack trace, which contains stuff like AsyncMethodBuilderCore and I realized this happens because it’s an async method. Stephen Cleary had this to say about async void methods:

Async void methods have different error-handling semantics. When an exception is thrown out of an async Task or async Task<T> method, that exception is captured and placed on the Task object. With async void methods, there is no Task object, so any exceptions thrown out of an async void method will be raised directly on the SynchronizationContext that was active when the async void method started.

In order to simplify error handling, an async method will never throw an exception to the calling code. The exception can be observed via the created Task. Otherwise you’d have to handle in a different way the case of an exception thrown before the await call and after it. But as Stephen Cleary says above, there is simply no way to catch an exception thrown by an async void method, except for the AppDomain.UnhandledException event or something of the sort.

In my case, GetClientIp threw an exception. The calling code is an async void method, so the exception was never caught and it crashed the process. FUN. The solution? Don’t use an async void method, and if you do, make sure to catch your exceptions! I ended up with something that looked like this:

   1:  

   2:     public class SplunkAppender : IAppender

   3:     {        

   4:         public void DoAppend(log4net.Core.LoggingEvent loggingEvent)

   5:         {

   6:             var clientIp = _clientIpRetriever.GetClientIp();

   7:             var message = new SplunkMessage(loggingEvent.Level, loggingEvent.ExceptionObject, clientIp);

   8:             SendMessageToSplunk(message);

   9:         }

  10:  

  11:         private async void SendMessageToSplunk(SplunkMessage message)

  12:         {

  13:             try

  14:             {

  15:                 var success = await _splunkLogger.Report(message);

  16:                 //do something unimportant

  17:             }

  18:             catch(Exception x)

  19:             {

  20:                 LogLog.Error(GetType(), "Error in SplunkAppender.", x);

  21:             }            

  22:         }

  23:         public void Close() { }

  24:         public string Name {get; set;}        

  25:     }

The DoAppend method is not async anymore, so any exception will be thrown and caught in the standard way. I do still have an async void helper method, but it is protected with a try-catch clause, and so production has been stable ever since.

Add comment
facebook linkedin twitter email

Leave a Reply

Your email address will not be published.

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>

*