Sunday, November 22, 2015

How to identify thread, which consumes most of process time in .NET application

Today we faced problem, that one of our services started consuming 50% of CPU after deployment. Luckily one of my colleagues already new how to investigate this issue.
So we will need two programs to process: WinDbg and ProcDump.
Let's assume we have following program which consumes 100% of processor time:

    class Program
    {
        static void Main(string[] args)
        {
            var rnd = new Random();
            while (true)
            {
                var number = rnd.NextDouble();
                Process(number);
            }
        }

        private static void Process(double input)
        {
            
        }
    }

Now, we need to create memory dump for process which causes problems. and that's why we need ProcDump. Execute following command:
procdump -ma PID
Flag -ma means, that we want full memory dump for our application.

Now start WinDbg(please not, that for 32bit application we will WinDbg(x86)) and open our dump: File->Open Crash Dump. To debug .NET applications, CLR support should be loaded, so execute following command:
.loadby sos clr
Now we need to execute runaway command, which shows us list running threads:
!runaway
For our program output of the command will be:
      User Mode Time
  Thread       Time
   0:3344      0 days 0:00:30.703
   7:1fc0      0 days 0:00:00.000
   6:1a64      0 days 0:00:00.000
   5:3a98      0 days 0:00:00.000
   
If we look at this output, we can see, that all process time was consumed by thread 0:3344. To switch to this thread we need to execute command:
~0s
where 0 is number before colon in thread ID. s means switch.
At this point we want to see call stack for this thread:
!clrstack
In my case I received following error: Symbols can not be loaded because symbol path is not initialized. To fix this I had to reload symbols with following commands:
.symfix
.reload
Execute !clrstack one more time and output at this time output will be:
OS Thread Id: 0x3344 (0)
Child SP       IP Call Site
00a9f114 715fa263 System.Random.InternalSample()
00a9f128 715fa20a System.Random.Sample()
00a9f130 7166c18d System.Random.NextDouble()
   
In case if we want to find memory leak, we can execute:
!dumpheap
And the output will be table with object name and number of objects of this type:
Statistics:
      MT    Count    TotalSize Class Name
71764cb0        3          468 System.Collections.Generic.Dictionary`2+Entry[[System.Type, mscorlib],[System.Security.Policy.EvidenceTypeDescriptor, mscorlib]][]
71764508        6          736 System.Int32[]
71763aac       52         1456 System.RuntimeType
717625fc       47         2586 System.String
717629f0        6        17528 System.Object[]
   

2 comments:

  1. Hi Uriil, I am trying to reach you. Could you write me please?
    gokhanfatih4@gmail.com

    ReplyDelete
  2. Hi Uriil can you email me I have a project for you. sradesign.net@gmail.com

    ReplyDelete