Provide details from MDS ops dump output

parse_mds_ops_dump.py

#!/usr/bin/env python

import sys, json, operator
from datetime import datetime


obj=json.load(sys.stdin)

globaltimespent={}
opcount=0
for op in obj["ops"]:
    timespent={}
    lastepoch=0
    longestop=""
    longestdt=""
    longestsec=0
    subopstart=0
    firstdt=""
    totaltime=0
    firstepoch=(datetime.strptime(op["initiated_at"], "%Y-%m-%d %H:%M:%S.%f") - datetime(1970, 1, 1)).total_seconds()
    duration=op["duration"]
    for event in op["type_data"]["events"]:
        if(firstdt==""):
            firstdt=event["time"]
        utc_time = datetime.strptime(event["time"], "%Y-%m-%d %H:%M:%S.%f")
        gmtime = (utc_time - datetime(1970, 1, 1)).total_seconds()
        if(event["event"] not in timespent):
            if(lastepoch==0):
                lastepoch=gmtime
            timespent[event["event"]]={ 'delta':(gmtime-lastepoch), 'lastepoch': gmtime, 'lastdt':event["time"] }
            if(event["event"][:23]=="waiting for subops from"):
                subopstart=gmtime
            elif(event["event"][:22]=="sub_op_commit_rec from"):
                timespent[event["event"]]={ 'delta':(gmtime-subopstart), 'lastepoch': gmtime, 'lastdt':event["time"] }

        else:
            timespent[event["event"]]["delta"]+=gmtime-timespent[event["event"]]["lastepoch"]
            timespent[event["event"]]["lastepoch"]=gmtime
            timespent[event["event"]]["lastdt"]=event["time"]
        totaltime+=timespent[event["event"]]["delta"]
        lastepoch=gmtime
    if totaltime<duration:
        timespent[event["event"]]["delta"]+=duration-totaltime
    print("{0} {1} {2}".format(duration,firstdt,op["description"]))
    for event, edata in sorted(timespent.iteritems(), key=lambda (k,v): (v["lastepoch"],k)):
        print("\t{0:8.4f} {1:s} {2:s}".format(edata["delta"],edata["lastdt"],event))
        if event not in globaltimespent:
            globaltimespent[event]={ 'delta':0, 'count':0 }
        globaltimespent[event]['delta']+=edata["delta"]
        globaltimespent[event]['count']+=1
        opcount+=1

print("\n\nGlobal Time Spent by Op Type across {0:d} ops:".format(opcount))
print("\tTot Time(s)\tEvent                           \t  Avg Sec/op  \tOp#")
for event,edata in globaltimespent.items():
    print("\t{0:12.4f}\t{1:32s}\t{2:10.4f}\t{3:d}".format(edata['delta'],event,edata['delta']/edata['count'], edata['count']))