联博以太坊高度:阿里短信回执.net sdk的bug导致生产服务cpu 100%排查

admin 4个月前 (05-27) 科技 38 0

一:靠山

1. 讲故事

去年阿里聚石塔上的所有isv短信通道所有对接阿里通讯,我们就做了对接革新,使用阿里提供的.net sdk

网址:https://help.aliyun.com/document_detail/114480.html

同事那时使用的是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 把所有线程的托管和非托管线程栈打出来,由于信息太多,我就截几张图。

小我私家预测,纯手艺讨论:

图1:

从客栈上看,有105个线程卡在 ntdll!ZwRemoveIoCompletion+0x14 这里,而且从 ONSClient4CPP!metaq_juce::URL::launchInDefaultBrowser+0x23072 中看,貌似阿里开了一个浏览器内核,用内核来发送数据,估量这里并发阈值开的还挺大的,咨询了下同事是前面有一家大客户发了许多的短信,估量是大量的回持积压,这个C# sdk进行了疯狂读取,这个跟CPU暴涨应该有脱不了的关系。

图2:

从检索上看有28个线程貌似正在临界区守候锁,CPU高的一个经典案例就是当许多线程在临界区守候的时刻,当某一个正在临界区中的线程脱离后,这28个线程的调剂竞抢也是CPU高的一个缘故原由。

小我私家水平有限,进一步挖非托管堆现在还没这个手艺(┬_┬) 。。。

四: 解决方案

这种SDK的问题还能有什么解决方案,能想到的就是去官网找下可有最新版:

可以看到最新版的 ons-.net v1.1.4 中提到的优化点:优化新闻拉取流程,制止特殊情形下拉取异常造成的新闻聚积

果真用了最新版的sdk就可以了,。

如您有更多问题与我互动,扫描下方进来吧~

联博以太坊高度:阿里短信回执.net sdk的bug导致生产服务cpu 100%排查 第1张,

Allbet

www.szqygww.com欢迎进入欧博开户平台(Allbet Gaming),欧博开户平台开放欧博(Allbet)开户、欧博(Allbet)代理开户、欧博(Allbet)电脑客户端、欧博(Allbet)APP下载等业务

AllBetGaming声明:该文看法仅代表作者自己,与本平台无关。转载请注明:联博以太坊高度:阿里短信回执.net sdk的bug导致生产服务cpu 100%排查

网友评论

  • (*)

最新评论

文章归档

站点信息

  • 文章总数:779
  • 页面总数:0
  • 分类总数:8
  • 标签总数:1285
  • 评论总数:468
  • 浏览总数:31839