2017-04-19 55 views
0

我有一个生产CPU问题,经过几天的常规活动后突然CPU开始达到峰值。我保存了转储文件并运行!runaway命令以获取CPU时间最长的线程列表。的输出低于:WinDbg失控命令输出解释

用户模式时间
线程时间
21:1100天10:51:39.781
19:F840天10:41:59.671
5:CC4 0 0天:53:25.343
48:74 0 0天:34:20.140
47:1670 0 0天:34:09.812
13:460 0 0天:32:57.640
8:14d40天0:19 :30.546
7:d90 0天0:03:15.00 0
23:1520 0 0天:02:21.984
22:CA00天0:02:08.375
24:72℃0 0天:02:01.640
29:10AC0天0:01:58.671
27:1088 0 0天:01:44.390

正如你所看到的,输出显示我有2个线程:21 & 19,消耗超过20小时的CPU时间相结合,我能跟踪其中1个线程的调用堆栈,如下所示:

〜21S
!CLRStack

输出不会在此刻没关系,让我们把它叫做“X调用堆栈”

我想什么,是有关!失控命令输出的解释。据我所知,转储文件是应用程序当前状态的快照。所以我的问题是:

  1. 失控命令如何显示线程21的10:51小时值,当转储过程只需要几秒钟?
  2. 这是否意味着使用!CLRStack命令找到的X调用堆栈的特定“实例”挂起超过10个小时?或者它是21线程执行整个X调用堆栈执行的总时间?如果是这样的话,看起来很奇怪的是21个线程负责这么多的X调用堆栈的执行。据我所知的起源是一个web请求(运行时应该指定每个呼叫随机线程)

我有一个猜测,可能回答这些2个问题:

也许在WinDbg通过计算时间取得线程调用堆栈的实际时间并将其除以转储过程的范围,因此,例如,如果X调用堆栈的特定执行时间为1秒,整个转储过程需要3秒钟(33%),而进程正在运行输出总共24小时将显示:

8小时(24小时的33%)

我是对的,还是完全搞错了?

+1

'!runaway'命令只显示线程自创建以来花费的CPU时间。在进行转储时,它可能会或可能不会与调用堆栈有关。如果您想查看调用树中每个函数花费的时间,则需要[使用分析器](https://msdn.microsoft.com/en-us/library/ms182372.aspx)。 (顺便说一句,你可以通过'!runaway 7'获得更多有关CPU和壁挂时间的信息。) –

+0

将usertime和kerneltime复制到来自kernelmode结构成员的转储kthread在转储时以特定间隔更新最后更新的时间被复制并显示windbg windbg只是显示的东西 – blabb

回答

2

此答案旨在为OP理解。它并不打算在所有位和字节中正确。

[...]和倾倒过程的范围除以[...]

这种理解大概是一切罪恶的根源:倾倒过程只给你进程状态在某个及时。转储过程的持续时间为0.0秒,因为所有线程在操作期间都被暂停。 (所以,你的过程相对时间,一切都没有改变,时间静止不动;当然挂钟时间的变化)

您正在考虑展开反倾销调查过程监控它在一段较长的时间,这不是的案件。因为涉及磁盘活动等因素,所以转储过程只需要一段时间。

因此,不存在“范围”,因此您无法(很难)测量崩溃转储的性能问题。

如何能失控命令显示螺纹21 10:51小时值,[...]

如何在你的C#程序知道过了多久,程序运行,如果你只有一个定时器每秒都会发生的事件?答案是:它使用一个变量并增加值。

这大概是Windows如何做到这一点。 Windows负责线程调度,每次它重新调度线程时,都会更新一个包含线程时间的变量。

在写故障转储时,很久以前由操作系统收集的信息已包含在故障转储中。

当转储过程只需要几秒钟?

由于崩溃转储由WinDbg的线程占用,因此在该线程上占用该时间。您需要调试WinDbg并在WinDbg线程上执行!runaway以查看占用了多少CPU时间。潜在的一个很好的练习和.dbgdbg(调试调试器)命令对你来说可能是新的;除此之外,这种特殊情况并不真正有用。

这是否意味着使用!CLRStack命令找到的X调用堆栈的特定“实例”挂起超过10个小时?

不。表示在创建故障转储的时间点执行了该特定的方法。不多,不少。

此信息与!runaway无关,因为该线程可能在很长一段时间内做了完全不同的事情,但刚刚结束。

或者它是21线程执行整个X调用堆栈执行的总时间?

否。故障转储不包含这些详细的性能数据。您需要像JetBrains dotTrace这样的性能分析器来获取这些信息。分析器会经常查看调用堆栈,然后聚合相同的调用堆栈并获取每个调用堆栈的CPU时间。

+2

很好的答案。内核存储执行时间;所以API调用由MiniDumpWriteDump API进行,以获取该信息,类似于检索句柄信息的方式。高执行时间着重意味着挂起的*相反*。你有一个繁忙的过程。要么它处于循环中,要么只是处理大量的请求。 –

+0

托马斯,谢谢你的详细解答!我能够通过创建一个控制台应用程序来验证您的答案,该应用程序运行3个线程,执行不同的调用堆栈,像“----”一样执行不同的调用堆栈 - time1 - thread1 start - thread1 finished - thread2&3 starts - 线程2完成-----线程3完成----我每转换一次---“”并用Windbg调试它。不幸的是你的答案是正确的:)我需要采取多个转储样本才能找到问题。我找到了下面的分析器,它应该做的窍门:https://github.com/jitbit/cpu-analyzer – Ofir