An analysis of the CPU explosion of an intelligent transportation background service in.Net

One ： background

1. Tell a story

The day before yesterday, a friend added wechat to ask for help. His program appeared CPU The problem of explosion height , The start is a red envelope , It scared me out of my mind ！

Because it is a small year in the South , It's inconvenient for me to deal with it in my hometown , I didn't help him deal with it at the first time , My friend found out the problem the next morning , Feedback said it was a  while(true)  As a result of , It's kind of interesting , In my analysis of many CPU In the case of high explosion , I really haven't met  while(true)   The situation of , Always have regrets , Good luck , I caught up with , ha-ha .

Next we use windbg Let's analyze it together .

Two ：Windbg analysis

1. see CPU Occupancy rate

My friends who have been following me know , use  !tp  Just order .

0:022> !tp
CPU utilization: 95 Unknown format characterUnknown format control characterWorker Thread: Total: 11 Running: 11 Idle: 0 MaxLimit: 32767 MinLimit: 4
Work Request in Queue: 0
--------------------------------------
Number of Timers: 3
--------------------------------------
Completion Port Thread:Total: 4 Free: 4 MaxFree: 8 CurrentLimit: 4 MaxLimit: 1000 MinLimit: 4

There is a sentence on it  Unknown format characterUnknown format control characterWorker  It's not very harmonious , In fact, that is  %  It means , I don't know why .NETCore There will be such coding problems , Next we use  !eeversion  to glance at .

0:022> !eeversion
4.700.21.56803 (3.x runtime) free
4,700,21,56803 @Commit: 28bb6f994c28bc91f09bc0ddb5dcb51d0f066806
Workstation mode
In plan phase of garbage collection
SOS Version: 5.0.4.36902 retail build

From the basic information , Now it's  .netcore 3.x  edition , And it's obvious that at present GC In the planning stage . What is the planning stage ？

2. What is the planning stage

In short , At the planning stage GC You need to decide that the current managed heap is simply marked free operation , Or do the heavyweight compression operation , If you want to compress , It also needs to involve the relocation of managed heap objects , This tends to cost quite a lot CPU Time slice , The next step is to explore what causes GC Trigger ？

3. GC trigger

because GC The trigger of is often User threads Caused by the allocation of data , stay GC In the whole execution flow triggered , One of them is freezing  CLR Execution engine , That is to say  SuspendEE, Can be in  gc.app  Middle school 1 .

Why do we have to mention  SuspendEE  Well ？ Because I can pass  !t -special  Find that  SuspendEE  The thread of , This is more accurate .

0:072> !t -special
ThreadCount:      54
UnstartedThread:  0
BackgroundThread: 40
PendingThread:    0
DeadThread:       1
Hosted Runtime:   no

          OSID Special thread type
        1 6328 DbgHelper 
        2 35c0 Finalizer 
        4 5aac Timer 
        5 38b0 ThreadpoolWorker 
       17 3530 ThreadpoolWorker 
       18 4484 ThreadpoolWorker 
       19 1e4c ThreadpoolWorker 
       21 6380 ThreadpoolWorker 
       44 5bc4 SuspendEE 
       52  8ac ThreadpoolWorker 
       54 4164 ThreadpoolWorker 
       56 61c8 ThreadpoolWorker 
       58 1fa4 ThreadpoolWorker 
       60 2788 ThreadpoolWorker 
       69 48f4 IOCompletion 
       70 5708 IOCompletion 
       71 3b58 ThreadpoolWorker 
       72 17a0 GC 
       73 2f00 Gate 
       74 35e8 IOCompletion 
       75 5730 IOCompletion 

You can see the current  44  Thread number is the trigger GC The thread of , Then it becomes clear , have a look 44 What is thread number doing ？ Cut to 44 Number thread , then  !clrstack  that will do .

0:044> !clrstack 
OS Thread Id: 0x5bc4 (44)
        Child SP               IP Call Site
000000A2B0C3E4C8 00007ffd471ead3a [HelperMethodFrame: 000000a2b0c3e4c8] 
000000A2B0C3E5E0 00007ffce8b4e506 System.Collections.Generic.List`1[[System.__Canon, System.Private.CoreLib]].System.Collections.Generic.IEnumerable.GetEnumerator() [/_/src/System.Private.CoreLib/shared/System/Collections/Generic/List.cs @ 585]
000000A2B0C3E630 00007ffce85e7a10 xxx.Program.DeletexxxExipredDate()
000000A2B0C3E780 00007ffd46bc1f0b System.Threading.ThreadHelper.ThreadStart_Context(System.Object) [/_/src/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 44]
000000A2B0C3E7B0 00007ffd46bb90b6 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 172]
000000A2B0C3E830 00007ffd46ba535b System.Threading.ThreadHelper.ThreadStart() [/_/src/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 93]
000000A2B0C3EA48 00007ffd47236c93 [GCFrame: 000000a2b0c3ea48] 
000000A2B0C3ECB0 00007ffd47236c93 [DebuggerU2MCatchHandlerFrame: 000000a2b0c3ecb0] 

From the output information , Here's the problem  DeletexxxExipredDate()  Method , Next, explore the source code of this method .

        private static void DeletexxxExipredDate()
        {
            while (true)
            {
                foreach (string key in xxx.xxxSpeedLimit.Keys)
                {
                    try
                    {
                        string[] array = xxx.xxxSpeedLimit[key].Split('$');
                        if (array.Length > 1)
                        {
                            DateTime dateTime = Convert.ToDateTime(array[1]);
                            if ((DateTime.Now - dateTime).TotalSeconds > 21600.0 && xxx.xxxSpeedLimit.ContainsKey(key))
                            {
                                xxx.xxxSpeedLimit.TryRemove(key, out var _);
                            }
                        }
                    }
                    catch (Exception ex)
                    {
                        LogHelper.WriteAppExceptionLog(" Exception occurred in deleting data :" + ex.Message, ex);
                    }
                    Thread.Sleep(20000);
                }
            }
        }

If you have a friend with rich experience in stepping on pits , I believe I can see the problems in this code at a glance , Yes , Is that when  xxxSpeedLimit  When the dictionary is empty , It's equivalent to a  while(true)  It's a dead cycle , Isn't it ？

To test my story , It can be used  !dso  find dict Memory address of , And then use  !wconcurrentdict  that will do .

0:044> !dso 
OS Thread Id: 0x5bc4 (44)
RSP/REG          Object           Name
...
000000A2B0C3E708 000001ba8007f618 System.Collections.Concurrent.ConcurrentDictionary`2[[System.String, System.Private.CoreLib],[System.String, System.Private.CoreLib]]
000000A2B0C3E760 000001ba88501cd0 System.Collections.Generic.List`1+Enumerator[[System.String, System.Private.CoreLib]]
000000A2B0C3E768 000001ba80050ec0 System.Threading.ContextCallback
000000A2B0C3E7F8 000001ba80a1a818 System.Threading.Thread
000000A2B0C3EA28 000001ba80a1a898 System.Threading.ThreadStart
0:044> !wconcurrentdict 000001ba8007f618
Empty ConcurrentDictionary

You can see , The present is a   An empty dictionary  

3、 ... and ： summary

The main cause of the accident ： Coders lack some programming experience , When writing business logic, there is a lack of right   An empty dictionary   Process processing of , Led to  while(true)   Embarrassment , It may also be that  Thread.Sleep(20000)  Wrong place

In general, I am very grateful to this friend for providing dump, Let me really see for real ！