1#![allow(dead_code)]
6
7pub mod events;
8pub mod gpu;
9pub mod io_monitor;
10pub mod memory;
11pub mod report;
12
13pub use events::{
15 BottleneckSeverity, BottleneckType, CpuBottleneckAnalysis, CpuProfile, HotFunction,
16 MemorySnapshot, PerformanceBottleneck, ProfileEvent, ProfileStats,
17};
18pub use gpu::{GpuKernelProfile, GpuKernelSummary, GpuMemoryPool, GpuProfiler};
19pub use io_monitor::{
20 BandwidthSample, IoDeviceType, IoMonitor, IoOperation, IoOperationType, IoPerformanceSummary,
21 IoProfile, LayerLatencyProfile,
22};
23pub use memory::{
24 MemoryAllocation, MemoryAllocationType, MemoryEfficiencyAnalysis, MemoryStats, MemoryTracker,
25};
26pub use report::{
27 EnhancedProfilerReport, LayerLatencyAnalysis, MemoryAllocationSummary, PerformanceAnalysis,
28 ProfilerReport,
29};
30
31use anyhow::Result;
32use std::collections::HashMap;
33use std::sync::{Arc, Mutex};
34use std::time::{Duration, Instant, SystemTime};
35use uuid::Uuid;
36
37use crate::DebugConfig;
38
39#[derive(Debug)]
41pub struct Profiler {
42 config: DebugConfig,
43 events: Vec<ProfileEvent>,
44 active_timers: HashMap<String, Instant>,
45 memory_snapshots: Vec<MemorySnapshot>,
46 start_time: Option<Instant>,
47 layer_profiles: HashMap<String, LayerProfile>,
48 bottlenecks: Vec<PerformanceBottleneck>,
49 gpu_kernel_profiles: Vec<GpuKernelProfile>,
51 memory_allocations: HashMap<Uuid, MemoryAllocation>,
52 layer_latency_profiles: HashMap<String, LayerLatencyProfile>,
53 io_profiles: Vec<IoProfile>,
54 cpu_bottleneck_analysis: Vec<CpuBottleneckAnalysis>,
55 memory_tracker: Arc<Mutex<MemoryTracker>>,
56 gpu_profiler: Option<GpuProfiler>,
57 io_monitor: IoMonitor,
58}
59
60#[derive(Debug)]
61pub struct LayerProfile {
62 layer_name: String,
63 forward_times: Vec<Duration>,
64 backward_times: Vec<Duration>,
65 memory_usage: Vec<usize>,
66 call_count: usize,
67}
68
69impl LayerProfile {
70 pub fn forward_times(&self) -> &Vec<Duration> {
72 &self.forward_times
73 }
74
75 pub fn backward_times(&self) -> &Vec<Duration> {
77 &self.backward_times
78 }
79
80 pub fn memory_usage(&self) -> &Vec<usize> {
82 &self.memory_usage
83 }
84
85 pub fn call_count(&self) -> usize {
87 self.call_count
88 }
89}
90
91impl Profiler {
92 pub fn new(config: &DebugConfig) -> Self {
94 Self {
95 config: config.clone(),
96 events: Vec::new(),
97 active_timers: HashMap::new(),
98 memory_snapshots: Vec::new(),
99 start_time: None,
100 layer_profiles: HashMap::new(),
101 bottlenecks: Vec::new(),
102 gpu_kernel_profiles: Vec::new(),
104 memory_allocations: HashMap::new(),
105 layer_latency_profiles: HashMap::new(),
106 io_profiles: Vec::new(),
107 cpu_bottleneck_analysis: Vec::new(),
108 memory_tracker: Arc::new(Mutex::new(MemoryTracker::new())),
109 gpu_profiler: GpuProfiler::new().ok(),
110 io_monitor: IoMonitor::new(),
111 }
112 }
113
114 pub async fn start(&mut self) -> Result<()> {
116 tracing::info!("Starting performance profiler");
117 self.start_time = Some(Instant::now());
118 self.take_memory_snapshot();
119 Ok(())
120 }
121
122 pub fn get_events(&self) -> &Vec<ProfileEvent> {
124 &self.events
125 }
126
127 pub fn start_timer(&mut self, name: &str) {
129 self.active_timers.insert(name.to_string(), Instant::now());
130 }
131
132 pub fn end_timer(&mut self, name: &str) -> Option<Duration> {
134 if let Some(start_time) = self.active_timers.remove(name) {
135 let duration = start_time.elapsed();
136
137 self.events.push(ProfileEvent::FunctionCall {
139 function_name: name.to_string(),
140 duration,
141 memory_delta: 0, });
143
144 Some(duration)
145 } else {
146 tracing::warn!("Timer '{}' was not started", name);
147 None
148 }
149 }
150
151 pub fn record_layer_execution(
153 &mut self,
154 layer_name: &str,
155 layer_type: &str,
156 forward_time: Duration,
157 backward_time: Option<Duration>,
158 memory_usage: usize,
159 parameter_count: usize,
160 ) {
161 self.events.push(ProfileEvent::LayerExecution {
163 layer_name: layer_name.to_string(),
164 layer_type: layer_type.to_string(),
165 forward_time,
166 backward_time,
167 memory_usage,
168 parameter_count,
169 });
170
171 let profile =
173 self.layer_profiles
174 .entry(layer_name.to_string())
175 .or_insert_with(|| LayerProfile {
176 layer_name: layer_name.to_string(),
177 forward_times: Vec::new(),
178 backward_times: Vec::new(),
179 memory_usage: Vec::new(),
180 call_count: 0,
181 });
182
183 profile.forward_times.push(forward_time);
184 if let Some(backward) = backward_time {
185 profile.backward_times.push(backward);
186 }
187 profile.memory_usage.push(memory_usage);
188 profile.call_count += 1;
189 }
190
191 pub fn record_tensor_operation(
193 &mut self,
194 operation: &str,
195 tensor_shape: &[usize],
196 duration: Duration,
197 memory_allocated: usize,
198 ) {
199 self.events.push(ProfileEvent::TensorOperation {
200 operation: operation.to_string(),
201 tensor_shape: tensor_shape.to_vec(),
202 duration,
203 memory_allocated,
204 });
205 }
206
207 pub fn record_model_inference(
209 &mut self,
210 batch_size: usize,
211 sequence_length: usize,
212 duration: Duration,
213 ) {
214 let tokens_per_second = (batch_size * sequence_length) as f64 / duration.as_secs_f64();
215
216 self.events.push(ProfileEvent::ModelInference {
217 batch_size,
218 sequence_length,
219 duration,
220 tokens_per_second,
221 });
222 }
223
224 pub fn record_gradient_computation(
226 &mut self,
227 layer_name: &str,
228 gradient_norm: f64,
229 duration: Duration,
230 ) {
231 self.events.push(ProfileEvent::GradientComputation {
232 layer_name: layer_name.to_string(),
233 gradient_norm,
234 duration,
235 });
236 }
237
238 pub fn take_memory_snapshot(&mut self) {
240 let snapshot = MemorySnapshot {
242 timestamp: chrono::Utc::now(),
243 heap_allocated: 0, heap_used: 0,
245 stack_size: 0,
246 gpu_allocated: None,
247 gpu_used: None,
248 };
249
250 self.memory_snapshots.push(snapshot);
251
252 if self.memory_snapshots.len() > 1000 {
254 self.memory_snapshots.drain(0..500);
255 }
256 }
257
258 pub fn analyze_performance(&mut self) -> Vec<PerformanceBottleneck> {
260 self.bottlenecks.clear();
261
262 self.analyze_layer_bottlenecks();
264
265 self.analyze_memory_bottlenecks();
267
268 self.analyze_tensor_bottlenecks();
270
271 self.bottlenecks.clone()
272 }
273
274 pub fn get_statistics(&self) -> HashMap<String, ProfileStats> {
276 let mut stats = HashMap::new();
277
278 let mut grouped_events: HashMap<String, Vec<&ProfileEvent>> = HashMap::new();
280
281 for event in &self.events {
282 let event_type = match event {
283 ProfileEvent::FunctionCall { .. } => "FunctionCall",
284 ProfileEvent::LayerExecution { .. } => "LayerExecution",
285 ProfileEvent::TensorOperation { .. } => "TensorOperation",
286 ProfileEvent::ModelInference { .. } => "ModelInference",
287 ProfileEvent::GradientComputation { .. } => "GradientComputation",
288 };
289
290 grouped_events.entry(event_type.to_string()).or_default().push(event);
291 }
292
293 for (event_type, events) in grouped_events {
295 let durations: Vec<Duration> = events
296 .iter()
297 .filter_map(|event| match event {
298 ProfileEvent::FunctionCall { duration, .. } => Some(*duration),
299 ProfileEvent::LayerExecution { forward_time, .. } => Some(*forward_time),
300 ProfileEvent::TensorOperation { duration, .. } => Some(*duration),
301 ProfileEvent::ModelInference { duration, .. } => Some(*duration),
302 ProfileEvent::GradientComputation { duration, .. } => Some(*duration),
303 })
304 .collect();
305
306 if !durations.is_empty() {
307 let total_duration: Duration = durations.iter().sum();
308 let avg_duration = total_duration / durations.len() as u32;
309 let min_duration = durations.iter().min().copied().unwrap_or_default();
310 let max_duration = durations.iter().max().copied().unwrap_or_default();
311
312 stats.insert(
313 event_type.clone(),
314 ProfileStats {
315 event_type,
316 count: durations.len(),
317 total_duration,
318 avg_duration,
319 min_duration,
320 max_duration,
321 total_memory: 0, avg_memory: 0.0,
323 },
324 );
325 }
326 }
327
328 stats
329 }
330
331 pub fn get_layer_profiles(&self) -> &HashMap<String, LayerProfile> {
333 &self.layer_profiles
334 }
335
336 pub fn get_memory_timeline(&self) -> &[MemorySnapshot] {
338 &self.memory_snapshots
339 }
340
341 pub async fn generate_report(&self) -> Result<ProfilerReport> {
343 let statistics = self.get_statistics();
344 let bottlenecks = self.bottlenecks.clone();
345 let total_events = self.events.len();
346
347 let total_runtime =
348 if let Some(start) = self.start_time { start.elapsed() } else { Duration::ZERO };
349
350 let slowest_layers = self.get_slowest_layers(5);
352
353 let memory_efficiency = self.analyze_memory_efficiency();
355
356 Ok(ProfilerReport {
357 total_events,
358 total_runtime,
359 statistics,
360 bottlenecks,
361 slowest_layers,
362 memory_efficiency,
363 recommendations: self.generate_performance_recommendations(),
364 })
365 }
366
367 pub fn clear(&mut self) {
369 self.events.clear();
370 self.active_timers.clear();
371 self.memory_snapshots.clear();
372 self.layer_profiles.clear();
373 self.bottlenecks.clear();
374 self.start_time = None;
375 self.gpu_kernel_profiles.clear();
377 self.memory_allocations.clear();
378 self.layer_latency_profiles.clear();
379 self.io_profiles.clear();
380 self.cpu_bottleneck_analysis.clear();
381 if let Ok(mut tracker) = self.memory_tracker.lock() {
382 *tracker = MemoryTracker::new();
383 }
384 self.io_monitor = IoMonitor::new();
385 }
386
387 pub fn profile_gpu_kernel(&mut self, kernel_profile: GpuKernelProfile) {
391 if let Some(ref mut gpu_profiler) = self.gpu_profiler {
392 gpu_profiler.profile_kernel(kernel_profile.clone());
393 }
394 self.gpu_kernel_profiles.push(kernel_profile);
395 }
396
397 pub fn track_memory_allocation(
399 &mut self,
400 size_bytes: usize,
401 allocation_type: MemoryAllocationType,
402 device_id: Option<i32>,
403 stack_trace: Vec<String>,
404 ) -> Uuid {
405 let allocation_id = Uuid::new_v4();
406 let allocation = MemoryAllocation {
407 allocation_id,
408 size_bytes,
409 allocation_type,
410 device_id,
411 timestamp: SystemTime::now(),
412 stack_trace,
413 freed: false,
414 free_timestamp: None,
415 };
416
417 if let Ok(mut tracker) = self.memory_tracker.lock() {
418 tracker.track_allocation(allocation.clone());
419 }
420
421 self.memory_allocations.insert(allocation_id, allocation);
422 allocation_id
423 }
424
425 pub fn track_memory_deallocation(&mut self, allocation_id: Uuid) {
427 if let Some(allocation) = self.memory_allocations.get_mut(&allocation_id) {
428 allocation.freed = true;
429 allocation.free_timestamp = Some(SystemTime::now());
430 }
431
432 if let Ok(mut tracker) = self.memory_tracker.lock() {
433 tracker.track_deallocation(allocation_id);
434 }
435 }
436
437 pub fn profile_layer_latency(&mut self, layer_latency: LayerLatencyProfile) {
439 self.layer_latency_profiles
440 .insert(layer_latency.layer_name.clone(), layer_latency);
441 }
442
443 pub fn start_io_profiling(
445 &mut self,
446 operation_type: IoOperationType,
447 bytes_expected: usize,
448 ) -> Uuid {
449 self.io_monitor.start_io_operation(operation_type, bytes_expected)
450 }
451
452 pub fn finish_io_profiling(&mut self, operation_id: Uuid, bytes_transferred: usize) {
454 if let Some(profile) = self.io_monitor.finish_io_operation(operation_id, bytes_transferred)
455 {
456 self.io_profiles.push(profile);
457 }
458 }
459
460 pub fn analyze_cpu_bottlenecks(&mut self) -> Vec<CpuBottleneckAnalysis> {
462 let analysis = CpuBottleneckAnalysis {
465 thread_id: 0, cpu_usage: 0.75, context_switches: 1000,
468 cache_misses: 500,
469 instructions_per_cycle: 2.5,
470 branch_mispredictions: 100,
471 hot_functions: vec![
472 HotFunction {
473 function_name: "tensor_multiply".to_string(),
474 self_time_percentage: 25.0,
475 call_count: 1000,
476 avg_time_per_call: Duration::from_micros(250),
477 },
478 HotFunction {
479 function_name: "gradient_computation".to_string(),
480 self_time_percentage: 20.0,
481 call_count: 500,
482 avg_time_per_call: Duration::from_micros(400),
483 },
484 ],
485 bottleneck_score: 0.6,
486 };
487
488 self.cpu_bottleneck_analysis.push(analysis.clone());
489 vec![analysis]
490 }
491
492 pub fn get_memory_stats(&self) -> Option<MemoryStats> {
494 if let Ok(tracker) = self.memory_tracker.lock() {
495 Some(tracker.get_memory_stats())
496 } else {
497 None
498 }
499 }
500
501 pub fn get_gpu_utilization(&self, device_id: i32) -> Option<f64> {
503 self.gpu_profiler
504 .as_ref()
505 .map(|profiler| profiler.get_gpu_utilization(device_id))
506 }
507
508 pub fn get_io_bandwidth_stats(&self) -> HashMap<IoDeviceType, f64> {
510 let mut stats = HashMap::new();
511
512 stats.insert(
513 IoDeviceType::SSD,
514 self.io_monitor.get_average_bandwidth(&IoDeviceType::SSD),
515 );
516 stats.insert(
517 IoDeviceType::HDD,
518 self.io_monitor.get_average_bandwidth(&IoDeviceType::HDD),
519 );
520 stats.insert(
521 IoDeviceType::Network,
522 self.io_monitor.get_average_bandwidth(&IoDeviceType::Network),
523 );
524 stats.insert(
525 IoDeviceType::Memory,
526 self.io_monitor.get_average_bandwidth(&IoDeviceType::Memory),
527 );
528 stats.insert(
529 IoDeviceType::Cache,
530 self.io_monitor.get_average_bandwidth(&IoDeviceType::Cache),
531 );
532
533 stats
534 }
535
536 pub fn get_layer_latency_analysis(&self) -> Vec<LayerLatencyAnalysis> {
538 self.layer_latency_profiles
539 .values()
540 .map(|profile| LayerLatencyAnalysis {
541 layer_name: profile.layer_name.clone(),
542 layer_type: profile.layer_type.clone(),
543 total_time: profile.cpu_time
544 + profile.gpu_time
545 + profile.memory_copy_time
546 + profile.sync_time,
547 cpu_percentage: profile.cpu_time.as_secs_f64()
548 / (profile.cpu_time
549 + profile.gpu_time
550 + profile.memory_copy_time
551 + profile.sync_time)
552 .as_secs_f64()
553 * 100.0,
554 gpu_percentage: profile.gpu_time.as_secs_f64()
555 / (profile.cpu_time
556 + profile.gpu_time
557 + profile.memory_copy_time
558 + profile.sync_time)
559 .as_secs_f64()
560 * 100.0,
561 memory_copy_percentage: profile.memory_copy_time.as_secs_f64()
562 / (profile.cpu_time
563 + profile.gpu_time
564 + profile.memory_copy_time
565 + profile.sync_time)
566 .as_secs_f64()
567 * 100.0,
568 flops_per_second: if profile.gpu_time.as_secs_f64() > 0.0 {
569 profile.flops as f64 / profile.gpu_time.as_secs_f64()
570 } else {
571 0.0
572 },
573 memory_bandwidth_utilization: profile.cache_hit_rate,
574 bottleneck_type: self.identify_layer_bottleneck(profile),
575 })
576 .collect()
577 }
578
579 pub fn get_performance_analysis(&self) -> PerformanceAnalysis {
581 let memory_stats = self.get_memory_stats();
582 let io_bandwidth_stats = self.get_io_bandwidth_stats();
583 let layer_analysis = self.get_layer_latency_analysis();
584
585 let gpu_utilization =
586 self.gpu_profiler.as_ref().map(|profiler| profiler.get_gpu_utilization(0));
587
588 PerformanceAnalysis {
589 memory_stats,
590 io_bandwidth_stats,
591 layer_analysis,
592 gpu_utilization,
593 cpu_bottlenecks: self.cpu_bottleneck_analysis.clone(),
594 total_gpu_kernels: self.gpu_kernel_profiles.len(),
595 total_io_operations: self.io_profiles.len(),
596 performance_score: self.calculate_overall_performance_score(),
597 recommendations: self.generate_enhanced_recommendations(),
598 }
599 }
600
601 fn identify_layer_bottleneck(&self, profile: &LayerLatencyProfile) -> String {
602 let total_time =
603 profile.cpu_time + profile.gpu_time + profile.memory_copy_time + profile.sync_time;
604
605 if profile.memory_copy_time > total_time / 2 {
606 "Memory Bandwidth".to_string()
607 } else if profile.sync_time > total_time / 3 {
608 "GPU Synchronization".to_string()
609 } else if profile.gpu_time > profile.cpu_time * 10 {
610 "GPU Compute".to_string()
611 } else {
612 "CPU Compute".to_string()
613 }
614 }
615
616 fn calculate_overall_performance_score(&self) -> f64 {
617 let mut score: f64 = 100.0;
618
619 for bottleneck in &self.bottlenecks {
621 match bottleneck.severity {
622 BottleneckSeverity::Critical => score -= 20.0,
623 BottleneckSeverity::High => score -= 10.0,
624 BottleneckSeverity::Medium => score -= 5.0,
625 BottleneckSeverity::Low => score -= 2.0,
626 }
627 }
628
629 if let Some(gpu_util) = self.get_gpu_utilization(0) {
631 if gpu_util < 0.5 {
632 score -= 15.0;
633 } else if gpu_util < 0.7 {
634 score -= 8.0;
635 }
636 }
637
638 if let Some(memory_stats) = self.get_memory_stats() {
640 if memory_stats.memory_efficiency < 0.8 {
641 score -= 10.0;
642 }
643 }
644
645 score.max(0.0)
646 }
647
648 fn generate_enhanced_recommendations(&self) -> Vec<String> {
649 let mut recommendations = Vec::new();
650
651 if let Some(gpu_util) = self.get_gpu_utilization(0) {
653 if gpu_util < 0.5 {
654 recommendations.push("Low GPU utilization detected. Consider increasing batch size or optimizing GPU kernels.".to_string());
655 }
656 }
657
658 if let Some(memory_stats) = self.get_memory_stats() {
660 if memory_stats.memory_efficiency < 0.8 {
661 recommendations.push("Memory allocation efficiency is low. Consider memory pooling or reducing allocations.".to_string());
662 }
663
664 if memory_stats.active_allocations > 10000 {
665 recommendations.push("High number of active memory allocations. Consider batch allocation strategies.".to_string());
666 }
667 }
668
669 let io_stats = self.get_io_bandwidth_stats();
671 if let Some(&ssd_bandwidth) = io_stats.get(&IoDeviceType::SSD) {
672 if ssd_bandwidth < 100.0 {
673 recommendations.push(
675 "Low SSD bandwidth utilization. Consider optimizing file I/O patterns."
676 .to_string(),
677 );
678 }
679 }
680
681 let layer_analysis = self.get_layer_latency_analysis();
683 for analysis in &layer_analysis {
684 if analysis.memory_copy_percentage > 50.0 {
685 recommendations.push(format!(
686 "Layer '{}' is memory bandwidth bound. Consider data layout optimization.",
687 analysis.layer_name
688 ));
689 }
690
691 if analysis.cpu_percentage > 80.0 {
692 recommendations.push(format!(
693 "Layer '{}' is CPU bound. Consider GPU acceleration.",
694 analysis.layer_name
695 ));
696 }
697 }
698
699 if recommendations.is_empty() {
700 recommendations
701 .push("Performance appears optimal based on current analysis.".to_string());
702 }
703
704 recommendations
705 }
706
707 fn analyze_layer_bottlenecks(&mut self) {
710 for (layer_name, profile) in &self.layer_profiles {
711 if profile.forward_times.is_empty() {
712 continue;
713 }
714
715 let avg_forward_time =
716 profile.forward_times.iter().sum::<Duration>() / profile.forward_times.len() as u32;
717
718 if avg_forward_time.as_millis() > 100 {
720 let mut metrics = HashMap::new();
721 metrics.insert(
722 "avg_forward_time_ms".to_string(),
723 avg_forward_time.as_millis() as f64,
724 );
725 metrics.insert("call_count".to_string(), profile.call_count as f64);
726
727 self.bottlenecks.push(PerformanceBottleneck {
728 bottleneck_type: BottleneckType::ModelComputation,
729 location: layer_name.clone(),
730 severity: if avg_forward_time.as_millis() > 500 {
731 BottleneckSeverity::High
732 } else {
733 BottleneckSeverity::Medium
734 },
735 description: format!(
736 "Layer '{}' has slow forward pass: {:.1}ms average",
737 layer_name,
738 avg_forward_time.as_millis()
739 ),
740 suggestion: "Consider optimizing layer implementation or reducing layer size"
741 .to_string(),
742 metrics,
743 });
744 }
745 }
746 }
747
748 fn analyze_memory_bottlenecks(&mut self) {
749 if self.memory_snapshots.len() < 2 {
750 return;
751 }
752
753 let recent_snapshots = if self.memory_snapshots.len() > 10 {
755 &self.memory_snapshots[self.memory_snapshots.len() - 10..]
756 } else {
757 &self.memory_snapshots
758 };
759
760 if recent_snapshots.len() >= 5 {
761 let initial_memory = recent_snapshots[0].heap_allocated;
762 let final_memory = recent_snapshots.last().map(|s| s.heap_allocated).unwrap_or(0);
763
764 if final_memory > initial_memory * 2 {
765 let mut metrics = HashMap::new();
766 metrics.insert(
767 "initial_memory_mb".to_string(),
768 initial_memory as f64 / (1024.0 * 1024.0),
769 );
770 metrics.insert(
771 "final_memory_mb".to_string(),
772 final_memory as f64 / (1024.0 * 1024.0),
773 );
774 metrics.insert(
775 "growth_ratio".to_string(),
776 final_memory as f64 / initial_memory as f64,
777 );
778
779 self.bottlenecks.push(PerformanceBottleneck {
780 bottleneck_type: BottleneckType::MemoryBound,
781 location: "Memory Usage".to_string(),
782 severity: BottleneckSeverity::High,
783 description: "Significant memory growth detected during profiling".to_string(),
784 suggestion: "Check for memory leaks or inefficient memory usage patterns"
785 .to_string(),
786 metrics,
787 });
788 }
789 }
790 }
791
792 fn analyze_tensor_bottlenecks(&mut self) {
793 let mut operation_groups: HashMap<String, Vec<Duration>> = HashMap::new();
795
796 for event in &self.events {
797 if let ProfileEvent::TensorOperation {
798 operation,
799 duration,
800 ..
801 } = event
802 {
803 operation_groups.entry(operation.clone()).or_default().push(*duration);
804 }
805 }
806
807 for (operation, durations) in operation_groups {
809 if durations.is_empty() {
810 continue;
811 }
812
813 let avg_duration = durations.iter().sum::<Duration>() / durations.len() as u32;
814 let total_time = durations.iter().sum::<Duration>();
815
816 if avg_duration.as_millis() > 10 {
818 let mut metrics = HashMap::new();
819 metrics.insert(
820 "avg_duration_ms".to_string(),
821 avg_duration.as_millis() as f64,
822 );
823 metrics.insert("total_time_ms".to_string(), total_time.as_millis() as f64);
824 metrics.insert("call_count".to_string(), durations.len() as f64);
825
826 self.bottlenecks.push(PerformanceBottleneck {
827 bottleneck_type: BottleneckType::CpuBound,
828 location: format!("Tensor Operation: {}", operation),
829 severity: if avg_duration.as_millis() > 50 {
830 BottleneckSeverity::High
831 } else {
832 BottleneckSeverity::Medium
833 },
834 description: format!(
835 "Tensor operation '{}' is slow: {:.1}ms average",
836 operation,
837 avg_duration.as_millis()
838 ),
839 suggestion:
840 "Consider optimizing tensor operation or using different data types"
841 .to_string(),
842 metrics,
843 });
844 }
845 }
846 }
847
848 fn get_slowest_layers(&self, limit: usize) -> Vec<(String, Duration)> {
849 let mut layer_times: Vec<(String, Duration)> = self
850 .layer_profiles
851 .iter()
852 .map(|(name, profile)| {
853 let avg_time = if profile.forward_times.is_empty() {
854 Duration::ZERO
855 } else {
856 profile.forward_times.iter().sum::<Duration>()
857 / profile.forward_times.len() as u32
858 };
859 (name.clone(), avg_time)
860 })
861 .collect();
862
863 layer_times.sort_by_key(|item| std::cmp::Reverse(item.1));
864 layer_times.truncate(limit);
865 layer_times
866 }
867
868 fn analyze_memory_efficiency(&self) -> MemoryEfficiencyAnalysis {
869 if self.memory_snapshots.is_empty() {
870 return MemoryEfficiencyAnalysis::default();
871 }
872
873 let memory_values: Vec<usize> =
874 self.memory_snapshots.iter().map(|snapshot| snapshot.heap_allocated).collect();
875
876 let max_memory = memory_values.iter().max().copied().unwrap_or(0);
877 let min_memory = memory_values.iter().min().copied().unwrap_or(0);
878 let avg_memory = memory_values.iter().sum::<usize>() / memory_values.len();
879
880 MemoryEfficiencyAnalysis {
881 peak_memory_mb: max_memory as f64 / (1024.0 * 1024.0),
882 min_memory_mb: min_memory as f64 / (1024.0 * 1024.0),
883 avg_memory_mb: avg_memory as f64 / (1024.0 * 1024.0),
884 memory_variance: self.calculate_memory_variance(&memory_values, avg_memory),
885 efficiency_score: self.calculate_memory_efficiency_score(&memory_values),
886 }
887 }
888
889 fn calculate_memory_variance(&self, values: &[usize], mean: usize) -> f64 {
890 if values.len() < 2 {
891 return 0.0;
892 }
893
894 let variance_sum: f64 = values
895 .iter()
896 .map(|&x| {
897 let diff = x as f64 - mean as f64;
898 diff * diff
899 })
900 .sum();
901
902 variance_sum / (values.len() - 1) as f64
903 }
904
905 fn calculate_memory_efficiency_score(&self, values: &[usize]) -> f64 {
906 if values.is_empty() {
907 return 0.0;
908 }
909
910 let max_memory = values.iter().max().copied().unwrap_or(0);
911 let min_memory = values.iter().min().copied().unwrap_or(0);
912
913 if max_memory == 0 {
914 return 100.0;
915 }
916
917 100.0 * (1.0 - (max_memory - min_memory) as f64 / max_memory as f64)
919 }
920
921 fn generate_performance_recommendations(&self) -> Vec<String> {
922 let mut recommendations = Vec::new();
923
924 for bottleneck in &self.bottlenecks {
926 match bottleneck.bottleneck_type {
927 BottleneckType::ModelComputation => {
928 recommendations.push(
929 "Consider model architecture optimizations or layer fusion".to_string(),
930 );
931 },
932 BottleneckType::MemoryBound => {
933 recommendations.push(
934 "Optimize memory usage with gradient checkpointing or model parallelism"
935 .to_string(),
936 );
937 },
938 BottleneckType::CpuBound => {
939 recommendations.push(
940 "Consider GPU acceleration or optimized CPU implementations".to_string(),
941 );
942 },
943 _ => {},
944 }
945 }
946
947 if self.events.len() > 10000 {
949 recommendations.push(
950 "High number of profiling events - consider reducing profiling overhead"
951 .to_string(),
952 );
953 }
954
955 let stats = self.get_statistics();
956 if let Some(layer_stats) = stats.get("LayerExecution") {
957 if layer_stats.avg_duration.as_millis() > 50 {
958 recommendations.push(
959 "Average layer execution time is high - consider layer optimization"
960 .to_string(),
961 );
962 }
963 }
964
965 if recommendations.is_empty() {
966 recommendations
967 .push("Performance appears optimal based on current profiling data".to_string());
968 }
969
970 recommendations
971 }
972
973 pub async fn generate_enhanced_report(&self) -> Result<EnhancedProfilerReport> {
975 let basic_report = self.generate_report().await?;
976 let performance_analysis = self.get_performance_analysis();
977
978 let gpu_kernel_summary = self.generate_gpu_kernel_summary();
979 let memory_allocation_summary = self.generate_memory_allocation_summary();
980 let io_performance_summary = self.generate_io_performance_summary();
981
982 Ok(EnhancedProfilerReport {
983 basic_report,
984 performance_analysis,
985 gpu_kernel_summary,
986 memory_allocation_summary,
987 io_performance_summary,
988 })
989 }
990
991 fn generate_gpu_kernel_summary(&self) -> GpuKernelSummary {
992 let total_kernels = self.gpu_kernel_profiles.len();
993 let total_execution_time = self.gpu_kernel_profiles.iter().map(|k| k.execution_time).sum();
994
995 let avg_occupancy = if total_kernels > 0 {
996 self.gpu_kernel_profiles.iter().map(|k| k.occupancy).sum::<f64>() / total_kernels as f64
997 } else {
998 0.0
999 };
1000
1001 let avg_compute_utilization = if total_kernels > 0 {
1002 self.gpu_kernel_profiles.iter().map(|k| k.compute_utilization).sum::<f64>()
1003 / total_kernels as f64
1004 } else {
1005 0.0
1006 };
1007
1008 let mut kernels_by_time: Vec<_> = self
1009 .gpu_kernel_profiles
1010 .iter()
1011 .map(|k| (k.kernel_name.clone(), k.execution_time))
1012 .collect();
1013 kernels_by_time.sort_by_key(|item| std::cmp::Reverse(item.1));
1014
1015 let slowest_kernels = kernels_by_time.into_iter().take(5).map(|(name, _)| name).collect();
1016
1017 GpuKernelSummary {
1018 total_kernels,
1019 total_execution_time,
1020 avg_occupancy,
1021 avg_compute_utilization,
1022 slowest_kernels,
1023 }
1024 }
1025
1026 fn generate_memory_allocation_summary(&self) -> MemoryAllocationSummary {
1027 let total_allocations = self.memory_allocations.len();
1028 let peak_memory_usage =
1029 self.memory_allocations.values().map(|a| a.size_bytes).max().unwrap_or(0);
1030
1031 let memory_efficiency = if let Some(stats) = self.get_memory_stats() {
1032 stats.memory_efficiency
1033 } else {
1034 1.0
1035 };
1036
1037 let mut allocations_by_size: Vec<_> = self
1038 .memory_allocations
1039 .values()
1040 .map(|a| (format!("{} bytes", a.size_bytes), a.size_bytes))
1041 .collect();
1042 allocations_by_size.sort_by_key(|item| std::cmp::Reverse(item.1));
1043
1044 let largest_allocations =
1045 allocations_by_size.into_iter().take(5).map(|(desc, _)| desc).collect();
1046
1047 let memory_leaks = self.memory_allocations.values().filter(|a| !a.freed).count();
1048
1049 MemoryAllocationSummary {
1050 total_allocations,
1051 peak_memory_usage,
1052 memory_efficiency,
1053 largest_allocations,
1054 memory_leaks,
1055 }
1056 }
1057
1058 fn generate_io_performance_summary(&self) -> IoPerformanceSummary {
1059 let total_operations = self.io_profiles.len();
1060 let total_bytes_transferred = self.io_profiles.iter().map(|io| io.bytes_transferred).sum();
1061
1062 let avg_bandwidth_by_device = self.get_io_bandwidth_stats();
1063
1064 let mut operations_by_duration: Vec<_> = self
1065 .io_profiles
1066 .iter()
1067 .map(|io| {
1068 (
1069 format!("{:?}: {} bytes", io.operation_type, io.bytes_transferred),
1070 io.duration,
1071 )
1072 })
1073 .collect();
1074 operations_by_duration.sort_by_key(|item| std::cmp::Reverse(item.1));
1075
1076 let slowest_operations =
1077 operations_by_duration.into_iter().take(5).map(|(desc, _)| desc).collect();
1078
1079 IoPerformanceSummary {
1080 total_operations,
1081 total_bytes_transferred,
1082 avg_bandwidth_by_device,
1083 slowest_operations,
1084 }
1085 }
1086}
1087
1088pub struct ScopedTimer<'a> {
1090 profiler: &'a mut Profiler,
1091 name: String,
1092}
1093
1094impl<'a> ScopedTimer<'a> {
1095 pub fn new(profiler: &'a mut Profiler, name: String) -> Self {
1096 profiler.start_timer(&name);
1097 Self { profiler, name }
1098 }
1099}
1100
1101impl<'a> Drop for ScopedTimer<'a> {
1102 fn drop(&mut self) {
1103 self.profiler.end_timer(&self.name);
1104 }
1105}
1106
1107#[macro_export]
1109macro_rules! profile_scope {
1110 ($profiler:expr, $name:expr) => {
1111 let _timer = ScopedTimer::new($profiler, $name.to_string());
1112 };
1113}
1114
1115#[cfg(test)]
1116mod tests {
1117 use super::*;
1118
1119 fn make_config() -> DebugConfig {
1120 DebugConfig::default()
1121 }
1122
1123 #[test]
1126 fn test_profiler_new() {
1127 let config = make_config();
1128 let profiler = Profiler::new(&config);
1129 assert!(profiler.events.is_empty());
1130 assert!(profiler.active_timers.is_empty());
1131 assert!(profiler.start_time.is_none());
1132 }
1133
1134 #[test]
1135 fn test_profiler_start_end_timer() {
1136 let config = make_config();
1137 let mut profiler = Profiler::new(&config);
1138 profiler.start_timer("test_op");
1139 let duration = profiler.end_timer("test_op");
1140 assert!(duration.is_some());
1141 assert_eq!(profiler.events.len(), 1);
1142 }
1143
1144 #[test]
1145 fn test_profiler_end_timer_not_started() {
1146 let config = make_config();
1147 let mut profiler = Profiler::new(&config);
1148 let duration = profiler.end_timer("nonexistent");
1149 assert!(duration.is_none());
1150 }
1151
1152 #[test]
1153 fn test_profiler_record_layer_execution() {
1154 let config = make_config();
1155 let mut profiler = Profiler::new(&config);
1156 profiler.record_layer_execution(
1157 "attention",
1158 "self_attention",
1159 Duration::from_millis(50),
1160 Some(Duration::from_millis(30)),
1161 1024,
1162 1000,
1163 );
1164 assert_eq!(profiler.events.len(), 1);
1165 let profiles = profiler.get_layer_profiles();
1166 assert!(profiles.contains_key("attention"));
1167 let lp = &profiles["attention"];
1168 assert_eq!(lp.call_count(), 1);
1169 assert_eq!(lp.forward_times().len(), 1);
1170 assert_eq!(lp.backward_times().len(), 1);
1171 }
1172
1173 #[test]
1174 fn test_profiler_record_tensor_operation() {
1175 let config = make_config();
1176 let mut profiler = Profiler::new(&config);
1177 profiler.record_tensor_operation("matmul", &[64, 128], Duration::from_micros(200), 8192);
1178 assert_eq!(profiler.events.len(), 1);
1179 }
1180
1181 #[test]
1182 fn test_profiler_record_model_inference() {
1183 let config = make_config();
1184 let mut profiler = Profiler::new(&config);
1185 profiler.record_model_inference(32, 512, Duration::from_millis(100));
1186 assert_eq!(profiler.events.len(), 1);
1187 }
1188
1189 #[test]
1190 fn test_profiler_record_gradient_computation() {
1191 let config = make_config();
1192 let mut profiler = Profiler::new(&config);
1193 profiler.record_gradient_computation("fc1", 0.5, Duration::from_millis(10));
1194 assert_eq!(profiler.events.len(), 1);
1195 }
1196
1197 #[test]
1198 fn test_profiler_get_statistics_empty() {
1199 let config = make_config();
1200 let profiler = Profiler::new(&config);
1201 let stats = profiler.get_statistics();
1202 assert!(stats.is_empty());
1203 }
1204
1205 #[test]
1206 fn test_profiler_get_statistics_with_events() {
1207 let config = make_config();
1208 let mut profiler = Profiler::new(&config);
1209 profiler.record_model_inference(8, 256, Duration::from_millis(50));
1210 profiler.record_model_inference(8, 256, Duration::from_millis(100));
1211 let stats = profiler.get_statistics();
1212 assert!(stats.contains_key("ModelInference"));
1213 let mi_stats = &stats["ModelInference"];
1214 assert_eq!(mi_stats.count, 2);
1215 }
1216
1217 #[test]
1218 fn test_profiler_clear() {
1219 let config = make_config();
1220 let mut profiler = Profiler::new(&config);
1221 profiler.start_timer("op1");
1222 profiler.end_timer("op1");
1223 profiler.take_memory_snapshot();
1224 profiler.clear();
1225 assert!(profiler.events.is_empty());
1226 assert!(profiler.active_timers.is_empty());
1227 assert!(profiler.memory_snapshots.is_empty());
1228 assert!(profiler.start_time.is_none());
1229 }
1230
1231 #[test]
1232 fn test_profiler_take_memory_snapshot() {
1233 let config = make_config();
1234 let mut profiler = Profiler::new(&config);
1235 profiler.take_memory_snapshot();
1236 assert_eq!(profiler.get_memory_timeline().len(), 1);
1237 }
1238
1239 #[test]
1240 fn test_profiler_memory_snapshot_limit() {
1241 let config = make_config();
1242 let mut profiler = Profiler::new(&config);
1243 for _ in 0..1100 {
1244 profiler.take_memory_snapshot();
1245 }
1246 assert!(profiler.get_memory_timeline().len() <= 601);
1248 }
1249
1250 #[test]
1251 fn test_profiler_analyze_performance_empty() {
1252 let config = make_config();
1253 let mut profiler = Profiler::new(&config);
1254 let bottlenecks = profiler.analyze_performance();
1255 assert!(bottlenecks.is_empty());
1256 }
1257
1258 #[test]
1259 fn test_profiler_analyze_performance_slow_layer() {
1260 let config = make_config();
1261 let mut profiler = Profiler::new(&config);
1262 for _ in 0..5 {
1263 profiler.record_layer_execution(
1264 "slow_layer",
1265 "dense",
1266 Duration::from_millis(600),
1267 None,
1268 4096,
1269 10000,
1270 );
1271 }
1272 let bottlenecks = profiler.analyze_performance();
1273 assert!(!bottlenecks.is_empty());
1274 }
1275
1276 #[test]
1277 fn test_profiler_get_slowest_layers() {
1278 let config = make_config();
1279 let mut profiler = Profiler::new(&config);
1280 profiler.record_layer_execution(
1281 "fast_layer",
1282 "relu",
1283 Duration::from_millis(1),
1284 None,
1285 128,
1286 0,
1287 );
1288 profiler.record_layer_execution(
1289 "slow_layer",
1290 "dense",
1291 Duration::from_millis(200),
1292 None,
1293 4096,
1294 10000,
1295 );
1296 let slowest = profiler.get_slowest_layers(2);
1297 assert_eq!(slowest.len(), 2);
1298 assert_eq!(slowest[0].0, "slow_layer");
1299 }
1300
1301 #[test]
1302 fn test_profiler_memory_efficiency_empty() {
1303 let config = make_config();
1304 let profiler = Profiler::new(&config);
1305 let analysis = profiler.analyze_memory_efficiency();
1306 assert!((analysis.efficiency_score - 100.0).abs() < 1e-9);
1307 }
1308
1309 #[test]
1310 fn test_profiler_calculate_memory_variance() {
1311 let config = make_config();
1312 let profiler = Profiler::new(&config);
1313 let values = vec![100, 200, 300];
1314 let mean = 200;
1315 let variance = profiler.calculate_memory_variance(&values, mean);
1316 assert!((variance - 10000.0).abs() < 1e-3);
1318 }
1319
1320 #[test]
1321 fn test_profiler_calculate_memory_efficiency_score_empty() {
1322 let config = make_config();
1323 let profiler = Profiler::new(&config);
1324 let score = profiler.calculate_memory_efficiency_score(&[]);
1325 assert!((score - 0.0).abs() < 1e-9);
1326 }
1327
1328 #[test]
1329 fn test_profiler_calculate_memory_efficiency_score_stable() {
1330 let config = make_config();
1331 let profiler = Profiler::new(&config);
1332 let values = vec![100, 100, 100];
1333 let score = profiler.calculate_memory_efficiency_score(&values);
1334 assert!((score - 100.0).abs() < 1e-9);
1335 }
1336
1337 #[test]
1338 fn test_profiler_calculate_memory_efficiency_score_varied() {
1339 let config = make_config();
1340 let profiler = Profiler::new(&config);
1341 let values = vec![50, 100];
1342 let score = profiler.calculate_memory_efficiency_score(&values);
1343 assert!((score - 50.0).abs() < 1e-9);
1345 }
1346
1347 #[test]
1348 fn test_profiler_overall_performance_score_no_bottlenecks() {
1349 let config = make_config();
1350 let profiler = Profiler::new(&config);
1351 let score = profiler.calculate_overall_performance_score();
1352 assert!(score >= 50.0);
1354 assert!(score <= 100.0);
1355 }
1356
1357 #[test]
1358 fn test_profiler_identify_layer_bottleneck_memory() {
1359 let config = make_config();
1360 let profiler = Profiler::new(&config);
1361 let profile = LayerLatencyProfile {
1362 layer_name: "test".to_string(),
1363 layer_type: "dense".to_string(),
1364 input_shapes: vec![vec![32, 128]],
1365 output_shapes: vec![vec![32, 256]],
1366 cpu_time: Duration::from_millis(10),
1367 gpu_time: Duration::from_millis(10),
1368 memory_copy_time: Duration::from_millis(100),
1369 sync_time: Duration::from_millis(5),
1370 parameter_count: 1000,
1371 flops: 100000,
1372 memory_footprint_bytes: 4096,
1373 cache_hit_rate: 0.5,
1374 };
1375 let bottleneck = profiler.identify_layer_bottleneck(&profile);
1376 assert_eq!(bottleneck, "Memory Bandwidth");
1377 }
1378
1379 #[test]
1380 fn test_profiler_identify_layer_bottleneck_sync() {
1381 let config = make_config();
1382 let profiler = Profiler::new(&config);
1383 let profile = LayerLatencyProfile {
1384 layer_name: "test".to_string(),
1385 layer_type: "dense".to_string(),
1386 input_shapes: vec![],
1387 output_shapes: vec![],
1388 cpu_time: Duration::from_millis(10),
1389 gpu_time: Duration::from_millis(10),
1390 memory_copy_time: Duration::from_millis(5),
1391 sync_time: Duration::from_millis(50),
1392 parameter_count: 0,
1393 flops: 0,
1394 memory_footprint_bytes: 0,
1395 cache_hit_rate: 0.0,
1396 };
1397 let bottleneck = profiler.identify_layer_bottleneck(&profile);
1398 assert_eq!(bottleneck, "GPU Synchronization");
1399 }
1400
1401 #[test]
1402 fn test_profiler_io_bandwidth_stats_empty() {
1403 let config = make_config();
1404 let profiler = Profiler::new(&config);
1405 let stats = profiler.get_io_bandwidth_stats();
1406 assert_eq!(stats.len(), 5);
1407 for &val in stats.values() {
1408 assert!((val - 0.0).abs() < 1e-9);
1409 }
1410 }
1411
1412 #[test]
1413 fn test_profiler_track_memory_allocation_and_deallocation() {
1414 let config = make_config();
1415 let mut profiler = Profiler::new(&config);
1416 let alloc_id = profiler.track_memory_allocation(
1417 4096,
1418 MemoryAllocationType::Host,
1419 None,
1420 vec!["test_frame".to_string()],
1421 );
1422 assert!(profiler.memory_allocations.contains_key(&alloc_id));
1423 profiler.track_memory_deallocation(alloc_id);
1424 let alloc = profiler.memory_allocations.get(&alloc_id);
1425 assert!(alloc.is_some());
1426 assert!(alloc.expect("allocation should exist").freed);
1427 }
1428
1429 #[test]
1430 fn test_profiler_gpu_kernel_summary_empty() {
1431 let config = make_config();
1432 let profiler = Profiler::new(&config);
1433 let summary = profiler.generate_gpu_kernel_summary();
1434 assert_eq!(summary.total_kernels, 0);
1435 assert!((summary.avg_occupancy - 0.0).abs() < 1e-9);
1436 }
1437
1438 #[test]
1439 fn test_profiler_memory_allocation_summary() {
1440 let config = make_config();
1441 let mut profiler = Profiler::new(&config);
1442 let _id = profiler.track_memory_allocation(
1443 1024,
1444 MemoryAllocationType::Device,
1445 Some(0),
1446 Vec::new(),
1447 );
1448 let summary = profiler.generate_memory_allocation_summary();
1449 assert_eq!(summary.total_allocations, 1);
1450 assert_eq!(summary.peak_memory_usage, 1024);
1451 assert_eq!(summary.memory_leaks, 1);
1452 }
1453
1454 #[test]
1455 fn test_profiler_io_performance_summary_empty() {
1456 let config = make_config();
1457 let profiler = Profiler::new(&config);
1458 let summary = profiler.generate_io_performance_summary();
1459 assert_eq!(summary.total_operations, 0);
1460 assert_eq!(summary.total_bytes_transferred, 0);
1461 }
1462
1463 #[test]
1464 fn test_profiler_analyze_cpu_bottlenecks() {
1465 let config = make_config();
1466 let mut profiler = Profiler::new(&config);
1467 let result = profiler.analyze_cpu_bottlenecks();
1468 assert!(!result.is_empty());
1469 assert_eq!(result[0].hot_functions.len(), 2);
1470 }
1471
1472 #[test]
1473 fn test_profiler_performance_analysis() {
1474 let config = make_config();
1475 let profiler = Profiler::new(&config);
1476 let analysis = profiler.get_performance_analysis();
1477 assert!(analysis.performance_score > 0.0);
1478 assert!(!analysis.recommendations.is_empty());
1479 }
1480
1481 #[test]
1482 fn test_profiler_generate_performance_recommendations_optimal() {
1483 let config = make_config();
1484 let profiler = Profiler::new(&config);
1485 let recs = profiler.generate_performance_recommendations();
1486 assert!(!recs.is_empty());
1487 assert!(recs[0].contains("optimal"));
1488 }
1489
1490 #[test]
1491 fn test_layer_profile_accessors() {
1492 let config = make_config();
1493 let mut profiler = Profiler::new(&config);
1494 profiler.record_layer_execution(
1495 "layer1",
1496 "conv",
1497 Duration::from_millis(10),
1498 Some(Duration::from_millis(5)),
1499 512,
1500 100,
1501 );
1502 let profiles = profiler.get_layer_profiles();
1503 let lp = &profiles["layer1"];
1504 assert_eq!(lp.forward_times().len(), 1);
1505 assert_eq!(lp.backward_times().len(), 1);
1506 assert_eq!(lp.memory_usage(), &vec![512]);
1507 assert_eq!(lp.call_count(), 1);
1508 }
1509}