Write it down once Net a new energy system thread surge analysis

One ： background

1. Tell a story

I received a friend's help some time ago , Said the number of threads in his program soared , Find out how to solve .

After my analysis , I think this question is very representative , So take it out and share it with you , Or old tools WinDbg.

Two ： WinDbg analysis

1. Are threads really soaring

To check whether the thread has soared , It can be used !t Order to have a look .

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) 

From the divination , The main thread is a STA, Description is a form program , A form can do 387 Threads , It's also very awesome , It can also be observed that most of them are ThreadPool Worker , That is, thread pool worker thread .

2. What are these threads doing

Here's a tip , That is, the larger the thread number , They are often newly created , Often you can get some useful things out of this , Just pick up the implication 380 ~ 387 The call stack of these threads .

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

From the thread stack , These threads are UnfairSemaphore Waiting for , This is a normal phenomenon , Because these threads are through UnfairSemaphore Lock to wake up , But strangely enough , Why do these threads occur , Why not die ？

According to experience, predict ： There must be code constantly scheduling Thread pool Threads , Then I did a short-lived operation , As a result, threads in the thread pool are constantly added , There is no threshold at which threads can die .

3. Is the program really scheduling threads frequently

Since the guess is that the program is calling the thread pool thread frequently , What we can do is to observe this moment dump Thread stack of all threads in , See if you can find something valuable , have access to ~*e !clrstack command .

After careful observation, this near 400 A thread stack , Found to have 37 Everywhere System.Threading.Thread.Sleep(Int32), And most of them are HslCommunication.Core.Net.NetworkBase.ThreadPoolCheckTimeOut(System.Object) function , You can clearly see that it is initiated by the thread pool , The next step is to use ILSpy Decompile this function to see what's going on .

        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;
                }
            }
        }

Next through ILSpy Check the reference of this method , I found many places , Take a few as follows ：

        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);
            ...
        }

From the code above , There are indeed some areas for discussion , A great deal of socket Operations are handled by thread pools ThreadPoolCheckTimeOut() function , And in this function, when hslTimeOut.IsSuccessful =false When , stay if ((DateTime.Now - hslTimeOut.StartTime).TotalMilliseconds > (double)hslTimeOut.DelayTime) There will always be sleep, This leads to when socket After the request quantity goes up , Many threads are in sleep state , The thread pool has to generate more threads to process ThreadPoolCheckTimeOut() Logic .

Here we finally found a match Thread pool thread The soaring underlying logic , So let's see HslCommunication.dll What is it , Look for its class library declaration .

[assembly: CompilationRelaxations(8)]
[assembly: RuntimeCompatibility(WrapNonExceptionThrows = true)]
[assembly: Debuggable(DebuggableAttribute.DebuggingModes.IgnoreSymbolStoreSequencePoints)]
[assembly: AssemblyTitle("HslCommunication")]
[assembly: AssemblyDescription(" A framework library , It includes perfect network communication and log components ")]
[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")]

You can see , This is a commercial component .

3、 ... and ： summary

It is suspected that HslCommunication Problems with components , After a look, I still Business Edition , This is awkward , The suggested solution is as follows ：

1） short-term ：

use ThreadPool.SetMaxThreads Limit the thread limit .

2） long-term ：

Find the author to see if there is the latest version , Or to https://github.com/dathlin/HslCommunication Bring up one issue, Let others solve it systematically .