oxirs_tdb/
slow_query_log.rs

1//! # Slow Query Logging and Analysis
2//!
3//! Provides comprehensive slow query logging for production monitoring and
4//! performance analysis. Captures detailed query execution metrics and
5//! provides analysis tools for identifying bottlenecks.
6
7use crate::dictionary::NodeId;
8use crate::query_hints::IndexType;
9use scirs2_core::metrics::{Counter, Histogram, Timer};
10use serde::{Deserialize, Serialize};
11use std::collections::VecDeque;
12use std::sync::atomic::{AtomicU64, Ordering};
13use std::sync::Arc;
14use std::time::{Duration, Instant, SystemTime};
15
16/// Configuration for slow query logging
17#[derive(Debug, Clone)]
18pub struct SlowQueryConfig {
19    /// Threshold for logging slow queries (milliseconds)
20    pub threshold_ms: u64,
21    /// Maximum number of slow queries to keep in memory
22    pub max_entries: usize,
23    /// Enable detailed execution plan logging
24    pub log_execution_plan: bool,
25    /// Enable stack trace capture for very slow queries
26    pub capture_stack_trace: bool,
27    /// Very slow query threshold for stack trace (milliseconds)
28    pub very_slow_threshold_ms: u64,
29    /// Enable automatic analysis
30    pub enable_analysis: bool,
31}
32
33impl Default for SlowQueryConfig {
34    fn default() -> Self {
35        Self {
36            threshold_ms: 100,            // Log queries > 100ms
37            max_entries: 1000,            // Keep last 1000 slow queries
38            log_execution_plan: true,     // Log execution plans
39            capture_stack_trace: false,   // Disabled by default (performance cost)
40            very_slow_threshold_ms: 1000, // Stack trace for queries > 1s
41            enable_analysis: true,        // Enable analysis
42        }
43    }
44}
45
46/// Slow query log entry
47#[derive(Debug, Clone, Serialize, Deserialize)]
48pub struct SlowQueryEntry {
49    /// Unique query ID
50    pub query_id: u64,
51    /// Timestamp when query started
52    pub timestamp: SystemTime,
53    /// Query execution time
54    pub duration_ms: u64,
55    /// Query pattern (subject, predicate, object)
56    pub pattern: QueryPattern,
57    /// Index used for execution
58    pub index_used: Option<IndexType>,
59    /// Number of results returned
60    pub result_count: usize,
61    /// Number of triples scanned
62    pub triples_scanned: usize,
63    /// Execution plan explanation
64    pub execution_plan: Option<String>,
65    /// Error message if query failed
66    pub error: Option<String>,
67    /// Transaction ID
68    pub transaction_id: Option<u64>,
69    /// Stack trace (if captured)
70    pub stack_trace: Option<String>,
71}
72
73/// Query pattern for logging
74#[derive(Debug, Clone, Serialize, Deserialize)]
75pub struct QueryPattern {
76    /// Subject (Some for bound, None for unbound)
77    pub subject: Option<NodeId>,
78    /// Predicate (Some for bound, None for unbound)
79    pub predicate: Option<NodeId>,
80    /// Object (Some for bound, None for unbound)
81    pub object: Option<NodeId>,
82}
83
84/// Query finish information for logging
85#[derive(Debug, Clone)]
86pub struct QueryFinishInfo {
87    /// Query pattern (subject, predicate, object)
88    pub pattern: QueryPattern,
89    /// Index used for execution
90    pub index_used: Option<IndexType>,
91    /// Number of results returned
92    pub result_count: usize,
93    /// Number of triples scanned
94    pub triples_scanned: usize,
95    /// Execution plan explanation
96    pub execution_plan: Option<String>,
97    /// Error message if query failed
98    pub error: Option<String>,
99    /// Transaction ID
100    pub transaction_id: Option<u64>,
101}
102
103impl QueryPattern {
104    /// Create new query pattern
105    pub fn new(s: Option<NodeId>, p: Option<NodeId>, o: Option<NodeId>) -> Self {
106        Self {
107            subject: s,
108            predicate: p,
109            object: o,
110        }
111    }
112
113    /// Get pattern signature for grouping
114    pub fn signature(&self) -> String {
115        format!(
116            "{}-{}-{}",
117            if self.subject.is_some() { "B" } else { "U" },
118            if self.predicate.is_some() { "B" } else { "U" },
119            if self.object.is_some() { "B" } else { "U" }
120        )
121    }
122
123    /// Count bound positions
124    pub fn bound_count(&self) -> usize {
125        let mut count = 0;
126        if self.subject.is_some() {
127            count += 1;
128        }
129        if self.predicate.is_some() {
130            count += 1;
131        }
132        if self.object.is_some() {
133            count += 1;
134        }
135        count
136    }
137}
138
139/// Analysis summary for slow queries
140#[derive(Debug, Clone, Serialize, Deserialize)]
141pub struct SlowQueryAnalysis {
142    /// Total slow queries
143    pub total_slow_queries: usize,
144    /// Average duration of slow queries (ms)
145    pub avg_duration_ms: f64,
146    /// Maximum duration (ms)
147    pub max_duration_ms: u64,
148    /// Most common query patterns
149    pub common_patterns: Vec<(String, usize)>,
150    /// Most expensive query patterns (by total time)
151    pub expensive_patterns: Vec<(String, f64)>,
152    /// Index usage statistics
153    pub index_usage: std::collections::HashMap<IndexType, usize>,
154    /// Recommendations
155    pub recommendations: Vec<String>,
156}
157
158/// Slow query logger
159pub struct SlowQueryLogger {
160    /// Configuration
161    config: SlowQueryConfig,
162    /// Slow query log entries
163    entries: parking_lot::RwLock<VecDeque<SlowQueryEntry>>,
164    /// Next query ID
165    next_query_id: AtomicU64,
166    /// Metrics
167    slow_query_counter: Counter,
168    query_duration_histogram: Histogram,
169    very_slow_query_counter: Counter,
170}
171
172impl SlowQueryLogger {
173    /// Create a new slow query logger
174    pub fn new(config: SlowQueryConfig) -> Self {
175        Self {
176            config,
177            entries: parking_lot::RwLock::new(VecDeque::new()),
178            next_query_id: AtomicU64::new(1),
179            slow_query_counter: Counter::new("slow_queries_total".to_string()),
180            query_duration_histogram: Histogram::new("slow_query_duration_ms".to_string()),
181            very_slow_query_counter: Counter::new("very_slow_queries_total".to_string()),
182        }
183    }
184
185    /// Start tracking a query
186    pub fn start_query(&self) -> QueryTracker<'_> {
187        QueryTracker {
188            logger: self,
189            query_id: self.next_query_id.fetch_add(1, Ordering::Relaxed),
190            start_time: Instant::now(),
191            timestamp: SystemTime::now(),
192        }
193    }
194
195    /// Log a slow query
196    pub fn log_slow_query(&self, entry: SlowQueryEntry) {
197        // Update metrics
198        self.slow_query_counter.inc();
199        self.query_duration_histogram
200            .observe(entry.duration_ms as f64);
201
202        if entry.duration_ms >= self.config.very_slow_threshold_ms {
203            self.very_slow_query_counter.inc();
204        }
205
206        // Add to log
207        let mut entries = self.entries.write();
208        entries.push_back(entry);
209
210        // Enforce maximum size
211        while entries.len() > self.config.max_entries {
212            entries.pop_front();
213        }
214    }
215
216    /// Get slow query entries
217    pub fn get_entries(&self) -> Vec<SlowQueryEntry> {
218        self.entries.read().iter().cloned().collect()
219    }
220
221    /// Get entries matching a pattern signature
222    pub fn get_entries_by_pattern(&self, signature: &str) -> Vec<SlowQueryEntry> {
223        self.entries
224            .read()
225            .iter()
226            .filter(|e| e.pattern.signature() == signature)
227            .cloned()
228            .collect()
229    }
230
231    /// Get slowest queries
232    pub fn get_slowest(&self, limit: usize) -> Vec<SlowQueryEntry> {
233        let mut entries = self.get_entries();
234        entries.sort_by_key(|b| std::cmp::Reverse(b.duration_ms));
235        entries.truncate(limit);
236        entries
237    }
238
239    /// Analyze slow queries
240    pub fn analyze(&self) -> SlowQueryAnalysis {
241        let entries = self.get_entries();
242
243        if entries.is_empty() {
244            return SlowQueryAnalysis {
245                total_slow_queries: 0,
246                avg_duration_ms: 0.0,
247                max_duration_ms: 0,
248                common_patterns: Vec::new(),
249                expensive_patterns: Vec::new(),
250                index_usage: std::collections::HashMap::new(),
251                recommendations: Vec::new(),
252            };
253        }
254
255        // Calculate statistics
256        let total_duration: u64 = entries.iter().map(|e| e.duration_ms).sum();
257        let avg_duration = total_duration as f64 / entries.len() as f64;
258        let max_duration = entries.iter().map(|e| e.duration_ms).max().unwrap_or(0);
259
260        // Pattern frequency analysis
261        let mut pattern_counts: std::collections::HashMap<String, usize> =
262            std::collections::HashMap::new();
263        let mut pattern_total_time: std::collections::HashMap<String, u64> =
264            std::collections::HashMap::new();
265
266        for entry in &entries {
267            let signature = entry.pattern.signature();
268            *pattern_counts.entry(signature.clone()).or_insert(0) += 1;
269            *pattern_total_time.entry(signature).or_insert(0) += entry.duration_ms;
270        }
271
272        // Most common patterns
273        let mut common_patterns: Vec<(String, usize)> = pattern_counts.into_iter().collect();
274        common_patterns.sort_by_key(|b| std::cmp::Reverse(b.1));
275        common_patterns.truncate(10);
276
277        // Most expensive patterns (by total time)
278        let mut expensive_patterns: Vec<(String, f64)> = pattern_total_time
279            .into_iter()
280            .map(|(k, v)| (k, v as f64))
281            .collect();
282        expensive_patterns
283            .sort_by(|a, b| b.1.partial_cmp(&a.1).unwrap_or(std::cmp::Ordering::Equal));
284        expensive_patterns.truncate(10);
285
286        // Index usage statistics
287        let mut index_usage: std::collections::HashMap<IndexType, usize> =
288            std::collections::HashMap::new();
289        for entry in &entries {
290            if let Some(index) = entry.index_used {
291                *index_usage.entry(index).or_insert(0) += 1;
292            }
293        }
294
295        // Generate recommendations
296        let recommendations = self.generate_recommendations(&entries);
297
298        SlowQueryAnalysis {
299            total_slow_queries: entries.len(),
300            avg_duration_ms: avg_duration,
301            max_duration_ms: max_duration,
302            common_patterns,
303            expensive_patterns,
304            index_usage,
305            recommendations,
306        }
307    }
308
309    /// Generate optimization recommendations
310    fn generate_recommendations(&self, entries: &[SlowQueryEntry]) -> Vec<String> {
311        let mut recommendations = Vec::new();
312
313        // Check for full scans
314        let full_scans = entries
315            .iter()
316            .filter(|e| e.pattern.bound_count() == 0)
317            .count();
318
319        if full_scans > entries.len() / 10 {
320            recommendations.push(format!(
321                "High number of full scans detected ({} out of {}). Consider adding filters or indexes.",
322                full_scans,
323                entries.len()
324            ));
325        }
326
327        // Check for very slow queries
328        let very_slow = entries
329            .iter()
330            .filter(|e| e.duration_ms >= self.config.very_slow_threshold_ms)
331            .count();
332
333        if very_slow > 0 {
334            recommendations.push(format!(
335                "{} queries exceeded {} ms threshold. Investigate execution plans and consider query optimization.",
336                very_slow, self.config.very_slow_threshold_ms
337            ));
338        }
339
340        // Check for low selectivity queries
341        let low_selectivity = entries
342            .iter()
343            .filter(|e| e.result_count > 0 && e.triples_scanned > e.result_count * 10)
344            .count();
345
346        if low_selectivity > entries.len() / 5 {
347            recommendations.push(format!(
348                "{} queries have low selectivity (scanning many triples for few results). Consider adding more specific filters.",
349                low_selectivity
350            ));
351        }
352
353        // Check average duration
354        let avg_duration: f64 =
355            entries.iter().map(|e| e.duration_ms as f64).sum::<f64>() / entries.len() as f64;
356
357        if avg_duration > (self.config.threshold_ms as f64 * 5.0) {
358            recommendations.push(format!(
359                "Average slow query duration ({:.2} ms) is significantly above threshold. Consider system-wide optimization.",
360                avg_duration
361            ));
362        }
363
364        if recommendations.is_empty() {
365            recommendations.push("No major issues detected. Monitor regularly.".to_string());
366        }
367
368        recommendations
369    }
370
371    /// Clear all slow query entries
372    pub fn clear(&self) {
373        self.entries.write().clear();
374    }
375
376    /// Get configuration
377    pub fn config(&self) -> &SlowQueryConfig {
378        &self.config
379    }
380
381    /// Get metrics
382    pub fn get_metrics(&self) -> SlowQueryMetrics {
383        let histogram_stats = self.query_duration_histogram.get_stats();
384
385        SlowQueryMetrics {
386            total_slow_queries: self.slow_query_counter.get(),
387            very_slow_queries: self.very_slow_query_counter.get(),
388            avg_duration_ms: histogram_stats.mean,
389            entries_in_memory: self.entries.read().len(),
390        }
391    }
392}
393
394/// Metrics for slow query logger
395#[derive(Debug, Clone)]
396pub struct SlowQueryMetrics {
397    /// Total slow queries logged
398    pub total_slow_queries: u64,
399    /// Total very slow queries
400    pub very_slow_queries: u64,
401    /// Average duration
402    pub avg_duration_ms: f64,
403    /// Current entries in memory
404    pub entries_in_memory: usize,
405}
406
407/// Query tracker for automatic logging
408pub struct QueryTracker<'a> {
409    logger: &'a SlowQueryLogger,
410    query_id: u64,
411    start_time: Instant,
412    timestamp: SystemTime,
413}
414
415impl<'a> QueryTracker<'a> {
416    /// Finish tracking and log if slow
417    pub fn finish(self, info: QueryFinishInfo) {
418        let duration = self.start_time.elapsed();
419        let duration_ms = duration.as_millis() as u64;
420
421        // Only log if exceeds threshold
422        if duration_ms >= self.logger.config.threshold_ms {
423            let stack_trace = if self.logger.config.capture_stack_trace
424                && duration_ms >= self.logger.config.very_slow_threshold_ms
425            {
426                // In production, this would capture actual stack trace
427                // For now, we just note that it would be captured
428                Some("Stack trace would be captured here".to_string())
429            } else {
430                None
431            };
432
433            let entry = SlowQueryEntry {
434                query_id: self.query_id,
435                timestamp: self.timestamp,
436                duration_ms,
437                pattern: info.pattern,
438                index_used: info.index_used,
439                result_count: info.result_count,
440                triples_scanned: info.triples_scanned,
441                execution_plan: info.execution_plan,
442                error: info.error,
443                transaction_id: info.transaction_id,
444                stack_trace,
445            };
446
447            self.logger.log_slow_query(entry);
448        }
449    }
450}
451
452#[cfg(test)]
453mod tests {
454    use super::*;
455
456    #[test]
457    fn test_slow_query_logger_creation() {
458        let config = SlowQueryConfig::default();
459        let logger = SlowQueryLogger::new(config);
460
461        let metrics = logger.get_metrics();
462        assert_eq!(metrics.total_slow_queries, 0);
463        assert_eq!(metrics.entries_in_memory, 0);
464    }
465
466    #[test]
467    fn test_query_pattern_signature() {
468        let pattern1 = QueryPattern::new(Some(NodeId::new(1)), None, None);
469        assert_eq!(pattern1.signature(), "B-U-U");
470
471        let pattern2 = QueryPattern::new(None, Some(NodeId::new(2)), None);
472        assert_eq!(pattern2.signature(), "U-B-U");
473
474        let pattern3 = QueryPattern::new(
475            Some(NodeId::new(1)),
476            Some(NodeId::new(2)),
477            Some(NodeId::new(3)),
478        );
479        assert_eq!(pattern3.signature(), "B-B-B");
480    }
481
482    #[test]
483    fn test_log_slow_query() {
484        let config = SlowQueryConfig {
485            threshold_ms: 50,
486            ..Default::default()
487        };
488        let logger = SlowQueryLogger::new(config);
489
490        let entry = SlowQueryEntry {
491            query_id: 1,
492            timestamp: SystemTime::now(),
493            duration_ms: 150,
494            pattern: QueryPattern::new(None, None, None),
495            index_used: Some(IndexType::SPO),
496            result_count: 100,
497            triples_scanned: 1000,
498            execution_plan: Some("Full scan using SPO index".to_string()),
499            error: None,
500            transaction_id: Some(42),
501            stack_trace: None,
502        };
503
504        logger.log_slow_query(entry);
505
506        let entries = logger.get_entries();
507        assert_eq!(entries.len(), 1);
508        assert_eq!(entries[0].duration_ms, 150);
509    }
510
511    #[test]
512    fn test_max_entries_limit() {
513        let config = SlowQueryConfig {
514            max_entries: 5,
515            ..Default::default()
516        };
517        let logger = SlowQueryLogger::new(config);
518
519        // Log 10 entries
520        for i in 0..10 {
521            let entry = SlowQueryEntry {
522                query_id: i,
523                timestamp: SystemTime::now(),
524                duration_ms: 100 + i,
525                pattern: QueryPattern::new(None, None, None),
526                index_used: Some(IndexType::SPO),
527                result_count: 10,
528                triples_scanned: 100,
529                execution_plan: None,
530                error: None,
531                transaction_id: None,
532                stack_trace: None,
533            };
534            logger.log_slow_query(entry);
535        }
536
537        let entries = logger.get_entries();
538        assert_eq!(entries.len(), 5);
539        // Should keep the latest 5 (IDs 5-9)
540        assert_eq!(entries[0].query_id, 5);
541        assert_eq!(entries[4].query_id, 9);
542    }
543
544    #[test]
545    fn test_get_slowest_queries() {
546        let logger = SlowQueryLogger::new(SlowQueryConfig::default());
547
548        // Log queries with different durations
549        for (id, duration) in [(1, 100), (2, 500), (3, 200), (4, 800), (5, 150)] {
550            let entry = SlowQueryEntry {
551                query_id: id,
552                timestamp: SystemTime::now(),
553                duration_ms: duration,
554                pattern: QueryPattern::new(None, None, None),
555                index_used: Some(IndexType::SPO),
556                result_count: 10,
557                triples_scanned: 100,
558                execution_plan: None,
559                error: None,
560                transaction_id: None,
561                stack_trace: None,
562            };
563            logger.log_slow_query(entry);
564        }
565
566        let slowest = logger.get_slowest(3);
567        assert_eq!(slowest.len(), 3);
568        assert_eq!(slowest[0].duration_ms, 800); // ID 4
569        assert_eq!(slowest[1].duration_ms, 500); // ID 2
570        assert_eq!(slowest[2].duration_ms, 200); // ID 3
571    }
572
573    #[test]
574    fn test_analyze_slow_queries() {
575        let logger = SlowQueryLogger::new(SlowQueryConfig::default());
576
577        // Log various query patterns
578        for i in 0..10 {
579            let pattern = if i % 3 == 0 {
580                QueryPattern::new(None, None, None) // Full scan
581            } else if i % 3 == 1 {
582                QueryPattern::new(Some(NodeId::new(1)), None, None) // Subject bound
583            } else {
584                QueryPattern::new(
585                    Some(NodeId::new(1)),
586                    Some(NodeId::new(2)),
587                    Some(NodeId::new(3)),
588                ) // All bound
589            };
590
591            let entry = SlowQueryEntry {
592                query_id: i,
593                timestamp: SystemTime::now(),
594                duration_ms: 100 + i * 10,
595                pattern,
596                index_used: Some(IndexType::SPO),
597                result_count: 10,
598                triples_scanned: 100,
599                execution_plan: None,
600                error: None,
601                transaction_id: None,
602                stack_trace: None,
603            };
604            logger.log_slow_query(entry);
605        }
606
607        let analysis = logger.analyze();
608        assert_eq!(analysis.total_slow_queries, 10);
609        assert!(analysis.avg_duration_ms > 0.0);
610        assert!(!analysis.common_patterns.is_empty());
611        assert!(!analysis.recommendations.is_empty());
612    }
613
614    #[test]
615    fn test_pattern_grouping() {
616        let logger = SlowQueryLogger::new(SlowQueryConfig::default());
617
618        // Log same pattern multiple times
619        for i in 0..5 {
620            let entry = SlowQueryEntry {
621                query_id: i,
622                timestamp: SystemTime::now(),
623                duration_ms: 100,
624                pattern: QueryPattern::new(Some(NodeId::new(1)), None, None),
625                index_used: Some(IndexType::SPO),
626                result_count: 10,
627                triples_scanned: 100,
628                execution_plan: None,
629                error: None,
630                transaction_id: None,
631                stack_trace: None,
632            };
633            logger.log_slow_query(entry);
634        }
635
636        let entries = logger.get_entries_by_pattern("B-U-U");
637        assert_eq!(entries.len(), 5);
638    }
639
640    #[test]
641    fn test_query_tracker() {
642        let logger = SlowQueryLogger::new(SlowQueryConfig {
643            threshold_ms: 50,
644            ..Default::default()
645        });
646
647        let tracker = logger.start_query();
648        std::thread::sleep(Duration::from_millis(60));
649
650        tracker.finish(QueryFinishInfo {
651            pattern: QueryPattern::new(None, None, None),
652            index_used: Some(IndexType::SPO),
653            result_count: 100,
654            triples_scanned: 1000,
655            execution_plan: Some("Test plan".to_string()),
656            error: None,
657            transaction_id: Some(42),
658        });
659
660        let entries = logger.get_entries();
661        assert_eq!(entries.len(), 1);
662        assert!(entries[0].duration_ms >= 50);
663    }
664
665    #[test]
666    fn test_below_threshold_not_logged() {
667        let logger = SlowQueryLogger::new(SlowQueryConfig {
668            threshold_ms: 1000,
669            ..Default::default()
670        });
671
672        let tracker = logger.start_query();
673        std::thread::sleep(Duration::from_millis(10));
674
675        tracker.finish(QueryFinishInfo {
676            pattern: QueryPattern::new(None, None, None),
677            index_used: Some(IndexType::SPO),
678            result_count: 10,
679            triples_scanned: 100,
680            execution_plan: None,
681            error: None,
682            transaction_id: None,
683        });
684
685        let entries = logger.get_entries();
686        assert_eq!(entries.len(), 0); // Should not be logged
687    }
688
689    #[test]
690    fn test_clear_entries() {
691        let logger = SlowQueryLogger::new(SlowQueryConfig::default());
692
693        for i in 0..5 {
694            let entry = SlowQueryEntry {
695                query_id: i,
696                timestamp: SystemTime::now(),
697                duration_ms: 100,
698                pattern: QueryPattern::new(None, None, None),
699                index_used: Some(IndexType::SPO),
700                result_count: 10,
701                triples_scanned: 100,
702                execution_plan: None,
703                error: None,
704                transaction_id: None,
705                stack_trace: None,
706            };
707            logger.log_slow_query(entry);
708        }
709
710        assert_eq!(logger.get_entries().len(), 5);
711
712        logger.clear();
713        assert_eq!(logger.get_entries().len(), 0);
714    }
715
716    #[test]
717    fn test_recommendations_full_scans() {
718        let logger = SlowQueryLogger::new(SlowQueryConfig::default());
719
720        // Log mostly full scans
721        for i in 0..20 {
722            let pattern = if i < 15 {
723                QueryPattern::new(None, None, None) // Full scan
724            } else {
725                QueryPattern::new(Some(NodeId::new(1)), None, None)
726            };
727
728            let entry = SlowQueryEntry {
729                query_id: i,
730                timestamp: SystemTime::now(),
731                duration_ms: 100,
732                pattern,
733                index_used: Some(IndexType::SPO),
734                result_count: 100,
735                triples_scanned: 1000,
736                execution_plan: None,
737                error: None,
738                transaction_id: None,
739                stack_trace: None,
740            };
741            logger.log_slow_query(entry);
742        }
743
744        let analysis = logger.analyze();
745        assert!(!analysis.recommendations.is_empty());
746        // Should recommend addressing full scans
747        assert!(analysis
748            .recommendations
749            .iter()
750            .any(|r| r.contains("full scan")));
751    }
752
753    #[test]
754    fn test_metrics_tracking() {
755        let logger = SlowQueryLogger::new(SlowQueryConfig {
756            threshold_ms: 50,
757            very_slow_threshold_ms: 200,
758            ..Default::default()
759        });
760
761        // Log a slow query
762        let entry1 = SlowQueryEntry {
763            query_id: 1,
764            timestamp: SystemTime::now(),
765            duration_ms: 150,
766            pattern: QueryPattern::new(None, None, None),
767            index_used: Some(IndexType::SPO),
768            result_count: 10,
769            triples_scanned: 100,
770            execution_plan: None,
771            error: None,
772            transaction_id: None,
773            stack_trace: None,
774        };
775        logger.log_slow_query(entry1);
776
777        // Log a very slow query
778        let entry2 = SlowQueryEntry {
779            query_id: 2,
780            timestamp: SystemTime::now(),
781            duration_ms: 500,
782            pattern: QueryPattern::new(None, None, None),
783            index_used: Some(IndexType::SPO),
784            result_count: 10,
785            triples_scanned: 100,
786            execution_plan: None,
787            error: None,
788            transaction_id: None,
789            stack_trace: None,
790        };
791        logger.log_slow_query(entry2);
792
793        let metrics = logger.get_metrics();
794        assert_eq!(metrics.total_slow_queries, 2);
795        assert_eq!(metrics.very_slow_queries, 1);
796        assert!(metrics.avg_duration_ms > 0.0);
797    }
798}
oxirs_tdb/slow_query_log.rs

oxirs_tdb/
slow_query_log.rs
