solenv/bin/finish-gbuild-trace.py

   1 #!/usr/bin/env python3
   2
   3 # Process file generated by using GBUILD_TRACE=file with make.
   4 # The file needs adjusting for viewing in Chromium's "chrome://tracing' URL.
   5 # See solenv/gbuild/Trace.mk for details.
   6
   7 import os
   8 import re
   9 import sys
  10
  11 if len(sys.argv) != 2:
  12     print ("Usage: " + sys.argv[0] + " [trace.json]", file=sys.stderr)
  13     sys.exit(1)
  14
  15 filename=sys.argv[1]
  16
  17 with open(filename) as infile:
  18     lines = [ line.rstrip('\n') for line in infile ]
  19
  20 if len(lines) == 0 :
  21     print( "Empty file?", file=sys.stderr)
  22     sys.exit(1)
  23
  24 if lines[0] == '{"traceEvents": [':
  25     print( "File already processed", file=sys.stderr)
  26     sys.exit(3)
  27
  28 # sort items by time (parallel writes may not write them in time order)
  29 def linekey(line):
  30     match = re.match( r'^.*, "ts": ([0-9]*)[0-9][0-9][0-9],.*$', line )
  31     assert match, "Unknown line: " + line
  32     return int(match.group(1))
  33 lines.sort( key=linekey )
  34
  35 # 'chrome://tracing' shows several rows, we use those to show build parallelism,
  36 # but we need to assign the proper ids by allocating them as slots.
  37 slots = []
  38 # start time of each slot
  39 slot_start_time = []
  40
  41 def make_slot_string(type, detail):
  42     return type + '#' + detail
  43
  44 def allocate_slot(type, detail):
  45     for index in range(len(slots)):
  46         if slots[index] == "":
  47             slots[index] = make_slot_string(type, detail)
  48             return index + 1
  49     index = len(slots)
  50     slots.append(make_slot_string(type, detail))
  51     slot_start_time.append(0)
  52     return index + 1
  53
  54 def free_slot(type, detail):
  55     for index in range(len(slots)):
  56         if slots[index] == make_slot_string(type, detail):
  57             slots[index] = ""
  58             return index + 1
  59     assert False, "free_slot(" + type + "," + detail + ") not found"
  60
  61 # key: Type (e.g. CXX), value: time total
  62 totals_time = {}
  63 totals_count = {}
  64
  65 # time of the first item, to rebase all times to 0
  66 start_time = 0
  67
  68 with open(filename + ".tmp", "w") as outfile:
  69     print( '{"traceEvents": [', file=outfile)
  70     for iline in range(len(lines)):
  71         line = lines[iline]
  72         # "ts" needs converting nanoseconds -> milliseconds
  73         match = re.match( r'^{"name": "([^"]*)", "ph": "(.)",.*"ts": ([0-9]*)[0-9][0-9][0-9],"args":{"message":"([^"]*)"}.*$', line )
  74         if not match:
  75             print( "Unknown line: " + line, file=sys.stderr)
  76             sys.exit(2)
  77         if start_time == 0:
  78             start_time = int(match.group(3))
  79         # "tid" needs replacing with proper slot
  80         tid = "0"
  81         # "ph"
  82         if match.group(2) == 'B':
  83             tid = allocate_slot(match.group(1), match.group(4)) # "name", "args"
  84             slot_start_time[tid-1] = int(match.group(3))
  85         elif match.group(2) == 'E':
  86             tid = free_slot(match.group(1), match.group(4)) # "name", "args"
  87             if not match.group(1) in totals_time:
  88                 totals_time[match.group(1)] = 0
  89                 totals_count[match.group(1)] = 0
  90             totals_time[match.group(1)] += int(match.group(3)) - slot_start_time[tid-1]
  91             totals_count[match.group(1)] += 1
  92         line = re.sub( r'"ts": [0-9]+,', '"ts": ' + str(int(match.group(3)) - start_time) + ",", line)
  93         line = re.sub( r'"tid": 1,', '"tid": ' + str(tid) + ",", line)
  94         if match.group(2) == 'i':
  95             rline = line
  96             # mark as affecting all slots
  97             line = re.sub( r'}},$', '}, "s": "p"},', line)
  98             print(line, file=outfile)
  99             # Chromium search doesn't find 'i' items, add extra 'R' for that
 100             rline = re.sub( r', "ph": "i",', ', "ph": "R",', rline)
 101             rline = re.sub( r', "tid": [0-9]+,', ',', rline)
 102             print(rline, file=outfile)
 103         else:
 104             print(line, file=outfile)
 105         # TODO: By the first time "[DEP]: LNK:Executable/makedepend.exe" is invoked the build tools
 106         # are not built yet, so the invocation fails, doesn't abort the build for some reason,
 107         # but the matching line about it ending is missing. So add the missing end line if it is
 108         # by another start line for it instead of an end line.
 109         if match.group(1) == "DEP" and match.group(4) == "[DEP]: LNK:Executable/makedepend.exe" and match.group(2) == "B":
 110             for iline2 in range(iline+1,len(lines)): # search following lines
 111                 line2 = lines[iline2]
 112                 match2 = re.match( r'^{"name": "([^"]*)", "ph": "(.)",.*"ts": ([0-9]*)[0-9][0-9][0-9],"args":{"message":"([^"]*)"}.*$', line2 )
 113                 if match2.group(1) == "DEP" and match2.group(4) == "[DEP]: LNK:Executable/makedepend.exe":
 114                     if match2.group(2) == "E":
 115                         break # it has a matching close
 116                     if match2.group(2) == "B":
 117                         print(re.sub( r', "ph": "B",', ', "ph": "E",', line), file=outfile) # close the starting line
 118                         free_slot(match.group(1), match.group(4))
 119                         break
 120
 121     total_num = 0
 122     for total in sorted(totals_time, key=totals_time.get, reverse=True):
 123         note = ""
 124         if total == "EXTERNAL":
 125             note = ',"note": "minimum (cannot detect parallelism)"'
 126         print( '{"pid":2,"tid":' + str(total_num) + ',"ts":0,"dur":' + str(totals_time[total]) + ',"ph":"X","name":"' + total
 127             + '","args":{"count":"' + str(totals_count[total]) + '"' + note + '}},', file=outfile)
 128         total_num += 1
 129
 130     print( '{"pid":1,"tid":0,"ts":0,"ph":"M","name":"process_name","args":{"name":"gbuild"}},', file=outfile)
 131     print( '{"pid":2,"tid":0,"ts":0,"ph":"M","name":"process_name","args":{"name":"totals"}}]}', file=outfile)
 132
 133 for index in range(len(slots)):
 134     if slots[index] != "":
 135         print( "Unclosed range: " + slots[index], file=sys.stderr)
 136
 137 os.rename(filename + ".tmp", filename)