office-gobmx/solenv/bin/finish-gbuild-trace.py
Luboš Luňák 0adc9b615f GBUILD_TRACE, support for finding out where the build time is spent
See instructions in solenv/gbuild/Trace.mk . This generates a file than
can be viewed e.g. in the Chromium tracing view.

Change-Id: I5f90647c58ca729375525b6daed2d4918adc8188
Reviewed-on: https://gerrit.libreoffice.org/c/core/+/88754
Tested-by: Jenkins
Reviewed-by: Luboš Luňák <l.lunak@collabora.com>
2020-02-16 14:49:45 +01:00

137 lines
5.7 KiB
Python
Executable file

#!/usr/bin/env python3
# Process file generated by using GBUILD_TRACE=file with make.
# The file needs adjusting for viewing in Chromium's "chrome://tracing' URL.
# See solenv/gbuild/Trace.mk for details.
import os
import re
import sys
if len(sys.argv) != 2:
print ("Usage: " + sys.argv[0] + " [trace.json]", file=sys.stderr)
sys.exit(1)
filename=sys.argv[1]
with open(filename) as infile:
lines = [ line.rstrip('\n') for line in infile ]
if len(lines) == 0 :
print( "Empty file?", file=sys.stderr)
sys.exit(1)
if lines[0] == '{"traceEvents": [':
print( "File already processed", file=sys.stderr)
sys.exit(3)
# sort items by time (parallel writes may not write them in time order)
def linekey(line):
match = re.match( r'^.*, "ts": ([0-9]*)[0-9][0-9][0-9],.*$', line )
assert match, "Unknown line: " + line
return int(match.group(1))
lines.sort( key=linekey )
# 'chrome://tracing' shows several rows, we use those to show build parallelism,
# but we need to assign the proper ids by allocating them as slots.
slots = []
# start time of each slot
slot_start_time = []
def make_slot_string(type, detail):
return type + '#' + detail
def allocate_slot(type, detail):
for index in range(len(slots)):
if slots[index] == "":
slots[index] = make_slot_string(type, detail)
return index + 1
index = len(slots)
slots.append(make_slot_string(type, detail))
slot_start_time.append(0)
return index + 1
def free_slot(type, detail):
for index in range(len(slots)):
if slots[index] == make_slot_string(type, detail):
slots[index] = ""
return index + 1
assert False, "free_slot(" + type + "," + detail + ") not found"
# key: Type (e.g. CXX), value: time total
totals_time = {}
totals_count = {}
# time of the first item, to rebase all times to 0
start_time = 0
with open(filename + ".tmp", "w") as outfile:
print( '{"traceEvents": [', file=outfile)
for iline in range(len(lines)):
line = lines[iline]
# "ts" needs converting nanoseconds -> milliseconds
match = re.match( r'^{"name": "([^"]*)", "ph": "(.)",.*"ts": ([0-9]*)[0-9][0-9][0-9],"args":{"message":"([^"]*)"}.*$', line )
if not match:
print( "Unknown line: " + line, file=sys.stderr)
sys.exit(2)
if start_time == 0:
start_time = int(match.group(3))
# "tid" needs replacing with proper slot
tid = "0"
# "ph"
if match.group(2) == 'B':
tid = allocate_slot(match.group(1), match.group(4)) # "name", "args"
slot_start_time[tid-1] = int(match.group(3))
elif match.group(2) == 'E':
tid = free_slot(match.group(1), match.group(4)) # "name", "args"
if not match.group(1) in totals_time:
totals_time[match.group(1)] = 0
totals_count[match.group(1)] = 0
totals_time[match.group(1)] += int(match.group(3)) - slot_start_time[tid-1]
totals_count[match.group(1)] += 1
line = re.sub( r'"ts": [0-9]+,', '"ts": ' + str(int(match.group(3)) - start_time) + ",", line)
line = re.sub( r'"tid": 1,', '"tid": ' + str(tid) + ",", line)
if match.group(2) == 'i':
rline = line
# mark as affecting all slots
line = re.sub( r'}},$', '}, "s": "p"},', line)
print(line, file=outfile)
# Chromium search doesn't find 'i' items, add extra 'R' for that
rline = re.sub( r', "ph": "i",', ', "ph": "R",', rline)
rline = re.sub( r', "tid": [0-9]+,', ',', rline)
print(rline, file=outfile)
else:
print(line, file=outfile)
# TODO: By the first time "[DEP]: LNK:Executable/makedepend.exe" is invoked the build tools
# are not built yet, so the invocation fails, doesn't abort the build for some reason,
# but the matching line about it ending is missing. So add the missing end line if it is
# by another start line for it instead of an end line.
if match.group(1) == "DEP" and match.group(4) == "[DEP]: LNK:Executable/makedepend.exe" and match.group(2) == "B":
for iline2 in range(iline+1,len(lines)): # search following lines
line2 = lines[iline2]
match2 = re.match( r'^{"name": "([^"]*)", "ph": "(.)",.*"ts": ([0-9]*)[0-9][0-9][0-9],"args":{"message":"([^"]*)"}.*$', line2 )
if match2.group(1) == "DEP" and match2.group(4) == "[DEP]: LNK:Executable/makedepend.exe":
if match2.group(2) == "E":
break # it has a matching close
if match2.group(2) == "B":
print(re.sub( r', "ph": "B",', ', "ph": "E",', line), file=outfile) # close the starting line
free_slot(match.group(1), match.group(4))
break
total_num = 0
for total in sorted(totals_time, key=totals_time.get, reverse=True):
note = ""
if total == "EXTERNAL":
note = ',"note": "minimum (cannot detect parallelism)"'
print( '{"pid":2,"tid":' + str(total_num) + ',"ts":0,"dur":' + str(totals_time[total]) + ',"ph":"X","name":"' + total
+ '","args":{"count":"' + str(totals_count[total]) + '"' + note + '}},', file=outfile)
total_num += 1
print( '{"pid":1,"tid":0,"ts":0,"ph":"M","name":"process_name","args":{"name":"gbuild"}},', file=outfile)
print( '{"pid":2,"tid":0,"ts":0,"ph":"M","name":"process_name","args":{"name":"totals"}}]}', file=outfile)
for index in range(len(slots)):
if slots[index] != "":
print( "Unclosed range: " + slots[index], file=sys.stderr)
os.rename(filename + ".tmp", filename)