2017-04-19 81 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