Клиенты сообщают о проблемах почти каждый день в одно и то же время. Это приложение работает на 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
Edit:
Я скачал 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, и он зависает при удаленном вызове. Но! Убегающий показывает, что он висит на 8 секунд. Так что не так долго. Итак, я проверил, что это за темы ожидания. Все, кроме темы 18:
<code>System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
Я мог бы понять одно, но почему их так много. Это специфично для движка моделирования бизнес-процессов, который мы используем, или это что-то типичное? Я предполагаю, что он принимает потоки, которые могут использоваться другими клиентами, и поэтому пользователи сообщают о замедлении. Являются ли эти темы темами портов завершения, о которых я спрашивал раньше? Могу ли я сделать что-нибудь еще для диагностики или наш код был причиной?