首页
论坛
课程
招聘
记一次有教益的内存碎片转储文件分析经历
2022-7-24 23:18 5045

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

2022-7-24 23:18
5045

前言

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

 

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

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

另有隐情

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

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

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

说明: 经常分析转储文件的小伙伴儿应该都知道,直接打开转储文件时,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

1
2
3
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 debuggerprocdump 在程序异常的时候抓取的。

 

2 运行环境

1
2
3
4
5
6
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。跟朋友的描述是一致的。

 

3 上下文相关信息

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
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 查看异常信息。

 

4 调用栈

 

 

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

 

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

初次分析

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

 

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

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

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

之前遇到的 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 堆块截图:

 

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

  • windbg 难道没有直接查找空闲堆块的命令吗?
  • 有插件可以做这事吗?

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

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

最后一个想法简单易行:把所有包含 [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 查看一下。该看哪些内容呢?

  1. 堆是否是可增长的?

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

  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 分析转储文件,先执行 !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 应该是系统使用的才对?用户态代码也可以使用?

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

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

[2022夏季班]《安卓高级研修班(网课)》月薪两万班招生中~

最后于 2022-7-24 23:27 被编程难编辑 ,原因:
收藏
点赞5
打赏
分享
最新回复 (6)
雪    币: 3
活跃值: 活跃值 (1454)
能力值: ( LV2,RANK:10 )
在线值:
发帖
回帖
粉丝
咖啡_741298 活跃值 2022-7-25 00:28
2
0
这程序开发没测试吧? 跑几个小时用任务管理器看下是基本操作吧,一眼就能看到内存有异常。

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

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