diff options
author | Rob Clark <robdclark@chromium.org> | 2020-11-30 11:15:12 -0800 |
---|---|---|
committer | Marge Bot <eric+marge@anholt.net> | 2020-12-03 21:19:58 +0000 |
commit | d5bc39c9d0e2a22d9cf968023fb39b296ffdcf5d (patch) | |
tree | 32f7313359da38ce94eefca28ac74eeefd5d8040 | |
parent | a02dcb970fff17e73648b58bf4a603bc4f9c0c36 (diff) |
freedreno: Add trace-parser.py
Similar to log-parser.py, but uses u_trace tracepoint log.
Signed-off-by: Rob Clark <robdclark@chromium.org>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/7818>
-rwxr-xr-x | src/gallium/drivers/freedreno/trace-parser.py | 308 |
1 files changed, 308 insertions, 0 deletions
diff --git a/src/gallium/drivers/freedreno/trace-parser.py b/src/gallium/drivers/freedreno/trace-parser.py new file mode 100755 index 00000000000..8966588a300 --- /dev/null +++ b/src/gallium/drivers/freedreno/trace-parser.py @@ -0,0 +1,308 @@ +#!/usr/bin/env python3 + +import re +import sys +import gzip +import io + +# Captures per-frame state, including all the renderpasses, and +# time spent in blits and compute jobs: +class Frame: + def __init__(self): + self.frame_nr = None + self.renderpasses = [] + # Times in ns: + self.times_sysmem = [] + self.times_gmem = [] + self.times_compute = [] + self.times_blit = [] + + def print(self): + print("FRAME[{}]: {} blits ({:,} ns), {} SYSMEM ({:,} ns), {} GMEM ({:,} ns), {} COMPUTE ({:,} ns)".format( + self.frame_nr, + len(self.times_blit), sum(self.times_blit), + len(self.times_sysmem), sum(self.times_sysmem), + len(self.times_gmem), sum(self.times_gmem), + len(self.times_compute), sum(self.times_compute) + )) + + i = 0 + prologue_time = 0 + binning_time = 0 + restore_clear_time = 0 + draw_time = 0 + resolve_time = 0 + elapsed_time = 0 + total_time = sum(self.times_blit) + sum(self.times_sysmem) + sum(self.times_gmem) + sum(self.times_compute) + + for renderpass in self.renderpasses: + renderpass.print(i) + prologue_time += renderpass.prologue_time + binning_time += renderpass.binning_time + restore_clear_time += renderpass.restore_clear_time + draw_time += renderpass.draw_time + resolve_time += renderpass.resolve_time + elapsed_time += renderpass.elapsed_time + i += 1 + + print(" TOTAL: prologue: {:,} ns ({}%), binning: {:,} ns ({}%), restore/clear: {:,} ns ({}%), draw: {:,} ns ({}%), resolve: {:,} ns ({}%), blit: {:,} ns ({}%), compute: {:,} ns ({}%), GMEM: {:,} ns ({}%), sysmem: {:,} ns ({}%), total: {:,} ns\n".format( + prologue_time, 100.0 * prologue_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, + sum(self.times_blit), 100.0 * sum(self.times_blit) / total_time, + sum(self.times_compute), 100.0 * sum(self.times_compute) / total_time, + sum(self.times_gmem), 100.0 * sum(self.times_gmem) / total_time, + sum(self.times_sysmem), 100.0 * sum(self.times_sysmem) / total_time, + total_time + )) + +class FramebufferState: + def __init__(self, width, height, layers, samples, nr_cbufs): + self.width = width + self.height = height + self.layers = layers + self.samples = samples + self.nr_cbufs = nr_cbufs + self.surfaces = [] # per MRT + zsbuf + + def get_formats(self): + formats = [] + for surface in self.surfaces: + formats.append(surface.format) + return formats + +class SurfaceState: + def __init__(self, width, height, samples, format): + self.width = width + self.height = height + self.samples = samples + self.format = format + +class BinningState: + def __init__(self, nbins_x, nbins_y, bin_w, bin_h): + self.nbins_x = nbins_x + self.nbins_y = nbins_y + self.bin_w = bin_w + self.bin_h = bin_h + +# Captures per-renderpass state, which can be either a binning or +# sysmem pass. Blits and compute jobs are not tracked separately +# but have their time their times accounted for in the Frame state +class RenderPass: + def __init__(self, cleared, gmem_reason, num_draws): + self.cleared = cleared + self.gmem_reason = gmem_reason + self.num_draws = num_draws + + # The rest of the parameters aren't known until we see a later trace: + self.binning_state = None # None for sysmem passes, else BinningState + self.fb = None + self.fast_cleared = None + + self.elapsed_time = 0 + self.state_restore_time = 0 + self.prologue_time = 0 + self.draw_time = 0 + self.restore_clear_time = 0 + + # Specific to GMEM passes: + self.binning_time = 0 + self.vsc_overflow_test_time = 0 + self.resolve_time = 0 + + def print_gmem_pass(self, nr): + print(" GMEM[{}]: {}x{} ({}x{} tiles), {} draws, prologue: {:,} ns, binning: {:,} ns, restore/clear: {:,} ns, draw: {:,} ns, resolve: {:,} ns, total: {:,} ns, rt/zs: {}".format( + nr, self.fb.width, self.fb.height, + self.binning_state.nbins_x, self.binning_state.nbins_y, + self.num_draws, self.prologue_time, self.binning_time, + self.restore_clear_time, self.draw_time, self.resolve_time, + self.elapsed_time, + ", ".join(self.fb.get_formats()) + )) + + def print_sysmem_pass(self, nr): + print(" SYSMEM[{}]: {}x{}, {} draws, prologue: {:,} ns, clear: {:,} ns, draw: {:,} ns, total: {:,} ns, rt/zs: {}".format( + nr, self.fb.width, self.fb.height, + self.num_draws, self.prologue_time, + self.restore_clear_time, self.draw_time, + self.elapsed_time, + ", ".join(self.fb.get_formats()) + )) + + def print(self, nr): + if self.binning_state: + self.print_gmem_pass(nr) + else: + self.print_sysmem_pass(nr) + +def main(): + filename = sys.argv[1] + if filename.endswith(".gz"): + file = gzip.open(filename, "r") + file = io.TextIOWrapper(file) + else: + file = open(filename, "r") + lines = file.read().split('\n') + + flush_batch_match = re.compile(r": flush_batch: (\S+): cleared=(\S+), gmem_reason=(\S+), num_draws=(\S+)") + framebuffer_match = re.compile(r": framebuffer: (\S+)x(\S+)x(\S+)@(\S+), nr_cbufs: (\S+)") + surface_match = re.compile(r": surface: (\S+)x(\S+)@(\S+), fmt=(\S+)") + + # draw/renderpass passes: + gmem_match = re.compile(r": render_gmem: (\S+)x(\S+) bins of (\S+)x(\S+)") + sysmem_match = re.compile(r": render_sysmem") + state_restore_match = re.compile(r"\+(\S+): end_state_restore") + prologue_match = re.compile(r"\+(\S+): end_prologue") + binning_ib_match = re.compile(r"\+(\S+): end_binning_ib") + vsc_overflow_match = re.compile(r"\+(\S+): end_vsc_overflow_test") + draw_ib_match = re.compile(r"\+(\S+): end_draw_ib") + resolve_match = re.compile(r"\+(\S+): end_resolve") + + start_clear_restore_match = re.compile(r"start_clear_restore: fast_cleared: (\S+)") + end_clear_restore_match = re.compile(r"\+(\S+): end_clear_restore") + + # Non-draw passes: + compute_match = re.compile(r": start_compute") + blit_match = re.compile(r": start_blit") + + # End of pass/frame markers: + elapsed_match = re.compile(r"ELAPSED: (\S+) ns") + eof_match = re.compile(r"END OF FRAME (\S+)") + + frame = Frame() # current frame state + renderpass = None # current renderpass state + times = None + + # Helper to set the appropriate times table for the current pass, + # which is expected to only happen once for a given render pass + def set_times(t): + nonlocal times + if times is not None: + print("expected times to not be set yet") + times = t + + for line in lines: + # Note, we only expect the flush_batch trace for !nondraw: + match = re.search(flush_batch_match, line) + if match is not None: + assert(renderpass is None) + renderpass = RenderPass(cleared=match.group(2), + gmem_reason=match.group(3), + num_draws=match.group(4)) + frame.renderpasses.append(renderpass) + continue + + match = re.search(framebuffer_match, line) + if match is not None: + assert(renderpass.fb is None) + renderpass.fb = FramebufferState(width=match.group(1), + height=match.group(2), + layers=match.group(3), + samples=match.group(4), + nr_cbufs=match.group(5)) + continue + + match = re.search(surface_match, line) + if match is not None: + surface = SurfaceState(width=match.group(1), + height=match.group(2), + samples=match.group(3), + format=match.group(4)) + renderpass.fb.surfaces.append(surface) + continue + + match = re.search(gmem_match, line) + if match is not None: + assert(renderpass.binning_state is None) + renderpass.binning_state = BinningState(nbins_x=match.group(1), + nbins_y=match.group(2), + bin_w=match.group(3), + bin_h=match.group(4)) + set_times(frame.times_gmem) + continue + + match = re.search(sysmem_match, line) + if match is not None: + assert(renderpass.binning_state is None) + set_times(frame.times_sysmem) + continue + + match = re.search(state_restore_match, line) + if match is not None: + renderpass.state_restore_time += int(match.group(1)) + continue + + match = re.search(prologue_match, line) + if match is not None: + renderpass.prologue_time += int(match.group(1)) + continue + + match = re.search(binning_ib_match, line) + if match is not None: + assert(renderpass.binning_state is not None) + renderpass.binning_time += int(match.group(1)) + continue + + match = re.search(vsc_overflow_match, line) + if match is not None: + assert(renderpass.binning_state is not None) + renderpass.vsc_overflow_test_time += int(match.group(1)) + continue + + match = re.search(draw_ib_match, line) + if match is not None: + renderpass.draw_time += int(match.group(1)) + continue + + match = re.search(resolve_match, line) + if match is not None: + assert(renderpass.binning_state is not None) + renderpass.resolve_time += int(match.group(1)) + continue + + match = re.search(start_clear_restore_match, line) + if match is not None: + renderpass.fast_cleared = match.group(1) + continue + + match = re.search(end_clear_restore_match, line) + if match is not None: + renderpass.restore_clear_time += int(match.group(1)) + continue + + match = re.search(compute_match, line) + if match is not None: + set_times(frame.times_compute) + continue + + match = re.search(blit_match, line) + if match is not None: + set_times(frame.times_blit) + continue + + match = re.search(eof_match, line) + if match is not None: + frame.frame_nr = int(match.group(1)) + frame.print() + frame = Frame() + times = None + renderpass = None + continue + + match = re.search(elapsed_match, line) + if match is not None: + time = int(match.group(1)) + #print("ELAPSED: " + str(time) + " ns") + if renderpass is not None: + renderpass.elapsed_time = time + times.append(time) + times = None + renderpass = None + continue + + +if __name__ == "__main__": + main() + |