Файл: Руссинович М., Маргозис А. Утилиты Sysinternals. Справочник администратора 2012.pdf
Добавлен: 29.10.2018
Просмотров: 33126
Скачиваний: 742

418 Часть
III
Поиск и устранение сбоев: загадочные случаи
Рис. 17-21. Длительные серии коротких произвольных операций чтения по сети
Однако стеки для этих операций показывали, что дело в самом Project.
На рис. 17-22 во фрейме 25 показан модуль WINPROJ.EXE, вызывающий
код из Ole32.dll, который вызывает Kernel32.dll (фрейм 15), а тот вызывает
API-функцию ReadFile из Kernelbase.dll (все это DLL Windows).
Рис. 17-22. Winproj.exe вызывает код Windows для чтения файла
Также инженер увидел серии некешируемых операций чтения больших
объемов данных (рис. 17-23). Небольшие операции, которые он увидел сна-
чала, кешировались, так что после первого обращения доступ по сети не по-
вторялся. Но некешированные данные каждый раз читались с сервера, что
делало их более вероятной причиной снижения производительности.
Рис. 17-23. Серии операций чтения больших объемов некешированных данных по сети
SIN_ch_17.indd 418
27.12.2011 14:41:28

Зависание и плохая производительность
Глава 17 419
Ухудшало ситуацию то, что один и тот же файл считывался по сети не-
сколько раз. На рис. 17-24 показаны отфильтрованные данные о первона-
чальных операциях чтения файлов, в которых смещение в столбце Detail
(Подробно) равно 0.
Рис. 17-24. Файлы повторно считываются по сети; смещение 0 указывает на то, что чтение
производится с начала файла
Стеки для этих операций чтения показали, что они выполняются драй-
вером стороннего производителя STRSP64.SYS. Первое указание на то, что
это сторонний драйвер, можно увидеть во фреймах 18-21 окна с данными
трассировки стека (рис. 17-25). Procmon настроен для получения символов
с серверов Microsoft, а драйвер SRTSP64.SYS не имеет информации о сим-
волах и вызывает FltReadFile (фрейм 17).
Рис. 17-25. Srtsp64.sys в стеке вызовов первоначальных операций чтения файлов
Далее, фреймы, стоящие выше в том же стеке (рис. 17-26), показали, что
серии операций чтения SRTSP64.SYS шли в контексте обратных вызовов
диспетчера фильтров (фрейм 31), выполнявшихся, когда файл открывался в
Project вызовом CreateFileW (фрейм 50). Такое поведение обычно для анти-
вирусов, выполняющих проверку при обращении к файлу.
Двойной щелчок одной из строк c SRTSP64.SYS в стеке открыл окно
свойств модуля (рис. 17-27), которое подтвердило, что это файл Symantec
AutoProtect, выполняющий проверку на вирусы каждый раз, когда файл
Project открывается с определенными параметрами.
SIN_ch_17.indd 419
27.12.2011 14:41:29

420 Часть
III
Поиск и устранение сбоев: загадочные случаи
Рис. 17-26. Открытие файла функцией CreateFileW (фрейм 50) инициирует операции
чтения файлов драйвером SRTSP64.Sys
Рис. 17-27. Окно свойств модуля SRTSP64.SYS
Обычно администраторы устанавливают антивирусы на файловых сер-
верах, чтобы клиентам не приходилось проверять файлы, к которым они
обращаются, так как проверки на стороне клиента попросту были бы из-
быточными. Поэтому второй рекомендацией инженера было установить в
клиентском антивирусе исключения для общей папки, в которой хранились
профили пользователей.
Менее чем за 15 минут инженер описал проведенный анализ и рекомен-
дуемые действия и отправил их клиенту. Журнал монитора сети был нужен
просто для подтверждения того, что было обнаружено в журнале Procmon.
Администратор выполнил полученные инструкции и через несколько дней
сообщил, что пользователь больше не жалуется. Так при помощи Procmon и
стеков потоков была решена еще одна проблема.
Сложный случай с зависанием Outlook
Этим рассказом со мной поделился мой друг Эндрю Ричардс, инженер служ-
бы поддержки Microsoft Exchange Server. Он весьма интересен, поскольку
описывает применение утилиты Sysinternals, разработанной специально для
служб поддержки Microsoft, и состоит из описания двух проблем.
SIN_ch_17.indd 420
27.12.2011 14:41:29

Зависание и плохая производительность
Глава 17 421
Началось все с того, что администратор одной корпорации обратился в
службу поддержки Microsoft с жалобами пользователей корпоративной сети на
зависания Outlook длительностью до 15 минут. Так как это указывало на про-
блемы с Exchange, дело было передано в службу поддержки Exchange Server.
Специалисты из этой службы создали регистраторы данных для Perfor-
mance Monitor с сотнями счетчиков, полезных при решении проблем с
Exchange и собирающих данные об активности LDAP, RPC и SMTP, числе
подключений Exchange, использовании памяти и процессора. Администратор
должен был записывать в журнал активность сервера с 12-часовыми цикла-
ми, первый из которых начинался в 9 вечера и заканчивался в 9 утра сле-
дующего дня. Когда инженеры службы поддержки просмотрели журнал,
они увидели две явных тенденции, несмотря на высокую плотность данных.
Во-первых, как и ожидалось, нагрузка на сервер Exchange возрастала утром,
когда пользователи приходили на работу и запускали Outlook. Во-вторых,
диаграммы счетчиков показывали аномальный период между 8:05 и 8:20,
который в точности соответствовал длительности задержек, на которые жа-
ловались пользователи.
Инженеры поддержки стали изучать трассировки, полученные в этот проме-
жуток времени, и увидели падение утилизации времени ЦП сервера Exchange,
снижение значения счетчика активных подключений и значительное повыше-
ние задержки отклика, но не смогли выявить причину (рис. 17-28).
Пики задержки RPC
после зависания ЦП
Зависание ЦП
Рис. 17-28. Падение использование ЦП и увеличение задержки RPC
SIN_ch_17.indd 421
27.12.2011 14:41:30

422 Часть
III
Поиск и устранение сбоев: загадочные случаи
Они передали дело на следующий уровень службы поддержки, и за него
взялся Эндрю. Эндрю изучил журналы и пришел к выводу, что требуется
дополнительная информация о том, что делает Exchange во время простоя.
В частности, ему нужен был дамп памяти Exchange, полученный в период,
когда сервер не отвечает на запросы, включающий содержимое адресного
пространства процесса, в том числе данные и код, а также состояние реги-
стров потоков процесса. Дамп процесса Exchange позволил бы проверить
потоки Exchange и узнать, что приводит к их простою.
Один из способов получить дамп — подключить к процессу отладчик, та-
кой как Windbg из пакета средств отладки для Windows (Debugging Tools for
Windows, включен в SDK Windows), и выполнить команду .dump. Однако
это довольно сложно: требуется скачать и установить эти утилиты, запу-
стить отладчик, подключить его к нужному процессу и только потом можно
сохранить дампы. Вместо этого Эндрю попросил администратора скачать
ProcDump. При помощи ProcDump легко получать дампы процессов, в
том числе с указанным интервалом. Администратор должен был запустить
ProcDump, когда производительность ЦП сервера упадет в следующий раз,
чтобы сгенерировать пять дампов Store.exe, основного процесса Exchange
Server, с интервалом три секунды:
procdump -n 5 -s 3 store.exe c:\dumps\store_mini.dmp
На следующий день проблема повторилась, и администратор отправил
Эндрю файла дампа, полученные ProcDump. Часто процесс временно за-
висает из-за того, что один из его потоков устанавливает блокировку для
защиты данных, которые необходимы другим потокам, и удерживает ее, вы-
полняя какую-либо длинную операцию. Поэтому Эндрю сначала проверил
блокировки. Наиболее часто при синхронизации процессов используется
блокировка «критическая секция». Команда !locks debugger позволяет про-
смотреть в дампе заблокированные критические секции, идентификатор по-
тока, установившего блокировку, и число ожидающих потоков. Эндрю ис-
пользовал аналогичную команду !critlist расширения отладчика Sieext.dll
3
.
Выходные данные показали, что несколько потоков ожидают освобождения
потоком 223 критической секции:
0:000> !sieext.critlist
CritSec at 608e244c. Owned by thread 223.
Waiting Threads: 43 218 219 220 221 222 224 226 227 228 230 231 232 233
Теперь нужно было посмотреть, что делает поток, устанавливающий бло-
кировку. Это могло указать на код, ответственный за длительные задержки.
Эндрю переключился в контекст потока-владельца, используя команду ~, и
выгрузил дамп стека потока командой k:
0:000> ~223s
3
С сайта microsoft.com можно скачать общедоступную версию — SieExtPub.dll
SIN_ch_17.indd 422
27.12.2011 14:41:30