# Understanding Traces Learn what ChronoTrace captures, how traces are structured, and how to interpret the data to effectively debug your Laravel application. --- ## 🎯 What is a Trace? A **trace** is a complete snapshot of a single HTTP request execution in your Laravel application. It captures: - **Request details** (URL, method, headers, payload) - **Response information** (status, headers, body) - **Execution timeline** with precise timestamps - **All events** that occurred during processing - **Performance metrics** (duration, memory usage) - **Error context** if the request failed Think of it as a "flight recorder" for your Laravel requests. --- ## 📊 Trace Structure ### High-Level Structure ```json { "trace_id": "chronotrace_20240806_143015_abc123", "request_info": { /* Request details */ }, "response_info": { /* Response details */ }, "performance": { /* Timing and memory */ }, "events": { "database": [ /* DB queries */ ], "cache": [ /* Cache operations */ ], "http": [ /* External API calls */ ], "jobs": [ /* Queue jobs */ ], "custom": [ /* Application events */ ] }, "metadata": { /* Trace metadata */ } } ``` ### Detailed Breakdown #### Request Information ```json { "request_info": { "method": "POST", "url": "https://example.com/api/users", "headers": { "Content-Type": "application/json", "Authorization": "[REDACTED]", "User-Agent": "Mozilla/5.0..." }, "body": { "name": "John Doe", "email": "[REDACTED]", "password": "[REDACTED]" }, "ip_address": "192.168.1.100", "user_id": 123, "session_id": "sess_abc123" } } ``` #### Performance Metrics ```json { "performance": { "total_duration_ms": 245, "memory_peak_mb": 12.5, "memory_start_mb": 8.2, "cpu_time_ms": 180, "started_at": "2024-08-06T14:30:15.123Z", "ended_at": "2024-08-06T14:30:15.368Z" } } ``` #### Event Timeline ```json { "events": { "database": [ { "timestamp": "2024-08-06T14:30:15.125Z", "offset_ms": 2, "sql": "SELECT * FROM users WHERE email = ?", "bindings": ["[REDACTED]"], "duration_ms": 5, "connection": "mysql", "rows_affected": 1 } ], "cache": [ { "timestamp": "2024-08-06T14:30:15.135Z", "offset_ms": 12, "operation": "get", "key": "user:123:profile", "result": "hit", "store": "redis", "ttl_seconds": 3600 } ] } } ``` --- ## 🕒 Timeline and Timing ### Understanding Timestamps ChronoTrace uses multiple timing references to help you understand execution flow: ``` Request Start: 2024-08-06T14:30:15.123Z (0ms) ├── [+2ms] Database Query: SELECT users ├── [+12ms] Cache GET: user:123:profile ├── [+45ms] HTTP POST: external-api.com ├── [+125ms] Database INSERT: user_activities ├── [+180ms] Cache SET: user:123:last_activity └── [+245ms] Request End: Response sent ``` #### Key Timing Concepts - **Absolute Timestamp**: Exact time when event occurred - **Relative Offset**: Milliseconds since request start - **Event Duration**: How long the specific operation took - **Total Duration**: Complete request processing time ### Example Timeline Analysis ```bash # Replay trace with timing focus php artisan chronotrace:replay abc123 --show-timeline ``` ``` ┌─ REQUEST TIMELINE ──────────────────────────────────────────┐ │ Total Duration: 245ms │ │ │ │ 0ms ████ Request Start │ │ 2ms ████ DB Query (5ms) │ │ 12ms ████ Cache Hit (1ms) │ │ 45ms ████████████████ HTTP Call (80ms) │ │ 125ms ████ DB Insert (3ms) │ │ 180ms ████ Cache Set (2ms) │ │ 245ms ████ Response Sent │ │ │ │ 🔍 Analysis: │ │ • HTTP call accounts for 33% of total time │ │ • Database operations: 8ms total (3% of time) │ │ • Cache operations: 3ms total (1% of time) │ │ • Opportunity: Optimize external API call │ └─────────────────────────────────────────────────────────────┘ ``` --- ## 🗃️ Event Types ### Database Events Captures all database interactions: ```json { "type": "database", "timestamp": "2024-08-06T14:30:15.125Z", "sql": "SELECT id, name, email FROM users WHERE active = ? AND created_at > ?", "bindings": [true, "2024-01-01 00:00:00"], "duration_ms": 15, "connection": "mysql", "rows_returned": 150, "query_type": "select", "table": "users" } ``` **What to look for:** - Slow queries (>100ms) - N+1 query patterns - Large result sets - Missing indexes (high duration + many rows) ### Cache Events Tracks cache operations and efficiency: ```json { "type": "cache", "operation": "get", "key": "products:featured:2024-08-06", "result": "miss", "store": "redis", "duration_ms": 2, "subsequent_action": "database_fallback" } ``` **What to look for:** - High cache miss rates - Expensive cache misses followed by DB queries - Cache stampeding patterns - Inefficient cache keys ### HTTP Events Monitors external API calls: ```json { "type": "http", "method": "POST", "url": "https://api.stripe.com/v1/charges", "request_headers": { "Authorization": "[REDACTED]", "Content-Type": "application/x-www-form-urlencoded" }, "request_body": "amount=2999¤cy=usd&source=tok_[REDACTED]", "response_status": 200, "response_headers": { "Content-Type": "application/json" }, "response_body": "{\"id\": \"ch_[REDACTED]\", \"status\": \"succeeded\"}", "duration_ms": 1250, "connection_time_ms": 45, "dns_time_ms": 12 } ``` **What to look for:** - Slow external APIs - Failed API calls - Timeout patterns - High connection overhead ### Queue Events Tracks job dispatching and processing: ```json { "type": "job", "action": "dispatched", "job_class": "App\\Jobs\\SendWelcomeEmail", "queue": "emails", "delay_seconds": 0, "payload": { "user_id": 123, "template": "welcome" }, "job_id": "job_abc123" } ``` **What to look for:** - Jobs failing to dispatch - Queue backlogs - Job processing delays - Heavy job payloads --- ## 🔍 Analyzing Trace Data ### Performance Analysis #### Identifying Bottlenecks 1. **Look at total duration first** ```bash # Find slow requests php artisan chronotrace:list --min-duration=1000 ``` 2. **Analyze the timeline** ```bash # Focus on timing php artisan chronotrace:replay abc123 --timeline ``` 3. **Identify the biggest time consumers** - Database queries >100ms - HTTP calls >500ms - Large memory allocations #### Memory Analysis ```json { "memory_analysis": { "peak_mb": 45.2, "growth_points": [ { "timestamp": "2024-08-06T14:30:15.145Z", "memory_mb": 25.1, "event": "Large collection loaded", "trigger": "User::with('posts', 'comments')->get()" } ], "recommendations": [ "Use pagination for large collections", "Implement lazy loading", "Consider select() to limit columns" ] } } ``` ### Error Analysis When traces capture errors, they include: ```json { "error_info": { "type": "Illuminate\\Database\\QueryException", "message": "SQLSTATE[23000]: Integrity constraint violation", "file": "/app/Models/User.php", "line": 45, "stack_trace": "...", "context": { "sql": "INSERT INTO users (email) VALUES (?)", "bindings": ["duplicate@example.com"] } } } ``` **Error analysis workflow:** 1. **Identify the error point** in the timeline 2. **Examine events leading up to the error** 3. **Check for data validation issues** 4. **Look for race conditions or conflicts** --- ## 📈 Trace Patterns ### Common Patterns to Recognize #### N+1 Query Pattern ``` [+0ms] SELECT * FROM posts WHERE user_id = 123 [+5ms] SELECT * FROM users WHERE id = 456 ← N+1 starts [+8ms] SELECT * FROM users WHERE id = 789 ← N+1 continues [+11ms] SELECT * FROM users WHERE id = 012 ← N+1 continues ``` **Solution**: Use eager loading ```php $posts = Post::with('user')->where('user_id', 123)->get(); ``` #### Cache Stampede Pattern ``` [+0ms] Cache MISS: expensive_calculation [+1ms] Cache MISS: expensive_calculation ← Multiple misses [+2ms] Cache MISS: expensive_calculation ← Concurrent requests [+3ms] Database query: expensive_calculation (1500ms) [+1503ms] Cache SET: expensive_calculation ``` **Solution**: Use cache locks ```php Cache::lock('expensive_calculation')->get(function () { return Cache::remember('expensive_calculation', 3600, function () { return $this->performExpensiveCalculation(); }); }); ``` #### API Timeout Cascade ``` [+0ms] HTTP POST: api.payment.com (timeout after 30s) [+30000ms] HTTP POST: api.payment.com (retry #1, timeout) [+60000ms] HTTP POST: api.payment.com (retry #2, timeout) [+90000ms] ERROR: Payment processing failed ``` **Solution**: Implement circuit breaker and better timeout handling --- ## 🎯 Best Practices for Trace Analysis ### 1. Start with the Big Picture Always begin by looking at: - Total request duration - HTTP status code - Memory usage - Error presence ### 2. Follow the Timeline Examine events chronologically: - What triggered the slow operation? - Are there patterns in the timing? - Where did things go wrong? ### 3. Focus on the Biggest Issues First Prioritize optimization by impact: - Operations taking >10% of total time - Operations with error rates >1% - Memory spikes >50% increase ### 4. Compare Similar Requests Look at multiple traces for the same endpoint: ```bash # Compare performance across similar requests php artisan chronotrace:list --route="api/users" --limit=10 ``` ### 5. Use Filtering Effectively Focus on specific aspects: ```bash # Only database events php artisan chronotrace:replay abc123 --filter=database # Only slow events php artisan chronotrace:replay abc123 --min-duration=100 # Only errors php artisan chronotrace:list --status=error ``` --- ## 🔧 Trace Metadata ### Understanding Metadata Each trace includes helpful metadata: ```json { "metadata": { "chronotrace_version": "1.0.0", "laravel_version": "11.x", "php_version": "8.3.0", "environment": "production", "server_info": { "hostname": "web-server-01", "ip": "10.0.1.100" }, "capture_settings": { "mode": "record_on_error", "events_captured": ["database", "http", "jobs"], "pii_scrubbed": true } } } ``` This helps with: - **Environment correlation** - Compare dev vs production - **Version tracking** - Identify when issues started - **Configuration validation** - Verify settings are correct --- ## 📚 Related Documentation - **[Basic Usage](Basic-Usage.md)** - Learn how to work with traces - **[Event Capturing](Event-Capturing.md)** - Configure what events to capture - **[Event Filtering](Event-Filtering.md)** - Focus on specific event types - **[Performance Analysis](Example-Performance-Analysis.md)** - Advanced analysis techniques --- **Understanding traces is key to effective debugging!** Take time to explore the structure and you'll quickly become proficient at identifying and solving performance issues.