|
| 1 | +# Logging Standards for Synaptic |
| 2 | + |
| 3 | +## Overview |
| 4 | + |
| 5 | +This document defines the logging standards and best practices for the Synaptic memory system. Consistent logging is crucial for production monitoring, debugging, and observability. |
| 6 | + |
| 7 | +## Logging Framework |
| 8 | + |
| 9 | +We use the `tracing` crate for structured logging throughout the codebase. This provides: |
| 10 | +- Structured, machine-readable logs |
| 11 | +- Hierarchical spans for request tracing |
| 12 | +- Configurable log levels |
| 13 | +- Rich context information |
| 14 | + |
| 15 | +## Log Levels |
| 16 | + |
| 17 | +### ERROR |
| 18 | +Use for errors that require immediate attention or indicate system failures: |
| 19 | +```rust |
| 20 | +tracing::error!( |
| 21 | + error = %err, |
| 22 | + operation = "memory_store", |
| 23 | + key = %memory_key, |
| 24 | + "Failed to store memory entry" |
| 25 | +); |
| 26 | +``` |
| 27 | + |
| 28 | +**When to use:** |
| 29 | +- Database connection failures |
| 30 | +- Critical system errors |
| 31 | +- Security violations |
| 32 | +- Data corruption |
| 33 | + |
| 34 | +### WARN |
| 35 | +Use for potentially problematic situations that don't stop execution: |
| 36 | +```rust |
| 37 | +tracing::warn!( |
| 38 | + threshold = %threshold, |
| 39 | + current_usage = %usage, |
| 40 | + "Memory usage approaching threshold" |
| 41 | +); |
| 42 | +``` |
| 43 | + |
| 44 | +**When to use:** |
| 45 | +- Resource usage warnings |
| 46 | +- Deprecated API usage |
| 47 | +- Configuration issues |
| 48 | +- Performance degradation |
| 49 | + |
| 50 | +### INFO |
| 51 | +Use for general operational information: |
| 52 | +```rust |
| 53 | +tracing::info!( |
| 54 | + component = "memory_manager", |
| 55 | + operation = "consolidation", |
| 56 | + memories_processed = %count, |
| 57 | + duration_ms = %duration.as_millis(), |
| 58 | + "Memory consolidation completed" |
| 59 | +); |
| 60 | +``` |
| 61 | + |
| 62 | +**When to use:** |
| 63 | +- System startup/shutdown |
| 64 | +- Major operation completion |
| 65 | +- Configuration changes |
| 66 | +- User actions |
| 67 | + |
| 68 | +### DEBUG |
| 69 | +Use for detailed diagnostic information: |
| 70 | +```rust |
| 71 | +tracing::debug!( |
| 72 | + query = %query_text, |
| 73 | + results_count = %results.len(), |
| 74 | + execution_time_ms = %execution_time.as_millis(), |
| 75 | + "Search query executed" |
| 76 | +); |
| 77 | +``` |
| 78 | + |
| 79 | +**When to use:** |
| 80 | +- Algorithm execution details |
| 81 | +- Internal state changes |
| 82 | +- Performance metrics |
| 83 | +- Detailed operation flow |
| 84 | + |
| 85 | +### TRACE |
| 86 | +Use for very detailed diagnostic information: |
| 87 | +```rust |
| 88 | +tracing::trace!( |
| 89 | + step = "similarity_calculation", |
| 90 | + vector_a_len = %vector_a.len(), |
| 91 | + vector_b_len = %vector_b.len(), |
| 92 | + similarity_score = %score, |
| 93 | + "Calculated vector similarity" |
| 94 | +); |
| 95 | +``` |
| 96 | + |
| 97 | +**When to use:** |
| 98 | +- Fine-grained execution flow |
| 99 | +- Loop iterations |
| 100 | +- Mathematical calculations |
| 101 | +- Low-level operations |
| 102 | + |
| 103 | +## Structured Logging Patterns |
| 104 | + |
| 105 | +### Standard Fields |
| 106 | + |
| 107 | +Always include these fields when relevant: |
| 108 | + |
| 109 | +```rust |
| 110 | +tracing::info!( |
| 111 | + component = "memory_manager", // Module/component name |
| 112 | + operation = "store", // Operation being performed |
| 113 | + user_id = %user_id, // User context (if applicable) |
| 114 | + session_id = %session_id, // Session context (if applicable) |
| 115 | + duration_ms = %duration.as_millis(), // Operation duration |
| 116 | + "Operation completed successfully" |
| 117 | +); |
| 118 | +``` |
| 119 | + |
| 120 | +### Error Logging Pattern |
| 121 | + |
| 122 | +```rust |
| 123 | +tracing::error!( |
| 124 | + error = %err, // Error details |
| 125 | + error_type = "ValidationError", // Error classification |
| 126 | + component = "input_validator", // Where error occurred |
| 127 | + operation = "validate_memory", // What was being done |
| 128 | + input_size = %input.len(), // Relevant context |
| 129 | + "Input validation failed" |
| 130 | +); |
| 131 | +``` |
| 132 | + |
| 133 | +### Performance Logging Pattern |
| 134 | + |
| 135 | +```rust |
| 136 | +tracing::info!( |
| 137 | + component = "search_engine", |
| 138 | + operation = "semantic_search", |
| 139 | + query_complexity = %complexity, |
| 140 | + results_count = %results.len(), |
| 141 | + cache_hit = %cache_hit, |
| 142 | + duration_ms = %duration.as_millis(), |
| 143 | + memory_usage_mb = %memory_usage / 1024 / 1024, |
| 144 | + "Search operation completed" |
| 145 | +); |
| 146 | +``` |
| 147 | + |
| 148 | +## Spans for Request Tracing |
| 149 | + |
| 150 | +Use spans to trace operations across multiple functions: |
| 151 | + |
| 152 | +```rust |
| 153 | +#[tracing::instrument( |
| 154 | + name = "memory_consolidation", |
| 155 | + fields( |
| 156 | + memory_count = %memories.len(), |
| 157 | + strategy = %strategy_name |
| 158 | + ) |
| 159 | +)] |
| 160 | +async fn consolidate_memories( |
| 161 | + memories: &[MemoryEntry], |
| 162 | + strategy_name: &str |
| 163 | +) -> Result<ConsolidationResult> { |
| 164 | + tracing::info!("Starting memory consolidation"); |
| 165 | + |
| 166 | + // Operation implementation |
| 167 | + |
| 168 | + tracing::info!( |
| 169 | + consolidated_count = %result.consolidated_count, |
| 170 | + "Consolidation completed successfully" |
| 171 | + ); |
| 172 | + |
| 173 | + Ok(result) |
| 174 | +} |
| 175 | +``` |
| 176 | + |
| 177 | +## Context Propagation |
| 178 | + |
| 179 | +Use the `tracing::Span::current()` to add context to existing spans: |
| 180 | + |
| 181 | +```rust |
| 182 | +async fn process_memory(&self, memory: &MemoryEntry) -> Result<()> { |
| 183 | + let span = tracing::Span::current(); |
| 184 | + span.record("memory_id", &memory.id); |
| 185 | + span.record("memory_type", &format!("{:?}", memory.memory_type)); |
| 186 | + |
| 187 | + // Processing logic |
| 188 | +} |
| 189 | +``` |
| 190 | + |
| 191 | +## What NOT to Log |
| 192 | + |
| 193 | +### Avoid println!/eprintln! |
| 194 | +Never use `println!` or `eprintln!` in production code. Use tracing instead: |
| 195 | + |
| 196 | +```rust |
| 197 | +// ❌ Don't do this |
| 198 | +println!("Processing memory: {}", memory_id); |
| 199 | + |
| 200 | +// ✅ Do this instead |
| 201 | +tracing::info!( |
| 202 | + memory_id = %memory_id, |
| 203 | + "Processing memory entry" |
| 204 | +); |
| 205 | +``` |
| 206 | + |
| 207 | +### Sensitive Information |
| 208 | +Never log sensitive data: |
| 209 | +- Passwords or API keys |
| 210 | +- Personal information |
| 211 | +- Encryption keys |
| 212 | +- Session tokens |
| 213 | + |
| 214 | +```rust |
| 215 | +// ❌ Don't do this |
| 216 | +tracing::info!("User password: {}", password); |
| 217 | + |
| 218 | +// ✅ Do this instead |
| 219 | +tracing::info!( |
| 220 | + user_id = %user_id, |
| 221 | + "User authentication successful" |
| 222 | +); |
| 223 | +``` |
| 224 | + |
| 225 | +### High-Frequency Logs |
| 226 | +Avoid logging in tight loops or high-frequency operations without rate limiting: |
| 227 | + |
| 228 | +```rust |
| 229 | +// ❌ Don't do this |
| 230 | +for item in large_collection { |
| 231 | + tracing::debug!("Processing item: {:?}", item); |
| 232 | +} |
| 233 | + |
| 234 | +// ✅ Do this instead |
| 235 | +tracing::debug!( |
| 236 | + item_count = %large_collection.len(), |
| 237 | + "Processing collection" |
| 238 | +); |
| 239 | +for (index, item) in large_collection.iter().enumerate() { |
| 240 | + if index % 1000 == 0 { |
| 241 | + tracing::debug!( |
| 242 | + processed = %index, |
| 243 | + total = %large_collection.len(), |
| 244 | + "Processing progress" |
| 245 | + ); |
| 246 | + } |
| 247 | +} |
| 248 | +``` |
| 249 | + |
| 250 | +## Configuration |
| 251 | + |
| 252 | +### Log Levels by Environment |
| 253 | + |
| 254 | +- **Development**: `TRACE` or `DEBUG` |
| 255 | +- **Testing**: `INFO` or `WARN` |
| 256 | +- **Production**: `INFO` or `WARN` |
| 257 | +- **Critical Systems**: `WARN` or `ERROR` |
| 258 | + |
| 259 | +### Environment Variables |
| 260 | + |
| 261 | +```bash |
| 262 | +# Set log level |
| 263 | +RUST_LOG=synaptic=info |
| 264 | + |
| 265 | +# Component-specific levels |
| 266 | +RUST_LOG=synaptic::memory=debug,synaptic::search=info |
| 267 | + |
| 268 | +# JSON output for production |
| 269 | +SYNAPTIC_LOG_FORMAT=json |
| 270 | +``` |
| 271 | + |
| 272 | +## Testing Logging |
| 273 | + |
| 274 | +Use `tracing-test` for testing log output: |
| 275 | + |
| 276 | +```rust |
| 277 | +#[cfg(test)] |
| 278 | +mod tests { |
| 279 | + use tracing_test::traced_test; |
| 280 | + |
| 281 | + #[traced_test] |
| 282 | + #[tokio::test] |
| 283 | + async fn test_memory_operation() { |
| 284 | + // Test implementation |
| 285 | + |
| 286 | + // Verify logs were emitted |
| 287 | + assert!(logs_contain("Memory operation completed")); |
| 288 | + } |
| 289 | +} |
| 290 | +``` |
| 291 | + |
| 292 | +## Monitoring Integration |
| 293 | + |
| 294 | +Logs should integrate with monitoring systems: |
| 295 | + |
| 296 | +```rust |
| 297 | +// Add correlation IDs for distributed tracing |
| 298 | +tracing::info!( |
| 299 | + trace_id = %trace_id, |
| 300 | + span_id = %span_id, |
| 301 | + component = "memory_manager", |
| 302 | + "Operation started" |
| 303 | +); |
| 304 | +``` |
| 305 | + |
| 306 | +## Performance Considerations |
| 307 | + |
| 308 | +- Use lazy evaluation for expensive log formatting |
| 309 | +- Consider log sampling for high-volume operations |
| 310 | +- Use appropriate log levels to control verbosity |
| 311 | +- Avoid string allocation in hot paths |
| 312 | + |
| 313 | +```rust |
| 314 | +// ❌ Expensive formatting always executed |
| 315 | +tracing::debug!("Complex data: {}", expensive_format(&data)); |
| 316 | + |
| 317 | +// ✅ Lazy evaluation |
| 318 | +tracing::debug!(data = ?data, "Complex data processed"); |
| 319 | +``` |
| 320 | + |
| 321 | +This logging standard ensures consistent, structured, and useful logging throughout the Synaptic codebase. |
0 commit comments