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

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

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

clip_image001

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

clip_image002

Указанные в журнале пути показали, что профили пользователей хранились на файловом сервере и что запуск 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 случаев долгих выполнений коротких операций случайного чтения:

clip_image003

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

clip_image004

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

clip_image005

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

clip_image006

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

clip_image007

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

clip_image008

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

clip_image009

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

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