IIS log (Time-Taken) – campos importantes que as vezes desconsideramos

 

Por: João C. Delinger de Souza

 

Em geral, quando queremos diagnosticar problemas de performance nas aplicações que rodam no servidor IIS, normalmente coletamos logs usando o Performance Monitor e as vezes traces de rede. No entanto, essa tarefa leva algum tempo pois temos que configurar as ferramentas acima, reproduzir o problema e depois coletar todos os logs.

 

Será que não poderiamos coletar algo já existente no servidor? Claro que sim! O próprio log do IIS revela muita coisa interessante relacionada a performance das suas aplicações.

 

Nos logs do IIS existem 3 campos que são muito úteis para nós:

 

Bytes Sent (sc-bytes) - número de bytes enviados pelo servidor;

Bytes Received (cs-bytes) - número de bytes recebidos pelo servidor;

Time Taken (time-taken) -  tempo em milisegundos que levou para o servidor completar a requisição do cliente;

 

A propriedade time-taken é um cálculo total do tempo de processamento que foi gasto no servidor para uma aplicação em particular. Um ‘timer’ interno é reiniciado durante o primeiro pacote enviado e é terminado no último ‘acknowledgement’ recebido do cliente indicando que o processamento foi completado no servidor.

 

Nota: uma vez que esse cálculo inclui o tempo de reconhecimento do último pacote vindo
do cliente, você deve considerar a latência na sua rede. Por isso, as vezes coletamos também
traces de rede para verificar se a lentidão não está somente na execução da página ASP mas sim
também na trafegação dos pacotes da sua rede.

 

Bom, infelizmente esses campos não estão habilitados por default. Abaixo listo as instruções para habilitá-los:

 

(formato W3C log somente):

 

1) Abra o IIS Manager (Start – Run – Inetmgr);

2) Botão direito em Web Sites (IIS 6 somente);

    Clientes usando IIS 5 devem clicar com botão direito no nome da máquina; Botão Edit com WWW Service selecionado;

3) Escolha Properties

4) Na aba General selecione Properties… em Active log format;

5) Na aba Advanced (Extended Properties em IIS5), procure por “Time-Taken” e marque essa opção;

    Faça o mesmo para os outros campos citados acima;

6) Clique Ok, Ok;

 

 

Ou se você preferir, pode habilitar o campo ‘time-taken’ pela linha de commando abaixo:

 

Tenha em mente que o comando abaixo configura um parametro global, ou seja, cada site herdará essa configuração.

adsutil.vbs set w3svc/LogExtFileTimeTaken 1

 

Se você preferir habilitar somente para um web site especifico, use o commando abaixo:

adsutil.vbs set w3svc/{site#}/root/LogExtFileTimeTaken 1

 

 

Como filtrar os logs do IIS:

Você pode usar uma ferramenta da Microsoft chamada Log Parser (excelente por sinal). Exemplo de uma query para achar as requisições que levaram mais tempo:

 

Logparser “select * from <filename> where time-taken > 10000 Order By cs-uri-stem”

 

Log parser download: http://www.microsoft.com/technet/scriptcenter/tools/logparser/default.mspx

 

 

Artigos interessantes:

 

299910            HOW TO: IIS 5.0 Logging Properties Reference:
http://support.microsoft.com/default.aspx?scid=kb;EN-US;299910

 

296085            How To Use SQL Server to Analyze Web Logs:
http://support.microsoft.com/default.aspx?scid=kb;EN-US;296085

 

Até a próxima……

 

 

João