蛙蛙推荐：一键定位CPU百分百问题

摘要：

当一个.net应用在生产环境CPU突然居高不下，如何快速准确的定位问题所在，并且对实时业务影响最小化？如何不抓Dump也不用live debug就可以知道你的应用在做什么？如何确认你的应用是由于哪个线程的执行造成的CPU升高，该线程正在执行什么代码？

分析：
CPU升高的原因有很多，
 1、有时候应用的负载大了，CPU自然会受业务请求的增加和增高；
 2、有时候因为GC回收使用了过高的CPU资源；
 3、有时候是某个线程执行的代码在某种情况下陷入了死循环；
 4、有时候是因为锁争用太激烈，某资源上的锁释放后，等待的线程去抢锁引起的；
 5、有时候是因为线程太多，上下文切换太频繁引起的。
 6、每秒抛出太多的Exception。
我们一一分析
 1、我们一般会用一些计数器来观察实际的应用的负载情况和并发请求量，比如每秒接受多少请求等，所以业务量增大引起的CPU高，很容易确定。
 2、GC使用的CPU百分比有专门的计数器，一看便知。
 3、如果某段代码陷入了死循环引起的CPU高，只抓Dump看~*e!clrstack和!runaway还是不太好定位问题，
  a)、一般都是连续抓几个dump，然后用!runaway来看哪些线程的用户态时间的差很大，然后再去看该线程的调用栈。
  b)、录制Thread\Thread Id和Thread\% Processor Time计数器，同时抓dump，从计数器里找到CPU消耗高的线程ID，然后从dump里看调用栈和调用栈的参数本地变量等。
 4、锁争用也有相关的.NET计数器可以直接看。
 5、每个进程的线程数，每秒上下文切换次数也可以有直接的计数器可看。
 6、每秒抛出的异常也有直接的计数器可看。

思路：
1、从上面看到也就是第3种地排查比较费劲，而且抓DUMP有时候容易把服务抓S，如果是一个有状态的服务，抓死服务后果很严重，所以我们得想出一种更轻量级的方法去获取服务的每个线程的调用栈。其实CLR本身有一些用于支持调试的接口，都是Com的，但.NET对此有一些包装，可以用c#来使用这些调试API，其中当然包括附加到进程，获取所有线程调用栈的功能。该DLL在.net sdk里，叫MdbgCore.dll。
2、另外获取计数器.NET也有现成的类，上篇帖子介绍过了。
3、.NET对进程的管理也有一些API，可以获取一个进程的线程数，每个线程的启动时间，用户态时间，线程状态，优先级等信息。

有了以上几个知识点，我们就可以综合起来写一个比较智能化定位高CPU问题的工具。

CPU高的DEMO
我们先写一个CPU高的DEMO，A方法因为有sleep所以不会太消耗CPU，而B方法没有Sleep，执行一个浮点运算，所以会造成CPU升高（占用一个CPU的资源）。

using System;
using System.Threading;

namespace HightCPUDemo
{
    internal class Program
    {
        private static void Main(string[] args)
        {
            new Thread(A).Start();
            new Thread(B).Start();
            Console.ReadKey();
        }

        private static void A(object state)
        {
            while (true)
            {
                Thread.Sleep(1000);
            }
        }

        private static void B(object state)
        {
            while (true)
            {
                double d = new Random().NextDouble()*new Random().NextDouble();
            }
        }
    }
}

代码实现

我们的目标在该程序运行的时候，找出B方法，并确认它就是引起CPU高度原因，代码如下，不太想解释了，代码不复杂，重在思路。

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Text;
using System.Threading;
using Microsoft.Samples.Debugging.MdbgEngine;

internal class MyThreadInfo
{
    public string CallStack = "null";
    public string Id;
    public string ProcessorTimePercentage;
    public string StartTime;
    public string UserProcessorTime;

    public override string ToString()
    {
        return
            string.Format(
                @"<table style="" 1000px;""><tr><td style="" 80px;"">ThreadId</td><td style="" 200px;"">{0}</td><td style="" 140px;"">% Processor Time</td><td>{1}</td></tr>
<tr><td style="" 80px;"">UserProcessorTime</td><td style="" 200px;"">{2}</td><td style="" 140px;"">StartTime</td><td>{3}</td></tr><tr><td colspan=""4"">{4}</td></tr></table>",
                Id, ProcessorTimePercentage, UserProcessorTime, StartTime, CallStack);
    }
}

internal class MyThreadCounterInfo
{
    public PerformanceCounter IdCounter;
    public PerformanceCounter ProcessorTimeCounter;

    public MyThreadCounterInfo(PerformanceCounter counter1, PerformanceCounter counter2)
    {
        IdCounter = counter1;
        ProcessorTimeCounter = counter2;
    }
}

internal class Program
{
    // Skip past fake attach events. 
    private static void DrainAttach(MDbgEngine debugger, MDbgProcess proc)
    {
        bool fOldStatus = debugger.Options.StopOnNewThread;
        debugger.Options.StopOnNewThread = false; // skip while waiting for AttachComplete

        proc.Go().WaitOne();
        Debug.Assert(proc.StopReason is AttachCompleteStopReason);

        debugger.Options.StopOnNewThread = true; // needed for attach= true; // needed for attach

        // Drain the rest of the thread create events.
        while (proc.CorProcess.HasQueuedCallbacks(null))
        {
            proc.Go().WaitOne();
            Debug.Assert(proc.StopReason is ThreadCreatedStopReason);
        }

        debugger.Options.StopOnNewThread = fOldStatus;
    }

    // Expects 1 arg, the pid as a decimal string
    private static void Main(string[] args)
    {
        try
        {
            int pid = int.Parse(args[0]);

            var sb = new StringBuilder();
            Process process = Process.GetProcessById(pid);
            var counters = new Dictionary<string, MyThreadCounterInfo>();
            var threadInfos = new Dictionary<string, MyThreadInfo>();

            sb.AppendFormat(
                @"<html><head><title>{0}</title><style type=""text/css"">table, td{{border: 1px solid #000;border-collapse: collapse;}}</style></head><body>",
                process.ProcessName);

            Console.WriteLine("1、正在收集计数器");

            var cate = new PerformanceCounterCategory("Thread");
            string[] instances = cate.GetInstanceNames();
            foreach (string instance in instances)
            {
                if (instance.StartsWith(process.ProcessName, StringComparison.CurrentCultureIgnoreCase))
                {
                    var counter1 =
                        new PerformanceCounter("Thread", "ID Thread", instance, true);
                    var counter2 =
                        new PerformanceCounter("Thread", "% Processor Time", instance, true);
                    counters.Add(instance, new MyThreadCounterInfo(counter1, counter2));
                }
            }

            foreach (var pair in counters)
            {
                pair.Value.IdCounter.NextValue();
                pair.Value.ProcessorTimeCounter.NextValue();
            }
            Thread.Sleep(1000);
            foreach (var pair in counters)
            {
                try
                {
                    var info = new MyThreadInfo();
                    info.Id = pair.Value.IdCounter.NextValue().ToString();
                    info.ProcessorTimePercentage = pair.Value.ProcessorTimeCounter.NextValue().ToString("0.0");

                    threadInfos.Add(info.Id, info);
                }
                catch
                {
                }
            }

            Console.WriteLine("2、正在收集线程信息");
            ProcessThreadCollection collection = process.Threads;
            foreach (ProcessThread thread in collection)
            {
                try
                {
                    MyThreadInfo info;
                    if (threadInfos.TryGetValue(thread.Id.ToString(), out info))
                    {
                        info.UserProcessorTime = thread.UserProcessorTime.ToString();
                        info.StartTime = thread.StartTime.ToString();
                    }
                }
                catch
                {
                }
            }

            var debugger = new MDbgEngine();

            MDbgProcess proc = null;
            try
            {
                proc = debugger.Attach(pid);
                DrainAttach(debugger, proc);

                MDbgThreadCollection tc = proc.Threads;
                Console.WriteLine("3、正在附加到进程{0}获取调用栈", pid);
                foreach (MDbgThread t in tc)
                {
                    var tempStrs = new StringBuilder();
                    foreach (MDbgFrame f in t.Frames)
                    {
                        tempStrs.AppendFormat("<br />" + f);
                    }
                    MyThreadInfo info;
                    if (threadInfos.TryGetValue(t.Id.ToString(), out info))
                    {
                        info.CallStack = tempStrs.Length == 0 ? "no managment call stack" : tempStrs.ToString();
                    }
                }
            }
            finally
            {
                if (proc != null)
                {
                    proc.Detach().WaitOne();
                }
            }
            foreach (var info in threadInfos)
            {
                sb.Append(info.Value.ToString());
                sb.Append("<hr />");
            }
            sb.Append("</body></html>");

            Console.WriteLine("4、正在生成报表");
            using (var sw = new StreamWriter(process.ProcessName + ".htm", false,
                                             Encoding.Default))
            {
                sw.Write(sb.ToString());
            }

            Process.Start(process.ProcessName + ".htm");
        }
        catch (Exception ex)
        {
            Console.WriteLine(ex);
        }
    }
}

单元测试
找出HeightCPUDemo的进程ID，比如是8724，然后执行PrintStack.exe 8724，输出结果如下
E:\study\ThreadStack\PrintStack\bin\Debug>PrintStack.exe 8724
1、正在收集计数器...
2、正在收集线程信息...
3、正在附加到进程8724获取调用栈...
4、正在生成报表...

最终会在当前目录生成一个HightCPUDemo.htm的报表，其中哪个线程耗费了很多的CPU，及其托管调用栈一目了然，很快就能定位问题。

ThreadId	10280	% Processor Time	97.1
UserProcessorTime	00:00:20.2187500	StartTime	2009-6-24 21:58:19
System.Random.Sample (source line information unavailable) System.Random.NextDouble (source line information unavailable) HightCPUDemo.Program.B (Program.cs:27) System.Threading.ThreadHelper.ThreadStart_Context (source line information unavailable) System.Threading.ExecutionContext.Run (source line information unavailable) System.Threading.ThreadHelper.ThreadStart (source line information unavailable)

参考链接

How the .NET Debugger Works
http://www.developerfusion.com/article/4692/how-the-net-debugger-works/
Working on managed wrappers for Native Debugging API
http://blogs.msdn.com/jmstall/archive/2006/07/05/managed-wrappers-for-native-debug-api.aspx
Runtime Call Stack Analysis with .NET
http://www.ddj.com/184405715
MDbg Linkfest
http://blogs.msdn.com/jmstall/archive/2005/11/08/mdbg_linkfest.aspx
Tool to get snapshot of managed callstacks
http://blogs.msdn.com/jmstall/archive/2005/11/28/snapshot.aspx