vprof_to_json.py 18 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585
  1. #!/usr/bin/env python3
  2. """
  3. vprof_to_json.py - Parse a Source Engine VProf recording (*.vprof) and emit JSON.
  4. The binary format is documented in VPROF_FORMAT.md. It is produced by the
  5. engine's ``vprof_record_start`` command (class CVProfRecorder in
  6. engine/vprof_record.cpp).
  7. Usage:
  8. python vprof_to_json.py test.vprof > test.json
  9. python vprof_to_json.py test.vprof -o test.json --indent 2
  10. python vprof_to_json.py test.vprof --summary-only
  11. python vprof_to_json.py test.vprof --no-frames --top 50
  12. """
  13. from __future__ import annotations
  14. import argparse
  15. import json
  16. import statistics
  17. import struct
  18. import sys
  19. from dataclasses import dataclass, field
  20. from typing import Dict, List, Optional
  21. # ---------------------------------------------------------------------------
  22. # Constants
  23. # ---------------------------------------------------------------------------
  24. VPROF_FILE_VERSION = 1
  25. TOKEN_START_FRAME = 0
  26. TOKEN_ADD_NODE = 1
  27. TOKEN_ADD_BUDGET_GROUP = 2
  28. TOKEN_TIMINGS = 3
  29. TOKEN_END_OF_FRAME = 4
  30. TOKEN_FILE_FINISHED = 5
  31. BUDGETFLAG_CLIENT = 1 << 0
  32. BUDGETFLAG_SERVER = 1 << 1
  33. BUDGETFLAG_OTHER = 1 << 2
  34. BUDGETFLAG_HIDDEN = 1 << 15
  35. _BUDGET_FLAG_NAMES = (
  36. (BUDGETFLAG_CLIENT, "CLIENT"),
  37. (BUDGETFLAG_SERVER, "SERVER"),
  38. (BUDGETFLAG_OTHER, "OTHER"),
  39. (BUDGETFLAG_HIDDEN, "HIDDEN"),
  40. )
  41. # The 31 budget groups registered by CVProfile::CVProfile() in a fixed order.
  42. # A recording may either rewrite all of them (index 0..30) or only the groups
  43. # added after construction; either way IDs 0..30 map to these names.
  44. DEFAULT_BUDGET_GROUPS = [
  45. ("Unaccounted", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  46. ("World Rendering", BUDGETFLAG_CLIENT),
  47. ("Displacement_Rendering", BUDGETFLAG_CLIENT),
  48. ("Game", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  49. ("Player", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  50. ("NPCs", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  51. ("Server Animation", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  52. ("Client_Animation", BUDGETFLAG_CLIENT),
  53. ("Physics", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  54. ("Static_Prop_Rendering", BUDGETFLAG_CLIENT),
  55. ("Other_Model_Rendering", BUDGETFLAG_CLIENT),
  56. ("Fast Path Model Rendering", BUDGETFLAG_CLIENT),
  57. ("Light_Cache", BUDGETFLAG_CLIENT),
  58. ("Brush_Model_Rendering", BUDGETFLAG_CLIENT),
  59. ("Shadow_Rendering", BUDGETFLAG_CLIENT),
  60. ("Detail_Prop_Rendering", BUDGETFLAG_CLIENT),
  61. ("Particle/Effect_Rendering", BUDGETFLAG_CLIENT),
  62. ("Ropes", BUDGETFLAG_CLIENT),
  63. ("Dynamic_Light_Rendering", BUDGETFLAG_CLIENT),
  64. ("Networking", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  65. ("Sound", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  66. ("VGUI", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  67. ("FileSystem", BUDGETFLAG_SERVER | BUDGETFLAG_OTHER),
  68. ("Prediction", BUDGETFLAG_CLIENT),
  69. ("Interpolation", BUDGETFLAG_CLIENT),
  70. ("Swap_Buffers", BUDGETFLAG_CLIENT),
  71. ("Occlusion", BUDGETFLAG_CLIENT),
  72. ("Overlays", BUDGETFLAG_CLIENT),
  73. ("Tools", BUDGETFLAG_CLIENT | BUDGETFLAG_OTHER),
  74. ("Texture_Cache", BUDGETFLAG_CLIENT),
  75. ("Replay", BUDGETFLAG_SERVER),
  76. ]
  77. class VProfError(Exception):
  78. """Raised when a .vprof stream is malformed."""
  79. def decode_flags(flags: int) -> List[str]:
  80. return [name for bit, name in _BUDGET_FLAG_NAMES if flags & bit]
  81. # ---------------------------------------------------------------------------
  82. # Binary reader
  83. # ---------------------------------------------------------------------------
  84. class Reader:
  85. """Small cursor over an in-memory byte buffer, little-endian."""
  86. __slots__ = ("data", "pos", "size")
  87. def __init__(self, data: bytes):
  88. self.data = data
  89. self.pos = 0
  90. self.size = len(data)
  91. @property
  92. def remaining(self) -> int:
  93. return self.size - self.pos
  94. def _take(self, n: int) -> bytes:
  95. if self.pos + n > self.size:
  96. raise VProfError(
  97. f"unexpected end of file at offset {self.pos} (wanted {n} bytes)"
  98. )
  99. chunk = self.data[self.pos : self.pos + n]
  100. self.pos += n
  101. return chunk
  102. def u8(self) -> int:
  103. return self._take(1)[0]
  104. def i32(self) -> int:
  105. return struct.unpack("<i", self._take(4))[0]
  106. def u16(self) -> int:
  107. return struct.unpack("<H", self._take(2))[0]
  108. def u32(self) -> int:
  109. return struct.unpack("<I", self._take(4))[0]
  110. def cstring(self, max_len: int = 4096) -> str:
  111. end = self.data.find(b"\x00", self.pos)
  112. if end < 0:
  113. raise VProfError(f"unterminated string at offset {self.pos}")
  114. if end - self.pos > max_len:
  115. raise VProfError(f"string too long at offset {self.pos}")
  116. raw = self.data[self.pos : end]
  117. self.pos = end + 1
  118. # Source writes narrow strings; Windows-1252 is a safe superset of
  119. # the ASCII that is normally used.
  120. return raw.decode("utf-8", "replace")
  121. # ---------------------------------------------------------------------------
  122. # Data model
  123. # ---------------------------------------------------------------------------
  124. @dataclass
  125. class BudgetGroup:
  126. id: int
  127. name: str
  128. flags: int
  129. is_default: bool = False
  130. @dataclass
  131. class Node:
  132. id: int
  133. name: str
  134. parent_id: Optional[int]
  135. budget_group_id: int
  136. children: List[int] = field(default_factory=list)
  137. @dataclass
  138. class Frame:
  139. index: int
  140. tick: int
  141. samples: Dict[int, tuple] = field(default_factory=dict) # node_id -> (calls, us)
  142. added_nodes: List[int] = field(default_factory=list)
  143. added_budget_groups: List[int] = field(default_factory=list)
  144. @dataclass
  145. class Recording:
  146. version: int
  147. root_node_id: int
  148. budget_groups: List[BudgetGroup]
  149. nodes: Dict[int, Node]
  150. frames: List[Frame]
  151. # ---------------------------------------------------------------------------
  152. # Parser
  153. # ---------------------------------------------------------------------------
  154. def parse_vprof(data: bytes) -> Recording:
  155. r = Reader(data)
  156. try:
  157. version = r.i32()
  158. root_node_id = r.i32()
  159. except VProfError as e:
  160. raise VProfError(f"truncated header: {e}") from e
  161. if version != VPROF_FILE_VERSION:
  162. # Do not fail outright: other revisions may be readable.
  163. sys.stderr.write(
  164. f"warning: vprof file version is {version}, "
  165. f"expected {VPROF_FILE_VERSION}; attempting to parse anyway\n"
  166. )
  167. # Pre-seed the default budget groups so IDs stay correct whether or not
  168. # the recording rewrites them.
  169. groups: List[BudgetGroup] = [
  170. BudgetGroup(id=i, name=name, flags=flags, is_default=True)
  171. for i, (name, flags) in enumerate(DEFAULT_BUDGET_GROUPS)
  172. ]
  173. group_by_name: Dict[str, int] = {g.name: g.id for g in groups}
  174. def add_budget_group(name: str, flags: int) -> tuple:
  175. """Return (id, was_new)."""
  176. existing = group_by_name.get(name)
  177. if existing is not None:
  178. groups[existing].flags = flags
  179. return existing, False
  180. gid = len(groups)
  181. groups.append(BudgetGroup(id=gid, name=name, flags=flags, is_default=False))
  182. group_by_name[name] = gid
  183. return gid, True
  184. nodes: Dict[int, Node] = {
  185. root_node_id: Node(
  186. id=root_node_id, name="Root", parent_id=None, budget_group_id=0
  187. )
  188. }
  189. frames: List[Frame] = []
  190. def read_timings(node_id: int, samples: Dict[int, tuple]) -> None:
  191. node = nodes[node_id]
  192. calls_token = r.u8()
  193. if calls_token == 255:
  194. calls = r.u16()
  195. else:
  196. calls = calls_token
  197. time_units = r.u16()
  198. if time_units == 0xFFFF:
  199. microseconds = r.u32() * 4
  200. else:
  201. microseconds = time_units * 4
  202. samples[node_id] = (calls, microseconds)
  203. for child_id in node.children:
  204. read_timings(child_id, samples)
  205. while r.remaining:
  206. token = r.u8()
  207. if token == TOKEN_FILE_FINISHED:
  208. break
  209. if token != TOKEN_START_FRAME:
  210. raise VProfError(
  211. f"expected Token_StartFrame at offset {r.pos - 1}, got {token}"
  212. )
  213. tick = r.i32()
  214. frame = Frame(index=len(frames), tick=tick)
  215. while True:
  216. inner = r.u8()
  217. if inner == TOKEN_END_OF_FRAME:
  218. break
  219. elif inner == TOKEN_ADD_BUDGET_GROUP:
  220. name = r.cstring()
  221. flags = r.i32()
  222. gid, is_new = add_budget_group(name, flags)
  223. if is_new:
  224. frame.added_budget_groups.append(gid)
  225. elif inner == TOKEN_ADD_NODE:
  226. parent_id = r.i32()
  227. name = r.cstring()
  228. budget_group_id = r.i32()
  229. node_id = r.i32()
  230. if parent_id not in nodes:
  231. raise VProfError(
  232. f"AddNode references unknown parent {parent_id} "
  233. f"at offset {r.pos}"
  234. )
  235. if node_id in nodes:
  236. raise VProfError(
  237. f"AddNode re-declares existing node {node_id} "
  238. f"at offset {r.pos}"
  239. )
  240. nodes[node_id] = Node(
  241. id=node_id,
  242. name=name,
  243. parent_id=parent_id,
  244. budget_group_id=budget_group_id,
  245. )
  246. # CVProfNode::GetSubNode() prepends, so mirror that here.
  247. nodes[parent_id].children.insert(0, node_id)
  248. frame.added_nodes.append(node_id)
  249. elif inner == TOKEN_TIMINGS:
  250. read_timings(root_node_id, frame.samples)
  251. else:
  252. raise VProfError(
  253. f"unexpected token {inner} inside frame {frame.index} "
  254. f"at offset {r.pos - 1}"
  255. )
  256. frames.append(frame)
  257. return Recording(
  258. version=version,
  259. root_node_id=root_node_id,
  260. budget_groups=groups,
  261. nodes=nodes,
  262. frames=frames,
  263. )
  264. # ---------------------------------------------------------------------------
  265. # JSON conversion
  266. # ---------------------------------------------------------------------------
  267. def _group_name(recording: Recording, group_id: int) -> str:
  268. if 0 <= group_id < len(recording.budget_groups):
  269. return recording.budget_groups[group_id].name
  270. return f"<unknown group {group_id}>"
  271. def build_summary(recording: Recording, top_n: int) -> dict:
  272. totals = [
  273. f.samples.get(recording.root_node_id, (0, 0))[1] for f in recording.frames
  274. ]
  275. # Per-node aggregates.
  276. agg: Dict[int, dict] = {}
  277. for frame in recording.frames:
  278. for node_id, (calls, us) in frame.samples.items():
  279. entry = agg.get(node_id)
  280. if entry is None:
  281. entry = agg[node_id] = {
  282. "total_calls": 0,
  283. "total_microseconds": 0,
  284. "max_microseconds": 0,
  285. "frames_present": 0,
  286. }
  287. entry["total_calls"] += calls
  288. entry["total_microseconds"] += us
  289. entry["frames_present"] += 1
  290. if us > entry["max_microseconds"]:
  291. entry["max_microseconds"] = us
  292. grand_total = sum(totals) or 1
  293. top_nodes = []
  294. for node_id, entry in sorted(
  295. agg.items(), key=lambda kv: kv[1]["total_microseconds"], reverse=True
  296. )[:top_n]:
  297. node = recording.nodes.get(node_id)
  298. frames_present = entry["frames_present"] or 1
  299. top_nodes.append(
  300. {
  301. "node_id": node_id,
  302. "name": node.name if node else f"<node {node_id}>",
  303. "budget_group": _group_name(
  304. recording, node.budget_group_id if node else 0
  305. ),
  306. "total_calls": entry["total_calls"],
  307. "total_microseconds": entry["total_microseconds"],
  308. "avg_microseconds": round(
  309. entry["total_microseconds"] / frames_present, 3
  310. ),
  311. "max_microseconds": entry["max_microseconds"],
  312. "percent_of_total": round(
  313. 100.0 * entry["total_microseconds"] / grand_total, 4
  314. ),
  315. }
  316. )
  317. def stat(values: List[int]) -> Optional[dict]:
  318. if not values:
  319. return None
  320. ordered = sorted(values)
  321. result = {
  322. "min": ordered[0],
  323. "max": ordered[-1],
  324. "mean": round(statistics.fmean(values), 3),
  325. "median": round(statistics.median(values), 3),
  326. "total": sum(values),
  327. }
  328. if len(ordered) > 1:
  329. idx = min(len(ordered) - 1, int(round(0.95 * (len(ordered) - 1))))
  330. result["p95"] = ordered[idx]
  331. return result
  332. ticks = [f.tick for f in recording.frames]
  333. return {
  334. "frame_count": len(recording.frames),
  335. "node_count": len(recording.nodes),
  336. "budget_group_count": len(recording.budget_groups),
  337. "tick_first": ticks[0] if ticks else None,
  338. "tick_last": ticks[-1] if ticks else None,
  339. "tick_span": (ticks[-1] - ticks[0]) if ticks else None,
  340. "total_recorded_microseconds": sum(totals),
  341. "frame_time_microseconds": stat(totals),
  342. "top_nodes_by_total_microseconds": top_nodes,
  343. }
  344. def recording_to_dict(
  345. recording: Recording,
  346. *,
  347. source_name: str,
  348. size_bytes: int,
  349. include_frames: bool,
  350. include_nodes: bool,
  351. top_n: int,
  352. ) -> dict:
  353. out = {
  354. "format": "source-vprof",
  355. "source": {
  356. "file": source_name,
  357. "size_bytes": size_bytes,
  358. "version": recording.version,
  359. "root_node_id": recording.root_node_id,
  360. },
  361. }
  362. out["budget_groups"] = [
  363. {
  364. "id": g.id,
  365. "name": g.name,
  366. "flags": g.flags,
  367. "flags_decoded": decode_flags(g.flags),
  368. "is_default": g.is_default,
  369. }
  370. for g in recording.budget_groups
  371. ]
  372. if include_nodes:
  373. out["nodes"] = [
  374. {
  375. "id": n.id,
  376. "name": n.name,
  377. "parent_id": n.parent_id,
  378. "budget_group_id": n.budget_group_id,
  379. "budget_group": _group_name(recording, n.budget_group_id),
  380. "children": n.children,
  381. }
  382. for n in recording.nodes.values()
  383. ]
  384. if include_frames:
  385. frames_out = []
  386. for frame in recording.frames:
  387. total_us = frame.samples.get(recording.root_node_id, (0, 0))[1]
  388. frames_out.append(
  389. {
  390. "index": frame.index,
  391. "tick": frame.tick,
  392. "total_microseconds": total_us,
  393. # node_id (string key) -> {"calls": int, "microseconds": int}
  394. "samples": {
  395. str(node_id): {
  396. "calls": calls,
  397. "microseconds": us,
  398. }
  399. for node_id, (calls, us) in frame.samples.items()
  400. },
  401. "added_nodes": frame.added_nodes,
  402. "added_budget_groups": frame.added_budget_groups,
  403. }
  404. )
  405. out["frames"] = frames_out
  406. out["summary"] = build_summary(recording, top_n)
  407. return out
  408. # ---------------------------------------------------------------------------
  409. # CLI
  410. # ---------------------------------------------------------------------------
  411. def main(argv: Optional[List[str]] = None) -> int:
  412. parser = argparse.ArgumentParser(
  413. description="Parse a Source Engine .vprof recording and emit JSON.",
  414. formatter_class=argparse.ArgumentDefaultsHelpFormatter,
  415. )
  416. parser.add_argument("input", help="path to the .vprof file")
  417. parser.add_argument(
  418. "-o", "--output", help="output file (default: stdout)", default=None
  419. )
  420. parser.add_argument(
  421. "--indent",
  422. type=int,
  423. default=None,
  424. help="JSON indentation; omit for compact output",
  425. )
  426. parser.add_argument(
  427. "--no-frames",
  428. action="store_true",
  429. help="omit the per-frame timing samples",
  430. )
  431. parser.add_argument(
  432. "--no-nodes",
  433. action="store_true",
  434. help="omit the node definition table",
  435. )
  436. parser.add_argument(
  437. "--summary-only",
  438. action="store_true",
  439. help="emit only metadata, budget groups, and the summary",
  440. )
  441. parser.add_argument(
  442. "--top",
  443. type=int,
  444. default=25,
  445. help="number of hottest nodes to include in the summary",
  446. )
  447. parser.add_argument(
  448. "--max-frames",
  449. type=int,
  450. default=None,
  451. help="stop after this many frames (useful for huge captures)",
  452. )
  453. args = parser.parse_args(argv)
  454. try:
  455. with open(args.input, "rb") as fh:
  456. raw = fh.read()
  457. except OSError as e:
  458. sys.stderr.write(f"error: cannot read {args.input}: {e}\n")
  459. return 2
  460. try:
  461. recording = parse_vprof(raw)
  462. except VProfError as e:
  463. sys.stderr.write(f"error: {e}\n")
  464. return 1
  465. if args.max_frames is not None and args.max_frames >= 0:
  466. recording.frames = recording.frames[: args.max_frames]
  467. include_frames = not (args.no_frames or args.summary_only)
  468. include_nodes = not args.no_nodes
  469. result = recording_to_dict(
  470. recording,
  471. source_name=args.input,
  472. size_bytes=len(raw),
  473. include_frames=include_frames,
  474. include_nodes=include_nodes,
  475. top_n=args.top,
  476. )
  477. text = json.dumps(result, indent=args.indent, ensure_ascii=False)
  478. if args.output:
  479. with open(args.output, "w", encoding="utf-8") as fh:
  480. fh.write(text)
  481. else:
  482. try:
  483. sys.stdout.write(text)
  484. sys.stdout.write("\n")
  485. sys.stdout.flush()
  486. except BrokenPipeError:
  487. # e.g. `vprof_to_json.py file.vprof | head`
  488. try:
  489. sys.stdout.close()
  490. except OSError:
  491. pass
  492. return 0
  493. return 0
  494. if __name__ == "__main__":
  495. raise SystemExit(main())