共计 4943 个字符，预计需要花费 13 分钟才能阅读完成。
一：背景
1. 讲故事
去年阿里聚石塔上的所有 isv 短信通道全部对接阿里通信，我们就做了对接改造，使用阿里提供的.net sdk。
网址：https://help.aliyun.com/docum…
同事当时使用的是 ons-.net v1.1.3 版本，程序上线后若干天就会有一次程序崩溃现象，当时也没特别在意，以为是自己代码或者环境出了什么问题，索性就加了一个检测程序，如果检测到 sdk 程序退出就自动重启，就这样先糊弄着，直到有一天服务器告警，那个程序 CPU 居然飙到 100%，服务器可是 16 核 128G 的哦。。。
二：分析问题
1. 抓 dump 文件
情况比较紧急，马上给程序发送 Ctrl+ C 命令让程序退出，结果又退出不了，奇葩。。。为了分析问题抓了一个 dump 下来，然后强制 kill 掉程序。
2. 查看线程池以及各个线程正在做什么？
0:000> !tp
CPU utilization: 100%
Worker Thread: Total: 0 Running: 0 Idle: 0 MaxLimit: 32767 MinLimit: 16
Work Request in Queue: 0
--------------------------------------
Number of Timers: 1
--------------------------------------
Completion Port Thread:Total: 1 Free: 1 MaxFree: 32 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 16
从 CPU utilization: 100% 上看，果然 cpu100% 了，发现 Worker Thread 没有 Running 线程，可能是因为执行了 Ctrl+C 都销毁了，接下来用 ~*e !clrstack 把所有的托管线程栈打出来。
0:000> ~*e !clrstack
OS Thread Id: 0x1818 (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
从输出结果看，没有任何托管线程，唯一的那个线程 0 还不是还托管线程，然后改成 ~*e !dumpstack把非托管线程栈找出来。
0:000> ~*e !dumpstack
OS Thread Id: 0x1818 (0)
Current frame: ntdll!ZwRemoveIoCompletion+0x14
Child-SP RetAddr Caller, Callee
000000637323ef40 00007ff8327bac2f KERNELBASE!GetQueuedCompletionStatus+0x3f, calling ntdll!ZwRemoveIoCompletion
000000637323efa0 00007ff81b9c8a00 ONSClient4CPP!metaq_juce::URL::launchInDefaultBrowser+0x273d0, calling kernel32!GetQueuedCompletionStatus
000000637323f090 00007ff81ba3eb0a ONSClient4CPP!ons::Message::getMsgBody+0x5a8a, calling ONSClient4CPP!metaq_juce::URL::launchInDefaultBrowser+0x1f100
000000637323f140 00007ff81ba3f084 ONSClient4CPP!ons::Message::getMsgBody+0x6004, calling ONSClient4CPP!ons::Message::getMsgBody+0x5800
000000637323f280 00007ff81ba233b4 ONSClient4CPP!ons::ONSFactoryProperty::setSendMsgTimeout+0xa6b4, calling ONSClient4CPP!ons::ONSFactoryProperty::setSendMsgTimeout+0xa5d0
000000637323f2b0 00007ff81ba11b43 ONSClient4CPP!ons::ONSFactoryAPI::~ONSFactoryAPI+0x153
000000637323f310 00007ff81ba12d64 ONSClient4CPP!ons::SendResultONS::operator=+0xc44, calling ONSClient4CPP!ons::ONSFactoryAPI::~ONSFactoryAPI+0x10
000000637323f460 00007ff81ba83eb4 ONSClient4CPP!ons::Message::getStoreTimestamp+0xf484, calling ONSClient4CPP!ons::Message::getStoreTimestamp+0xf1c4
000000637323f630 00007ff8356f7d94 ntdll!RtlExitUserProcess+0xb4, calling ntdll!LdrShutdownProcess
000000637323f690 00007ff832777c23 KERNELBASE!CtrlRoutine+0xa3
000000637323f780 00007ff834df8364 kernel32!BaseThreadInitThunk+0x14, calling kernel32!WriteConsoleOutputW+0x530
从非托管调用栈来看，其中 KERNELBASE!CtrlRoutine 表明主线程接受到了Ctrl+C 命令，从栈顶发现貌似不能退出的原因是主线程被 ONSClient4CPP 接管，而且这个 C ++ 正在做远程连接再等待网络 IO 返回，但这种会把 16 核 cpu 打满应该不太可能，这个问题貌似到这里就卡住了。
三：重启程序发现问题依旧
1. 抓 dump 文件
很开心的是程序重新启动后，过了两分钟 CPU 又在飙升，这次学乖了，等 CPU 到了 60，70% 的时候抓 dump 文件。
2. 继续排查
0:000> .time
Debug session time: Fri Apr 17 17:36:50.000 2020 (UTC + 8:00)
System Uptime: 355 days 5:33:48.092
Process Uptime: 0 days 0:02:11.000
Kernel time: 0 days 0:03:31.000
User time: 0 days 0:13:22.000
0:000> !tp
CPU utilization: 59%
Worker Thread: Total: 3 Running: 0 Idle: 3 MaxLimit: 32767 MinLimit: 16
Work Request in Queue: 0
--------------------------------------
Number of Timers: 1
--------------------------------------
Completion Port Thread:Total: 2 Free: 2 MaxFree: 32 CurrentLimit: 2 MaxLimit: 1000 MinLimit: 16
从上面代码可以看到，进程启动了 2 分 11 秒，这次 cpu 利用率是 59%，抓的有点早，不过没关系，先看一下 Threads 情况。
0:000> !threads
ThreadCount: 25
UnstartedThread: 0
BackgroundThread: 8
PendingThread: 0
DeadThread: 16
Hosted Runtime: no
Lock
ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception
0 1 cdc 0000022bb9f53220 2a020 Preemptive 0000022BBBFACCE8:0000022BBBFADFD0 0000022bb9f27dc0 1 MTA
2 2 3dc 0000022bb9f7f9f0 2b220 Preemptive 0000000000000000:0000000000000000 0000022bb9f27dc0 0 MTA (Finalizer)
3 4 296c 0000022bb9fe97b0 102a220 Preemptive 0000000000000000:0000000000000000 0000022bb9f27dc0 0 MTA (Threadpool Worker)
XXXX 5 0 0000022bb9ffc5a0 1039820 Preemptive 0000000000000000:0000000000000000 0000022bb9f27dc0 0 Ukn (Threadpool Worker)
XXXX 6 0 0000022bd43938c0 1039820 Preemptive 0000000000000000:0000000000000000 0000022bb9f27dc0 0 Ukn (Threadpool Worker)
.............................................................................
163 24 29e8 0000022bd4898650 1029220 Preemptive 0000022BBC102108:0000022BBC103FD0 0000022bb9f27dc0 0 MTA (Threadpool Worker)
164 25 2984 0000022bd489d470 1029220 Preemptive 0000022BBC0EA2D0:0000022BBC0EBFD0 0000022bb9f27dc0 0 MTA (Threadpool Worker)
好家伙，才 2 分 11 秒，托管线程 ThreadCount: 25 就死了 DeadThread: 16 个，而且从 threads 列表中看，windbg 给的最大编号是 164，说明当前有 (164+1) - 25 =142 个非托管线程，应该就是阿里的 ONSClient4CPP 开启的，为什么开启这么多线程，这就是一个很值得关注的问题了，接下来还是用 ~*e !dumpstack 把所有线程的托管和非托管线程栈打出来，由于信息太多，我就截几张图。
<font color=”red” style=”font-size:large”> 个人猜测，纯技术讨论：</font>
图 1：
从堆栈上看，有 105 个线程卡在 ntdll!ZwRemoveIoCompletion+0x14 这里，而且从 ONSClient4CPP!metaq_juce::URL::launchInDefaultBrowser+0x23072 中看，貌似阿里开了一个浏览器内核，用内核来发送数据，估计这里并发阈值开的还挺大的，咨询了下同事是前面有一家大客户发了很多的短信，<font color=”red”> 估计是大量的回持积压 </font>，这个 C# sdk 进行了疯狂读取，这个跟 CPU 暴涨应该有脱不了的关系。
图 2：
从检索上看有 28 个线程貌似正在临界区等待锁，CPU 高的一个经典案例就是当很多线程在临界区等待的时候，当某一个正在临界区中的线程离开后，这 28 个线程的调度竞抢也是 CPU 高的一个原因。
个人水平有限，进一步挖非托管堆目前还没这个技术(┬_┬)。。。
四：解决方案
这种 SDK 的问题还能有什么解决方案，能想到的就是去官网找下可有最新版：
可以看到最新版的 ons-.net v1.1.4 中提到的优化点：<font color=”red”> 优化消息拉取流程，避免特殊情况下拉取异常造成的消息堆积 </font>。
果然用了最新版的 sdk 就可以了，??。
