记一次ASP.NET CORE线上内存溢出问题与dotnet-dump的排查方法

年年有餘 發表於 2025-5-16 12:00:00

记一次ASP.NET CORE线上内存溢出问题与dotnet-dump的排查方法

<div style="text-align: center; background-color: rgba(136, 136, 136, 1)">前言</div>
这周系统更新了一个版本,部署到线上.
客户反馈整个系统全部都卡顿,随即我们上服务器检查
发现整个服务器内存竟然达到了20-30G的占用..如图:
<img src="https://img2024.cnblogs.com/blog/653851/202505/653851-20250516081003138-1889588337.png" alt="" loading="lazy">
其中有一个订单服务,独自占用13-18G内存,
当它重启以后,内存会降低下来一段时间,但过不了多久就又会增长上去
高度怀疑出现了内存溢出的情况,由于是线上服务器而且是离线内网.
项目又都运行在docker容器中,容器为了最小化,采用了极简的系统,几乎任何常见命令都没有.
所以考虑采用挂载额外辅助容器的形式进行调试.
<div style="text-align: center; background-color: rgba(136, 136, 136, 1)">正文</div>
 
<h2>1.创建调试用的辅助容器</h2>
这个简单,我们直接创建DockerFile如下:
<div class="cnblogs_code">
<pre># 使用 .NET 5 SDK 作为基础镜像
FROM mcr.microsoft.com/dotnet/sdk:5.0

# 安装 dotnet-dump 、 dotnet-stack 、dotnet-counters、dotnet-trace的旧版本（兼容 .NET 5）
RUN dotnet tool install -g dotnet-dump --version 5.0.220101 \
&& dotnet tool install -g dotnet-stack --version 1.0.130701 \
&& dotnet tool install -g dotnet-counters --version 5.0.251802 \
&& dotnet tool install -g dotnet-trace --version 5.0.251802 \
&& apt-get update \
&& apt-get install -y unzip procps \
&& echo 'export PATH="$PATH:/root/.dotnet/tools"' >> /root/.bashrc

#设定全局工具环境变量
ENV PATH="${PATH}:/root/.dotnet/tools"

# 默认启动 bash 以方便交互
CMD ["/bin/bash"]</pre>
</div>
这里我们使用当前系统RunTime对应版本的SDK作为基础镜像.
然后安装我们调试程序信息需要的工具:dotnet-dump 、 dotnet-stack 、dotnet-counters、dotnet-trace
先介绍一下这些工具.
dotnet-dump:可以收集和分析 Windows、Linux 和 macOS dump的信息,可以运行 SOS 命令来分析崩溃和垃圾回收器 (GC)。
dotnet-stack:可以收集 .NET 进程中的所有线程捕获和打印托管堆栈。
dotnet-counters:是一个性能监视工具，可以临时监视.NET程序的运行状况和做一些初级的性能调查
dotnet-trace:在不使用本机探查器的情况下对正在运行的.NET Core 进程进行跟踪
<h2>2.将辅助调试容器附加到应用容器运行</h2>
首先我们需要重新run一个应用容器,并给它特权模式和系统级的调试权限,大概命令如下:
<div class="cnblogs_code">
<pre>docker run -d --name myapp --privileged=true --cap-add=SYS_PTRACE -e ASPNETCORE_ENVIRONMENT=dev -e COMPlus_EnableDiagnostics=1 --volume /home/tmp:/tmp order-test:5.0</pre>
</div>
重点是privileged参数和cap-add参数,还有应用系统的tmp文件夹需要映射到宿主机
然后我们运行我们的调试容器并附加到应用容器
<div class="cnblogs_code">
<pre>docker run -it --rm--cap-add=SYS_PTRACE --pid=container:myapp --privileged=true --volume /home/tmp:/tmp dotnet-debug-tools:5.0</pre>
</div>
同样,它也需要privileged参数和cap-add参数,tmp临时文件也需要映射在宿主机和应用容器同样的目录下
注意--pid=container:myapp 中的myapp 是上面应用容器的名称.
然后,我们在调试容器直接运行命令:
<div class="cnblogs_code">
<pre>ps aux</pre>
</div>
应该就能看到应用服务中的dotnet的进程了.因为在容器中运行,所以一般dotnet的PID是1,如图:
<img src="https://img2024.cnblogs.com/blog/653851/202505/653851-20250516101049122-858461876.png" alt="" loading="lazy">
 
<h2>3.分析应用容器内dotnet进程的情况.</h2>
我们可以先使用dotnet-counters进行监控.
命令如下,其中-p是dotnet的进程编号:
<div class="cnblogs_code">
<pre>dotnet-counters monitor -p 1</pre>
</div>
能得到如下结果:
<div class="cnblogs_code">
<pre>% Time in GC since last GC (%) 0
Allocation Rate (B / 2 sec) 98,016
CPU Usage (%) 0
Exception Count (Count / 2 sec) 0
GC Fragmentation (%) 8.189
GC Heap Size (MB) 11,419
Gen 0 GC Count (Count / 2 sec) 0
Gen 0 Size (B) 192
Gen 1 GC Count (Count / 2 sec) 0
Gen 1 Size (B) 36,742,336
Gen 2 GC Count (Count / 2 sec) 0
Gen 2 Size (B) 8.8066e+09
IL Bytes Jitted (B) 7,248,623
LOH Size (B) 3.3414e+09
Monitor Lock Contention Count (Count / 2 sec) 0
Number of Active Timers 209
Number of Assemblies Loaded 426
Number of Methods Jitted 135,063
POH (Pinned Object Heap) Size (B) 1,299,832
ThreadPool Completed Work Item Count (Count / 2 sec) 0
ThreadPool Queue Length 0
ThreadPool Thread Count 12
Working Set (MB) 14,910</pre>
</div>
我们可以直接借助AI分析这个性能指标如下:
<table style="height: 505px; width: 1188px">
<thead>
<tr><th>指标</th><th>当前值</th><th>分析建议</th></tr>
</thead>
<tbody>
<tr>
<td>CPU Usage (%)</td>
<td><code>0</code></td>
<td>CPU 几乎未被使用，说明当前应用 处于空闲或阻塞状态。如果此时预期它应该在处理请求，说明可能卡在 I/O、锁、数据库等等待资源上。</td>
</tr>
<tr>
<td>GC Heap Size (MB)</td>
<td><code>11,419 MB</code></td>
<td>堆内存非常大（约 11GB），说明分配对象多或存在内存泄漏风险。建议配合 dump 分析对象分布。</td>
</tr>
<tr>
<td>GC Fragmentation (%)</td>
<td><code>8.189%</code></td>
<td>碎片率较低，尚可接受。通常低于 20% 问题不大。</td>
</tr>
<tr>
<td>LOH Size (B)</td>
<td><code>~3.34 GB</code></td>
<td>Large Object Heap（LOH）占用了非常大的空间。意味着有很多大对象（如数组、字符串、缓存等）未被及时回收，或持续增长。需要进一步 dump 分析。</td>
</tr>
<tr>
<td>Gen 2 Size (B)</td>
<td><code>~8.8 GB</code></td>
<td>Gen2 表示长时间存活对象。此值非常高，说明内存中存在大量老对象未被释放，极可能存在内存泄漏。</td>
</tr>
<tr>
<td>Gen 0/1 GC Count</td>
<td><code>0</code></td>
<td>说明当前没有发生 GC，或者是刚启动。这种情况下内存持续增长会导致最终触发 GC 或 OOM。</td>
</tr>
<tr>
<td>% Time in GC since last GC</td>
<td><code>0%</code></td>
<td>目前没有 GC 时间消耗，结合上面 GC Count 是 0，一致。</td>
</tr>
<tr>
<td>Working Set (MB)</td>
<td><code>14,910 MB</code></td>
<td>进程实际占用物理内存约 14GB，结合堆大小与 LOH/Gen2 数值合理，但这也是很大的内存占用，需要关注增长趋势。</td>
</tr>
<tr>
<td>Allocation Rate</td>
<td><code>98 KB / 2 sec</code></td>
<td>内存分配速率很低（接近空闲），说明当前没有明显的内存增长。</td>
</tr>
<tr>
<td>ThreadPool Thread Count</td>
<td><code>12</code></td>
<td>线程池线程数正常范围，无需担心。</td>
</tr>
<tr>
<td>ThreadPool Queue Length</td>
<td><code>0</code></td>
<td>没有待处理任务，说明任务执行速度没有瓶颈。</td>
</tr>
<tr>
<td>Exception Count</td>
<td><code>0</code></td>
<td>无异常抛出，良好。</td>
</tr>
<tr>
<td>Monitor Lock Contention Count</td>
<td><code>0</code></td>
<td>没有锁争用，说明线程间竞争不激烈。</td>
</tr>
</tbody>
</table>
 
根据AI的分析报告,我们可以得知:
GC Heap Size (MB) 堆内存极大达到了11G
LOH Size (B)大对象指标也很大,有3G的大对象
Gen2 长期活动的对象很多,占用了8G
这样我们基本就可以断定是在应用中出现了内存泄漏的情况.
 
也不用额外在看别的信息了. 我们直接使用dotnet-dump 抓取内存快照进行分析,抓取命令如下:
<div class="cnblogs_code">
<pre>dotnet-dump collect -p 1</pre>
</div>
我们会得到如下结果:
<div class="cnblogs_code">
<pre>Writing minidump with heap to ./core_20250514_030614
Complete</pre>
</div>
由于内存快照比较大,复制回来分析..难度比较高.我们可以直接继续利用dotnet-dump analyze 在线上分析
执行命令如下:
<div class="cnblogs_code">
<pre>dotnet-dump analyze core_20250514_030614</pre>
</div>
然后我们就可以使用sos命令进行分析了.
既然是内存泄漏,我们直接查看托管堆里面的到底是啥情况,命令如下:
<div class="cnblogs_code">
<pre>dumpheap -stat</pre>
</div>
正常是按从小到大排序的..所以很尬,我们划到最下面,看到如下结果:
<img src="https://img2024.cnblogs.com/blog/653851/202505/653851-20250516111349823-486551890.png" alt="" loading="lazy">
 由于我比较清楚这个代码的情况,直接发现了一个很明显的问题,
Order.OperApply.ApplyVoucherDetail  只是一个业务实体而已,但是在堆里面有29W个对象,
明显是很不合理的.
我们直接分析它.可以使用dumpheap -mt 获取它的所有实列地址.
<div class="cnblogs_code">
<pre>dumpheap -mt 00007f117f67e590</pre>
</div>
可以得到如下结果:
<img src="https://img2024.cnblogs.com/blog/653851/202505/653851-20250516111903405-1288286457.png" alt="" loading="lazy">
 我们选择最后一个Adderss寻找对象的根方法.命令如下:
<div class="cnblogs_code">
<pre>gcroot 00007f0ca9b55818</pre>
</div>
可以看到如下代码内容(由于太多,我只贴出来有用的):
<div class="cnblogs_code">
<pre>->00007F0E643FB770 RabbitMQ.Client.Impl.AsyncConsumerWorkService
->00007F0DA4D0BBB8 System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[,]
->00007F0AFCCE9020 System.Collections.Generic.Dictionary`2+Entry[,][]
->00007F1035A778A0 Order.OperApply.ApplyVoucher </pre>
</div>
这四条,我们就可以看出来,是RabbitMQ的消息队列,在ProductInOutStockStatDistributedHandler方法,进行消费的时候
会通过EF CORE 创建这个ApplyVoucher的实例,接下来,我们就需要查看这个ProductInOutStockStatDistributedHandler,到底做了什么.
<h2>4.排查代码</h2>
直接去查看这个方法的代码,发现竟然没有任何一处使用了ApplyVoucher实体.
所以,我们直接运行本地调试,发现在这个方法结束后会去查询ApplyVoucher表.
分析代码后,我们发现,由于我们使用的是ABP的框架,在方法结束后,会自动写入审计日志,最后才会结束整个调用.
遂调查审计日志模块,发现有小伙伴在审计日志中对ABP的AuditLogInfo对象进行了序列化操作.
查询ABP源码发现,AuditLogInfo的EntityChanges中竟然储存了Microsoft.EntityFrameworkCore.ChangeTracking.EntityEntry对象
而EntityEntry对象又包含了整个DBContext上下文..然而我们的DBContext 又开启了懒加载的功能
所以当它被序列化的时候...等于在序列化整个数据库..(这里省略一百个C...)
赶紧屏蔽这段代码,并更新到线上. 问题瞬间解决了..
<h2>5.深入求证.</h2>
解决问题后,还是比较好奇,有没有同样使用ABP的兄弟遇见相关问题,遂去查询abp源码仓库..
竟然发现在Extracting a Module as a Microservice的相关说明里.
看到了这一段...
<img src="https://img2024.cnblogs.com/blog/653851/202505/653851-20250516115649667-1719917290.png" alt="" loading="lazy">
而且ABP框架还特意创建了一个IAuditLogInfoToAuditLogConverter来转换AuditLogInfo对象..方便后面进行序列化和存储..
 
<div style="text-align: center; background-color: rgba(136, 136, 136, 1)">后记</div>
 
这一次分析线上问题的过程,还是比较有参考性的,所以记录一下.也希望对各位兄弟们有帮助.觉得OK的可以点个推荐~~.3Q~

</div>
<div id="MySignature" role="contentinfo">
作者：顾振印
出处：http://www.cnblogs.com/GuZhenYin/
如果您觉得阅读本文对您有帮助，请点一下“推荐”按钮，您的“推荐”将是我最大的写作动力！本文版权归作者和博客园共有，欢迎转载，但未经作者同意必须保留此段声明，且在文章页面 
来源：https://www.cnblogs.com/GuZhenYin/p/18879790

頁: [1]

琼殿技术论坛's Archiver

记一次ASP.NET CORE线上内存溢出问题与dotnet-dump的排查方法