tools: parselog: parse winfsp logs

tools/parselog.nim

@@ -0,0 +1,318 @@
+# @file parselog.nim
+#
+# parse WinFsp debug logs
+#
+# @copyright 2015-2020 Bill Zissimopoulos
+
+import algorithm
+import macros
+import parseopt
+import parseutils
+import strformat
+import strscans
+import strutils
+import tables
+
+type
+    Req = ref object
+        fsname: string
+        tid: uint32
+        irp: uint64
+        op: string
+        inform: string
+        context: string
+        args: seq[(string, string)]
+    Rsp = ref object
+        fsname: string
+        tid: uint32
+        irp: uint64
+        op: string
+        status: uint32
+        inform: uint
+        context: string
+        args: seq[(string, string)]
+
+proc parseAndAddArg(prefix: string, rest: var string, args: var seq[(string, string)]) =
+    discard scanf(rest, ",$*", rest)
+    discard scanf(rest, "$s$*", rest)
+    var n, v: string
+    if scanf(rest, "\"$*\"$*", v, rest):
+        args.add((prefix & "", v))
+    elif scanf(rest, "$w=\"$*\"$*", n, v, rest):
+        args.add((prefix & n, v))
+    elif scanf(rest, "$w={$*}$*", n, v, rest):
+        while "" != v:
+            parseAndAddArg(n & ".", v, args)
+    elif scanf(rest, "$w=$*,$*", n, v, rest):
+        args.add((prefix & n, v))
+    elif scanf(rest, "$w=$*$.", n, v):
+        rest = ""
+        args.add((prefix & n, v))
+    elif scanf(rest, "$*,$*", v, rest):
+        args.add((prefix & "", v))
+    else:
+        v = rest
+        rest = ""
+        args.add((prefix & "", v))
+
+proc parseArgs(rest: var string): seq[(string, string)] =
+    while "" != rest:
+        parseAndAddArg("", rest, result)
+
+proc parseReq(op, rest: string): Req =
+    result = Req(op: op)
+    var rest = rest
+    var inform: string
+    if scanf(rest, "[$+]$s$*", inform, rest):
+        result.inform = inform
+    var c0, c1: uint64
+    if scanf(rest, "${parseHex[uint64]}:${parseHex[uint64]}$*", c0, c1, rest):
+        result.context = toHex(c0) & ":" & toHex(c1)
+    result.args = parseArgs(rest)
+
+proc parseRsp(op, rest: string): Rsp =
+    result = Rsp(op: op)
+    var rest = rest
+    var status: uint32
+    var inform: uint
+    if scanf(rest, "IoStatus=${parseHex[uint32]}[${parseUint}]$s$*", status, inform, rest):
+        result.status = status
+        result.inform = inform
+    var c0, c1: uint64
+    if scanf(rest, "UserContext=${parseHex[uint64]}:${parseHex[uint64]}$*", c0, c1, rest):
+        result.context = toHex(c0) & ":" & toHex(c1)
+    result.args = parseArgs(rest)
+
+proc parseLog(path: string, processReq: proc(req: Req), processRsp: proc(rsp: Rsp)) =
+    let file = open(path)
+    defer: file.close()
+    var lineno = 0
+    try:
+        for line in lines file:
+            inc lineno
+            var fsname, dir, op, rest: string
+            var tid: uint32
+            var irp: uint64
+            var req: Req
+            var rsp: Rsp
+            if scanf(line, "$+[TID=${parseHex[uint32]}]:$s${parseHex[uint64]}:$s$+ $*",
+                fsname, tid, irp, op, rest):
+                dir = op[0..1]
+                op = op[2..^1]
+                case dir
+                of ">>":
+                    req = parseReq(op, rest)
+                    req.fsname = fsname
+                    req.tid = tid
+                    req.irp = irp
+                    processReq(req)
+                of "<<":
+                    rsp = parseRsp(op, rest)
+                    rsp.fsname = fsname
+                    rsp.tid = tid
+                    rsp.irp = irp
+                    processRsp(rsp)
+                else:
+                    continue
+    except:
+        echo &"An exception has occurred while parsing file {path} line {lineno}"
+        raise
+
+type
+    Stat = ref object
+        ototal: int                     # open total
+        oerror: int                     # open error total
+        mtotal: int                     # multiplicate open total
+        rtotal: int                     # read total
+        rbytes: uint64                  # read bytes
+        rerror: int                     # read error total
+        wtotal: int                     # write total
+        wbytes: uint64                  # write bytes
+        werror: int                     # write error total
+        dtotal: int                     # query directory total
+        dbytes: uint64                  # query directory bytes
+        derror: int                     # query directory error total
+        ptotal: int                     # query directory w/ pattern total
+        pbytes: uint64                  # query directory w/ pattern bytes
+        perror: int                     # query directory w/ pattern error total
+        ocount: int                     # current open count
+var
+    reqtab = newTable[uint64, Req]()
+    filetab = newTable[string, string]()
+    stattab = newOrderedTable[string, Stat]()
+    aggr = Stat()
+
+proc getArg(args: seq[(string, string)], name: string): string =
+    for n, v in items(args):
+        if name == n:
+            return v
+
+proc processReq(req: Req) =
+    reqtab[req.irp] = req
+    case req.op
+    of "Close":
+        var filename: string
+        if filetab.pop(req.context, filename):
+            var stat = stattab.mgetOrPut(filename, Stat())
+            stat.ocount -= 1
+
+proc processRsp(rsp: Rsp) =
+    var req: Req
+    if reqtab.pop(rsp.irp, req):
+        doAssert req.op == rsp.op
+        doAssert req.irp == rsp.irp
+        case req.op
+        of "Create":
+            var filename = getArg(req.args, "")
+            if "" != filename:
+                if 0 == rsp.status:
+                    filetab[rsp.context] = filename
+                    var stat = stattab.mgetOrPut(filename, Stat())
+                    stat.ototal += 1
+                    aggr.ototal += 1
+                    stat.ocount += 1
+                    if 2 == stat.ocount:
+                        stat.mtotal += 1
+                        aggr.mtotal += 1
+                else:
+                    var stat = stattab.mgetOrPut(filename, Stat())
+                    stat.oerror += 1
+                    aggr.oerror += 1
+        of "Read":
+            var filename = filetab[req.context]
+            var stat = stattab.mgetOrPut(filename, Stat())
+            if 0 == rsp.status:
+                stat.rtotal += 1
+                stat.rbytes += rsp.inform
+                aggr.rtotal += 1
+                aggr.rbytes += rsp.inform
+            elif 0xC0000011u32 != rsp.status:
+                echo &"{rsp.status:X}"
+                stat.rerror += 1
+                aggr.rerror += 1
+        of "Write":
+            var filename = filetab[req.context]
+            var stat = stattab.mgetOrPut(filename, Stat())
+            if 0 == rsp.status:
+                stat.wtotal += 1
+                stat.wbytes += rsp.inform
+                aggr.wtotal += 1
+                aggr.wbytes += rsp.inform
+            else:
+                stat.werror += 1
+                aggr.werror += 1
+        of "QueryDirectory":
+            var filename = filetab[req.context]
+            var stat = stattab.mgetOrPut(filename, Stat())
+            var pattern = getArg(req.args, "Pattern")
+            if "NULL" == pattern:
+                if 0 == rsp.status:
+                    stat.dtotal += 1
+                    stat.dbytes += rsp.inform
+                    aggr.dtotal += 1
+                    aggr.dbytes += rsp.inform
+                else:
+                    stat.derror += 1
+                    aggr.derror += 1
+            else:
+                if 0 == rsp.status:
+                    stat.ptotal += 1
+                    stat.pbytes += rsp.inform
+                    aggr.ptotal += 1
+                    aggr.pbytes += rsp.inform
+                else:
+                    stat.perror += 1
+                    aggr.perror += 1
+
+macro identName(n: untyped): untyped =
+    result = n.strVal.newLit
+
+template dumpstat(F: untyped) =
+    stattab.sort(proc (x, y: (string, Stat)): int =
+        cmp(x[1].F, y[1].F), SortOrder.Descending)
+    var width, rows = 0
+    for filename, stat in stattab.pairs:
+        if 0 == width:
+            var s = identName(F).toUpperAscii()
+            width = len($aggr.F)
+            if width < len(s):
+                width = len(s)
+            var f: string
+            formatValue(f, s, ">" & $width)
+            echo f, "  PER% FILENAME"
+        var c0, c1: string
+        formatValue(c0, stat.F, $width)
+        if 0 != aggr.F:
+            formatValue(c1, 100.0 * float(stat.F) / float(aggr.F), "5.1f")
+        else:
+            c1 = "     "
+        echo c0, " ", c1, " ", filename
+        inc rows
+        if opttop == rows:
+            break
+    var c0: string
+    formatValue(c0, aggr.F, $width)
+    echo c0, " 100.0 TOTAL"
+
+proc main =
+    var filenames: seq[string]
+    var optstat: seq[string]
+    var opttop = 0
+    for kind, key, val in getopt(shortNoVal = {'Z'}, longNoVal = @["Zoo"]):
+        case kind
+        of cmdShortOption, cmdLongOption:
+            case key
+            of "stat":
+                optstat.add(val)
+            of "n":
+                opttop = parseInt(val)
+        of cmdArgument:
+            filenames.add(key)
+        else:
+            discard
+    if 0 == len(optstat):
+        optstat.add("ototal")
+
+    if 0 == len(filenames):
+        stderr.writeLine("usage: parselog [-nNN] [--stat ototal|rtotal|wtotal|dtotal|...] file...")
+        quit(2)
+
+    for filename in filenames:
+        parseLog filename, processReq, processRsp
+
+    for s in optstat:
+        case s
+        of "ototal":
+            dumpstat ototal
+        of "oerror":
+            dumpstat oerror
+        of "mtotal":
+            dumpstat mtotal
+        of "rtotal":
+            dumpstat rtotal
+        of "rbytes":
+            dumpstat rbytes
+        of "rerror":
+            dumpstat rerror
+        of "wtotal":
+            dumpstat wtotal
+        of "wbytes":
+            dumpstat wbytes
+        of "werror":
+            dumpstat werror
+        of "dtotal":
+            dumpstat dtotal
+        of "dbytes":
+            dumpstat dbytes
+        of "derror":
+            dumpstat derror
+        of "ptotal":
+            dumpstat ptotal
+        of "pbytes":
+            dumpstat pbytes
+        of "perror":
+            dumpstat perror
+        echo ""
+
+when isMainModule:
+    main()