Дело о медленном открытии файлов Project

Если вы видели одну из моих презентаций из серии "Дело о …" (например ту, которую я представил на TechEd Europe в прошлом месяце, доступную для просмотра в сети), то вы знаете, что я считаю стеки потоков мощным диагностическим инструментом для поиска корневой причины проблем производительности, некорректного поведения программ, сбоев и зависаний (краткое описание того, что представляет собой стек, я привожу в упомянутой презентации с TechEd). Причина этого заключается в том, что часто некорректное поведение процессов вызвано загружаемым им кодом; в явных случаях, это связанные с ним DLL, а иногда - расширения процесса. Описываемый в этой статье случай является еще одним примером успешной диагностики проблемы с помощью стека. Он также показывает за малый промежуток времени, потраченный на диагностику, можно получить несколько подсказок, который помогут быстро найти решение проблемы.

Все началось с того, что клиент - администратор сети - связался с поддержкой Microsoft из-за того, что пользователи сообщили ему о том, что открытие файлов Microsoft Project, расположенных на сетевом носителе, занимало около минуты, и что один раз из десяти оно завершалось ошибкой:

Администратор подтвердил наличие проблемы, проверил настройки сети и задержки к файловому серверу, но не смог найти ничего, чтобы бы объяснило проблему. Инженер поддержки Microsoft, которому было поручено исследовать этот случай, попросил администратора зафиксировать с помощью Process Monitor и Network Monitor факт медленного открытия файла. Спустя некоторое время, после получения лог-файла, он открыл этот лог-файл и установил фильтр, чтобы отображались только операции, запущенные процессом Project, и пути, которые ссылались на целевое сетевое хранилище файлов - \\DBG.ADS.DB.COM\LON-USERS-U. Итоговый список, который он открыл через меню Tools в Process Monitor, показал существенные временные издержки на операции доступа к файлам на сетевом хранилище, отображенные в столбце File Time:

Указанные в логе пути показали, что профили пользователей хранились на файловом сервере и что запуск Project вызывал существенную нагрузку на доступ к подпапке AppData в этих профилях. Если многие пользователи хранили свои профили на одном и том же сервере через перенаправление папок и запускали одинаковые приложения, которые использовали данных, хранимые в AppData, это в некоторой степени объяснило бы часть задержек, испытываемых пользователями. Хорошо известно, что переадресация папки AppData может привести к проблемам производительности, в связи с чем инженер поддержки сформулировал свою первую рекомендацию: компании следовало настроить их перемещаемые профили пользователей не на переадресацию AppData, а на синхронизацию папки AppData только при входе и выходе пользователей из системы, согласно руководству, приведенному в следующей публикации из блога Microsoft:

Особые рекомендации для папки AppData\Roaming:
Если папка AppData перенаправляется, некоторые приложения могут испытать проблемы в производительности, поскольку они будут обращаться к этой папке по сети. Если такие случаи имеют место, ваш рекомендуется настроить следующий параметр групповой политики на синхронизацию папки AppData\Roaming только при входе и выходе из системы и использовать локальный кэш при входе пользователей в систему. Хотя это может повлиять на скорость входа/выхода из системы, пользователям будет удобнее работать, так как приложения перестанут зависать из-за сетевых задежек.

User configuration>Administrative Templates>System>User Profiles>Network directories to sync at Logon/Logoff

Если приложения продолжают испытывать проблемы, вы должны рассмотреть исключение AppData из Перенаправления папок - обратной стороной такого подхода может стать увеличение времени входа/выхода из системы.

Далее инженер продолжил изучение лога, чтобы увидеть, ответственен ли Project за весь трафик к таким файлам, как Global.MPT, или это связано с работой дополнений. Для этой задачи незаменимы логи стека. После установки фильтра на отображение только попыток доступа к Global.MPT - файла, который, согласно общему логу, занимал больше всего времени на операции ввода/вывода - он заметил, что он открывался и считывался множество раз. Во-первых, он заметил 5 или 6 случаев долгих выполнений коротких операций случайного чтения:

Однако стеки этих операций показали, что за это был ответственен Project:

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

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

Стеки эти считываний показали, что их инициатором был сторонний драйвер, который был виден благодаря тому факту, что диалоговое окно с логом стека, которое он настроил для получения символов с публичного сервера символов Microsoft, не отображало информацию о символах:

Выше по стеку находились записи, указывающие на то, что последовательности считываний выполнялись в рамках контекста процесса открытия файлов Project, что похоже на поведение on-access сканеров вирусов:

Двойной клик на одной из строк SRTSP64.SYS в диалоговом окне стека подтвердил, что это был сканер Symantec AutoProtect, который неоднократно выполнял сканирование на вирусы каждый раз, когда Project открывал файл с определенными параметрами:

Как правило, администраторы настраивают антивирус на файловых серверах, так что клиентам нет необходимости в сканировании файлов на сервере, на которые они ссылаются, так как клиентское сканирование является по сути дублирующим. Это стало причиной второй рекомендации инженера поддержки: администратору следовало установить исключающий фильтр на развертываниях антивируса у их клиентов для файлов, расположенных в общем хранилище профилей пользователей.

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


Источник: http://blogs.technet.com/markrussinovich
Перевод: Dazila