LogParser – Log extraction and visualizing

Or How to use the Log Parser to create a message sequence chart from protocol logs.

My call processing application generates copious amounts of logs that are irreplaceable in debugging problems with the system but its a pain to read and sift through thousands of lines to track logs for a particular call.
Log Parser is a great but overlooked tool that can help. Although there is a wide variety of built in input log formats that LogParser knows about, I found the CSV format to be more most convenient for my purpose.
I also found this Log Parser ToolkitBORDER=0 book to be a great resource for real world examples, diving right in.

An excerpt version of my logfile shows comma separated fields of information, I have added the header row for log parser to parse out the fields.

Time, Type, Port, Direction, Message, Extra
05:28.2,PROTO,0x410113fa , Recv, INVITE, From 4152484012 To 8886938437 IIDigits 0 CallId 5a87905440af7d8d2d677b8f6a4999ab@198.87.25.207. User2 is 0
05:28.2,PROTO,0x410113fa , Sent, 200 OK for INVITE, User2 is 0
05:28.4,FYI,0x410113fa ,, Playing prompt(s) c:\hello\Ivr\Prompts\NonWorkingNumber.pcm^,
05:28.4,PROTO,0x410113fa , Recv, ACK, User2 is 0
05:29.7,PROTO,0x410113fa , Recv, BYE, No Contents
05:29.7,PROTO,0x410113fa , Sent, 200 OK, for BYE
05:29.8,FYI,0x410113fa ,, Prompt play canceled,
08:14.6,FYI,0xffffffff , Initiating call to route 7, IP Address 10.2.20.20, Port 5060
08:14.6,PROTO,0x43f6e1a4 , Sent, INVITE, to User To – 14152484155 From – 8009751379 UserInfo – none CallId – 127bd67abc760140@REVWQURNSU4wMi5kZXYua2Vlbi5jb20.. User2 is 0
08:14.6,PROTO,0x43f6e1a4 , Recv,100, for INVITE
08:21.1,PROTO,0x43f6e1a4 , Recv,183, for INVITE
08:21.1,FYI,0x43f6e1a4 ,, Send Port Change of State. User2 is 0 ,
08:29.4,PROTO,0x43f6e1a4 , Recv,200, for INVITE
08:29.4,PROTO,0x43f6e1a4 , Sent, ACK, User2 is 0

The application dumps PROTO as part of the log statement where the SIP message is received or sent. We’ll use this field to identify the interesting lines.
Logparser lets you search log files by writing a SQL type query and the one I use looks something like this.

select
Message,
case Direction
when ‘Sent’ then ”
else ‘ ‘
end as Direction,
Extra
from input.csv to msc.out
where Type = ‘PROTO’

To generate a nice looking message sequence chart, I use the TPL output type and use this template file.

<LPHEADER>
<HTML>
<HEAD>
<TITLE>MSC</TITLE>
</HEAD>

<BODY>
<H1>MSC</H1>
<TABLEĀ  >
<TR>
<TH align=”left”>Carrier</TH>
<TH></TH>
<TH align=”left”><B>Switch</B></TH>
<TH></TH>
</TR>
</LPHEADER>

<LPBODY>
<TR>
<TD align=”center” colspan=”2″><TT>%Message%<BR>%Direction%</TT></TD>
<TD>%Extra%</TD>
</TR>

</LPBODY>

<LPFOOTER>
</BODY>
</HTML>
</LPFOOTER>

Now all we have to do is C:\> logparser file:input.sql -i:CSV -o:TPL -tpl:html.tpl and here is what the output comes out looking like.

Carrier
Switch
INVITE
—————–> From 4152484012 To 8886938437 IIDigits 0 CallId 5a87905440af7d8d2d677b8f6a4999ab@198.87.25.207. User2 is 0
200 OK for INVITE
User2 is 0
BYE
—————–> No Contents
200 OK
<—————– for BYE
INVITE
for INVITE
183
—————–> for INVITE
200
—————–> for INVITE
ACK
<—————– User2 is 0

Nice!!