Дело об ошибке печати

Самые интересные случаи, рассказы о которых я получаю, связаны с демонстрацией уникальной техники поиска неисправностей или раскрывают интересную основную причину. Данный случай объединяет оба случая. Началось все с того, что системный администратор получил отчет от пользователя, в котором говорилось о том, что он не может напечатать документ с компьютера. Не было никакой видимой реакции на нажатие кнопки OK в диалоге печати или при выборе соответствующего пункта меню, тогда как обычно наблюдалось сообщение диалогового окна об отправке документа на принтер и появление значка в системное трее, говорящего об активности очереди печати.

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

clip_image001clip_image002

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

Администратор обратился к Sysinternals Procdump. Procdump – это утилита, которая генерирует файлы аварийного содержимого памяти процесса, когда случаются указанные вами события. Реализованные триггеры включают в себя использование CPU, использование виртуальной памяти, необработанные исключения и завершение процесса. Например, вы можете взять триггер использования CPU для фиксации состояния процесса, когда он вызывает кратковременную полную загрузку CPU, позволяя вам изучить этот процесс для обнаружения причины подобного скачка загрузки. Администратор предположил, что трассировка стека завершившегося потока может дать подсказку.

Он знал, что у него в распоряжении есть некоторый промежуток времени для запуска Procdump после старта службы очереди печати. Потому он запустил Notepad, попытался начать печать и затем запустил Procdump с параметром -e и именем процесса Spooler Service (Spoolsv), чтобы Procdump ожидал выхода службы до того, как записать файл дампа. Несколькими секундами позже Procdump сообщал о завершении работы и сохранении файла дампа:

clip_image003

Он открыл дамп в Windbg и выполнил команду «k», которая вызывает дамп стека потока, вызвавшего сбой, в Windbg. Трассировка стека, которая по существу заключается в перечислении записей вызовов функций, выполненных перед сбоем, показала, что процесс «умер» в последовательности вызовов, включающих несколько функций Ldr, в том числе LdrpLoadDll:

clip_image004

Поиск в сети показал, что LdrpLoadDll – это функция, связанная с системным загрузчиком DLL. Подозревая, что процесс умер либо из-за того, что он не смог найти нужную DLL, либо из-за того, что была загружена неправильная DLL, он обратился к Process Monitor, который позволит ему увидеть активность файловой системы, связанную с DLL. Он запустил Process Monitor, снова попытался запустить печать и затем остановил сбор данных. Пройдя этот путь от окончания трассировки к началу, он хотел найти подсказки, указывающие на первопричину ошибки. Незадолго до выхода Spoolsvc, он увидел, что этот процесс не смог найти Localspl.dll в различных директориях системы:

clip_image005

Он предположил, что данная DLL должна быть там. Когда он посмотрел в другой идентичной конфигурации системы Windows XP в его сети, он обнаружил Localspl.dll в директории \Windows\System32, но в проблемной системе ее на месте не было:

clip_image006

Описание файла сообщало, что это библиотека локального диспетчера очереди (Local Spooler DLL), что объясняло неспособность диспетчера печати поддерживать операцию печати. После копирования файла из рабочей системы, он смог удачно напечатать документ.

Проблема была решена и пользователь смог вернуться к работе, но у администратора оставался один вопрос – что же случилось с оригинальной DLL? На форумах в сети он нашел темы, описывающие похожую проблему, с которой сталкивались другие пользователи. В одной из них были описаны те же самые признаки, которые он наблюдал, включая записи журнала событий, аналогичное решение в виде копирования Localspl.dll из другой системы, и в этой теме источником ошибки называли деинсталляторы стороннего программного обеспечения для печати и факса, которые неправильно удаляли Localspl.dll:

clip_image007

Он не мог сказать наверняка, имела ли место похожая ситуация на данной конкретной системе, поскольку пользователь не мог вспомнить, удалял ли он программное обеспечение для печати или факса, но данная тема на форуме по крайней мере дала ему теорию о возможной причине загадочного удаления данных файлов из системы. Он смог решить проблему с помощью Procdump и Process Monitor.

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