作者技术从业16年踩过坑、做过技术负责人、带过团队也亲眼看着AI把很多”理所当然”的事情重新洗牌。不追热点只写真实踩过的坑和总结过的东西欢迎关注一起交流。起因现场说系统卡得没法用了周三下午现场群里炸了。一套跑了十几年的 ERP/WMS 系统基于 ASP.NET WebForms跑在 IIS 上。业务方反馈“点哪儿都卡有时候转半天没反应有时候突然又好了。”这种时好时坏的卡顿是排查里最磨人的一类。CPU 打满型好办性能计数器一盯就知道哪条 SQL、哪个接口在烧死锁也好办看日志就能定位。偏偏是间歇性的——你盯着它它不犯你一走它又卡。现场运维小张还算靠谱趁卡顿的时候用任务管理器右键 → 创建转储文件抓了一个 w3wp.exe 的 dump 发给我。2.46 GBFull Memory。我接过来倒了杯水觉得这活儿半小时能搞定。结果我被这个 dump 折磨了整整一下午。因为它是废的。这篇记录的就是这次排查的全过程。如果你也遇到过 ASP.NET 间歇卡顿、也抓过看起来没问题的 dump 却分析不出名堂照着走能少走至少半天弯路。我把能踩的坑都踩了。第一个坎dump 抓回来了托管栈全是死的抓回 dump第一件事是上 WinDbg 分析。这系统的运行时是 .NET Framework 4.8所以我得先加载 SOS 扩展才能看托管堆和托管线程栈。命令很标准0:000 .loadby sos clr 0:000 ~* e !clrstack.loadby sos clr的意思是 clr 模块在哪儿就去那儿找 sos.dll 并加载。~* e !clrstack是对每个线程都执行一次 !clrstack把所有托管线程的调用栈打出来。回车刷屏。刷出来的却不是栈是一屏的报错OS Thread Id: 0xf21c (0) Unable to walk the managed stack. The current thread is likely not a managed thread. You can run !threads to get a list of managed threads in the process Failed to start stack walk: 80070057每个线程都是这行Failed to start stack walk: 80070057。80070057是E_INVALIDARG——参数无效。意思是 SOS 想遍历托管栈但遍历器启动就失败了。所有线程的托管栈一个都读不出来。我盯着屏幕心里咯噔一下。这是排查最尴尬的局面dump 抓回来了原生栈能看到但托管世界一片漆黑。而这系统是 .NET 的业务逻辑全在托管代码里——读不到托管栈就等于知道案发地点却不知道凶手是谁、用的什么凶器。那一刻我怀疑过很多方向是不是 SOS 版本不对是不是 dump 损坏了是不是抓的时候进程状态特殊但有一个方向我没第一时间往那想——是不是 dump 的抓取方式本身就有问题这一关给我的教训很朴素也是这篇文章最想让你记住的一句话任务管理器抓的 .NET dump托管栈经常是死的。这不是玄学是机制问题。下面我慢慢讲清楚。小反转先别慌看 !analyze -v 说啥在怀疑一切之前我习惯先让 WinDbg 自己说一遍——跑!analyze -v这是 WinDbg 的自动分析命令会帮你定位异常、故障模块。跑完输出里有一段很显眼FAILURE_BUCKET_ID: BREAKPOINT_80000003_w3wphost.dll!WP_IPM::WaitForShutdown EXCEPTION_CODE_STR: 80000003 STACK_TEXT: ntdll!NtWaitForSingleObject0x14 KERNELBASE!WaitForSingleObjectEx0x93 w3wphost!WP_IPM::WaitForShutdown0x11 w3wphost!AppHostInitialize0x147 w3wp!wmain0x420新人看到EXCEPTION_CODE 80000003、FAILURE_BUCKET这种字眼很容易慌——“完了进程崩了是个断点异常”别慌。这是个假警报。80000003是 break 指令异常也就是断点。但你看栈——w3wphost!WP_IPM::WaitForShutdown这是 w3wp 主线程在等待关闭的循环里。这不是崩溃是有人主动打断进程、抓了个 dump。任务管理器抓 dump 就是这么干的给进程注入一个断点趁进程停在断点的瞬间把内存拷出来。所以!analyze -v这里报告的异常本质是抓 dump 这个动作本身跟卡顿半毛钱关系都没有。带团队这些年我特别怕新人遇到!analyze -v报异常就紧张。先看栈在哪儿——栈停在WaitForShutdown是抓取断点栈停在某个业务方法里才是真现场。判断这是抓取动作还是真故障的能力是 dump 分析的第一道分水岭。但这里也确认了一个坏消息栈顶是WaitForShutdown说明抓 dump 的瞬间这个 w3wp 主线程是闲着的。这是个不祥之兆——卡顿如果是持续性的抓到的瞬间线程应该在忙抓到闲着的很可能没抓到现场。我心里隐隐有了预感但还得验证。排查方向一是不是 SOS 版本不对托管栈读不出来最常见的解释是 SOS 版本和 CLR 版本不匹配。SOS 是 CLR 的配套调试扩展版本必须严格对上差一个小版本号都可能出幺。我让 WinDbg 报了一下版本CLR Version: 4.8.4110.0 SOS Version: 4.8.9139.0果然对不上。CLR 是 4.8.4110但自动加载的 SOS 是 4.8.9139——我本机装的 .NET 比生产服务器新.loadby顺着我本机的 .NET 目录加载了更新版的 SOS。第一反应是找匹配的 SOS。.loadby加载错了我手动.load指定路径总行吧。我本机有 .NET Framework 自带的 SOSC:\Windows\Microsoft.NET\Framework64\v4.0.30319\sos.dll加载它重试!clrstack。结果——还是80070057全部失败。我本机的 Framework64 sos.dll 也是 4.8.9139版本还是不对。那加载精确匹配的 4.8.4110 版本。好在 WinDbg 自动从微软符号服务器下载匹配 SOS 时把它存到了本地符号缓存C:\ProgramData\dbg\sym\SOS_AMD64_AMD64_4.8.4110.00.dll\ ...\SOS_AMD64_AMD64_4.8.4110.00.dll ← image 4.8.4110.0精确匹配我卸掉错的加载这个精确匹配的0:000 .unload sos 0:000 .load C:\ProgramData\dbg\sym\...\SOS_AMD64_AMD64_4.8.4110.00.dll 0:000 .chain ← 确认加载的是 4.8.4110 0:000 ~* e !clrstack结果——依然80070057。到这里结论已经清晰这不是 SOS 版本问题。我换了三个 SOS版本从 4.8.9139 换到精确匹配的 4.8.4110托管栈遍历照样失败。这是我踩的第一个大坑也是新手最容易卡住的地方。!clrstack失败第一反应都是换 SOS 版本但换完还不行就该意识到不是 SOS 的锅是这个 dump 本身的托管栈不可走。别在 SOS 版本上耗太久——换两个还不行方向就错了。我还试了!eestack -ee混合栈遍历器号称更稳健同样失败。这下死心了这个 dump 的托管栈彻底读不出来。那一刻我反而松了口气。因为方向错了不可怕可怕的是不知道方向在哪。现在方向明确了——不是分析能力的问题是抓取方式的问题。反转真正的问题在抓取方式——任务管理器 vs procdump托管栈为什么读不出来这要回到 dump 是怎么抓的。现场小张用的是任务管理器 → 右键进程 → 创建转储文件。这条路最省事点一下就行运维人人都会。但它有个致命弱点它抓的 dump托管堆的元数据经常不完整导致 SOS 遍历栈时拿不到有效上下文于是80070057。这不是任务管理器的 bug是它抓取时机和方式的局限——它用最简单的注入断点方式抓没像专业工具那样做托管堆的状态保全。正确的姿势是用 procdumpSysinternals 出品微软官方。procdump 抓 dump 时会确保托管堆状态完整SOS 能正常遍历。我让小张用 procdump 重抓。命令其实就一行procdump64.exe-maw3wp的PIDw3wp.dmp-ma是 Full Memory dump抓全内存。对 .NET 排查必须用-ma——少了它托管堆和栈照样读不全。更进一步针对间歇卡顿procdump 还能挂着等——CPU 一飙高就自动抓# CPU 超过 80% 持续 5 秒自动抓 1 个procdump64.exe-ma-c80-s5PIDw3wp_cpu.dmp# 抓 3 个间歇卡顿要多抓几个对比procdump64.exe-ma-c80-s5-n3PID参数含义-maFull Memory dump.NET 排查必选-c 80CPU 超过 80% 时触发-s 5持续 5 秒才触发过滤瞬时毛刺-n 3连续抓 3 个但这里有个现实问题现场卡顿是间歇的挂 procdump 等触发可能等半天也等不到。而我手头这个已经抓好的、托管栈读不出的 dump难道就白瞎了不白瞎。我做了个决定这个 dump 虽然!clrstack废了但!threads、!dumpheap、!eeheap这些命令都正常——它们不依赖栈遍历只读堆结构。我可以从线程状态和托管堆对象分布两个角度把根因挖出来。这是我踩坑后想明白的一件事一个不完美的 dump不代表没价值。抓 dump 这事讲究时机现场不一定每次都抓得准。与其干等重抓不如先把能榨的信息榨干。分析能力体现在手里只有半张牌也能打出结论。换个姿势从线程在干嘛入手托管栈读不了我换第一个角度——看线程在等什么。这条路靠原生栈~* kb不依赖 SOS一定走得通。先看线程池状态。!threadpool是看线程池忙不忙的关键命令0:000 !threadpool CPU utilization: 0% Worker Thread: Total: 34 Running: 1 Idle: 33 MaxLimit: 32767 MinLimit: 32 Work Request in Queue: 0 Completion Port Thread: Total: 2 Free: 2 Number of Timers: 2我盯着这五行心里那个没抓到现场的预感坐实了。逐行拆解指标值含义CPU utilization0%抓取瞬间 CPU 几乎空闲Worker Thread Running1 / 3434 个工作线程只有 1 个在跑33 个闲着Work Request in Queue0线程池待处理队列为空没有请求积压Completion Port Free2 / 2IO 完成端口线程全空闲翻译成人话抓 dump 的这一刻系统是闲着的。CPU 没打满线程没排队请求没积压。这跟卡得没法用的反馈对不上。但别急——这恰恰印证了间歇性。卡顿是一阵一阵的抓到的这一秒正好是阵歇期。这正常间歇卡顿的 dump 本来就难抓到峰值。再看有没有锁竞争。!syncblk看托管 Monitor 锁0:000 !syncblk Index SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner ------------------------------------------------------------- Total 659 Free 351竞争表是空的——Total 659个 SyncBlockFree 351没有一个线程在等锁。排除了锁竞争和死锁。再看 CPU 累计消耗。!runaway列出每个线程的累计 CPU 时间是找哪个线程在烧 CPU的利器0:000 !runaway 7 User Mode Time Thread Time 34:15d0c 0 days 0:00:02.812 106:15fdc 0 days 0:00:02.453 98:ad0 0 days 0:00:01.390 89:14df0 0 days 0:00:01.359 ...后面越来越小这里有个坑新手必栽。!runaway默认会输出三段User Mode Time用户态、Kernel Mode Time内核态、Elapsed Time线程存活时长。我看到第一段 User Mode Time 最高才 2.8 秒——但这系统已经跑了 20 小时 51 分钟。20 小时累计才烧了 2.8 秒 CPU等于几乎没在计算。但如果你看岔了去看第三段 Elapsed Time会吓一跳Elapsed Time 3:4ef0 0 days 0:31:31.428 ← 31 分钟 124:f3c 0 days 0:30:31.393一堆线程31 分钟。新人容易误读成这些线程烧了 31 分钟 CPU。错。Elapsed Time 是线程从创建到现在的存活时长不是 CPU 占用——线程一直在那儿挂着等任务31 分钟只是它活了31 分钟跟 CPU 一毛钱关系没有。!runaway这个命令只看 User Mode Time 那一段。Elapsed Time 是存活时长最唬人——一堆 30 分钟的数字新手一看以为 CPU 爆了其实是线程在睡觉。这个误读我见过不止一个人栽。到这里线程角度的结论很清楚了抓取瞬间系统空闲、无锁竞争、CPU 累计消耗极低。急性瓶颈CPU 打满 / 死锁 / 线程池饿死一个都没坐实。但没坐实不等于没有。卡顿是间歇的抓到闲着的一秒说明不了问题不存在。只是这条线索断了得换一条。排查方向二统计线程在等什么揪出等待大户线程角度的宏观状态看完了我再钻进去——100 多个线程到底各自在等什么这个统计能透露很多信息。我用的是所有线程原生栈~* kb然后对栈顶的等待函数做计数。在 WinDbg 里没法直接统计我把输出导出来用脚本 grep sort uniq 计数。栈顶等待函数分布NtWaitForSingleObject 202 NtRemoveIoCompletion 70 NtWaitForMultipleObjects 10 NtWaitForWorkViaWorkerFactory 8 NtDelayExecution 4200 多个线程都在NtWaitForSingleObject上等。但在等不等于被阻塞卡住——线程池空闲的 worker 也在等等任务派发。得看它们等的是哪种东西。我顺着每个WaitForSingleObject往栈上一帧看统计它的上层调用者谁调用了 WaitForSingleObjectEx取调用点 130 clr!CLREventWaitHelper2 ← 托管事件等待 66 clr!CLRSemaphore::Wait ← 信号量等待 2 clr!ThreadpoolMgr::GateThreadStart 2 w3wphost!WP_IPM::WaitForShutdown两条主路130 个线程在CLREventWaitHelper2托管事件等待66 个在CLRSemaphore::Wait信号量等待。第一眼看到 66 个线程卡在信号量我心里一动——是不是连接池耗尽业务请求拿不到 Oracle 连接全堵在信号量上这是 .NET 应用卡顿的经典剧本。但我没急着下结论把这个信号量等待的线程栈拉出来看ntdll!NtWaitForSingleObject0x14 KERNELBASE!WaitForSingleObjectEx0x93 clr!CLRSemaphore::Wait0x7d clr!ThreadpoolMgr::UnfairSemaphore::Wait0x115 ← 注意这行 clr!ThreadpoolMgr::WorkerThreadStart0x2c2看到clr!ThreadpoolMgr::UnfairSemaphore::Wait我心里凉了半截——这不是业务信号量是线程池自己的派发信号量。意思是这 66 个线程是空闲的工作线程在等线程池派活给它们。也就是说它们不是被卡住是没活干在休息。这是我差点栽的第二个坑。看到一堆线程卡在CLRSemaphore::Wait第一反应是连接池/业务信号量耗尽——但必须往上多看一层。如果上面是OracleInternal.ConnectionPool那是连接池耗尽真问题如果上面是ThreadpoolMgr::UnfairSemaphore那是空闲 worker 在等任务正常现象。差一行栈帧结论天差地别。多看一层栈是省掉一次误判的关键。那 130 个CLREventWaitHelper2呢我往上追上层是clr!CLREventBase::WaitEx——这是通用的托管事件等待路径WaitHandle.WaitOne、Task 完成等待、CLR 内部事件都走这里。具体是哪个业务调用得上托管栈!clrstack才能定位——而托管栈恰好读不了。这条线索到这里也到头了。线程等待的统计告诉我没人在干活、也没人被业务锁卡住但读不到托管栈就定位不到那 130 个等待事件背后是哪段业务代码。两条线索都断了但它们共同指向一个判断这不是线程在跑业务代码时卡住更像是一种全停顿。什么样的全停顿能让所有线程同时歇菜、抓 dump 又抓到闲着我心里有了一个怀疑的方向。但这次我学乖了不急着下结论——先把托管堆翻出来看。排查方向三翻托管堆696 万个对象说了实话线程线索断了我转向最后一个、也是最可能出真相的地方——托管堆。!dumpheap和!eeheap这两个命令只读堆结构、不依赖栈遍历在当前 dump 里完全可用。先看堆有多大。!eeheap -gc0:000 !eeheap -gc Number of GC Heaps: 32 ... GC Heap Size: Size: 0x2059d508 (542758152) bytes.542 MB。一个 w3wp 进程的托管堆 542 MB活堆不算小。但比多大更要命的是堆里都装了啥。!dumpheap -stat按类型统计堆上对象输出按对象大小排序。我把 Top 类型拎出来MT Count TotalSize Class Name 00007ffb746559c0 2698813 188546664 System.String 00007ffb1793cb80 846743 54191552 Newtonsoft.Json.Linq.JValue 00007ffb746567d0 159573 43883626 System.Char[] 00007ffb7465aaa0 22899 31977350 System.Byte[] 00007ffb1a0ae6a0 338596 28917744 Newtonsoft.Json.Linq.JToken[] 00007ffb17ea5658 169497 16271712 Newtonsoft.Json.Linq.JArray ... Total 6967071 objects最后一行是重锤Total 6967071 objects——堆上有 696 万个对象。逐行看根因自己浮出来了类型数量大小System.String269 万180 MBNewtonsoft.Json.Linq.JValue84 万54 MBSystem.Char[]16 万43 MBSystem.Byte[]2.3 万31 MBNewtonsoft.Json.Linq.JToken[]33 万28 MBNewtonsoft.Json.Linq.JArray17 万16 MBNewtonsoft JTokenLineInfo36 万8.6 MB整个堆被 Newtonsoft.Json 的 JObject/JArray/JToken 这棵 DOM 树和 270 万个字符串塞满了。把 Newtonsoft 相关的全加起来JValue JArray JToken[] LineInfo List光 JSON 的 DOM 对象就占了 ~114 MB再加上和它关联的 180 MB 字符串——JSON 相关的内存是这个堆的绝对主体。那一刻我懂了。排查卡顿线程告诉你现在在干嘛堆告诉你过去攒了什么。线程抓到闲着不代表没问题——因为问题可能不在线程卡住而在堆被塞爆每次 GC 都得停一下。这两个角度互补缺一个都可能误判。根因不是线程卡住是 GC 在卡把所有线索串起来根因水落石出。先看大对象堆LOH。!eeheap -gc会把每代堆分开列我把 32 个堆的 LOH 段求和堆分段大小说明托管堆总量517.6 MB大对象堆 LOH148.9 MB≥85KB 大对象只在 Gen2 回收小对象堆 SOH368.7 MB主要为长期存活的 Gen2堆对象总数696 万个LOH 149 MB意味着有大量 ≥85KB 的大对象大byte[]、大string、大数组。这些对象只在 Gen2 回收时才被处理。机制是这样的堆里有 518 MB 活对象、696 万个引用、149 MB LOH其中绝大部分Gen2 LOH是长期存活的——270 万个 String、84 万个 JValue不会随 Gen0/1 回收消失当堆增长到触发 Gen2 回收或后台 GC时GC 的标记阶段要扫描这 696 万个对象的引用关系扫 696 万对象 标记 518 MB 堆需要时间——这段时间里所有托管线程被暂停STWStop-The-World暂停的几十到上百毫秒用户感知为卡一下扫完恢复又突然好了。这完美解释了所有现象✅为什么时好时坏——GC 不是一直跑是堆涨到阈值才触发两次回收之间系统正常✅为什么抓 dump 抓到闲着——STW 停顿通常很短几十到几百毫秒抓 dump 的瞬间大概率落在回收之外的正常期✅为什么 CPU 不高——STW 期间主要是 GC 线程在标记扫描业务线程是被暂停而非在烧 CPU累计 CPU 自然低✅为什么没有锁竞争——根本不是锁的问题是 GC 停顿✅为什么堆里全是 JSON 和字符串——这些正是 Gen2 长期存活、撑大堆的元凶。找根因的时间远大于改代码的时间。这一下午我大半时间花在搞清楚 dump 为什么读不出托管栈、线程在等什么、堆里装了什么真正定位根因就是!dumpheap -stat那一下——看到 270 万 String 和 84 万 JValue 的瞬间答案就摆在那儿了。但如果没有前面几步把线程没问题排除掉我不会有信心相信根因在堆。排查是排除法不是猜谜。验证根因的几个抓手根因是推断出来的托管栈读不了没法 100% 锤实是哪个业务方法在产生这些 JSON所以我给现场几个验证抓手确认这个判断1. perfmon 看 GC 指标。这是验证 GC 压力最直接的方式盯.NET CLR Memory这组计数器计数器看什么异常信号% Time in GCGC 占用时间比例卡顿时峰值 30% 即坐实# Gen 2 CollectionsGen2 回收次数卡顿前后是否激增Large Object Heap SizeLOH 大小是否只增不减Allocated Bytes/sec每秒分配量是否异常高2. 抓两份 dump 对比。隔 10 分钟抓两个用 procdump别再用任务管理器跑!dumpheap -stat对比System.String和JValue的数量是否在涨。只增不减就是有地方在持续产生、不释放。3. 抓一份卡顿瞬间的合格 dump。用 procdump卡顿当场立即抓procdump64.exe-maPIDw3wp_stuck.dmp这份 dump 能跑!clrstack就能定位到底是哪个业务方法在产生那 270 万个 String 和 84 万个 JObject。SignalR 推送API 序列化Excel 导出报表生成还是把结果缓存进System.Runtime.Caching后长期不释放——抓到现场一锤定音。复盘这次排查留下的六条铁律回看这一下午把经验浓缩成六条建议你截图存档1. .NET dump永远用 procdump -ma 抓别用任务管理器。任务管理器抓的 dump 托管栈经常是死的80070057SOS 遍历不动。procdump 的-ma会保全托管堆状态是 .NET 排查的唯一正解。这一条值一整个下午。2.!clrstack失败先换一两次 SOS 版本换两次还不行就换方向。.loadby sos clr加载错版本是常事手动.load匹配版或符号缓存里的SOS_AMD64_AMD64_4.8.4110.00.dll。但换两次还80070057就别在 SOS 上耗了——是 dump 的问题不是工具的问题。3.!runaway只看 User Mode Time别被 Elapsed Time 骗了。Elapsed Time 是线程存活时长一堆 30 分钟的数字是线程在睡觉不是在烧 CPU。看岔了会误判成CPU 爆了。4. 线程等待要往上多看一层栈别只看栈顶函数名。CLRSemaphore::Wait可能是连接池耗尽业务问题也可能是ThreadpoolMgr::UnfairSemaphore空闲 worker正常。差一行栈帧结论相反。5. 线程告诉你现在在干嘛堆告诉你过去攒了什么。两个角度互补。线程抓到闲着不代表没问题——问题可能不在卡住而在堆被塞爆、GC 频繁停顿。!dumpheap -stat是 .NET 排查里被低估的神命令270 万个 String 直接开口说了实话。6. 不完美的 dump 也有价值先榨干再重抓。手头这个 dump 托管栈废了但!threadpool/!syncblk/!dumpheap/!eeheap全能用。与其干等重抓不如把能读的全读了。分析能力体现在只有半张牌也能打出结论。命令速查这次的排查工具箱把这次用到的命令收个尾下次直接照搬命令干嘛用的关键看什么!analyze -v自动分析异常栈在WaitForShutdown 抓取断点非崩溃!threadpool线程池状态Queue 是否积压、Running/Idle 比!syncblk托管锁竞争有无活动 Monitor 等待!runaway 7各线程累计 CPU只看 User Mode Time~* kb全线程原生栈统计栈顶等待函数.loadby sos clr加载 SOS失败则手动.load匹配版~* e !clrstack全线程托管栈80070057 dump 抓废了!eeheap -gcGC 各代堆大小LOH、Gen2 占比!dumpheap -stat堆对象类型统计Top 类型、对象总数人到中年最大的变化是学会了不急。带团队也好找第二曲线也好都不必非要在某个节点交出满分答卷。每天做一点新的尝试被年轻人带飞几次被自己蠢哭几回这一天就没白过。不油腻的秘诀保持被打脸的机会然后笑嘻嘻地爬起来。关注我咱们一起晒太阳、赶路。
)
