Mesa (master): freedreno: Add trace-parser.py
GitLab Mirror
gitlab-mirror at kemper.freedesktop.org
Thu Dec 3 21:40:22 UTC 2020
Module: Mesa
Branch: master
Commit: d5bc39c9d0e2a22d9cf968023fb39b296ffdcf5d
URL: http://cgit.freedesktop.org/mesa/mesa/commit/?id=d5bc39c9d0e2a22d9cf968023fb39b296ffdcf5d
Author: Rob Clark <robdclark at chromium.org>
Date: Mon Nov 30 11:15:12 2020 -0800
freedreno: Add trace-parser.py
Similar to log-parser.py, but uses u_trace tracepoint log.
Signed-off-by: Rob Clark <robdclark at chromium.org>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/7818>
---
src/gallium/drivers/freedreno/trace-parser.py | 308 ++++++++++++++++++++++++++
1 file changed, 308 insertions(+)
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()
+
More information about the mesa-commit
mailing list