Bug 1990

Summary: Нужно научиться получать backtrace с места генерации исключения
Product: WINE@Etersoft Reporter: Vitaly Lipatov <lav>
Component: Запуск ; Отладка ; ИсключенияAssignee: Виталий Перов <vitperov>
Status: CLOSED LATER QA Contact:
Severity: minor    
Priority: P5 CC: amorozov, baraka, ivan, lav, romand, smoke, vitperov, vostok
Version: unspecified   
Target Milestone: ---   
Hardware: PC   
OS: All   
Whiteboard:
Заявки RT: Связано с:
Дата напоминания:
Bug Depends on:    
Bug Blocks: 1677, 2305, 2521    
Attachments: Ловля программных исключений
для тестов.
Ловля программных исключений
Переделанный патч, позволяющий перехватывать программные исключения

Description Vitaly Lipatov 2008-06-25 11:27:00 MSD
Ряд проблем при отладке связан с тем, что мы не видим место и причину генерации исключения, невозможность увидеть backtrace приводит к слишком длительному неэффективному поиску ошибки.
Comment 1 Anton Rudnev 2008-08-18 16:52:58 MSD
Ничего не приходит в голову, кроме как написать парсер дебаглога, включающего строчки из каналов +snoop и +relay и исключающие строчки других каналов.

+relay дает нам строчки:
   Call: WineFunctionName ...
            ...
   Ret: WineFunctionName ...

+snoop дает нам строчки:
   CALL: DLLFunctionName ...
            ...
   RET: DLLFunctionName ...

Вот кусок простыни, который дает такой дебаглог:
-----------------------------------------------------------------------
            ...
0014:Call ntdll.wcschr(0125b99c L"  %0 page(s) processed, %1 page(s) left",00000025) ret=2142a8dd
0014:Ret  ntdll.wcschr() retval=0125b9a0 ret=2142a8dd
0014:Call msvcrt._errno() ret=21429bc0
0014:Call KERNEL32.GetLastError() ret=7e30b7d4
ну допустим здесь какая-либо ошибка с текстом starting debugger ...
            ...
-----------------------------------------------------------------------


Из нее можно получить текстовичек , например:
-----------------------------------------------------------------------
...
  mscvrt._errno
    KERNEL32.GetLastError()
      Starting Debugger
-----------------------------------------------------------------------

только пока не проверил, будет ли отображаться в дебаглоге Call-строчка той функции, которая крахнулась.
Comment 2 Vitaly Lipatov 2008-09-03 20:22:10 MSD
Ну всё же нужно научиться блокировать обработчик исключения, выставляемый в программе, или сделать так, чтобы он не мешал выводу backtrace.
Comment 3 Vitaly Lipatov 2008-09-04 18:22:24 MSD
Да, отключение обработчика должно быть управляемым через переменную окружения.
Comment 4 Anton Rudnev 2008-09-09 13:51:10 MSD
Created attachment 705 [details]
Ловля программных исключений

Думаю, что решений может быть несколько. Это как одно из возможных.

Пропатчив wine/dlls/ntdll/exception.c ловить программные исключения можно так:

1. Запустить приложение с установленной переменной SEHBLOCK=all, примерно так:
SEHBLOCK=all wwxp test.exe

2. Когда возникнет программное исключение, то программа остановит ход выполнения с запросом в консоли:
Handled exception.(D)ebugger, (c)ontinue, (s)top:

нажав 'c', программа продолжит своё выполнение используя программный обработчик.
нажав 'd', запустится отладчик, с бэктрейсом (программа при этом не прекратит свою работу, её можно будет продолжить, нажав затем на 'c')
нажав 's', программа завершит своё выполнение, без обработки исключения

просьба потестить на реальных багах.
Comment 5 Anton Rudnev 2008-09-16 20:09:08 MSD
в существующем патче как минимум две проблемы:
1) mscvrt подменяет глобальный обрабочик, таким образом отладчик не запускается.
2) иногда исключения происходят (и незаметно обрабатываются) по таймеру. Необходимо сделать систему фильтров, которые бы не засекали строго определённые исключения.

Состояние:
1) - решено
2) - ~70%
Comment 6 Vitaly Lipatov 2008-09-16 20:28:53 MSD
(In reply to comment #5)
> 1) mscvrt подменяет глобальный обрабочик,
> таким образом отладчик не запускается.
О каком msvcrt речь? Возможно нужно явно указывать, что мы используем встроенную в wine библиотеку.

> Состояние:
> 1) - решено
> 2) - ~70%
Там сверху есть оценка времени, если её указать, проценты завершения багзилла сама будет считать. 

Comment 7 Виталий Перов 2008-09-16 21:29:26 MSD
Хотелось бы получить текущую версию для тестирования.
Comment 8 Anton Rudnev 2008-09-17 13:20:00 MSD
Created attachment 730 [details]
для тестов.

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

вместо переменной окружения SEHBLOCK использовать WINESEHBLOCK, т. е. запуск:
WINESEHBLOCK=all wwxp test.exe
c - продолжение программы после исключения (применение встроенного обработчика)
d - вызов отладчика
s - завершение программы
f, f+, f- - недоделанные фильтры
Comment 9 Anton Rudnev 2008-09-17 13:30:03 MSD
(In reply to comment #6)
> (In reply to comment #5)
> > 1) mscvrt подменяет глобальный обрабочик,
> > таким образом отладчик не запускается.
> О каком msvcrt речь? Возможно нужно явно
> указывать, что мы используем встроенную в
> wine библиотеку.

то, что оно подменяет глобальный обработчик UnhandledExceptionFilter() своим через SetUnhandledExceptionFilter(), справедливо и для сторонней и для встроенной библиотеки. Решение состоит в том, чтобы блокировать SetUnhandledExceptionFilter() при назначенной переменной окружения, не пропуская попытки заменить обработчик UnhandledExceptionFilter, каким-то своим.
Comment 10 Виталий Перов 2008-09-17 19:28:21 MSD
Проверил на Декларанте.

Бутылка deklarant. Программа c:/CTM/DCL/dcl.exe
Со включенным перехватом исключений повисает примерно на середине загрузки.
С выключенным перехватом такого не происходит
Comment 11 Anton Rudnev 2008-09-19 17:40:25 MSD
Created attachment 739 [details]
Ловля программных исключений

Если был установлен предыдущий патч, то откатить и установить этот.

Запуск:
WINESEHBLOCK=all wwxp test.exe

Вначале, при старте, отлаживаемая программа может попытаться подменить глобальный обработчик UnhandledExceptionFilter, каким-то своим.
Когда это происходит, ход выполнения останавливается и выводится на экран следующее:
Call SetUnhandledExceptionFilter. Current filter - адрес1, new filter - адрес2.
[A]llow, [i]gnore(default)?:
где адрес1 - адрес текущего глобального обработчика, а адрес2 - адрес глобального обработчика, который навязывается программой.
a - подмена глобального обработчика произойдет.
i (или просто нажать на Enter) - подмены не произойдет.

Далее возникают программные исключения. Например:
Handled exception code=e06d7363, flags=1, addr=0x7b843228, parameters[3]={19930520, 32e1e4, 10634efc}
[d]ebugger, [c]ontinue, [e]xit, [h]elp:

d - вызовет отладчик winedbg
c - продолжит выполнение программы, дав обработать исключение отлаживаемой программе
e - завершит программу
h - вывод на экран краткой справки

Как видно из сообщения об исключении, у него имеются некоторые атрибуты:

code - причина возникновения исключения: ее значения могу быть EXCEPTION_ILLEGAL_INSTRUCTION, EXCEPTION_ACCESS_VIOLATION, EXCEPTION_INT_DIVIDE_BY_ZERO, и т. п. соответствия этих макросов с числовыми значениями можно искать в wine/include/winbase.h

flags - флаг исключения. Бывает двух значений:
#define EXCEPTION_CONTINUABLE        0
#define EXCEPTION_NONCONTINUABLE     0x01
(из wine/include/winnt.h)

addr - адрес где произошло исключение.
возможно не всегда, но это скорее всего значение регистра ip команды, следующей за командой, где произошло исключение.

parameters - параметры исключения.
Зависят от вида исключения. Если отлаживаемая программа сама насильно вызвала исключение, то эти параметры она может передать в качестве аргументов при вызове RaiseException ( http://msdn.microsoft.com/en-us/library/ms680552(VS.85).aspx )
количество параметров не превышает #define EXCEPTION_MAXIMUM_PARAMETERS 15

По атрибутам можно установить скип - условие, состоящее из равенств атрибутов, которое, если оказывается истинно, для произошедшего исключения, то выполнение программы не приостанавливается, а проходит дальше.
Скип состоит из равенств разделенных пробелами, например:
addr=7b843228 code=e06d736 parameters[1]=32e1e4
По этому скипу, если произойдет исключение с кодом e06d736, по адресу 7b843228, и вторым параметром равным 32e1e4, то выполнение программы приостановлено не будет.
Скипов может быть несколько. Если сработает хотя бы один из списка, то программа продолжит своё выполнение не останавливаясь.

Для работы со скипами можно использовать следующие команды:
s - выводит список скипов
s+ СТРОКА_СКИПА - добавляет к списку скипов новый скип указанный в СТРОКА_СКИПА
s- НОМЕР_СКИПА - удаляет из списка скипов скип по его номеру
s. - добавляет скип для текущего исключения в список скипов без параметров
s= - добавляет скип для текущего исключения в список скипов с параметрами
результат добавления/удаления скипа, можно увидеть через вывод списка скипов.

не стал менять printf на MESSAGE.
Если это сделать, то последовательность ввода и вывода нарушается, например
      MESSAGE("[d]ebugger, [c]ontinue, [e]xit, [h]elp:");
      fgets(command, 256, stdin);
здесь сначала, будет запрошена и записана в command строка от пользователя, а уж потом будет вывод строчки "[d]ebugger, [c]ontinue, [e]xit, [h]elp:", что никак не соответствует тому, что ожидается.
Comment 12 Anton Rudnev 2008-09-23 11:14:04 MSD
> не стал менять printf на MESSAGE.
> Если это сделать, то последовательность
> ввода и вывода нарушается, например
>       MESSAGE("[d]ebugger, [c]ontinue, [e]xit, [h]elp:");
>       fgets(command, 256, stdin);
> здесь сначала, будет запрошена и записана в
> command строка от пользователя, а уж потом
> будет вывод строчки "[d]ebugger, [c]ontinue, [e]xit, [h]elp:",
> что никак не соответствует тому, что
> ожидается.

Догадка, почему это происходит.

Когда мы пишем, к примеру  TRACE("string"), то оно кидает "string" в stderr не сразу, а пишет его сначала в промежуточный буфер. Пишет до тех пор, пока не встретит \n.  И только тогда, когда в TRACE встречается "\n" например, TRACE("other-string1\nstring"), оно скидывает в stderr до символа \n включительно.

Сделано это для того, что перед строкой в TRACE писать префикс "имя_канала:имя_функции" в процессе скидывания очередной строки в stderr.

MESSAGE, вероятно работает по такому же алгоритму, хоть и не должна (она не выводит префикса).
Comment 13 Vitaly Lipatov 2009-07-26 13:21:12 MSD
Опубликовал описание на вики
http://freesource.info/wiki/WINE/UpravlenieObrabotchikomIskljuchenijj
Comment 14 Виталий Перов 2010-05-17 19:02:18 MSD
Патч не прикладывается. Пробую переделать - пока не получается
Comment 15 Виталий Перов 2010-05-17 19:18:33 MSD
функции call_stack_handlers и raise_exception раньше были в файле exception.c. Теперь они в файле signal_i386.c
Comment 16 Виталий Перов 2010-05-17 19:53:51 MSD
Created attachment 1702 [details]
Переделанный патч, позволяющий перехватывать программные исключения
Comment 17 Виталий Перов 2010-05-17 20:00:39 MSD
Протестировал патч на Гаранте.
При подмене обработчика исключений выводится сообщение с выбором действия.
Как при выборе "разрешить", так и при выборе "игнорировать" программа выполняется немного дальше, и зависает после очередного вызова GetModuleHandle:

fixme:module:LoadLibraryA Loading library 'winex11.drv', result=2119565312
err:module:GetModuleHandleExA Invalid address 0x4. Eterhack: return 0

Хорошо бы проверить патч на другой программеjavascript:void(0)
Comment 18 Виталий Перов 2010-05-17 20:34:19 MSD
Патч требует доработок:
1) операция getenv("WINESEHBLOCK") выполняется долго. хорошо бы вызывать её только один раз, сохраняя результат.
2) Сообщение printf"[A]llow, [i]gnore(default)?:" выводится не всегда.
Comment 19 Виталий Перов 2010-05-17 20:49:15 MSD
ещё проблема с функцией c = fgetc(stdin).
Почему-то она завершается сразу не дожидаясь ввода символа
Comment 20 Виталий Перов 2010-10-22 13:12:40 MSD
Общий вывод следующий:
Патч определённо представляет какую-то пользу.
В некоторых случаях он может помочь.
Но во многих ситуациях он не работает корректно. Нужно вложить много сил и времени, чтобы довести его до приемлемого состояния
Comment 21 Роман Дадьков 2012-02-10 20:13:29 MSK
переделал для баги 5892. не все виды исключений обрабатываются, но для того чтобы просто уронить и посмотреть стек хватает. на всякий случай отправил патч на wine-patches@
Comment 22 Роман Дадьков 2012-06-09 18:54:35 MSK
вынес все в отдельные функции:
show_filters
check_arg
check_string
auto_continue
eter_raise_exception
изменения в raise_exception (та, которая в signal_i386, есть и в других, но там я ничего не стал трогать) сводятся исключительно к вызову eter_raise_exception.

в kernel32/except.c тоже все вынес в отдельную функцию EterUnhandledExceptionFilter, она теперь вызывается в SetUnhandledExceptionFilter.

патч для eterhack и eter-2.0

отправил патч на wine-patches@
Comment 23 Роман Дадьков 2012-06-21 18:18:59 MSK
на данный момент, отключается глобальный обработчик исключений или заменяется на управляемую обработку.
Comment 24 Роман Дадьков 2012-06-22 17:16:39 MSK
ва принципе место возникновения ошибки показывается. то есть можно уже в ручную взять поставить там точку останова и работать при помощи wwdbg.
но можно попробовать вывести backtrace сразу. для этого, пока не ясно как приаттачиться к текущему процессу.
Comment 25 Vitaly Lipatov 2014-09-11 18:50:12 MSK
Для тех, кто не пользуется багзиллой или не умеет пользоваться групповым редактированием при поиске, закрываем задачи, которые они должны были принять.