WinDBg定位asp.net mvc项目异常崩溃源码位置

项目介绍：asp.net mvc + angular +iis+windows server

系统莫名崩溃

最近有个系统默认奇妙崩溃50x，服务整体变成无响应，当运维告知我只有重启应用程序池项目才能正常。

我问他如何重现，得到的回复是我这里无法重现，但客户使用一段时间后，就会崩溃。

于是我崩溃了。因为查日志没有任何错误，查windows系统日志上也只有一个错误 System.AccessViolationException 尝试读取或写入受保护的内存。这通常指示其他内存已损坏，从系统的日志也无法定位到错误代码。搜索关键字，未找到任何有用的信息。

寻求其他方案定位错误

正好最近看到一线码农通过dump文件定位程序异常情况，分析内存，分析线程的操作。我这才有了新的思路，不然也只能二眼干瞪，无计可施。

第一步是抓取dump文件。

首先，在服务器端：

1.开启Windows Error Reporting Service服务。

2.将下面的脚本保存成 dumps.reg ,在服务器上执行。

.执行注册表脚本后，在w3wp.exe程序挂掉的时候，自动将dump文件保存到D:\dumps文件夹中：

1Windows Registry Editor Version 5.00
2[HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\Windows Error Reporting\LocalDumps\w3wp.exe]
3"DumpFolder"=hex(2):64,00,3a,00,5c,00,64,00,75,00,6d,00,70,00,73,00,00,00
4"DumpCount"=dword:00000002
5"DumpType"=dword:00000002

正好服务器没有d盘，我们就打开cmd,输入 regedit 打开服务器的注册表。找到 HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\Windows Error Reporting\LocalDumps\w3wp.exe, 我们可以看到DumpFolder的设置项，可以根据自己需要改成相应的目录。

image-20210429195613526

过了半天，程序又崩溃了，我先让实施先重启IIS应用池，再拿过来dmp文件，发现会有二个。

image即使

一开始我按一些文档，将抓取的dump文件，用vs打开，尝试vs调试，即时设置了符号服务器，调试源文件增加源代码路径，也无法定位到源代码。浪费了许多时间。我决定去找下专业的工具。

WinDbg出场

工具：WinDbg

https://docs.microsoft.com/zh-cn/windows-hardware/drivers/debugger/debugger-download-tools

从Microsoft Store下载windbg Preview，

image-20210429200324089

For analysis of this file, run !analyze -v

点击后!analyze -v得到的一些信息，和之前的windows系统日志差不多。此时处于busy状态，无法操作，标记处是输入查询命令处。

image-20210429200515952

经过一段时间分析，得到如下结果。

1    Key  : CLR.Exception.System.AccessViolationException._message
2    Value: 尝试读取或写入受保护的内存。这通常指示其他内存已损坏。
3
4    Key  : CLR.Exception.Type
5    Value: System.AccessViolationException

还有一段，我一直看不懂。因为当时看到了如何从 dump 文件中提取出 C# 源代码？这个文章，我就想，能不能，定位错误的源码，所以用 !savemodule 76c656e8 d:\dumps\xxx.dll ，生成dll，再用ILspy，是无法反编译的，可能这段错，实际上是c++上报的错。我想应该，那篇文章就只是从dump文件中找到相应的模块，然后导出整体dll。由于源码非常多，在一个dll上，也是无法找到错误的。

 1CONTEXT:  (.ecxr)2eax=1c8cf308 ebx=00000005 ecx=00000005 edx=00000000 esi=1c8cf3d0 edi=000000013eip=76c656e8 esp=1c8cf308 ebp=1c8cf364 iopl=0         nv up ei pl nz ac po nc4cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=000002125KERNELBASE!RaiseException+0x48:676c656e8 8b4c2454        mov     ecx,dword ptr [esp+54h] ss:002b:1c8cf35c=69c849467Resetting default scope89EXCEPTION_RECORD:  (.exr -1)
10ExceptionAddress: 76c656e8 (KERNELBASE!RaiseException+0x00000048)
11   ExceptionCode: e0434352 (CLR exception)
12  ExceptionFlags: 00000001
13NumberParameters: 5
14   Parameter[0]: 80004003
15   Parameter[1]: 00000000
16   Parameter[2]: 00000000
17   Parameter[3]: 00000000
18   Parameter[4]: 70880000
19   PROCESS_NAME:  w3wp.exe
20
21EXCEPTION_CODE_STR:  80004003
22
23FAULTING_THREAD:  ffffffff
24
25STACK_TEXT:
2600000000 00000000 w3wp!unknown_function+0x0
27STACK_COMMAND:  ** Pseudo Context ** ManagedPseudo ** Value: ffffffff ** ; kb
28
29SYMBOL_NAME:  w3wp!unknown_function
30
31MODULE_NAME: w3wp
32
33IMAGE_NAME:  w3wp.exe
34
35FAILURE_BUCKET_ID:  CLR_EXCEPTION_System.AccessViolationException_80004003_w3wp.exe!unknown_function

我就在想会不会有死锁，或文件访问异常导致的。先把写日志的代码单独拿出来，再用Jmeter，并发访问写日志的接口，即时是我们自己写的日志，在疯狂请求时，也不会导致程序异常，。由于项目代码是旧代码，对内部可能哪里会问题也猜不到。

我先说正确的思路

!threads

我们可以看到有一个线程Woker上有异常。

 1ThreadCount:      92UnstartedThread:  03BackgroundThread: 94PendingThread:    05DeadThread:       06Hosted Runtime:   no7                                                                         Lock  8       ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception9   8    1 2188 019da830     28220 Preemptive  10C08398:00000000 01a02bd8 0     Ukn
10  29    2 36b8 025d7738     2b220 Preemptive  00000000:00000000 01a02bd8 0     MTA (Finalizer)
11  31    3 1c6c 0260b568   102a220 Preemptive  00000000:00000000 01a02bd8 0     MTA (Threadpool Worker)
12  32    4 315c 02616678     21220 Preemptive  00000000:00000000 01a02bd8 0     Ukn
13  34    6 31c0 026180e0   1020220 Preemptive  00000000:00000000 01a02bd8 0     Ukn (Threadpool Worker)
14  35    7 1274 02618628   1029220 Preemptive  069745A0:00000000 01a02bd8 0     MTA (Threadpool Worker)
15  37    8 2484 02617108   1029220 Preemptive  0EBFFB18:00000000 01a02bd8 0     MTA (Threadpool Worker) System.AccessViolationException 0ebee9dc
16  38    9 2234 026156a0   1029220 Preemptive  0AAED5CC:00000000 01a02bd8 0     MTA (Threadpool Worker)
17  39   10 3858 02617b98   1029220 Preemptive  0CB7BEE0:00000000 01a02bd8 0     MTA (Threadpool Worker)

这时候我们就可以使用 !pe ，这个命令打印出exception

10:037> !pe
2Exception object: 0ebee9dc
3Exception type:   System.AccessViolationException
4Message:          尝试读取或写入受保护的内存。这通常指示其他内存已损坏。
5InnerException:   <none>
6StackTrace (generated):
7<none>
8StackTraceString: <none>
9HResult: 80004003

0ebee9dc这个在windbg上显示是绿色的。可以直接点击，就会生成如下命令。

10:037> !DumpObj /d 0ebee9dc

可以看到_stackTraceString的value是灰色，是无法点击的，我有好几次已经定位到这一步了，但我没有点击如下选中的value值。点击他就会展示具体的源码错误异常，没走对方向，主要原因不清楚 windbg是什么，这些变量代表的含义。

这是点击绿色的0ebfd24c这个地址执行的命令。

10:037> !DumpObj /d 0ebfd24c

定位到源码，一切就会很清楚了，虽然感觉这行不可能报错，但事实就是普普通通Oralce 访问数据库的ExecuteNonQuery()，报的AccessViolationException` 错，这个错即使通过Try Catch也无法抓取，

相似的问题：https://stackoverflow.com/questions/27383472/executenonquery-exception-not-caught-by-try-catch
Runtime中也有类似的issues :https://github.com/dotnet/runtime/issues/981
https://stackoverflow.com/questions/63945367/accessviolationexception-with-provider-oraoledb-oracle-on-12c

网上看到一些方法是重置网络，由于是生产环境，我对服务器环境一无所知，有实施管理，所以未尝试。

netsh winsock reset

重新定位了最后几个请求的参数，的确发现了有些奇怪。这个变量是换行的，而且有$$，:""特殊字符，。我一开始也看到这个语句，当时是很奇怪，而且拿到plSQL中执行，发现是正常的，就没在意，但现在发现可能是这个参数导致的。

update xxx set  xxx='  "$$hashKey": "object:231"' where info_id = '792094'

定位下前台源码，原来某个下拉区选择，代码取的是object,没取到对应的值，直接传给后台，而后台sql是配置的，该变量直接是拼接的，不是参数化。所以我决定先改掉这个再看情况，给实施发布打包，最近已经10天（2021-4-29），也没有说程序崩溃的问题。

在此之前，我还查了内存，死锁情况，然而一无所获。

在此非常感谢一线码农，原本也没打算写个文章，但大佬说也整理分享下遇到的坑。才有此文章。

也正是了解到了windbg这种方式去调试，去分析，才能定位，并解决这种问题。

不然程序崩溃，我也要一起崩溃。。。