• 记一次 .NET 某新能源系统 线程疯涨 分析


    一:背景

    1. 讲故事

    前段时间收到一个朋友的求助,说他的程序线程数疯涨,寻求如何解决。

    等我分析完之后,我觉得这个问题很有代表性,所以拿出来和大家分享下,还是上老工具 WinDbg。

    二: WinDbg 分析

    1. 线程真的在疯涨吗

    要想查线程有没有疯涨,可以用 !t 命令看一下。

    
    0:000:x86> !t
    ThreadCount:      382
    UnstartedThread:  1
    BackgroundThread: 376
    PendingThread:    0
    DeadThread:       2
    Hosted Runtime:   no
                                                                             Lock  
           ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
       0    1  59c 00e52fb0     26020 Preemptive  12D67610:00000000 00e4b408 0     STA 
       2    2 2b30 00e61aa0     2b220 Preemptive  00000000:00000000 00e4b408 0     MTA (Finalizer) 
       3    3 18cc 00ea72b8   202b220 Preemptive  00000000:00000000 00e4b408 0     MTA 
       5    4 1f18 00f02998   1020220 Preemptive  00000000:00000000 00e4b408 0     Ukn (Threadpool Worker) 
    XXXX    6    0 00f056f8     39820 Preemptive  00000000:00000000 00e4b408 0     MTA 
       6    7 2154 09052448   202b020 Preemptive  12E353E0:00000000 00e4b408 0     MTA 
       ...
     377  373 2ee8 21a90958   1029220 Preemptive  12D1FCCC:00000000 00e4b408 0     MTA (Threadpool Worker) 
     378  374 227c 21b1d510   1029220 Preemptive  12DCBFC8:00000000 00e4b408 0     MTA (Threadpool Worker) 
     379  375  7e8 21b1baa8   1029220 Preemptive  12D39ADC:00000000 00e4b408 0     MTA (Threadpool Worker) 
     380  376 1d1c 21a8fec8   1029220 Preemptive  12D11F40:00000000 00e4b408 0     MTA (Threadpool Worker) 
     381  366 19ec 215c1bd0   1029220 Preemptive  12DB42D8:00000000 00e4b408 0     MTA (Threadpool Worker) 
     382  377 1dc8 21b1bff0   1029220 Preemptive  12C71F9C:00000000 00e4b408 0     MTA (Threadpool Worker) 
     383  378  f94 215bc750   1029220 Preemptive  12E10568:00000000 00e4b408 0     MTA (Threadpool Worker) 
     384  379 17d4 21ac5580   1029220 Preemptive  12D8EE98:00000000 00e4b408 0     MTA (Threadpool Worker) 
     385  381 2c1c 21b1b018   1029220 Preemptive  12D0DD00:00000000 00e4b408 0     MTA (Threadpool Worker) 
     386  380 309c 21b1da58   1029220 Preemptive  12E25028:00000000 00e4b408 0     MTA (Threadpool Worker) 
     387  382 3048 21ac6aa0   1029220 Preemptive  12DFA918:00000000 00e4b408 0     MTA (Threadpool Worker) 
    

    从卦中看,主线程是一个 STA,说明是一个窗体程序,一个窗体能做到 387 个线程,也是挺牛的,同时也能观察到大多都是 ThreadPool Worker ,也就是线程池工作线程。

    2. 这些线程都在干嘛

    这里有一个小技巧,那就是线程号越大,往往都是最新创建的,往往从这里面就能套出来一些有用的东西,言外之意就扒一扒 380 ~ 387 这些线程的调用栈。

    
    0:387:x86> ~387s
    ntdll_77380000!NtWaitForSingleObject+0xc:
    773f29dc c20c00          ret     0Ch
    0:387:x86> k
    CvRegToMachine(x86) conversion failure for 0x14f
    X86MachineInfo::SetVal: unknown register 0 requested
     # ChildEBP RetAddr      
    00 31fef104 755a1539     ntdll_77380000!NtWaitForSingleObject+0xc
    01 31fef104 74b3ee3b     KERNELBASE!WaitForSingleObjectEx+0x99
    02 31fef168 74b3efed     clr!CLRSemaphore::Wait+0xbe
    03 31fef19c 74b3eee2     clr!ThreadpoolMgr::UnfairSemaphore::Wait+0x13a
    04 31fef204 74a54c27     clr!ThreadpoolMgr::WorkerThreadStart+0x328
    05 31feff24 7649fa29     clr!Thread::intermediateThreadProc+0x58
    06 31feff34 773e7a7e     kernel32!BaseThreadInitThunk+0x19
    07 31feff90 773e7a4e     ntdll_77380000!__RtlUserThreadStart+0x2f
    0:387:x86> ~386s
    ntdll_77380000!NtWaitForSingleObject+0xc:
    773f29dc c20c00          ret     0Ch
    0:386:x86> k
    CvRegToMachine(x86) conversion failure for 0x14f
    X86MachineInfo::SetVal: unknown register 0 requested
     # ChildEBP RetAddr      
    00 31d6ede4 755a1539     ntdll_77380000!NtWaitForSingleObject+0xc
    01 31d6ede4 74b3ee3b     KERNELBASE!WaitForSingleObjectEx+0x99
    02 31d6ee48 74b3efed     clr!CLRSemaphore::Wait+0xbe
    03 31d6ee7c 74b3eee2     clr!ThreadpoolMgr::UnfairSemaphore::Wait+0x13a
    04 31d6eee4 74a54c27     clr!ThreadpoolMgr::WorkerThreadStart+0x328
    05 31d6fb84 7649fa29     clr!Thread::intermediateThreadProc+0x58
    06 31d6fb94 773e7a7e     kernel32!BaseThreadInitThunk+0x19
    07 31d6fbf0 773e7a4e     ntdll_77380000!__RtlUserThreadStart+0x2f
    0:386:x86> ~385s
    ntdll_77380000!NtWaitForSingleObject+0xc:
    773f29dc c20c00          ret     0Ch
    0:385:x86> k
    CvRegToMachine(x86) conversion failure for 0x14f
    X86MachineInfo::SetVal: unknown register 0 requested
     # ChildEBP RetAddr      
    00 31eaee64 755a1539     ntdll_77380000!NtWaitForSingleObject+0xc
    01 31eaee64 74b3ee3b     KERNELBASE!WaitForSingleObjectEx+0x99
    02 31eaeec8 74b3efed     clr!CLRSemaphore::Wait+0xbe
    03 31eaeefc 74b3eee2     clr!ThreadpoolMgr::UnfairSemaphore::Wait+0x13a
    04 31eaef64 74a54c27     clr!ThreadpoolMgr::WorkerThreadStart+0x328
    05 31eafb7c 7649fa29     clr!Thread::intermediateThreadProc+0x58
    06 31eafb8c 773e7a7e     kernel32!BaseThreadInitThunk+0x19
    07 31eafbe8 773e7a4e     ntdll_77380000!__RtlUserThreadStart+0x2f
    
    

    从线程栈上看,这些线程都在 UnfairSemaphore 处等待,这是一个正常现象,因为这些线程都是通过 UnfairSemaphore 锁来唤醒,不过奇怪的是,这些线程为什么产生,又为什么不被消亡?

    根据经验预测:肯定有代码在不断的调度 线程池 线程,然后又做了一个短命的操作,导致线程池线程不断新增,又得不到线程可以被消亡的阈值。

    3. 程序真的在频繁调度线程吗

    既然猜测是程序在频繁的调用线程池线程,能做的只能是观察此时 dump 中的所有线程的线程栈,看能不能挖到点有价值的东西,可以使用 ~*e !clrstack 命令。

    经过仔细观察这近400个线程栈,发现有 37 处都是 System.Threading.Thread.Sleep(Int32), 而且大多都是 HslCommunication.Core.Net.NetworkBase.ThreadPoolCheckTimeOut(System.Object) 函数,能清楚的看到是由线程池发起的,接下来就是用 ILSpy 反编译下这个函数看下到底是怎么回事。

    
            protected void ThreadPoolCheckTimeOut(object obj)
            {
                HslTimeOut hslTimeOut;
                if ((hslTimeOut = obj as HslTimeOut) == null)
                {
                    return;
                }
                while (!hslTimeOut.IsSuccessful)
                {
                    Thread.Sleep(100);
                    if ((DateTime.Now - hslTimeOut.StartTime).TotalMilliseconds > (double)hslTimeOut.DelayTime)
                    {
                        if (!hslTimeOut.IsSuccessful)
                        {
                            LogNet?.WriteWarn(ToString(), "Wait Time Out : " + hslTimeOut.DelayTime);
                            hslTimeOut.Operator?.Invoke();
                            hslTimeOut.WorkSocket?.Close();
                        }
                        break;
                    }
                }
            }
    
    

    接下来通过 ILSpy 查看这个方法的引用,发现有很多处,抽几个如下:

    
            protected OperateResult<TNetMessage> ReceiveMessage<TNetMessage>(Socket socket, int timeOut, TNetMessage netMsg) where TNetMessage : INetMessage
            {
                ...
                if (timeOut > 0)
                {
                    ThreadPool.QueueUserWorkItem(ThreadPoolCheckTimeOut, hslTimeOut);
                }
                ...
            }
    
            protected OperateResult<Socket> CreateSocketAndConnect(IPEndPoint endPoint, int timeOut)
            {
                ...
                ThreadPool.QueueUserWorkItem(ThreadPoolCheckTimeOut, hslTimeOut);
                ...
            }
    
            protected void CreateSocketAndConnect(IPEndPoint endPoint, int timeOut, Action<OperateResult<Socket>> connectCallback)
            {
                ...
                ThreadPool.QueueUserWorkItem(ThreadPoolCheckTimeOut, hslTimeOut);
                ...
            }
    
    

    从上面代码看,确实存在一些商榷的地方,很多的 socket 操作都用线程池来处理 ThreadPoolCheckTimeOut() 函数,而在这个函数内当 hslTimeOut.IsSuccessful =false 的时候,在 if ((DateTime.Now - hslTimeOut.StartTime).TotalMilliseconds > (double)hslTimeOut.DelayTime) 不满足的时间区间内会一直 sleep,这就导致当 socket 请求量上去后,导致很多线程处于 sleep 状态, 线程池又不得不生成更多的线程来处理 ThreadPoolCheckTimeOut() 逻辑。

    到这里终于就找到了符合 线程池线程 疯涨的底层逻辑,接下来看看 HslCommunication.dll 为何物,去找一下它的类库声明。

    
    [assembly: CompilationRelaxations(8)]
    [assembly: RuntimeCompatibility(WrapNonExceptionThrows = true)]
    [assembly: Debuggable(DebuggableAttribute.DebuggingModes.IgnoreSymbolStoreSequencePoints)]
    [assembly: AssemblyTitle("HslCommunication")]
    [assembly: AssemblyDescription("一个框架库,包含完善的网络通信及日志组件")]
    [assembly: AssemblyConfiguration("")]
    [assembly: AssemblyCompany("")]
    [assembly: AssemblyProduct("HslCommunication")]
    [assembly: AssemblyCopyright("Copyright © By Richard.Hu 2018")]
    [assembly: AssemblyTrademark("")]
    [assembly: ComVisible(false)]
    [assembly: Guid("d3710b78-1b32-4d53-9604-0451a795a2f5")]
    [assembly: AssemblyFileVersion("5.3.2.0")]
    [assembly: AssemblyVersion("5.3.2.0")]
    
    

    可以看到,这是一个商业组件。

    三:总结

    由于定位到疑似是 HslCommunication 组件的问题,看了下还是 商业版 , 这就尴尬了,建议的解决办法如下:

    1) 短期:

    ThreadPool.SetMaxThreads 限定线程上限。

    2) 长期:

    找作者看看有没有最新版,或者到 https://github.com/dathlin/HslCommunication 上提一个 issue,让别人系统性解决一下。

    图片名称
  • 相关阅读:
    【原】一张图片优化5K的带宽成本
    让手机站点像原生应用的四大途径
    iScroll4下表单元素聚焦及键盘的异常问题
    蜕变·WebRebuild 2013 前端年度交流会邀请
    【原】js实现复制到剪贴板功能,兼容所有浏览器
    【原】css实现两端对齐的3种方法
    【原】常见CSS3属性对ios&android&winphone的支持
    一枚前端开发-页面重构方向的招聘信息
    【原】分享超实用工具给大家
    【原】webapp开发中兼容Android4.0以下版本的css hack
  • 原文地址:https://www.cnblogs.com/huangxincheng/p/16453897.html
Copyright © 2020-2023  润新知