Skip to content

Commit 839db01

Browse files
committed
Optimize TrackEvent conversion overhead
1 parent beed916 commit 839db01

1 file changed

Lines changed: 106 additions & 81 deletions

File tree

transformer_nuggets/utils/track_event.py

Lines changed: 106 additions & 81 deletions
Original file line numberDiff line numberDiff line change
@@ -2,12 +2,13 @@
22

33
from __future__ import annotations
44

5+
import functools
56
import hashlib
67
import json
78
import re
89
import warnings
910
from collections import defaultdict
10-
from dataclasses import dataclass
11+
from dataclasses import dataclass, field
1112
from pathlib import Path
1213
from typing import Any
1314
from collections.abc import Iterable
@@ -20,8 +21,10 @@
2021
TrackKey = tuple[Any, Any]
2122
"""Chrome JSON track identity: ``(pid, tid)``."""
2223

24+
_TRAILING_TRACK_LANE_RE = re.compile(r"\s+#\d+$")
2325

24-
@dataclass(frozen=True)
26+
27+
@dataclass(frozen=True, slots=True)
2528
class ChromeTrack:
2629
"""A logical Chrome JSON track derived from ``pid``/``tid`` metadata.
2730
@@ -35,13 +38,13 @@ class ChromeTrack:
3538
tid: Any
3639
name: str
3740
sort_index: int = 0
41+
key: TrackKey = field(init=False, repr=False, compare=False)
3842

39-
@property
40-
def key(self) -> TrackKey:
41-
return (self.pid, self.tid)
43+
def __post_init__(self) -> None:
44+
object.__setattr__(self, "key", (self.pid, self.tid))
4245

4346

44-
@dataclass(frozen=True)
47+
@dataclass(frozen=True, slots=True)
4548
class ChromeMetadata:
4649
"""Process and track metadata parsed from Chrome JSON ``ph='M'`` events."""
4750

@@ -57,7 +60,7 @@ def track_for(self, pid: Any, tid: Any) -> ChromeTrack:
5760
return ChromeTrack(pid=pid, tid=tid, name=_clean_track_name(pid, tid))
5861

5962

60-
@dataclass(frozen=True)
63+
@dataclass(frozen=True, slots=True)
6164
class DurationSlice:
6265
"""A Chrome JSON ``ph='X'`` duration event with normalized timing.
6366
@@ -82,7 +85,7 @@ def end_us(self) -> float:
8285
return self.ts_us + self.dur_us
8386

8487

85-
@dataclass(frozen=True)
88+
@dataclass(frozen=True, slots=True)
8689
class InstantEvent:
8790
"""A Chrome JSON instant event, ``ph='i'`` or ``ph='I'``."""
8891

@@ -92,7 +95,7 @@ class InstantEvent:
9295
ts_us: float
9396

9497

95-
@dataclass(frozen=True)
98+
@dataclass(frozen=True, slots=True)
9699
class CounterSample:
97100
"""A numeric sample parsed from a Chrome JSON counter event, ``ph='C'``."""
98101

@@ -104,7 +107,7 @@ class CounterSample:
104107
value: int | float
105108

106109

107-
@dataclass(frozen=True)
110+
@dataclass(frozen=True, slots=True)
108111
class FlowInstant:
109112
"""A Chrome JSON flow marker, ``ph='s'``/``'t'``/``'f'``.
110113
@@ -118,7 +121,7 @@ class FlowInstant:
118121
ts_us: float
119122

120123

121-
@dataclass(frozen=True)
124+
@dataclass(frozen=True, slots=True)
122125
class ParsedChromeTrace:
123126
"""Typed subset of a Chrome JSON trace before TrackEvent lane assignment.
124127
@@ -141,7 +144,7 @@ class ParsedChromeTrace:
141144
unsupported_phases: frozenset[str]
142145

143146

144-
@dataclass(frozen=True)
147+
@dataclass(frozen=True, slots=True)
145148
class AssignedTrace:
146149
"""Parsed Chrome trace after TrackEvent-compatible lane assignment."""
147150

@@ -157,7 +160,7 @@ def _is_numeric_process_id(pid: Any) -> bool:
157160
return isinstance(pid, int) and not isinstance(pid, bool) and pid >= 0
158161

159162

160-
@dataclass(frozen=True)
163+
@dataclass(frozen=True, slots=True)
161164
class TrackEventProtos:
162165
"""Perfetto protobuf classes loaded lazily from the ``perfetto`` package."""
163166

@@ -166,7 +169,7 @@ class TrackEventProtos:
166169
TrackEvent: Any
167170

168171

169-
@dataclass(frozen=True)
172+
@dataclass(frozen=True, slots=True)
170173
class TrackIds:
171174
"""Stable protobuf UUID mappings for emitted TrackEvent descriptors."""
172175

@@ -176,15 +179,8 @@ class TrackIds:
176179
counter_track_uuids: dict[tuple[TrackKey, str], int]
177180

178181

179-
@dataclass(frozen=True)
180-
class Marker:
181-
"""Begin/end packet marker for a TrackEvent duration slice."""
182-
183-
ts_ns: int
184-
is_begin: bool
185-
duration_key: float
186-
track_uuid: int
187-
slice: DurationSlice
182+
Marker = tuple[int, int, float, int, int, bool, DurationSlice]
183+
"""Sortable begin/end packet marker for a TrackEvent duration slice."""
188184

189185

190186
def default_track_event_path(file_path: str | Path) -> Path:
@@ -223,6 +219,7 @@ def _timestamp_us_to_ns(value: Any) -> int:
223219
return int(round(float(value or 0) * 1000.0))
224220

225221

222+
@functools.cache
226223
def _load_perfetto_protos() -> TrackEventProtos:
227224
try:
228225
from perfetto.trace_builder.proto_builder import TraceProtoBuilder
@@ -243,18 +240,29 @@ def _event_args(event: TraceDict) -> dict[str, Any]:
243240
return args if isinstance(args, dict) else {}
244241

245242

246-
def _event_track(metadata: ChromeMetadata, event: TraceDict) -> ChromeTrack:
243+
def _event_track(
244+
metadata: ChromeMetadata,
245+
event: TraceDict,
246+
annotation_track_cache: dict[TrackKey, ChromeTrack],
247+
) -> ChromeTrack:
247248
pid = event.get("pid", 0)
248249
tid = event.get("tid", 0)
249250
base_track = metadata.track_for(pid, tid)
250-
if event.get("cat") == "gpu_user_annotation":
251-
return ChromeTrack(
252-
pid=pid,
253-
tid=f"{tid}:gpu_user_annotation",
254-
name=f"GPU annotations {base_track.name}",
255-
sort_index=base_track.sort_index,
256-
)
257-
return base_track
251+
if event.get("cat") != "gpu_user_annotation":
252+
return base_track
253+
254+
key = base_track.key
255+
annotation_track = annotation_track_cache.get(key)
256+
if annotation_track is not None:
257+
return annotation_track
258+
annotation_track = ChromeTrack(
259+
pid=pid,
260+
tid=f"{tid}:gpu_user_annotation",
261+
name=f"GPU annotations {base_track.name}",
262+
sort_index=base_track.sort_index,
263+
)
264+
annotation_track_cache[key] = annotation_track
265+
return annotation_track
258266

259267

260268
def _clean_process_name(pid: Any, name: Any | None = None) -> str:
@@ -269,7 +277,7 @@ def _clean_track_name(pid: Any, tid: Any, name: Any | None = None) -> str:
269277
if pid == -1:
270278
return "Kineto events"
271279
text = str(name if name is not None else f"track {tid}").rstrip()
272-
text = re.sub(r"\s+#\d+$", "", text)
280+
text = _TRAILING_TRACK_LANE_RE.sub("", text)
273281
if text.startswith("track ") and text != "track 0":
274282
text = text[len("track ") :]
275283
return text
@@ -349,21 +357,23 @@ def _parse_counter_samples(
349357

350358
def parse_chrome_trace(trace: TraceDict) -> ParsedChromeTrace:
351359
"""Parse loose Chrome JSON into explicit internal event models."""
352-
events = list(trace.get("traceEvents", []))
360+
raw_events = trace.get("traceEvents", [])
361+
events = raw_events if isinstance(raw_events, list) else list(raw_events)
353362
metadata = _parse_metadata(events)
354363
duration_slices: list[DurationSlice] = []
355364
instants: list[InstantEvent] = []
356365
counters: list[CounterSample] = []
357366
flows: list[FlowInstant] = []
358367
unsupported: set[str] = set()
368+
annotation_track_cache: dict[TrackKey, ChromeTrack] = {}
359369

360370
for idx, event in enumerate(events):
361371
if _hide_chrome_event(event):
362372
continue
363373
ph = event.get("ph")
364374
if ph == "M":
365375
continue
366-
track = _event_track(metadata, event)
376+
track = _event_track(metadata, event, annotation_track_cache)
367377
if ph == "X":
368378
dur_us = float(event.get("dur", 0) or 0)
369379
if dur_us > 0:
@@ -604,10 +614,15 @@ def _add_debug_annotation(track_event: Any, name: str, value: Any) -> None:
604614
annotation.legacy_json_value = json.dumps(value, default=str)
605615

606616

607-
def _copy_event_payload(track_event: Any, event: TraceDict) -> None:
617+
def _copy_event_payload(
618+
track_event: Any,
619+
event: TraceDict,
620+
args: dict[str, Any] | None = None,
621+
) -> None:
608622
if "cat" in event:
609623
track_event.categories.append(str(event["cat"]))
610-
for name, value in _event_args(event).items():
624+
event_args = _event_args(event) if args is None else args
625+
for name, value in event_args.items():
611626
_add_debug_annotation(track_event, str(name), value)
612627

613628

@@ -652,8 +667,8 @@ def _process_sort_rank(trace: AssignedTrace, pid: Any) -> int:
652667
return trace.metadata.process_sort_indices.get(pid, 0)
653668

654669

655-
def _process_ids(trace: AssignedTrace) -> list[Any]:
656-
pids = {track.pid for track in _sorted_tracks(trace)} | set(trace.metadata.process_names)
670+
def _process_ids(trace: AssignedTrace, tracks: list[ChromeTrack]) -> list[Any]:
671+
pids = {track.pid for track in tracks} | set(trace.metadata.process_names)
657672
return sorted(pids, key=lambda pid: (_process_sort_rank(trace, pid), str(pid)))
658673

659674

@@ -668,9 +683,10 @@ def _define_process_tracks(
668683
builder: Any,
669684
trace: AssignedTrace,
670685
protos: TrackEventProtos,
686+
tracks: list[ChromeTrack],
671687
) -> dict[Any, int]:
672688
process_uuids: dict[Any, int] = {}
673-
for pid in _process_ids(trace):
689+
for pid in _process_ids(trace, tracks):
674690
process_uuid = _stable_uuid("process", pid)
675691
process_uuids[pid] = process_uuid
676692
packet = builder.add_packet()
@@ -697,10 +713,11 @@ def _define_duration_tracks(
697713
trace: AssignedTrace,
698714
process_uuids: dict[Any, int],
699715
protos: TrackEventProtos,
716+
tracks: list[ChromeTrack],
700717
) -> dict[tuple[TrackKey, int], int]:
701718
max_lane_by_track = _max_lane_by_track(trace)
702719
track_uuids: dict[tuple[TrackKey, int], int] = {}
703-
for track in _sorted_tracks(trace):
720+
for track in tracks:
704721
lane_count = max_lane_by_track.get(track.key, 0) + 1
705722
for lane in range(lane_count):
706723
track_uuid = _stable_uuid("track", track.pid, track.tid, lane)
@@ -745,13 +762,19 @@ def _define_counter_tracks(
745762

746763

747764
def _define_track_ids(builder: Any, trace: AssignedTrace, protos: TrackEventProtos) -> TrackIds:
748-
process_uuids = _define_process_tracks(builder, trace, protos)
765+
tracks = _sorted_tracks(trace)
766+
process_uuids = _define_process_tracks(builder, trace, protos, tracks)
749767
return TrackIds(
750768
process_uuids=process_uuids,
751-
duration_track_uuids=_define_duration_tracks(builder, trace, process_uuids, protos),
769+
duration_track_uuids=_define_duration_tracks(
770+
builder,
771+
trace,
772+
process_uuids,
773+
protos,
774+
tracks,
775+
),
752776
instant_track_uuids={
753-
track.key: _stable_uuid("track", track.pid, track.tid, 0)
754-
for track in _sorted_tracks(trace)
777+
track.key: _stable_uuid("track", track.pid, track.tid, 0) for track in tracks
755778
},
756779
counter_track_uuids=_define_counter_tracks(builder, trace, process_uuids),
757780
)
@@ -762,33 +785,29 @@ def _duration_markers(trace: AssignedTrace, track_ids: TrackIds) -> list[Marker]
762785
for slc in trace.duration_slices:
763786
track_uuid = track_ids.duration_track_uuids[(slc.track.key, slc.lane)]
764787
markers.append(
765-
Marker(
766-
ts_ns=_timestamp_us_to_ns(slc.ts_us),
767-
is_begin=True,
768-
duration_key=-slc.dur_us,
769-
track_uuid=track_uuid,
770-
slice=slc,
788+
(
789+
_timestamp_us_to_ns(slc.ts_us),
790+
0,
791+
-slc.dur_us,
792+
track_uuid,
793+
slc.index,
794+
True,
795+
slc,
771796
)
772797
)
773798
markers.append(
774-
Marker(
775-
ts_ns=_timestamp_us_to_ns(slc.end_us),
776-
is_begin=False,
777-
duration_key=slc.dur_us,
778-
track_uuid=track_uuid,
779-
slice=slc,
799+
(
800+
_timestamp_us_to_ns(slc.end_us),
801+
1,
802+
slc.dur_us,
803+
track_uuid,
804+
slc.index,
805+
False,
806+
slc,
780807
)
781808
)
782-
return sorted(
783-
markers,
784-
key=lambda marker: (
785-
marker.ts_ns,
786-
not marker.is_begin,
787-
marker.duration_key,
788-
marker.track_uuid,
789-
marker.slice.index,
790-
),
791-
)
809+
markers.sort()
810+
return markers
792811

793812

794813
def _emit_duration_markers(
@@ -798,30 +817,36 @@ def _emit_duration_markers(
798817
protos: TrackEventProtos,
799818
trusted_packet_sequence_id: int,
800819
) -> None:
801-
for marker in _duration_markers(trace, track_ids):
802-
packet = builder.add_packet()
803-
packet.timestamp = marker.ts_ns
820+
add_packet = builder.add_packet
821+
slice_begin = protos.TrackEvent.TYPE_SLICE_BEGIN
822+
slice_end = protos.TrackEvent.TYPE_SLICE_END
823+
for ts_ns, _begin_order, _duration_key, track_uuid, _slice_index, is_begin, slc in (
824+
_duration_markers(trace, track_ids)
825+
):
826+
packet = add_packet()
827+
packet.timestamp = ts_ns
804828
packet.trusted_packet_sequence_id = trusted_packet_sequence_id
805829
track_event = packet.track_event
806-
track_event.track_uuid = marker.track_uuid
807-
if marker.is_begin:
808-
event = marker.slice.event
809-
track_event.type = protos.TrackEvent.TYPE_SLICE_BEGIN
830+
track_event.track_uuid = track_uuid
831+
if is_begin:
832+
event = slc.event
833+
event_args = _event_args(event)
834+
track_event.type = slice_begin
810835
track_event.name = str(event.get("name", "slice"))
811-
_copy_event_payload(track_event, event)
812-
_add_correlation_id(track_event, _event_args(event).get("correlation"))
813-
track_event.flow_ids.extend(marker.slice.flow_ids)
814-
if marker.slice.flow_latencies_us:
815-
for flow_id, latency_us in marker.slice.flow_latencies_us:
816-
suffix = "" if len(marker.slice.flow_latencies_us) == 1 else f"[{flow_id}]"
836+
_copy_event_payload(track_event, event, event_args)
837+
_add_correlation_id(track_event, event_args.get("correlation"))
838+
track_event.flow_ids.extend(slc.flow_ids)
839+
if slc.flow_latencies_us:
840+
for flow_id, latency_us in slc.flow_latencies_us:
841+
suffix = "" if len(slc.flow_latencies_us) == 1 else f"[{flow_id}]"
817842
_add_debug_annotation(
818843
track_event,
819844
f"launch_latency_us{suffix}",
820845
latency_us,
821846
)
822847
_add_debug_annotation(track_event, f"launch_flow_id{suffix}", flow_id)
823848
else:
824-
track_event.type = protos.TrackEvent.TYPE_SLICE_END
849+
track_event.type = slice_end
825850

826851

827852
def _emit_instants(

0 commit comments

Comments
 (0)