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 cpu_sampler: sysinfo::System,
63 last_cpu_sample: Instant,
67}
68
69#[derive(Debug)]
70pub struct LayerProfile {
71 layer_name: String,
72 forward_times: Vec<Duration>,
73 backward_times: Vec<Duration>,
74 memory_usage: Vec<usize>,
75 call_count: usize,
76}
77
78impl LayerProfile {
79 pub fn forward_times(&self) -> &Vec<Duration> {
81 &self.forward_times
82 }
83
84 pub fn backward_times(&self) -> &Vec<Duration> {
86 &self.backward_times
87 }
88
89 pub fn memory_usage(&self) -> &Vec<usize> {
91 &self.memory_usage
92 }
93
94 pub fn call_count(&self) -> usize {
96 self.call_count
97 }
98}
99
100fn refresh_own_process_cpu(system: &mut sysinfo::System) {
107 let pid = sysinfo::Pid::from_u32(std::process::id());
108 system.refresh_processes_specifics(
109 sysinfo::ProcessesToUpdate::Some(&[pid]),
110 true,
111 sysinfo::ProcessRefreshKind::nothing().with_cpu(),
112 );
113}
114
115impl Profiler {
116 pub fn new(config: &DebugConfig) -> Self {
118 Self {
119 config: config.clone(),
120 events: Vec::new(),
121 active_timers: HashMap::new(),
122 memory_snapshots: Vec::new(),
123 start_time: None,
124 layer_profiles: HashMap::new(),
125 bottlenecks: Vec::new(),
126 gpu_kernel_profiles: Vec::new(),
128 memory_allocations: HashMap::new(),
129 layer_latency_profiles: HashMap::new(),
130 io_profiles: Vec::new(),
131 cpu_bottleneck_analysis: Vec::new(),
132 memory_tracker: Arc::new(Mutex::new(MemoryTracker::new())),
133 gpu_profiler: GpuProfiler::new().ok(),
134 io_monitor: IoMonitor::new(),
135 cpu_sampler: {
136 let mut system = sysinfo::System::new();
137 refresh_own_process_cpu(&mut system);
138 system
139 },
140 last_cpu_sample: Instant::now(),
141 }
142 }
143
144 pub async fn start(&mut self) -> Result<()> {
146 tracing::info!("Starting performance profiler");
147 self.start_time = Some(Instant::now());
148 self.take_memory_snapshot();
149 Ok(())
150 }
151
152 pub fn get_events(&self) -> &Vec<ProfileEvent> {
154 &self.events
155 }
156
157 pub fn start_timer(&mut self, name: &str) {
159 self.active_timers.insert(name.to_string(), Instant::now());
160 }
161
162 pub fn end_timer(&mut self, name: &str) -> Option<Duration> {
164 if let Some(start_time) = self.active_timers.remove(name) {
165 let duration = start_time.elapsed();
166
167 self.events.push(ProfileEvent::FunctionCall {
169 function_name: name.to_string(),
170 duration,
171 memory_delta: 0, });
173
174 Some(duration)
175 } else {
176 tracing::warn!("Timer '{}' was not started", name);
177 None
178 }
179 }
180
181 pub fn record_layer_execution(
183 &mut self,
184 layer_name: &str,
185 layer_type: &str,
186 forward_time: Duration,
187 backward_time: Option<Duration>,
188 memory_usage: usize,
189 parameter_count: usize,
190 ) {
191 self.events.push(ProfileEvent::LayerExecution {
193 layer_name: layer_name.to_string(),
194 layer_type: layer_type.to_string(),
195 forward_time,
196 backward_time,
197 memory_usage,
198 parameter_count,
199 });
200
201 let profile =
203 self.layer_profiles
204 .entry(layer_name.to_string())
205 .or_insert_with(|| LayerProfile {
206 layer_name: layer_name.to_string(),
207 forward_times: Vec::new(),
208 backward_times: Vec::new(),
209 memory_usage: Vec::new(),
210 call_count: 0,
211 });
212
213 profile.forward_times.push(forward_time);
214 if let Some(backward) = backward_time {
215 profile.backward_times.push(backward);
216 }
217 profile.memory_usage.push(memory_usage);
218 profile.call_count += 1;
219 }
220
221 pub fn record_tensor_operation(
223 &mut self,
224 operation: &str,
225 tensor_shape: &[usize],
226 duration: Duration,
227 memory_allocated: usize,
228 ) {
229 self.events.push(ProfileEvent::TensorOperation {
230 operation: operation.to_string(),
231 tensor_shape: tensor_shape.to_vec(),
232 duration,
233 memory_allocated,
234 });
235 }
236
237 pub fn record_model_inference(
239 &mut self,
240 batch_size: usize,
241 sequence_length: usize,
242 duration: Duration,
243 ) {
244 let tokens_per_second = (batch_size * sequence_length) as f64 / duration.as_secs_f64();
245
246 self.events.push(ProfileEvent::ModelInference {
247 batch_size,
248 sequence_length,
249 duration,
250 tokens_per_second,
251 });
252 }
253
254 pub fn record_gradient_computation(
256 &mut self,
257 layer_name: &str,
258 gradient_norm: f64,
259 duration: Duration,
260 ) {
261 self.events.push(ProfileEvent::GradientComputation {
262 layer_name: layer_name.to_string(),
263 gradient_norm,
264 duration,
265 });
266 }
267
268 pub fn take_memory_snapshot(&mut self) {
273 let pid = sysinfo::Pid::from_u32(std::process::id());
274 let mut system = sysinfo::System::new();
275 system.refresh_processes_specifics(
276 sysinfo::ProcessesToUpdate::Some(&[pid]),
277 true,
278 sysinfo::ProcessRefreshKind::nothing().with_memory(),
279 );
280 let process = system.process(pid);
281
282 let snapshot = MemorySnapshot {
283 timestamp: chrono::Utc::now(),
284 process_rss_bytes: process.map(|p| p.memory() as usize),
285 process_virtual_bytes: process.map(|p| p.virtual_memory() as usize),
286 gpu_allocated: None,
288 gpu_used: None,
289 };
290
291 self.memory_snapshots.push(snapshot);
292
293 if self.memory_snapshots.len() > 1000 {
295 self.memory_snapshots.drain(0..500);
296 }
297 }
298
299 pub fn analyze_performance(&mut self) -> Vec<PerformanceBottleneck> {
301 self.bottlenecks.clear();
302
303 self.analyze_layer_bottlenecks();
305
306 self.analyze_memory_bottlenecks();
308
309 self.analyze_tensor_bottlenecks();
311
312 self.bottlenecks.clone()
313 }
314
315 pub fn get_statistics(&self) -> HashMap<String, ProfileStats> {
317 let mut stats = HashMap::new();
318
319 let mut grouped_events: HashMap<String, Vec<&ProfileEvent>> = HashMap::new();
321
322 for event in &self.events {
323 let event_type = match event {
324 ProfileEvent::FunctionCall { .. } => "FunctionCall",
325 ProfileEvent::LayerExecution { .. } => "LayerExecution",
326 ProfileEvent::TensorOperation { .. } => "TensorOperation",
327 ProfileEvent::ModelInference { .. } => "ModelInference",
328 ProfileEvent::GradientComputation { .. } => "GradientComputation",
329 };
330
331 grouped_events.entry(event_type.to_string()).or_default().push(event);
332 }
333
334 for (event_type, events) in grouped_events {
336 let durations: Vec<Duration> = events
337 .iter()
338 .filter_map(|event| match event {
339 ProfileEvent::FunctionCall { duration, .. } => Some(*duration),
340 ProfileEvent::LayerExecution { forward_time, .. } => Some(*forward_time),
341 ProfileEvent::TensorOperation { duration, .. } => Some(*duration),
342 ProfileEvent::ModelInference { duration, .. } => Some(*duration),
343 ProfileEvent::GradientComputation { duration, .. } => Some(*duration),
344 })
345 .collect();
346
347 if !durations.is_empty() {
348 let total_duration: Duration = durations.iter().sum();
349 let avg_duration = total_duration / durations.len() as u32;
350 let min_duration = durations.iter().min().copied().unwrap_or_default();
351 let max_duration = durations.iter().max().copied().unwrap_or_default();
352
353 stats.insert(
354 event_type.clone(),
355 ProfileStats {
356 event_type,
357 count: durations.len(),
358 total_duration,
359 avg_duration,
360 min_duration,
361 max_duration,
362 total_memory: 0, avg_memory: 0.0,
364 },
365 );
366 }
367 }
368
369 stats
370 }
371
372 pub fn get_layer_profiles(&self) -> &HashMap<String, LayerProfile> {
374 &self.layer_profiles
375 }
376
377 pub fn get_memory_timeline(&self) -> &[MemorySnapshot] {
379 &self.memory_snapshots
380 }
381
382 pub async fn generate_report(&self) -> Result<ProfilerReport> {
384 let statistics = self.get_statistics();
385 let bottlenecks = self.bottlenecks.clone();
386 let total_events = self.events.len();
387
388 let total_runtime =
389 if let Some(start) = self.start_time { start.elapsed() } else { Duration::ZERO };
390
391 let slowest_layers = self.get_slowest_layers(5);
393
394 let memory_efficiency = self.analyze_memory_efficiency();
396
397 Ok(ProfilerReport {
398 total_events,
399 total_runtime,
400 statistics,
401 bottlenecks,
402 slowest_layers,
403 memory_efficiency,
404 recommendations: self.generate_performance_recommendations(),
405 })
406 }
407
408 pub fn clear(&mut self) {
410 self.events.clear();
411 self.active_timers.clear();
412 self.memory_snapshots.clear();
413 self.layer_profiles.clear();
414 self.bottlenecks.clear();
415 self.start_time = None;
416 self.gpu_kernel_profiles.clear();
418 self.memory_allocations.clear();
419 self.layer_latency_profiles.clear();
420 self.io_profiles.clear();
421 self.cpu_bottleneck_analysis.clear();
422 if let Ok(mut tracker) = self.memory_tracker.lock() {
423 *tracker = MemoryTracker::new();
424 }
425 self.io_monitor = IoMonitor::new();
426 }
427
428 pub fn profile_gpu_kernel(&mut self, kernel_profile: GpuKernelProfile) {
432 if let Some(ref mut gpu_profiler) = self.gpu_profiler {
433 gpu_profiler.profile_kernel(kernel_profile.clone());
434 }
435 self.gpu_kernel_profiles.push(kernel_profile);
436 }
437
438 pub fn track_memory_allocation(
440 &mut self,
441 size_bytes: usize,
442 allocation_type: MemoryAllocationType,
443 device_id: Option<i32>,
444 stack_trace: Vec<String>,
445 ) -> Uuid {
446 let allocation_id = Uuid::new_v4();
447 let allocation = MemoryAllocation {
448 allocation_id,
449 size_bytes,
450 allocation_type,
451 device_id,
452 timestamp: SystemTime::now(),
453 stack_trace,
454 freed: false,
455 free_timestamp: None,
456 };
457
458 if let Ok(mut tracker) = self.memory_tracker.lock() {
459 tracker.track_allocation(allocation.clone());
460 }
461
462 self.memory_allocations.insert(allocation_id, allocation);
463 allocation_id
464 }
465
466 pub fn track_memory_deallocation(&mut self, allocation_id: Uuid) {
468 if let Some(allocation) = self.memory_allocations.get_mut(&allocation_id) {
469 allocation.freed = true;
470 allocation.free_timestamp = Some(SystemTime::now());
471 }
472
473 if let Ok(mut tracker) = self.memory_tracker.lock() {
474 tracker.track_deallocation(allocation_id);
475 }
476 }
477
478 pub fn profile_layer_latency(&mut self, layer_latency: LayerLatencyProfile) {
480 self.layer_latency_profiles
481 .insert(layer_latency.layer_name.clone(), layer_latency);
482 }
483
484 pub fn start_io_profiling(
486 &mut self,
487 operation_type: IoOperationType,
488 bytes_expected: usize,
489 ) -> Uuid {
490 self.io_monitor.start_io_operation(operation_type, bytes_expected)
491 }
492
493 pub fn finish_io_profiling(&mut self, operation_id: Uuid, bytes_transferred: usize) {
495 if let Some(profile) = self.io_monitor.finish_io_operation(operation_id, bytes_transferred)
496 {
497 self.io_profiles.push(profile);
498 }
499 }
500
501 fn sample_process_cpu_usage(&mut self) -> Option<f64> {
517 if self.last_cpu_sample.elapsed() < sysinfo::MINIMUM_CPU_UPDATE_INTERVAL {
518 return None;
519 }
520 refresh_own_process_cpu(&mut self.cpu_sampler);
521 self.last_cpu_sample = Instant::now();
522 let pid = sysinfo::Pid::from_u32(std::process::id());
523 self.cpu_sampler.process(pid).map(|p| p.cpu_usage() as f64)
524 }
525
526 pub fn analyze_cpu_bottlenecks(&mut self) -> Vec<CpuBottleneckAnalysis> {
538 let mut totals: Vec<(String, Duration, usize)> = self
540 .layer_profiles
541 .values()
542 .map(|profile| {
543 let total: Duration = profile
544 .forward_times()
545 .iter()
546 .chain(profile.backward_times().iter())
547 .copied()
548 .sum();
549 let calls = profile.forward_times().len() + profile.backward_times().len();
550 (profile.layer_name.clone(), total, calls)
551 })
552 .filter(|(_, _, calls)| *calls > 0)
553 .collect();
554
555 if totals.is_empty() {
556 return Vec::new();
557 }
558
559 totals.sort_by_key(|(_, total, _)| std::cmp::Reverse(*total));
560 let grand_total: Duration = totals.iter().map(|(_, d, _)| *d).sum();
561 let grand_total_secs = grand_total.as_secs_f64();
562
563 let hot_functions: Vec<HotFunction> = totals
564 .iter()
565 .take(10)
566 .map(|(name, total, calls)| HotFunction {
567 function_name: name.clone(),
568 self_time_percentage: if grand_total_secs > 0.0 {
569 total.as_secs_f64() / grand_total_secs * 100.0
570 } else {
571 0.0
572 },
573 call_count: *calls,
574 avg_time_per_call: *total / (*calls).max(1) as u32,
575 })
576 .collect();
577
578 let bottleneck_score = if grand_total_secs > 0.0 {
580 hot_functions.first().map(|f| f.self_time_percentage / 100.0)
581 } else {
582 None
583 };
584
585 let pid_raw = std::process::id();
586 let cpu_usage_percent = self.sample_process_cpu_usage();
587
588 let analysis = CpuBottleneckAnalysis {
589 process_id: pid_raw,
590 cpu_usage_percent,
591 context_switches: None,
592 cache_misses: None,
593 instructions_per_cycle: None,
594 branch_mispredictions: None,
595 hot_functions,
596 bottleneck_score,
597 };
598
599 self.cpu_bottleneck_analysis.push(analysis.clone());
600 vec![analysis]
601 }
602
603 pub fn get_memory_stats(&self) -> Option<MemoryStats> {
605 if let Ok(tracker) = self.memory_tracker.lock() {
606 Some(tracker.get_memory_stats())
607 } else {
608 None
609 }
610 }
611
612 pub fn get_gpu_utilization(&self, device_id: i32) -> Option<f64> {
614 self.gpu_profiler
615 .as_ref()
616 .map(|profiler| profiler.get_gpu_utilization(device_id))
617 }
618
619 pub fn get_io_bandwidth_stats(&self) -> HashMap<IoDeviceType, f64> {
621 let mut stats = HashMap::new();
622
623 stats.insert(
624 IoDeviceType::SSD,
625 self.io_monitor.get_average_bandwidth(&IoDeviceType::SSD),
626 );
627 stats.insert(
628 IoDeviceType::HDD,
629 self.io_monitor.get_average_bandwidth(&IoDeviceType::HDD),
630 );
631 stats.insert(
632 IoDeviceType::Network,
633 self.io_monitor.get_average_bandwidth(&IoDeviceType::Network),
634 );
635 stats.insert(
636 IoDeviceType::Memory,
637 self.io_monitor.get_average_bandwidth(&IoDeviceType::Memory),
638 );
639 stats.insert(
640 IoDeviceType::Cache,
641 self.io_monitor.get_average_bandwidth(&IoDeviceType::Cache),
642 );
643
644 stats
645 }
646
647 pub fn get_layer_latency_analysis(&self) -> Vec<LayerLatencyAnalysis> {
649 self.layer_latency_profiles
650 .values()
651 .map(|profile| LayerLatencyAnalysis {
652 layer_name: profile.layer_name.clone(),
653 layer_type: profile.layer_type.clone(),
654 total_time: profile.cpu_time
655 + profile.gpu_time
656 + profile.memory_copy_time
657 + profile.sync_time,
658 cpu_percentage: profile.cpu_time.as_secs_f64()
659 / (profile.cpu_time
660 + profile.gpu_time
661 + profile.memory_copy_time
662 + profile.sync_time)
663 .as_secs_f64()
664 * 100.0,
665 gpu_percentage: profile.gpu_time.as_secs_f64()
666 / (profile.cpu_time
667 + profile.gpu_time
668 + profile.memory_copy_time
669 + profile.sync_time)
670 .as_secs_f64()
671 * 100.0,
672 memory_copy_percentage: profile.memory_copy_time.as_secs_f64()
673 / (profile.cpu_time
674 + profile.gpu_time
675 + profile.memory_copy_time
676 + profile.sync_time)
677 .as_secs_f64()
678 * 100.0,
679 flops_per_second: if profile.gpu_time.as_secs_f64() > 0.0 {
680 profile.flops as f64 / profile.gpu_time.as_secs_f64()
681 } else {
682 0.0
683 },
684 memory_bandwidth_utilization: profile.cache_hit_rate,
685 bottleneck_type: self.identify_layer_bottleneck(profile),
686 })
687 .collect()
688 }
689
690 pub fn get_performance_analysis(&self) -> PerformanceAnalysis {
692 let memory_stats = self.get_memory_stats();
693 let io_bandwidth_stats = self.get_io_bandwidth_stats();
694 let layer_analysis = self.get_layer_latency_analysis();
695
696 let gpu_utilization =
697 self.gpu_profiler.as_ref().map(|profiler| profiler.get_gpu_utilization(0));
698
699 PerformanceAnalysis {
700 memory_stats,
701 io_bandwidth_stats,
702 layer_analysis,
703 gpu_utilization,
704 cpu_bottlenecks: self.cpu_bottleneck_analysis.clone(),
705 total_gpu_kernels: self.gpu_kernel_profiles.len(),
706 total_io_operations: self.io_profiles.len(),
707 performance_score: self.calculate_overall_performance_score(),
708 recommendations: self.generate_enhanced_recommendations(),
709 }
710 }
711
712 fn identify_layer_bottleneck(&self, profile: &LayerLatencyProfile) -> String {
713 let total_time =
714 profile.cpu_time + profile.gpu_time + profile.memory_copy_time + profile.sync_time;
715
716 if profile.memory_copy_time > total_time / 2 {
717 "Memory Bandwidth".to_string()
718 } else if profile.sync_time > total_time / 3 {
719 "GPU Synchronization".to_string()
720 } else if profile.gpu_time > profile.cpu_time * 10 {
721 "GPU Compute".to_string()
722 } else {
723 "CPU Compute".to_string()
724 }
725 }
726
727 fn calculate_overall_performance_score(&self) -> f64 {
728 let mut score: f64 = 100.0;
729
730 for bottleneck in &self.bottlenecks {
732 match bottleneck.severity {
733 BottleneckSeverity::Critical => score -= 20.0,
734 BottleneckSeverity::High => score -= 10.0,
735 BottleneckSeverity::Medium => score -= 5.0,
736 BottleneckSeverity::Low => score -= 2.0,
737 }
738 }
739
740 if let Some(gpu_util) = self.get_gpu_utilization(0) {
742 if gpu_util < 0.5 {
743 score -= 15.0;
744 } else if gpu_util < 0.7 {
745 score -= 8.0;
746 }
747 }
748
749 if let Some(memory_stats) = self.get_memory_stats() {
751 if memory_stats.memory_efficiency < 0.8 {
752 score -= 10.0;
753 }
754 }
755
756 score.max(0.0)
757 }
758
759 fn generate_enhanced_recommendations(&self) -> Vec<String> {
760 let mut recommendations = Vec::new();
761
762 if let Some(gpu_util) = self.get_gpu_utilization(0) {
764 if gpu_util < 0.5 {
765 recommendations.push("Low GPU utilization detected. Consider increasing batch size or optimizing GPU kernels.".to_string());
766 }
767 }
768
769 if let Some(memory_stats) = self.get_memory_stats() {
771 if memory_stats.memory_efficiency < 0.8 {
772 recommendations.push("Memory allocation efficiency is low. Consider memory pooling or reducing allocations.".to_string());
773 }
774
775 if memory_stats.active_allocations > 10000 {
776 recommendations.push("High number of active memory allocations. Consider batch allocation strategies.".to_string());
777 }
778 }
779
780 let io_stats = self.get_io_bandwidth_stats();
782 if let Some(&ssd_bandwidth) = io_stats.get(&IoDeviceType::SSD) {
783 if ssd_bandwidth < 100.0 {
784 recommendations.push(
786 "Low SSD bandwidth utilization. Consider optimizing file I/O patterns."
787 .to_string(),
788 );
789 }
790 }
791
792 let layer_analysis = self.get_layer_latency_analysis();
794 for analysis in &layer_analysis {
795 if analysis.memory_copy_percentage > 50.0 {
796 recommendations.push(format!(
797 "Layer '{}' is memory bandwidth bound. Consider data layout optimization.",
798 analysis.layer_name
799 ));
800 }
801
802 if analysis.cpu_percentage > 80.0 {
803 recommendations.push(format!(
804 "Layer '{}' is CPU bound. Consider GPU acceleration.",
805 analysis.layer_name
806 ));
807 }
808 }
809
810 if recommendations.is_empty() {
811 recommendations
812 .push("Performance appears optimal based on current analysis.".to_string());
813 }
814
815 recommendations
816 }
817
818 fn analyze_layer_bottlenecks(&mut self) {
821 for (layer_name, profile) in &self.layer_profiles {
822 if profile.forward_times.is_empty() {
823 continue;
824 }
825
826 let avg_forward_time =
827 profile.forward_times.iter().sum::<Duration>() / profile.forward_times.len() as u32;
828
829 if avg_forward_time.as_millis() > 100 {
831 let mut metrics = HashMap::new();
832 metrics.insert(
833 "avg_forward_time_ms".to_string(),
834 avg_forward_time.as_millis() as f64,
835 );
836 metrics.insert("call_count".to_string(), profile.call_count as f64);
837
838 self.bottlenecks.push(PerformanceBottleneck {
839 bottleneck_type: BottleneckType::ModelComputation,
840 location: layer_name.clone(),
841 severity: if avg_forward_time.as_millis() > 500 {
842 BottleneckSeverity::High
843 } else {
844 BottleneckSeverity::Medium
845 },
846 description: format!(
847 "Layer '{}' has slow forward pass: {:.1}ms average",
848 layer_name,
849 avg_forward_time.as_millis()
850 ),
851 suggestion: "Consider optimizing layer implementation or reducing layer size"
852 .to_string(),
853 metrics,
854 });
855 }
856 }
857 }
858
859 fn analyze_memory_bottlenecks(&mut self) {
860 if self.memory_snapshots.len() < 2 {
861 return;
862 }
863
864 let recent_snapshots = if self.memory_snapshots.len() > 10 {
866 &self.memory_snapshots[self.memory_snapshots.len() - 10..]
867 } else {
868 &self.memory_snapshots
869 };
870
871 let measured: Vec<usize> =
873 recent_snapshots.iter().filter_map(|s| s.process_rss_bytes).collect();
874 if measured.len() >= 5 {
875 let initial_memory = measured[0];
876 let final_memory = measured.last().copied().unwrap_or(0);
877
878 if final_memory > initial_memory * 2 {
879 let mut metrics = HashMap::new();
880 metrics.insert(
881 "initial_memory_mb".to_string(),
882 initial_memory as f64 / (1024.0 * 1024.0),
883 );
884 metrics.insert(
885 "final_memory_mb".to_string(),
886 final_memory as f64 / (1024.0 * 1024.0),
887 );
888 metrics.insert(
889 "growth_ratio".to_string(),
890 final_memory as f64 / initial_memory as f64,
891 );
892
893 self.bottlenecks.push(PerformanceBottleneck {
894 bottleneck_type: BottleneckType::MemoryBound,
895 location: "Memory Usage".to_string(),
896 severity: BottleneckSeverity::High,
897 description: "Significant memory growth detected during profiling".to_string(),
898 suggestion: "Check for memory leaks or inefficient memory usage patterns"
899 .to_string(),
900 metrics,
901 });
902 }
903 }
904 }
905
906 fn analyze_tensor_bottlenecks(&mut self) {
907 let mut operation_groups: HashMap<String, Vec<Duration>> = HashMap::new();
909
910 for event in &self.events {
911 if let ProfileEvent::TensorOperation {
912 operation,
913 duration,
914 ..
915 } = event
916 {
917 operation_groups.entry(operation.clone()).or_default().push(*duration);
918 }
919 }
920
921 for (operation, durations) in operation_groups {
923 if durations.is_empty() {
924 continue;
925 }
926
927 let avg_duration = durations.iter().sum::<Duration>() / durations.len() as u32;
928 let total_time = durations.iter().sum::<Duration>();
929
930 if avg_duration.as_millis() > 10 {
932 let mut metrics = HashMap::new();
933 metrics.insert(
934 "avg_duration_ms".to_string(),
935 avg_duration.as_millis() as f64,
936 );
937 metrics.insert("total_time_ms".to_string(), total_time.as_millis() as f64);
938 metrics.insert("call_count".to_string(), durations.len() as f64);
939
940 self.bottlenecks.push(PerformanceBottleneck {
941 bottleneck_type: BottleneckType::CpuBound,
942 location: format!("Tensor Operation: {}", operation),
943 severity: if avg_duration.as_millis() > 50 {
944 BottleneckSeverity::High
945 } else {
946 BottleneckSeverity::Medium
947 },
948 description: format!(
949 "Tensor operation '{}' is slow: {:.1}ms average",
950 operation,
951 avg_duration.as_millis()
952 ),
953 suggestion:
954 "Consider optimizing tensor operation or using different data types"
955 .to_string(),
956 metrics,
957 });
958 }
959 }
960 }
961
962 fn get_slowest_layers(&self, limit: usize) -> Vec<(String, Duration)> {
963 let mut layer_times: Vec<(String, Duration)> = self
964 .layer_profiles
965 .iter()
966 .map(|(name, profile)| {
967 let avg_time = if profile.forward_times.is_empty() {
968 Duration::ZERO
969 } else {
970 profile.forward_times.iter().sum::<Duration>()
971 / profile.forward_times.len() as u32
972 };
973 (name.clone(), avg_time)
974 })
975 .collect();
976
977 layer_times.sort_by_key(|item| std::cmp::Reverse(item.1));
978 layer_times.truncate(limit);
979 layer_times
980 }
981
982 fn analyze_memory_efficiency(&self) -> MemoryEfficiencyAnalysis {
983 if self.memory_snapshots.is_empty() {
984 return MemoryEfficiencyAnalysis::default();
985 }
986
987 let memory_values: Vec<usize> = self
988 .memory_snapshots
989 .iter()
990 .filter_map(|snapshot| snapshot.process_rss_bytes)
991 .collect();
992 if memory_values.is_empty() {
993 return MemoryEfficiencyAnalysis::default();
995 }
996
997 let max_memory = memory_values.iter().max().copied().unwrap_or(0);
998 let min_memory = memory_values.iter().min().copied().unwrap_or(0);
999 let avg_memory = memory_values.iter().sum::<usize>() / memory_values.len();
1000
1001 MemoryEfficiencyAnalysis {
1002 peak_memory_mb: max_memory as f64 / (1024.0 * 1024.0),
1003 min_memory_mb: min_memory as f64 / (1024.0 * 1024.0),
1004 avg_memory_mb: avg_memory as f64 / (1024.0 * 1024.0),
1005 memory_variance: self.calculate_memory_variance(&memory_values, avg_memory),
1006 efficiency_score: self.calculate_memory_efficiency_score(&memory_values),
1007 }
1008 }
1009
1010 fn calculate_memory_variance(&self, values: &[usize], mean: usize) -> f64 {
1011 if values.len() < 2 {
1012 return 0.0;
1013 }
1014
1015 let variance_sum: f64 = values
1016 .iter()
1017 .map(|&x| {
1018 let diff = x as f64 - mean as f64;
1019 diff * diff
1020 })
1021 .sum();
1022
1023 variance_sum / (values.len() - 1) as f64
1024 }
1025
1026 fn calculate_memory_efficiency_score(&self, values: &[usize]) -> f64 {
1027 if values.is_empty() {
1028 return 0.0;
1029 }
1030
1031 let max_memory = values.iter().max().copied().unwrap_or(0);
1032 let min_memory = values.iter().min().copied().unwrap_or(0);
1033
1034 if max_memory == 0 {
1035 return 100.0;
1036 }
1037
1038 100.0 * (1.0 - (max_memory - min_memory) as f64 / max_memory as f64)
1040 }
1041
1042 fn generate_performance_recommendations(&self) -> Vec<String> {
1043 let mut recommendations = Vec::new();
1044
1045 for bottleneck in &self.bottlenecks {
1047 match bottleneck.bottleneck_type {
1048 BottleneckType::ModelComputation => {
1049 recommendations.push(
1050 "Consider model architecture optimizations or layer fusion".to_string(),
1051 );
1052 },
1053 BottleneckType::MemoryBound => {
1054 recommendations.push(
1055 "Optimize memory usage with gradient checkpointing or model parallelism"
1056 .to_string(),
1057 );
1058 },
1059 BottleneckType::CpuBound => {
1060 recommendations.push(
1061 "Consider GPU acceleration or optimized CPU implementations".to_string(),
1062 );
1063 },
1064 _ => {},
1065 }
1066 }
1067
1068 if self.events.len() > 10000 {
1070 recommendations.push(
1071 "High number of profiling events - consider reducing profiling overhead"
1072 .to_string(),
1073 );
1074 }
1075
1076 let stats = self.get_statistics();
1077 if let Some(layer_stats) = stats.get("LayerExecution") {
1078 if layer_stats.avg_duration.as_millis() > 50 {
1079 recommendations.push(
1080 "Average layer execution time is high - consider layer optimization"
1081 .to_string(),
1082 );
1083 }
1084 }
1085
1086 if recommendations.is_empty() {
1087 recommendations
1088 .push("Performance appears optimal based on current profiling data".to_string());
1089 }
1090
1091 recommendations
1092 }
1093
1094 pub async fn generate_enhanced_report(&self) -> Result<EnhancedProfilerReport> {
1096 let basic_report = self.generate_report().await?;
1097 let performance_analysis = self.get_performance_analysis();
1098
1099 let gpu_kernel_summary = self.generate_gpu_kernel_summary();
1100 let memory_allocation_summary = self.generate_memory_allocation_summary();
1101 let io_performance_summary = self.generate_io_performance_summary();
1102
1103 Ok(EnhancedProfilerReport {
1104 basic_report,
1105 performance_analysis,
1106 gpu_kernel_summary,
1107 memory_allocation_summary,
1108 io_performance_summary,
1109 })
1110 }
1111
1112 fn generate_gpu_kernel_summary(&self) -> GpuKernelSummary {
1113 let total_kernels = self.gpu_kernel_profiles.len();
1114 let total_execution_time = self.gpu_kernel_profiles.iter().map(|k| k.execution_time).sum();
1115
1116 let avg_occupancy = if total_kernels > 0 {
1117 self.gpu_kernel_profiles.iter().map(|k| k.occupancy).sum::<f64>() / total_kernels as f64
1118 } else {
1119 0.0
1120 };
1121
1122 let avg_compute_utilization = if total_kernels > 0 {
1123 self.gpu_kernel_profiles.iter().map(|k| k.compute_utilization).sum::<f64>()
1124 / total_kernels as f64
1125 } else {
1126 0.0
1127 };
1128
1129 let mut kernels_by_time: Vec<_> = self
1130 .gpu_kernel_profiles
1131 .iter()
1132 .map(|k| (k.kernel_name.clone(), k.execution_time))
1133 .collect();
1134 kernels_by_time.sort_by_key(|item| std::cmp::Reverse(item.1));
1135
1136 let slowest_kernels = kernels_by_time.into_iter().take(5).map(|(name, _)| name).collect();
1137
1138 GpuKernelSummary {
1139 total_kernels,
1140 total_execution_time,
1141 avg_occupancy,
1142 avg_compute_utilization,
1143 slowest_kernels,
1144 }
1145 }
1146
1147 fn generate_memory_allocation_summary(&self) -> MemoryAllocationSummary {
1148 let total_allocations = self.memory_allocations.len();
1149 let peak_memory_usage =
1150 self.memory_allocations.values().map(|a| a.size_bytes).max().unwrap_or(0);
1151
1152 let memory_efficiency = if let Some(stats) = self.get_memory_stats() {
1153 stats.memory_efficiency
1154 } else {
1155 1.0
1156 };
1157
1158 let mut allocations_by_size: Vec<_> = self
1159 .memory_allocations
1160 .values()
1161 .map(|a| (format!("{} bytes", a.size_bytes), a.size_bytes))
1162 .collect();
1163 allocations_by_size.sort_by_key(|item| std::cmp::Reverse(item.1));
1164
1165 let largest_allocations =
1166 allocations_by_size.into_iter().take(5).map(|(desc, _)| desc).collect();
1167
1168 let memory_leaks = self.memory_allocations.values().filter(|a| !a.freed).count();
1169
1170 MemoryAllocationSummary {
1171 total_allocations,
1172 peak_memory_usage,
1173 memory_efficiency,
1174 largest_allocations,
1175 memory_leaks,
1176 }
1177 }
1178
1179 fn generate_io_performance_summary(&self) -> IoPerformanceSummary {
1180 let total_operations = self.io_profiles.len();
1181 let total_bytes_transferred = self.io_profiles.iter().map(|io| io.bytes_transferred).sum();
1182
1183 let avg_bandwidth_by_device = self.get_io_bandwidth_stats();
1184
1185 let mut operations_by_duration: Vec<_> = self
1186 .io_profiles
1187 .iter()
1188 .map(|io| {
1189 (
1190 format!("{:?}: {} bytes", io.operation_type, io.bytes_transferred),
1191 io.duration,
1192 )
1193 })
1194 .collect();
1195 operations_by_duration.sort_by_key(|item| std::cmp::Reverse(item.1));
1196
1197 let slowest_operations =
1198 operations_by_duration.into_iter().take(5).map(|(desc, _)| desc).collect();
1199
1200 IoPerformanceSummary {
1201 total_operations,
1202 total_bytes_transferred,
1203 avg_bandwidth_by_device,
1204 slowest_operations,
1205 }
1206 }
1207}
1208
1209pub struct ScopedTimer<'a> {
1211 profiler: &'a mut Profiler,
1212 name: String,
1213}
1214
1215impl<'a> ScopedTimer<'a> {
1216 pub fn new(profiler: &'a mut Profiler, name: String) -> Self {
1217 profiler.start_timer(&name);
1218 Self { profiler, name }
1219 }
1220}
1221
1222impl<'a> Drop for ScopedTimer<'a> {
1223 fn drop(&mut self) {
1224 self.profiler.end_timer(&self.name);
1225 }
1226}
1227
1228#[macro_export]
1230macro_rules! profile_scope {
1231 ($profiler:expr, $name:expr) => {
1232 let _timer = ScopedTimer::new($profiler, $name.to_string());
1233 };
1234}
1235
1236#[cfg(test)]
1237#[path = "../profiler_tests.rs"]
1238mod profiler_tests;
1239
1240#[cfg(test)]
1241mod tests {
1242 use super::*;
1243
1244 fn make_config() -> DebugConfig {
1245 DebugConfig::default()
1246 }
1247
1248 #[test]
1251 fn test_profiler_new() {
1252 let config = make_config();
1253 let profiler = Profiler::new(&config);
1254 assert!(profiler.events.is_empty());
1255 assert!(profiler.active_timers.is_empty());
1256 assert!(profiler.start_time.is_none());
1257 }
1258
1259 #[test]
1260 fn test_profiler_start_end_timer() {
1261 let config = make_config();
1262 let mut profiler = Profiler::new(&config);
1263 profiler.start_timer("test_op");
1264 let duration = profiler.end_timer("test_op");
1265 assert!(duration.is_some());
1266 assert_eq!(profiler.events.len(), 1);
1267 }
1268
1269 #[test]
1270 fn test_profiler_end_timer_not_started() {
1271 let config = make_config();
1272 let mut profiler = Profiler::new(&config);
1273 let duration = profiler.end_timer("nonexistent");
1274 assert!(duration.is_none());
1275 }
1276
1277 #[test]
1278 fn test_profiler_record_layer_execution() {
1279 let config = make_config();
1280 let mut profiler = Profiler::new(&config);
1281 profiler.record_layer_execution(
1282 "attention",
1283 "self_attention",
1284 Duration::from_millis(50),
1285 Some(Duration::from_millis(30)),
1286 1024,
1287 1000,
1288 );
1289 assert_eq!(profiler.events.len(), 1);
1290 let profiles = profiler.get_layer_profiles();
1291 assert!(profiles.contains_key("attention"));
1292 let lp = &profiles["attention"];
1293 assert_eq!(lp.call_count(), 1);
1294 assert_eq!(lp.forward_times().len(), 1);
1295 assert_eq!(lp.backward_times().len(), 1);
1296 }
1297
1298 #[test]
1299 fn test_profiler_record_tensor_operation() {
1300 let config = make_config();
1301 let mut profiler = Profiler::new(&config);
1302 profiler.record_tensor_operation("matmul", &[64, 128], Duration::from_micros(200), 8192);
1303 assert_eq!(profiler.events.len(), 1);
1304 }
1305
1306 #[test]
1307 fn test_profiler_record_model_inference() {
1308 let config = make_config();
1309 let mut profiler = Profiler::new(&config);
1310 profiler.record_model_inference(32, 512, Duration::from_millis(100));
1311 assert_eq!(profiler.events.len(), 1);
1312 }
1313
1314 #[test]
1315 fn test_profiler_record_gradient_computation() {
1316 let config = make_config();
1317 let mut profiler = Profiler::new(&config);
1318 profiler.record_gradient_computation("fc1", 0.5, Duration::from_millis(10));
1319 assert_eq!(profiler.events.len(), 1);
1320 }
1321
1322 #[test]
1323 fn test_profiler_get_statistics_empty() {
1324 let config = make_config();
1325 let profiler = Profiler::new(&config);
1326 let stats = profiler.get_statistics();
1327 assert!(stats.is_empty());
1328 }
1329
1330 #[test]
1331 fn test_profiler_get_statistics_with_events() {
1332 let config = make_config();
1333 let mut profiler = Profiler::new(&config);
1334 profiler.record_model_inference(8, 256, Duration::from_millis(50));
1335 profiler.record_model_inference(8, 256, Duration::from_millis(100));
1336 let stats = profiler.get_statistics();
1337 assert!(stats.contains_key("ModelInference"));
1338 let mi_stats = &stats["ModelInference"];
1339 assert_eq!(mi_stats.count, 2);
1340 }
1341
1342 #[test]
1343 fn test_profiler_clear() {
1344 let config = make_config();
1345 let mut profiler = Profiler::new(&config);
1346 profiler.start_timer("op1");
1347 profiler.end_timer("op1");
1348 profiler.take_memory_snapshot();
1349 profiler.clear();
1350 assert!(profiler.events.is_empty());
1351 assert!(profiler.active_timers.is_empty());
1352 assert!(profiler.memory_snapshots.is_empty());
1353 assert!(profiler.start_time.is_none());
1354 }
1355
1356 #[test]
1357 fn test_profiler_take_memory_snapshot() {
1358 let config = make_config();
1359 let mut profiler = Profiler::new(&config);
1360 profiler.take_memory_snapshot();
1361 assert_eq!(profiler.get_memory_timeline().len(), 1);
1362 }
1363
1364 #[test]
1365 fn test_profiler_memory_snapshot_limit() {
1366 let config = make_config();
1367 let mut profiler = Profiler::new(&config);
1368 for _ in 0..1100 {
1369 profiler.take_memory_snapshot();
1370 }
1371 assert!(profiler.get_memory_timeline().len() <= 601);
1373 }
1374
1375 #[test]
1376 fn test_profiler_analyze_performance_empty() {
1377 let config = make_config();
1378 let mut profiler = Profiler::new(&config);
1379 let bottlenecks = profiler.analyze_performance();
1380 assert!(bottlenecks.is_empty());
1381 }
1382
1383 #[test]
1384 fn test_profiler_analyze_performance_slow_layer() {
1385 let config = make_config();
1386 let mut profiler = Profiler::new(&config);
1387 for _ in 0..5 {
1388 profiler.record_layer_execution(
1389 "slow_layer",
1390 "dense",
1391 Duration::from_millis(600),
1392 None,
1393 4096,
1394 10000,
1395 );
1396 }
1397 let bottlenecks = profiler.analyze_performance();
1398 assert!(!bottlenecks.is_empty());
1399 }
1400
1401 #[test]
1402 fn test_profiler_get_slowest_layers() {
1403 let config = make_config();
1404 let mut profiler = Profiler::new(&config);
1405 profiler.record_layer_execution(
1406 "fast_layer",
1407 "relu",
1408 Duration::from_millis(1),
1409 None,
1410 128,
1411 0,
1412 );
1413 profiler.record_layer_execution(
1414 "slow_layer",
1415 "dense",
1416 Duration::from_millis(200),
1417 None,
1418 4096,
1419 10000,
1420 );
1421 let slowest = profiler.get_slowest_layers(2);
1422 assert_eq!(slowest.len(), 2);
1423 assert_eq!(slowest[0].0, "slow_layer");
1424 }
1425
1426 #[test]
1427 fn test_profiler_memory_efficiency_empty() {
1428 let config = make_config();
1429 let profiler = Profiler::new(&config);
1430 let analysis = profiler.analyze_memory_efficiency();
1431 assert!((analysis.efficiency_score - 100.0).abs() < 1e-9);
1432 }
1433
1434 #[test]
1435 fn test_profiler_calculate_memory_variance() {
1436 let config = make_config();
1437 let profiler = Profiler::new(&config);
1438 let values = vec![100, 200, 300];
1439 let mean = 200;
1440 let variance = profiler.calculate_memory_variance(&values, mean);
1441 assert!((variance - 10000.0).abs() < 1e-3);
1443 }
1444
1445 #[test]
1446 fn test_profiler_calculate_memory_efficiency_score_empty() {
1447 let config = make_config();
1448 let profiler = Profiler::new(&config);
1449 let score = profiler.calculate_memory_efficiency_score(&[]);
1450 assert!((score - 0.0).abs() < 1e-9);
1451 }
1452
1453 #[test]
1454 fn test_profiler_calculate_memory_efficiency_score_stable() {
1455 let config = make_config();
1456 let profiler = Profiler::new(&config);
1457 let values = vec![100, 100, 100];
1458 let score = profiler.calculate_memory_efficiency_score(&values);
1459 assert!((score - 100.0).abs() < 1e-9);
1460 }
1461
1462 #[test]
1463 fn test_profiler_calculate_memory_efficiency_score_varied() {
1464 let config = make_config();
1465 let profiler = Profiler::new(&config);
1466 let values = vec![50, 100];
1467 let score = profiler.calculate_memory_efficiency_score(&values);
1468 assert!((score - 50.0).abs() < 1e-9);
1470 }
1471
1472 #[test]
1473 fn test_profiler_overall_performance_score_no_bottlenecks() {
1474 let config = make_config();
1475 let profiler = Profiler::new(&config);
1476 let score = profiler.calculate_overall_performance_score();
1477 assert!(score >= 50.0);
1479 assert!(score <= 100.0);
1480 }
1481
1482 #[test]
1483 fn test_profiler_identify_layer_bottleneck_memory() {
1484 let config = make_config();
1485 let profiler = Profiler::new(&config);
1486 let profile = LayerLatencyProfile {
1487 layer_name: "test".to_string(),
1488 layer_type: "dense".to_string(),
1489 input_shapes: vec![vec![32, 128]],
1490 output_shapes: vec![vec![32, 256]],
1491 cpu_time: Duration::from_millis(10),
1492 gpu_time: Duration::from_millis(10),
1493 memory_copy_time: Duration::from_millis(100),
1494 sync_time: Duration::from_millis(5),
1495 parameter_count: 1000,
1496 flops: 100000,
1497 memory_footprint_bytes: 4096,
1498 cache_hit_rate: 0.5,
1499 };
1500 let bottleneck = profiler.identify_layer_bottleneck(&profile);
1501 assert_eq!(bottleneck, "Memory Bandwidth");
1502 }
1503
1504 #[test]
1505 fn test_profiler_identify_layer_bottleneck_sync() {
1506 let config = make_config();
1507 let profiler = Profiler::new(&config);
1508 let profile = LayerLatencyProfile {
1509 layer_name: "test".to_string(),
1510 layer_type: "dense".to_string(),
1511 input_shapes: vec![],
1512 output_shapes: vec![],
1513 cpu_time: Duration::from_millis(10),
1514 gpu_time: Duration::from_millis(10),
1515 memory_copy_time: Duration::from_millis(5),
1516 sync_time: Duration::from_millis(50),
1517 parameter_count: 0,
1518 flops: 0,
1519 memory_footprint_bytes: 0,
1520 cache_hit_rate: 0.0,
1521 };
1522 let bottleneck = profiler.identify_layer_bottleneck(&profile);
1523 assert_eq!(bottleneck, "GPU Synchronization");
1524 }
1525
1526 #[test]
1527 fn test_profiler_io_bandwidth_stats_empty() {
1528 let config = make_config();
1529 let profiler = Profiler::new(&config);
1530 let stats = profiler.get_io_bandwidth_stats();
1531 assert_eq!(stats.len(), 5);
1532 for &val in stats.values() {
1533 assert!((val - 0.0).abs() < 1e-9);
1534 }
1535 }
1536
1537 #[test]
1538 fn test_profiler_track_memory_allocation_and_deallocation() {
1539 let config = make_config();
1540 let mut profiler = Profiler::new(&config);
1541 let alloc_id = profiler.track_memory_allocation(
1542 4096,
1543 MemoryAllocationType::Host,
1544 None,
1545 vec!["test_frame".to_string()],
1546 );
1547 assert!(profiler.memory_allocations.contains_key(&alloc_id));
1548 profiler.track_memory_deallocation(alloc_id);
1549 let alloc = profiler.memory_allocations.get(&alloc_id);
1550 assert!(alloc.is_some());
1551 assert!(alloc.expect("allocation should exist").freed);
1552 }
1553
1554 #[test]
1555 fn test_profiler_gpu_kernel_summary_empty() {
1556 let config = make_config();
1557 let profiler = Profiler::new(&config);
1558 let summary = profiler.generate_gpu_kernel_summary();
1559 assert_eq!(summary.total_kernels, 0);
1560 assert!((summary.avg_occupancy - 0.0).abs() < 1e-9);
1561 }
1562
1563 #[test]
1564 fn test_profiler_memory_allocation_summary() {
1565 let config = make_config();
1566 let mut profiler = Profiler::new(&config);
1567 let _id = profiler.track_memory_allocation(
1568 1024,
1569 MemoryAllocationType::Device,
1570 Some(0),
1571 Vec::new(),
1572 );
1573 let summary = profiler.generate_memory_allocation_summary();
1574 assert_eq!(summary.total_allocations, 1);
1575 assert_eq!(summary.peak_memory_usage, 1024);
1576 assert_eq!(summary.memory_leaks, 1);
1577 }
1578
1579 #[test]
1580 fn test_profiler_io_performance_summary_empty() {
1581 let config = make_config();
1582 let profiler = Profiler::new(&config);
1583 let summary = profiler.generate_io_performance_summary();
1584 assert_eq!(summary.total_operations, 0);
1585 assert_eq!(summary.total_bytes_transferred, 0);
1586 }
1587
1588 #[test]
1593 fn test_profiler_analyze_cpu_bottlenecks_reports_nothing_before_profiling() {
1594 let config = make_config();
1595 let mut profiler = Profiler::new(&config);
1596 assert!(
1597 profiler.analyze_cpu_bottlenecks().is_empty(),
1598 "nothing has been profiled, so there is no bottleneck to report"
1599 );
1600 }
1601
1602 #[test]
1603 fn test_profiler_analyze_cpu_bottlenecks_ranks_real_recorded_layers() {
1604 let config = make_config();
1605 let mut profiler = Profiler::new(&config);
1606 profiler.record_layer_execution(
1607 "slow_layer",
1608 "linear",
1609 Duration::from_millis(90),
1610 None,
1611 0,
1612 0,
1613 );
1614 profiler.record_layer_execution(
1615 "fast_layer",
1616 "linear",
1617 Duration::from_millis(10),
1618 None,
1619 0,
1620 0,
1621 );
1622
1623 let result = profiler.analyze_cpu_bottlenecks();
1624 assert_eq!(result.len(), 1);
1625 let analysis = &result[0];
1626 assert_eq!(analysis.process_id, std::process::id());
1627 assert_eq!(
1628 analysis.hot_functions.len(),
1629 2,
1630 "exactly the two layers that were really recorded"
1631 );
1632 assert_eq!(
1633 analysis.hot_functions[0].function_name, "slow_layer",
1634 "hottest first"
1635 );
1636 assert!(
1637 (analysis.hot_functions[0].self_time_percentage - 90.0).abs() < 1.0,
1638 "90ms of 100ms is 90%, got {}",
1639 analysis.hot_functions[0].self_time_percentage
1640 );
1641 assert!(
1642 (analysis.bottleneck_score.expect("a score once something is profiled") - 0.9).abs()
1643 < 0.01
1644 );
1645 assert_eq!(analysis.context_switches, None);
1648 assert_eq!(analysis.cache_misses, None);
1649 assert_eq!(analysis.instructions_per_cycle, None);
1650 assert_eq!(analysis.branch_mispredictions, None);
1651 }
1652
1653 #[test]
1659 fn test_profiler_cpu_usage_is_a_real_two_sample_measurement() {
1660 let config = make_config();
1661 let mut profiler = Profiler::new(&config);
1662 profiler.record_layer_execution("burner", "linear", Duration::from_millis(10), None, 0, 0);
1663
1664 let mut observed = None;
1669 for _ in 0..5 {
1670 let burn_until = Instant::now() + sysinfo::MINIMUM_CPU_UPDATE_INTERVAL * 2;
1671 let mut spin: u64 = 0;
1672 while Instant::now() < burn_until {
1673 spin = spin.wrapping_mul(6_364_136_223_846_793_005).wrapping_add(1);
1674 }
1675 assert_ne!(
1676 spin,
1677 u64::MAX,
1678 "keep the busy loop from being optimised out"
1679 );
1680
1681 let analysis = profiler.analyze_cpu_bottlenecks();
1682 assert_eq!(analysis.len(), 1);
1683 if let Some(cpu) = analysis[0].cpu_usage_percent {
1684 if cpu > 0.0 {
1685 observed = Some(cpu);
1686 break;
1687 }
1688 }
1689 }
1690 let cpu = observed
1691 .expect("a process that spent ~400ms in a busy loop must report non-zero CPU usage");
1692 assert!(cpu.is_finite(), "got {cpu}");
1693 }
1694
1695 #[test]
1699 fn test_profiler_cpu_usage_is_none_before_the_minimum_sampling_interval() {
1700 let config = make_config();
1701 let constructed_at = Instant::now();
1702 let mut profiler = Profiler::new(&config);
1703 profiler.record_layer_execution("layer", "linear", Duration::from_millis(1), None, 0, 0);
1704 let before = Instant::now();
1709 let analysis = profiler.analyze_cpu_bottlenecks();
1710 let elapsed_since_construction = before.duration_since(constructed_at);
1711 assert_eq!(analysis.len(), 1);
1712 if elapsed_since_construction < sysinfo::MINIMUM_CPU_UPDATE_INTERVAL {
1713 assert_eq!(
1714 analysis[0].cpu_usage_percent, None,
1715 "only {elapsed_since_construction:?} has passed since the priming sample \
1716 taken in Profiler::new, which is below the minimum sampling interval"
1717 );
1718 }
1719 }
1720
1721 #[test]
1722 fn test_profiler_performance_analysis() {
1723 let config = make_config();
1724 let profiler = Profiler::new(&config);
1725 let analysis = profiler.get_performance_analysis();
1726 assert!(analysis.performance_score > 0.0);
1727 assert!(!analysis.recommendations.is_empty());
1728 }
1729
1730 #[test]
1731 fn test_profiler_generate_performance_recommendations_optimal() {
1732 let config = make_config();
1733 let profiler = Profiler::new(&config);
1734 let recs = profiler.generate_performance_recommendations();
1735 assert!(!recs.is_empty());
1736 assert!(recs[0].contains("optimal"));
1737 }
1738
1739 #[test]
1740 fn test_layer_profile_accessors() {
1741 let config = make_config();
1742 let mut profiler = Profiler::new(&config);
1743 profiler.record_layer_execution(
1744 "layer1",
1745 "conv",
1746 Duration::from_millis(10),
1747 Some(Duration::from_millis(5)),
1748 512,
1749 100,
1750 );
1751 let profiles = profiler.get_layer_profiles();
1752 let lp = &profiles["layer1"];
1753 assert_eq!(lp.forward_times().len(), 1);
1754 assert_eq!(lp.backward_times().len(), 1);
1755 assert_eq!(lp.memory_usage(), &vec![512]);
1756 assert_eq!(lp.call_count(), 1);
1757 }
1758}