/home/noah/src/trueno/src/brick/profiler/mod.rs
Line | Count | Source |
1 | | //! BrickProfiler: Token-Centric Profiling System |
2 | | //! |
3 | | //! TILING-SPEC-001: Tile-Level Profiling Support |
4 | | //! |
5 | | //! This module provides hierarchical profiling for compute bricks: |
6 | | //! - Per-brick timing and throughput (PAR-073) |
7 | | //! - O(1) hot path with BrickId enum (PAR-200) |
8 | | //! - Tile-level profiling for cache-blocked operations (TILING-SPEC-001) |
9 | | //! - Kernel checksum capture for divergence detection (CORRECTNESS-011) |
10 | | |
11 | | mod tile_stats; |
12 | | mod checksum; |
13 | | |
14 | | #[cfg(test)] |
15 | | mod tests; |
16 | | |
17 | | pub use tile_stats::{TileStats, TileLevel, TileTimer}; |
18 | | pub use checksum::{KernelChecksum, DivergenceInfo, fnv1a_f32_checksum}; |
19 | | |
20 | | use std::time::Instant; |
21 | | |
22 | | use super::exec_graph::{ |
23 | | BrickBottleneck, BrickCategory, BrickId, BrickStats, CategoryStats, ExecutionGraph, |
24 | | ExecutionNode, ExecutionNodeId, SyncMode, |
25 | | }; |
26 | | |
27 | | /// Pending measurement for deferred sync mode. |
28 | | #[derive(Debug, Clone)] |
29 | | struct PendingMeasurement { |
30 | | /// Brick ID (if known) |
31 | | brick_id: Option<BrickId>, |
32 | | /// Brick name (for dynamic bricks) |
33 | | name: Option<String>, |
34 | | /// Start time in nanoseconds (from Instant::now()) |
35 | | start_ns: u64, |
36 | | /// Number of elements processed |
37 | | elements: u64, |
38 | | } |
39 | | |
40 | | /// Per-brick profiler using pure Rust timing. |
41 | | /// |
42 | | /// # Design (PAR-073, PAR-200) |
43 | | /// |
44 | | /// - Uses `std::time::Instant` for timing (no CUDA event FFI) |
45 | | /// - PAR-200: O(1) hot path with `BrickId` enum + array storage |
46 | | /// - GPU operations require explicit sync before timing point |
47 | | /// - Supports deferred sync mode for low-overhead production profiling |
48 | | /// - Aggregates statistics per brick name |
49 | | /// |
50 | | /// # Usage |
51 | | /// |
52 | | /// ```rust,ignore |
53 | | /// use trueno::brick::{BrickProfiler, BrickId, SyncMode}; |
54 | | /// |
55 | | /// let mut profiler = BrickProfiler::new(); |
56 | | /// profiler.enable(); |
57 | | /// |
58 | | /// // Fast path: use BrickId for known bricks (PAR-200) |
59 | | /// let timer = profiler.start_brick(BrickId::RmsNorm); |
60 | | /// // ... do work ... |
61 | | /// // For GPU: cuda_stream.synchronize() HERE |
62 | | /// profiler.stop_brick(timer, 1); |
63 | | /// |
64 | | /// // Legacy path: string-based (slower, for unknown bricks) |
65 | | /// let timer = profiler.start("CustomBrick"); |
66 | | /// profiler.stop(timer, 1); |
67 | | /// |
68 | | /// // Deferred sync mode (production) |
69 | | /// profiler.set_sync_mode(SyncMode::Deferred); |
70 | | /// profiler.record_deferred(BrickId::RmsNorm, start_ns, 1); |
71 | | /// // ... more operations ... |
72 | | /// cuda_stream.synchronize(); |
73 | | /// profiler.finalize(end_ns); |
74 | | /// |
75 | | /// // Get statistics |
76 | | /// let stats = profiler.brick_stats(BrickId::RmsNorm); |
77 | | /// println!("RmsNorm avg: {:.2}µs", stats.avg_us()); |
78 | | /// |
79 | | /// // Get category breakdown |
80 | | /// let cats = profiler.category_stats(); |
81 | | /// println!("Attention: {:.1}%", cats[BrickCategory::Attention as usize].percentage(profiler.total_ns())); |
82 | | /// ``` |
83 | | #[derive(Debug)] |
84 | | pub struct BrickProfiler { |
85 | | // PAR-200: Fast path - pre-allocated array for known bricks |
86 | | /// Per-brick statistics for known BrickId types (O(1) lookup) |
87 | | brick_stats: [BrickStats; BrickId::COUNT], |
88 | | |
89 | | // Legacy path - HashMap for dynamic/unknown brick names |
90 | | /// Per-brick statistics for unknown brick names (slower, O(1) amortized) |
91 | | dynamic_stats: std::collections::HashMap<String, BrickStats>, |
92 | | |
93 | | // PAR-200: Deferred sync support |
94 | | /// Pending measurements awaiting GPU sync |
95 | | pending: Vec<PendingMeasurement>, |
96 | | /// Synchronization mode |
97 | | sync_mode: SyncMode, |
98 | | /// Reference instant for deferred timing |
99 | | epoch: Instant, |
100 | | |
101 | | /// Whether profiling is enabled |
102 | | enabled: bool, |
103 | | /// Total tokens processed |
104 | | total_tokens: u64, |
105 | | /// Total time (ns) across all bricks |
106 | | total_ns: u64, |
107 | | /// L2 cache hit rate (0.0-1.0) - v1.1.0 OBSERVE phase |
108 | | l2_cache_hit_rate: Option<f32>, |
109 | | /// Whether zero-copy memory transfers are enabled - v1.1.0 OBSERVE phase |
110 | | is_zero_copy: bool, |
111 | | /// CORRECTNESS-011: Per-kernel checksums for divergence detection |
112 | | kernel_checksums: Vec<KernelChecksum>, |
113 | | |
114 | | // PAR-201: Execution path graph |
115 | | /// Whether execution graph tracking is enabled |
116 | | graph_enabled: bool, |
117 | | /// Execution path graph for PTX→kernel→brick relationships |
118 | | execution_graph: ExecutionGraph, |
119 | | |
120 | | // TILING-SPEC-001: Tile-level profiling |
121 | | /// Per-level tile statistics (Macro, Midi, Micro) |
122 | | tile_stats: [TileStats; 3], |
123 | | /// Whether tile profiling is enabled |
124 | | tile_profiling_enabled: bool, |
125 | | } |
126 | | |
127 | | /// Timer handle returned by `start()` (legacy string-based API). |
128 | | #[derive(Debug)] |
129 | | pub struct BrickTimer { |
130 | | /// Brick name |
131 | | name: String, |
132 | | /// Start time |
133 | | start: Instant, |
134 | | } |
135 | | |
136 | | /// Timer handle returned by `start_brick()` (PAR-200 fast path). |
137 | | #[derive(Debug)] |
138 | | pub struct BrickIdTimer { |
139 | | /// Brick ID |
140 | | brick_id: BrickId, |
141 | | /// Start time |
142 | | start: Instant, |
143 | | } |
144 | | |
145 | | impl Default for BrickProfiler { |
146 | 0 | fn default() -> Self { |
147 | 0 | Self::new() |
148 | 0 | } |
149 | | } |
150 | | |
151 | | impl BrickProfiler { |
152 | | /// Create a new profiler (disabled by default for zero overhead). |
153 | 0 | pub fn new() -> Self { |
154 | | Self { |
155 | 0 | brick_stats: std::array::from_fn(|i| { |
156 | | // Safety: i < BrickId::COUNT by construction |
157 | 0 | let brick_id = unsafe { std::mem::transmute::<u8, BrickId>(i as u8) }; |
158 | 0 | BrickStats::new(brick_id.name()) |
159 | 0 | }), |
160 | 0 | dynamic_stats: std::collections::HashMap::new(), |
161 | 0 | pending: Vec::new(), |
162 | 0 | sync_mode: SyncMode::Deferred, |
163 | 0 | epoch: Instant::now(), |
164 | | enabled: false, |
165 | | total_tokens: 0, |
166 | | total_ns: 0, |
167 | 0 | l2_cache_hit_rate: None, |
168 | | is_zero_copy: false, |
169 | 0 | kernel_checksums: Vec::new(), |
170 | | graph_enabled: false, |
171 | 0 | execution_graph: ExecutionGraph::new(), |
172 | 0 | tile_stats: [ |
173 | 0 | TileStats::new(TileLevel::Macro), |
174 | 0 | TileStats::new(TileLevel::Midi), |
175 | 0 | TileStats::new(TileLevel::Micro), |
176 | 0 | ], |
177 | | tile_profiling_enabled: false, |
178 | | } |
179 | 0 | } |
180 | | |
181 | | /// Create an enabled profiler. |
182 | 0 | pub fn enabled() -> Self { |
183 | 0 | let mut profiler = Self::new(); |
184 | 0 | profiler.enabled = true; |
185 | 0 | profiler |
186 | 0 | } |
187 | | |
188 | | // ======================================================================== |
189 | | // PAR-200: Sync Mode Configuration |
190 | | // ======================================================================== |
191 | | |
192 | | /// Set the synchronization mode for GPU profiling. |
193 | | /// |
194 | | /// # Modes |
195 | | /// - `Immediate`: Sync after each kernel (accurate but slow) |
196 | | /// - `PerLayer`: Sync once per transformer layer |
197 | | /// - `Deferred`: Sync once per forward pass (default, fast) |
198 | | /// - `None`: No synchronization |
199 | 0 | pub fn set_sync_mode(&mut self, mode: SyncMode) { |
200 | 0 | self.sync_mode = mode; |
201 | 0 | } |
202 | | |
203 | | /// Get the current synchronization mode. |
204 | | #[must_use] |
205 | 0 | pub fn sync_mode(&self) -> SyncMode { |
206 | 0 | self.sync_mode |
207 | 0 | } |
208 | | |
209 | | /// Reset the epoch for deferred timing. |
210 | | /// Call this at the start of a forward pass. |
211 | 0 | pub fn reset_epoch(&mut self) { |
212 | 0 | self.epoch = Instant::now(); |
213 | 0 | } |
214 | | |
215 | | /// Get nanoseconds elapsed since epoch. |
216 | | #[inline] |
217 | 0 | pub fn elapsed_ns(&self) -> u64 { |
218 | 0 | self.epoch.elapsed().as_nanos() as u64 |
219 | 0 | } |
220 | | |
221 | | // ======================================================================== |
222 | | // PAR-200: Fast Path API (BrickId-based) |
223 | | // ======================================================================== |
224 | | |
225 | | /// Start timing a brick using BrickId (O(1) hot path). |
226 | | /// |
227 | | /// This is the preferred API for known brick types. |
228 | | /// For GPU operations, call `stream.synchronize()` before `stop_brick()`. |
229 | | #[inline] |
230 | | #[must_use] |
231 | 0 | pub fn start_brick(&self, brick_id: BrickId) -> BrickIdTimer { |
232 | 0 | BrickIdTimer { |
233 | 0 | brick_id, |
234 | 0 | start: Instant::now(), |
235 | 0 | } |
236 | 0 | } |
237 | | |
238 | | /// Stop timing and record the sample (O(1) hot path). |
239 | | #[inline] |
240 | 0 | pub fn stop_brick(&mut self, timer: BrickIdTimer, elements: u64) { |
241 | 0 | if !self.enabled { |
242 | 0 | return; |
243 | 0 | } |
244 | | |
245 | 0 | let elapsed = timer.start.elapsed(); |
246 | 0 | let elapsed_ns = elapsed.as_nanos() as u64; |
247 | | |
248 | | // O(1) array access |
249 | 0 | let stats = &mut self.brick_stats[timer.brick_id as usize]; |
250 | 0 | stats.add_sample(elapsed_ns, elements); |
251 | | |
252 | | // Update totals |
253 | 0 | self.total_tokens += elements; |
254 | 0 | self.total_ns += elapsed_ns; |
255 | 0 | } |
256 | | |
257 | | /// Get statistics for a known brick type (O(1)). |
258 | | #[inline] |
259 | | #[must_use] |
260 | 0 | pub fn brick_stats(&self, brick_id: BrickId) -> &BrickStats { |
261 | 0 | &self.brick_stats[brick_id as usize] |
262 | 0 | } |
263 | | |
264 | | /// Get mutable statistics for a known brick type (O(1)). |
265 | | #[inline] |
266 | 0 | pub fn brick_stats_mut(&mut self, brick_id: BrickId) -> &mut BrickStats { |
267 | 0 | &mut self.brick_stats[brick_id as usize] |
268 | 0 | } |
269 | | |
270 | | // ======================================================================== |
271 | | // PAR-200: Deferred Sync API |
272 | | // ======================================================================== |
273 | | |
274 | | /// Record a measurement without GPU sync (deferred mode). |
275 | | /// |
276 | | /// Call `finalize()` after GPU sync to apply all pending measurements. |
277 | | /// |
278 | | /// # Arguments |
279 | | /// - `brick_id`: The brick type |
280 | | /// - `start_ns`: Start time (from `elapsed_ns()` at operation start) |
281 | | /// - `elements`: Number of elements processed |
282 | | #[inline] |
283 | 0 | pub fn record_deferred(&mut self, brick_id: BrickId, start_ns: u64, elements: u64) { |
284 | 0 | if !self.enabled { |
285 | 0 | return; |
286 | 0 | } |
287 | 0 | self.pending.push(PendingMeasurement { |
288 | 0 | brick_id: Some(brick_id), |
289 | 0 | name: None, |
290 | 0 | start_ns, |
291 | 0 | elements, |
292 | 0 | }); |
293 | 0 | } |
294 | | |
295 | | /// Record a measurement for a dynamic brick (deferred mode). |
296 | | #[inline] |
297 | 0 | pub fn record_deferred_dynamic(&mut self, name: &str, start_ns: u64, elements: u64) { |
298 | 0 | if !self.enabled { |
299 | 0 | return; |
300 | 0 | } |
301 | 0 | self.pending.push(PendingMeasurement { |
302 | 0 | brick_id: BrickId::from_str(name), |
303 | 0 | name: Some(name.to_string()), |
304 | 0 | start_ns, |
305 | 0 | elements, |
306 | 0 | }); |
307 | 0 | } |
308 | | |
309 | | /// Finalize all pending measurements after GPU sync. |
310 | | /// |
311 | | /// Must be called after `stream.synchronize()` to get accurate timing. |
312 | | /// |
313 | | /// # Arguments |
314 | | /// - `end_ns`: End time (from `elapsed_ns()` after sync) |
315 | 0 | pub fn finalize(&mut self, end_ns: u64) { |
316 | 0 | if self.pending.is_empty() { |
317 | 0 | return; |
318 | 0 | } |
319 | | |
320 | | // Calculate elapsed time for each pending measurement |
321 | 0 | for m in self.pending.drain(..) { |
322 | 0 | let elapsed_ns = end_ns.saturating_sub(m.start_ns); |
323 | | |
324 | 0 | if let Some(brick_id) = m.brick_id { |
325 | 0 | // Fast path: known brick |
326 | 0 | let stats = &mut self.brick_stats[brick_id as usize]; |
327 | 0 | stats.add_sample(elapsed_ns, m.elements); |
328 | 0 | } else if let Some(name) = m.name { |
329 | | // Slow path: dynamic brick |
330 | 0 | let stats = self |
331 | 0 | .dynamic_stats |
332 | 0 | .entry(name.clone()) |
333 | 0 | .or_insert_with(|| BrickStats::new(&name)); |
334 | 0 | stats.add_sample(elapsed_ns, m.elements); |
335 | 0 | } |
336 | | |
337 | 0 | self.total_tokens += m.elements; |
338 | 0 | self.total_ns += elapsed_ns; |
339 | | } |
340 | 0 | } |
341 | | |
342 | | /// Check if there are pending measurements. |
343 | | #[inline] |
344 | | #[must_use] |
345 | 0 | pub fn has_pending(&self) -> bool { |
346 | 0 | !self.pending.is_empty() |
347 | 0 | } |
348 | | |
349 | | /// Get number of pending measurements. |
350 | | #[inline] |
351 | | #[must_use] |
352 | 0 | pub fn pending_count(&self) -> usize { |
353 | 0 | self.pending.len() |
354 | 0 | } |
355 | | |
356 | | // ======================================================================== |
357 | | // PAR-200: Category Aggregation |
358 | | // ======================================================================== |
359 | | |
360 | | /// Get aggregated statistics by category. |
361 | | /// |
362 | | /// Returns an array indexed by `BrickCategory as usize`. |
363 | | #[must_use] |
364 | 0 | pub fn category_stats(&self) -> [CategoryStats; BrickCategory::COUNT] { |
365 | 0 | let mut result = [CategoryStats::default(); BrickCategory::COUNT]; |
366 | | |
367 | 0 | for (i, stats) in self.brick_stats.iter().enumerate() { |
368 | 0 | // Safety: i < BrickId::COUNT by construction |
369 | 0 | let brick_id = unsafe { std::mem::transmute::<u8, BrickId>(i as u8) }; |
370 | 0 | let cat = brick_id.category() as usize; |
371 | 0 | result[cat].total_ns += stats.total_ns; |
372 | 0 | result[cat].total_elements += stats.total_elements; |
373 | 0 | result[cat].count += stats.count; |
374 | 0 | } |
375 | | |
376 | | // Include dynamic stats in "Other" category |
377 | 0 | for stats in self.dynamic_stats.values() { |
378 | 0 | let cat = BrickCategory::Other as usize; |
379 | 0 | result[cat].total_ns += stats.total_ns; |
380 | 0 | result[cat].total_elements += stats.total_elements; |
381 | 0 | result[cat].count += stats.count; |
382 | 0 | } |
383 | | |
384 | 0 | result |
385 | 0 | } |
386 | | |
387 | | /// Print category breakdown to console. |
388 | 0 | pub fn print_category_stats(&self) { |
389 | 0 | let cats = self.category_stats(); |
390 | 0 | let total = self.total_ns; |
391 | | |
392 | 0 | println!("╭─────────────────────────────────────────────────────────╮"); |
393 | 0 | println!("│ Category Breakdown (PAR-200) │"); |
394 | 0 | println!("├─────────────────────────────────────────────────────────┤"); |
395 | 0 | for (i, cat_stats) in cats.iter().enumerate() { |
396 | | // Safety: i < BrickCategory::COUNT |
397 | 0 | let cat = unsafe { std::mem::transmute::<u8, BrickCategory>(i as u8) }; |
398 | 0 | if cat_stats.count > 0 { |
399 | 0 | println!( |
400 | 0 | "│ {:12} {:8.2}µs avg {:6.1}% [{:5} samples] │", |
401 | 0 | cat.name(), |
402 | 0 | cat_stats.avg_us(), |
403 | 0 | cat_stats.percentage(total), |
404 | 0 | cat_stats.count |
405 | 0 | ); |
406 | 0 | } |
407 | | } |
408 | 0 | println!("╰─────────────────────────────────────────────────────────╯"); |
409 | 0 | } |
410 | | |
411 | | // ======================================================================== |
412 | | // PAR-201: Execution Path Graph |
413 | | // ======================================================================== |
414 | | |
415 | | /// Enable execution graph tracking. |
416 | | /// |
417 | | /// When enabled, the profiler records the execution hierarchy: |
418 | | /// - Layer → Brick → Kernel relationships |
419 | | /// - PTX hashes for kernel identity |
420 | | /// - Timing data per node |
421 | 0 | pub fn enable_graph(&mut self) { |
422 | 0 | self.graph_enabled = true; |
423 | 0 | } |
424 | | |
425 | | /// Disable execution graph tracking. |
426 | 0 | pub fn disable_graph(&mut self) { |
427 | 0 | self.graph_enabled = false; |
428 | 0 | } |
429 | | |
430 | | /// Check if execution graph tracking is enabled. |
431 | | #[must_use] |
432 | 0 | pub fn is_graph_enabled(&self) -> bool { |
433 | 0 | self.graph_enabled |
434 | 0 | } |
435 | | |
436 | | /// Get the execution graph (immutable). |
437 | | #[must_use] |
438 | 0 | pub fn execution_graph(&self) -> &ExecutionGraph { |
439 | 0 | &self.execution_graph |
440 | 0 | } |
441 | | |
442 | | /// Get the execution graph (mutable). |
443 | 0 | pub fn execution_graph_mut(&mut self) -> &mut ExecutionGraph { |
444 | 0 | &mut self.execution_graph |
445 | 0 | } |
446 | | |
447 | | /// Push a scope for hierarchical graph recording. |
448 | | /// |
449 | | /// # Example |
450 | | /// |
451 | | /// ```rust,ignore |
452 | | /// profiler.enable_graph(); |
453 | | /// profiler.graph_push_scope(ExecutionNode::Layer { index: 0 }); |
454 | | /// // ... record bricks and kernels ... |
455 | | /// profiler.graph_pop_scope(); |
456 | | /// ``` |
457 | 0 | pub fn graph_push_scope(&mut self, node: ExecutionNode) -> Option<ExecutionNodeId> { |
458 | 0 | if !self.graph_enabled { |
459 | 0 | return None; |
460 | 0 | } |
461 | 0 | Some(self.execution_graph.push_scope(node)) |
462 | 0 | } |
463 | | |
464 | | /// Pop the current scope. |
465 | 0 | pub fn graph_pop_scope(&mut self) -> Option<ExecutionNodeId> { |
466 | 0 | if !self.graph_enabled { |
467 | 0 | return None; |
468 | 0 | } |
469 | 0 | self.execution_graph.pop_scope() |
470 | 0 | } |
471 | | |
472 | | /// Record a brick in the execution graph. |
473 | | /// |
474 | | /// This should be called after `stop_brick()` with the timing data. |
475 | 0 | pub fn graph_record_brick( |
476 | 0 | &mut self, |
477 | 0 | brick_id: BrickId, |
478 | 0 | timing_ns: u64, |
479 | 0 | elements: u64, |
480 | 0 | ) -> Option<ExecutionNodeId> { |
481 | 0 | if !self.graph_enabled { |
482 | 0 | return None; |
483 | 0 | } |
484 | 0 | let node = ExecutionNode::Brick { |
485 | 0 | id: brick_id, |
486 | 0 | timing_ns, |
487 | 0 | elements, |
488 | 0 | }; |
489 | 0 | Some(self.execution_graph.add_node_in_scope(node)) |
490 | 0 | } |
491 | | |
492 | | /// Record a kernel launch in the execution graph. |
493 | | /// |
494 | | /// # Arguments |
495 | | /// - `name`: Kernel name (e.g., "batched_q4k_gemv") |
496 | | /// - `ptx_hash`: FNV-1a hash of PTX source for identity |
497 | | /// - `grid`: Grid dimensions (blocks) |
498 | | /// - `block`: Block dimensions (threads) |
499 | | /// - `shared_mem`: Shared memory bytes |
500 | 0 | pub fn graph_record_kernel( |
501 | 0 | &mut self, |
502 | 0 | name: &str, |
503 | 0 | ptx_hash: u64, |
504 | 0 | grid: (u32, u32, u32), |
505 | 0 | block: (u32, u32, u32), |
506 | 0 | shared_mem: u32, |
507 | 0 | ) -> Option<ExecutionNodeId> { |
508 | 0 | if !self.graph_enabled { |
509 | 0 | return None; |
510 | 0 | } |
511 | 0 | Some( |
512 | 0 | self.execution_graph |
513 | 0 | .record_kernel_launch(name, ptx_hash, grid, block, shared_mem), |
514 | 0 | ) |
515 | 0 | } |
516 | | |
517 | | /// Export execution graph to DOT format for visualization. |
518 | | /// |
519 | | /// Use with Graphviz: `dot -Tsvg output.dot -o graph.svg` |
520 | | #[must_use] |
521 | 0 | pub fn graph_to_dot(&self) -> String { |
522 | 0 | self.execution_graph.to_dot() |
523 | 0 | } |
524 | | |
525 | | /// Export execution graph to trueno-graph CsrGraph. |
526 | | #[cfg(feature = "execution-graph")] |
527 | | #[must_use] |
528 | | pub fn graph_to_csr(&self) -> trueno_graph::CsrGraph { |
529 | | self.execution_graph.to_csr() |
530 | | } |
531 | | |
532 | | /// Clear the execution graph. |
533 | 0 | pub fn graph_clear(&mut self) { |
534 | 0 | self.execution_graph.clear(); |
535 | 0 | } |
536 | | |
537 | | /// Check if the execution graph scope stack is balanced. |
538 | | #[must_use] |
539 | 0 | pub fn graph_is_scope_balanced(&self) -> bool { |
540 | 0 | self.execution_graph.is_scope_balanced() |
541 | 0 | } |
542 | | |
543 | | /// Set L2 cache hit rate (v1.1.0 OBSERVE phase) |
544 | 0 | pub fn set_l2_cache_hit_rate(&mut self, rate: f32) { |
545 | 0 | self.l2_cache_hit_rate = Some(rate.clamp(0.0, 1.0)); |
546 | 0 | } |
547 | | |
548 | | /// Get L2 cache hit rate |
549 | 0 | pub fn l2_cache_hit_rate(&self) -> Option<f32> { |
550 | 0 | self.l2_cache_hit_rate |
551 | 0 | } |
552 | | |
553 | | /// Set zero-copy mode (v1.1.0 OBSERVE phase) |
554 | 0 | pub fn set_zero_copy(&mut self, enabled: bool) { |
555 | 0 | self.is_zero_copy = enabled; |
556 | 0 | } |
557 | | |
558 | | /// Check if zero-copy is enabled |
559 | 0 | pub fn is_zero_copy(&self) -> bool { |
560 | 0 | self.is_zero_copy |
561 | 0 | } |
562 | | |
563 | | /// Enable profiling. |
564 | 0 | pub fn enable(&mut self) { |
565 | 0 | self.enabled = true; |
566 | 0 | } |
567 | | |
568 | | /// Disable profiling. |
569 | 0 | pub fn disable(&mut self) { |
570 | 0 | self.enabled = false; |
571 | 0 | } |
572 | | |
573 | | /// Check if profiling is enabled. |
574 | | #[must_use] |
575 | 0 | pub fn is_enabled(&self) -> bool { |
576 | 0 | self.enabled |
577 | 0 | } |
578 | | |
579 | | /// Start timing a brick. Returns timer handle. |
580 | | /// |
581 | | /// IMPORTANT: For GPU operations, call sync AFTER the operation |
582 | | /// completes but BEFORE calling stop(). |
583 | | #[must_use] |
584 | 0 | pub fn start(&self, name: &str) -> BrickTimer { |
585 | 0 | BrickTimer { |
586 | 0 | name: name.to_string(), |
587 | 0 | start: Instant::now(), |
588 | 0 | } |
589 | 0 | } |
590 | | |
591 | | /// Stop timing and record the sample. |
592 | | /// |
593 | | /// # Arguments |
594 | | /// - `timer`: Timer handle from `start()` |
595 | | /// - `elements`: Number of elements (tokens) processed |
596 | 0 | pub fn stop(&mut self, timer: BrickTimer, elements: u64) { |
597 | 0 | if !self.enabled { |
598 | 0 | return; |
599 | 0 | } |
600 | | |
601 | 0 | let elapsed = timer.start.elapsed(); |
602 | 0 | let elapsed_ns = elapsed.as_nanos() as u64; |
603 | | |
604 | | // PAR-200: Try fast path first if name matches a known BrickId |
605 | 0 | if let Some(brick_id) = BrickId::from_str(&timer.name) { |
606 | 0 | let stats = &mut self.brick_stats[brick_id as usize]; |
607 | 0 | stats.add_sample(elapsed_ns, elements); |
608 | 0 | } else { |
609 | | // Fall back to dynamic stats |
610 | 0 | let name = timer.name; |
611 | 0 | let stats = self |
612 | 0 | .dynamic_stats |
613 | 0 | .entry(name.clone()) |
614 | 0 | .or_insert_with(|| BrickStats::new(&name)); |
615 | 0 | stats.add_sample(elapsed_ns, elements); |
616 | | } |
617 | | |
618 | | // Update totals |
619 | 0 | self.total_tokens += elements; |
620 | 0 | self.total_ns += elapsed_ns; |
621 | 0 | } |
622 | | |
623 | | /// Record a pre-measured duration for a brick. |
624 | | /// |
625 | | /// PAR-073: This method allows timing with raw `Instant` calls, avoiding |
626 | | /// borrow conflicts when profiling CUDA operations that also need `&mut self`. |
627 | | /// |
628 | | /// # Arguments |
629 | | /// - `name`: Brick name |
630 | | /// - `elapsed`: Duration of the operation (from `Instant::elapsed()`) |
631 | | /// - `elements`: Number of elements (tokens) processed |
632 | | /// |
633 | | /// # Example |
634 | | /// ```rust,ignore |
635 | | /// let start = std::time::Instant::now(); |
636 | | /// cuda_stream.synchronize()?; |
637 | | /// self.some_cuda_operation()?; |
638 | | /// cuda_stream.synchronize()?; |
639 | | /// let elapsed = start.elapsed(); |
640 | | /// self.profiler.record_elapsed("SomeBrick", elapsed, 1); |
641 | | /// ``` |
642 | 0 | pub fn record_elapsed(&mut self, name: &str, elapsed: std::time::Duration, elements: u64) { |
643 | 0 | if !self.enabled { |
644 | 0 | return; |
645 | 0 | } |
646 | | |
647 | 0 | let elapsed_ns = elapsed.as_nanos() as u64; |
648 | | |
649 | | // PAR-200: Try fast path first if name matches a known BrickId |
650 | 0 | if let Some(brick_id) = BrickId::from_str(name) { |
651 | 0 | let stats = &mut self.brick_stats[brick_id as usize]; |
652 | 0 | stats.add_sample(elapsed_ns, elements); |
653 | 0 | } else { |
654 | | // Fall back to dynamic stats |
655 | 0 | let stats = self |
656 | 0 | .dynamic_stats |
657 | 0 | .entry(name.to_string()) |
658 | 0 | .or_insert_with(|| BrickStats::new(name)); |
659 | 0 | stats.add_sample(elapsed_ns, elements); |
660 | | } |
661 | | |
662 | | // Update totals |
663 | 0 | self.total_tokens += elements; |
664 | 0 | self.total_ns += elapsed_ns; |
665 | 0 | } |
666 | | |
667 | | /// PMAT-451: Record elapsed time with byte metrics for compression workloads. |
668 | | /// |
669 | | /// # Arguments |
670 | | /// - `name`: Brick name |
671 | | /// - `elapsed`: Duration of the operation |
672 | | /// - `elements`: Number of elements (pages) processed |
673 | | /// - `input_bytes`: Original uncompressed size |
674 | | /// - `output_bytes`: Compressed output size |
675 | | /// |
676 | | /// # Example |
677 | | /// ```rust,ignore |
678 | | /// let start = std::time::Instant::now(); |
679 | | /// let compressed = zstd_compress(&page_data); |
680 | | /// let elapsed = start.elapsed(); |
681 | | /// profiler.record_elapsed_with_bytes( |
682 | | /// "ZstdCompress", |
683 | | /// elapsed, |
684 | | /// 1, |
685 | | /// page_data.len() as u64, |
686 | | /// compressed.len() as u64, |
687 | | /// ); |
688 | | /// ``` |
689 | 0 | pub fn record_elapsed_with_bytes( |
690 | 0 | &mut self, |
691 | 0 | name: &str, |
692 | 0 | elapsed: std::time::Duration, |
693 | 0 | elements: u64, |
694 | 0 | input_bytes: u64, |
695 | 0 | output_bytes: u64, |
696 | 0 | ) { |
697 | 0 | if !self.enabled { |
698 | 0 | return; |
699 | 0 | } |
700 | | |
701 | 0 | let elapsed_ns = elapsed.as_nanos() as u64; |
702 | | |
703 | | // PAR-200: Try fast path first if name matches a known BrickId |
704 | 0 | if let Some(brick_id) = BrickId::from_str(name) { |
705 | 0 | let stats = &mut self.brick_stats[brick_id as usize]; |
706 | 0 | stats.add_sample_with_bytes(elapsed_ns, elements, input_bytes, output_bytes); |
707 | 0 | } else { |
708 | | // Fall back to dynamic stats |
709 | 0 | let stats = self |
710 | 0 | .dynamic_stats |
711 | 0 | .entry(name.to_string()) |
712 | 0 | .or_insert_with(|| BrickStats::new(name)); |
713 | 0 | stats.add_sample_with_bytes(elapsed_ns, elements, input_bytes, output_bytes); |
714 | | } |
715 | | |
716 | | // Update totals |
717 | 0 | self.total_tokens += elements; |
718 | 0 | self.total_ns += elapsed_ns; |
719 | 0 | } |
720 | | |
721 | | /// PMAT-451: Set bottleneck classification for a brick. |
722 | 0 | pub fn set_brick_bottleneck(&mut self, name: &str, bottleneck: BrickBottleneck) { |
723 | | // PAR-200: Try fast path first |
724 | 0 | if let Some(brick_id) = BrickId::from_str(name) { |
725 | 0 | self.brick_stats[brick_id as usize].set_bottleneck(bottleneck); |
726 | 0 | } else if let Some(stats) = self.dynamic_stats.get_mut(name) { |
727 | 0 | stats.set_bottleneck(bottleneck); |
728 | 0 | } |
729 | 0 | } |
730 | | |
731 | | /// Get statistics for a specific brick by name. |
732 | | /// |
733 | | /// First checks known BrickId types (O(1)), then falls back to dynamic stats. |
734 | | #[must_use] |
735 | 0 | pub fn stats(&self, name: &str) -> Option<&BrickStats> { |
736 | | // Try fast path first |
737 | 0 | if let Some(brick_id) = BrickId::from_str(name) { |
738 | 0 | let stats = &self.brick_stats[brick_id as usize]; |
739 | 0 | if stats.count > 0 { |
740 | 0 | return Some(stats); |
741 | 0 | } |
742 | 0 | } |
743 | | // Fall back to dynamic stats |
744 | 0 | self.dynamic_stats.get(name) |
745 | 0 | } |
746 | | |
747 | | /// Get all brick statistics (legacy API, returns dynamic stats only). |
748 | | /// |
749 | | /// For full statistics including known bricks, use `all_brick_stats()` instead. |
750 | | #[must_use] |
751 | | #[deprecated( |
752 | | since = "0.12.0", |
753 | | note = "Use all_brick_stats() for complete statistics" |
754 | | )] |
755 | 0 | pub fn all_stats(&self) -> &std::collections::HashMap<String, BrickStats> { |
756 | 0 | &self.dynamic_stats |
757 | 0 | } |
758 | | |
759 | | /// Get all brick statistics including both known and dynamic bricks. |
760 | 0 | pub fn all_brick_stats(&self) -> impl Iterator<Item = &BrickStats> { |
761 | 0 | self.brick_stats |
762 | 0 | .iter() |
763 | 0 | .filter(|s| s.count > 0) |
764 | 0 | .chain(self.dynamic_stats.values()) |
765 | 0 | } |
766 | | |
767 | | /// Get total throughput across all bricks. |
768 | | #[must_use] |
769 | 0 | pub fn total_throughput(&self) -> f64 { |
770 | 0 | if self.total_ns == 0 { |
771 | 0 | 0.0 |
772 | | } else { |
773 | 0 | self.total_tokens as f64 / (self.total_ns as f64 / 1_000_000_000.0) |
774 | | } |
775 | 0 | } |
776 | | |
777 | | /// Get total tokens processed. |
778 | | #[must_use] |
779 | 0 | pub fn total_tokens(&self) -> u64 { |
780 | 0 | self.total_tokens |
781 | 0 | } |
782 | | |
783 | | /// Get total time in nanoseconds. |
784 | | #[must_use] |
785 | 0 | pub fn total_ns(&self) -> u64 { |
786 | 0 | self.total_ns |
787 | 0 | } |
788 | | |
789 | | /// Get all brick names. |
790 | | #[must_use] |
791 | 0 | pub fn brick_names(&self) -> Vec<String> { |
792 | 0 | let mut names: Vec<String> = self |
793 | 0 | .brick_stats |
794 | 0 | .iter() |
795 | 0 | .enumerate() |
796 | 0 | .filter(|(_, s)| s.count > 0) |
797 | 0 | .map(|(i, _)| { |
798 | | // Safety: i < BrickId::COUNT |
799 | 0 | let brick_id = unsafe { std::mem::transmute::<u8, BrickId>(i as u8) }; |
800 | 0 | brick_id.name().to_string() |
801 | 0 | }) |
802 | 0 | .collect(); |
803 | 0 | names.extend(self.dynamic_stats.keys().cloned()); |
804 | 0 | names |
805 | 0 | } |
806 | | |
807 | | /// Reset all statistics. |
808 | 0 | pub fn reset(&mut self) { |
809 | 0 | for stats in &mut self.brick_stats { |
810 | 0 | stats.count = 0; |
811 | 0 | stats.total_ns = 0; |
812 | 0 | stats.min_ns = u64::MAX; |
813 | 0 | stats.max_ns = 0; |
814 | 0 | stats.total_elements = 0; |
815 | 0 | stats.total_bytes = 0; |
816 | 0 | stats.total_compressed_bytes = 0; |
817 | 0 | } |
818 | 0 | self.dynamic_stats.clear(); |
819 | 0 | self.pending.clear(); |
820 | 0 | self.total_tokens = 0; |
821 | 0 | self.total_ns = 0; |
822 | 0 | } |
823 | | |
824 | | /// Generate a summary report. |
825 | | #[must_use] |
826 | 0 | pub fn summary(&self) -> String { |
827 | 0 | let mut report = String::new(); |
828 | 0 | report.push_str("=== Brick Profiler Summary (PAR-200) ===\n"); |
829 | 0 | report.push_str(&format!( |
830 | 0 | "Total: {} tokens, {:.2}µs, {:.1} tok/s\n", |
831 | 0 | self.total_tokens, |
832 | 0 | self.total_ns as f64 / 1000.0, |
833 | 0 | self.total_throughput() |
834 | 0 | )); |
835 | 0 | report.push_str("\nPer-Brick Breakdown:\n"); |
836 | | |
837 | | // Collect all stats (known + dynamic) |
838 | 0 | let mut all_stats: Vec<(&str, &BrickStats)> = Vec::new(); |
839 | | |
840 | | // Add known bricks with non-zero counts |
841 | 0 | for (i, stats) in self.brick_stats.iter().enumerate() { |
842 | 0 | if stats.count > 0 { |
843 | 0 | // Safety: i < BrickId::COUNT |
844 | 0 | let brick_id = unsafe { std::mem::transmute::<u8, BrickId>(i as u8) }; |
845 | 0 | all_stats.push((brick_id.name(), stats)); |
846 | 0 | } |
847 | | } |
848 | | |
849 | | // Add dynamic bricks |
850 | 0 | for (name, stats) in &self.dynamic_stats { |
851 | 0 | all_stats.push((name.as_str(), stats)); |
852 | 0 | } |
853 | | |
854 | | // Sort by total time descending |
855 | 0 | all_stats.sort_by(|a, b| b.1.total_ns.cmp(&a.1.total_ns)); |
856 | | |
857 | 0 | for (name, stats) in all_stats { |
858 | 0 | let pct = if self.total_ns > 0 { |
859 | 0 | 100.0 * stats.total_ns as f64 / self.total_ns as f64 |
860 | | } else { |
861 | 0 | 0.0 |
862 | | }; |
863 | 0 | report.push_str(&format!( |
864 | 0 | " {:20} {:8.2}µs avg ({:5.1}%) [{} samples]\n", |
865 | 0 | name, |
866 | 0 | stats.avg_us(), |
867 | 0 | pct, |
868 | 0 | stats.count |
869 | 0 | )); |
870 | | } |
871 | | |
872 | | // Add category breakdown |
873 | 0 | report.push_str("\nCategory Breakdown:\n"); |
874 | 0 | let cats = self.category_stats(); |
875 | 0 | for (i, cat_stats) in cats.iter().enumerate() { |
876 | 0 | if cat_stats.count > 0 { |
877 | 0 | // Safety: i < BrickCategory::COUNT |
878 | 0 | let cat = unsafe { std::mem::transmute::<u8, BrickCategory>(i as u8) }; |
879 | 0 | report.push_str(&format!( |
880 | 0 | " {:12} {:8.2}µs avg ({:5.1}%)\n", |
881 | 0 | cat.name(), |
882 | 0 | cat_stats.avg_us(), |
883 | 0 | cat_stats.percentage(self.total_ns) |
884 | 0 | )); |
885 | 0 | } |
886 | | } |
887 | | |
888 | 0 | report |
889 | 0 | } |
890 | | |
891 | | /// Export profiling data as JSON for pmat metrics integration. |
892 | | /// |
893 | | /// Format compatible with `.pmat-metrics/trends/` structure: |
894 | | /// ```json |
895 | | /// { |
896 | | /// "total_tokens": 1000, |
897 | | /// "total_ns": 5000000, |
898 | | /// "total_throughput": 200000.0, |
899 | | /// "bricks": [ |
900 | | /// { |
901 | | /// "name": "RmsNorm", |
902 | | /// "count": 10, |
903 | | /// "total_ns": 1000000, |
904 | | /// "avg_us": 100.0, |
905 | | /// "min_us": 90.0, |
906 | | /// "max_us": 120.0, |
907 | | /// "throughput": 10000.0, |
908 | | /// "pct": 20.0 |
909 | | /// } |
910 | | /// ] |
911 | | /// } |
912 | | /// ``` |
913 | | #[must_use] |
914 | 0 | pub fn to_json(&self) -> String { |
915 | 0 | let mut bricks = Vec::new(); |
916 | | |
917 | | // Collect all stats (known + dynamic) |
918 | 0 | let mut all_stats: Vec<(&str, &BrickStats)> = Vec::new(); |
919 | | |
920 | | // Add known bricks with non-zero counts |
921 | 0 | for (i, stats) in self.brick_stats.iter().enumerate() { |
922 | 0 | if stats.count > 0 { |
923 | 0 | // Safety: i < BrickId::COUNT |
924 | 0 | let brick_id = unsafe { std::mem::transmute::<u8, BrickId>(i as u8) }; |
925 | 0 | all_stats.push((brick_id.name(), stats)); |
926 | 0 | } |
927 | | } |
928 | | |
929 | | // Add dynamic bricks |
930 | 0 | for (name, stats) in &self.dynamic_stats { |
931 | 0 | all_stats.push((name.as_str(), stats)); |
932 | 0 | } |
933 | | |
934 | | // Sort by total time descending |
935 | 0 | all_stats.sort_by(|a, b| b.1.total_ns.cmp(&a.1.total_ns)); |
936 | | |
937 | 0 | for (name, stats) in all_stats { |
938 | 0 | let pct = if self.total_ns > 0 { |
939 | 0 | 100.0 * stats.total_ns as f64 / self.total_ns as f64 |
940 | | } else { |
941 | 0 | 0.0 |
942 | | }; |
943 | | // PMAT-451: Include compression_ratio, throughput_gbps, and bottleneck |
944 | 0 | let compression = stats.compression_ratio(); |
945 | 0 | let throughput_gbps = stats.throughput_gbps(); |
946 | 0 | let bottleneck = stats.get_bottleneck(); |
947 | 0 | bricks.push(format!( |
948 | 0 | r#"{{"name":"{}","count":{},"total_ns":{},"avg_us":{:.2},"min_us":{:.2},"max_us":{:.2},"throughput":{:.1},"pct":{:.1},"total_bytes":{},"compression_ratio":{:.2},"throughput_gbps":{:.2},"bottleneck":"{}"}}"#, |
949 | | name, |
950 | | stats.count, |
951 | | stats.total_ns, |
952 | 0 | stats.avg_us(), |
953 | 0 | stats.min_us(), |
954 | 0 | stats.max_us(), |
955 | 0 | stats.throughput(), |
956 | | pct, |
957 | | stats.total_bytes, |
958 | | compression, |
959 | | throughput_gbps, |
960 | | bottleneck |
961 | | )); |
962 | | } |
963 | | |
964 | 0 | format!( |
965 | 0 | r#"{{"total_tokens":{},"total_ns":{},"total_throughput":{:.1},"bricks":[{}]}}"#, |
966 | | self.total_tokens, |
967 | | self.total_ns, |
968 | 0 | self.total_throughput(), |
969 | 0 | bricks.join(",") |
970 | | ) |
971 | 0 | } |
972 | | |
973 | | /// Write profiling data to a JSON file for pmat tracking. |
974 | | /// |
975 | | /// # Errors |
976 | | /// Returns error if file cannot be written. |
977 | 0 | pub fn write_json(&self, path: &std::path::Path) -> std::io::Result<()> { |
978 | 0 | std::fs::write(path, self.to_json()) |
979 | 0 | } |
980 | | |
981 | | // ======================================================================= |
982 | | // CORRECTNESS-011: Per-kernel checksum capture for divergence detection |
983 | | // ======================================================================= |
984 | | |
985 | | /// Record a kernel trace with output checksum for divergence detection. |
986 | | /// |
987 | | /// This enables automated CPU/GPU divergence detection by capturing |
988 | | /// output checksums alongside timing data. When GPU produces wrong output, |
989 | | /// this identifies WHICH kernel diverged without hours of manual debugging. |
990 | | /// |
991 | | /// Five-Whys Root Cause: Hours of manual "let me check X in Y" debugging |
992 | | /// → No automated tool identified which kernel diverged |
993 | | /// → BrickProfiler only captured timing, not checksums |
994 | | /// → Missing feature: per-kernel checksum capture |
995 | | /// |
996 | | /// # Arguments |
997 | | /// - `name`: Brick/kernel name |
998 | | /// - `layer_idx`: Layer index (0-N for transformer layers) |
999 | | /// - `position`: Position in sequence |
1000 | | /// - `output`: Output tensor data (first 64 floats checksummed) |
1001 | | /// |
1002 | | /// # Example |
1003 | | /// ```rust,ignore |
1004 | | /// // After RoPE kernel |
1005 | | /// profiler.record_checksum("RopeNeox", layer_idx, position, &q_rotated); |
1006 | | /// ``` |
1007 | 0 | pub fn record_checksum(&mut self, name: &str, layer_idx: usize, position: u32, output: &[f32]) { |
1008 | 0 | if !self.enabled { |
1009 | 0 | return; |
1010 | 0 | } |
1011 | 0 | let checksum = fnv1a_f32_checksum(output); |
1012 | 0 | let trace = KernelChecksum { |
1013 | 0 | name: name.to_string(), |
1014 | 0 | layer_idx, |
1015 | 0 | position, |
1016 | 0 | checksum, |
1017 | 0 | }; |
1018 | 0 | self.kernel_checksums.push(trace); |
1019 | 0 | } |
1020 | | |
1021 | | /// Get all kernel checksums for divergence comparison. |
1022 | | #[must_use] |
1023 | 0 | pub fn get_checksums(&self) -> &[KernelChecksum] { |
1024 | 0 | &self.kernel_checksums |
1025 | 0 | } |
1026 | | |
1027 | | /// Compare checksums with a reference profiler (e.g., CPU baseline). |
1028 | | /// |
1029 | | /// Returns None if all checksums match, or the first divergent kernel. |
1030 | | #[must_use] |
1031 | 0 | pub fn find_divergence(&self, reference: &BrickProfiler) -> Option<DivergenceInfo> { |
1032 | | use std::collections::HashMap; |
1033 | | |
1034 | | // Index reference checksums by (name, layer_idx, position) |
1035 | 0 | let ref_index: HashMap<(&str, usize, u32), u64> = reference |
1036 | 0 | .kernel_checksums |
1037 | 0 | .iter() |
1038 | 0 | .map(|t| ((t.name.as_str(), t.layer_idx, t.position), t.checksum)) |
1039 | 0 | .collect(); |
1040 | | |
1041 | | // Check each of our checksums against reference |
1042 | 0 | for trace in &self.kernel_checksums { |
1043 | 0 | let key = (trace.name.as_str(), trace.layer_idx, trace.position); |
1044 | 0 | if let Some(&expected) = ref_index.get(&key) { |
1045 | 0 | if trace.checksum != expected { |
1046 | 0 | return Some(DivergenceInfo { |
1047 | 0 | kernel_name: trace.name.clone(), |
1048 | 0 | layer_idx: trace.layer_idx, |
1049 | 0 | position: trace.position, |
1050 | 0 | expected_checksum: expected, |
1051 | 0 | actual_checksum: trace.checksum, |
1052 | 0 | }); |
1053 | 0 | } |
1054 | 0 | } |
1055 | | } |
1056 | 0 | None |
1057 | 0 | } |
1058 | | |
1059 | | /// Reset checksum tracking (call before new forward pass). |
1060 | 0 | pub fn reset_checksums(&mut self) { |
1061 | 0 | self.kernel_checksums.clear(); |
1062 | 0 | } |
1063 | | |
1064 | | // ======================================================================== |
1065 | | // TILING-SPEC-001: Tile-Level Profiling (Phase 15) |
1066 | | // ======================================================================== |
1067 | | |
1068 | | /// Enable tile-level profiling. |
1069 | | /// |
1070 | | /// When enabled, `start_tile()`/`stop_tile()` record per-tile statistics |
1071 | | /// for Macro/Midi/Micro tile hierarchy. |
1072 | 0 | pub fn enable_tile_profiling(&mut self) { |
1073 | 0 | self.tile_profiling_enabled = true; |
1074 | 0 | } |
1075 | | |
1076 | | /// Disable tile-level profiling. |
1077 | 0 | pub fn disable_tile_profiling(&mut self) { |
1078 | 0 | self.tile_profiling_enabled = false; |
1079 | 0 | } |
1080 | | |
1081 | | /// Check if tile profiling is enabled. |
1082 | | #[must_use] |
1083 | 0 | pub fn is_tile_profiling_enabled(&self) -> bool { |
1084 | 0 | self.tile_profiling_enabled |
1085 | 0 | } |
1086 | | |
1087 | | /// Start timing a tile execution. |
1088 | | /// |
1089 | | /// Returns a `TileTimer` that should be passed to `stop_tile()` after |
1090 | | /// the tile computation completes. |
1091 | | /// |
1092 | | /// # Arguments |
1093 | | /// - `level`: Tile hierarchy level (Macro/Midi/Micro) |
1094 | | /// - `row`: Row index within parent tile |
1095 | | /// - `col`: Column index within parent tile |
1096 | | /// |
1097 | | /// # Example |
1098 | | /// ```rust,ignore |
1099 | | /// let timer = profiler.start_tile(TileLevel::Macro, 0, 0); |
1100 | | /// // ... execute tile computation ... |
1101 | | /// profiler.stop_tile(timer, 256 * 256, 2 * 256 * 256 * 256); |
1102 | | /// ``` |
1103 | | #[must_use] |
1104 | 0 | pub fn start_tile(&self, level: TileLevel, row: u32, col: u32) -> TileTimer { |
1105 | 0 | TileTimer { |
1106 | 0 | level, |
1107 | 0 | _row: row, |
1108 | 0 | _col: col, |
1109 | 0 | start: Instant::now(), |
1110 | 0 | } |
1111 | 0 | } |
1112 | | |
1113 | | /// Stop timing and record tile statistics. |
1114 | | /// |
1115 | | /// # Arguments |
1116 | | /// - `timer`: Timer handle from `start_tile()` |
1117 | | /// - `elements`: Number of elements processed by this tile |
1118 | | /// - `flops`: Number of floating-point operations performed |
1119 | 0 | pub fn stop_tile(&mut self, timer: TileTimer, elements: u64, flops: u64) { |
1120 | 0 | if !self.tile_profiling_enabled { |
1121 | 0 | return; |
1122 | 0 | } |
1123 | | |
1124 | 0 | let elapsed_ns = timer.start.elapsed().as_nanos() as u64; |
1125 | 0 | let idx = timer.level as usize; |
1126 | 0 | self.tile_stats[idx].add_sample(elapsed_ns, elements, flops); |
1127 | 0 | } |
1128 | | |
1129 | | /// Get tile statistics for a given level. |
1130 | | #[must_use] |
1131 | 0 | pub fn tile_stats(&self, level: TileLevel) -> &TileStats { |
1132 | 0 | &self.tile_stats[level as usize] |
1133 | 0 | } |
1134 | | |
1135 | | /// Get mutable tile statistics for a given level. |
1136 | 0 | pub fn tile_stats_mut(&mut self, level: TileLevel) -> &mut TileStats { |
1137 | 0 | &mut self.tile_stats[level as usize] |
1138 | 0 | } |
1139 | | |
1140 | | /// Get all tile statistics as a slice. |
1141 | | #[must_use] |
1142 | 0 | pub fn all_tile_stats(&self) -> &[TileStats; 3] { |
1143 | 0 | &self.tile_stats |
1144 | 0 | } |
1145 | | |
1146 | | /// Reset tile statistics for all levels. |
1147 | 0 | pub fn reset_tile_stats(&mut self) { |
1148 | 0 | self.tile_stats = [ |
1149 | 0 | TileStats::new(TileLevel::Macro), |
1150 | 0 | TileStats::new(TileLevel::Midi), |
1151 | 0 | TileStats::new(TileLevel::Micro), |
1152 | 0 | ]; |
1153 | 0 | } |
1154 | | |
1155 | | /// Generate tile profiling summary report. |
1156 | | /// |
1157 | | /// # Example Output |
1158 | | /// ```text |
1159 | | /// === Tile Profiling Summary (TILING-SPEC-001) === |
1160 | | /// Level Samples Avg µs GFLOP/s AI Elements |
1161 | | /// Macro 128 1234.5 12.34 0.50 1048576 |
1162 | | /// Midi 2048 78.2 45.67 2.00 65536 |
1163 | | /// Micro 32768 4.9 89.12 4.00 4096 |
1164 | | /// ``` |
1165 | | #[must_use] |
1166 | 0 | pub fn tile_summary(&self) -> String { |
1167 | 0 | let mut report = String::new(); |
1168 | 0 | report.push_str("=== Tile Profiling Summary (TILING-SPEC-001) ===\n"); |
1169 | 0 | report.push_str("Level Samples Avg µs GFLOP/s AI Elements\n"); |
1170 | | |
1171 | 0 | for stats in &self.tile_stats { |
1172 | 0 | if stats.count > 0 { |
1173 | 0 | report.push_str(&format!( |
1174 | 0 | "{:8} {:9} {:8.1} {:8.2} {:4.2} {:10}\n", |
1175 | 0 | stats.level.name(), |
1176 | 0 | stats.count, |
1177 | 0 | stats.avg_us(), |
1178 | 0 | stats.gflops(), |
1179 | 0 | stats.arithmetic_intensity(), |
1180 | 0 | stats.total_elements / stats.count.max(1) |
1181 | 0 | )); |
1182 | 0 | } |
1183 | | } |
1184 | | |
1185 | 0 | report |
1186 | 0 | } |
1187 | | |
1188 | | /// Export tile statistics as JSON. |
1189 | | /// |
1190 | | /// Compatible with pmat metrics integration. |
1191 | | #[must_use] |
1192 | 0 | pub fn tile_stats_to_json(&self) -> String { |
1193 | 0 | let tiles: Vec<String> = self |
1194 | 0 | .tile_stats |
1195 | 0 | .iter() |
1196 | 0 | .filter(|s| s.count > 0) |
1197 | 0 | .map(|s| { |
1198 | 0 | format!( |
1199 | 0 | r#"{{"level":"{}","count":{},"total_ns":{},"avg_us":{:.2},"min_us":{:.2},"max_us":{:.2},"gflops":{:.2},"arithmetic_intensity":{:.2},"total_elements":{},"total_flops":{}}}"#, |
1200 | 0 | s.level.name(), |
1201 | | s.count, |
1202 | | s.total_ns, |
1203 | 0 | s.avg_us(), |
1204 | 0 | s.min_ns as f64 / 1000.0, |
1205 | 0 | s.max_ns as f64 / 1000.0, |
1206 | 0 | s.gflops(), |
1207 | 0 | s.arithmetic_intensity(), |
1208 | | s.total_elements, |
1209 | | s.total_flops |
1210 | | ) |
1211 | 0 | }) |
1212 | 0 | .collect(); |
1213 | | |
1214 | 0 | format!( |
1215 | 0 | r#"{{"tile_profiling_enabled":{},"tiles":[{}]}}"#, |
1216 | | self.tile_profiling_enabled, |
1217 | 0 | tiles.join(",") |
1218 | | ) |
1219 | 0 | } |
1220 | | } |