Skip to main content

trustformers_debug/profiler/
mod.rs

1//! Performance profiling tools for debugging
2// reason: debug/profiling scaffolding — structs are constructed and their fields/methods
3// are retained for the data model, serialization completeness, and future consumers that
4// do not yet read every member. Consolidated from many item-level #[allow(dead_code)].
5#![allow(dead_code)]
6
7pub mod events;
8pub mod gpu;
9pub mod io_monitor;
10pub mod memory;
11pub mod report;
12
13// Re-export all public types from sub-modules
14pub 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/// Performance profiler
40#[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    // Enhanced profiling features
50    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    /// Long-lived `sysinfo` handle kept solely so that process CPU usage has a
59    /// previous sample to be a delta against. `sysinfo` computes
60    /// `Process::cpu_usage` between two consecutive refreshes of the *same*
61    /// `System`; a freshly constructed one therefore always reports `0.0`.
62    cpu_sampler: sysinfo::System,
63    /// When [`Self::cpu_sampler`] last refreshed the process. A second sample
64    /// is only meaningful once at least [`sysinfo::MINIMUM_CPU_UPDATE_INTERVAL`]
65    /// has elapsed.
66    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    /// Get forward execution times
80    pub fn forward_times(&self) -> &Vec<Duration> {
81        &self.forward_times
82    }
83
84    /// Get backward execution times
85    pub fn backward_times(&self) -> &Vec<Duration> {
86        &self.backward_times
87    }
88
89    /// Get memory usage samples
90    pub fn memory_usage(&self) -> &Vec<usize> {
91        &self.memory_usage
92    }
93
94    /// Get total number of calls
95    pub fn call_count(&self) -> usize {
96        self.call_count
97    }
98}
99
100/// Refresh only this process's CPU accounting on `system`.
101///
102/// Factored out so [`Profiler::new`]'s priming sample and
103/// [`Profiler::sample_process_cpu_usage`]'s measuring sample are provably the
104/// same operation on the same `System` -- which is the whole requirement for
105/// `sysinfo`'s CPU delta to be meaningful.
106fn 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    /// Create a new profiler
117    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            // Enhanced profiling features
127            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    /// Start profiling session
145    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    /// Get reference to profiling events
153    pub fn get_events(&self) -> &Vec<ProfileEvent> {
154        &self.events
155    }
156
157    /// Start timing a function or operation
158    pub fn start_timer(&mut self, name: &str) {
159        self.active_timers.insert(name.to_string(), Instant::now());
160    }
161
162    /// End timing and record the event
163    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            // Record basic function call event
168            self.events.push(ProfileEvent::FunctionCall {
169                function_name: name.to_string(),
170                duration,
171                memory_delta: 0, // Would need actual memory tracking
172            });
173
174            Some(duration)
175        } else {
176            tracing::warn!("Timer '{}' was not started", name);
177            None
178        }
179    }
180
181    /// Record layer execution timing
182    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        // Record event
192        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        // Update layer profile
202        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    /// Record tensor operation timing
222    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    /// Record model inference timing
238    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    /// Record gradient computation timing
255    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    /// Take a real memory usage snapshot of this process via `sysinfo`.
269    ///
270    /// Every field used to be a hardcoded `0`, so the whole snapshot series
271    /// read as "this process never allocated anything".
272    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            // No GPU driver is linked into this crate.
287            gpu_allocated: None,
288            gpu_used: None,
289        };
290
291        self.memory_snapshots.push(snapshot);
292
293        // Keep only recent snapshots to prevent memory growth
294        if self.memory_snapshots.len() > 1000 {
295            self.memory_snapshots.drain(0..500);
296        }
297    }
298
299    /// Analyze performance and detect bottlenecks
300    pub fn analyze_performance(&mut self) -> Vec<PerformanceBottleneck> {
301        self.bottlenecks.clear();
302
303        // Analyze layer execution times
304        self.analyze_layer_bottlenecks();
305
306        // Analyze memory usage patterns
307        self.analyze_memory_bottlenecks();
308
309        // Analyze tensor operation efficiency
310        self.analyze_tensor_bottlenecks();
311
312        self.bottlenecks.clone()
313    }
314
315    /// Get profiling statistics
316    pub fn get_statistics(&self) -> HashMap<String, ProfileStats> {
317        let mut stats = HashMap::new();
318
319        // Group events by type
320        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        // Calculate statistics for each event type
335        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, // Simplified
363                        avg_memory: 0.0,
364                    },
365                );
366            }
367        }
368
369        stats
370    }
371
372    /// Get layer-specific performance profiles
373    pub fn get_layer_profiles(&self) -> &HashMap<String, LayerProfile> {
374        &self.layer_profiles
375    }
376
377    /// Get memory usage over time
378    pub fn get_memory_timeline(&self) -> &[MemorySnapshot] {
379        &self.memory_snapshots
380    }
381
382    /// Generate performance report
383    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        // Calculate slowest layers
392        let slowest_layers = self.get_slowest_layers(5);
393
394        // Memory efficiency analysis
395        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    /// Clear all profiling data
409    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        // Clear enhanced profiling data
417        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    // Enhanced profiling methods
429
430    /// Profile GPU kernel execution
431    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    /// Track memory allocation
439    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    /// Track memory deallocation
467    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    /// Profile layer latency with detailed breakdown
479    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    /// Start I/O operation profiling
485    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    /// Finish I/O operation profiling
494    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    /// Take the second half of a two-sample process CPU measurement.
502    ///
503    /// `sysinfo` derives `Process::cpu_usage` from the CPU time consumed
504    /// between two refreshes of the same `System`; the first sample was taken
505    /// in [`Profiler::new`]. Refreshing a brand-new `System` once -- what this
506    /// code used to do -- can only ever report `0.0`, because there is no
507    /// earlier sample to subtract.
508    ///
509    /// Returns `None` when less than [`sysinfo::MINIMUM_CPU_UPDATE_INTERVAL`]
510    /// has passed since the previous sample (the platform counters have not
511    /// advanced enough for the quotient to mean anything) or when the process
512    /// cannot be read at all. It never blocks the caller waiting for that
513    /// interval: the other in-repo sampling sites can afford
514    /// `thread::sleep(MINIMUM_CPU_UPDATE_INTERVAL)` because they are dedicated
515    /// samplers, whereas this one runs inside report generation.
516    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    /// Analyse CPU bottlenecks from this profiler's own recorded layer
527    /// timings plus real process CPU usage from `sysinfo`.
528    ///
529    /// Hardware counters (context switches, cache misses, IPC, branch
530    /// mispredictions) are honestly `None`: reading them needs PMU access this
531    /// Pure-Rust crate does not have. They used to be published as the
532    /// constants 1000 / 500 / 2.5 / 100, alongside a fixed `hot_functions`
533    /// list naming `tensor_multiply` and `gradient_computation` regardless of
534    /// what had actually been profiled, and a fixed `bottleneck_score` of 0.6.
535    ///
536    /// Returns an empty vector when nothing has been profiled yet.
537    pub fn analyze_cpu_bottlenecks(&mut self) -> Vec<CpuBottleneckAnalysis> {
538        // Real per-layer totals from the recorded forward/backward times.
539        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        // Share of all recorded time spent in the single hottest layer.
579        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    /// Get memory allocation statistics
604    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    /// Get GPU utilization metrics
613    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    /// Get I/O bandwidth statistics
620    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    /// Get layer latency analysis
648    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    /// Get comprehensive performance analysis
691    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        // Deduct for bottlenecks
731        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        // Deduct for poor GPU utilization
741        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        // Deduct for memory inefficiency
750        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        // GPU utilization recommendations
763        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        // Memory recommendations
770        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        // I/O recommendations
781        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                // Less than 100 MB/s
785                recommendations.push(
786                    "Low SSD bandwidth utilization. Consider optimizing file I/O patterns."
787                        .to_string(),
788                );
789            }
790        }
791
792        // Layer-specific recommendations
793        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    // Private analysis methods
819
820    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            // Consider a layer slow if it takes more than 100ms on average
830            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        // Check for memory growth trend
865        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        // Only snapshots that carry a real RSS reading can show growth.
872        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        // Group tensor operations by type
908        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        // Find slow operations
922        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            // Consider operation slow if it takes more than 10ms on average
931            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            // Snapshots exist but none carried a real reading.
994            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        // Efficiency score: closer to 100% means more stable memory usage
1039        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        // Analyze bottlenecks for recommendations
1046        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        // General recommendations based on profiling data
1069        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    /// Generate enhanced profiler report with advanced metrics
1095    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
1209/// Scoped timer for automatic timing
1210pub 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 for convenient timing
1229#[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    // --- Profiler tests ---
1249
1250    #[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        // Should trim to ~500 after exceeding 1000
1372        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        // variance = ((100-200)^2 + (200-200)^2 + (300-200)^2) / 2 = 10000
1442        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        // 100 * (1.0 - (100-50)/100) = 50.0
1469        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        // Score starts at 100 but GPU utilization of 0.0 deducts 15 points
1478        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    /// Rewritten for Wave 6c: this used to assert `hot_functions.len() == 2`,
1589    /// which only held because the two entries were the hardcoded literals
1590    /// `tensor_multiply` and `gradient_computation` -- present no matter what
1591    /// (or whether anything) had been profiled.
1592    #[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        // PMU counters are not readable from Pure Rust; they must be absent,
1646        // not the old constants 1000 / 500 / 2.5 / 100.
1647        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    /// Regression test for the single-refresh `sysinfo` bug: the previous
1654    /// implementation built a fresh `System`, refreshed it once and read
1655    /// `cpu_usage()`, which is a delta against a previous refresh that did not
1656    /// exist -- so it could only ever report `Some(0.0)` no matter how much
1657    /// CPU the process was burning.
1658    #[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        // Burn CPU on this thread for longer than sysinfo's minimum sampling
1665        // interval, then measure. Retried a few times so a scheduler hiccup on
1666        // a loaded machine cannot fail the run; the old code failed all
1667        // attempts by construction.
1668        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    /// The documented honest-absence half of the same contract: asked again
1696    /// before the platform counters can have moved, the profiler reports
1697    /// `None` rather than a meaningless quotient.
1698    #[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        // Self-checking rather than clock-dependent: only assert the absence
1705        // if the interval really was too short. A scheduler stall between
1706        // `Profiler::new` and this call would otherwise flip the result on a
1707        // loaded machine.
1708        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}