Помогите мне проанализировать файл дампа

Клиенты сообщают о проблемах почти каждый день примерно в одно и то же время. Это приложение работает на 2 узлах. Это платформа Metastorm BPM, и она вызывает наш код.

В некоторых дампах я заметил очень длинные потоки (~ 50 минут), но не во всех. Администраторы также говорят мне, что непосредственно перед тем, как пользователи сообщают о проблемах, увеличивается использование памяти. Затем все замедляется до такой степени, что они не могут работать, и администраторам приходится перезапускать платформы на обоих узлах. Моей первой мыслью были взаимоблокировки (длительные потоки), но я не смог это подтвердить. !syncblk ничего не возвращает. Затем я посмотрел на использование памяти. Я заметил много динамических сборок, поэтому подумал, что сборки могут протекать. Но похоже это не то. Я получил дамп со дня, когда все работало нормально, и количество динамических сборок было аналогичным. Так что, возможно, утечка памяти, подумал я. Но и подтвердить это не может. !dumpheap -stat показывает рост использования памяти, но я не нашел ничего интересного с !gcroot. Но есть одна вещь, которую я не знаю, что это такое. Порт завершения Threadpool. Их много. Так может быть, что-то ждет на что-то? Вот данные, которые я могу вам дать на данный момент, которые поместятся в этом посте. Не могли бы Вы предложить что-нибудь, что могло бы помочь диагностировать эту ситуацию?

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*)
Я мог бы понять одну, но почему их так много. Является ли это специфичным для механизма моделирования бизнес-процессов, который мы используем, или это что-то типичное? Я предполагаю, что он использует потоки, которые могут быть использованы другими клиентами, и поэтому пользователи сообщают о замедлении. Являются ли эти потоки потоками порта завершения, о которых я спрашивал ранее? Могу ли я сделать что-нибудь еще для диагностики или я обнаружил, что причиной является наш код?


person Piotr Perak    schedule 30.06.2011    source источник


Ответы (1)


Судя по выходным данным, большая часть памяти находится не в кучах .net (всего 35 МБ из ~ 650), поэтому, если вы смотрите на кучи .net, я думаю, что вы ищете не в том месте. Память, вероятно, находится либо в сборках, либо в собственной памяти, если вы используете какой-либо собственный компонент для передачи файлов или чего-то подобного. Вы бы хотели использовать Debug Diag для мониторинга этого.

Трудно сказать, если вы пропускаете динамические сборки, не глядя на модель роста, поэтому я бы посоветовал вам посмотреть на perfmon и #current сборки, чтобы увидеть, продолжает ли он расти с течением времени, если это так, то вам придется исследовать это дальше, посмотрев, что такое динамические сборки с !dda

person Tess    schedule 01.07.2011
comment
Спасибо Тесс. Я не знал об инструменте DebugDiag. Можешь посмотреть, что я с ним обнаружил? - person Piotr Perak; 03.07.2011
comment
Вы можете посетить блог Тесс по адресу blogs.msdn.com/Tess и изучить его. Самый быстрый способ — открыть запрос в службу поддержки через support.microsoft.com, чтобы проконсультироваться со специалистами службы поддержки Microsoft. - person Lex Li; 08.07.2011
comment
Все, что я знаю, я узнал из блога Тесс. А на самом деле я попросил ее туда приехать сюда :) - person Piotr Perak; 07.08.2011