Время от времени в своей работе технический специалист сталкивается с проблемами различных этапов функционирования операционной системы Windows: проблемами загрузки, завершения, гибернации, сна и прч. В подавляющем большинстве случаев подобные инциденты проявляются в том, что операционная система долго стартует, либо долго завершается, визуально это может выражаться как непривычно долго "висящие" на экране надписи Загрузка Windows, Завершение работы либо черный экран с курсором или без при загрузке/завершении. Иногда подобные этапы могут затянуться очень уж надолго, переходя все грани приличия. К решению подобного рода проблем существует множество подходов, одни состоят в использовании проверенного временем “метода тыка”, когда отключаются стоящие в автозапуске программы, сервисы этапа загрузки, другие же являются более продвинутыми и заключаются в применении специализированного диагностического инструментария от команды Microsoft, который позволяет получить о проблеме достаточно подробную информацию. В данной статье мы будем рассматривать, пожалуй, один из самых результативных способов диагностики проблем загрузки и завершения Windows - использование утилит комплекта Windows Performance Toolkit, таких как xbootmgr, xperf, xperfview.
Сделаем небольшое отступление и поговорим об общих причинах подобного поведения системы. В общем случае, медленная загрузка/завершение Windows может быть вызвана проблемами в работе драйверов устройств (обычно сторонних), сервисов либо приложений этапа загрузки, стартующих на различных этапах загрузки ОС. Теоретически, любой компонент операционной системы, стартующий на этапах загрузки/завершения ОС, может являться источником существенного увеличения времени, требующегося для выполнения всех фаз процесса загрузки/завершения. Причиной может быть как некорректное проектирование данного программного обеспечения, так и неисправность аппаратной части компьютера. К примеру, программа может выполнять многочисленные (избыточные) обращения к реестру, что, в свою очередь, так же может являться причиной общего падения производительности.
Для того, чтобы локализовать проблему с точностью до участка кода проблемного компонента, Microsoft предлагает широкому кругу специалистов набор специализированных утилит для диагностики различных аспектов быстродействия системы, который носит название Windows Performance Toolkit. Инструментарий Windows Performance Toolkit использует технологию Трассировки Событий (Event Tracing for Windows, ETW). На самом деле, ETW это довольно обширная область знаний, изучение которой представляет особый интерес для специалиста и описание которой может развернуться на добрую серию статей, однако здесь я приведу лишь основные термины.
Сказать иначе, это своеобразный расширяемый механизм логирования, встроенный в систему Windows. Реализован на уровне ядра, позволяет по запросу собирать события от приложений пользовательского режима, драйверов режима ядра и непосредственно кода самого ядра. Дело в том, что во многие компоненты ядра Windows, да и некоторые драйверы устройств включена возможность отслеживания операций с целью дальнейшего использования накопленной статистики при поиске причин системных сбоев. ETW предоставляет обширнейшую информацию по функционированию, как то, переключение контекста, статистика по прерываниям, отложенные вызовы процедур (DPC), процедуры обработки прерываний (ISR), создание и уничтожение процессов и потоков, дисковый ввод-вывод, ошибки страниц, переходы процессора между режимами в рабочем состоянии (p-state), операции с реестром, и многое другое. Предоставляется возможность включать запись событий "на лету", без необходимости перезагрузки системы либо приложения. События трассировки содержат заголовок события и зависящие от поставщика (провайдера) данные, описывающие текущее состояние приложения или операции.
Сам по себе инструментарий Windows Performance Toolkit содержит достаточно большое количество средств диагностики, из которых, в свете решения проблем различных этапов работы операционной системы, нас будет интересовать лишь несколько приложений, это утилиты xbootmgr, xperf и xperfview.
- xperf - контроллер провайдеров и сессий трассировки. Утилита командной строки, имеющая широкий функционал: контроль процесса трассировки, обработка данных трассировки (поддержка анализаторов, называемых действиями, которые генерируют отчет об отдельных составляющих трассировки), старт/останов сессий трассировки, фильтрация собираемых событий, постобработка данных трассировки (конвертация из ETL в XML, объединение данных трассировки, добавление мета-данных в трассировку). В дополнение к основному функционалу, утилита может использоваться как анализатор результатов, однако, поскольку запускается только из командной строки, для визуализации вывода все-равно использует xperfview. Интересная особенность утилиты заключается в том, что она может использоваться как отдельный трассировщик событий уровня ядра прямо в процессе работы операционной системы.
- xbootmgr - контроллер провайдеров и сессий трассировки. По сути тот же
xperf, предназначенный для автоматизации определенных сценариев: по заданным условиям запускает/останавливает сеансы регистрации, автоматизирует процедуры изменения состояний операционной системы, выполняет автоматическую перезагрузку системы заданное количество раз, контролирует трассировку на всем протяжении переключений состояний, позволяет коллекционировать статистику по строго определенным системным событиям (загрузка, завершение, переход в/из режим сна, ожидание). - xperfview - потребитель, получатель или визуализатор результатов производительности с графическим интерфейсом. Основное назначение - извлечение данных трассировки из файлов протоколов сессий ETW и представление их в графическом виде в форме графиков и таблиц. По моему мнению, наиболее удобный инструмент для анализа результатов трассировки.
В дальнейшем, накопленные данные трассировки могут быть использованы для отладки приложения и диагностирования проблем быстродействия. Контроллеры xbootmgr/xperf коллекционируют данные событий трассировки в специальные регистрационные файлы формата .etl.
Своим появлением ETW существенно расширила функционал встроенной системы журналирования Windows, благодаря чему она научилась получать данные от системных и пользовательских провайдеров ETW. В повседневной работе Вы можете наблюдать данные события через службу Журнала Событий, в оснастке "Просмотр Событий" (в разделе "Журналы приложений и служб"), потому как Служба событий может подписываться на любые события, которые предоставляет ETW посредством провайдеров событий.
Одна из основных особенностей ETW, поддерживаемой в WPT, заключается в поддержке символов для декодирования и профилирования стеков вызовов потоков, что дает возможность увидеть виновника сбоя вплоть до функции в коде, эта возможность крайне полезна и открывает такие перспективы, как отладка без отладчика.
Установка и настройка
На более-менее живой системе установить набор Windows Performance Toolkit может посредством полного инсталлятора Windows SDK. Я уже подробно описывал процесс установки Debugging Tools for Windows, по ней можно с легкостью установить и Windows Performance Toolkit. Просто во время установки не забудьте отметить пункт "Windows Performance Toolkit". Помните, что лучше было бы установить дистрибутив, соответствующий разрядности Вашей платформы. По окончании установки рабочий каталог инструментария при установке из пакета: C:\Program Files\Microsoft Windows Performance Toolkit, при установке посредством онлайн-инсталлятора: C:\Program Files (x86)\Windows Kits\XX\Windows Performance Toolkit, хотя пути могут в будущих дистрибутивах и измениться.
Несколько сложнее дела обстоят с системой, в которой имеются проблемы загрузки в нормальном режиме. Дело в том, что ..
Для выхода из подобных обстоятельств имеется три решения:
- компоненты WPT могут работать в качестве переносных приложений, достаточно скопировать с рабочей системы каталог Microsoft Windows Performance Toolkit и использовать его в качестве портабельной версии. Единственное, учитывайте разрядность систем!!
- можно использовать хитрый твик реестра для установки .msi в безопасном режиме.
- можно использовать альтернативное решение - утилиту Process Monitor в режиме протоколирования этапа загрузки.
Запуск трассировки
Непосредственно перед запуском процедуры трассировки, желательно соблюсти следующие простые требования:
- Все нижеописанные действия рекомендуется производить не просто из командной строки, запущенной из-под учетной записи, входящей в группу "Пользователи журналов производительности" либо "Администраторы", а непосредственно из сеанса любой административной учетной записи во избежание проблем с доступом к провайдерам ядра в ходе многочисленных перезагрузок.
- Во всех случаях трассировки проблем этапов загрузки операционной системы Windows рекомендуется настроить автоматический вход пользователя в систему, дабы время, затраченное на ввод пароля пользователем, не повлияло существенно на измерения. Хотя я этого не делал.
Для запуска утилит переходить в каталог установки инструментария вовсе не обязательно, поскольку на этапе инсталляции инструментарий добавляет свой рабочий каталог в системную переменную пути, тем самым делая доступным свои файл из любого местоположения.
Для трассировки этапа загрузки выполняем команду:
xbootmgr -trace boot -traceflags BASE+CSWITCH+DRIVERS+POWER -numruns 1 –stackwalk Profile+CSwitch -resultpath C:\TEMP
Для трассировки этапа завершения выполняем команду:
xbootmgr -trace shutdown -traceflags BASE+CSWITCH+DRIVERS+POWER -numruns 1 –stackwalk Profile+CSwitch -resultpath C:\TEMP -noprepreboot
После выполнения данной команды, контроллер xbootmgr передает ETW-коду в ядре информацию о классах событий, к отслеживанию которых необходимо приступить.
Небольшая ремарка: для хранения результатов я использую директорию для временных файлов системы, описанную в переменной %TEMP%, у меня обычно это традиционно C:\TEMP. Соглашусь, что порой достаточно проблематично найти требуемый файл результатов в нагромождении временных файлов, однако это мой личный выбор, Ваше же право использовать произвольную целевую директорию.
Думаю, опции командной строки утилиты xbootmgr требуют дополнительного пояснения:
| Опция | Описание |
|---|---|
| -trace | Режим трассировки.
|
| -traceFlags | Флаги трассировки. Так называемые "флаги" представляют собой провайдеры событий, с помощью которых можно получить доступ к тем или иным событиям. Более подробную информацию о провайдерах можно получить командой xperf -help providers. По-умолчанию используются опции BASE+CSWITCH. Описаны ниже. |
| -numRuns | Количество повторений заданной стадии. |
| -resultPath | Целевой каталог для формирования файла отчета. Опция задает режим мониторинга контроллера - запись результатов в файл. По-умолчанию логи сохраняются в директории %WINDIR%\System32. |
| -stackWalk | Фильтр прохода по стеку. Используются для углубленного анализа событий с помощью логирования участков кода момента событий и их последующего анализа. В данной статье мы не будем рассматривать этот функционал. Вероятно, по-умолчанию используется комбинация ProcessCreate+CSwitch, однако данный факт не подтвержден. |
| -noPrepReboot | Отключить предварительную подготовительную перезагрузку. Применяю эту опцию в случае трассировки этапа перезагрузки, поскольку она позволяет отлавливать некоторые баги. |
| -prepSystem | Проводит подготовку системы перед началом очередного этапа трассировки. Подготовка, в зависимости от ситуации, может быть разной, но основная польза данного ключа состоит в запуске процесса дефрагментации диска. |
Понятное дело, что у утилиты xbootmgr значительно больше опций командной строки, нежели представлено в моей таблице, самостоятельно Вы можете познакомиться с ними, выполнив команду xbootmgr -help.
По информации по опциям утилиты xbootmgr меня больше всего заинтересовала информация о флагах трассировки (провайдерах) и фильтре прохода по стеку. Как выяснилось позже, провайдеров представлено в системе достаточно большое количество, к тому же, провайдеры могут добавляться пользовательскими приложениям. Многие из этих провайдеров требуют дополнительного пояснения.
| Флаг | Описание |
|---|---|
| BASE | Базовая информация. Какая именно? |
| PROC_THREAD | Создание/удаление процесса или потока. |
| LOADER | Загрузчик образов исполняемых файлов. События загрузки/выгрузки образа (библиотек, драйверов, программ) пользовательского режима или режима ядра. |
| PROFILE | Профилирование процессора. Дискретное событие, происходящее каждую 1 миллисекунду. Во время работы xbootmgr профилировщик прерывает процессор с интервалом в 1 миллисекунду и записывает стек вызова выполняющихся потоков. Помогает исследовать расход процессорного времени и выявить медленный код. |
| CSWITCH | Переключение контекста. Процедура сохранения контекста одной задачи и восстановления контекста другой. Количество переключений контекста в заданный промежуток времени? |
| COMPACT_CSWITCH | Компактное переключение контекста. Чем отличается от обычного? |
| DISPATCHER | Планировщик. Диспетчер, процесс, выполняющий принятие решений по переключению управления между задачами. |
| DPC | События вызовов отложенных процедур. |
| INTERRUPT | Прерывания. События возникновения программных и аппаратных прерываний. |
| SYSCALL | Системные вызовы. Обращения кода пользовательского режима к функциям ядра для выполнения каких-либо задач. Фиксируется количество вызовов? |
| PRIORITY | События по смене приоритета процесса/потока? |
| ALPC | Усовершенствованных вызов локальной процедуры, Advanced Local Procedure Call. Средство межпроцессового взаимодействия для быстрого обмена сообщениями. Механизм доступен только для внутренних системных процессов и не доступен для пользовательского кода. |
| PERF_COUNTER | Счетчики производительности процессов. Что имеется в виду? |
| DISK_IO | Дисковый ввод-вывод. |
| DISK_IO_INIT | Дисковый ввод-вывод. Инициализация. |
| FILE_IO | Файловый ввод-вывод. Время и результат выполнения операций файловой системы. |
| FILE_IO_INIT | Начало файлового ввода-вывода. Создание/Открытие. |
| HARD_FAULTS | Ошибки обращения к странице (Hard Pagefaults, ошибки страниц), требующие ее считывания с диска, соответственно, требующие иногда существенного времени для завершения. Прерывание, генерируемое в случае попытки доступа программы к странице памяти, которая отображена на виртуальное адресное пространство процесса, но фактически не загружена в оперативную память. Отличаются от Pagefaults тем, что это не просто событие ошибки обращения к странице, но требует её фактической загрузки в память. |
| FILENAME | Операции с файлами (создание / удаление / сводка). |
| SPLIT_IO | Раздробленный (разделенный) ввод-вывод. Частота разделений операций ввода-вывода физического диска на несколько составных более низкоуровневых операций. Указывает на то, что запросы ввода-вывода были расщеплены на множественные запросы ввода-вывода физического диска из-за более низкоуровневых аппаратных средств работы с диском. Позволяет диагностировать время отклика диска. Помогает определить концепцию дефрагментации диска. |
| REGISTRY | Активность системного реестра. Трассировка операций реестра. |
| DRIVERS | Событий драйверов. Задержки. |
| POWER | События электропитания. |
| NETWORKTRACE | События сетевого уровня (такие как прием и передача TCP/UDP пакетов). |
| VIRT_ALLOC | Операции с виртуальной памятью. Резервирование, передача, изменение, освобождение региона страниц в виртуальном адресном пространстве. |
| MEMINFO | Информация об использовании памяти. |
| ALL_FAULTS | Все ошибки страниц. Вероятно, отличаются от HARD_FAULTS тем, что включают еще и события Page_faults, то есть обычные ошибки обращения к странице, не требующие подгрузки с носителя. |
Особенное внимание еще уделяется так называемым флагам прохода по стеку (Stack Walking Flags). Вероятно, это атомарные события, при которых код трассировки лезет в стек вызовов текущего потока для записи данных при наступлении конкретного события. Перечислю в виде списка, поскольку пока что нет глубокого понимания ситуации:
ProcessCreate, ProcessDelete, ImageLoad, ImageUnload, ThreadCreate, ThreadDelete, CSwitch, ReadyThread, ThreadSetPriority, ThreadSetBasePriority, Mark, SyscallEnter, SyscallExit, Profile, ProfileSetInterval, DiskReadInit, DiskWriteInit, DiskFlushInit, FileCreate, FileCleanup, FileClose, FileRead, FileWrite, FileSetInformation, FileDelete, FileRename, FileDirEnum, FileFlush, FileQueryInformation, FileFSCTL, FileDirNotify, FileOpEnd, SplitIO, RegQueryKey, RegEnumerateKey, RegEnumerateValueKey, RegDeleteKey, RegCreateKey, RegOpenKey, RegSetValue, RegDeleteValue, RegQueryValue, RegQueryMultipleValue, RegSetInformation, RegFlush, RegKcbCreate, RegKcbDelete, RegVirtualize, RegCloseKey, HardFault, PagefaultTransition, PagefaultTransition, PagefaultDemandZero, PagefaultCopyOnWrite, PagefaultGuard, PagefaultHard, PagefaultAV, VirtualAlloc, VirtualFree, PagefileBackedImageMapping, HeapRangeCreate, HeapRangeReserve, HeapRangeRelease, HeapRangeDestroy, HeapCreate, HeapAlloc, HeapRealloc, HeapFree, HeapDestroy, AlpcSendMessage, AlpcReceiveMessage, AlpcWaitForReply, AlpcWaitForNewMessage, AlpcUnwait, ThreadPoolCallbackEnqueue, ThreadPoolCallbackDequeue, ThreadPoolCallbackStart, ThreadPoolCallbackStop, ThreadPoolCallbackCancel, ThreadPoolCreate, ThreadPoolClose, ThreadPoolSetMinThreads, ThreadPoolSetMaxThreads, PowerSetPowerAction, PowerSetPowerActionReturn, PowerSetDevicesState, PowerSetDevicesStateReturn, PowerDeviceNotify, PowerDeviceNotifyComplete, PowerSessionCallout, PowerSessionCalloutReturn, PowerPreSleep, PowerPostSleep, PowerPerfStateChange, PowerIdleStateChange, PowerThermalConstraint, ExecutiveResource, PoolAlloc, PoolAllocSession, PoolFree, PoolFreeSession.
Вернемся к процедуре трассировки. После запуска вышеописанной команды, xbootmgr создает сессии (буфера в памяти) и начинает собирать информацию, поступающую через программные интерфейсы ETW от провайдеров, указанных пользователем (в нашем случае это BASE, CSWITCH, DRIVERS, POWER). Параллельно, в зависимости от режима работы xbootmgr, выполняются те или иные ключевые этапы (загрузка, завершение, сон, гибернация). Запомните, что в зависимости от опций утилиты, Вы должны быть готовы к мгновенной перезагрузке операционной системы, поэтому не забудьте предварительно сохранить рабочие данные!
На каждом из ключевых этапов сессии, по мере заполнения буферов, данные сбрасываются на диск в отдельные файлы трассировки. Затем все эти файлы, на последнем этапе, объединяются контроллером в один единственный формата .etl. Поэтому особенно нетерпеливые могут наблюдать несколько .etl файлов в целевой директории отчета, это говорит о том, что процесс сборки еще не завершен! В ходе сборки разрозненных данных трассировки, на каждом из этапов будет создаваться отдельный etl-файл отчета и выводиться такое вот предупреждение:
После того, как оно исчезнет с экрана, можно быть уверенным, что целевой файл отчетов консолидирован и процесс (или один из этапов) трассировки завершен, а в целевом каталоге у нас появится файл shutdown_BASE+CSWITCH+DRIVERS+POWER_1.etl (имя которого зависит от указанных в командной строке провайдеров).
Анализ результатов трассировки
Непосредственно перед началом анализирования результатов трассировки необходимо обратить внимание вот на что:
premerge (например boot_BASE+CSWITCH+DRIVERS+POWER_1_km_premerge.etl), то это означает, что процесс трассировки не завершен и идет сборка отчета.В этом случае необходимо дождаться окончания процесса и склеивания файлов отчетов в один. Интервал сбора данных утилитой xbootmgr после загрузки системы на финальном этапе задается при помощью опции командной строки –PostBootDelay и по-умолчанию равен 120 секундам.
Просмотр отчета
И так, на текущий момент на руках у нас имеется файл результатов трассировки, и следующим шагом, конечно же, мы преступим к его изучению. Для проведения анализа у нас в распоряжении имеется несколько способов:
- Открыть файл результатов через просмотрщик
xperfview. Сделать это можно либо непосредственно запустив утилиту и выбрав пункты File -> Open, либо запустив xperfview с параметром командной строки, эквивалентным имени файла результатов трассировки. - Сконвертировать .etl файл в .xml файл командой: xperf -i shutdown_BASE+CSWITCH+DRIVERS+POWER_1.etl -o shutdown_analysis.xml -a shutdown Затем открыть получившийся файл shutdown_analysis.xml в веб-браузере. Обратите внимание на опцию -a, которая задает фильтр вывода, она должна соответствовать конкретному режиму, в котором создавалась трасса, либо можно эту опцию просто убрать совсем.
- Открыть файл .etl утилитой xperf. Для этого выполняем команду: xperf shutdown_BASE+CSWITCH+DRIVERS+POWER_1.etl –a shutdown
xperf в директории, где располагаются отчеты, либо указывать в командной строке полный путь к файлу .etlА я бы на Вашем месте, не мудрствуя лукаво, выбрал бы первый способ с использованием утилиты xperfview, как наиболее простой. Потому как далее мы будем рассматривать как раз этот способ изучения результатов трассировки.
Общий алгоритм
- При анализе проблем загрузки, определить на каком из этапов происходит основная задержка:
- Pre Session Init (PreSMSS);
- Session Init (SMSSInit);
- Winlogon Init
- Explorer Init
- Post Boot
- При анализе проблем завершения, определить, какой именно компонент завершается дольше обычного;
- На графике, на котором виден проблемный компонент, выделить интересующий интервал, на нем по правой кнопке мыши вызвать меню и выбрать пункт Summary Table;
- В открывшемся окне по столбцам времени выполнения (содержащем слова Time), определить, какой из модулей (или процедур/функций) тратит изрядное время на свой функционал;
Пример
Тут мы разберем показательный пример из личного опыта. На одной из корпоративных рабочих станций появились проблемы с выключением/перезагрузкой, этап завершения операционной системы Windows 7 тянулся неоправданно долго, порой доходя до десятков минут. Поэтому, сразу имейте в виду, что дальнейшие отчеты и анализ у нас будут показаны для этапа завершения операционной системы.
Непосредственно после запуска утилиты xperfview и открытия файла трассировки, на экране появляется графическое представление результатов отчета. Картинка щелкабельна, поэтому Вы можете более внимательно ознакомиться с результатами нашей с вами трассировки:
По-умолчанию, графическое представление разбито на несколько (11) секций. Некоторые из этих секций соответствуют описанным ранее провайдерам данных, другие же требуют дополнительного пояснения:
- CPU Sampling - Замеры используемого процессорного времени (в процентах).
- CPU Frequency - Отслеживание изменения частоты процессора.
- CPU Idle States - Состояния процессора.
- Disk I/O - Дисковый ввод-вывод. Количество операций ввода-вывода.
- Disk Utilization - Использование диска (в процентах).
- Driver Delays >=100ms - Драйвера с задержкой, превышающей порог в 100 миллисекунд.
- Process Lifetimes - Карта времени завершения процессов.
- Hard Faults - Количество "тяжелых" ошибок страниц, требующих считывания информации с диска.
- Services - Карта сервисов. Обращайте внимание на ключевое слово (у нас "stop") после имени сервиса. В нашем случае говорит о том, что мы трассировали этап завершения.
- Winlogon - Основные контрольные точки этапа Winlogon.
- Generic Events - Карта всех событий.
Из всех, представленных на сриншотах, результатов интерес вызывают, пожалуй всего два раздела, а именно Services и Driver Delays >=100ms. Тут мы можем воочию наблюдать существенные отклонения от типовых диапазонов быстродействия. Три драйвера csc.sys, mup.sys, fltmgr.sys по какой-то необъяснимой причине очень долго выгружались. Так же и сервисы gpsvc и wuauserv завершались довольно продолжительное время.
- %SystemRoot%\System32\Drivers\csc.sys - это драйвер удаленной файловой системы, мини-редиректор, поддерживающий функционал системного механизма автономных файлов и отвечающий за то, куда именно перенаправляются запросы ввода-вывода, к удаленной файловой системе или к локальному кешу (%SystemRoot%\CSC). Драйвер поддерживает локальный кеш и обновляет кешированные данные при запросах ввода-вывода.
- %SystemRoot%\System32\Drivers\mup.sys - Многосетевой UNC-поставщик, драйвер удаленной файловой системы, непосредственно показывающий (отображающий) системным драйверам файловых систем удаленную файловую систему. Является эдаким центральным хабом самого низкого уровня, обрабатывающим запросы ввода-вывода для доступа к удаленным файловым системам через UNC-пути (\\Server\User\Path) и маршрутизирующим ввод-вывод определенному редиректору.
- %SystemRoot%\System32\Drivers\fltmgr.sys - диспетчер фильтров файловых систем или высокоуровневый обработчик запросов к файловой системе, отвечает за функционирование всех драйверов фильтров в системе, которые могут представлять из себя модули различного назначения: антивирусные файловые сканеры, репликаторы файлов, шифровщики файлов, резервное копирование файлов и прч.
Судя по общей направленности всех этих проблемных компонентов, могу предположить, что проблема у нас кроется где-то в сетевом взаимодействии с каким-то сетевым ресурсом (возможно в рамках домена), а конкретнее можно начать с функционала Автономных файлов.
Очень пригодилось почитать русскоязычную подачу при траблшутинге xperf-ом. Спасибо!
не за что, заходите еще