8 июня 2010 г.

Как узнать, почему зависла программа?

Сегодняшняя статья будет посвящена нескольким подходам к отладке зависаний программы.

Состоит она из шести частей:
- Подготовка - общие действия для всех случаев отладки.
- Delphi - отладка зависания в Delphi.
- EurekaLog - поиск причины зависания в EurekaLog.
- Process Explorer - поиск причины зависания утилитой Process Explorer.
- Threads Snapshot - поиск причины зависания утилитой Threads Snapshot.
- Практический пример - пример с искусственным зависанием в программе.

Подготовка

Ну, прежде чем приступать к отладке программы, вам надо бы её пересобрать (делайте Build, а не просто Compile), добавив в неё отладочную информацию. Для разных подходов требуется разные форматы отладочной информации, поэтому лучше включить всё сразу, чтобы не думать :) Это необходимо сделать, чтобы отладочные средства могли показывать вам читабельные названия процедур и номера строк в исходниках. В противном случае, вам придётся иметь дело с машинным кодом и смещениями.

Итак, вам нужно включить (Project/Options/Linking): "MAP file" - Detailed, "Debug Information" (в старых версиях Delphi она называлась "Include TD32 debug info") - True, "Include remote debug symbols" - True:

Добавление отладочной информации в проект Delphi

Кроме отладочной информации, полезно включить опции "Stack Frames" и "Use Debug DCUs" на вкладке "Compiling":

Включение отладочных опций для проекта Delphi

Уж позвольте мне не повторяться, что делают эти опции.

Не забываем сделать Build после изменения опций. Понятно, что если у вас несколько проектов (DLL, BPL и т.п.), то менять опции и пересобирать надо все. Также, если вы используете сборку с run-time пакетами - по возможности, выключите их на время тестирования, ибо пакеты сильно всё усложняют.

Delphi

Вы можете подумать: "но я не могу воспроизвести это под отладчиком!" или "на проблемной машине у меня не стоит Delphi!". Но не спешите переходить к следующему разделу.

Во-первых, вам необязательно запускать программу в Delphi. Вы можете запустить программу как обычно, вне среды, и работать с ней, пока она не зависнет - после чего подключить к ней отладчик. Во-вторых, если на машине не стоит Delphi - вы можете установить на неё удалённый отладчик. Подробнее об удалённом отладчике - см. справку или мою статью (большой объём, вот вариант в PDF) - раздел 2, в конце секции 2.1.1. про работу с отладчиком.

Для отладки зависшего проекта в Delphi его, конечно же, нужно открыть. Предварительно он должен быть скомпилирован - с установленными опциями отладки, как мы сделали выше. Кроме того, для локальной машины желательно, чтобы вы запускали программу из Output path, указанном в опциях проекта (т.е. не перемещали бы скомпилированный exe перед запуском).

Итак, вы запустили свою программу, она сколько-то там поработала и зависла. Открываем Delphi, загружаем нужный проект и делаем Run/Attach to process:

Окно Delphi Run/Attach to process

Из списка выбираем вашу программу (введя при необходимости имя удалённой машины, если Delphi и программа находятся на разных машинах), устанавливаем галочку "Pause after attach" и жмём "Attach".

Отладчик подключится к процессу и установит его на паузу - путём возбуждения точки останова в потоке отладчика:

Остановка на паузу отладчика Delphi после подключения к процессу

Вы можете игнорировать поток отладчика - просто перейдите на окно Threads и выберите любой свой поток для его отладки. Вы можете просмотреть стек вызовов, переключаться между потоками, анализировать переменные, делать пошаговое выполнение и т.п. - в общем, пользоваться отладчиком Delphi как обычно. Если вы включали отладочную информацию, то вы можете закрыть окно CPU и пользоваться отладкой по исходному тексту.

Напомню, что при возможности отладку зависаний стоит производить в ОС Vista и выше - потому что в этих системах появилась новая возможность для отладчиком: Wait Chain Traversal. Отладчик Delphi последних версий поддерживает WCT. Поэтому, если вы используете BDS 2009 или выше и Windows Vista или выше, то в окне Threads напротив каждого потока в колонке "Wait Chain" можно увидеть его статус, чего он ждёт, есть ли взаимоблокировка и т.п.:

Поддержка Wait Chain Traversal в Delphi 2009 и выше

EurekaLog

В EurekaLog есть фишка "Anti-Freeze". Собственно, её я уже разбирал в отдельной статье, поэтому не буду останавливаться сейчас - у нас и так сегодня куча материала.

Кратко скажу: это - удобная возможность, когда она применима. Но вы не можете использовать её, если ваш главный поток не занят выборкой сообщений (т.е. в консольных приложениях и службах). В результате применения вы получите стек вызовов зависшего потока и сможете проанализировать ситуацию. Это удобно для сообщения вам о проблемах на клиентских машинах, где у вас нет не то что отладчика, но часто вы даже можете не знать, что программа у кого-то виснет. Для отладки же - намного удобнее использовать Delphi, как мы только что разбирали.

Process Explorer

Если же по каким-то причинам среда Delphi для вас недоступна - вам придётся производить отладку руками.

Перед тем, как производить отладку, надо подготовить Process Explorer. Здесь будет два шага - оба опциональных, но для максимального удобства лучше сделать оба.

Шаг первый - настроить Process Explorer на загрузку отладочных символов. Дело в том, что Windows поставляется с обычными исполняемыми модулями без отладочной информации. Для своих программ мы только что включили генерацию отладочной информации (см. первый пункт), то как мы можем сделать это для Windows, чьи исходники нам недоступны? Ну, Microsoft позаботилась об этом: она распространяет отладочную информацию для своих программ отдельно. Вы можете скачать её и получить читабельные стеки вызовов.

Для начала вам понадобится скачать и установить Windows Debugging Tools. Затем, вам нужно решить, качать ли всю отладочную информацию скопом или же пусть она качается по запросу отладочной программы. Если вы выбрали первый путь - то вперёд, качаем и устанавливаем. Лично я выбираю второй путь.

Для второго способа вам нужно создать папку на своей машине с правом чтения-записи файлов и папок в ней. После чего остаётся только настроить Process Explorer:


В первом поле указывается путь к DbgHelp.dll - если вы устанавливали Windows Debugging Tools, то берите библиотеку оттуда. Если нет - то берите C:\Windows\System32\dbghelp.dll (однако я не уверен, будет ли это работать).

Во втором поле указывается сразу две вещи: первая - ваша общая папка, где вы хотите складировать отладочную информацию. Вторая - сервер отладочной информации, который выдаёт её по запросу программы. Как видите, я складываю информацию в папку C:\ProgramData\DebugSymbols (я добавил права на запись для пользователей в этой папке), а беру её со стандартного сервера Microsoft http://msdl.microsoft.com/download/symbols.

После того, как вы это настроили, Process Explorer будет пытаться получить отладочную информацию о каждом необходимом файле и кэшировать её в указанной папке. Поэтому, когда вы просматриваете потоки процесса или их стек вызовов, вы можете иногда видеть надпись "Loading symbols for ABC.exe+0xXYZ...". В общем, после этого вам станет доступно больше информации для системных модулей.

Второй момент, который нужно сделать - сконвертировать map-файл вашего проекта в формат, понимаемый Process Explorer. Дело в том, что Delphi создаёт только различные Borland-ские форматы отладочной информации, а Process Explorer, как утилита Microsoft, понимает только Microsoft-ские форматы отладочной информации. Я уже говорил об этом. Сделать это можно утилитой map2dbg. Это простая консольная утилитка. Качаете архив, распаковываете, открываете консоль и пишете:
map2dbg Project1.exe
По файлам Project1.exe и Project1.map утилита сделает вам файл Project1.dbg, который может быть использован в Microsoft-ских утилитах.

Что-ж, я тут много чего сказал. Давайте я продемонстрирую, что вы получаете, выполнив указанные выше вещи. Ниже - три скриншота. Слева направо: вид стека вызовов без выполнения обоих пунктов (т.е. без системной и без проектной отладочной информацией), вид стека вызовов с первым пунктом (с системной, но без проектной отладочной информацией) и вид стека вызовов с обоими пунктами (с системной и с проектной отладочной информацией):

Вид стека вызовов в Process Explorer без отладочной информацииВид стека вызовов в Process Explorer с системной отладочной информациейВид стека вызовов в Process Explorer с полной отладочной информацией

Как видите, подключение отладочной информации даёт вам три вещи:

- Более читабельный стек вызовов (вместо имя-модуля+смещение вы получаете имя-модуля!процедура+смещение)
- Более полный стек вызовов (без отладочной информации эвристика трассировки стека может опускать вызовы)
- Более правдивый стек вызовов (анализатор может неверно определять имя функции, если идёт вызов внутренней функции, которая не имеет публичного имени, но рядом находится другая функция, которая как-раз таки имеет публичное имя - поэтому анализатор может посчитать внутреннюю функцию частью публичной)

Если вы не будете (или не сможете) подключать отладочную информацию - вам придётся работать со смещениями. Вы конечно, можете искать смещения в map-файле руками, но это весьма хлопотно. Гораздо проще просто выписать на бумажку все числа, приписав имя модуля. Затем запускаете проект у себя, ставите его на паузу и используете команду Search/Goto address. Вводите адрес - и Delphi переводит вас на строчку в исходном тексте, а если это невозможно - то открывает окно CPU. Какой вводить адрес? Два примера. Вы выписали Project1.exe + $1234 и Project2.dll + $4321. Базовый адрес exe обычно не меняется и равен $400000. Вы загрузили проект у себя. Базовый адрес exe тот-же - $400000, а вот DLL оказалась загруженной по адресу $50000000 (вы можете выяснить это в окне Modules: View/Debug Windows/Modules). Тогда вас интересуют адреса $400000 + $1234 = $401234 и $50000000 + $4321 = $50004321.

Фух, разобрались. Как видите, намного удобнее подключать отладочную информацию, чем работать без неё :)

Теперь, что вы собственно должны делать для отладки зависания. Ну, вы запускаете свою программу и работаете с ней, пока она не зависнет. Потом вы запускаете Process Explorer, выбираете в списке процессов свою программу, правый щелчок -> Properties (свойства). В свойствах процесса переходим на вкладку Threads (потоки):

Вкладка Threads в Process Explorer

Здесь вы можете посмотреть, чем занимаются потоки вашей программы. Кто кушает процессор, кто чего-то ждёт и т.п. Выберите поток и нажмите кнопку "Stack" для просмотра его стека вызова (пример окна - см. три скриншота чуть выше).

Конечно, вы не сможете посмотреть переменные или что-то такое - только состояние и точки выполнения потоков. Так что вам придётся использовать свои телепатические способности, чтобы определить причину зависания.

Threads Snapshot

Ну, использование Process Explorer хотя и несложно, но не выглядит таковым. Для новичка тут много работы и новых понятий. Да и вся эта возня с отладочной информацией не слишком удобна. Поэтому я написал простую утилитку (сейчас - часть EurekaLog Tools), которая позволяет вам выбрать запущенный процесс и дампит в текстовый файл информацию по всем потокам, включая:

- Базовая инфа: ID, приоритет и т.п.
- Стек вызова. Используются следующие источники отладочной информации: Borland-ские, JCL, EurekaLog и madExcept. Чуть позже добавлю поддержку Microsoft-ских и закачку по запросу, как у Process Explorer.
- Информация от Wait Chain Traversal (на Windows Vista и выше).
- Контекст потока - регистры и флаги.

Собственно, вы запускаете свою проблемную программу и работаете в ней, пока она не зависнет. Потом запускаете утилиту Threads snapshot и тыркаете её на зависший процесс. Она снимет вам снимок потоков, который вы сможете проанализировать.

Интерфейс:

Утилита Threads Snapshot

Результат работы:

Process [ 147C / 5244 ]: H:\Test\Project88.exe (2010.06.08 16:31:07)

[ 18C4 / 6340 ] Priority: 8
Wait Chain Count = 1; Deadlock: False
Type: Thread; status: Blocked; process: [ 147C / 5244 ]; thread: [ 18C4 / 6340 ]; wait time: 701985; context switches: 4040
EIP:    772E438D  EFlags: 00000202
EBP:    0018FF1C  ESP:    0018FEEC
EAX:    000100B8  EBX:    0008E301  ECX:    00000000  EDX:    00000000
ESI:    00000000  EDI:    0018FEE4
SegCS:  00000023  CegSS:  0000002B  SegGS:  0000002B  SegFS:  00000053  SegES:  0000002B  SegDS:  0000002B
----------------------------------------------------------------------------------------------------------------------------------------------
|Methods |Details|Stack   |Address |Module       |Unit     |Class    |Procedure/Method                                             |Line     |
----------------------------------------------------------------------------------------------------------------------------------------------
|Calling Thread: ID=6340; Priority=??; Class=                                                                                                |
|--------------------------------------------------------------------------------------------------------------------------------------------|
|00000008|03     |00000000|772E438D|user32.dll   |USER32   |         |WaitMessage                                                  |         |
|000000F2|04     |0018FF20|0049F5CC|Project88.exe|Forms    |Forms    |TApplication.Idle                                            |10358[0] |
|000000F2|04     |0018FF20|0049E8FF|Project88.exe|Forms    |Forms    |TApplication.HandleMessage                                   |9814[23] |
|000000F2|04     |0018FF44|0049E8E8|Project88.exe|Forms    |Forms    |TApplication.HandleMessage                                   |9813[0]  |
|000000F2|04     |0018FF44|0049EC1D|Project88.exe|Forms    |Forms    |TApplication.Run                                             |9951[201]|
|000000F2|04     |0018FF74|0049EB54|Project88.exe|Forms    |Forms    |TApplication.Run                                             |9925[0]  |
|000000F2|04     |0018FF74|004A6C91|Project88.exe|Project88|Project88|Project88                                                    |13[73]   |
|000000F2|03     |0018FF8C|770D3675|kernel32.dll |kernel32 |         |BaseThreadInitThunk                                          |         |
|000000F2|03     |0018FF98|77B29D70|ntdll.dll    |ntdll    |         |Unknown function at 77B29D70 near RtlInitializeExceptionChain|         |
|000000F2|03     |0018FFD8|77B29D4B|ntdll.dll    |ntdll    |         |Unknown function at 77B29D4B near RtlInitializeExceptionChain|         |
|000000F2|03     |0018FFD8|77B29D40|ntdll.dll    |ntdll    |         |Unknown function at 77B29D40 near RtlInitializeExceptionChain|         |
----------------------------------------------------------------------------------------------------------------------------------------------


[ 1834 / 6196 ] Priority: 8
Wait Chain Count = 1; Deadlock: False
Type: Thread; status: Blocked; process: [ 147C / 5244 ]; thread: [ 1834 / 6196 ]; wait time: 720156; context switches: 2
EIP:    77B100FD  EFlags: 00000202
EBP:    02F7FF88  ESP:    02F7FDF4
EAX:    77B51C7F  EBX:    77B51C20  ECX:    00000000  EDX:    00000000
ESI:    006B7C60  EDI:    00000000
SegCS:  00000023  CegSS:  0000002B  SegGS:  0000002B  SegFS:  00000053  SegES:  0000002B  SegDS:  0000002B
-----------------------------------------------------------------------------------------------------------------------------------
|Methods |Details|Stack   |Address |Module      |Unit    |Class|Procedure/Method                                             |Line|
-----------------------------------------------------------------------------------------------------------------------------------
|Calling Thread: ID=6196; Priority=??; Class=                                                                                     |
|---------------------------------------------------------------------------------------------------------------------------------|
|00000008|03     |00000000|77B100FD|ntdll.dll   |ntdll   |     |ZwWaitForMultipleObjects                                     |    |
|000000F2|03     |02F7FF8C|770D3675|kernel32.dll|kernel32|     |BaseThreadInitThunk                                          |    |
|000000F2|03     |02F7FF98|77B29D70|ntdll.dll   |ntdll   |     |Unknown function at 77B29D70 near RtlInitializeExceptionChain|    |
|000000F2|03     |02F7FFD8|77B29D4B|ntdll.dll   |ntdll   |     |Unknown function at 77B29D4B near RtlInitializeExceptionChain|    |
|000000F2|03     |02F7FFD8|77B29D40|ntdll.dll   |ntdll   |     |Unknown function at 77B29D40 near RtlInitializeExceptionChain|    |
-----------------------------------------------------------------------------------------------------------------------------------

Как видите - достаточно простая и удобная альтернатива ручной отладке с Process Explorer. Дополнительный плюс - вы можете попросить вашего клиента снять вам снимок процесса на его машине. В случае же с Process Explorer-ом - навряд ли вы сможете объяснить клиенту, что куда ставить и где жать. Не забудьте только передать все необходимые файлы (map-файлы, например).

Я написал эту утилиту буквально только что за два дня. Поэтому она "немножко" сыровата. Нормальная и отлаженная версия этой утилиты должна войти в EurekaLog v7.

Практический пример

Я написал простую программу с двумя кнопками. Вы можете использовать её как обучающий пример. Первая кнопка создаёт несколько потоков, которые ждут друг друга. Вторая кнопка вызывает порчу памяти, приводящую к зависанию. Запустите программу, нажмите на кнопку и попробуйте выяснить причину зависания. Посмотрим, как мы сможем отладить эти два случая.

В Delphi: если у вас есть поддержка WCT, то отладка первой кнопки вообще не представляет сложностей: запустили, нажали, поставили программу на паузу и смотрим окно Threads:

Deadlock 1 в Delphi с поддержкой Wait Chain Traversal (WCT)

Откуда сразу видно, что у нас есть три потока (не смотрите на последний - это поток отладчика, его можно игнорировать), главный (первый) ждёт завершения рабочего потока (второго), который отправил сообщение (SendMessage) третьему потоку. А третий для обработки сообщения попытался взять критическую секцию, которой владеет второй поток. Т.е. второй поток ждёт третьего потока, а третий ждёт второй поток. Вот вам и взаимная блокировка.

Если же WCT у вас нет, то придётся поработать головой и руками. Вы должны проанализировать стеки вызова каждого потока: щёлкаете по потокам в окне "Threads" и смотрите стеки вызовов:

Deadlock 1 в Delphi без поддержки Wait Chain Traversal (WCT)

После переключения на поток открывается окно CPU с текущей выполняемой инструкцией, но вы можете щёлкать по строчкам в окне "Call stack", чтобы посмотреть исходный код.

Проанализировав стеки вызовов всех трёх потоков, вы составите картину произошедшего.

Как эта же ситуация выглядит в Process Explorer и Threads snapshot? Ну, вы запускаете Process Explorer и смотрите стеки потоков (у меня первый поток открывался около минуты, не знаю, с чем связано - потом пошло гладко):

Deadlock 1 в Process Explorer

Хотя вы не видите здесь номеров строк, но вы видите имена функций и последовательность вызовов - например, в примере выше обратите внимание на Thread1Func, различные dispatch-функции, CriticalSection.Aquire и т.п. И снова: вы смотрите стеки вызова всех потоков и реконструируете ситуацию. Сделать это будет сложнее, чем используя Delphi (ибо нет номеров строк), но с известной долей телепатии - вполне возможно.

Что касается Threads snapshot, то она даёт такой лог (я отрезал лишние части для уменьшения лога):

Process [ 1A1C / 6684 ]: H:\Test\HangDemo.exe (2010.06.08 17:54:33)

[ 1BD8 / 7128 ] Priority: 8
Wait Chain Count = 7; Deadlock: True
Type: Thread; status: Blocked; process: [ 1A1C / 6684 ]; thread: [ 1BD8 / 7128 ]; wait time: 1038023; context switches: 762
Type: Unknown; status: Owned; name: " "; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: " "; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
EIP:    77B0F871  EFlags: 00000202
EBP:    0018F438  ESP:    0018F3CC
EAX:    00000000  EBX:    00000000  ECX:    00000000  EDX:    00000000
ESI:    00000120  EDI:    00000000
SegCS:  00000023  CegSS:  0000002B  SegGS:  0000002B  SegFS:  00000053  SegES:  0000002B  SegDS:  0000002B
----------------------------------------------------------------------------------------------------------------------------------------------
|Methods |Details|Stack   |Address |Module        |Unit      |Class   |Procedure/Method                                           |Line      |
----------------------------------------------------------------------------------------------------------------------------------------------
|Calling Thread: ID=7128; Priority=??; Class=                                                                                                |
|--------------------------------------------------------------------------------------------------------------------------------------------|
|00000008|03     |00000000|77B0F871|ntdll.dll     |ntdll     |        |ZwWaitForSingleObject                                      |          |
|000000F2|03     |0018F43C|7757077E|KERNELBASE.dll|KERNELBASE|        |WaitForSingleObjectEx                                      |          |
|000000F2|03     |0018F43C|770D117F|kernel32.dll  |kernel32  |        |WaitForSingleObjectEx                                      |          |
|000000F2|03     |0018F454|770D1141|kernel32.dll  |kernel32  |        |WaitForSingleObjectEx                                      |          |
|000000F2|03     |0018F454|770D1133|kernel32.dll  |kernel32  |        |WaitForSingleObject                                        |          |
|000000F2|03     |0018F468|770D1126|kernel32.dll  |kernel32  |        |WaitForSingleObject                                        |          |
|000000F2|04     |0018F468|004B3580|HangDemo.exe  |UnitMain  |UnitMain|TfmMain.Button1Click                                       |101[68]   |
|000000F2|04     |0018F47C|0048331F|HangDemo.exe  |Controls  |Controls|TControl.Click                                             |7178[111] |
----------------------------------------------------------------------------------------------------------------------------------------------


[ 065C / 1628 ] Priority: 8
Wait Chain Count = 5; Deadlock: True
Type: Thread; status: Blocked; process: [ 1A1C / 6684 ]; thread: [ 065C / 1628 ]; wait time: 1038024; context switches: 34
Type: Unknown; status: No access; name: " "; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: " "; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
EIP:    77B0F871  EFlags: 00000202
EBP:    0237FD40  ESP:    0237FCDC
EAX:    00000000  EBX:    00000000  ECX:    00000000  EDX:    00000000
ESI:    006293C4  EDI:    00000000
SegCS:  00000023  CegSS:  0000002B  SegGS:  0000002B  SegFS:  00000053  SegES:  0000002B  SegDS:  0000002B
-------------------------------------------------------------------------------------------------------------------------------------------
|Methods |Details|Stack   |Address |Module      |Unit    |Class   |Procedure/Method                                             |Line     |
-------------------------------------------------------------------------------------------------------------------------------------------
|Calling Thread: ID=1628; Priority=??; Class=                                                                                             |
|-----------------------------------------------------------------------------------------------------------------------------------------|
|00000008|03     |00000000|77B0F871|ntdll.dll   |ntdll   |        |ZwWaitForSingleObject                                        |         |
|000000F2|03     |0237FD44|77B28B9A|ntdll.dll   |ntdll   |        |Unknown function at 77B28B9A near RtlIntegerToUnicodeString  |         |
|000000F2|03     |0237FD44|77B28B43|ntdll.dll   |ntdll   |        |Unknown function at 77B28B43 near RtlIntegerToUnicodeString  |         |
|000000F2|03     |0237FD6C|77B12260|ntdll.dll   |ntdll   |        |RtlEnterCriticalSection                                      |         |
|000000F2|04     |0237FD6C|00441408|HangDemo.exe|SyncObjs|SyncObjs|TCriticalSection.Acquire                                     |546[4]   |
|000000F2|04     |0237FD74|004B3354|HangDemo.exe|UnitMain|UnitMain|WndProc                                                      |43[20]   |
|000000F2|03     |0237FDA8|772D6215|user32.dll  |USER32  |        |Unknown function at 772D6215 near gapfnScSendMessage         |         |
|000000F2|03     |0237FDA8|772D68E5|user32.dll  |USER32  |        |Unknown function at 772D68E5 near gapfnScSendMessage         |         |
|000000F2|03     |0237FDEC|772D6893|user32.dll  |USER32  |        |Unknown function at 772D6893 near gapfnScSendMessage         |         |
|000000F2|03     |0237FE20|772D682D|user32.dll  |USER32  |        |Unknown function at 772D682D near gapfnScSendMessage         |         |
|000000F2|03     |0237FE20|772D7172|user32.dll  |USER32  |        |Unknown function at 772D7172 near GetWindowLongW             |         |
|000000F2|03     |0237FEA8|772D682D|user32.dll  |USER32  |        |Unknown function at 772D682D near gapfnScSendMessage         |         |
|000000F2|03     |0237FEA8|772D7D2C|user32.dll  |USER32  |        |Unknown function at 772D7D2C near LoadStringW                |         |
|000000F2|03     |0237FEF0|772D7E2C|user32.dll  |USER32  |        |DispatchMessageW                                             |         |
|000000F2|03     |0237FEF0|772D7EB8|user32.dll  |USER32  |        |GetMessageW                                                  |         |
|000000F2|03     |0237FF0C|772D7E92|user32.dll  |USER32  |        |GetMessageW                                                  |         |
|000000F2|04     |0237FF0C|004B3420|HangDemo.exe|UnitMain|UnitMain|Thread1Func                                                  |71[132]  |
|000000F2|04     |0237FF78|00405FE4|HangDemo.exe|System  |System  |ThreadWrapper                                                |13579[40]|
|000000F2|03     |0237FF8C|770D3675|kernel32.dll|kernel32|        |BaseThreadInitThunk                                          |         |
|000000F2|03     |0237FF98|77B29D70|ntdll.dll   |ntdll   |        |Unknown function at 77B29D70 near RtlInitializeExceptionChain|         |
|000000F2|03     |0237FFD8|77B29D4B|ntdll.dll   |ntdll   |        |Unknown function at 77B29D4B near RtlInitializeExceptionChain|         |
|000000F2|03     |0237FFD8|77B29D40|ntdll.dll   |ntdll   |        |Unknown function at 77B29D40 near RtlInitializeExceptionChain|         |
-------------------------------------------------------------------------------------------------------------------------------------------


[ 1504 / 5380 ] Priority: 8
Wait Chain Count = 5; Deadlock: True
Type: Thread; status: Blocked; process: [ 1A1C / 6684 ]; thread: [ 1504 / 5380 ]; wait time: 1038024; context switches: 8
Type: Unknown; status: Running; name: " "; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: " "; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
Type: Unknown; status: Unknown; name: ""; timeout: 0; alertable: 0
EIP:    772D723B  EFlags: 00000202
EBP:    03C1FF28  ESP:    03C1FEE8
EAX:    00BD2C30  EBX:    005E0EC0  ECX:    00000000  EDX:    00000000
ESI:    00BD2C30  EDI:    00000401
SegCS:  00000023  CegSS:  0000002B  SegGS:  0000002B  SegFS:  00000053  SegES:  0000002B  SegDS:  0000002B
-------------------------------------------------------------------------------------------------------------------------------------------
|Methods |Details|Stack   |Address |Module      |Unit    |Class   |Procedure/Method                                             |Line     |
-------------------------------------------------------------------------------------------------------------------------------------------
|Calling Thread: ID=5380; Priority=??; Class=                                                                                             |
|-----------------------------------------------------------------------------------------------------------------------------------------|
|00000008|03     |00000000|772D723B|user32.dll  |USER32  |        |Unknown function at 772D723B near GetPropW                   |         |
|000000F2|03     |03C1FF2C|772DCC02|user32.dll  |USER32  |        |Unknown function at 772DCC02 near GetWindow                  |         |
|000000F2|03     |03C1FF2C|772DCD7C|user32.dll  |USER32  |        |SendMessageW                                                 |         |
|000000F2|03     |03C1FF50|772DCD35|user32.dll  |USER32  |        |SendMessageW                                                 |         |
|000000F2|04     |03C1FF50|004B350F|HangDemo.exe|UnitMain|UnitMain|Thread2Func                                                  |85[67]   |
|000000F2|04     |03C1FF78|00405FE4|HangDemo.exe|System  |System  |ThreadWrapper                                                |13579[40]|
|000000F2|03     |03C1FF8C|770D3675|kernel32.dll|kernel32|        |BaseThreadInitThunk                                          |         |
|000000F2|03     |03C1FF98|77B29D70|ntdll.dll   |ntdll   |        |Unknown function at 77B29D70 near RtlInitializeExceptionChain|         |
|000000F2|03     |03C1FFD8|77B29D4B|ntdll.dll   |ntdll   |        |Unknown function at 77B29D4B near RtlInitializeExceptionChain|         |
|000000F2|03     |03C1FFD8|77B29D40|ntdll.dll   |ntdll   |        |Unknown function at 77B29D40 near RtlInitializeExceptionChain|         |
-------------------------------------------------------------------------------------------------------------------------------------------

К сожалению, вывод WCT пока не очень форматирован (это моё домашнее задание! :) ), но цепочку ожиданий увидеть можно. Плюс стеки потоков (к сожалению, без системной отладочной информации - это моё второе домашнее задание!) самым решительным образом намекают на происходящее.

Ничего сложного.

Второй случай сложнее. Потому что зависание -лишь внешнее проявление другой проблемы.

Итак, в Delphi вы запускаете программу, она виснет, мы ставим её на паузу. У нас только один поток, поэтому WCT нам не помощник, даже если он есть. Поэтому сразу переключаемся на главный поток и смотрим стек вызовов:

Deadlock 2 в Delphi

Опять-таки: щёлкая по стеку вызовов, мы видим исходный код.

В этот раз, простой анализ стека вызовов нам не помогает. Пока что неясно, что же случилось. Тем более, что программа вроде бы не висит, а что-то делает (т.е., строго говоря, у нас не зависание, а зацикливание). Поэтому мы начинаем пошаговый прогон программы. Пройдясь по коду мы видим, что код постоянно крутит цикл со Sleep, проверяя некий флаг. Мы видим, что этот код - код менеджера памяти FastMM. Почитав комментарии в коде, мы узнаём, что FastMM пытается получить блокировку. А проверяемый флаг - это признак занят/свободен. Поскольку FastMM проверяет этот флаг уже полчаса - ясно, что тут что-то не так. Этот же вывод следует из того, что в нашёй программе всего один поток - т.е. ждать-то и вовсе некого, кроме нас в программе никого нет. Иными словами, состояние флага не соответствует действительности - т.е. он испорчен вследствие повреждения памяти.

К сожалению, найти повреждение памяти не так-то просто и это отдельная тема, которую я недавно закончил обсуждать.

Поэтому, задача анализа зависания - выяснить причину. Мы её нашли: это - повреждение памяти. Дальше, анализ зависания закончен, но проблема пока не найдена и не устранена - мы переходим к анализу и поиску проблем с памятью.

Собственно, второй случай выглядит примерно аналогично везде (в Delphi, Process Exporer и Threads snapshot): мы получаем примерно один и тот же стек вызовов, который может меняться время от времени, но всегда это будет цикл и с вероятностью в 99% - стоять на Sleep. Делается просто несколько проверок, чтобы в этом убедиться. Для примера - вот как это выглядит в Process Explorer:

Deadlock 2 в Process Explorer

Напомню, что из этого мы вынесем только вывод (не однозначный, конечно же, а всего лишь обоснованное предположение), что у нас есть повреждение памяти. Дальше - это уже другая история.

Фух. На сегодня у меня всё. Надеюсь, этот материал был полезен. Если хотите, вот ещё дополнение - презентация по ручному поиску места ошибки по адресу (см. "How to find the exception source line"). На английском, но может пригодится или будет интересно.

13 комментариев :

  1. Надеюсь, этот материал был полезен.
    Александр, не скромничайте, материал более чем полезен!

    ОтветитьУдалить
  2. Полезен! Очень интересно было читать. Даже несмотря на то, что всё расписано очень понятно и подробно, я всё-равно чувствую себя ламером и надеюсь что мне никогда не придётся расследовать ситуацию зависания программы без исходников.

    ОтветитьУдалить
  3. >>> без исходников

    Блин, забыл сказать. Короче, я хотел ещё дать ссылку на блог Марка Руссиновича (оригинал на английском).

    В нём куча примеров, как можно понять, что происходит в программе, не имея её исходников и используя утилиты вроде Process Explorer, Process Monitor и т.п.

    Например, случай зависания приложения MS Office при старте. Process Explorer-ом посмотрели стек вызова - увидели, что там есть вызов OpenPrinter, а дальше пошёл RPC - т.е. идёт обращение к сетевому принтеру. Глянули в панель управления - а там старые настройки, сетевой принтер ссылается в никуда. Поэтому офис при старте пытался достучаться до несуществующего принтера.

    Вот, пример применения телепатии для высказывания обоснованного предположения.

    ОтветитьУдалить
  4. Как постоянный читатель вашего блога, хочу сказать огромное спасибо! за столь интересные и глубокие материалы! Редко по дельфи найдеш такие интересные материалы, которые полезны людям уже с серьезным опытом, а не только новичкам.

    ОтветитьУдалить
  5. Полезный и очень скурпульозно выложенный материал, все систематично разжовано, за что автору спс

    ОтветитьУдалить
  6. Ещё забыл сказать: иногда причина зависания может быть очевидна - если ваша программа серверного характера (т.е. работает постоянно) и виснет не только программа, но и вся машина (причём с завидной регулярностью) - то проверьтесь на утечки памяти. Вполне возможно, что, на самом деле, машина не висит, а просто очень медленно реагирует.

    ОтветитьУдалить
  7. Если в Process Explorer оставить Dbghelp.dll из system32, он не очень внятно ругается при закрытии окошка настроек, а при открытии свойств процесса говорит следующее:

    The version of Dbghelp.dll configured does not support the Microsoft Symbol Server.
    Please download and install the Microsoft Debugging Tools for Windows to get a
    version that does.

    P.S.: А в хелпе у него - про путь с сервером написано пути через звёздочки писать:

    Configure Symbols: on Windows NT and higher, if you want Process Explorer to resolve addresses for thread start addresses in the threads tab of the process properties dialog and the thread stack window then configure symbols by first downloading the Debugging Tools for Windows package from Microsoft's web site and installing it in its default directory. Open the Configure Symbols dialog and specify the path to the dbghelp.dll that's in the Debugging Tools directory and have the symbol engine download symbols on demand from Microsoft to a directory on your disk by entering a symbol server string for the symbol path. For example, to have symbols download to the c:\symbols directory you would enter this string:

    srv*c:\symbols*http://msdl.microsoft.com/download/symbols

    ОтветитьУдалить
  8. а, у Вас тож со звёздочками.. что-то сразу я не разглядел..

    ОтветитьУдалить
  9. По картинке можно щёлкнуть - она увеличится.

    ОтветитьУдалить
  10. Я иногда использую Debug Diagnostic Tool от Microsoft в связке с Process Explorer.
    Process Explorer дампит процесс, Debug Diagnostic Tool открывает и анализирует дамп.
    Много интересного можно узнать. Особенно если сконвертировать map файл в dbg (map2dbg.exe) и положить в папку symbols.
    Хорош также ASMprofiler.
    Не говоря уже об AQTime.

    ЗЫ. Может кто-нить знает как секцию JCLDebug выкусить из бинарника, сохранить на диск и преобразовать обратно в map?

    ОтветитьУдалить
  11. Может кому-то известно как преобразовать MAP или DBG в PDB? Пытаюсь использовать Intel VTune Performance Analyzer, а он понимает только PDB :(

    ОтветитьУдалить
  12. Нет, но можно проголосовать за это и это.

    ОтветитьУдалить

Можно использовать некоторые HTML-теги, например:

<b>Жирный</b>
<i>Курсив</i>
<a href="http://www.example.com/">Ссылка</a>

Вам необязательно регистрироваться для комментирования - для этого просто выберите из списка "Анонимный" (для анонимного комментария) или "Имя/URL" (для указания вашего имени и (опционально) ссылки на сайт). Все прочие варианты потребуют от вас входа в вашу учётку (поддерживается OpenID).

Пожалуйста, по возможности используйте "Имя/URL" вместо "Анонимный". URL можно просто не указывать.

Ваше сообщение может быть помечено как спам спам-фильтром - не волнуйтесь, оно появится после проверки администратором.