首页
社区
课程
招聘
记一次有教益的内存碎片转储文件分析经历
发表于: 2022-7-24 23:18 17482

记一次有教益的内存碎片转储文件分析经历

2022-7-24 23:18
17482

其实,这篇文章早在 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

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

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

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

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

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

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

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

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

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

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

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

1 转储文件中的 comment

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

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 堆块(flags100)。

下图是 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 对应的记录,就可以确定没有一块空闲堆块满足本次的分配请求了。

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

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

HEAP_ENTRY 结构的前两个字节是以分配粒度表示的堆块大小。分配粒度通常为 8,这意味着每个堆块的最大值是 216 次方乘以 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 的输出结果中看到,Granularity8 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 被编程难编辑 ,原因:
收藏
免费 7
支持
分享
最新回复 (6)
雪    币: 6
活跃值: (3290)
能力值: ( LV2,RANK:10 )
在线值:
发帖
回帖
粉丝
2
这程序开发没测试吧? 跑几个小时用任务管理器看下是基本操作吧,一眼就能看到内存有异常。

32位程序开PAE也可以用几十G的内存吧,但是只能使用0-3G的地址空间。
2022-7-25 00:28
0
雪    币: 576
活跃值: (2035)
能力值: ( LV2,RANK:10 )
在线值:
发帖
回帖
粉丝
3
mark
2022-7-25 11:05
0
雪    币: 10023
活跃值: (4416)
能力值: ( LV2,RANK:10 )
在线值:
发帖
回帖
粉丝
4
感谢分享
2022-7-25 11:07
0
雪    币: 8519
活跃值: (9122)
能力值: ( LV12,RANK:360 )
在线值:
发帖
回帖
粉丝
5
chengdrgon 感谢分享
感谢阅读
2022-7-25 18:42
0
雪    币: 8519
活跃值: (9122)
能力值: ( LV12,RANK:360 )
在线值:
发帖
回帖
粉丝
6
咖啡_741298 这程序开发没测试吧? 跑几个小时用任务管理器看下是基本操作吧,一眼就能看到内存有异常。 32位程序开PAE也可以用几十G的内存吧,但是只能使用0-3G的地址空间。
具体情况不清楚,反正遇到问题了 就查查呗,祝大佬代码永不宕机

32位程序开PAE也可以用几十G的内存吧,但是只能使用0-3G的地址空间。
这说法还是头一次听到,麻烦大佬讲详细点?
2022-7-25 18:43
0
雪    币: 436
活跃值: (2668)
能力值: ( LV2,RANK:10 )
在线值:
发帖
回帖
粉丝
7
感谢分享。
2022-7-28 20:26
0
游客
登录 | 注册 方可回帖
返回
//