user/kvmtrace_format

   1 #!/usr/bin/env python
   2
   3 # by Mark Williamson, (C) 2004 Intel Research Cambridge
   4
   5 # Program for reformatting trace buffer output according to user-supplied rules
   6
   7 import re, sys, string, signal, struct, os, getopt, operator
   8
   9 def usage():
  10     print >> sys.stderr, \
  11           "Usage: " + sys.argv[0] + """ defs-file
  12           Parses trace data in binary format, as output by kvmtrace and
  13           reformats it according to the rules in a file of definitions.  The
  14           rules in this file should have the format ({ and } show grouping
  15           and are not part of the syntax):
  16
  17           {event_id}{whitespace}{text format string}
  18
  19           The textual format string may include format specifiers, such as:
  20             %(ts)d, %(event)d, %(pid)d %(vcpu)d %(1)d, %(2)d,
  21             %(3)d, %(4)d, %(5)d
  22           [ the 'd' format specifier outputs in decimal, alternatively 'x'
  23             will output in hexadecimal and 'o' will output in octal ]
  24
  25           Which correspond to the event ID, timestamp counter, pid
  26           , vcpu and the 5 data fields from the trace record.  There should be
  27           one such rule for each type of event.
  28           Depending on your system and the volume of trace buffer data,
  29           this script may not be able to keep up with the output of kvmtrace
  30           if it is piped directly.  In these circumstances you should have
  31           kvmtrace output to a file for processing off-line.
  32
  33           kvmtrace_format has the following additional switches
  34           -s     - if this switch is set additional trace statistics are
  35                    created and printed at the end of the output
  36           """
  37     sys.exit(1)
  38
  39 def read_defs(defs_file):
  40     defs = {}
  41
  42     fd = open(defs_file)
  43
  44     reg = re.compile('(\S+)\s+(\S.*)')
  45
  46     while True:
  47         line = fd.readline()
  48         if not line:
  49             break
  50
  51         if line[0] == '#' or line[0] == '\n':
  52             continue
  53
  54         m = reg.match(line)
  55
  56         if not m: print >> sys.stderr, "Bad format file" ; sys.exit(1)
  57
  58         defs[str(eval(m.group(1)))] = m.group(2)
  59
  60     return defs
  61
  62 def sighand(x,y):
  63     global interrupted
  64     interrupted = 1
  65
  66 # ppc instruction decoding for event type 0x00020019 (PPC_INSTR)
  67 # some globals for statistic summaries
  68 stat_ppc_instr_mnemonic = {};
  69 stat_ppc_instr_spr = {};
  70 stat_ppc_instr_dcr = {};
  71 stat_ppc_instr_tlb = {};
  72
  73 def ppc_instr_print_summary(sortedlist, colname):
  74         print "\n\n%14s + %10s" % (colname, "count")
  75         print "%s" % (15*"-"+"+"+11*"-")
  76         sum = 0
  77         for value, key in sortedlist:
  78                 sum += key
  79                 print "%14s | %10d" % (value, key)
  80         print "%14s = %10d" % ("sum", sum)
  81
  82
  83 def ppc_instr_summary():
  84         # don't print empty statistics
  85         if stat_ppc_instr_mnemonic:
  86                 ppc_instr_print_summary(sorted(stat_ppc_instr_mnemonic.iteritems(), key=operator.itemgetter(1), reverse=True), "mnemonic")
  87         if stat_ppc_instr_spr:
  88                 ppc_instr_print_summary(sorted(stat_ppc_instr_spr.iteritems(), key=operator.itemgetter(1), reverse=True), "mnemonic-spr")
  89         if stat_ppc_instr_dcr:
  90                 ppc_instr_print_summary(sorted(stat_ppc_instr_dcr.iteritems(), key=operator.itemgetter(1), reverse=True), "mnemonic-dcr")
  91         if stat_ppc_instr_tlb:
  92                 ppc_instr_print_summary(sorted(stat_ppc_instr_tlb.iteritems(), key=operator.itemgetter(1), reverse=True), "mnemonic-tlb")
  93
  94 def get_op(instr):
  95         return (instr >> 26);
  96
  97 def get_xop(instr):
  98         return (instr >> 1) & 0x3ff;
  99
 100 def get_sprn(instr):
 101         return ((instr >> 16) & 0x1f) | ((instr >> 6) & 0x3e0)
 102
 103 def get_dcrn(instr):
 104         return ((instr >> 16) & 0x1f) | ((instr >> 6) & 0x3e0);
 105
 106 def get_tlbwe_type(instr):
 107         ws = (instr >> 11) & 0x1f;
 108         if ws == 0:
 109                 return "PAGEID"
 110         elif ws == 1:
 111                 return "XLAT"
 112         elif ws == 2:
 113                 return "ATTRIB"
 114         else:
 115                 return "UNKNOWN"
 116
 117 def get_name(instr):
 118         if get_op(instr)==3:
 119                 return "trap"
 120         elif get_op(instr)==19:
 121                 if get_xop(instr) == 50:
 122                         return "rfi"
 123                 else:
 124                         return "unknown"
 125         elif get_op(instr)==31:
 126                 if get_xop(instr) == 83:
 127                         return "mfmsr"
 128
 129                 elif get_xop(instr) == 87:
 130                         return "lbzx"
 131
 132                 elif get_xop(instr) == 131:
 133                         return "wrtee"
 134
 135                 elif get_xop(instr) == 146:
 136                         return "mtmsr"
 137
 138                 elif get_xop(instr) == 163:
 139                         return "wrteei"
 140
 141                 elif get_xop(instr) == 215:
 142                         return "stbx"
 143
 144                 elif get_xop(instr) == 247:
 145                         return "stbux"
 146
 147                 elif get_xop(instr) == 279:
 148                         return "lhzx"
 149
 150                 elif get_xop(instr) == 311:
 151                         return "lhzux"
 152
 153                 elif get_xop(instr) == 323:
 154                         return "mfdcr"
 155
 156                 elif get_xop(instr) == 339:
 157                         return "mfspr"
 158
 159                 elif get_xop(instr) == 407:
 160                         return "sthx"
 161
 162                 elif get_xop(instr) == 439:
 163                         return "sthux"
 164
 165                 elif get_xop(instr) == 451:
 166                         return "mtdcr"
 167
 168                 elif get_xop(instr) == 467:
 169                         return "mtspr"
 170
 171                 elif get_xop(instr) == 470:
 172                         return "dcbi"
 173
 174                 elif get_xop(instr) == 534:
 175                         return "lwbrx"
 176
 177                 elif get_xop(instr) == 566:
 178                         return "tlbsync"
 179
 180                 elif get_xop(instr) == 662:
 181                         return "stwbrx"
 182
 183                 elif get_xop(instr) == 978:
 184                         return "tlbwe"
 185
 186                 elif get_xop(instr) == 914:
 187                         return "tlbsx"
 188
 189                 elif get_xop(instr) == 790:
 190                         return "lhbrx"
 191
 192                 elif get_xop(instr) == 918:
 193                         return "sthbrx"
 194
 195                 elif get_xop(instr) == 966:
 196                         return "iccci"
 197
 198                 else:
 199                         return "unknown"
 200
 201         elif get_op(instr) == 32:
 202                 return "lwz"
 203
 204         elif get_op(instr) == 33:
 205                 return "lwzu"
 206
 207         elif get_op(instr) == 34:
 208                 return "lbz"
 209
 210         elif get_op(instr) == 35:
 211                 return "lbzu"
 212
 213         elif get_op(instr) == 36:
 214                 return "stw"
 215
 216         elif get_op(instr) == 37:
 217                 return "stwu"
 218
 219         elif get_op(instr) == 38:
 220                 return "stb"
 221
 222         elif get_op(instr) == 39:
 223                 return "stbu"
 224
 225         elif get_op(instr) == 40:
 226                 return "lhz"
 227
 228         elif get_op(instr) == 41:
 229                 return "lhzu"
 230
 231         elif get_op(instr) == 44:
 232                 return "sth"
 233
 234         elif get_op(instr) == 45:
 235                 return "sthu"
 236
 237         else:
 238                 return "unknown"
 239
 240 def get_sprn_name(sprn):
 241                 if sprn == 0x01a:
 242                         return "SRR0"
 243                 elif sprn == 0x01b:
 244                         return "SRR1"
 245                 elif sprn == 0x3b2:
 246                         return "MMUCR"
 247                 elif sprn == 0x030:
 248                         return "PID"
 249                 elif sprn == 0x03f:
 250                         return "IVPR"
 251                 elif sprn == 0x3b3:
 252                         return "CCR0"
 253                 elif sprn == 0x378:
 254                         return "CCR1"
 255                 elif sprn == 0x11f:
 256                         return "PVR"
 257                 elif sprn == 0x03d:
 258                         return "DEAR"
 259                 elif sprn == 0x03e:
 260                         return "ESR"
 261                 elif sprn == 0x134:
 262                         return "DBCR0"
 263                 elif sprn == 0x135:
 264                         return "DBCR1"
 265                 elif sprn == 0x11c:
 266                         return "TBWL"
 267                 elif sprn == 0x11d:
 268                         return "TBWU"
 269                 elif sprn == 0x016:
 270                         return "DEC"
 271                 elif sprn == 0x150:
 272                         return "TSR"
 273                 elif sprn == 0x154:
 274                         return "TCR"
 275                 elif sprn == 0x110:
 276                         return "SPRG0"
 277                 elif sprn == 0x111:
 278                         return "SPRG1"
 279                 elif sprn == 0x112:
 280                         return "SPRG2"
 281                 elif sprn == 0x113:
 282                         return "SPRG3"
 283                 elif sprn == 0x114:
 284                         return "SPRG4"
 285                 elif sprn == 0x115:
 286                         return "SPRG5"
 287                 elif sprn == 0x116:
 288                         return "SPRG6"
 289                 elif sprn == 0x117:
 290                         return "SPRG7"
 291                 elif sprn == 0x190:
 292                         return "IVOR0"
 293                 elif sprn == 0x191:
 294                         return "IVOR1"
 295                 elif sprn == 0x192:
 296                         return "IVOR2"
 297                 elif sprn == 0x193:
 298                         return "IVOR3"
 299                 elif sprn == 0x194:
 300                         return "IVOR4"
 301                 elif sprn == 0x195:
 302                         return "IVOR5"
 303                 elif sprn == 0x196:
 304                         return "IVOR6"
 305                 elif sprn == 0x197:
 306                         return "IVOR7"
 307                 elif sprn == 0x198:
 308                         return "IVOR8"
 309                 elif sprn == 0x199:
 310                         return "IVOR9"
 311                 elif sprn == 0x19a:
 312                         return "IVOR10"
 313                 elif sprn == 0x19b:
 314                         return "IVOR11"
 315                 elif sprn == 0x19c:
 316                         return "IVOR12"
 317                 elif sprn == 0x19d:
 318                         return "IVOR13"
 319                 elif sprn == 0x19e:
 320                         return "IVOR14"
 321                 elif sprn == 0x19f:
 322                         return "IVOR15"
 323                 else:
 324                         return "UNKNOWN"
 325
 326 def get_special(instr):
 327         name = get_name(instr);
 328         if stat_ppc_instr_mnemonic.has_key(name):
 329                 stat_ppc_instr_mnemonic[name] += 1
 330         else:
 331                 stat_ppc_instr_mnemonic[name] = 1
 332
 333         if get_op(instr) == 31:
 334                 if (get_xop(instr) == 339) or (get_xop(instr) == 467):
 335                         sprn = get_sprn(instr);
 336                         sprn_name = get_sprn_name(sprn);
 337                         stat_idx = name+"-"+sprn_name
 338                         if stat_ppc_instr_spr.has_key(stat_idx):
 339                                 stat_ppc_instr_spr[stat_idx] += 1
 340                         else:
 341                                 stat_ppc_instr_spr[stat_idx] = 1
 342                         return ("- sprn 0x%03x %8s" % (sprn, sprn_name))
 343                 elif (get_xop(instr) == 323 ) or (get_xop(instr) == 451):
 344                         dcrn = get_dcrn(instr);
 345                         stat_idx = name+"-"+("%04X"%dcrn)
 346                         if stat_ppc_instr_dcr.has_key(stat_idx):
 347                                 stat_ppc_instr_dcr[stat_idx] += 1
 348                         else:
 349                                 stat_ppc_instr_dcr[stat_idx] = 1
 350                         return ("- dcrn 0x%03x" % dcrn)
 351                 elif (get_xop(instr) == 978 ) or (get_xop(instr) == 451):
 352                         tlbwe_type = get_tlbwe_type(instr)
 353                         stat_idx = name+"-"+tlbwe_type
 354                         if stat_ppc_instr_tlb.has_key(stat_idx):
 355                                 stat_ppc_instr_tlb[stat_idx] += 1
 356                         else:
 357                                 stat_ppc_instr_tlb[stat_idx] = 1
 358                         return ("- ws -> %8s" % tlbwe_type)
 359         return ""
 360
 361 ##### Main code
 362
 363 summary = False
 364
 365 if len(sys.argv) < 2:
 366     usage()
 367
 368 try:
 369     opts, arg = getopt.getopt(sys.argv[1:], "sc:" )
 370     for opt in opts:
 371         if opt[0] == '-s' : summary = True
 372
 373 except getopt.GetoptError:
 374     usage()
 375
 376 signal.signal(signal.SIGTERM, sighand)
 377 signal.signal(signal.SIGHUP,  sighand)
 378 signal.signal(signal.SIGINT,  sighand)
 379
 380 interrupted = 0
 381
 382 defs = read_defs(arg[0])
 383
 384 # structure of trace record (as output by kvmtrace):
 385 # HDR(I) {TSC(Q)} D1(I) D2(I) D3(I) D4(I) D5(I)
 386 #
 387 # HDR consists of EVENT:28:, n_data:3:, ts_in:1:
 388 # pid:32, vcpu_id:32
 389 # EVENT means Event ID
 390 # n_data means number of data (like D1, D2, ...)
 391 # ts_in means Timestamp data exists(1) or not(0).
 392 # if ts_in == 0, TSC(Q) does not exists.
 393 #
 394 HDRREC = "<III"
 395 TSCREC = "<Q"
 396 D1REC  = "<I"
 397 D2REC  = "<II"
 398 D3REC  = "<III"
 399 D4REC  = "<IIII"
 400 D5REC  = "<IIIII"
 401 KMAGIC  = "<I"
 402
 403 last_ts = 0
 404
 405 i=0
 406
 407 while not interrupted:
 408     try:
 409         i=i+1
 410
 411         if i == 1:
 412             line = sys.stdin.read(struct.calcsize(KMAGIC))
 413             if not line:
 414                 break
 415             kmgc = struct.unpack(KMAGIC, line)[0]
 416
 417             #firstly try to parse data file as little endian
 418             # if "kvmtrace-metadata".kmagic != kmagic
 419             # then data file must be big endian"
 420             if kmgc != 0x12345678:
 421                 if kmgc != 0x78563412:
 422                     print >> sys.stderr, "Bad data file: magic number error."
 423                     break;
 424                 else:
 425                     HDRREC = ">III"
 426                     TSCREC = ">Q"
 427                     D1REC  = ">I"
 428                     D2REC  = ">II"
 429                     D3REC  = ">III"
 430                     D4REC  = ">IIII"
 431                     D5REC  = ">IIIII"
 432             continue
 433
 434         line = sys.stdin.read(struct.calcsize(HDRREC))
 435         if not line:
 436             break
 437         (event, pid, vcpu_id) = struct.unpack(HDRREC, line)
 438
 439         n_data = event >> 28 & 0x7
 440         ts_in = event >> 31
 441
 442         d1 = 0
 443         d2 = 0
 444         d3 = 0
 445         d4 = 0
 446         d5 = 0
 447
 448         ts = 0
 449
 450         if ts_in == 1:
 451             line = sys.stdin.read(struct.calcsize(TSCREC))
 452             if not line:
 453                 break
 454             ts = struct.unpack(TSCREC, line)[0]
 455         if n_data == 1:
 456             line = sys.stdin.read(struct.calcsize(D1REC))
 457             if not line:
 458                 break
 459             d1 = struct.unpack(D1REC, line)[0]
 460         if n_data == 2:
 461             line = sys.stdin.read(struct.calcsize(D2REC))
 462             if not line:
 463                 break
 464             (d1, d2) = struct.unpack(D2REC, line)
 465         if n_data == 3:
 466             line = sys.stdin.read(struct.calcsize(D3REC))
 467             if not line:
 468                 break
 469             (d1, d2, d3) = struct.unpack(D3REC, line)
 470         if n_data == 4:
 471             line = sys.stdin.read(struct.calcsize(D4REC))
 472             if not line:
 473                 break
 474             (d1, d2, d3, d4) = struct.unpack(D4REC, line)
 475         if n_data == 5:
 476             line = sys.stdin.read(struct.calcsize(D5REC))
 477             if not line:
 478                 break
 479             (d1, d2, d3, d4, d5) = struct.unpack(D5REC, line)
 480
 481         event &= 0x0fffffff
 482
 483         # provide relative TSC
 484
 485         if last_ts > 0 and ts_in == 1:
 486             relts = ts - last_ts
 487         else:
 488             relts = 0
 489
 490         if ts_in == 1:
 491             last_ts = ts
 492
 493         args = {'ts'   : ts,
 494                 'event' : event,
 495                 'relts': relts,
 496                 'pid'   : pid,
 497                 'vcpu'  : vcpu_id,
 498                 '1'     : d1,
 499                 '2'     : d2,
 500                 '3'     : d3,
 501                 '4'     : d4,
 502                 '5'     : d5    }
 503
 504         # some event types need more than just formats mapping they are if/elif
 505         # chained here and the last default else is the mapping via formats
 506         if event == 0x00020019:
 507             pdata = (ts, relts, vcpu_id, pid, d1, d2, d3, get_name(d1), get_special(d1))
 508             print "%d (+%12d)  PPC_INSTR vcpu = 0x%08x  pid = 0x%08x [ instr = 0x%08x, pc = 0x%08x, emul = %01d, mnemonic = %8s %s" % pdata
 509         else:
 510             try:
 511                 if defs.has_key(str(event)):
 512                     print defs[str(event)] % args
 513                 else:
 514                     if defs.has_key(str(0)): print defs[str(0)] % args
 515             except TypeError:
 516                 if defs.has_key(str(event)):
 517                     print defs[str(event)]
 518                     print args
 519                 else:
 520                     if defs.has_key(str(0)):
 521                         print defs[str(0)]
 522                         print args
 523
 524     except IOError, struct.error: sys.exit()
 525
 526 if summary:
 527         ppc_instr_summary()