探索黑客技术攻防,实战研究与安全创新

导航菜单

Sysmon高CPU和内存占用问题的深度剖析与解决

一、背景 在近期的项目中,我们引入了sysinternals开发的监控工具sysmon.exe。然而,用户反馈在特定条件下,sysmon.exe进程(以下简称sysmon)会出现异常资源占用情况。具体表现为,sysmon会持续占用CPU,通常会跑满一个逻辑核。例如,在双核4线程的CPU环境中,sysmon的占用率可达25%。同时,其内存占用也呈持续上升趋势。 本文所展示的图片均在调试环境中随文章编写截取,因此各位看到图中sysmon进程的PID可能不一致。

202501101736515855705208.png

二、问题定位与分析 问题初步定位

202501101736515894545232.png

借助ProcessExplorer工具,我们深入观察sysmon进程各线程的CPU使用情况。结果发现,单个线程的CPU占用率并不高,但却出现大量新线程不断创建,同时大量旧线程被销毁的现象。这表明,CPU时间片主要被消耗在线程的创建与销毁操作上。 与此同时,我们对sysmon的句柄使用情况进行观察,惊讶地发现句柄数量在极短时间内竟达到万级规模,呈现出异常增高的态势。202501101736515894545232.png

基于以上发现,后续的分析重点将围绕线程的频繁创建与销毁以及句柄的异常创建展开。 调试器中定位问题 I. 定位线程大量创建销毁的问题 从图2中我们注意到,所有创建的线程均以sysmon.exe + 0x494a8这个地址作为起始点。沿着这一线索深入挖掘,我们发现sysmon + 0x495aa这个堆栈返回地址,恰好位于sysmon.exe + 0x494a8函数的范围内。通过对sysmon + 0x495aa栈回溯线索的逐步追踪,最终确定sysmon + 0x1820e为问题函数。以下是sysmon各个子线程的栈回溯图:202501101736515894545232.png

在这一步分析完成后,我们先暂时搁置,稍后再对分析结果进行验证。接下来,我们将关注点转向内存占用过高的问题。 II. 定位内存占用过高问题 从图3可知,sysmon在短时间内创建了大量句柄。在调试器中进一步查看这些句柄的使用情况,我们得到以下信息:202501101736516011175182.png

由上图可见,短短几分钟内,句柄数量从图3的4.5万多个急剧增加到72942个。其中,Event类型的句柄多达72878个,占比高达99%。并且这些Event都需要人工重置状态,这意味着在程序未对这些Event状态进行人工重置前,它们不会被释放。如此大量的Event在短时间内被创建且未释放,随着时间推移,内存占用自然会不断攀升。 在调试器中确认问题 I. 内存占用过高问题的确认 经过上一节的分析,我们初步确定了CPU和内存占用过高的原因。接下来,我们需要进一步验证这一结论。由于刚刚分析完内存占用过高问题,我们就从这里入手。 熟悉Windows编程的人都知道,创建Event通常会调用CreateEvent函数。因此,我们在该函数上设置断点,具体设置如下:202501101736516073412594.png这个断点的含义是:首先在kernel32.dll中的CreateEventW函数调用起始位置中断,然后打印堆栈调用信息,最后恢复程序执行。 以下是部分执行结果:

202501101736516157857366.png

上图展示的是程序执行约5秒钟后的情况。从右侧下拉条可以看出,输出内容约有几千条,这意味着在5秒钟内创建了几千个Event,与我们之前观察到的句柄暴增现象相符。仔细查看每次栈回溯输出,我们发现都是由sysmon + 0x181b7附近触发了CreateEventW的调用。这里先留个悬念:注意OpenTraceW函数。 同时,我们还需留意图6中最后一个sysmon模块的函数调用返回地址:sysmon + 0x181b7。结合图4中我们定位到的导致新线程不断创建的地址sysmon + 0x1820e,二者距离非常近。至于它们之间的因果关系,我们将在下文详细分析。 II. 线程大量创建销毁的问题的确认 刚才提到sysmon + 0x181b7与sysmon + 0x1820e两个地址相近,通过下图,大家可以更直观地感受它们之间的距离:202501101736516201458704.png

基于目前所掌握的信息,整个问题的逻辑可能是这样的: 1. 系统中出现大量线程创建的情况。 2. 新创建的线程又大量创建了Event。 3. 创建的线程虽然退出,但由于Event需要手动重置,所以并未被释放。 天下没有免费的午餐,如此大量的Event必然需要占用内存空间。因此,大量线程创建导致CPU使用率升高,大量未释放的Event则导致内存使用率上升。 看到这里,可能有人会质疑,上述内容只是猜测,有什么证据支持吗?接下来,我们将在调试器中验证这一猜测。在正式开始验证之前,先阐述一下验证思路:根据前面的分析结论,新创建的线程会导致新创建Event。所以,如果我们在sysmon + 0x1820e处设置一个断点,在系统的CreateEventW函数上再设置一个断点,那么这两个断点应该会交替命中。由于这两个断点,一个位于sysmon模块的线程函数处,另一个位于系统的kernel32.dll模块地址,它们理论上并无必然联系。如果实际现象是两个断点交替命中,那么就可以验证我们之前的猜测。 以下是实际操作过程,首先展示两个断点的设置情况:

202501101736516261413862.png

解释一下,每行最开始的数值是断点编号,0代表0号断点,1代表1号断点;e表示两个断点均处于激活(enable)状态;后面的kernel32!CreateEventW和sysmon + 0x1820e分别代表断点的地址(具体分析见上文);最后双引号里以.echo开头的部分表示,一旦命中该地址的断点,就打印当前断点的编号与堆栈调用关系,然后恢复执行。以下是断点命中的情况:

202501101736516313639368.png

可以看到,实际现象与我们设想的一致,这进一步印证了我们猜测的正确性。或许仍有较真的读者认为,目前这些都只是间接证据。那么,接下来我们将直面问题,用代码来揭示真相。

出现此问题的根本证据 上文中提到的两个地址(sysmon + 181b7与sysmon + 1820e)均位于函数sysmon + 0x180E0中。下面直接给出该函数的伪代码:202501101736516373409634.png

这里说明一下关键逻辑,请注意图10中的第44行处的函数调用sub_140018360,以及本函数的地址sub_1400180e0。这段代码的含义是,在某个全局信号的作用下,有可能会调用sub_140018360这个函数,并向其传递参数1。 接下来,我们看看sub_140018360函数的具体功能,为了便于说明问题,对伪代码做了部分折叠处理:202501101736516434561871.png

请注意第69行的线程创建函数,也就是说,当sub_140018360函数的参数为1且不出现错误时,会执行到第69行的线程创建操作,而线程的入口函数正是sub_1400180e0。是不是感觉很眼熟?如果不熟悉,请回看上图10。这意味着sub_1400180e0最终会调用sub_140018360函数,而sub_140018360函数内部又创建了一个线程,该线程再次调用回sub_1400180e0函数。从图6的分析可知,正是由于sub_1400180e0里面的OpenTraceW函数导致创建了大量的Event,从而使得内存急剧上升。这是一个类似递归调用的逻辑,如果一直持续下去,将永无止境。 至此,我们已经清晰地明确了问题所在。为了获取某种Trace的结果(上文提到的OpenTraceW函数),sysmon采用了类似递归的逻辑,不断重试以尝试获取结果。正是由于: 1. 递归调用创建线程,导致CPU使用率急剧飙升。 2. 上述创建的线程通过OpenTraceW创建了大量Event,导致内存占用飙升。 至此,sysmon占用高CPU和高内存的直接原因已被成功找到。 三、什么原因导致的此问题的产生 在调试过程中,我们发现了以下几个关键现象: 1. sysmon会经历一次重启,且仅在重启后才会出现高CPU和内存占用的情况。 2. 在sysmon重启前,TsService.exe会启动几个进程,但这些进程很快就结束了。 此时,可能大家心中会有疑问,TsService.exe究竟是什么呢?答案是,它是QQ浏览器的后台服务进程。以下是相关证据(该可执行文件具有正常的腾讯签名):202501101736516491558007.png

随后,我们进一步跟进了TsService.exe启动的几个进程具体是什么: 顺便提一下,图13中第一行未截全的部分是:set - default - browser --slient ; -)。接下来才是我们重点关注的内容,即几个xperf子进程的命令。 在此,插入一个题外话。在解决这个问题查阅资料的过程中,我们发现了一篇名为《QQ浏览器性能提升之路 - windows性能分析工具篇》的文章。这篇文章详细解释了图13中xperf命令的含义:

202501101736516583859994.png

同时,文章还提到了一些在使用过程中遇到的坑:

202501121736668845492602.png

文章指出,ProcessMonitor和ProcessExplorer会导致xperf失败,需要先关闭它们再启动xperf。经过我们的测试,sysmon同样会导致xper.exe抛出与上图相同的错误。 再补充一个知识点,xperf是微软官方提供的性能信息收集工具,借助它可以深入分析Windows系统上程序的多种性能问题。 回顾本节开头提到的两个现象,sysmon重启后出现高占用现象,难道这与腾讯浏览器启动的xperf存在关联? 四、此问题在任意机器上的复现 为了验证上述猜测,我们进行了如下实验。 首先直接公布结论,通过xperf和sysmon的“协同配合”,可以在任何机器上复现sysmon高CPU和内存占用的问题。 具体操作步骤如下: 1. 首先,准备一个全新安装的纯净系统(此步骤可选)。 2. 在系统上安装sysmon服务,具体操作是在管理员权限的cmd下执行:sysmon -i。 3. 停止sysmon服务(因为不停止会导致xperf命令报错)。 4. 使用xperf.exe依次执行如下命令:

image.png

5. 重新启动sysmon服务。 完成上述步骤后,新启动的sysmon服务的CPU使用率会占满一个逻辑核,内存使用率也会逐渐上升。 如果在sysmon的CPU使用率升高后,再次执行:image.png

则sysmon的使用率将降回到正常水平。 五、谁关闭了sysmon? 通过前面的分析我们知道,此问题的根本原因在于sysmon重启后,其所需的资源(NT Kernel Logger)被占用,导致重启后的sysmon服务无法获取所需资源,从而不断重试。那么,究竟是什么原因导致sysmon退出呢? 结合上文分析,我们将排查重点放在了TsService.exe服务上。通过对TsService.exe进程的OpenServiceW函数设置断点,最终将问题锁定在PerfTool.dll这个模块上:202501121736668880997977.png

六、此问题的解决方案(部分) I. 方案一 请注意,这里只是基于上文分析提出的几种解决方案,并非最终的唯一解决办法。 从图10中的第43和44行可知,在调用导致“递归”的函数之前,存在一个if判断。该判断使用sub_14008da0(我们已将其重命名为fnReadRegistryValue)的返回值与1进行逻辑与操作,只有当该操作为真时,才会触发“递归”逻辑。接下来,我们看看fnReadRegistryValue这个函数的具体功能:202501121736668913552437.png

可以看到,该函数的返回值为Data,而Data中的数据来源于注册表的如下键值:image.png

如果此键值的值与1做与运算结果为0,即可终止“递归”逻辑。也就是说,如果这个键值下的数值为偶数,那么就永远不会因为这两个函数的“递归”调用而产生高CPU和内存占用的问题。 那么这个键值有什么作用呢?从sysmon的帮助文档可知,sysmon是一个命令行工具,具备启动参数。结合Options的含义,我们知道不同的sysmon监控启动参数会导致这个值发生变化。后续实验也证实了这一点,该键值的确会根据sysmon的启动参数不同而改变。 因此,一个可行的解决方案是,当发现CPU占用过高且内存缓慢上升时,可以暂时将该键值设置为0,使程序跳出“递归”逻辑,之后再将该值恢复为原来的值,以避免影响其正常监控功能。 II. 方案二 从图16可知,TsService.exe关闭sysmon采用的是硬编码方式。而sysmon在安装服务时,支持使用其他服务名。所以,另一个可行的解决方案是在安装sysmon服务时,选用其他服务名,从而防止被TsService.exe关闭。

七、总结 正如本文所剖析的性能问题一样,原本旨在进行性能排查的操作,却最终引发了性能问题,进而需要进一步对该性能问题展开排查。而此问题的产生并非单一因素所致,而是多种因素共同作用的结果。由于性能测试具有一定的特殊性,并非所有机器都需要执行此项测试。因此,初始化过程中的关闭sysmon、启动xperf进行性能信息收集这一操作,并不会在每台机器上执行。所以,这个问题的出现具有一定的“随机性”,并非在每台机器上都会出现。通过对这一复杂问题的深入分析与解决,我们不仅成功找到了sysmon高CPU和内存占用问题的根源,还提出了相应的解决方案,为今后处理类似问题积累了宝贵经验。