关键词：
一：背景
1. 讲故事
这个月中旬，有位朋友加我wx求助他的程序线程占有率很高，寻求如何解决，截图如下：
说实话，和不同行业的程序员聊天还是蛮有意思的，广交朋友，也能扩大自己的圈子，朋友说他因为这个bug还导致项目黄了一个... 😂😂😂
哈哈，看样子是客户不买账，验收不了，害。。。早找到我，这客户不就捞回来啦，这也许就是技术的价值吧！😁😁😁
既然找到我，那就让这个挂死问题彻底消失吧，上windbg说话。
二：Windbg 分析
1. 查看线程情况
既然朋友说线程高，那就从线程入手，用 !t 命令即可。
0:000> !t
ThreadCount: 1006
UnstartedThread: 0
BackgroundThread: 1005
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
Lock
DBG ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception
0 1 10c8 00000000004D89A0 2a020 Preemptive 0000000000000000:0000000000000000 00000000002f1070 0 MTA
2 2 13c0 000000000031FF70 2b220 Preemptive 0000000000000000:0000000000000000 00000000002f1070 0 MTA (Finalizer)
3 3 12cc 000000000032B780 102a220 Preemptive 0000000000000000:0000000000000000 00000000002f1070 0 MTA (Threadpool Worker)
4 5 138c 000000000039E3C0 8029220 Preemptive 00000000B6D3CCA0:00000000B6D3D260 00000000002f1070 0 MTA (Threadpool Completion Port)
6 6 106c 0000000019E562A0 3029220 Preemptive 0000000000000000:0000000000000000 00000000002f1070 0 MTA (Threadpool Worker)
8 11 7f0 0000000019F8F9E0 20220 Preemptive 0000000000000000:0000000000000000 00000000002f1070 0 Ukn
9 1949 323c 000000009AA69E40 8029220 Preemptive 00000000B6BB8AD0:00000000B6BB94E0 00000000002f1070 0 MTA (Threadpool Completion Port)
10 1637 b3c 000000009AA1C260 8029220 Preemptive 00000000B6CD4220:00000000B6CD47E0 00000000002f1070 0 MTA (Threadpool Completion Port)
11 1947 223c 000000009ADB72E0 8029220 Preemptive 00000000B6D88D68:00000000B6D89550 00000000002f1070 0 MTA (Threadpool Completion Port)
12 1968 2e74 000000009AA1E330 8029220 Preemptive 00000000B6A8CD40:00000000B6A8D300 00000000002f1070 0 MTA (Threadpool Completion Port)
...
994 313 1fa4 000000009A81FFC0 8029220 Preemptive 00000000B6BFC1B8:00000000B6BFC410 00000000002f1070 0 MTA (Threadpool Completion Port)
995 1564 18ec 000000009A835510 8029220 Preemptive 00000000B6AC1ED0:00000000B6AC2490 00000000002f1070 0 MTA (Threadpool Completion Port)
996 1581 4ac 000000001C2E36E0 8029220 Preemptive 00000000B6C51500:00000000B6C51AC0 00000000002f1070 0 MTA (Threadpool Completion Port)
997 814 2acc 000000009A73B5E0 8029220 Preemptive 00000000B6D67BF8:00000000B6D683E0 00000000002f1070 0 MTA (Threadpool Completion Port)
998 517 25dc 000000009A838990 8029220 Preemptive 00000000B6D2CA10:00000000B6D2CFD0 00000000002f1070 0 MTA (Threadpool Completion Port)
999 670 2a10 000000001C2E4400 8029220 Preemptive 00000000B6CD0490:00000000B6CD0A50 00000000002f1070 0 MTA (Threadpool Completion Port)
1000 183 1704 000000009A81F930 8029220 Preemptive 00000000B6AE8670:00000000B6AE8C30 00000000002f1070 0 MTA (Threadpool Completion Port)
1001 117 1bcc 000000009A73BC70 8029220 Preemptive 00000000B6B92780:00000000B6B92D40 00000000002f1070 0 MTA (Threadpool Completion Port)
1002 1855 1d68 000000009A81E580 8029220 Preemptive 00000000B6B28460:00000000B6B28A20 00000000002f1070 0 MTA (Threadpool Completion Port)
1003 1070 2ef0 000000009A73C300 8029220 Preemptive 00000000B6B8F640:00000000B6B8FC00 00000000002f1070 0 MTA (Threadpool Completion Port)
1004 1429 210c 000000001C2E4A90 8029220 Preemptive 00000000B6D5F488:00000000B6D5FC70 00000000002f1070 0 MTA (Threadpool Completion Port)
1005 1252 2f38 000000009A838300 8029220 Preemptive 00000000B6A99240:00000000B6A99800 00000000002f1070 0 MTA (Threadpool Completion Port)
1006 1317 3118 000000001C2E5120 8029220 Preemptive 00000000B6DA3A30:00000000B6DA4440 00000000002f1070 0 MTA (Threadpool Completion Port)
1007 1837 3120 000000009A8375E0 8029220 Preemptive 00000000B6D38F10:00000000B6D394D0 00000000002f1070 0 MTA (Threadpool Completion Port)
1009 1964 2f64 000000009A81DEF0 1029220 Preemptive 0000000000000000:0000000000000000 00000000002f1070 0 MTA (Threadpool Worker)可以看到当前有 1006 个线程，其中 1000 个是 Threadpool Completion Port，这么多IO线程卡死也是第一次遇到，🐂👃。
说实话，看到 Threadpool Completion Port 我就想到这是一个异步操作的回调，那为什么会有这么多IO线程被卡死 ? 要想寻找答案，抽个线程看一下。
0:1000> ~1000s
ntdll!NtNotifyChangeDirectoryFile+0xa:
00000000`77c7a75a c3 ret
0:1000> !clrstack
OS Thread Id: 0x1704 (1000)
Child SP IP Call Site
00000000A99FF4C0 0000000077c7a75a [InlinedCallFrame: 00000000a99ff4c0] Interop+Kernel32.ReadDirectoryChangesW(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Boolean, Int32, Int32 ByRef, System.Threading.NativeOverlapped*, IntPtr)
00000000A99FF4C0 000007fe8e87bd20 [InlinedCallFrame: 00000000a99ff4c0] Interop+Kernel32.ReadDirectoryChangesW(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Boolean, Int32, Int32 ByRef, System.Threading.NativeOverlapped*, IntPtr)
00000000A99FF470 000007fe8e87bd20 DomainBoundILStubClass.IL_STUB_PInvoke(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Boolean, Int32, Int32 ByRef, System.Threading.NativeOverlapped*, IntPtr)
00000000A99FF560 000007fef19dab6e System.IO.FileSystemWatcher.Monitor(AsyncReadState) [E:\\A\\_work\\322\\s\\corefx\\src\\System.IO.FileSystem.Watcher\\src\\System\\IO\\FileSystemWatcher.Win32.cs @ 141]
00000000A99FF5E0 000007fef19dae6c System.IO.FileSystemWatcher.ReadDirectoryChangesCallback(UInt32, UInt32, System.Threading.NativeOverlapped*) [E:\\A\\_work\\322\\s\\corefx\\src\\System.IO.FileSystem.Watcher\\src\\System\\IO\\FileSystemWatcher.Win32.cs @ 227]
00000000A99FF630 000007feedbe0af9 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [E:\\A\\_work\\191\\s\\src\\mscorlib\\shared\\System\\Threading\\ExecutionContext.cs @ 167]
00000000A99FF6B0 000007feede094dc System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*) [E:\\A\\_work\\191\\s\\src\\mscorlib\\src\\System\\Threading\\Overlapped.cs @ 108]
00000000A99FF7F0 000007feee359ed3 [GCFrame: 00000000a99ff7f0]
00000000A99FF9D0 000007feee359ed3 [DebuggerU2MCatchHandlerFrame: 00000000a99ff9d0]我去，又见 FileSystemWatcher ，追这个系列的朋友应该知道，我上个月分析了一篇 记一次 .NET 某流媒体独角兽 API 句柄泄漏分析文件句柄 爆高，他的形成原因是 定时刷新 appsetttings + reloadOnChange=true 所致，这世界真小，莫不会撞车了。。。接下来我们重点关注一下它。
2. 探究 FileSystemWatcher
要想进一步分析，先用 !dso 命令看一下当前的线程栈对象。
0:1000> !dso
OS Thread Id: 0x1704 (1000)
RSP/REG Object Name
00000000A99FF508 00000000263285d8 System.Byte[]
00000000A99FF518 00000000242aeb10 System.Threading._IOCompletionCallback
00000000A99FF560 00000000242ae1b0 Microsoft.Win32.SafeHandles.SafeFileHandle
00000000A99FF568 00000000242aeaa8 System.Threading.PreAllocatedOverlapped
00000000A99FF578 00000000242aeb10 System.Threading._IOCompletionCallback
00000000A99FF5E0 00000000242a8538 System.IO.FileSystemWatcher
00000000A99FF5E8 00000000242aea10 System.IO.FileSystemWatcher+AsyncReadState
00000000A99FF608 00000000242aea10 System.IO.FileSystemWatcher+AsyncReadState
00000000A99FF610 0000000023206e30 System.Threading.ExecutionContext
00000000A99FF618 0000000001032928 System.Threading.ContextCallback
00000000A99FF630 00000000242a8538 System.IO.FileSystemWatcher
00000000A99FF678 00000000b6a69a40 System.Threading.Thread
00000000A99FF688 00000000242aeb10 System.Threading._IOCompletionCallback
00000000A99FF690 0000000023206e30 System.Threading.ExecutionContext
00000000A99FF6C0 0000000021fa55d8 System.Threading._IOCompletionCallback
00000000A99FF6C8 000000002052e6e0 System.Threading.ExecutionContext
00000000A99FF7E0 000000000560d2b0 System.Threading.OverlappedData由于线程栈上的对象是向小扩展的，所以看那个最小地址上的 System.Byte[] 内容就知道当前回调的是啥啦，截图如下：
经过上一役的分析经验，到这里我基本就搞清楚了，这又是一个不断构建 ConfigurationRoot 时配了 reloadOnChange: true 的经典案例，它的后果会导致内存中新增大量的 FileSystemWatcher 和 ConfigurationRoot 无法释放，而诱发点就是上图中的日志文件的不断变更导致的海量回调函数触发的卡死案例，具体详情... 请听我慢慢分解，先验证下这两个类在托管堆上的个数。
0:1000> !dumpheap -stat -type FileSystemWatcher
Statistics:
MT Count TotalSize Class Name
000007fe8ed5bc90 2 160 System.Collections.Generic.Dictionary`2[[System.String, System.Private.CoreLib],[System.IO.FileSystemWatcher, System.IO.FileSystem.Watcher]]
000007fe8e9f11a0 34480 1930880 System.IO.FileSystemWatcher+AsyncReadState
000007fe8e9d69c8 34480 4137600 System.IO.FileSystemWatcher
Total 68962 objects
0:1000> !dumpheap -stat -type ConfigurationRoot
Statistics:
MT Count TotalSize Class Name
000007fe8e9f1e70 34480 827520 Microsoft.Extensions.Configuration.ConfigurationRoot+<>c__DisplayClass2_0
000007fe8e999560 34480 1103360 Microsoft.Extensions.Configuration.ConfigurationRoot
Total 68960 objects果不其然，托管堆有 3.4w 的 FileSystemWatcher 和 ConfigurationRoot，接下来就得和朋友沟通了。
3. 到底是什么代码引起的?
询问朋友为什么会有 3.4w 的 ConfigurationRoot 对象，理论上一个程序只会有一个，根据这些信息，朋友很快就找到了问题代码，截图如下：
就是因为上图中的 reloadOnChange: true 让底层构建了 FileSystemWatcher 对 appsettings.json 的实时监控，从而导致内存出现了 3.4w 的对象无法释放。
三：为什么日志变更会造成程序卡死
1. 当初的困惑
其实我当初分析到这里的时候也是很困惑的，就算内存中有 3.4w 的 FileSystemWatcher，那也只是对 appsettings.json 的监控，只要这个文件不变动就不会触发 3.4w 的回调，不是吗？可当我分析完 ConfigurationRoot 源码之后，我发现自己真tmd的天真。
2. 从源码中寻找答案
首先我们看看 FileSystemWatcher 到底监控的是啥？可以在它的构造函数中设一个断点，如下图所示：
很明显的看到，它 watch 的是程序根目录，这就能解释为什么日志文件有变更就会触发文件变更的回调函数，为了验证，我可以在 ReadDirectoryChangesCallback 方法中下一个断点，再丢一个日志文件到根目录，看是否能触发就知道了。。。截图如下：
回到本案例，也就是说一旦有日志变动，就会触发 3.4w 个回调函数，如果变动100次，就会触发 340w 次回调，而日志变更不停止，自然就会因为海量的回调把程序搞死。。。对吧。。。
四：总结
本次事故可能是由于朋友偷懒，没有将 Configuration 或 IOptions 注下去，而是采用重新构建 ConfigurationRoot 的方式获取 ConnectionString，并错误的配置 reloadOnChange: true， 导致IO线程无法及时处理由于日志文件的变更导致的海量回调函数，进而导致程序挂死。
知道整个来龙去脉之后，优化措施就很简单了，提供两种方法。
将
reloadOnChange: true改成reloadOnChange: false。想办法将 Configuration 注入到 DataBaseConfig 类中，做成静态变量也行 。😁😁😁
最后上一个彩蛋，朋友太客气了。
END
工作中的你，是否已遇到 ...
1. CPU爆高
2. 内存暴涨
3. 资源泄漏
4. 崩溃死锁
5. 程序呆滞
等紧急事件，全公司都指望着你能解决... 危难时刻才能展现你的技术价值，作为专注于.NET高级调试的技术博主，欢迎微信搜索: 一线码农聊技术，免费协助你分析Dump文件，希望我能将你的踩坑经验分享给更多的人。
记一次.net某上市工业智造cpu+内存+挂死三高分析(代码片段)
一：背景1.讲故事上个月有位朋友加wx告知他的程序有挂死现象，询问如何进一步分析，截图如下：看这位朋友还是有一定的分析基础，可能玩的少，缺乏一定的分析经验，当我简单分析之后，我发... 查看详情
记一次.net某新能源汽车锂电池检测程序ui挂死分析(代码片段)
一：背景1.讲故事这世间事说来也奇怪，近两个月有三位朋友找到我，让我帮忙分析下他的程序hangon现象，这三个dump分别涉及：医疗，新能源，POS系统。截图如下：那这篇为什么要拿其中的新能源... 查看详情
记一次.net某工控mes程序崩溃分析(代码片段)
一：背景1.讲故事前几天有位朋友找到我，说他的程序出现了偶发性崩溃，已经抓到了dump文件，Windows事件日志显示的崩溃点在clr.dll中，让我帮忙看下是怎么回事，那到底怎么回事呢?上WinDbg说话。二：W... 查看详情
记一次.net某云采购平台api挂死分析(代码片段)
一：背景1.讲故事大概有两个月没写博客了，关注我的朋友应该知道我最近都把精力花在了星球，这两个月时间也陆陆续续的有朋友求助如何分析dump，有些朋友太客气了，给了大大的红包，哈哈????，手... 查看详情
记一次.net某车零件mes系统登录异常分析
一：背景1.讲故事这个案例有点特殊，以前dump分析都是和软件工程师打交道，这次和非业内人士交流，隔行如隔山，从指导dump怎么抓到问题解决，需要一个强大的耐心。前几天有位朋友在微信上找到我，说他们公司采购的MES系... 查看详情
记一次.net某电厂web系统内存泄漏分析
一：背景1.讲故事前段时间有位朋友找到我，说他的程序内存占用比较大，寻求如何解决，截图就不发了，分析下来我感觉除了程序本身的问题之外，.NET5在内存管理方面做的也不够好，所以有必要给大家分享一下。二：WinDbg分... 查看详情
记一次.net某新能源系统线程疯涨分析
一：背景1.讲故事前段时间收到一个朋友的求助，说他的程序线程数疯涨，寻求如何解决。等我分析完之后，我觉得这个问题很有代表性，所以拿出来和大家分享下，还是上老工具WinDbg。二：WinDbg分析1.线程真的在疯涨吗要想查... 查看详情
记一次.net某智能服装智造系统内存泄漏分析(代码片段)
一：背景1.讲故事上个月有位朋友找到我，说他的程序出现了内存泄漏，不知道如何进一步分析，截图如下：朋友这段话已经说的非常言简意赅了，那就上windbg说话吧。二：Windbg分析1.到底是哪一方面的泄漏根据朋友描述，程序... 查看详情
记一次.net某新能源系统线程疯涨分析(代码片段)
一：背景1.讲故事前段时间收到一个朋友的求助，说他的程序线程数疯涨，寻求如何解决。等我分析完之后，我觉得这个问题很有代表性，所以拿出来和大家分享下，还是上老工具WinDbg。二：WinDbg分析1.... 查看详情
记一次.net某智慧水厂api非托管内存泄漏分析(代码片段)
一：背景1.讲故事七月底的时候有位朋友在wx上找到我，说他的程序内存占用8G，托管才占用1.5G，询问剩下的内存哪里去了？截图如下：从求助内容看，这位朋友真的太客气了，动不动就谈钱，... 查看详情
记一次.net某智慧物流wcs系统cpu爆高分析
一：背景1.讲故事哈哈，再次见到物流类软件，上个月有位朋友找到我，说他的程序出现了CPU爆高，让我帮忙看下什么原因，由于那段时间在苦心研究C++，分析和经验分享也就懈怠了，今天就给大家安排上。话不多说，上windbg说... 查看详情
记一次.net某工控自动化控制系统卡死分析(代码片段)
一：背景1.讲故事前段时间遇到了好几起关于窗体程序的进程加载锁引发的程序卡死和线程暴涨问题，这种dump分析难度较大，主要涉及到Windows操作系统和C++的基础知识，所以有必要简单整理和大家分享一下&... 查看详情
记一次.net某流媒体独角兽api句柄泄漏分析(代码片段)
一：背景1.讲故事上上周有位朋友找到我，说他的程序CPU和句柄都在不断的增长，无回头趋势，查了好些天也没什么进展，特加wx寻求帮助，截图如下：看的出来这位朋友也是非常郁闷，出问题还出... 查看详情
记一次.net某wms仓储打单系统内存暴涨分析(代码片段)
一：背景1.讲故事七月中旬有一位朋友加wx求助，他的程序在生产上跑着跑着内存就飙起来了，貌似没有回头的趋势，询问如何解决，截图如下：和这位朋友聊下来，感觉像是自己在小县城当了个小老板... 查看详情
记一次.net某医疗住院系统崩溃分析(代码片段)
一：背景1.讲故事最近收到了两起程序崩溃的dump，查了下都是经典的doublefree造成的，蛮有意思，这里就抽一篇出来分享一下经验供后面的学习者避坑吧。二：WinDbg分析1.崩溃点在哪里windbg带了一个自动化分析... 查看详情
记一次.net某消防物联网后台服务内存泄漏分析
一：背景1.讲故事去年十月份有位朋友从微信找到我，说他的程序内存要炸掉了。。。截图如下：时间有点久，图片都被清理了，不过有点讽刺的是，自己的程序本身就是做监控的，结果自己出了问题，太尴尬了 查看详情
记一次.net某消防物联网后台服务内存泄漏分析
一：背景1.讲故事去年十月份有位朋友从微信找到我，说他的程序内存要炸掉了。。。截图如下：时间有点久，图片都被清理了，不过有点讽刺的是，自己的程序本身就是做监控的，结果自己出了问题，太尴尬了 查看详情
记一次.net某电厂web系统内存泄漏分析(代码片段)
一：背景1.讲故事前段时间有位朋友找到我，说他的程序内存占用比较大，寻求如何解决，截图就不发了，分析下来我感觉除了程序本身的问题之外，.NET5在内存管理方面做的也不够好，所以有必要给大... 查看详情