Хроника одного бага

Проект, над которым я работаю, предполагает довольно серьезные изменения некоторых компонентов системы, которые могут откликнуться проблемами с совместимости с существующими приложениями. В Microsoft-е совместимостью разве что малых детей не пугают, соответственно любое подобное изменение не обходится без внимания Application Compatibility team. В моем случае это означает, что я должен прогнать N-ое количество приложений через систему автоматических тестов и убедиться что все работает. И исправить если что-то не работает.

На прошлой неделе меня порадовал корейский MS Publisher 2000. После инсталляции, при каждом запуске появлялось окно Windows Installer, чего не наблюдалось на эталонной системе. Было похоже, что приложение безуспешно пытается установить какой-то отсутствующий компонент.

Хорошо. Запускаю приложение под отладчиком и останавливаю его в момент, когда появляется окно инсталлятора. В стеке – цепочка вызовов: mspub.exe -> … -> mso9.dll -> msi.dll. msi.dll это системная DLL, часть Windows Installer. mso9.dll – компонент MS Office и похоже, что интересующий меня кусок кода находится именно там. По крайней мере, функции из msi.dll похоже отвечают за установку features, что бы это не означало в данном конкретном случае. Проблема однако в том, что символы mso9.dll не доступны, а по куску из msi.dll не понятно, какая именно feature устанавливается.

Покопавшись во внутренней сети нашел как получить доступ к символам Office. Выясняется, что это может занять 6 и более часов. :-( Запрашиваю доступ и продолжаю коматься в отладчике без символов. В стеке выуживается строчка «UserData», которая, похоже, имеет непосредственное отношение к устанавливаемой feature. Поиск в реестре этой строчки находит много всего и ничего конкретного.

День второй.

На следующий день у меня уже есть доступ к хранилищу символов MS Office. Снова лезу в отладчик, но символы все равно не находятся. «.symopt+0x80000000» - выясняется, что нужных символов в хранилище похоже нет, так как моя mso9.dll была скомпилирована в 1999 году. Почесав затылок не придумал ничего лучше, как подменить mso9.dll версией на четыре года свежее. Как ни странно – заработало!

Вчерашняя догадка, что “UserData” – это название feature подтверждается, но что с этим знанием делать по-прежнему не понятно. Пробую декомпилировать .msi файл инсталляции. dark.exe из WiX, который был под рукой, не работает. Трачу еще полчаса на поиски Orca.

С его помощью по ключевой строке UserData нахожу путь “01:\Software\Microsoft\Office\9.0\UserData”. Проверяю – такого пути действительно нет (01 – это “HKEY_CURRENT_USER”) и Process Monitor показывает, что Publisher пытается открыть именно этот ключ. Тем не менее инсталлятор создавать этот ключ отказывается. Пробую несколько раз и наконец вижу, что нужный ключ создается, но создается он не в “HKEY_CURRENT_USER”, а в “HKEY_USER.DEFAULT”!?

“HKEY_USER.DEFAULT” – это “HKEY_CURRENT_USER” для учетной записи Local System. Это уже похоже на проблему с имперсонировнием учетных записей в msiexec.exe, который, в одном из своих воплощений запускается как служба под учетной записью Local System. Проблема только в том, что я не менял ничего, чтобы относилось к имперсонации.

Третий день.

Во время инсталляции процессы msiexec.exe плодятся как кролики. Определить какой из них создает ключ не всегда просто. Поэтому я просто добавляю код в NtCreateKey и NtOpenKey, который бросает отладочное исключение когда видит, что создается или открывается интересующий меня ключ. По ходу дела пишу письмо Руссиновичу – мол неплохо бы добавить в Process Monitor возможность генерировать отладочное исключение по нужному событию. На следующий день он отвечает – «да, неплохо бы, но ты один такой, кому это надо».

Запускаю инсталляцию и ловлю третий вызов NtOpenKey, как показал лог из Process Monitor. “!token” говорит, что текущий пользователь – Local System. «Ага!» – сказали сибирские мужики. «Фиг вам!» - ответила бензопила Дружба. Делаю тот же трюк на эталонной системе – текущий пользователь тоже Local Sуstem. Описатели ключей при этом по-прежнему показываю на разные ключи: “HKEY_CURRENT_USER” администратора и “HKEY_USER.DEFAULT”.

Иду на поклон к гуру реестра. Он подсказывает, где псевдо описатели вроде “HKEY_CURRENT_USER” отображаются на настоящие описатели ключей. Ставлю точку останова по записи в переменную, где хранится описатель для “HKEY_CURRENT_USER”. Запускаю инсталляцию и ничего не происходит. Переключаюсь в ядерный отладчик, делаю это еще раз – и вижу где именно открывается этот описатель. На двух системах это происходит в совершенно разных местах и действительно, на эталонной системе msiexec.exe имперсонирует клиента, а на сбойной системе – нет.

Далее, ориентируясь на «правильный» стек, ставлю точку останова на том месте, где код сервиса получает RPC вызов от клиента запрашивающего инсталляцию. Фокус удаётся и дальнейшее дело техники. Просто трассирую код ориентируясь по эталонному стеку. Несколько раз промахиваюсь, но в конце концов нахожу проблемное место. Оказалось, что код отображения “HKEY_CURRENT_USER” на настоящий описатель проверял не имперсонирует ли текущий поток кого-либо и если это так, то полученный описатель не сохранялся в глобальной таблице. Вместо этого туда попадал описатель открытый сразу после вызова RevertToSelf, который как раз показывал на “HKEY_USER.DEFAULT”.

Спрашиваю гуру что, мол, за дела? А он говорит, что да, помню было такое исправление, которое потом откатили назад, так как оно сломало множество приложений. А моя ветка создавалась именно в момент, когда это исправление еще не откатили…

Итог – две строчки кода равняются 24 часам отладки. :-)

Upd: Почему-то все решили, что баг был в Windows Installer. Это не так, баг сидел совсем в другом месте. Инсталлятор, как и любое другое приложение, просто вызывал этот код.