Introduzione a LogParser

Tra gli strumenti che mi capita di usare più spesso nel mio lavoro c’è sicuramente LogParser, un tool alla riga di comando (per il quale però esistono alcune GUI che facilitano l’uso tramite un’interfaccia grafica) che tramite un linguaggio molto simile al T-SQL permette di analizzare log in formato testuale ma non solo; io lo trovo particolarmente utile per analizzare log di IIS ed i log dell’Event Viewer, ma l’utilizzo è in realtà più ampio e molto flessibile.

LogParser supporta un numero piuttosto ampio di formati di file sia in input che in output, ecco l’elenco completo per la versione 2.2:

Input Formats
ADS Restituisce proprietà relative ad oggetti contenuti in Active Directory
BIN IIS logs in formato Centralized Binary Log File
COM Fornisce un’interfaccia per Custom Input Format COM Plugins
CSV Log in formato testo separato da virgole
ETW Formato per Enterprise Tracing for Windows (file .etl) e trace di sessioni live ETW
EVT Usato per leggere gli eventi dal Windows Event Log (sia dalla macchina locale che da una remota) e file .evt
FS Informazioni riguardo gli oggetti del File System (file e cartelle)
HTTPERR Log creati dal driver Http.sys (HTTP Error logs)
IIS Log di IIS nel formato nativo Microsoft (IIS Log File Format)
IISODBC Restituisce le informazioni dalle tabelle utilizzare quando IIS è configurato per salvare i log nel formato ODBC Log
IISW3C Usato per i log di IIS nel formato W3C Extended Log File Format (questa è la modalità di logging di default di IIS)
NCSA Usato per file in formato NCSA (nelle tre modalità Common, Combined ed Extended). Il formato NCSA è basato su campi a lunghezza fissa separati da spazi
NETMON Permette l’analisi di trace di rete (file .cap) prodotte con Network Monitor
REG Usato per fare query sul registro di sistema
TEXTLINE Restituisce righe di testo da file di testo generici
TEXTWORD Restituisce parole (words) da file di testo generici
TSV Gestisce file con valori separati da tab o da spazi
URLSCAN Usato per fare query su file generati da URLScan
W3C Gestisce file in formato W3C Extended Log File Format
XML Usato per gestire file in formato XML
Output Formats
CHART Usato per creare grafici; è necessario installare gli Office Web Components
CSV Log in formato testo separato da virgole
DATAGRID Mostra i record in una finestra grafica con una griglia tipo GridView
IIS Log di IIS nel formato nativo Microsoft (IIS Log File Format)
NAT Scrive i record in un formato separato da tab rispettando l’allineamento delle colonne per una comoda leggibilità
SQL Scrive l’output in una tabella di Sql Server
SYSLOG Può essere usato per mandare messaggi ad un Syslog server, per creare file di testo contenenti messaggi di tipo Syslog e per mandare messaggi di tipo Syslog agli utenti
TPL Scrive l’output formattandolo in base ad un template definito dall’utente
TSV Scrive l’output in record separati da tab o da spazi
W3C Scrive file in formato W3C Extended Log File Format
XML Scrive l’output in un file XML

Qualche esempio pratico

IIS

Per fare un esempio pratico vorrei usare il campo time-taken che troviamo nei log di IIS: nelle versioni fino alle 6 era necessario abilitare esplicitamente questo valore nel log, fortunatamente dalla versione 7 in poi è invece abilitato di default:

time-taken in IIS 6

Il campo time-taken misura il tempo necessario per l’esecuzione di una richiesta http: il timestamp viene inizializzato quando il server (meglio, il driver http.sys, il responsabile del logging in IIS) riceve il primo byte della richiesta proveniente dal client e comprende il tempo per completare l’elaborazione e spedire il risultato (la pagina richiesta). A partire da IIS 6 questo valore tiene conto anche del tempo di trasmissione sulla rete, questo perchè http.sys ferma il timer quando riceve conferma che il client ha ricevuto anche l’ultimo byte spedito. Usando questo valore (in combinazione con gli altri dati contenuti nei log di IIS) è possibile creare report, grafici e statistiche circa i tempi di esecuzione delle richieste http, aggregarli e manipolarli come più ci piace e ci serve.

Ad esempio per conoscere il tempo medio di esecuzione delle nostre pagine .aspx possiamo eseguire una query simile a questa:

 logparser 
    "SELECT AVG(time-taken) As AverageTimeTaken, MAX(time-taken) As MaxTimeTaken, COUNT(*) As Hits, TO_LOWERCASE(cs-uri-stem) As Uri
    INTO average_uri_execution_time.txt FROM ex*.log 
    WHERE EXTRACT_EXTENSION(TO_LOWERCASE(cs-uri-stem)) = 'aspx'
    GROUP BY TO_LOWERCASE(cs-uri-stem) 
    ORDER BY AverageTimeTaken DESC"  
    -i:IISW3C -o:NAT -RTP:-1

Nota: il comando deve essere scritto ed eseguito in una riga singola, io l’ho diviso su più righe solo per migliorarne la leggibilità

Il risultato sarà qualcosa simile a questo:

 AverageTimeTaken MaxTimeTaken Hits Uri 
---------------- ------------ ---- -------------------------------
65382            130359       2    /testapp/post.aspx
57452            98531        3    /content/page2.aspx
44000            44000        2    /testapp/embed.aspx
43781            43781        1    /testapp/testapphandler.aspx
41953            41953        2    /testapp/sample.aspx
36046            36046        2    /testapp/connect.aspx
[...]

Se avete i log organizzati in sotto cartelle (o se avete più siti sullo stesso server, ognuno dei quali con i log raggruppati in una cartella separata), usando il formato di input IISW3C è possibile elaborarli tutti in una volta sola aggiungendo il parametro “ -recurse:-1” al comando qui sopra.

E se volessimo sapere quali sono le 10 pagine più lente del nostro sito?

 logparser 
    "SELECT TOP 10 time-taken, cs-uri-stem INTO top_time_taken.txt FROM ex*.log 
    WHERE EXTRACT_EXTENSION(TO_LOWERCASE(cs-uri-stem))='aspx' 
    ORDER BY time-taken DESC" 
    -i:IISW3C -o:NAT -RTP:-1

Se invece fossimo interessati ad una specifica finestra temporale (ad esempio per capire cosa è stato loggato quando si è verificato un particolare problema sul server):

 logparser 
    "SELECT AVG(time-taken) As AverageTimeTaken, MAX(time-taken) As MaxTimeTaken, COUNT(*) As Hits, TO_LOWERCASE(cs-uri-stem) As Uri 
    INTO date_range.txt FROM *.log 
    WHERE TO_TIMESTAMP(date,time) BETWEEN TIMESTAMP('2009/05/27 10:11:00', 'yyyy/MM/dd hh:mm:ss') AND TIMESTAMP('2009/05/27 11:20:00', 'yyyy/MM/dd hh:mm:ss') 
    GROUP BY TO_LOWERCASE(cs-uri-stem)" 
    -i:IISW3C -RECURSE:-1 -o:NAT -RTP:-1

Infine, per sapere quali tipi di risorse (tipi di file) vengono serviti dal nostro IIS, quali sono i tempi di esecuzione e quanti file per ogni tipo (per ogni estensione) sono stati richiesti, possiamo eseguire questo:

 logparser
    "SELECT TO_LOWERCASE(EXTRACT_EXTENSION(cs-uri-stem)) as ResourceType, MIN(time-taken) as MinTimeTaken, 
    MAX(time-taken) as MaxTimeTaken, AVG(time-taken) as AvgTimeTaken, COUNT(*) as Hits 
    INTO timers.txt FROM ex*.log GROUP BY ResourceType" 
    -i:IISW3C -o:NAT -RTP:-1

Ed otterremo questo:

 ResourceType  MinTimeTaken MaxTimeTaken AvgTimeTaken Hits 
------------- ------------ ------------ ------------ -----
aspx          0            338750       673          55984
htm           0            4640         247          928
mpeg          312          14453        8877         13
gif           0            792171       246          25881
ico           0            96734        691          2178
jpg           0            280859       1982         2694
pdf           0            1653156      6731         8752
css           0            63453        357          10284
js            0            73125        308          4719
html          0            32734        1214         2144
axd           0            88718        1324         1197
png           0            17593        794          458
[...]

Event Viewer

Cambiamo tipo di file in input. Capita spesso di aver bisogno di estrarre tutti i log per un particolare EventID dall’Event Viewer:

 logparser "SELECT TimeWritten, SourceName, EventID, Message INTO eventid.txt FROM *.evt 
    WHERE EventID = '1011'" -i:EVT -o:NAT -RTP:-1

Oppure possiamo convertire facilmente un file .evt in un file .csv ad esempio per poi filtrarlo con Excel (strano, ma so che c’è chi lo preferisce Surprised):

 logparser "SELECT * INTO System.csv FROM System.evt" -i:EVT -o:CSV

Nota: su Vista, Windows 2008 e Windows 7 prima di poter leggere da LogParser un file in formato .evt è necessario convertirlo nel nuovo formato .evtx con questo comando:

wevtutil epl application.evt application.evtx /lf:true

 

Spero di aver stuzzicato un po’ l’interesse per questo strumento potente e flessibile, in un prossimo post mostrerò altri query d’esempio e come creare grafici.

Carlo Cardella

Senior Support Engineer

EMEA IIS and Web Developer Support