Отладка Высокое использование ЦП

У меня есть управляемое приложение, которое использует UCMA (Unified Communications Managed API) 4.0 SDK. Я пытаюсь отладить проблему, в которой приложение использует 100% процессора и системы. Я использовал расширения SOS, чтобы попробовать и отладить основную причину. Я в настоящее время застрял. Мне удалось найти идентификаторы потоков, которые занимают процессорное время, но в основном это неуправляемые потоки. Мне действительно нужна помощь в этом.Отладка Высокое использование ЦП

Резьбы 15, 18, 16, 17, 19, 20 являются неуправляемыми потоками и имеют один и тот же стек вызовов. Темы 9, 10, 11, 12, 13, 14 - все неуправляемые потоки и имеют одинаковый стек вызовов. Другой вопрос в том, что потоки 21 и 22, похоже, ожидают события, поэтому почему они считаются бегущими потоками, потребляющими процессорное время?

Кто-нибудь знает, что делает ZwRemoveIoCompletionEx? Это что-то такое, что неактивно, как NtWaitForMultipleObjects, или это может быть пережевывание процессорного времени? В случае с этим приложением, когда он достигает 100%, он никогда не откатывается, пока приложение не будет перезапущено.

0:000> !loadby sos clr 
0:009> .time 
Debug session time: Wed May 27 15:47:52.000 2015 (UTC - 4:00) 
System Uptime: 31 days 1:05:59.329 
Process Uptime: 31 days 1:01:27.000 
    Kernel time: 0 days 21:44:58.000 
    User time: 1 days 16:51:40.000 
0:000> !runaway 
User Mode Time 
    Thread  Time 
    15:113c  0 days 3:46:30.510 
    18:1418  0 days 3:18:07.135 
    16:1404  0 days 3:08:01.009 
    17:140c  0 days 3:07:19.310 
    19:1428  0 days 3:04:56.943 
    20:1434  0 days 2:52:51.664 
    22:1450  0 days 0:47:50.153 
    9:11dc  0 days 0:45:02.904 
    21:1440  0 days 0:43:34.623 
    12:13cc  0 days 0:33:35.298 
    11:1250  0 days 0:32:50.386 
    14:fbc  0 days 0:31:57.018 
    10:1178  0 days 0:29:12.920 
    13:13c4  0 days 0:28:42.048 
    2:fa8  0 days 0:03:11.678 
    4:1164  0 days 0:02:45.080 

0:015> kb 
RetAddr   : Args to Child               : Call Site 
000007fe`fd36546f : 00000000`272946f0 000007fe`e5394b29 00000000`27295b18 00000000`27295b18 : ntdll!ZwRemoveIoCompletionEx+0xa 
00000000`7700c089 : 00000000`1c4981e0 00000000`00000001 00000000`00000001 00000000`00000000 : KERNELBASE!GetQueuedCompletionStatusEx+0xdf 
000007fe`e51b634b : 00000000`000009b0 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!GetQueuedCompletionStatusExStub+0x19 
000007fe`e538fc0b : 00000000`1c4981e0 00000000`1c4981e0 000007fe`e5905340 00000000`00000000 : rtmpal!RtcPalTaskQueueDequeue+0x17 
000007fe`e538f960 : 00000000`1f55fcf0 00000000`00000000 00000000`1db59eb0 00000000`1f55fcf0 : Microsoft_Rtc_Internal_Media!CStreamingEngineImpl::EngineWorkerThread+0x267 
000007fe`e51b33c8 : 00000000`00000000 00000000`1c40a6a0 00000000`1c4a4f80 00000000`00000000 : Microsoft_Rtc_Internal_Media!CStreamingEngineImpl::EngineWorkerThreadProc+0xf0 
000007fe`f22a3d67 : 00000000`00000000 00000000`1c40a6a0 00000000`00000000 00000000`00000000 : rtmpal!RtcPalSetSchedulerPolicy+0x194 
000007fe`f22a3f0e : 000007fe`f233cdb0 00000000`00000000 00000000`00000000 00000000`00000000 : msvcr110!beginthreadex+0x107 
00000000`76fd652d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : msvcr110!endthreadex+0x192 
00000000`7720c541 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd 
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d 

0:022> !clrstack 
OS Thread Id: 0x1450 (22) 
     Child SP    IP Call Site 
000000001fdcda68 000000007723186a [HelperMethodFrame_1OBJ: 000000001fdcda68] System.Threading.WaitHandle.WaitMultiple(System.Threading.WaitHandle[], Int32, Boolean, Boolean) 
000000001fdcdba0 000007fee968c64c System.Threading.WaitHandle.WaitAny(System.Threading.WaitHandle[], Int32, Boolean) 
000000001fdcdc00 000007fe8e097a70 Microsoft.Rtc.Internal.Media.RtpEventHandlerThread.EventHandlerThreadProc() 
000000001fdce8d0 000007fee973d0b5 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) 
000000001fdcea30 000007fee973ce19 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) 
000000001fdcea60 000007fee973cdd7 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) 
000000001fdceab0 000007fee96b0301 System.Threading.ThreadHelper.ThreadStart() 
000000001fdcedc8 000007feed44ffe3 [GCFrame: 000000001fdcedc8] 
000000001fdcf0f8 000007feed44ffe3 [DebuggerU2MCatchHandlerFrame: 000000001fdcf0f8] 

0:021> kb 
RetAddr   : Args to Child               : Call Site 
000007fe`fd331430 : 00000000`00190398 00000000`771f3a92 00000000`c0000008 00000000`00000110 : ntdll!NtWaitForMultipleObjects+0xa 
00000000`76fd1220 : 00000000`1edefc18 00000000`1edefc00 00000000`00000000 00000000`00da7a64 : KERNELBASE!WaitForMultipleObjectsEx+0xe8 
000007fe`e53bc322 : 00000000`0000cae8 00816179`f67cb320 00000000`1c497eb0 00000000`1edefce0 : kernel32!WaitForMultipleObjects+0xb0 
000007fe`e51b33c8 : 00000000`00000000 00000000`00000000 00000000`1dad4630 00000000`1c4a5160 : Microsoft_Rtc_Internal_Media!CStreamingEngineImpl::TimerThreadProc+0x37e 
000007fe`f22a3d67 : 00000000`00000000 00000000`1dad4630 00000000`00000000 00000000`00000000 : rtmpal!RtcPalSetSchedulerPolicy+0x194 
000007fe`f22a3f0e : 000007fe`f233cdb0 00000000`00000000 00000000`00000000 00000000`00000000 : msvcr110!beginthreadex+0x107 
00000000`76fd652d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : msvcr110!endthreadex+0x192 
00000000`7720c541 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd 
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d 

0:013> kb 
RetAddr   : Args to Child               : Call Site 
000007fe`fd36546f : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!ZwRemoveIoCompletionEx+0xa 
00000000`7700c089 : 00000000`00000000 00000000`000000b7 00000000`00000001 00000000`1c4a4a40 : KERNELBASE!GetQueuedCompletionStatusEx+0xdf 
000007fe`e51c0fef : 000007fe`e5905340 000007fe`e53eb764 00000000`00000000 00000000`1dac2ab0 : kernel32!GetQueuedCompletionStatusExStub+0x19 
000007fe`e53eaf4b : 000007fe`e5905340 00000000`35bdd608 00000000`00000001 00000000`1f17fc20 : rtmpal!RtcPalIOCP::GetQueuedCompletionStatus+0x18f 
000007fe`e53eac6d : 00000000`00000510 00000000`0000dddd 00000000`1dad9fe0 00000000`1f17fc80 : Microsoft_Rtc_Internal_Media!CTransportManagerImpl::TransportWorkerThread+0xe7 
000007fe`e51b33c8 : 00000000`00000000 00000000`1c409460 00000000`1c4a4e40 00000000`00000000 : Microsoft_Rtc_Internal_Media!CTransportManagerImpl::TransportWorkerThreadProc+0x13d 
000007fe`f22a3d67 : 00000000`00000000 00000000`1c409460 00000000`00000000 00000000`00000000 : rtmpal!RtcPalSetSchedulerPolicy+0x194 
000007fe`f22a3f0e : 000007fe`f233cdb0 00000000`00000000 00000000`00000000 00000000`00000000 : msvcr110!beginthreadex+0x107 
00000000`76fd652d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : msvcr110!endthreadex+0x192 
00000000`7720c541 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd 
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

источник

2015-06-03 sgobiraj

Итак ... каковы ваши темы на самом деле? Что делает ваш код? –

Использование Windbg - лучший способ определить, что происходит. Единственная проблема заключается в том, что гениальность состоит в том, чтобы все это понять, потому что MSFT никогда не показывал внутренние структуры данных так, как это было хорошо документировано или легко понято. Есть несколько хороших учебных пособий, но посмотрите на Интернет для учебников WINDBG и потоков WINDBG runaway. И, к счастью, я никогда не нашел WINDBG легко расшифровать и только около 5 раз из 50 или около того, где я смог понять, что происходит. –

@EdS. Это то, что я, похоже, не могу отследить там, где это выполняется, потому что это неуправляемые потоки, которые, по-видимому, выделяются библиотекой Microsoft UCMA. Если бы я мог сопоставить это обратно с идентификатором управляемого потока, который мое приложение вызвало в Microsoft UCMA SDK, тогда было бы полезно. – sgobiraj

Отладка проблем с производительностью с помощью WinDbg потребует нескольких дампов. Один дамп - это всего лишь моментальный снимок во времени и не дает вам полной картины.

Прямо сейчас (в момент создания дампа) нитки могут ничего не делать. Вы уверены, что использовали 100% процессор, когда вы взяли свалку? Или он восстановился со 100% всего за миллисекунду до того, как была взята свалка?

Значения, отображаемые !runaway, являются накопленными значениями на протяжении всего времени работы программы. Это просто говорит вам, что поток много работал в прошлом. Он не говорит вам, что он делает сейчас или будет делать в будущем.

Хотя это было сделано Марк Руссинович и некоторые другие трещины, это не для новичков.

Поскольку вам нужно много дампов, чтобы получить полную картину, используйте другие инструменты для анализа проблем производительности. Типичные инструменты называются профайлерами, например. Профилер ANTS Redgate или dotTrace для JetBrains.

Если вы действительно хотите пройти этот трудный путь, по крайней мере используйте ProcDump (SysInternals) с параметрами -ma -c -n -s, чтобы собрать несколько хороших высоких дампов процессора.

источник

2015-06-03 22:07:46

Нет проблем с этим приложением, так это то, что он постоянно застревает на 100% и не падает. Другая проблема заключается в том, что это иногда происходит после того, как приложение работает в течение нескольких дней или иногда через несколько недель. Должны ли эти профилировщики устанавливать отладочные сборки? Невозможно развернуть сборку отладки в производственной среде. – sgobiraj

@sgobiraj: хорошо, если он воспроизводится только в производственной среде в таких трудных условиях, профайлер может просто отказаться (потому что он производит столько данных) или просто слишком медленно использовать программу в процессе производства. В этом случае получение нескольких таких дампов с помощью Procdump - это, пожалуй, единственный выбор. –

@sgobiraj: Кажется, вы потратили много времени на поиски проблем, и решение, и ваш выбор, чтобы создать свалку, подняли вес. Не могли бы вы рассказать нам немного больше, что вы пробовали, чтобы у нас не возникали слишком простые ответы? Например. Посмотрите на время ядра: ваш процесс имеет 21-часовое время ядра и 40 часов пользовательского времени. Это маловероятно для .NET-приложения, делает ли ваше приложение что-то еще, что может быть связано с ядром, кроме UCMA? Используете ли вы последнюю версию? Требуется ли UCMA драйверы? Если да, то они актуальны? ... –

Пробуйте Process Explorer и ProcMon от SysInternals. Хотя это может не дать вам ответ сразу, это дает много контекста вокруг процесса и может помочь пролить свет на разные вещи, которые делает приложение. В ProcMon просто установите фильтр для того, что ProcessName вам интересно. В Process Explorer найдите процесс, щелкните правой кнопкой мыши -> свойства. Вы увидите такие вещи, как потоки и TCP-соединения, и многое другое.

источник

2015-06-03 22:13:06 dmarlow

Да, извините. Я хотел сказать ProcMon. – dmarlow

Все прошло отлично. Есть проблема, вы используете windbg, чтобы получить трассировку стека, были некоторые предложения, а затем wham мир изменился, когда вы произнесли магические слова «производственная среда».

Что касается остальной части вашего поста, я заметил это:

В случае этого приложения после его пронзает до 100% он никогда не идет вниз, пока приложение не будет перезапущен.

В основном это означает, что он сломан, и он сломан плохо.

Я также замечаю, что у вас многопоточное приложение, что еще более затрудняет выяснение, где все идет не так.

Вещи, которые вы не должны делать в производственной среде

Ну, в основном список является:

Отладочные
Профилирование
Запуск модульных тестов
... У этого списка нет конца.

Если у вас есть 100% -ый всплеск процессора, который никогда не опускается, может быть интересно посмотреть на остальную часть процесса разработки программного обеспечения. У вас есть автоматический (функциональный) тестовый код? Используете ли вы покрытие кода для проверки того, что вы тестируете? Короче говоря: вы полагаете, что у вас стабильная среда?

На данный момент это не поможет вам. Тем не менее, после исправления ошибки, я думаю, что важно подумать об этих вопросах в долгосрочной перспективе. Я не уверен, что это относится к вашему делу, но, по моему опыту, тот факт, что у вас есть такая ошибка, обычно подразумевает, что вам все еще предстоит сделать тяжелую работу.

Это уже сломана, так что невозможно разорвать его

Первые вещи первых, давайте исправим это. Посмотрим правде в глаза. Это уже сломано, поэтому, если мы временно сломаем его, все в порядке.

Проблема 100% CPU. То, что вам нужно знать, это то, где в коде используется использование ЦП. Профилировщик - лучший инструмент для этого.

Получите профессиональный профессиональный профайлер, такой как Red Gate ANTS. Установите, запустите. Кроме того, вам нужно поставить PDB и исходный код (та же структура папок, что и ваша машина-разработчик) на ваш производственный сервер, и я бы, вероятно, разместил DLL отладки. Все это просто временно, после того как мы нашли нашу ошибку, все это должно исчезнуть снова. Как я уже сказал, вы не хотите этого в производственной среде.

Не будьте осторожны в своем производственном приложении, просто используйте профилирование уровня линии или уровня метода только для исходного кода. Он не нарушит ваше приложение, он просто сделает его медленнее. Вы также можете «приостанавливать» профилировщик, что в основном означает, что данные по выборке больше не собираются - это хорошая идея, чтобы сделать ошибку до тех пор, пока ошибка не появится.

Когда появляется ошибка, продолжите профайлер и запишите некоторые данные.

Debuggers

В моем опыте, делая отладку и «стек трассировки» на приложениях иногда ломает их. Я не совсем уверен, когда это произойдет, но в указанной рабочей среде вы должны перезапустить приложение, которое вы отлаживаете, после того как вы остановили процесс отладки.

Одно возможное приложение отслеживания стека - process explorer от sysinternals. Запуск от имени администратора, дважды щелкните процесс, перейдите на вкладку «темы» и нажмите «трассировка стека» (или дважды щелкните) для каждого потока, пока не найдете что-то смешное.

Если вы заметили Wait или Sleep, это, вероятно, просто отлично.

Удачи вам!

источник

2015-06-04 08:18:56 atlaste

Отладка Высокое использование ЦП

ответ

Смежные вопросы