其实,这篇文章早在 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 行
看样子像栈相关的问题。于是简单跟朋友说了下我的猜想,有可能是栈破坏了。没想到,远不是这么简单。
说明: 之所以一定要写这篇总结,是因为我在分析过程中犯了很多想当然的错误,记录下来,以后不要再犯。
过了一会,朋友发了一段更贴近真相的错误提示,并且发送了更详细的语音描述。
这个提示跟最开始的提示风马牛不相及。一个是栈相关的问题,一个是内存分配的问题。
说明: 经常分析转储文件的小伙伴儿应该都知道,直接打开转储文件时,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
却指向了内存分配相关的问题。
这里简单摘录几个关键的信息:
1 转储文件中的 comment
说明此 dump
是注册为 JIT debugger
的 procdump
在程序异常的时候抓取的。
2 运行环境
win10
服务器系统,系统运行时间是 40 days 1:00:55.704
,程序运行时间是 7:00:35.000
。跟朋友的描述是一致的。
3 上下文相关信息
可以使用 .cxr 0xf77ef58
切换上下文,使用 .exr 0xf77ef08
查看异常信息。
4 调用栈
注意: 上图中红色部分,表示正在处理 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
堆块截图:
由于实在是太多了,找到一半的时候真的是找(累)不(成)动(狗)了!于是停下来开始思考:
有插件可以做这事吗?
自己写个脚本(程序)整理下输出结果?
想个办法过滤一下空闲块,然后再排序?
最后一个想法简单易行:把所有包含 [100]
的行找出来,然后保存为 .csv
文件。按 [100]
前面的字段(当前堆块的大小)降序排列,就可以很快找出最大空闲堆块了。
整个过程参考下面视频:
说明: 看雪好像不能传视频,到我服务器上下载查看吧。视频里也没什么,就是查找过程。 http://resources.bianchengnan.tech/analyze-a-crash-dump-and-find-the-root-cause-memory-fragmentation/filter-free-entry-and-find-the-largest.mp4
最后发现最大空闲堆块的大小是 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
帮助文档
后面又跟朋友折腾了一些其它问题,颇有收获,希望能有时间做个总结。
为什么 32
位程序可以使用的内存空间是 4GB
?高 2GB
应该是系统使用的才对?用户态代码也可以使用?
如果一条命令输出结果太多,直接显示的话太慢,怎么办?
FAILURE_ID_HASH_STRING: um:fail_fast_fatal_app_exit_c0000409_server.exe!std::_xbad_alloc
FAILURE_ID_HASH_STRING: um:fail_fast_fatal_app_exit_c0000409_server.exe!std::_xbad_alloc
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
'
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
'
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
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
[培训]内核驱动高级班,冲击BAT一流互联网大厂工作,每周日13:00-18:00直播授课
最后于 2022-7-24 23:27
被编程难编辑
,原因: