前言

其实,这篇文章早在 2021年就完成了初稿,后面一直没来得及完善(各种加班各种忙),所以一直没来得及整理发布。而且,我从这个案例里学到的东西太多了,很多内容并没有体现在本篇文章中,后续有机会一定会再写文章分享。话不多说,一起来看正文吧。

缘起

前一阵子,有朋友在微信上发了一段 windbg的输出信息,大概内容如下:

This dump file has an exception of interest stored in it.The stored exception information can be accessed via .ecxr.(fd0.9bc): Security check failure or stack buffer overrun - code c0000409 (first/second chance not available)For analysis of this file, run !analyze -v


【资料图】

... 省略 N 行

看样子像栈相关的问题。于是简单跟朋友说了下我的猜想,有可能是栈破坏了。没想到,远不是这么简单。

说明: 之所以一定要写这篇总结,是因为我在分析过程中犯了很多想当然的错误,记录下来,以后不要再犯。

另有隐情

过了一会,朋友发了一段更贴近真相的错误提示,并且发送了更详细的语音描述。

FAILURE_ID_HASH_STRING:um:fail_fast_fatal_app_exit_c0000409_server.exe!std::_xbad_alloc

这个提示跟最开始的提示风马牛不相及。一个是栈相关的问题,一个是内存分配的问题。

说明: 经常分析转储文件的小伙伴儿应该都知道,直接打开转储文件时,windbg给出的提示有可能是不准确的,如果想获取最准确的信息,最好通过 .cxr切换上下文,然后再执行 k系列命令查看。但是,很多时候直接执行 !analayze -v就能拿到正确信息。正式分析之前,不妨先试试 !analyze -v。

又跟朋友又聊了几个相关问题,得到了更多的关键信息。比如,

之前解决过类似的内存泄漏问题,当时抓的 dump有 3GB多。

这次抓取的 dump只有 905MB,但是确实是 full dump。

说明: 内存相关问题,最好抓一个 full dump,否则分析到一半,由于转储文件缺少关键信息,没法继续确认,就太尴尬了。

程序是 32位的,并且开启了大地址。

说明: 64位程序的虚拟地址空间比 32位程序大多了,不太容易在短时间内看出问题。

前几次出问题时都是运行了很久才出问题,这次只运行了 7个小时左右就出问题了。

几次出问题时,都是在内存比较紧张的时候。

聊了一会,问朋友是否方便发送完整的 !analyze -v结果。没想到,朋友除了发送 !analyze -v的分析结果外,还特别贴心的发送了 转储文件和对应的符号文件。必须为朋友点赞,看来没少分析转储文件。

查看分析结果

由于当时在北京出差的路上,于是在地铁里用手机查看了一下 !analyze -v的分析结果(旁边的小哥哥小姐姐会不会以为我在看小说?),跟朋友说的一样,打开转储文件后,windbg给出的错误提示确实是栈相关的,但是 !analyze -v却指向了内存分配相关的问题。

这里简单摘录几个关键的信息:

转储文件中的 comment

Comment:"***"D:\software\Procdump_installer\procdump.exe"-accepteula-ma-j"D:\software\Procdump_installer\dumps"404838400990000***Just-In-Timedebugger.PID:4048EventHandle:384JITContext:.jdinfo0x990000"

说明此 dump是注册为 JIT debugger的 procdump在程序异常的时候抓取的。

运行环境

Windows10Version14393MP(2procs)Freex86compatibleProduct:Server,suite:TerminalServerDataCenterSingleUserTS10.0.14393.2430(rs1_release_inmarket_aim.180806-1810)Debugsessiontime:WedAug1820:32:43.0002021(UTC+8:00)SystemUptime:40days1:00:55.704ProcessUptime:0days7:00:35.000

win10服务器系统,系统运行时间是 40 days 1:00:55.704,程序运行时间是 7:00:35.000。跟朋友的描述是一致的。

上下文相关信息

CONTEXT:0f77ef58--(.cxr0xf77ef58)eax=0f77f3b8ebx=0f77f468ecx=00000003edx=00000000esi=00eceba8edi=00ef7dd4eip=76b6c232esp=0f77f3b8ebp=0f77f414iopl=0nvupeiplnzacpenccs=0023ss=002bds=002bes=002bfs=0053gs=002befl=00000216KERNELBASE!RaiseException+0x62:76b6c2328b4c2454movecx,dwordptr[esp+54h]ss:002b:0f77f40c=93fc57d7ResettingdefaultscopeFAULTING_IP:Server!abort+28[d:\th\minkernel\crts\ucrt\src\appcrt\startup\abort.cpp@77]00ea0d4fcd29int29hEXCEPTION_RECORD:0f77ef08--(.exr0xf77ef08)ExceptionAddress:76b6c232(KERNELBASE!RaiseException+0x00000062)ExceptionCode:e06d7363(C++EHexception)ExceptionFlags:00000001NumberParameters:3Parameter[0]:19930520Parameter[1]:0f77f468Parameter[2]:00ef7dd4pExceptionObject:0f77f468_s_ThrowInfo:00ef7dd4Type:classstd::bad_allocType:classstd::exception

可以使用 .cxr 0xf77ef58切换上下文,使用 .exr 0xf77ef08查看异常信息。

调用栈

windbg-analyze-v-callstack

注意:上图中红色部分,表示正在处理 std::_Xbad_alloc异常。黄色部分是一个警告,意思是说下面的调用栈可能不准确。

看样子,极有可能是内存分配的问题了。当时想着一定要找个时间分析一下。过了两三天,终于有了一点儿时间(今年加班是真的多),折腾完调试环境(主要是加载调试符号,从微软服务器下载符号有时候需要梯子),就可以开始分析了。

初次分析

加载好符号后,根据 !analyze -v的结果,先执行 .cxr 0xf77ef58,切换上下文,然后执行 kp查看调用栈(p表示显示参数,应该是 parameter的缩写)。如下图:

append-string-call-stack

从整个调用栈来看,是在拼接两个字符串时,需要分配 0x8e52d字节的空间,但是失败了,抛出了 std::_Xbad_alloc异常。

说明: 看到 std::_Xbad_alloc时,脑子里自然而然地想到了两种可能:

分配的内存超级大(本例不属于这种情况)内存不够用了,没有一块内存可以满足本次的分配请求。

之前遇到的 std::_Xbad_alloc异常都是尝试分配的内存超级大(非常典型的是在反序列化 vector, string的时候,由于内存错位导致尝试分配超大内存),但是本次的分配请求看上去相对合理。

既然是跟内存分配相关的问题(而且是标准库中涉及到的内存分配),很可能跟堆有关,可以查看堆相关的信息。在 windbg中执行 !heap -s命令,查看堆概要信息。

heap-s

看到上图中的输出结果,我很(草)快(率)得(凑)出了一个结论。

草率了

我犯的第一个超级愚蠢的错误是:一看 Free这一列显示的值是 334147。而 0x8e52d的十进制值是 582957(可以在 windbg中通过 .formats 0x8e52d方便的显示出来),就跟朋友说是堆空间不足导致的,建议从内存泄漏这个角度排查一下。做出这个结论的依据是:Free一列给出的值比要分配的值"小"。

为什么草率了呢?

首先,我忽略了 Free的单位,在 Free的下方明显的写着 (k),说明这一列是按 KB计算的 。

其次,这一列给出的数不是 10进制的,如果仔细看其它相关信息,可以推断出这里的值是以 16进制表示的,比如 Lock cont.的值是 1b61,明显是 16进制。

既然是分配一个正常大小的内存块失败了,那肯定是堆里没有能满足请求大小的空闲堆块了。

如果能找出堆中空闲的堆块,而且每个堆块的大小都比本次分配请求的大小(0x8e52d)要小,说明没有一个空闲堆块能满足本次的分配请求,那么抛出 std::_Xbad_alloc就很正常了。

接着分析

可以通过 !heap -a打印出所有信息。在 windbg中输入 !heap -a 00a80000,因为输出结果太多了,在执行此命令前,先执行 .logopen d:\heap.txt,这样输出结果会同时保存到日志文件 d:\heap.txt中,执行完需要的命令后,可以通过执行 .logclose关闭日志文件。

接下来,从输出信息中查找空闲堆块。

我不会告诉你,最开始找空闲堆块的时候我是傻傻的到每一个 Segment里面找里面包含的 free堆块(flags是 100)。

下图是 Sement27中的部分 Free堆块截图:

view-free-heap-entry-in-segment

由于实在是太多了,找到一半的时候真的是找(累)不(成)动(狗)了!于是停下来开始思考:

windbg难道没有直接查找空闲堆块的命令吗?

有插件可以做这事吗?

自己写个脚本(程序)整理下输出结果?

想个办法过滤一下空闲块,然后再排序?

最后一个想法简单易行:把所有包含 [100]的行找出来,然后保存为 .csv文件。按 [100]前面的字段(当前堆块的大小)降序排列,就可以很快找出最大空闲堆块了。

整个过程参考下面视频:

最后发现最大空闲堆块的大小是 0x7f000,比 0x8e52d要小。

意外发现

在查找过程中偶然发现了一个有意思的现象,同一个地址会出现两次,比如 03c8da98这个地址:

same-address-showup-twice

仔细一看,所有的空闲堆块会被单独整理出来,放到 FreeList下。赶紧通过 .hh !heap查看帮助手册,关键部分截图如下:

原来可以通过 !heap -f heap_address直接显示所有的空闲堆块。于是在 windbg中输入 !heap -f 00a80000验证一下,果然可以列出所有空闲堆块。

view-all-free-heap-entry

而且,空闲块是按大小排序的,找到最后一个空闲块,就找到了最大的空闲块(大小是 0x7f000),比上面的方法简单太多了。

又草率了

查找完所有空闲堆块后发现,没有一个空闲堆块的大小比 0x8e52d还要大。于是,赶紧跟朋友说上次分析的结果应该没错,但是判断依据不对。告诉朋友可以在 windbg中执行!heap -a a80000,然后查找 FreeList对应的记录,就可以确定没有一块空闲堆块满足本次的分配请求了。

跟朋友说完之后长出了一口气,心想这次肯定稳了,应该没问题了。

不对劲儿

过了一两天,忙完手头工作后,又想起这件事,隐约感到有些不对劲。赶紧翻开《软件调试》第一版查找关于堆的介绍,在第 23章 23.4.1节 655页中有非常清晰的描述,摘录如下:

HEAP_ENTRY 结构的前两个字节是以分配粒度表示的堆块大小。分配粒度通常为 8,这意味着每个堆块的最大值是 2的 16次方乘以 8,即 0x10000 * 8 = 0x80000 = 524288 字节 = 512 KB,因为每个堆块至少要有 8字节的管理信息,因此应用程序可以使用的最大堆块便是 0x80000-8=0x7FFF8,这也正是 SDK 文档中所给出的数值(位于 HeapCreate 函数 dwMaximumSize参数的说明中)。不过这并不意味着不可以从 Win32 堆上分配到更大的内存块。当一个应用程序要分配大于 512KB 的堆块时,如果堆标志包含 HEAP_GROWABLE(2),那么堆管理器便会直接调用 ZwAllocateVirtualMemory来满足这次分配,并把分得的地址记录在 HEAP 结构的 VirtualAllocatedBlocks所指向的链表中。

有了理论依据,实际用 windbg查看一下。该看哪些内容呢?

堆是否是可增长的?

ntdll!_HEAP中的 Flags字段如果为 2则表示堆是可以自动增长的。

阈值是多少?本次请求是否超出了阈值?

阈值是由 VirtualMemoryThreshold中的值乘以分配粒度计算得到的。

说明: 分配粒度与 _HEAP_ENTRY的大小一致,32位程序是 8字节, 64位程序是 16字节。可以在 !heap -f 00a80000的输出结果中看到,Granularity是 8 bytes。

在 windbg中输入如下命令 dt _HEAP -y Flags VirtualMemoryThreshold a80000即可查看这两个关键的信息,如下图:

view-flags-and-virtualmemorythreshold

可以确认堆是可增长的,而且阈值是 0xfe00 * 8 = 0x7f000。本次请求大小( 0x8e52d)超出了阈值,会直接通过 ZwAllocVirtualMemory进行分配。

说明: 空闲列表中的最大空闲块的尺寸也是 0x7f000。前面做了这么多无用功,真是浪费时间。

既然请求大小超出了阈值,接下来的任务是找到整个内存空间中最大空闲区域,看看其是否能满足本次分配请求(应该是不满足,要不然也不会抛出异常了)。

查找空闲区域

相信,很多小伙伴儿都知道使用 !address查看地址信息。我经常在排查内存访问异常的时候,通过该命令查看某个地址的详细信息。比如,下图是通过 !address 0x12345678查看到的关于地址 0x12345678的相关信息:

address-0x12345678

另外一个非常有用的命令是 !address -summary, 可以查看地址空间概要信息。

address-summary

通过查看 Usage Summary的数据可以发现,在整个内存空间中,堆空间大小是 3.930GB,占比 98.25%。通过查看 State Summary的数据可知,保留( MEM_RESERVE)大小是 3.105GB,提交(MEM_COMMIT)大小是 910.848MB。通过查看 Largest Region by Usage可以发现,最大的空闲内存大小是 0x1c000,要比本次申请的大小 0x8e52d小很多。

内存严重碎片化

说实话,刚开始我是有点不敢相信 !address -summary给出的结果:最大的空闲空间居然只有区区的 112KB!

继续使用 !address -f:Free -o:csv命令打印出所有的空闲内存。整理后的结果如下图所示:

-o:csv表示以逗号分隔的 csv格式输出,这样可以把结果直接粘贴到 csv文件中。

view-largest-free-region-in-process

可以看出,跟 !address -summary给出的结论是一致的。最大空闲区域的大小是 0n114688(十六进制对应的数值是 0x1c000)。空闲内存的总大小是 0n5791744,只有区区的 5656KB(也就是 5.23MB)。碎片化真的是太严重了。

再回过头仔细看 !heap -s的输出结果。其中有如下提示:

Virtual address fragmentation 77 % (1713 uncommited ranges)

意思是说虚拟地址空间的碎片率已经高达 77%。看来这次的崩溃确实是由内存碎片导致的。

总结

之前只是理论上知道如果碎片太严重可能导致分配失败,没想到这次真遇到了。刚开始给出的结论虽然正确,但是理由太牵强,站不住脚。

使用 windbg分析转储文件,先执行 !analyze -v,很多情况下问题就解决了。发生异常的时候会保存线程上下文和异常相关信息。异常信息可以通过 .exr address查看,线程上下文可以通过 .cxr address查看并切换。在 windbg中可以通过 .hh command查看对应命令的帮助。windbg中的 !heap扩展命令是查看堆信息的好帮手,!heap -s可以给出堆的概要信息。!heap -f heap_address可以显示所有空闲堆块,!heap -a heap_address可以显示所有堆块。!address命令相当强大。!address address可以查看指定内存地址的信息,!address -summary可以给出一个概要信息,!address -f:Type可以给出特定的内存区域,甚至后面还可以跟命令。堆中分配内存时,如果堆大小可以增长并且申请的大小超出阈值(VirtualMemoryThreshold * Granularity),会直接使用 ZwAllocVirtualMemory进行分配。参考资料

《软件调试》第一版

windbg帮助文档

未完待续

后面又跟朋友折腾了一些其它问题,颇有收获,希望能有时间做个总结。

为什么 32位程序可以使用的内存空间是 4GB?高 2GB应该是系统使用的才对?用户态代码也可以使用?

如果一条命令输出结果太多,直接显示的话太慢,怎么办?

转储文件中包含了一些珍贵的数据(比如某些充值记录),如何找出来?

...

推荐内容