#!/usr/bin/env python3 """Reduce an async-profiler collapsed file to the question we keep asking. The client JVM is sampled on wall clock, which records every thread including the parked ones, so a raw read of the file is mostly threads doing nothing. The only thread that costs a player anything is the EDT: while it is busy or blocked, no frame ships. So this splits the EDT out, separates the part of it that was waiting for an event from the part that was running, and then reports where the running part went. The buckets are the two arguments the repo keeps having with itself, both from TODO.md: how much of a repaint is MegaMek deciding what to draw, and how much is Suramadu turning it into PNG bytes on the way out. ./tests/profile-summary.py .arena-artifacts/arena-dev/profile-client.collapsed ./tests/profile-summary.py --top 20 profile-client.collapsed Not part of ./test.sh: it reads an artefact a profiled match produced, and there is nothing to gate. """ import argparse import sys from collections import Counter # Substring -> what it means. Ordered: a stack is counted in every bucket it # matches, because they nest - an encode happens inside a paint. BUCKETS = ( ("paint", ("BoardView", "paintComponent", "RepaintManager")), # Everything that turns pixels into PNG bytes, including zlib's own # internals. Naming only the entry points undercounted this by nearly 3x: # the encoders hand off to deflate and the samples land in longest_match # and compress_block, which named neither ZPNG nor PNG. ( "png+deflate", ( "ZPNG", "libzpng", "EncoderBase", "PNGImageWriter", "ImageIO", "deflate", "longest_match", "compress_block", "slide_hash", ), ), # A subset of the above, called out because it is not frame traffic at all: # MegaMek's GameSummaryBoardView preference writes a board PNG through # ImageIO on every phase change, on the EDT. Nobody has ever looked at one. (" of which game-summary images", ("ImageIO", "PNGImageWriter")), ("directdraw", ("ImageConst", "DrawConstantPool", "DrawInstructionFactory")), ("hash", ("xxhash", "Coords.hashCode")), ("gc/alloc", ("GCTaskThread", "G1", "CollectedHeap")), ) # A stack containing one of these was parked waiting for something to do # rather than doing it. getNextEvent is the EDT's own idle; the rest matter # once --thread is widened, because wall-clock sampling records every pooled # worker sitting in its queue and they would otherwise read as work. IDLE = ( "getNextEvent", "Object.wait", "park", "ThreadPoolExecutor.getTask", "PosixSemaphore::wait", ) def parse(path): """Yield (frames, samples) for each line of a collapsed file.""" with open(path, encoding="utf-8", errors="replace") as fh: for line in fh: line = line.rstrip("\n") if not line: continue stack, _, count = line.rpartition(" ") try: n = int(count) except ValueError: continue yield stack, n def main(argv=None): ap = argparse.ArgumentParser(description=__doc__.split("\n", maxsplit=1)[0]) ap.add_argument("profile", help="a .collapsed file") ap.add_argument( "--thread", default="EventDispatchThread.run", help="frame identifying the thread of interest " "(default: the EDT; use '' for every thread)", ) ap.add_argument("--top", type=int, default=12, help="how many leaf frames to list") args = ap.parse_args(argv) total = idle = working = 0 buckets = Counter() leaves = Counter() for stack, n in parse(args.profile): total += n if args.thread and args.thread not in stack: continue if any(marker in stack for marker in IDLE): idle += n continue working += n leaves[stack.rpartition(";")[2]] += n for name, markers in BUCKETS: if any(m in stack for m in markers): buckets[name] += n if not total: print(f"{args.profile}: no samples", file=sys.stderr) return 1 who = args.thread or "all threads" print(f"{args.profile}") print(f" {total:>10,} samples in the file") print( f" {idle + working:>10,} on {who} ({pct(idle + working, total)} of the file)" ) print(f" {idle:>10,} waiting for something to do") print(f" {working:>10,} running{sub(working, idle + working)}") if not working: print("\n nothing was running - a longer or busier match is needed") return 0 print(f"\n where the {working:,} running samples went (buckets nest):") for name, _ in BUCKETS: if buckets[name]: print(f" {buckets[name]:>10,} {pct(buckets[name], working):>6} {name}") print(f"\n top {args.top} leaf frames:") for frame, n in leaves.most_common(args.top): print(f" {n:>10,} {pct(n, working):>6} {frame}") return 0 def pct(part, whole): return f"{100.0 * part / whole:.1f}%" if whole else "-" def sub(part, whole): return f" ({pct(part, whole)} of it)" if whole else "" if __name__ == "__main__": sys.exit(main())