记一次有教益的内存碎片转储文件分析经历
记一次有教益的内存碎片转储文件分析经历
前言
其实,这篇文章早在 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" 4048 384 00990000
*** Just-In-Time debugger. PID: 4048 Event Handle: 384 JIT Context: .jdinfo 0x990000'
说明此 dump
是注册为 JIT debugger
的 procdump
在程序异常的时候抓取的。
- 运行环境
Windows 10 Version 14393 MP (2 procs) Free x86 compatible
Product: Server, suite: TerminalServer DataCenter SingleUserTS
10.0.14393.2430 (rs1_release_inmarket_aim.180806-1810)
Debug session time: Wed Aug 18 20:32:43.000 2021 (UTC + 8:00)
System Uptime: 40 days 1:00:55.704
Process Uptime: 0 days 7:00:35.000
win10
服务器系统,系统运行时间是 40 days 1:00:55.704
,程序运行时间是 7:00:35.000
。跟朋友的描述是一致的。
- 上下文相关信息
CONTEXT: 0f77ef58 -- (.cxr 0xf77ef58)
eax=0f77f3b8 ebx=0f77f468 ecx=00000003 edx=00000000 esi=00eceba8 edi=00ef7dd4
eip=76b6c232 esp=0f77f3b8 ebp=0f77f414 iopl=0 nv up ei pl nz ac pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000216
KERNELBASE!RaiseException+0x62:
76b6c232 8b4c2454 mov ecx,dword ptr [esp+54h] ss:002b:0f77f40c=93fc57d7
Resetting default scope
FAULTING_IP:
Server!abort+28 [d:\th\minkernel\crts\ucrt\src\appcrt\startup\abort.cpp @ 77]
00ea0d4f cd29 int 29h
EXCEPTION_RECORD: 0f77ef08 -- (.exr 0xf77ef08)
ExceptionAddress: 76b6c232 (KERNELBASE!RaiseException+0x00000062)
ExceptionCode: e06d7363 (C++ EH exception)
ExceptionFlags: 00000001
NumberParameters: 3
Parameter[0]: 19930520
Parameter[1]: 0f77f468
Parameter[2]: 00ef7dd4
pExceptionObject: 0f77f468
_s_ThrowInfo : 00ef7dd4
Type : class std::bad_alloc
Type : class std::exception
可以使用 .cxr 0xf77ef58
切换上下文,使用 .exr 0xf77ef08
查看异常信息。
-
调用栈
**注意:**上图中红色部分,表示正在处理
std::_Xbad_alloc
异常。黄色部分是一个警告,意思是说下面的调用栈可能不准确。
看样子,极有可能是内存分配的问题了。当时想着一定要找个时间分析一下。过了两三天,终于有了一点儿时间(今年加班是真的多),折腾完调试环境(主要是加载调试符号,从微软服务器下载符号有时候需要梯子),就可以开始分析了。
初次分析
加载好符号后,根据 !analyze -v
的结果,先执行 .cxr 0xf77ef58
,切换上下文,然后执行 kp
查看调用栈(p
表示显示参数,应该是 parameter
的缩写)。如下图:
从整个调用栈来看,是在拼接两个字符串时,需要分配 0x8e52d
字节的空间,但是失败了,抛出了 std::_Xbad_alloc
异常。
说明: 看到
std::_Xbad_alloc
时,脑子里自然而然地想到了两种可能:
- 分配的内存超级大(本例不属于这种情况)
- 内存不够用了,没有一块内存可以满足本次的分配请求。
之前遇到的 std::_Xbad_alloc
异常都是尝试分配的内存超级大(非常典型的是在反序列化 vector
, string
的时候,由于内存错位导致尝试分配超大内存),但是本次的分配请求看上去相对合理。
既然是跟内存分配相关的问题(而且是标准库中涉及到的内存分配),很可能跟堆有关,可以查看堆相关的信息。在 windbg
中执行 !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
堆块截图:
由于实在是太多了,找到一半的时候真的是找(累)不(成)动(狗)了!于是停下来开始思考:
-
windbg
难道没有直接查找空闲堆块的命令吗? -
有插件可以做这事吗?
-
自己写个脚本(程序)整理下输出结果?
-
想个办法过滤一下空闲块,然后再排序?
最后一个想法简单易行:把所有包含 [100]
的行找出来,然后保存为 .csv
文件。按 [100]
前面的字段(当前堆块的大小)降序排列,就可以很快找出最大空闲堆块了。
整个过程参考下面视频:
最后发现最大空闲堆块的大小是 0x7f000
,比 0x8e52d
要小。
意外发现
在查找过程中偶然发现了一个有意思的现象,同一个地址会出现两次,比如 03c8da98
这个地址:
仔细一看,所有的空闲堆块会被单独整理出来,放到 FreeList
下。赶紧通过 .hh !heap
查看帮助手册,关键部分截图如下:
!heap -f heap_address
直接显示所有的空闲堆块。于是在 windbg
中输入 !heap -f 00a80000
验证一下,果然可以列出所有空闲堆块。
而且,空闲块是按大小排序的,找到最后一个空闲块,就找到了最大的空闲块(大小是 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
即可查看这两个关键的信息,如下图:
可以确认堆是可增长的,而且阈值是 0xfe00 * 8 = 0x7f000
。本次请求大小( 0x8e52d
)超出了阈值,会直接通过 ZwAllocVirtualMemory
进行分配。
说明: 空闲列表中的最大空闲块的尺寸也是
0x7f000
。前面做了这么多无用功,真是浪费时间。
既然请求大小超出了阈值,接下来的任务是找到整个内存空间中最大空闲区域,看看其是否能满足本次分配请求(应该是不满足,要不然也不会抛出异常了)。
查找空闲区域
相信,很多小伙伴儿都知道使用 !address
查看地址信息。我经常在排查内存访问异常的时候,通过该命令查看某个地址的详细信息。比如,下图是通过 !address 0x12345678
查看到的关于地址 0x12345678
的相关信息:
另外一个非常有用的命令是 !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
文件中。
可以看出,跟 !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
应该是系统使用的才对?用户态代码也可以使用? -
如果一条命令输出结果太多,直接显示的话太慢,怎么办?
-
转储文件中包含了一些珍贵的数据(比如某些充值记录),如何找出来?
-
...