Compartilhar via

Solucionar problemas de desempenho do IIS ou erros de aplicativo usando o LogParser

Aplica-se a: Serviços de Informações da Internet

Este artigo descreve as etapas de solução de problemas para identificar problemas de desempenho usando o Microsoft LogParser para analisar os logs do IIS (Serviços de Informações da Internet).

Ferramentas e conhecimentos utilizados nesta Resolução de Problemas

  • Microsoft LogParser
  • Prompt de comando
  • Conhecimento básico de códigos de status HTTP do IIS
  • Conhecimento básico de consultas SQL

Visão geral

Este artigo ajuda você a analisar os arquivos de log do IIS em um esforço para determinar a causa quando um aplicativo hospedado no IIS está falhando ou enfrentando problemas de desempenho. Antes de começar, é importante observar que todos os campos que o IIS pode registrar não estão habilitados por padrão. Por exemplo, Bytes Enviados e Bytes Recebidos não são habilitados por padrão, mas são muito úteis ao solucionar um problema de desempenho. Portanto, o melhor momento para incluir esses campos adicionais é antes que você esteja enfrentando problemas de sistema. Portanto, certifique-se de ter ativado esses campos adicionais. Eles ajudarão você a encontrar soluções quando ocorrerem problemas. Para obter mais informações sobre como habilitar esses campos, consulte Modificando dados de log do IIS 7 no Windows 2008.

Cenário

Como administrador do sistema, você começa a ouvir relatórios de usuários do seu sistema hospedado no IIS de que as respostas são lentas. Alguns deles mencionam que os navegadores de internet simplesmente excedem o tempo limite ou param de responder completamente quando estão acessando seu site.

Você entra em ação e reinicia o processo de trabalho. Tudo parece estar funcionando novamente, normalmente.

No entanto, você não pode aceitar isso como uma solução e precisa saber por que isso aconteceu, mas não sabe por onde começar. Você não tem detalhes dos usuários, como códigos de erro, capturas de tela e pior, você não tem dados de desempenho para comparar o que acabou de acontecer com o desempenho normal. Em muitos casos, outros novos problemas o afastam de qualquer análise séria de causa raiz.

O Microsoft LogParser é uma boa ferramenta rápida e fácil de usar. Em muitas situações, a ferramenta ajuda você a obter rapidamente uma compreensão mais profunda do que aconteceu no servidor e pode ajudá-lo a identificar problemas. Você pode obter as informações coletadas com o LogParser e repassá-las para sua equipe de banco de dados, sua equipe de rede ou para seus desenvolvedores para obter mais análises.

Coleta de dados

Por padrão, os arquivos de log do IIS estão localizados nos seguintes diretórios:

  • IIS 7 e posterior: %SystemDrive%\inetpub\logs\LogFiles
  • IIS 6 e anteriores: %WinDir%\System32\LogFiles

Nesta solução de problemas, usarei o IIS 8. Abra o Gerenciador do IIS e selecione Sites, conforme mostrado na Figura 1. Isso mostra a ID de cada site hospedado em seu servidor. Você precisa dessa ID para determinar qual diretório W3SVC* deve ser analisado.

Captura de tela da janela I I S Manager mostrando Sites no painel principal.
Figura 1: Obtendo o ID do seu site

Abra o Windows Explorer e navegue até o diretório que contém os arquivos de log do IIS do site que apresentou o problema de desempenho. A Figura 2 mostra como seria isso.

Captura de tela do Windows Explorer mostrando os locais dos arquivos.
Figura 2: local do arquivo de log do IIS

Os arquivos de log do IIS podem ser muito grandes; por exemplo, na Figura 2, o arquivo de log u_ex12101858.log tem quase 100 MB de tamanho. Como esses arquivos de log podem ser enormes e contêm centenas de milhares de entradas de arquivo de log individuais, examinar manualmente cada um desses arquivos em busca de um erro não é uma boa abordagem e retorna poucos resultados pelo tempo investido.

É quando o LogParser se torna uma ferramenta indispensável em seu arsenal de solução de problemas.

Análise de dados

Sua primeira etapa é determinar quais arquivos de log podem conter erros. Por exemplo, se os clientes estavam reclamando do desempenho em 3 de junho de 2012, o arquivo de log pode ser u_ex120603.log, em que:

  • 12 é a abreviação do ano de 2012
  • 06 refere-se ao sexto mês (junho)
  • 03 é o terceiro dia do mês

Observação: o exemplo acima pressupõe que o log do IIS está configurado para girar arquivos de log diariamente, que é o padrão. Se você tiver alterado as configurações do IIS para girar arquivos de log em um intervalo de tempo diferente, como semanal ou por hora, os nomes dos arquivos de log serão diferentes. Para obter mais informações sobre a sintaxe dos nomes de arquivo de log do IIS, consulte Formatos de arquivo de log do IIS.

Observação

Por padrão, a data e a hora nos logs do IIS são armazenadas usando GMT; você precisará levar isso em conta ao determinar quais logs contêm erros. Dito isso, você pode ajustar as datas/horas usando a função LogParser TO_LOCALTIME(), conforme ilustrado no exemplo a seguir:

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

Depois de identificar os arquivos de log do IIS que contêm erros, você deve copiá-los para um local onde eles possam ser analisados. Essa etapa é opcional, mas não é recomendável que você analise seus logs no servidor IIS, pois as consultas do LogParser podem levar muito tempo para serem executadas e, se os arquivos de log forem grandes, o Analisador de Logs poderá competir por recursos do sistema.

Por exemplo, você pode copiar os logs do IIS para uma pasta no computador pessoal onde você já copiou os arquivos do LogParser, que é como eu normalmente analiso meus arquivos de log. A Figura 3 mostra um exemplo do local em que os armazenei para criar este artigo.

Captura de tela do Windows Explorer mostrando a localização do executável do analisador de log.
Figura 3: arquivos de logs do IIS hospedados localmente para análise usando o LogParser

Depois de baixar o LogParser, você estará pronto para iniciar a análise. A primeira consulta que executo é mostrada na Figura 4. Os resultados fornecem uma visão geral de como o IIS tem respondido às solicitações.

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

Figura 4: consulta LogParser (sc-status e sc-substatus)

Os pontos de interesse dentro dos resultados são:

  • A proporção entre códigos de status HTTP 200 e 304 (solicitações bem-sucedidas)
  • O número de códigos de status HTTP 500 (solicitações com falha)

A significância para cada um desses códigos de status é explicada abaixo.

A proporção entre os códigos de status HTTP 200 e 304 (analisando solicitações bem-sucedidas)

A proporção entre os códigos de status HTTP 200 e 304 é importante porque mostra quantas solicitações estão sendo recuperadas do cache dos clientes, em vez de diretamente do servidor. Os resultados na Figura 4 mostram que há 3.920.658 solicitações que resultaram em um código de status HTTP 200. Isso significa que o arquivo solicitado foi servido do servidor todas as vezes. Em contraste, houve 178.705 solicitações que resultaram em um código de status HTTP 304. Isso significa que o arquivo solicitado foi recuperado do cache local. Ou seja, 95,5% das solicitações estão sendo tratadas no servidor.

O cache pode ter um impacto muito positivo no desempenho do seu sistema; consulte os detalhes da compactação estática e dinâmica no artigo Configuração da compactação HTTP no IIS 7.

Códigos de status HTTP 500 (analisando solicitações com falha)

Códigos de status HTTP 500 podem indicar problemas sérios em seu sistema. O nível de impacto que a causa raiz de um erro HTTP 500 pode ter em seu sistema pode variar de nada até a falha de um processo de trabalho. Portanto, ao vê-los, você deve executar a consulta mostrada na Figura 5 para localizar quais solicitações resultaram em um código de status 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

Figura 5: Consulta LogParser (cs-uri-stem com um 500 sc-status)

Esses resultados mostram o caminho e o nome do arquivo que, quando solicitado, respondeu com um código de status HTTP 500. Esse tipo de informação seria valiosa para a equipe de desenvolvimento. Por exemplo, a equipe de desenvolvimento pode examinar mais profundamente esse código específico e procurar código que é executado sem estar contido em um bloco de código try {...} catch {...}, ou ela está executando grandes consultas de dados que precisam ser otimizadas.

Vamos dar um passo adiante neste exemplo e nos concentrar no principal contribuidor para códigos de status HTTP 500. Seria interessante saber quando esses erros ocorreram, pois essas informações podem ser usadas para verificar se as dependências estavam tendo algum problema ao mesmo tempo.

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

Figura 6: Consulta LogParser (cs-uri-stem com um status 500 sc)

O subconjunto de resultados na Figura 6 restringe o intervalo de datas do problema. Essas informações podem ser passadas para a rede, banco de dados, administradores do sistema operacional e as equipes de desenvolvimento para verificar se algo mais estava acontecendo ao mesmo tempo. Por exemplo: Houve algum problema adicional entre 08:00 e 09:59:59 GMT e entre 14:00:00 e 14:59:59 GMT?

O próximo conjunto de consultas LogParser utiliza os seguintes campos, que podem fornecer uma visão melhor dos problemas de desempenho:

Campo Descrição Habilitado por padrão
time-taken O tempo que a ação levou, em milissegundos. Sim
sc-bytes O número de bytes enviados pelo servidor Não
cs-bytes O número de bytes recebidos pelo servidor Não

Como mencionado anteriormente, reserve um tempo agora para solicitar que os campos sc-bytes e cs-bytes sejam habilitados ou, se possível, habilite-os você mesmo. Eles fornecem algumas informações valiosas sobre seu sistema e seu comportamento. Veja a Figura 7, por exemplo. Você observa que o tempo médio é muito bom em algumas centenas de milissegundos. No entanto, observe o tempo máximo, isso é tempo demais.

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

Figura 7: Consulta do LogParser (tempo gasto MAX e AVG)

Eu sei que você já está se perguntando a próxima pergunta que precisa ser respondida. Qual solicitação está demorando tanto? A Figura 8 mostra a resposta a essa pergunta. Como você notará, eu prossegui e incluí o campo sc-bytes na consulta LogParser. Lembre-se, sc-bytes representa o tamanho do arquivo enviado do servidor de volta para o cliente.

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

Figura 8: Consulta do LogParser (time-taken MAX e AVG)

Provavelmente todos concordaríamos que o tempo necessário para as solicitações excede um tempo de resposta normal. No entanto, o tamanho dos arquivos é algo que o administrador ou desenvolvedor precisaria analisar para determinar se os tamanhos estão dentro de um intervalo aceitável.

A conclusão é que o arquivo GetDetailsView.aspx tem lançado vários códigos de status HTTP 500 e, em algum momento, levou muito tempo para ser concluído, embora fosse um arquivo relativamente pequeno. Talvez você queira examinar a data e a hora em que os problemas ocorreram para este arquivo e examinar o código no arquivo com quaisquer problemas que ocorreram. (Por exemplo, os logs do IIS contêm uma lista de variáveis que foram passadas na cadeia de caracteres de consulta; você pode verificar esses valores em busca de dados incorretos.)

Os exemplos fornecidos nas figuras 4 a 8 ajudam a entender onde a causa raiz de um problema pode existir. É provável, no entanto, que essa análise tenha renderizado apenas uma visão melhor da situação, o que levará a mais perguntas e análises mais profundas. Se for esse o caso, convém criar uma representação desses dados de uma maneira mais apresentável. A seção a seguir aborda isso em detalhes.

Reporting

Capturas de tela de uma janela de comando contendo consultas LogParser e seus resultados podem ser bons durante a fase de análise de um problema de desempenho; no entanto, se você precisar explicar diretamente para gerentes ou diretores o que aconteceu, elas podem não ser suficientes.

Observação

Para que o gráfico funcione por meio do LogParser, você precisará instalar os Componentes Web do Office. Os artigos a seguir explicam como fazer isso:

A Figura 9 mostra a consulta LogParser para criar um gráfico de pizza 3D contendo o número de solicitações e seu código de status HTTP associado. Eu removi o status 200, pois esses são bem-sucedidos. O que eu busco aqui são solicitações que não estão OK.

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

Figura 9: Consulta do LogParser (Criar um gráfico de pizza 3D)

O resultado da consulta é ilustrado na Figura 10. Há muitos parâmetros adicionais que você pode passar para o LogParser que afetam a imagem. Por exemplo, legenda, groupSize, configuração etc. Para obter uma lista completa, insira: LogParser -h -o:CHART para uma lista de todos os parâmetros. Esse comando também fornecerá uma lista dos diferentes tipos de gráfico.

Diagrama de um gráfico de setores tridimensional mostrando as situações de status das solicitações.
Figura 10: gráfico de pizza 3D do LogParser

Outro gráfico útil é a proporção entre solicitações em cache e reais. Lembre-se da seção Análise de Dados, onde discuti que um código de Status HTTP 200 significa que os arquivos solicitados são recuperados do servidor, no entanto, um 304 é recuperado do cliente. A Figura 11 mostra a consulta LogParser para a criação deste gráfico. Observe que usei o parâmetro -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

Figura 11: Consulta do LogParser (Crie um gráfico de pizza 3D)

Embora a diferença entre o código de status HTTP 200 e 304 sejam claramente visíveis, pensei que poderia adicionar algum valor para incluir o número de acessos para cada um. A Figura 12 ilustra a saída da consulta LogParser anterior.

Diagrama de um gráfico de pizza tridimensional mostrando a alocação de cache.
Figura 12: gráfico de setor 3D do LogParser

Acho que você está começando a perceber como usar o LogParser para analisar os logs do IIS pode ajudar a transmitir o que está acontecendo de forma muito melhor do que uma tabela de dados. Mas antes de parar, quero mostrar mais um exemplo usando o tipo de gráfico Coluna. A consulta LogParser mostrada na Figura 13 produz um gráfico de colunas 3D mostrando a contagem de códigos de status HTTPS 500 por hora.

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

Figura 13: consulta do LogParser (Criar um gráfico de coluna 3D)

O gráfico resultante é ilustrado na Figura 14.

Diagrama de um gráfico de colunas tridimensional mostrando o número de 500 erros por hora por data.
Figura 14: gráfico de colunas 3D do LogParser

Como criar gráficos usando Excel e CSV

No início desta seção, mencionei que a instalação do Office Web Component (OWC) é um requisito se você quiser usar os recursos de gráficos do LogParser. Em sua organização, pode haver restrições que proíbam isso ou você simplesmente não deseja instalá-lo. Se for o caso, considere exportar o resultado da consulta LogParser para um arquivo CSV e importá-lo para o Excel.

A Figura 15 mostra a consulta LogParser que extrai os códigos de status HTTP para todas as solicitações que não são 200 para um arquivo 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

Figura 15: consulta LogParser (Criar um arquivo CSV para importação no Excel)

Observe na Figura 15 que usei o parâmetro -o para que o LogParser criasse a saída no formato CSV.

Para importar o arquivo CSV para o Excel para que um gráfico possa ser criado a partir dele, abra o Excel, navegue até a guia DADOS e selecione Do texto. A Figura 16 mostra como isso se parece.

Captura de tela mostrando as opções do menu da guia Dados do Excel.
Figura 16: importar o arquivo CSV criado pelo LogParser para o Excel

Selecione o arquivo status.csv criado pela consulta LogParser e navegue pelo assistente de importação. Importe o arquivo CSV delimitado por vírgulas e você acabará com o Status na coluna A e o número de ocorrências para cada status na coluna B. Isso pressupõe que você executou a consulta LogParser mostrada na Figura 15. Por fim, selecione todos os dados das colunas A e B, incluindo os cabeçalhos e escolha o tipo de gráfico de pizza para criar. A Figura 17 ilustra a aparência disso.

Captura de tela mostrando as opções da guia Inserir do Excel. Os dados nas colunas A e B são selecionados.
igura 17: criar um gráfico de pizza usando um arquivo CSV

O resultado final é um gráfico de pizza, Figura 18, que é semelhante ao mostrado anteriormente na Figura 10. Há muitas opções em relação à cor, tipo de gráfico, rótulos etc. Com uma seleção de um botão, você pode alterar o tipo de gráfico de Pizza para Barra ou para Linha. Há muitas opções para criar gráficos de aparência profissional no Excel.

Captura de tela de um gráfico de setores tridimensional mostrando o status da solicitação.
Figura 18: um gráfico de pizza usando um arquivo CSV semelhante à Figura 10

Há tantas opções e possibilidades para analisar e apresentar os resultados dessa análise usando o LogParser. Para algumas dicas e exemplos adicionais, confira os blogs sobre o LogParser escritos por Robert McMurray. Há também um arquivo de ajuda muito útil e muitos scripts pré-escritos fornecidos dentro do pacote de instalação do LogParser. A próxima seção discutirá este e outros tópicos com mais detalhes.

Ajuda

Quando você instala o LogParser 2.2 em seu computador, ele é instalado no diretório C:\Arquivos de Programas (x86)\Log Parser 2.2 por padrão. Navegue até esse local e examine os diretórios Samples\Queries e Samples\Scripts para obter um suprimento abundante de código pré-escrito que o ajudará a se mover rapidamente.

Você também terá um grande benefício lendo o conteúdo no arquivo LogParser.chm .

Redução do tamanho ou divisão de arquivos de log do IIS

Você pode encontrar uma situação em que o arquivo de log do IIS é muito grande para o LogParser consultar. Isso é mais provável em uma máquina de 32 bits, mas também pode acontecer em uma máquina de 64 bits. No entanto, se você tiver erros de "falta de memória" ao executar uma consulta LogParser, considere executar o comando mostrado na Figura 19. A consulta extrai alguns campos essenciais de um arquivo de log grande do IIS e os coloca em outro, o que resulta em um arquivo de log menor.

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

Figura 19: redução do tamanho de um arquivo de log do IIS (removendo campos)

Neste exemplo, percebi uma redução no tamanho do arquivo de cerca de 45%. Em muitos casos isso pode ser suficiente, em outros talvez não. Depende do tamanho do arquivo de log original. Se você achar que ainda precisa reduzir o tamanho do arquivo de log do IIS, considere adicionar uma restrição de data e hora à consulta LogParser, conforme mostrado na Figura 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

Figura 20: redução ainda maior do tamanho de um arquivo de log do IIS adicionando uma cláusula WHERE

Essa é uma técnica valiosa para reduzir o tamanho do arquivo, mas também é útil remover entradas indesejadas do Log do IIS. Por exemplo, ao começar a solucionar um problema, sc-bytes você percebe isso time-takee cs-bytes não estava sendo registrado. Você os habilitou no IIS e deseja que a consulta analise apenas essas entradas com os campos habilitados recentemente. Use a instrução where para extrair os dados do arquivo de log do IIS do momento em que esses campos foram habilitados. Isso é importante quando você usa o AVG, MIN e MAX agregações.

Conclusão

O LogParser é uma ferramenta pequena, mas poderosa, para analisar muitos tipos de log do sistema diferentes. Este artigo se concentrou nas consultas aplicáveis aos logs do IIS. Quando problemas de desempenho ou erros são experimentados em seu ambiente do IIS, às vezes é difícil saber por onde começar.

O LogParser pode ser usado como ponto de partida, porque um administrador de sistema que tenha algumas habilidades em SQL pode criar rapidamente algumas consultas LogParser muito sofisticadas. Essas consultas podem ser usadas para promover a análise da causa raiz do problema.