См также
Доктор, у меня все болит
Как объяснить? Как описать?
Даже всезнание отказывает…
Вернор Виндж, «Пламя над бездной»
Если вы не разу не встречались с ситуацией, когда приложение отлично работает на машине разработчика, но необъяснимо глючит у заказчика – вы очень везучий программист. Или вы не программист, а кто-то другой.
Обычно ситуации такие возникают нечасто, но каждая из них до боли запоминается, и вспоминаешь о ней с содроганием еще спустя месяцы. Ну еще бы – заказчики звонят, менеджеры матерятся, команда сидит сутками на работе и пытается спасти положение. Если проблему удается решить, чувствуешь себя чуть ли не Кутузовым, выигравшим очередное сражение. Если же нет…
Я сейчас расскажу о том, как можно облегчить себе жизнь в ситуации, когда ASP.NET приложение ведет себя невесть как на production машине, а вы не можете понять, почему так происходит.
Обычно симптомы простые – очень злые заказчики выходят на связь и говорят, что «сайт не работает». Когда начинаешь разбираться – выясняется, что приложение действительно время от времени недоступно и веб-сервер радостно кидает ошибки вида “502 Service Unavailable”. Для клиента это может выглядеть как надпись «Page cannot be found» в браузере.
После такого дела, естественно, захочется посмотреть, что же там происходит на сервере. В этом поможет приложение Process Explorer (в принципе, и стандартный Task Manager сгодится, но он похуже).
Process Explorer и другие чудо-утилиты – File Monitor, Registry Monitor, Process Monitor etc – написал великий мастер Марк Руссинович. Все это хозяйство можно скачать с сайта Microsoft вот по такому адресу:
http://www.microsoft.com/technet/sysinternals.
Когда запустите Process Explorer, посмотрите информацию по процессу w3wp.exe
W3WP – это такой процесс, в котором Internet Information Server 6 по умолчанию запускает приложения ASP и ASP.NET. Точнее – те приложения, которые вы сгруппируете в одном AppPool. Прочитать про w3wp можно тут: http://msdn2.microsoft.com/en-us/library/ms524990.aspx
Вот например, как может вести себя w3wp:
В какой-то момент процессор на сервере начал потреблять 100% CPU. На картинке мы видим длительную 50%-ю загрузку, потому что на сервере установлен 2хядерный процессор и только половина ресурсов процессора была потрачена. Справа на картинке видно, как какой-то другой запрос скушал остатки процессорной мощности секунд на 10.
Еще бывает очень полезно настроить логгинг Performance Counters – можно много узнать о личной жизни сервера. Вот здесь (http://msdn2.microsoft.com/en-us/library/fxk122b4(vs.71).aspx) рассказывается про каунтеры, полезные для анализа ASP.NET приложений.
Дальше нам нужно понять – что же так грузит процессор? Раз дело в w3wp, значит, это наше приложение (или не наше, но здесь для простоты давайте считать, что только ваше приложение сидит в данном AppPool-е)
Дело может осложниться тем, что проблема возникает только на рабочем сервере, где любая отладка невозможна, и нигде больше проблему повторить не удается. Значит, надо как-то анализировать «нутро» процесса, его помыслы и деяния. Причем, не мешая настоящим, живым пользователям пользоваться сайтом.
Знаю, знаю, что на production отлаживаться нельзя. И доступа туда разработчики иметь не должны. Но если вы работаете не в банке, а скорость реагирования на проблему важнее бюрократии и безопасности – доступ вам скорее всего дадут. Впрочем, снять дамп процесса можно научить и сисадминов, причем без проблем. Сисадмины обычно в курсе, что такое core dumped, и с радостью помогают в создании таких «кор» другим.
В принципе, Process Explorer показывает, какие у процесса есть потоки и чем они заняты (даже Stack Trace делает и отладочные символы понимает). Проблема только в том, что Process Explorer не показывает .Net-овский управляемый стек.
Вот, например, попробуйте догадаться, чем сейчас занимается .Net приложение:
Раз Process Explorer нам не помощник, значит, нужен инструмент, который сделает трассировку .net-стека по всем потокам процесса. И такой инструмент есть – называется он Debugging Tools for Windows и совершенно бесплатно доступен на сайте Microsoft.
WinDbg в составе Debugging Tools – это, наверное, вообще самый мощный отладчик для Windows. Он умеет отлаживать все – от драйверов до .Net приложений. И что немаловажно, он умеет анализировать дампы процессов, в том числе и дампы, которые создали на другой машине. И .Net он тоже понимает. Скачать Debugging Tools можно по этому адресу: http://www.microsoft.com/whdc/devtools/debugging/default.mspx
Пользуемся User Dump
Но мы не можем отлаживаться на production! Поэтому мы сделаем дамп процесса, скопируем его к себе и будем исследовать при помощи WinDbg из поставки Debugging Tools.
А дамп процесса мы сделаем при помощи утилиты UserDump, которую качаем опять же с сайте Microsoft:
http://www.microsoft.com/downloads/details.aspx?FamilyID=E089CA41-6A87-40C8-BF69-28AC08570B7E&displaylang=en&displaylang=en
Инсталлировать ничего не нужно, нужно только подкараулить наш процесс, когда он начнет вести себя плохо, и сделать дамп, указав userdump-у ID процесса:
На время работы утилиты процесс блокируется и никакие запросы к сайту не работают. К счастью, дамп создается быстро – меньше минуты. Может и за 10 секунд управиться.
Созданный .dmp файл архивируем и копируем затем на девелоперскую машину. Файл будет размером с рабочий набор процесса – то есть не меньше 30 мегабайт а скорее всего раз в 10 больше. Впрочем, сжимается дамп-файл неплохо.
Ставим Debugging Tools for Windows
Тут даже рассказывать-то особенно нечего – скачиваем Debugging Tools и устанавливаем к себе на компьютер.
Затем запускаем WinDbg и открываем наш дамп:
Не пугайтесь только внешнего вида WinDbg – он кажется каким-то выходцем из прошлого. Примерно так наверное выглядит робот-марсоход изнутри. Какие-то приборы, циферки, буковки … Короче, не программа, а мечта.
Анализируем дамп процесса
Когда дамп процесса загрузится, вы увидите примерно следующее:
Красным выделена команда, которую нужно будет набрать в консоли дебаггера. Дело в том, что функции отладки .net приложений в WinDbg выполнены в виде плагина, который и загружается командой “.load”.
Существует два вида библиотеки sos.dll (sos – это сокращение от почему-то ”Son of Strike”). Одна версия подходит для managed программ, работающих под .Net 1.0 и 1.1, а вторая – для .Net 2.0
Для .Net 1.x sos.dll лежит в каталоге %DEBUGGING_TOOLS_HOME%\clr10.
Версия для .Net 2.0 поставляется вместе с самим .Net Framework. По необъяснимым причинам, она беднее по функционалу, чем sos.dll для 1.x, но тоже ничего.
Загругить ее можно так:
“.load C:\<WINDOWS_HOME>\Microsoft.NET\ Framework\v2.0.50727\sos.dll”
После того, как мы загрузили sos.dll, в отладчик добавилось множество полезных команд. Все эти команды начинаются со знака ”!”.
Полный список команд можно посмотреть, набрав «!help» в консоли отладчика. Команд там страницы на две, и с помощью них можно узнать много всего о .net – приложении.
Вот список команд для sos.dll от .net 1.x. Впечатляет?
Смысл части команд понятен из названия, а чтобы узнать подробности , наберите в консоли «!help <ИМЯ КОМАНДЫ>». Советую посмотреть справку по всем командам – многое потом может пригодиться.
Вспоминаем про нашу проблему – 100% загруженность CPU.
Смотрим список managed потоков – команда «!Threads»
Помимо кучи разных цифр здесь видно, что в процессе, который мы задампили, выполнялось 12 потоков. Пользы от этого нам сейчас немного, но для цельного понимания картины пригодится.
Теперь нам не остается ничего, кроме как просмотреть трассировку всех стеков для всех потоков с помощью команды «!EEStack»
EEStack выводит уйму информации: ссылки на стековые фреймы, адреса возврата и самое главное – символические имена для каждого стекового фрейма.
По-хорошему, при отладке не помешают бы еще и PDB файлы Windows – отладочные символы от основных DLL. Их можно получить, подключившись в Microsoft Symbol Server. Как - смотрим на сайте Microsoft: http://msdn2.microsoft.com/en-us/library/b8ttk8zy.aspx
Но поскольку мы не собираемся отлаживаться на уровне ассемблера откомпилированный JIT-компилятором код, в дампах стека нас будут интересовать только символы, начинающиеся с “MethodDesc“. Это, собственно и есть названя .net-овских классов и методов.
На следующей картинке можно получить кучу полезной информации, например вот тут видно, какую страницу рендерил ASPNET в этом потоке в момент, когда вызвали userdump.exe
Явно это был SlideViewer.aspx, что бы это название не значило.
А дальше нужно всего лишь внимательно просмотреть стеки от всех потоков и понять, где же тот самый поток, который загрузил процессор. Ну а еще дальше – сущие пустяки: успокоить заказчика, починить баг, написать тесты, выкатить обновление программы. После всего, через что мы только что прошли, это уже мелочи…
Понятное дело, что WinDbg вместе с sos.dll умеют в сотни раз больше, чем я тут описал. Например, можно посмотреть, какие объекты лежат в куче, как они распределены по поколениям. Можно посмотреть на внутренние структуры ASP.NET, на синхротаблицы объектов и многое другое…
К чему я клоню – встроенный отладчик Visual Studio по сравнению с WinDbg – просто неумелое дитя. Хотя – тсс, никому не говорите – в Visual Studio при помощи окна Immediate тоже можно загружать и использовать sos.dll.. Но, хотя дамп процесса проанализировать в ней можно, интеграции с sos.dll у Visual Studio нет, да и среда не столь заточена под ручную работу.
На заметку: Чтобы открыть дамп процесса в Visual Studio, нужно сказать File->Open Project и указать тип проекта как "Dump File". После этого дамп-файл откроется в IDE и можно будеть зайти в режим отладки (Debug this Instance), в котором доступна часть функциональности WinDbg на уровне пользовательского интерфейса (Окна Stack Trace, Threads, Memory и др.)
Удачи в отладке!
Версия 1.1
Ю.Скалецкий, 21 сентября 2007
http://yuryskaletskiy.blogspot.com/
История:
23 sep - версия 1.1: Оказывается, в Visual Studio тоже есть возможность анализировать дампы.
