Дело о медленном входе в систему

Письма с описанием случаев возникновения различных проблем и предложения по их решению продолжают приходить в мой ящик. Я получил много историй, которые начинались с рассказа о, казалось бы, неразрешимых проблемах, а заканчивались их решением, либо, что не менее полезно, рецептом того, как эту проблему можно обойти. У меня накопилось несколько сотен таких случаев, зафиксированных в более чем 400 слайдах PowerPoint, которые являются прекрасным материалом для моего блога и серии обсуждений «Дело о необъяснимом», с которыми я выступаю на многих конференциях.

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

Эта история началась с того, что системный администратор крупной компании получил множество жалоб от конечных пользователей о том, что процесс входа в систему занимал три минуты. После входа в систему пользователи ни с какими проблемами не сталкивались, однако такая задержка, очевидно, была для них весьма неприятной. При этом остальные сотрудники, работающие с той же программной конфигурацией, с подобной проблемой не сталкивались. Пытаясь найти что-то общее между проблемными системами, администратор сделал запрос в базу данных конфигурации сети и обнаружил, что все эти системы были рабочими станциями Dell Precision 670. Он думал, что это его главная зацепка, пока не увидел, что в числе систем, которые работали нормально, находились точно такие же рабочие станции серии 670.

В поисках других подсказок он попытался проанализировать процесс входа в систему проблемных машин. Он воспользовался PsExec для запуска Process Explorer под учетной записью Local System, чтобы PE не завершился при выходе из системы и оставался активным во время следующего входа в систему. Поскольку проблемные компьютеры работали под Windows XP, командная строка, которую он использовал, выглядела следующим образом (см. конец этой статьи, чтобы узнать, как это сделать в системах Windows Vista и старше):

psexec -sid c:\sysint\procexp.exe

Параметр «-s» указывает PsExec на запуск процесса под учетной записью Local System, «-i» – на соединение процесса с интерактивным рабочим столом, чтобы было видно его окна, и «-d» – на мгновенный возврат без ожидания завершения целевого процесса. Обратите внимание, что если у вас включена функция быстрого переключения пользователей и вы вошли в систему не по нулевой сессии, не выходите из системы, а просто смените пользователя, авторизуйтесь под проблемной учетной записью и переключайтесь обратно на сессию, в которой вы запустили PsExec.

При последующем входе в систему он обратил внимание, что Lisa_client_7.0.0.0.exe, собственное рабочее приложение компании для учета, в течение некоторого времени активно использовала центральный процессор, далее следовал трехминутный простой, после чего она завершала работу, и затем возобновлялся обычный процесс входа в систему:

Еще до того, как Process Monitor заменил Filemon и Regmon, Дэвид Соломон сказал следующее: «Если сомневаешься, запускай Process Monitor!» (я неукоснительно следую этому совету). Этот случай – прекрасный пример применения этой философии на практике, поскольку то, что Process Monitor покажет причину зависания процесса, маловероятно, но, тем не менее, администратор обратился к этому инструменту.

После запуска Process Monitor с PsExec и регистрации процесса входа в систему он просмотрел полученный лог и начал его анализировать. Из-за того, что он увидел в Process Explorer, процесс Lisa_client стал первым подозреваемым, поэтому он щелкнул правой кнопкой мыши на имени процесса в одной и строк лога и выбрал пункт меню Include, чтобы убрать из отображаемого списка записи, связанные с другими процессами:

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

Он приятно удивился, когда обнаружил подобный поток, которые не только предшествовал трехминутной задержке, но и завершился с необычным кодом ошибки – IO DEVICE ERROR:

Оказалось, что процесс Lisa_client выполнял команду передачи данных через интерфейс SCSI на диск, на котором расположен главный том C:, причем эта операция завершилась спустя три минуты аппаратной ошибкой. Желая узнать, каков был результат выполнения этой команды на других рабочих станциях, которые не испытывали сложностей со входом в систему, он зафиксировал факт выполнения данной операции и обнаружил, что она выполнилась успешно и заняла меньше миллисекунды:

Этот факт ясно указывал на аппаратную проблему с жесткими дисками, установленными на проблемных компьютерах, потому он собрал данные о типах дисков, установленных на всех компьютерах, соотнес их с отчетами о медленных входах в систему, и обнаружил, что на всех медленных системах стояли диски Seagate, а на остальных – Fujitsu.

Его компания, очевидно, не собиралась заменять диски только для того, чтобы избежать проблемы, созданной ее собственным приложением, так что ему пришлось думать над тем, как эту проблему обойти. Он сообщил об ошибке команде разработчиков Lisa_client, которые ответили, что они могут убрать эту команду без потери функционала, но для обновления им потребуется несколько дней, чтобы пройти через внутренний процесс. На это время важно было обеспечить нормальную производительность систем для конечных пользователей, для чего он написал WMI-скрипт, который запрашивал тип системного диска и запускал Lisa_client только в том случае, если это была модель, отличная от Seagate.

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

В заключение, как я обещал выше, привожу последовательность действий по настройке приложения, чтобы оно смогло «пережить» выход и последующий вход в систему в Windows Vista, Windows Server 2008 и выше. Команда PsExec, которую я привел выше, не будет работать на этих операционных системах, поскольку Windows Vista включает в себя механизм изоляции нулевой сессии, которая требует несколько дополнительных команд для того, чтобы оставить доступным приложение после входа в систему. Во-первых, запустите утилиту в нулевой сессии с помощью программы PsExec для командной строки:

 psexec -sd -i 0 c:\sysint\procmon.exe

Вы увидите окно «Interactive services dialog detection» на панели задач, указывающее на то, что процесс запущен в окне в нулевой сессии рабочего стола. Переключитесь на это диалоговое окно и нажмите на кнопку «Show me the message», чтобы переключиться на этот рабочий стол:

Запущенная утилита доступна и вы сможете настроить ее так, как нужно (она работает под учетной записью Local System, потому ваша учетная запись не будет установлена по умолчанию). По завершении просто щелкните на кнопке Return для возвращения на основной рабочий стол. Теперь вы можете совершить выход и последующий повторный вход в систему для того, чтобы воспроизвести ошибку, которую исследуете. Когда снова войдете в систему, выполните через командную строку следующие команды, чтобы опять получить доступ к рабочему столу нулевой сессии:

 net stop ui0detect

net start ui0detect

Вернитесь на рабочий стол нулевой сессии, чтобы просмотреть зафиксированную информацию о процессе входа в систему, и закройте утилиту.

Напоследок хочу вам напомнить, что я уже опубликовал много других статьей об интересных диагностических случаях в этом блоге, и вы можете найти здесь. Вы также можете просмотреть записи из серии «Дело о необъяснимом» на сайте TechEd. Также не забудьте посетить конференцию TechEd, которая пройдет в июле в Новом Орлеане, где я расскажу о новых интересных случаях использования диагностических утилит Sysintenals.