Working together with Roy Holder of HADSL on an engagement to improve performance of a large CRM application, we needed a quick way to analyze client clock data from a Lotus Notes client.
I developed an excel macro that does the job. Here it is:
(you do need MS VbScript Regular Expressions 5.5, available in VB 6.0)
'(C) 2011 Trust Factory BV
' Wouter Aukema
Public Type parsedline
linenr As Double
seqThread As Integer
seconds As Double
seqLog As Double
rpccall As String
server As String
filepath As String
replicaid As String
noteid As String
ms As Double
bytesin As Double
bytesout As Double
bytesall As Double
parse_completed As Boolean
End Type
Sub ParseClock()
Dim ws As Worksheet
Dim ORegex As RegExp
Dim OMatchCollection As MatchCollection
Dim OMatch As Match
Dim strPattern As String
Dim strLine As String
Dim origLine() As String
Dim newLine() As String
Dim errLine() As String
Dim logEntry() As parsedline
'SET ROW HEADERS IN WORKSHEET
ActiveWorkbook.Worksheets.Add
Set ws = ActiveSheet
ws.Name = Format(Now, "ddmmmyyyy_hhmmss")
ws.Cells(1, 1) = "timestamp"
ws.Cells(1, 2) = "line_nr"
ws.Cells(1, 3) = "seqThread"
ws.Cells(1, 4) = "seconds"
ws.Cells(1, 5) = "seqLog"
ws.Cells(1, 6) = "rpccall"
ws.Cells(1, 7) = "dbserver"
ws.Cells(1, 8) = "dbfilepath"
ws.Cells(1, 9) = "dbreplicaid"
ws.Cells(1, 10) = "noteid"
ws.Cells(1, 11) = "calloptions"
ws.Cells(1, 12) = "milliseconds"
ws.Cells(1, 13) = "bytesin"
ws.Cells(1, 14) = "bytesout"
ws.Cells(1, 15) = "bytesall"
ws.Cells(1, 16) = "elapsedtime"
ws.Cells(1, 17) = "elapsedbytes"
ws.Cells(1, 18) = "elapsedkbps"
ws.Cells(1, 19) = "design_type"
ws.Cells(1, 20) = "design_name"
ws.Cells(1, 21) = "design_url"
Dim v As Variant
Set v = ActiveWorkbook.CustomDocumentProperties
' Stop
txtdir = InputBox("Directory", , ActiveWorkbook.CustomDocumentProperties("directory").Value)
If txtdir <> "" And txtdir <> ActiveWorkbook.CustomDocumentProperties("directory").Value Then ActiveWorkbook.CustomDocumentProperties("directory").Value = txtdir
logfile = InputBox("Directory", , ActiveWorkbook.CustomDocumentProperties("logfile").Value)
If logfile <> "" And logfile <> ActiveWorkbook.CustomDocumentProperties("logfile").Value Then ActiveWorkbook.CustomDocumentProperties("logfile").Value = logfile
If logfile = "" Or txtdir = "" Then End
Open txtdir + "\" + logfile For Input As #1
'Open "C:\Program Files\lotus\notes\data\IBM_TECHNICAL_SUPPORT\xxx.log" For Input As #1
Application.StatusBar = "Processing " & txtdir & "\" & logfile & " ..."
'GET STARTTIMEDATE from LOGFILE
Set ORegex = New RegExp
Input #1, strLine
ORegex.Pattern = "([0-9]{4})\_([0-9]{2})\_([0-9]{2})\@([0-9]{2})\_([0-9]{2})\_([0-9]{2})"
Set OMatchCollection = ORegex.Execute(strLine)
For Each OMatch In OMatchCollection
logDate = DateSerial(Val(Left(OMatch.Value, 4)), Val(Mid(OMatch.Value, 6, 2)), Val(Mid(OMatch.Value, 9, 2)))
logTime = TimeSerial(Val(Mid(OMatch.Value, 12, 2)), Val(Mid(OMatch.Value, 15, 2)), Val(Mid(OMatch.Value, 18, 2)))
Next
logStart = logDate + logTime
ws.Cells(2, 1).NumberFormat = "dd/mm/yy hh:mm:ss"
ws.Cells(2, 1) = logStart
'READ ALL LINES FROM LOGFILE into origLine()
n = 0
While Not EOF(1)
ReDim Preserve origLine(n)
Line Input #1, origLine(n)
origLine(n) = WorksheetFunction.Substitute(origLine(n), "NOTE LOCK/UNLOCK", "NOTE_LOCK_UNLOCK")
origLine(n) = WorksheetFunction.Substitute(origLine(n), "GET LAST INDEX TIME", "GET_LAST_INDEX_TIME")
'add more replacements when needed...
n = n + 1
Wend
Close 1
'NOW START WORKING LINE BY LINE, splitting multiple commands into seperate newlines()
linenum = 2
ReDim Preserve newLine(0)
While linenum < UBound(origLine)
'Check for proper lines to interpret:
strPattern = "\([0-9]*\-[0-9]*\ \[[0-9]+\]\)\ ([A-Z0-9_]+)"
ORegex.Pattern = strPattern
ORegex.Global = True
Set OMatchCollection = ORegex.Execute(origLine(linenum))
If OMatchCollection.Count > 1 Then 'we have multiple commands on a single line...
ReDim Preserve newLine(UBound(newLine) + 2)
i = InStr(1, origLine(linenum), OMatchCollection.Item(1)) - 1
newLine(UBound(newLine) - 1) = Left(origLine(linenum), i)
newLine(UBound(newLine) - 1) = Trim(OMatchCollection.Item(0))
'start parsing second command:
newLine(UBound(newLine) + 0) = Trim(Mid(origLine(linenum), Len(newLine(UBound(newLine) - 1)) + 1, 200))
ElseIf OMatchCollection.Count = 1 Then
ReDim Preserve newLine(UBound(newLine) + 1)
newLine(UBound(newLine)) = origLine(linenum) 'was: Trim(OMatchCollection.Item(0))
Else
'skip line
'Stop
End If
linenum = linenum + 1
Wend
'NOW START PARSING ENTRIES
ReDim logEntry(UBound(newLine))
linenum = 1
While linenum <= UBound(newLine)
'first 4 items:
ORegex.Pattern = "^.*\(([0-9]*)\-([0-9]*)\ \[([0-9]+)\]\)\ ([A-Z0-9_]+)"
ORegex.Global = True
Set OMatchCollection = ORegex.Execute(newLine(linenum))
Set OMatch = OMatchCollection.Item(0)
ReDim Preserve logEntry(linenum)
logEntry(linenum).linenr = linenum
logEntry(linenum).seqThread = OMatch.SubMatches(0)
logEntry(linenum).seconds = OMatch.SubMatches(1)
logEntry(linenum).seqLog = OMatch.SubMatches(2)
logEntry(linenum).rpccall = OMatch.SubMatches(3)
'replica_ids if exist...
ORegex.Pattern = ".*REP([A-F0-9]{8})\:([A-F0-9]{8})"
ORegex.Global = False
Set OMatchCollection = ORegex.Execute(newLine(linenum))
If OMatchCollection.Count > 0 Then
Set OMatch = OMatchCollection.Item(0)
logEntry(linenum).replicaid = OMatch.SubMatches(0) + OMatch.SubMatches(1)
End If
'note_ids if exist...
ORegex.Pattern = ".*\-NT([A-F0-9]{8})"
ORegex.Global = False
Set OMatchCollection = ORegex.Execute(newLine(linenum))
If OMatchCollection.Count > 0 Then
Set OMatch = OMatchCollection.Item(0)
logEntry(linenum).noteid = OMatch.SubMatches(0)
End If
'milliseconds...
ORegex.Pattern = "\ ([0-9]+)\ ms"
ORegex.Global = True
Set OMatchCollection = ORegex.Execute(newLine(linenum))
If OMatchCollection.Count > 0 Then
Set OMatch = OMatchCollection.Item(0)
logEntry(linenum).ms = OMatch.SubMatches(0)
End If
'bytes IO...
ORegex.Pattern = "\[([0-9]+)\+([0-9]+)\=([0-9]+)\]"
ORegex.Global = True
Set OMatchCollection = ORegex.Execute(newLine(linenum))
If OMatchCollection.Count > 0 Then
Set OMatch = OMatchCollection.Item(0)
If OMatch.SubMatches.Count > 1 Then
logEntry(linenum).bytesout = OMatch.SubMatches(0)
logEntry(linenum).bytesin = OMatch.SubMatches(1)
logEntry(linenum).bytesall = OMatch.SubMatches(2)
End If
End If
'Stop
linenum = linenum + 1
Wend
'FILL WORKSHEET
If UBound(logEntry) > 65535 Then
MsgBox "Too many Lines!"
End
End If
Excel.Application.ScreenUpdating = False
Excel.Application.Calculation = xlCalculationManual
ws.Cells(2, 4) = 0
For n = 0 To UBound(logEntry)
ws.Cells(n + 3, 2).NumberFormat = "#,##"
ws.Cells(n + 3, 2) = logEntry(n).linenr
ws.Cells(n + 3, 3) = logEntry(n).seqThread
ws.Cells(n + 3, 4).NumberFormat = "#,##"
ws.Cells(n + 3, 4) = logEntry(n).seconds
ws.Cells(n + 3, 5).NumberFormat = "#,##"
ws.Cells(n + 3, 5) = logEntry(n).seqLog
ws.Cells(n + 3, 6) = logEntry(n).rpccall
'ws.Cells(n + 3, 7) = logEntry(n).server
'ws.Cells(n + 3, 8) = logEntry(n).filepath
ws.Cells(n + 3, 9).NumberFormat = "@"
ws.Cells(n + 3, 9) = logEntry(n).replicaid
ws.Cells(n + 3, 10).NumberFormat = "@"
ws.Cells(n + 3, 10) = logEntry(n).noteid
ws.Cells(n + 3, 12).NumberFormat = "#,##"
ws.Cells(n + 3, 12) = logEntry(n).ms
ws.Cells(n + 3, 13).NumberFormat = "#,##"
ws.Cells(n + 3, 13) = logEntry(n).bytesin
ws.Cells(n + 3, 14).NumberFormat = "#,##"
ws.Cells(n + 3, 14) = logEntry(n).bytesout
ws.Cells(n + 3, 15).NumberFormat = "#,##"
ws.Cells(n + 3, 15) = logEntry(n).bytesall
ws.Cells(n + 3, 16).NumberFormat = "#,##.00"
ws.Cells(n + 3, 16) = "=(RC[-15]-R2C[-15])*3600*24"
ws.Cells(n + 3, 17).NumberFormat = "#,##"
ws.Cells(n + 3, 17) = "=SUM(R2C[-2]:RC[-2])/1"
ws.Cells(n + 3, 18).NumberFormat = "#,##"
ws.Cells(n + 3, 18) = "=IF(RC[-2]>0,8*RC[-1]/RC[-2])/1024"
ws.Cells(n + 3, 1) = "=R2C+R[-1]C[3]/24/3600"
ws.Cells(n + 3, 1).NumberFormat = "dd/mm/yy hh:mm:ss"
If n / 100 = Int(n / 100) Then Application.StatusBar = "Processing " & txtdir & "\" & logfile & " ... " & Str(n)
Next n
Excel.Application.ScreenUpdating = True
Excel.Application.Calculation = xlCalculationAutomatic
Application.StatusBar = False
End Sub
Function regreplace(rIn As String, rPattern As String, rReplace As String, Optional rIgnoreCase As Boolean, Optional rGlobal As Boolean) As String
Dim regex As New RegExp
Dim mc As MatchCollection
With regex
.Pattern = rPattern
.IgnoreCase = rIgnoreCase
.Global = rGlobal
End With
Set mc = regex.Execute(rIn)
If mc.Count <> 0 Then
regreplace = regex.Replace(rIn, rReplace)
Else
regreplace = ""
' Debug.Print rIn
End If
End Function
ReplyDeleteDear Wouter, for the analysis of NRPC Calls I recommend the OpenNTF project NRPC Parser:
http://www.openntf.org/Projects/pmt.nsf/7638426676e9ef6a8625755a00680e95/e4e4acf820f937fa8625746200066082!OpenDocument
Andrew
Thank you Andrew, I will take a look at it!
Delete