使用 Windbg 分析一个 异步操作 引发的 Crash 异常

上周我们收到了一个客户的紧急求助，他们的一个 iis应用程序池 经历了频繁重启，即使从错误日志中也不得到任何有用的信息，异常信息如下：

System.NullReferenceException : Object reference not set to an instance of an object.
System.Web.ThreadContext.AssociateWithCurrentThread(Boolean)
   System.Web.HttpApplication.OnThreadEnterPrivate(Boolean)
   System.Web.LegacyAspNetSynchronizationContext.CallCallbackPossiblyUnderLock(System.Threading.SendOrPostCallback, System.Object)
   System.Web.LegacyAspNetSynchronizationContext.CallCallback(System.Threading.SendOrPostCallback, System.Object)
   System.Threading.Tasks.AwaitTaskContinuation.RunCallback(System.Threading.ContextCallback, System.Object, System.Threading.Tasks.Task ByRef)
   System.Threading.Tasks.AwaitTaskContinuation+<>c.b__18_0(System.Object)
   System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
   System.Threading.ThreadPoolWorkQueue.Dispatch()

这种异常会杀掉进程，通过 google 搜索会发现这是 .NET 4.5 异步操作下的某种经典异常，大概就是说没有在合适的地方等待 Task, 参考：https://stackoverflow.com/questions/18759987/async-code-without-waiting-for-completion  ，参考如下代码：

var getDataTask = getData();

if(some_condition == true) {
    return some_object;
}

getDataTask.Wait();

return getDataTask.result;

如果代码无意走了 if(some_condition == true) 路径并没有 Wait 后续的 getDataTask 就会抛出这种异常，现在的问题是堆栈信息太少，并不能找到异常的源头在哪里？

使用 windbg 分析

如果你有 crash 的 dump，用windbg就能挖到很多有价值的信息。

1. File → Open Crash Dump

首先使用 windbg 打开 crash 文件，如下图：

从图中可以看到，windbg 已经告知我们当前有一个 CLR 异常。

1. Symbols

虽然没有客户的 debug 符号，这里使用微软的符号服务器， srv*C:\symbols*http://msdl.microsoft.com/download/symbols; 如下图：

1. 加载 SOS 扩展

在 windbg 命令窗口中输入  .loadby sos clr 。

1. 异常分析命令

使用 windbg 自带的异常分析自动化命令 !analyze -v ，然后你会得到很多的 异常信息, 参见下图：

上面的图中会告诉我们出问题的线程，接下来我们怎么看是谁创建了 Task，它的源头在哪里？可以用 !dso 查看这个问题线程的所有栈对象。

0:069> !dumpstackobjects
OS Thread Id: 0x2d20 (69)
RSP/REG          Object           Name
r15              0000002031518d78 System.Threading.Thread
00000022C6EBE680 0000001db1a917a8 System.NullReferenceException
00000022C6EBE6A0 0000001db1a917a8 System.NullReferenceException
00000022C6EBE6F8 0000001db1a917a8 System.NullReferenceException
00000022C6EBE740 0000001db1a91c40 System.Threading.QueueUserWorkItemCallback
00000022C6EBE758 0000001db1a91ad0 System.Runtime.ExceptionServices.ExceptionDispatchInfo
00000022C6EBE760 0000001db1a917a8 System.NullReferenceException
00000022C6EBE780 0000002031518d78 System.Threading.Thread
00000022C6EBE788 0000001db1a91c40 System.Threading.QueueUserWorkItemCallback
00000022C6EBE790 0000001db1a917a8 System.NullReferenceException
00000022C6EBE7A8 0000001df1b95078 System.SByte[]
00000022C6EBE7B0 0000001df1392cc0 System.Threading.ContextCallback
00000022C6EBE7C0 0000001db1a917a8 System.NullReferenceException
00000022C6EBE880 0000001db1a91ad0 System.Runtime.ExceptionServices.ExceptionDispatchInfo
00000022C6EBE888 0000001db1a917a8 System.NullReferenceException
00000022C6EBE8A8 0000001db1a91c40 System.Threading.QueueUserWorkItemCallback
00000022C6EBE8B0 0000002031518d78 System.Threading.Thread
00000022C6EBE910 0000001df1392cc0 System.Threading.ContextCallback
00000022C6EBE920 0000001db1a917a8 System.NullReferenceException
00000022C6EBE928 0000001db1a91ad0 System.Runtime.ExceptionServices.ExceptionDispatchInfo
00000022C6EBE938 0000001db1a91cc8 System.Threading.ExecutionContext
00000022C6EBE940 0000001db1a91cc8 System.Threading.ExecutionContext
00000022C6EBE950 0000001df1392cc0 System.Threading.ContextCallback
00000022C6EBE990 0000002031518d78 System.Threading.Thread
00000022C6EBE9F0 0000001db1a91c40 System.Threading.QueueUserWorkItemCallback
00000022C6EBE9F8 0000001db1a91cc8 System.Threading.ExecutionContext
00000022C6EBEA60 0000001df1392c98 System.Threading.ThreadPoolWorkQueue
00000022C6EBEAB8 0000001fb114f2e8 System.Threading.TimerQueue
00000022C6EBEAD8 00000020314c0ae8 System.Threading.ThreadPoolWorkQueueThreadLocals
00000022C6EBEAE0 0000001df1392c98 System.Threading.ThreadPoolWorkQueue
00000022C6EBEB00 0000001db1a91c40 System.Threading.QueueUserWorkItemCallback
00000022C6EBEE18 0000001df19f8320 System.Web.Hosting.IIS7WorkerRequest

这里有很多我们感兴趣的对象，那源头自然要深挖栈底对象 System.Web.Hosting.IIS7WorkerRequest ，使用 !do xxx 命令。

然后再挖里面的 _path 和 _httpVerb 字段，继续使用 !do。

从图中可以看到，线程的源头是从 POST /Account/Login 请求开始的。

总结

当把调查结果反馈给客户，几分钟后我收到了一封邮件，他们已经定位并解决了这个问题，据说是因为调用了第三方的 dll ，但这个 dll 并没有合理的实现 wait 所致。