Поделиться через

Устранение неполадок с производительностью IIS или ошибок приложений с помощью LogParser

Применимо к: службы Интернет-информации

В этой статье описаны действия по устранению неполадок с производительностью с помощью Microsoft LogParser для анализа журналов службы IIS (IIS).

Средства и знания, используемые в этом средстве устранения неполадок

  • Microsoft LogParser
  • Командная строка
  • Основные сведения о HTTP-кодах состояния IIS
  • Базовые знания о запросах SQL

Обзор

В этой статье показано, как проанализировать файлы журналов IIS, чтобы определить причину неисправности приложения, размещённого на IIS, или проблемами производительности. Перед началом работы важно отметить, что журналирование всех полей в IIS по умолчанию не включено. Например, Байты, отправленные и полученные байты , по умолчанию не включены, но они очень полезны при устранении неполадок с производительностью. Поэтому лучшее время включения этих дополнительных полей — прежде чем возникать системные проблемы. Поэтому убедитесь, что вы включили эти дополнительные поля. Они помогут вам найти решения, когда возникают проблемы. Дополнительные сведения о включении этих полей см. в разделе "Изменение данных журнала IIS 7 в Windows 2008".

Сценарий

Как системный администратор вы начинаете получать сообщения от пользователей вашей системы, размещенной на сервере IIS, что ответы медленные. Некоторые из них говорят, что веб-браузеры просто выдают тайм-аут или перестают полностью отвечать при попытке доступа к вашему веб-сайту.

Вы прыгаете в действие и перезапускаете рабочий процесс. Все, как представляется, снова работает, как обычно.

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

Microsoft LogParser — это хороший инструмент, который можно быстро и легко использовать. Во многих ситуациях средство помогает быстро получить более глубокое представление о том, что произошло на сервере, и может помочь вам выявить проблемы. Вы можете взять сведения, собранные с помощью LogParser, и передать их команде базы данных, вашей сетевой команде или разработчикам для более подробного анализа.

Сбор данных

По умолчанию файлы журналов IIS находятся в следующих каталогах:

  • IIS 7 и более поздних версий: %SystemDrive%\inetpub\logs\LogFiles
  • IIS 6 и более ранних версий: %WinDir%\System32\LogFiles

В этом средстве устранения неполадок я буду использовать IIS 8. Откройте диспетчер IIS и выберите сайты, как показано на рис. 1. Здесь показан идентификатор каждого веб-сайта, размещенного на сервере. Этот идентификатор необходим, чтобы определить, какой каталог W3SVC* нужно проанализировать.

Снимок экрана: окно
Рис. 1. Получение идентификатора веб-сайта

Откройте проводник Windows и перейдите в каталог, содержащий файлы журналов IIS веб-сайта, который столкнулся с проблемой производительности. На рисунке 2 показано, как это может выглядеть.

Снимок экрана Проводника Windows с расположениями файлов.
Рис. 2. Расположение файла журнала IIS

Файлы журнала IIS могут быть довольно большими; Например, на рис. 2 файл журнала u_ex12101858.log размером почти 100 МБ. Так как эти файлы журнала могут быть огромными и содержать сотни тысяч отдельных записей, ручной просмотр каждого из них в поисках ошибки не является хорошим подходом и дает мало результатов относительно затраченного времени.

Это происходит, когда LogParser становится незаменимым инструментом в арсенале устранения неполадок.

Анализ данных

Сначала необходимо определить, какие файлы журналов могут содержать ошибки. Например, если клиенты жаловались на производительность 3 июня 2012 года, файл журнала может быть u_ex120603.log, где:

  • 12 — сокращенное обозначение 2012 года
  • 06 ссылается на шестой месяц (июнь)
  • 03 — третий день месяца

Примечание. В приведенном выше примере предполагается, что ведение журнала IIS настроено для смены файлов журналов ежедневно, что является значением по умолчанию. Если вы изменили параметры IIS для изменения интервала времени смены файлов журналов, например еженедельно или почасово, тогда имена файлов журналов будут другими. Дополнительные сведения о синтаксисе имен файлов журнала IIS см. в разделе "Форматы файлов журнала IIS".

Примечание.

По умолчанию дата и время в журналах IIS хранятся с помощью GMT; Это необходимо учитывать при определении ошибок журналов. При этом можно настроить даты и время с помощью функции LogParser TO_LOCALTIME() , как показано в следующем примере:

logparser.exe "SELECT TO_STRING(TO_LOCALTIME(TO_TIMESTAMP(date,time)),'yyyy-MM-dd hh:mm:ss') AS LocalTime, COUNT(*) AS Hits FROM *.log WHERE date='2012-10-18' GROUP BY LocalTime ORDER BY LocalTime" -i:w3c

После идентификации файлов журналов IIS, содержащих ошибки, необходимо скопировать их в расположение, где их можно проанализировать. Этот шаг необязателен, но не рекомендуется анализировать журналы на сервере IIS, так как запросы LogParser могут занять много времени, а если файлы журнала большие, средство синтаксического анализа журналов может конкурировать за системные ресурсы.

Например, вы можете скопировать свои журналы IIS в папку на вашем личном компьютере, где вы уже скопировали файлы LogParser, что является моим обычным способом анализа файлов журнала. На рисунке 3 показано, где я их хранил для создания этой статьи.

Снимок экрана проводника Windows, показывающий расположение исполняемого файла лог парсера.
Рис. 3. Файлы журналов IIS, размещенные локально для анализа с помощью LogParser

Скачав LogParser, вы готовы начать анализ. Первый выполняемый запрос показан на рис. 4. Результаты дают вам обзор того, как IIS отвечает на запросы.

logparser.exe "SELECT sc-status, sc-substatus, COUNT(*) FROM *.log GROUP BY sc-status, sc-substatus ORDER BY sc-status" -i:w3c

sc-status sc-substatus COUNT(ALL *)
--------- ------------ ------------
200       0            3920658
206       0            2096
301       0            1031
302       0            65386
304       0            178705
400       0            35
401       2            692096
404       0            2935
404       11           7
405       0            1
406       0            36
500       0            11418

Statistics:
-----------
Elements processed: 4189228
Elements output:    12
Execution time:     7.70 seconds

Рис. 4. Запрос LogParser (sc-status и sc-substatus)

Точки интереса в результатах:

  • Соотношение между 200 и 304 кодами состояния HTTP (успешные запросы)
  • Число 500 кодов состояния HTTP (неудачные запросы)

Значение для каждого из этих кодов состояния описано ниже.

Соотношение между кодами состояния HTTP 200 и 304 (анализ успешных запросов)

Соотношение между кодами состояния HTTP 200 и 304 важно, так как оно показывает, сколько запросов извлекается из кэша клиентов, а не непосредственно с сервера. Результаты на рис. 4 показывают, что 3 920 658 запросов, которые привели к коду состояния HTTP 200. Это означает, что запрошенный файл каждый раз выдавался с сервера. В отличие от этого, было 178 705 запросов, что привело к коду состояния HTTP 304. Это означает, что запрошенный файл был получен из локального кэша. Другими словами, 95,5% запросов обрабатываются с сервера.

Кэширование может оказать очень положительное влияние на производительность вашей системы; Дополнительные сведения о статической и динамической сжатия см. в статье о настройке сжатия HTTP в IIS 7 .

Коды состояния HTTP 500 (анализ неудачных запросов)

Коды состояния HTTP 500 могут указывать на серьезные проблемы в системе. Уровень влияния, который может оказать основная причина ошибки HTTP 500 в вашей системе, может быть от ничего до сбоя рабочего процесса. Поэтому при отображении этих запросов необходимо выполнить запрос, показанный на рис. 5 , чтобы найти, какие запросы привели к коду состояния HTTP 500.

logparser.exe "SELECT cs-uri-stem, COUNT(*) FROM *.log WHERE sc-status=500 GROUP BY cs-uri-stem ORDER BY COUNT(*) DESC" -i:w3c

cs-uri-stem                 COUNT(ALL *)
--------------------------- ------------
/ShoppingCart/ViewCart.aspx 1378
/DataService.asmx           1377  
/Start/default.aspx         949
/GetDetailsView.aspx        753
/Details/ImageUrls.asmx     722

Statistics:
-----------
Elements processed: 4189228
Elements output:    5
Execution time:     24.89 seconds

Рис. 5. Запрос LogParser (cs-uri-stem с состоянием sc-status 500)

Эти результаты показывают путь и имя файла, который при запросе ответил с кодом состояния HTTP 500. Эта информация будет ценна команде разработчиков. Например, команда разработчиков может изучить этот конкретный код и искать код, который выполняется без хранения в try {...} catch {...} блоке кода, или они выполняют большие запросы данных, которые необходимо оптимизировать.

Давайте перейдем от этого примера дальше и сосредоточимся на основном источнике для кодов состояния HTTP 500. Интересно было бы узнать, когда произошли эти ошибки, поскольку эту информацию можно использовать для проверки, были ли какие-либо проблемы с зависимостями в то же время.

logparser.exe "SELECT TO_STRING(TO_TIMESTAMP(date,time),'yyyy-MM-dd hh') AS Hour, COUNT(*) FROM *.log WHERE sc-status=500 AND cs-uri-stem='/Start/default.aspx' AND date='2012-10-18' GROUP BY Hour ORDER BY Hour" -i:w3c

Hour          COUNT(ALL *)
------------- ------------
2012-10-18 08 191
2012-10-18 09 163
2012-10-18 14 150

Statistics:
-----------
Elements processed: 4189228
Elements output:    3
Execution time:     6.36 seconds

Рис. 6. Запрос LogParser (cs-uri-stem с sc-status 500)

Подмножество результатов на рис. 6 ограничивает диапазон дат проблемы. Эти сведения можно передать в сеть, базу данных, администраторов операционной системы и команды разработчиков, чтобы проверить, происходит ли что-либо другое в то же время. Например: были ли дополнительные проблемы между 08:00 и 09:59:59 GMT и между 14:00:00 и 14:59:59 GMT?

Следующий набор запросов LogParser использует следующие поля, которые могут дать более подробные сведения о проблемах с производительностью:

Поле Description Включено по умолчанию
time-taken Продолжительность действия в миллисекундах Да
sc-bytes Количество байтов, отправляемых сервером Нет
cs-bytes Количество байтов, полученных сервером Нет

Перед тем, как приступить к дальнейшим действиям, попросите включить поля sc-bytes и cs-bytes или, если это возможно, включите их самостоятельно. Они предоставляют некоторые ценные сведения о вашей системе и его поведении. Возьмем, например, рисунок 7. Вы видите, что среднее время отклика составляет несколько сотен миллисекунд и это довольно неплохой показатель. Тем не менее, посмотрите на максимальное время, то есть слишком много времени.

logparser.exe "SELECT  cs-method, COUNT(*) AS TotalCount, MAX(time-taken) AS MaximumTime, AVG(time-taken) AS AverageTime FROM *.log GROUP BY cs-method ORDER BY TotalCount DESC" -i:w3c

cs-method TotalCount MaximumTime AverageTime
--------- ---------- ----------- -----------
GET       3172034    1366976     153
POST      1011765    256539      359  
HEAD      5363       26750       209  

Statistics:
-----------
Elements processed: 4189228
Elements output:    3
Execution time:     6.36 seconds

Рис. 7. Запрос LogParser (время ожидания MAX и AVG)

Я знаю, что вы уже задаете себе следующий вопрос, на который нужно ответить. Какой запрос занимает столько времени? На рисунке 8 показан ответ на этот вопрос. Как вы заметите, я пошел вперед и включил поле sc-bytes в запрос LogParser. Помните, что sc-bytes представляет размер файла, отправленного с сервера обратно клиенту.

logparser.exe "SELECT cs-uri-stem, time-taken, sc-bytes FROM *.log WHERE time-taken > 250000 ORDER BY time-taken DESC" -i:w3c

cs-uri-stem                 time-taken sc-bytes
--------------------------- ---------- --------
/ShoppingCart/ViewCart.aspx 1366976    256328
/DataService.asmx           1265383    53860
/Start/default.aspx         262796     8077
/GetDetailsView.aspx        261305     5038
/Details/ImageUrls.asmx     256539     2351

Statistics:
-----------
Elements processed: 4189228
Elements output:    5
Execution time:     8.98 seconds

Рис. 8. Запрос LogParser (время ожидания MAX и AVG)

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

Вывод заключается в том, что файл GetDetailsView.aspx вызывает ряд кодов состояния HTTP 500 и в какой-то момент занимает много времени, даже если это был относительно небольшой файл. Вы можете просмотреть дату и время возникновения проблем, возникающих для этого файла, и проверить код в файле с любыми возникшими проблемами. (Например, журналы IIS содержат список переменных, переданных в строке запроса; эти значения можно проверить на наличие плохих данных.)

Примеры, представленные на рисунках 4 – 8, помогают понять, где может существовать основная причина проблемы. Однако, скорее всего, этот анализ лишь показал лучшее представление о ситуации, что приведет к более глубоким вопросам и более глубокому анализу. Если это так, может потребоваться создать представление этих данных более презентацией. В следующем разделе подробно описано.

Отчетность

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

Примечание.

Чтобы заставить построение диаграмм работать через LogParser, необходимо установить Office Web Components. В следующих статьях объясняется, как это сделать:

На рисунке 9 показан запрос LogParser для создания трехмерной круговой диаграммы, содержащей количество запросов и связанный код состояния HTTP. Я удалил статус 200, так как они успешные. Меня интересуют запросы, которые отличаются от ОК.

logparser.exe "SELECT sc-status AS Status, COUNT(*) AS Count INTO status.gif FROM *.log WHERE sc-status > 200 GROUP BY Status ORDER BY Status" -i:w3c -o:CHART -chartType:PieExploded3D -ChartTitle:"Request Status"

Statistics:
-----------
Elements processed: 4189228
Elements output:    10
Execution time:     6.20 seconds

Рис. 9. Запрос LogParser (создание трехмерной круговой диаграммы)

Результат запроса показан на рис. 10. Существует множество дополнительных параметров, которые можно передать в LogParser, влияющие на изображение. Например, условные обозначения, groupSize, config и т. д. Чтобы получить полный список, LogParser -h -o:CHART введите список всех параметров. Эта команда также предоставит список различных типов диаграмм.

Диаграмма трехмерной круговой диаграммы, показывающая распределение статусов запросов.
Рис. 10. Круговая диаграмма LogParser 3D

Другая полезная диаграмма — это соотношение между кэшируемыми и фактическими запросами. Помните из раздела "Анализ данных", в котором я обсудил, что код состояния HTTP 200 означает, что запрошенные файлы извлекаются с сервера, однако 304 извлекается из клиента. На рисунке 11 показан запрос LogParser для создания этой диаграммы. Обратите внимание, что я использовал параметр -values.

logparser.exe "SELECT sc-status AS Status, COUNT(*) AS Count INTO cache.gif FROM *.log WHERE sc-status=200 OR sc-status=304 GROUP BY Status ORDER BY Status" -i:w3c -o:CHART -chartType:PieExploded3D -ChartTitle:"Cache" -values:ON

Statistics:
-----------
Elements processed: 4189228
Elements output:    2
Execution time:     6.35 seconds

Рис. 11. Запрос LogParser (создание трехмерной круговой диаграммы)

Хотя разница между кодами состояния HTTP 200 и 304 явно видна, я подумал, что будет полезно включить количество запросов для каждого. Рисунок 12 иллюстрирует выходные данные предыдущего запроса LogParser.

Схема трехмерной круговой диаграммы с выделением кэша.
Рис. 12. Круговая диаграмма LogParser 3D

Я думаю, что вы получаете рисунок теперь о том, как диаграмма журналов IIS с помощью LogParser может помочь передать то, что происходит гораздо лучше, чем таблица данных. Но прежде чем остановиться, я хочу показать вам еще один пример с помощью типа диаграммы столбцов. Запрос LogParser, показанный на рис. 13 , создает трехмерную диаграмму столбцов с числом 500 кодов состояния HTTPS в час.

logparser.exe "SELECT to_string(to_timestamp(date, time), 'yyyy-MM-dd hh') AS Hour, COUNT(*) AS Count INTO 500.gif FROM *.log WHERE sc-status=500 GROUP BY Hour ORDER BY Hour" -i:w3c -o:CHART -chartType:Column3D -ChartTitle:"500 Errors by Hour"

Statistics:
-----------
Elements processed: 4189228
Elements output:    13
Execution time:     6.32 seconds

Рис. 13. Запрос LogParser (создание трехмерной диаграммы столбцов)

Результирующая диаграмма показана на рисунке 14.

Схема трехмерной столбчатой диаграммы, показывающая число ошибок 500 в час по дате.
Рис. 14. Диаграмма столбцов LogParser 3D

Создание диаграмм с помощью Excel и CSV

В начале этого раздела я упомянул, что установка веб-компонента Office (OWC) является обязательным требованием, если вы хотите использовать возможности диаграмм LogParser. В вашей организации могут быть ограничения, которые запрещают это или вы просто не хотите его установить. Если это так, попробуйте экспортировать результат запроса LogParser в CSV-файл и импортировать его в Excel.

На рисунке 15 показан запрос LogParser, который извлекает коды состояния HTTP для всех запросов, которые не являются 200 в CSV-файл.

logparser.exe "SELECT sc-status AS Status, COUNT(*) AS Count INTO status.csv FROM *.log WHERE sc-status > 200 GROUP BY Status ORDER BY Status" -i:w3c -o:csv

Statistics:
-----------
Elements processed: 4189228
Elements output:    10
Execution time:     6.20 seconds

Рис. 15. Запрос LogParser (создание CSV-файла для импорта в Excel)

Обратите внимание на рис. 15 , что я использовал параметр -o, чтобы LogParser создал выходные данные в формате CSV.

Чтобы импортировать CSV-файл в Excel, чтобы диаграмма была создана из нее, откройте Excel, перейдите на вкладку DATA и выберите "Из текста". На рисунке 16 показано, как это выглядит.

Снимок экрана: параметры меню вкладки
Рис. 16. Импорт CSV-файла, созданного LogParser в Excel

Выберите файл status.csv, созданный запросом LogParser, и перейдите по мастеру импорта. Импортируйте CSV-файл, разделённый запятыми, и отобразится состояние в столбце A и количество появлений для каждого состояния в столбце B. Предполагается, что вы выполнили запрос LogParser, показанный на рис. 15. Наконец, выберите все данные из столбца A и B, включая заголовки и выберите тип круговой диаграммы для создания. Рис. 17, иллюстрирует, как это может выглядеть.

Снимок экрана: параметры вкладки
Рис. 17. Создание круговой диаграммы с помощью CSV-файла

Конечным результатом является круговая диаграмма, рис. 18 , аналогичная показанной ранее на рис. 10. Существует множество вариантов в отношении цвета, типа диаграммы, меток и т. д. При выборе кнопки можно изменить тип диаграммы с "Круг" на "Панель" или "Линия". Существует множество вариантов создания профессиональных диаграмм в Excel.

Снимок экрана: трехмерная круговая диаграмма с состоянием запроса.
Рис. 18. Круговая диаграмма, созданная с использованием CSV-файла, аналогичного рис. 10

Существует так много вариантов и возможностей для анализа и представления результатов этого анализа с помощью LogParser. Дополнительные советы и примеры см. в блогах о LogParser , написанном Робертом Макмюррей. Существует также очень полезный файл справки и многие предварительно написанные скрипты, предоставляемые в пакете установки LogParser. В следующем разделе подробно рассматриваются эти и другие темы.

Помощь

При установке LogParser 2.2 на компьютере он устанавливается в каталог C:\Program Files (x86)\Log Parser 2.2 по умолчанию. Перейдите в это место и просмотрите каталоги Samples\Queries и Samples\Scripts, чтобы найти большое количество готового кода, который позволит вам быстро начать работу.

Вы также получите большое преимущество, прочитав содержимое файла LogParser.chm.

Уменьшение размера или разделения файлов журнала IIS

Может возникнуть ситуация, когда файл журнала IIS слишком велик для запроса LogParser. Это, скорее всего, на 32-разрядном компьютере, но может произойти на 64-разрядном компьютере тоже. Тем не менее, если при выполнении запроса LogParser возникают ошибки "вне памяти", рекомендуется выполнить команду, показанную на рис. 19. Запрос извлекает некоторые важные поля из большого файла журнала IIS и помещает их в другой, что приводит к меньшему файлу журнала.

logparser.exe "SELECT date, time, c-ip, cs-uri-stem, cs-uri-query, sc-status, sc-substatus, sc-win32-status, sc-bytes, cs-bytes, time-taken INTO u_exJUSTRIGHT.log FROM u_exTOOBIG.log" -i:w3c -o:w3c

Statistics:
-----------
Elements processed: 19712301
Elements output:    19712301
Execution time:     3.07 seconds

Рис. 19. Уменьшение размера файла журнала IIS (путем удаления полей)

В этом примере я понял, что размер файла уменьшается примерно на 45 %. Во многих случаях это может быть достаточно, в других, возможно, нет. Он зависит от размера исходного файла журнала. Если вы обнаружите, что вам по-прежнему нужно уменьшить размер файла журнала IIS, попробуйте добавить ограничение даты и времени в запрос LogParser, как показано на рис. 20.

logparser.exe "SELECT date, time, c-ip, cs-uri-stem, cs-uri-query, sc-status, sc-substatus, sc-win32-status, sc-bytes, cs-bytes, time-taken INTO u_exJUSTRIGHT.log FROM u_exTOOBIG.log WHERE to_timestamp(date, time) >= timestamp('2012-11-09 00:00:00', 'yyyy-MM-dd hh:mm:ss')" -i:w3c -o:w3c

Statistics:
-----------
Elements processed: 240123
Elements output:    240123
Execution time:     0.45 seconds

Рис. 20. Дальнейшее уменьшение размера файла журнала IIS путем добавления предложения WHERE

Это ценный способ уменьшения размера файла, но это также полезно для удаления нежелательных записей из журнала IIS. Например, начиная устранять проблему, вы осознаёте, что time-take, sc-bytes и cs-bytes не регистрировались. Вы включили их в IIS и хотите, чтобы запрос анализировал только те записи, у которых были недавно включенные поля. Используйте инструкцию where для извлечения данных из файла журнала IIS с момента включения этих полей. Это важно при использовании агрегатов AVG, MIN и MAX.

Заключение

LogParser — это небольшое, но мощное средство для анализа различных типов системных журналов. В этой статье рассматриваются запросы, применимые к журналам IIS. При возникновении проблем с производительностью или ошибок в среде IIS иногда сложно знать, где начать работу.

LogParser можно использовать в качестве отправной точки, так как системный администратор, имеющий некоторые навыки SQL, может быстро создавать очень сложные запросы LogParser. Эти запросы можно использовать для дальнейшего анализа первопричин проблемы.