From 7aa55f5acbcf7fa472805fd2c155a5cc0b9cb2a8 Mon Sep 17 00:00:00 2001 From: Rob Clark Date: Tue, 7 Apr 2020 14:54:33 -0700 Subject: [PATCH] freedreno/log: spiff out parser some more Extract breakdown of time in GMEM passes. Signed-off-by: Rob Clark Part-of: --- src/gallium/drivers/freedreno/log-parser.py | 126 +++++++++++++++++++- 1 file changed, 122 insertions(+), 4 deletions(-) diff --git a/src/gallium/drivers/freedreno/log-parser.py b/src/gallium/drivers/freedreno/log-parser.py index 8d409e15742..a69a55b5ef2 100755 --- a/src/gallium/drivers/freedreno/log-parser.py +++ b/src/gallium/drivers/freedreno/log-parser.py @@ -3,12 +3,74 @@ import re import sys + +class GMEMPass: + def __init__(self): + self.cleared = None + self.gmem_reason = None + self.num_draws = None + self.samples = None + + self.width = None + self.height = None + self.nbinx = None + self.nbiny = None + + self.formats = [] # format per MRT + zsbuf + self.lrz_clear_time = 0 + self.binning_time = 0 + self.restore_clear_time = 0 + self.draw_time = 0 + self.resolve_time = 0 + self.elapsed_time = 0 + +def dump_gmem_passes(gmem_passes, blit_time, sysmem_time, total_time): + i = 0 + lrz_clear_time = 0 + binning_time = 0 + restore_clear_time = 0 + draw_time = 0 + resolve_time = 0 + elapsed_time = 0 + for gmem in gmem_passes: + print(" GMEM[{}]: {}x{} ({}x{} tiles), {} draws, lrz clear: {:,} ns, binning: {:,} ns, restore/clear: {:,} ns, draw: {:,} ns, resolve: {:,} ns, total: {:,} ns, rt/zs: {}".format( + i, gmem.width, gmem.height, gmem.nbinx, gmem.nbiny, gmem.num_draws, + gmem.lrz_clear_time, gmem.binning_time, gmem.restore_clear_time, + gmem.draw_time, gmem.resolve_time, gmem.elapsed_time, + ", ".join(gmem.formats) + )) + lrz_clear_time += gmem.lrz_clear_time + binning_time += gmem.binning_time + restore_clear_time += gmem.restore_clear_time + draw_time += gmem.draw_time + resolve_time += gmem.resolve_time + elapsed_time += gmem.elapsed_time + i += 1 + + print(" TOTAL: lrz clear: {:,} ns ({}%), binning: {:,} ns ({}%), restore/clear: {:,} ns ({}%), draw: {:,} ns ({}%), resolve: {:,} ns ({}%), blit: {:,} ns ({}%), sysmem: {:,} ns ({}%), total: {:,} ns\n".format( + lrz_clear_time, 100.0 * lrz_clear_time / total_time, + binning_time, 100.0 * binning_time / total_time, + restore_clear_time, 100.0 * restore_clear_time / total_time, + draw_time, 100.0 * draw_time / total_time, + resolve_time, 100.0 * resolve_time / total_time, + blit_time, 100.0 * blit_time / total_time, + sysmem_time, 100.0 * sysmem_time / total_time, + total_time + )) + def main(): file = open(sys.argv[1], "r") lines = file.read().split('\n') compute_match = re.compile(r"COMPUTE: START") - gmem_match = re.compile(r": rendering (\S+)x(\S+) tiles") + gmem_start_match = re.compile(r": GMEM: cleared=(\S+), gmem_reason=(\S+), num_draws=(\S+), samples=(\S+)") + gmem_match = re.compile(r": rendering (\S+)x(\S+) tiles (\S+)x(\S+)") + gmem_surf_match = re.compile(r": {format = (\S+),") + gmem_lrz_clear_match = re.compile(r"\+(\S+): END LRZ CLEAR") + gmem_binning_match = re.compile(r"\+(\S+): GMEM: END BINNING IB") + gmem_restore_clear_match = re.compile(r"\+(\S+): TILE: END CLEAR/RESTORE") + gmem_draw_match = re.compile(r"\+(\S+): TILE\[\S+\]: END DRAW IB") + gmem_resolve_match = re.compile(r"\+(\S+): TILE: END RESOLVE") sysmem_match = re.compile(r": rendering sysmem (\S+)x(\S+)") blit_match = re.compile(r": END BLIT") elapsed_match = re.compile(r"ELAPSED: (\S+) ns") @@ -20,6 +82,8 @@ def main(): times_gmem = [] times_compute = [] times = None + gmem_passes = [] # set of GMEM passes in frame + gmem = None # current GMEM pass for line in lines: match = re.search(compute_match, line) @@ -30,13 +94,58 @@ def main(): times = times_compute continue - match = re.search(gmem_match, line) + match = re.search(gmem_start_match, line) if match is not None: - #print("GMEM") + if gmem is not None: + print("expected gmem to not be set yet") if times is not None: print("expected times to not be set yet") times = times_gmem - continue + gmem = GMEMPass() + gmem.cleared = match.group(1) + gmem.gmem_reason = match.group(2) + gmem.num_draws = match.group(3) + gmem.samples = match.group(4) + + if gmem is not None: + match = re.search(gmem_match, line) + if match is not None: + gmem.width = int(match.group(1)) + gmem.height = int(match.group(2)) + gmem.nbinx = int(match.group(3)) + gmem.nbiny = int(match.group(4)) + continue + + match = re.search(gmem_surf_match, line) + if match is not None: + gmem.formats.append(match.group(1)) + continue + + match = re.search(gmem_lrz_clear_match, line) + if match is not None: + gmem.lrz_clear_time += int(match.group(1)) + continue + + match = re.search(gmem_binning_match, line) + if match is not None: + gmem.binning_time += int(match.group(1)) + continue + + match = re.search(gmem_restore_clear_match, line) + if match is not None: + gmem.restore_clear_time += int(match.group(1)) + continue + + match = re.search(gmem_draw_match, line) + if match is not None: + gmem.draw_time += int(match.group(1)) + continue + + match = re.search(gmem_resolve_match, line) + if match is not None: + gmem.resolve_time += int(match.group(1)) + continue + match = re.search(sysmem_match, line) if match is not None: @@ -64,10 +173,15 @@ def main(): len(times_gmem), sum(times_gmem), len(times_compute), sum(times_compute) )) + if len(gmem_passes) > 0: + total_time = sum(times_blit) + sum(times_sysmem) + sum(times_gmem) + sum(times_compute) + dump_gmem_passes(gmem_passes, sum(times_blit), sum(times_sysmem), total_time) times_blit = [] times_sysmem = [] times_gmem = [] times = None + gmem_passes = [] + gmem = None continue match = re.search(elapsed_match, line) @@ -76,6 +190,10 @@ def main(): #print("ELAPSED: " + str(time) + " ns") times.append(time) times = None + if gmem is not None: + gmem.elapsed_time = time + gmem_passes.append(gmem) + gmem = None continue -- 2.30.2