Трассировка exception в Delphi

← →
Alex Konshin © (2007-02-27 15:53) [0]

Я тут в одном (коммерческом) проекте реализовал печать стека вызовов при exception.
После Java отсутствие распечатки стека вызовов сильно раздражает и
Я знаю, что это уже есть в JCL, но там это сделано как-то слишком лохмато - код имеет кучу зависимостей от других модулей JCL, совершено ненужных мне вариантов отладочной информации, и т.п.. Причем это невозможно разделить на куски и использовать только то, что нужно.
Короче, не буду врать, что я не заглядывал в их код, но все-таки я написал свои модули, которые более обозримы, и, самое главное, работают. У меня сделан отдельно парсер *.map, отдельно структура и функции работы с картой памяти, отдельно модуль с хуком на exception и функции раскрутки фреймов стека.

Понятное дело, что так красиво, как в Java не получится. Нужно понимать где и когда Delphi создает фреймы. Если скомпилировано с включеным debug, то можно напечатать имена модулей и номера строк. Если же нет, то хотя бы смещения от начала модулей. Понятно, что в release версии уже номеров строк не будет. Но все равно эти модули уже оказались ислючительно полезны для бета-тестирования. Например, недавно в логах были обнаружены Access violation exception - всем знакомые ужасно противные исключения, и все известно, как тяжело искать причину в таком случае, особенно если учесть, что у меня многопоточное приложение. А тут я сразу нахожу конкретное место в коде, а также цепочку вызовов (ну не совсем так, но откуда пришли понять можно):
20070203 01:07:27.437 EAccessViolation: Access violation at address 00403EF8 in module "InsiderWinMonitor.exe". Read of address FFFFFFFC 20070203 01:07:27.437 00403EF8: System offset=2EF8 20070203 01:07:27.437 00423B3D: NetThreads.pas,255 20070203 01:07:27.437 00423BDA: NetThreads.pas,266 20070203 01:07:27.453 004048B0: System._ExceptionHandler
Короче, я тут так вкусно рассказываю, что у некоторых наверняка потекли слюньки :). Добавим ложку дегтя, чтоб жизнь медом не казалась :). Эти модули я писал для себя и потому не могу гарантировать, что это будет также замечательно работать для вас. Это также означает, что исходники поставляются как есть и ничего кроме них. Для человека дружного со своей головой этого достаточно, а другим этого и не надо :)

В самом простом случае, чтобы это все заработало, нужно просто в самом начале вызвать
DebugUtils.HookException(PrintToConsoleAndODS);
Или что-то в этом духе (там несколько вариантов).
Простой случай это когда у вас только один executable и нет своих DLL/BPL, которые хочется отслеживать. Иначе нужно для каждой DLL/BPL вызвать парсер *.map. На самом деле мне лично это было ненужно и потому я это не тестировал. Возможно, что нужно будет немного доработать напильником. У меня предполагается, что реальный адрес загрузки DLL/BPL совпадает с адресом загрузки установленым при компиляции, что может быть неправдой. Это должно быть несложно доделать, если это нужно.

Да, чуть не забыл самое главное. Я положил это свой сайт
http://home.earthlink.net/~akonshin/files/DebugUtils.zip

Поддержку не гарантирую - я в последнее время сильно занят, а спать иногда хочется. Сейчас вот только выкроил время для души - отдыхаю :)
Но уже 8 утра, пора и спать.

← →
oldman © (2007-02-27 16:22) [1]

> Alex Konshin © (27.02.07 15:53)
> ...skipped...
> Но уже 8 утра, пора и спать.

Ни фига у тебя глюки!!!

← →
Alex Konshin © (2007-02-27 16:25) [2]

> oldman © (27.02.07 16:22) [1]
> > Alex Konshin © (27.02.07 15:53)
> > ...skipped...
> > Но уже 8 утра, пора и спать.
> Ни фига у тебя глюки!!!

В смысле? Сейчас у меня 8:19 утра.
Вот PartitionMagic завершится и я пойду спать.

← →
alien1769 © (2007-02-27 16:29) [3]

> oldman © (27.02.07 16:22) [1]
>
> > Alex Konshin © (27.02.07 15:53)
> > ...skipped...
> > Но уже 8 утра, пора и спать.
>
>
> Ни фига у тебя глюки!!!

По местному времени.

← →
oldman © (2007-02-27 16:33) [4]

> alien1769 © (27.02.07 16:29) [3]

> Alex Konshin © (27.02.07 16:25) [2]

Да я не про время :)))

← →
Ketmar © (2007-02-27 16:55) [5]

интересно. забрал. почитаю на досуге. %-)

tnx. а то из JCL я когда-то начал выковыривать, но понял, что задача по плечу лишь больным на голову титанам. %-)

← →
oldman © (2007-02-27 16:56) [6]

> Ketmar © (27.02.07 16:55) [5]
> задача по плечу лишь больным на голову титанам.

Она, кстати, только им и нужна...

← →
Ketmar © (2007-02-27 17:00) [7]

> oldman © (27.02.07 16:56) [6]
ни фига подобного. я, например, вменяемый способ отлаживать некий сервис так и не нашёл. только логами и дампами. это если ты про саму идею подобных дампов.

← →
novill © (2007-02-27 17:07) [8]

Штука в общем занятная, но вот много ли дадут адреса вызовов?

← →
Alex Konshin © (2007-02-27 17:10) [9]

Ну у меня, собственно, тоже сервис.
Вообще я очень редко отлаживаюсь в Delphi IDE, да и чаще всего это просто невозможно. А многопоточные приложения так вообще отлаживать тяжко. Кроме как ODS практически никаких вариантов.

← →
Alex Konshin © (2007-02-27 17:12) [10]

> novill © (27.02.07 17:07) [8]
> Штука в общем занятная, но вот много ли дадут адреса вызовов?

А ты приглядись. Там не только адреса, а имена исходных файлов и номера строк в них.

← →
Alex Konshin © (2007-02-27 17:22) [11]

Вот еще пример из лога:
20070209 08:28:19.359 EStructuredStreamClosed: Conection has been closed 20070209 08:28:19.375 0041D76C: StructuredStreams.pas,568 20070209 08:28:19.375 0041DA25: StructuredStreams.pas,701 20070209 08:28:19.375 0041DAAC: StructuredStreams.pas,713 20070209 08:28:19.390 0041E2AE: StructuredStreams.pas,919 20070209 08:28:19.390 0041E2CA: StructuredStreams.pas,921 20070209 08:28:19.390 004243AB: NetThreads.pas,437 20070209 08:28:19.390 00424435: NetThreads.pas,461 20070209 08:28:19.390 0042447B: NetThreads.pas,464 20070209 08:28:19.390 00423A9E: NetThreads.pas,243 20070209 08:28:19.390 00423BDA: NetThreads.pas,266 20070209 08:28:19.406 004048B0: System._ExceptionHandler

← →
atruhin © (2007-02-27 17:24) [12]

Хорошая вещь! Давно хотел найти, но ставить JCL только из за глупо.

← →
novill © (2007-02-27 17:28) [13]

> А ты приглядись.

У меня вот такую штуку выдает:

EInvalidOp: Invalid floating point operation 00457117: Unknown module 00433724: TestProject1.exe+032724 00433745: TestProject1.exe+032745 00433724: TestProject1.exe+032724 00433745: TestProject1.exe+032745 0044F516: TestProject1.exe+04E516 0044F53F: TestProject1.exe+04E53F 00403EEC: TestProject1.exe+2EEC

Можешь подсказать, что там еще доработать надо?

← →
Alex Konshin © (2007-02-27 17:30) [14]

Ты компилил с генерацией *.map файла?

← →
Джо © (2007-02-27 17:30) [15]

> [13] novill © (27.02.07 17:28)
> > А ты приглядись.
>
> У меня вот такую штуку выдает:
>
> EInvalidOp: Invalid floating point operation
> 00457117: Unknown module
> 00433724: TestProject1.exe+032724
> 00433745: TestProject1.exe+032745
> 00433724: TestProject1.exe+032724
> 00433745: TestProject1.exe+032745
> 0044F516: TestProject1.exe+04E516
> 0044F53F: TestProject1.exe+04E53F
> 00403EEC: TestProject1.exe+2EEC
>
>
> Можешь подсказать, что там еще доработать надо?

Думаю, что необходимо включить генерацию map-файлов.

← →
Alex Konshin © (2007-02-27 17:31) [16]

Сразу видно, что голубой значок :)

← →
Piter © (2007-02-27 17:33) [17]

а можно для ламеров поподробнее, что это такое означает "распечатка стека вызовов"?

Какие функции в каком порядке вызывались? Дык этих вызовов тысячи будут!

Или объясните на примере, я не догоняю :(

И вот например:

> 20070209 08:28:19.390 0042447B: NetThreads.pas,464

что это такое? Ну дата понятна... Что за адрес 0042447B? Что произошло в строчке 464 модуля NetThreads.pas?

← →
oldman © (2007-02-27 17:34) [18]

> Alex Konshin © (27.02.07 15:53)

Извини, не допер сначала.

Вещь хорошая, но мне (пока) не нужна...

← →
Джо © (2007-02-27 17:35) [19]

> [16] Alex Konshin © (27.02.07 17:31)
> Сразу видно, что голубой значок :)

Ну дык, остро отточенный телепатор вручили вместе со значком :)

← →
Alex Konshin © (2007-02-27 17:50) [20]

> Piter © (27.02.07 17:33) [17]
> а можно для ламеров поподробнее, что это такое означает
> "распечатка стека вызовов"?
> Какие функции в каком порядке вызывались? Дык этих вызовов
> тысячи будут!

Что такое стек? Что значит вызов функции/метода из другого метода?
Могут быть и тысячи, но маловероятно. Тысячи могут быть, если у тебя рекурсия, а так - обычно не больше десятка.

Но на самом деле тут печатаются строки, где создавались стек фреймы. А Delphi их создает не во всех функциях/методах, но зато на всех try ... finally/except. Создание фреймов тоже регулируется опциями компиляции.

Короче, этой информации обычно достаточно для понимания где произшло exception и откуда мы туда пришли.

← →
novill © (2007-02-27 17:51) [21]

> [16] Alex Konshin © (27.02.07 17:31)

EMapParserException: Table of publics by value is not found 0040A8EA: TestProject2.exe+98EA 0040AB16: TestProject2.exe+9B16 0040A55A: TestProject2.exe+955A 0040A587: TestProject2.exe+9587 00403DB0: TestProject2.exe+2DB0 Exception EMapParserException in module TestProject2.exe at 0000A8EA. Table of publics by value is not found.

Похоже просто парсилку придется "доработать напильником"

← →
Суслик © (2007-02-27 18:19) [22]

> [20] Alex Konshin © (27.02.07 17:50)

Скажи, у тебя по функционалу также сделано как в JEDI или все-таки нет?

Вопрос вот в чем: когда я пользуюсь JEDI я иногда в стеке замечаню методы, в которые вообще вход быть не доолжен. Типа такого:

function C(): ... begin end; proceure B(...) begin raise ... end; procedure A() begin B(C()); end;

В этом (или каком-то очень похожем - закономерности я все-таки не понял до конца) случае в стеке быдет типа
A
C
B
т.е. как будто в ходе работы был вызов С. Он то был, но и возврат из него уже был.

Собственно вопрос - эта особенность нестранима, или я что-то не понимаю.

← →
GrayFace © (2007-02-27 18:41) [23]

Спасибо, посмотрю. Сам хотел такое делать и даже чуть-чуть сделал.

← →
Ketmar © (2007-02-27 18:43) [24]

> oldman © (27.02.07 17:34) [18]
счастливый...

← →
Сало © (2007-02-27 18:46) [25]

Не знаю, втянул из JCL 6 модулей, да и работает себе
JclDebug, JclHookExcept, JclPeImage, JclTD32, JclBase и JclFileUtils.

← →
Piter © (2007-02-27 19:10) [26]

Alex Konshin © (27.02.07 17:50) [20]
Что такое стек? Что значит вызов функции/метода из другого метода?
Могут быть и тысячи, но маловероятно. Тысячи могут быть, если у тебя рекурсия, а так - обычно не больше десятка.

а, все, понял. В общем, программка печатает стек. Но ведь далеко не все функции помещают аргументы в стек, верно? Если у функции, например, один параметр integer, так он вроде сразу в регистр будет запихнут?

Да и вообще... В стеке ведь хранятся аргументы для функций, как можно определить к какой функции что относится... :)

← →
Ketmar © (2007-02-27 19:33) [27]

> Piter © (27.02.07 19:10) [26]
эх. ну не качай ты эту муть. явно она тебе ещё не нужна...

← →
Piter © (2007-02-27 20:28) [28]

Ketmar © (27.02.07 19:33) [27]

бла бла бла :)

> Piter © (27.02.07 20:28) [28]
и я о том же. не понимашешь, что и зачем -- не бери. не стоят у тебя, значит, такие задачи, где подобная штучка сильно облегчит жизнь.

ну как можно узнать нужна ли тебе вещь, если ты вещью никогда не пользовался?

По твоей логике, если вещь ты никогда не использовал - значит, она тебе не нужна. Оригинально, но немного бредово ;)

> Piter © (27.02.07 21:06) [30]
ты без этого жил? жил. значит -- не нужна. была бы нужна -- ты бы искал нечто подобное и сразу понял бы, о чём речь. ничего бредового не вижу.

> [31] Ketmar © (27.02.07 21:12)

Не спорь ты с ним. Он ведь правда похоже считает, что суть в передаваемых в функции аргументах :)

Пару копеек - не получилось вывести трассировку в VCL Forms (пробовал через DebugUtils.HookException(ODS) и запуском DbgView от SysInternals;
В консольном приложении все прекрасно вышло.

> Игорь Шевченко © (27.02.07 22:56) [33]

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

Alex Konshin,

20070209 08:28:19.375 0041D76C: StructuredStreams.pas,568
20070209 08:28:19.375 0041DA25: StructuredStreams.pas,701
20070209 08:28:19.375 0041DAAC: StructuredStreams.pas,713
20070209 08:28:19.390 0041E2AE: StructuredStreams.pas,919
20070209 08:28:19.390 0041E2CA: StructuredStreams.pas,921
20070209 08:28:19.390 004243AB: NetThreads.pas,437
20070209 08:28:19.390 00424435: NetThreads.pas,461
20070209 08:28:19.390 0042447B: NetThreads.pas,464
20070209 08:28:19.390 00423A9E: NetThreads.pas,243
20070209 08:28:19.390 00423BDA: NetThreads.pas,266

Лучше еще сразу имя функции выводить. А то так не очень красиво. Было бы имя функции, тогда в некоторых случаях можно было бы определить ошибку еще до заглядывания в код.

У меня написана полностью своя трассировка стека и багрепорт, который автоматом отсылается мне на мыло, в случае unhandled exception содержит: место ошибки в виде модуль, метод, строка. Затем трассировку вызовов + если ошибка была в при открытии датасета, то его SQL + Скриншот экрана юзера + еще некоторую системную информацию.

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

> ZeroDivide © (28.02.07 00:16) [35]

Проблема в том, что в *.map попадают далеко не все имена функций. Поэтому в распечатку могут попасть функции, которые в памяти перед нужной функции,
что еще более некрасиво.
Но если есть желание, то можешь писать имена функций. Необходимая функциональность реализована. В тех примерах из лога это даже видно - в *.map нет информации о строках из System, но зато есть адреса функций оттуда, поэтому они и попадают в распечатку.
Я уже сказал, что на мой взгляд мой код более обозримый и человек с головой сможет подстроить его под свой вкус. C JCL кодом это было нереально - я безуспешно пробовал несколько раз, слишком много лишнего.

Еще одно замечание.
У меня реализован парсер *.map файлов, причем отдельно и без левых зависимостей. С таким же успехом можно довольно просто реализовать парсер TD32 информации или подключение карты из ресурсов/файлов и т.п.. Обратите внимание, что формат карты специально сделан таким, что он допускает загрузку-выгрузку ее в бинарном виде одним куском. То есть карта не содержит абсолютных ссылок, только смещения. Также не должно быть проблемой загрузить несколько карт. Мне это не нужно было, но я писал свой код имея в виду такую возможность.

То есть, по сути можно сделать любую функциональность, которая есть в JCL, при этом не захламляя лишним кодом. Считайте это набором "Сделай сам". На мой взгляд вполне простой в использовании набор :)

> Игорь Шевченко © (27.02.07 22:56) [33]
> Пару копеек - не получилось вывести трассировку в VCL Forms
> (пробовал через DebugUtils.HookException(ODS) и запуском
> DbgView от SysInternals;
> В консольном приложении все прекрасно вышло.

А что хоть происходит?
Ну у меня это сделано в сервисе, так что я с формами не тестировал, всякое может быть. Но по идее должно работать.
Ты включи отладку самого стектрейсера (в defines.inc), возможно поймешь в чем дело. Я на вскидку, конечно, не знаю в чем дело, но возможно, что трейсер не может найти конец место, где надо остановится раскручивать. Хотя, черт его знает что там у тебя случилось - ты же ничего конкретного не сообщил.

> Сало © (27.02.07 18:46) [25]
> Не знаю, втянул из JCL 6 модулей, да и работает себе
> JclDebug, JclHookExcept, JclPeImage, JclTD32, JclBase и
> JclFileUtils.

Работать-то может и работает, охотно верю. Только мне в сервисе столько хлама абсолютно незачем. Вот зачем мне формат PE executable, несколько парсеров карт и debug info и какие-то утилиты работы с файлами? У меня своих достаточно. Тем более, что это не основная, а вспомогательная функциональность, которая к основной задаче не имеет никакого отношения. И переделывать под себя эти модули из JCL очень затруднительно. На мой взгляд они перемудрили и накидали в кучу много лишнего. Нужно было более продумано распределить функциональность по модулям. Короче, проще было переписать все нафиг (типичный русский подход), что я и сделал :).

> novill © (27.02.07 17:51) [21]
> > [16] Alex Konshin © (27.02.07 17:31)
> EMapParserException: Table of publics by value is not found
> 0040A8EA: TestProject2.exe+98EA
> 0040AB16: TestProject2.exe+9B16
> 0040A55A: TestProject2.exe+955A
> 0040A587: TestProject2.exe+9587
> 00403DB0: TestProject2.exe+2DB0
> Exception EMapParserException in module TestProject2.exe
> at 0000A8EA.
> Table of publics by value is not found.
>
> Похоже просто парсилку придется "доработать напильником"

А кто говорил, что будет легко? :)
Наверно у тебя просто слишком маленький проектик и нет public методов. В реальных проектах эта таблица не будет пустой. Так как я это делал для конкретного реального проекта, то я и не стал заморачиваться с нереальными случаями.
Также возможно, что у тебя не включена отладочная информация, хотя вроде в таком случае в *.map все равно что-то все-таки попадает (хотя номеров строк уже не будет). Вот это я проверял, у меня работало и на урезаной карте.

> Kerk © (27.02.07 22:25) [32]
так я ж и пытался пояснить, что "нэ трэба!" (ц) %-)

> Alex Konshin © (28.02.07 02:34) [36]
> реализовать парсер TD32
где ж ты был неделю назад?! когда у меня ещё был жив раздел, на котором жили мои исходники? в том числе и выдраный из JCL (после чего переписаный почти заново) парзер TD32 debug info?! всё как всегда... а опять "втыкать" в формат (хоть он и простой) да писать нет желания. и времени тоже.

Трассировка exception в Delphi Найти похожие ветки