【问题标题】:Help me analyze dump file帮我分析转储文件
【发布时间】:2011-06-30 22:15:53
【问题描述】:

客户几乎每天都在相同的时间报告问题。此应用程序在 2 个节点上运行。它是 Metastorm BPM 平台,它正在调用我们的代码。

在一些转储中,我注意到运行时间很长的线程(大约 50 分钟),但不是所有的。管理员还告诉我,就在用户报告问题之前,内存使用量会上升。然后一切都变慢到无法工作的地步,管理员必须在两个节点上重新启动平台。我的第一个想法是死锁(长时间运行的线程),但没有设法确认。 !syncblk 没有返回任何东西。然后我查看了内存使用情况。我注意到很多动态程序集,所以认为程序集可能会泄漏。但看起来并非如此。从一切正常并且动态程序集的数量相似的那一天起,我就收到了转储。所以我想也许是内存泄漏。但也无法证实。 !dumpheap -stat 显示内存使用量在增长,但我没有发现 !gcroot 有什么有趣的地方。但有一件事我不知道它是什么。线程池完成端口。他们有很多。所以也许某事正在等待某事?这是到目前为止我可以给你的数据,这些数据适合这篇文章。您能提出任何可以帮助诊断这种情况的建议吗?

Users not reporting problems:
                    Node1                       Node2
Size of dump:       638MB                       646MB
DynamicAssemblies   259                         265
GC Heaps:           37MB                        35MB                    
Loader Heaps:       11MB                        11MB

Node1:
Number of Timers: 12
CPU utilization 2%
Worker Thread: Total: 5 Running: 0 Idle: 5 MaxLimit: 2000 MinLimit: 200
Completion Port Thread:Total: 2 Free: 2 MaxFree: 16 CurrentLimit: 4 MaxLimit: 1000 MinLimit: 8

!dumpheap -stat (biggest)
0x793041d0   32,664    2,563,292 System.Object[]
0x79332b9c   23,072    3,485,624 System.Int32[]
0x79330a00   46,823    3,530,664 System.String
0x79333470   22,549    4,049,536 System.Byte[]

Node2:
Number of Timers: 12
CPU utilization 0%
Worker Thread: Total: 7 Running: 0 Idle: 7 MaxLimit: 2000 MinLimit: 200
Completion Port Thread:Total: 3 Free: 1 MaxFree: 16 CurrentLimit: 5 MaxLimit: 1000 MinLimit: 8

!dumpheap -stat
0x793041d0   30,678    2,537,272 System.Object[]
0x79332b9c   21,589    3,298,488 System.Int32[]
0x79333470   21,825    3,680,000 System.Byte[]
0x79330a00   46,938    5,446,576 System.String
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Users start to report problems:
                    Node1                      Node2
Size of dump:       662MB                       655MB
DynamicAssemblies   236                         235
GC Heaps:           159MB                       113MB                   
Loader Heaps:       10MB                        10MB

Node1:
Work Request in Queue: 0
Number of Timers: 14
CPU utilization 20%
Worker Thread: Total: 7 Running: 0 Idle: 7 MaxLimit: 2000 MinLimit: 200
Completion Port Thread:Total: 48 Free: 1 MaxFree: 16 CurrentLimit: 49 MaxLimit: 1000 MinLimit: 8

!dumpheap -stat
0x7932a208   88,974    3,914,856 System.Threading.ReaderWriterLock
0x79333054   71,397    3,998,232 System.Collections.Hashtable
0x24f70350  319,053    5,104,848 Our.Class
0x79332b9c   53,190    6,821,588 System.Int32[]
0x79333470   52,693    6,883,120 System.Byte[]
0x79333150   72,900   11,081,328 System.Collections.Hashtable+bucket[]
0x793041d0  247,011   26,229,980 System.Object[]
0x79330a00  644,807   34,144,396 System.String

Node2:
Work Request in Queue: 1
Number of Timers: 17
CPU utilization 17%
Worker Thread: Total: 6 Running: 0 Idle: 6 MaxLimit: 2000 MinLimit: 200
Completion Port Thread:Total: 48 Free: 2 MaxFree: 16 CurrentLimit: 49 MaxLimit: 1000 MinLimit: 8

!dumpheap -stat
0x7932a208   76,425    3,362,700 System.Threading.ReaderWriterLock
0x79332b9c   42,417    5,695,492 System.Int32[]
0x79333150   41,172    6,451,368 System.Collections.Hashtable+bucket[]
0x79333470   44,052    6,792,004 System.Byte[]
0x793041d0  175,973   18,573,780 System.Object[]
0x79330a00  397,361   21,489,204 System.String

编辑: 我下载了 debugdiag 并让它分析我的转储。这是输出的一部分:


The following threads in process_name name_of_dump.dmp are making a COM call to thread 193 within the same process which in turn is waiting on data to be returned from another server via WinSock.

 The call to WinSock originated from 0x0107b03b and is destined for port xxxx at IP address xxx.xxx.xxx.xxx


( 18 76 172 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 210 211 212 213 214 215 216 217 218 224 225 226 227 228 229 231 232 233 236 239 )

14,79% of threads blocked

建议是:

Several threads making calls to the same STA thread can cause a performance bottleneck due to serialization. Server side COM servers are recommended to be thread aware and follow MTA guidelines when multiple threads are sharing the same object instance.

我使用 windbg 检查了线程 193 的作用。它正在调用我们的代码。我们的代码正在调用一些 Metastorm 引擎代码,它挂在一些远程调用上。但是 !runaway 显示它挂了 8 秒。所以没那么久。所以我检查了那些等待线程。除了线程 18 之外的所有内容都是:

System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
我能理解一个,但为什么这么多。它是特定于我们正在使用的业务流程建模引擎还是典型的东西?我猜它正在占用其他客户端可以使用的线程,这就是用户报告速度下降的原因。那些线程是我之前问过的 Completion Port Threads 吗?我可以做更多的事情来诊断还是我发现我们的代码是原因?

【问题讨论】:

    标签: windbg crash-dumps


    【解决方案1】:

    从输出的外观来看,大部分内存不在 .net 堆上(大约 650 个中只有 35 MB),所以如果你正在查看 .net 堆,我认为你找错地方了。如果您使用某些本机组件进行文件传输或类似操作,则内​​存可能位于程序集中或本机内存中。您可能希望使用 Debug Diag 来监控它。

    如果不查看增长模式就很难说您是否泄漏了动态程序集,因此我建议您查看 perfmon 和 #current 程序集,看看它是否会随着时间的推移而不断增长,如果确实如此,那么您必须通过查看 !dda 的动态程序集来进一步调查

    【讨论】:

    • 谢谢苔丝。我不知道 DebugDiag 工具。你能看看我用它发现了什么吗?
    • 你可以去Tess的博客blogs.msdn.com/Tess学习。最快的方法是通过support.microsoft.com 打开支持案例以咨询 Microsoft 支持专业人员。
    • 我从 Tess 的博客中学到的知识。事实上我让她来这里:)
    猜你喜欢
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2020-11-25
    • 2011-07-04
    • 1970-01-01
    • 2011-03-14
    • 1970-01-01
    • 1970-01-01
    相关资源
    最近更新 更多