Bug 9439

Summary: Гарант: не обнаруживается сервер консультаций при установке
Product: WINE@Etersoft Reporter: Svetlana Zhukova <svzhu>
Component: Установка программ / MSIAssignee: Сергей Гуральник <serhio>
Status: DEFERRED --- QA Contact: Svetlana Zhukova <svzhu>
Severity: critical    
Priority: P1 CC: kondratyuk, lav
Version: 2.1   
Target Milestone: ---   
Hardware: PC   
OS: All   
Whiteboard:
Заявки RT: 31985 Связано с:
Дата напоминания:

Description Svetlana Zhukova 2013-07-22 13:24:23 MSK
swine 2.1 garant/780-cs
WINE@Etersoft SQL 2.1.3/2.1.0-eter4/3

Версия 7.08.0.163 cs
Установка на этапе "проверяется доступность сервера консультаций" завершается падением.
Comment 2 Сергей Гуральник 2013-08-26 18:08:18 MSK
(В ответ на comment #0)
> swine 2.1 garant/780-cs
> WINE@Etersoft SQL 2.1.3/2.1.0-eter4/3
> 
> Версия 7.08.0.163 cs
> Установка на этапе "проверяется доступность сервера консультаций" завершается
> падением.

Установка действительно может визуально нормально продолжаться, т.к. падает дочерний процесс. 
wine: Unhandled page fault on read access to 0x00000050 at address 0x4ffae8 (thread 0083), starting debugger...
Comment 3 Сергей Гуральник 2013-08-30 15:56:13 MSK
(В ответ на comment #2)
> wine: Unhandled page fault on read access to 0x00000050 at address 0x4ffae8
> (thread 0083), starting debugger...

В надежде узнать откуда  берется это исключение сделал +all лог, который может помочь в этом деле. Положение затрудняет то, что перед сообщением об исключении отсутствуют какие-бы то ни было сообщения об ошибках или предупреждения, Пока ничего особо ценного извлечь не удалось.
Comment 4 Сергей Гуральник 2013-09-03 16:57:54 MSK
Продолжаю возиться с логом.
Пока наибольшие подозрения вызывает эта последовательность:

007f: destroy_window( handle=000100d8 )
x80044 -> 3
...
007f: destroy_window() = 0
...
0080: set_class_info( window=000100d8, flags=00000000, atom=000011212.645:0013:trace:xrender:LookupEntry 3
...
0080: get_window_text( handle=000100d8 )
0080: get_window_text() = ERROR_INVALID_WINDOW_HANDLE { text=L"" }
...
11212.646:0080:trace:msg:PostMessageW hwnd 0x100d8 msg 0 (WM_NULL) wp 0 lp 0
...
0080: get_window_info( handle=000100d8 )
0080: get_window_info() = ERROR_INVALID_WINDOW_HANDLE { full_handle=00000000, last_active=00000000, pid=0000, tid=0000, atom=0000, is_unicode=0 }
...
11212.646:0080:trace:seh:raise_exception code=c0000005 flags=0 addr=0x4ffae8 ip=004ffae8 tid=0080

Возможно факт уничтожения окна некорректно обрабатывается чем-то из этой цепочки.
Comment 5 Сергей Гуральник 2013-09-04 17:31:58 MSK
Более пристальный анализ хода установки показал что падение происходит в процессе F1ConsultChecker.run.
> wine: Unhandled page fault on read access to 0x00000050 at address 0x4ffae8
> (thread 0083), starting debugger...
На этом месте при запуске программы находятся нули, т.е код в этом месте генерируется в рантайме. Ничего особенного в нем нет.
Вот кусок командной строки используемой при запуске чекера:
trace:process:create_process_impl app (null) cmdline L"\"C:\\Program Files\\Garant-Server\\apps\\winNT\\F1ConsultingChecker.run\" -ConsultingTransportConfig \"C:\\Program Files\\Garant-Server\\settings\\garant.ini\" -GCMConfigFile \"C:\\Program Files\\Garant-Server\\garant.ini\" -GPMAdapterConfigSection \"F1Server Params\" -ORBLogFile \".\\..\\..\\logs\\"...

Как мне кажется многоточие указывает на то что в лог попала не вся строка (вероятно из-за ограничения какого-нибудь внутреннего буфера отладочной печати).
Попытки получить полную командную строку пока  безуспешны. Как только я добавляю вывод командной строки через printf или сбрасывая на диск падения тотчас же прекращаются. Похоже на обращение по невалидному адресу/выход за границу буфера.

После извлечения целой командной строки можно попытаться запустить чекер автономно, возможно это позволит увидеть проблему в более удобном для исследования виде.
Comment 6 Сергей Гуральник 2013-09-06 16:24:58 MSK
Извлечь командную строку удалось:
"C:\Program Files\Garant-Server\apps\winNT\F1ConsultingChecker.run" -ConsultingTransportConfig "C:\Program Files\Garant-Server\settings\garant.ini" -GCMConfigFile "C:\Program Files\Garant-Server\garant.ini" -GPMAdapterConfigSection "F1Server Params" -ORBLogFile ".\..\..\logs\checker.log" -AutoTest

Если отдать ее на исполнение то возникает то же самое исключение что описывалось ранее, причем так же нестабильно. Из за этого пока не удается получить backtrace процесса в момент обработки исключения.
Comment 8 Сергей Гуральник 2013-09-09 09:23:10 MSK
(В ответ на comment #7)
> (В ответ на comment #6)
> > Извлечь командную строку удалось:
> Как?

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

P.S. Получение командной строки во время обработки исключения позволяет стопроцентно узнать в каком процессе происходит сбой, не загромождая при этом результат командными строками других процессов.
Comment 9 Сергей Гуральник 2013-09-10 17:43:32 MSK
Просмотрев код гаранта в месте крэша можно увидеть, что его причиной является разыменование нулевых this-указателей (иногда это не 0x0 а 0x1) или точнее попытка прочитать поле объекта используя этот указатель. Продолжаю работать с логом на предмет поиска вызовов которые потенциально могли бы портить стек.
Comment 10 Vitaly Lipatov 2013-09-10 18:37:34 MSK
(В ответ на comment #9)
> Просмотрев код гаранта в месте крэша можно увидеть, что его причиной является
> разыменование нулевых this-указателей (иногда это не 0x0 а 0x1) или точнее
> попытка прочитать поле объекта используя этот указатель. Продолжаю работать с
> логом на предмет поиска вызовов которые потенциально могли бы портить стек.
Иногда бывает, что никто не портил, просто объект не создался или не создавался.
Если указатель хранится в стеке, то я бы проверял простой вариант, поставив точку останова на функцию, где происходит падение, и посмотрев, как заполняются локальные переменные.
Comment 16 Svetlana Zhukova 2013-11-01 12:58:56 MSK
И все-таки бага проявляется.
При установки версии 7.08.1 и 7.09.1 в wine из testing.
Comment 17 Svetlana Zhukova 2013-11-01 13:01:39 MSK
(В ответ на comment #16)
> И все-таки бага проявляется.
> При установки версии 7.08.1 и 7.09.1 в wine из testing.

После killall wineserver + wineserver -k повтрная установка работет корректно.
Comment 19 Svetlana Zhukova 2013-11-01 13:54:58 MSK
При очередной установке появилась ошибка wine "получены неверные параметры", в консоли:

fixme:storage:create_storagefile Storage share mode not implemented.
fixme:browseui:ProgressDialog_StartProgressDialog Reserved parameters not null ((nil), 0x33fa44)
wine: Unhandled page fault on read access to 0x00000000 at address 0x3b9e98 (thread 0079), starting debugger...
после чего установка продолжилась.
Comment 22 Vitaly Lipatov 2014-09-11 18:41:19 MSK
Откладываем задачи, к которым не обращались более 100 дней.