# Database Debugging Example A real-world scenario showing how to use ChronoTrace to debug database performance issues and query problems in a Laravel application. --- ## 🎯 Scenario: Slow User Dashboard Your users are complaining that the dashboard loads slowly. Let's use ChronoTrace to identify and fix the database performance issues. ### The Problem - Dashboard taking 3-5 seconds to load - Users experiencing timeouts - Increased server load during peak hours - No clear indication of what's causing the slowdown --- ## 📋 Step 1: Enable Targeted Recording Since this is a specific performance issue, let's use targeted recording to focus on the dashboard: ```bash # Target the dashboard route CHRONOTRACE_MODE=targeted # In config/chronotrace.php 'targeted_routes' => [ 'dashboard', 'dashboard/*', 'api/dashboard/*', ], ``` Or start manual recording: ```bash # Record dashboard requests for 10 minutes php artisan chronotrace:record --routes="dashboard*" --duration=10m ``` --- ## 🚀 Step 2: Generate Test Traffic Let's create some dashboard requests to capture traces: ```bash # Simulate dashboard access curl -H "Authorization: Bearer YOUR_TOKEN" http://localhost:8000/dashboard # Or visit in browser while logged in # Navigate to: http://localhost:8000/dashboard ``` --- ## 🔍 Step 3: Identify Slow Requests List traces to find slow dashboard requests: ```bash # Find slow dashboard requests (>1 second) php artisan chronotrace:list --route="dashboard*" --min-duration=1000 # Example output: ┌────────────┬─────────────────────┬────────┬──────────┬─────────────────┬──────────┐ │ Trace ID │ Timestamp │ Method │ Status │ Route │ Duration │ ├────────────┼─────────────────────┼────────┼──────────┼─────────────────┼──────────┤ │ slow_001 │ 2024-08-06 14:30:15 │ GET │ 200 │ dashboard │ 3,245ms │ │ slow_002 │ 2024-08-06 14:32:42 │ GET │ 200 │ dashboard │ 2,891ms │ │ slow_003 │ 2024-08-06 14:35:18 │ GET │ 200 │ dashboard │ 4,156ms │ └────────────┴─────────────────────┴────────┴──────────┴─────────────────┴──────────┘ ``` --- ## 📊 Step 4: Analyze Database Queries Let's examine the database queries in a slow trace: ```bash # Replay focusing on database events php artisan chronotrace:replay slow_001 --filter=database ``` ### Example Output Analysis ``` ┌─ DATABASE EVENTS (15 queries, 2,890ms total) ───────────────┐ │ [+0ms] SELECT * FROM users WHERE id = ? [123] (5ms) │ Connection: mysql, Rows: 1 │ │ [+12ms] SELECT * FROM user_settings WHERE user_id = ? [123] (3ms) │ Connection: mysql, Rows: 1 │ │ [+25ms] SELECT * FROM posts WHERE user_id = ? ORDER BY created_at DESC [123] (1,245ms) ⚠️ │ Connection: mysql, Rows: 10,000 │ │ [+1,280ms] SELECT * FROM comments WHERE post_id IN (?, ?, ?, ...) [1,2,3...] (892ms) ⚠️ │ Connection: mysql, Rows: 50,000 │ │ [+2,185ms] SELECT * FROM likes WHERE post_id IN (?, ?, ?, ...) [1,2,3...] (634ms) ⚠️ │ Connection: mysql, Rows: 25,000 │ │ [+2,845ms] SELECT * FROM users WHERE id IN (?, ?, ?, ...) [456,789...] (45ms) │ Connection: mysql, Rows: 500 └──────────────────────────────────────────────────────────────────────────────┘ ``` ### 🔴 Issues Identified 1. **N+1 Query Problem**: Loading posts individually instead of eagerly loading 2. **Missing Indexes**: Slow queries on `posts.user_id` and `comments.post_id` 3. **Over-fetching**: Loading all posts instead of paginating 4. **Inefficient IN clauses**: Large IN queries for comments and likes --- ## 🛠️ Step 5: Fix the Issues ### Issue 1: N+1 Query Problem **Before (problematic code):** ```php // In DashboardController.php public function index() { $user = auth()->user(); // This will cause N+1 queries $posts = $user->posts()->latest()->get(); foreach ($posts as $post) { $post->comments; // N+1 query $post->likes; // Another N+1 query } return view('dashboard', compact('posts')); } ``` **After (optimized code):** ```php // In DashboardController.php public function index() { $user = auth()->user(); // Eager load relationships to prevent N+1 $posts = $user->posts() ->with(['comments' => function($query) { $query->latest()->limit(5); // Only recent comments }, 'likes', 'author']) ->latest() ->paginate(10); // Add pagination return view('dashboard', compact('posts')); } ``` ### Issue 2: Add Database Indexes ```php // Create migration: php artisan make:migration add_dashboard_indexes public function up() { Schema::table('posts', function (Blueprint $table) { $table->index(['user_id', 'created_at']); // Composite index }); Schema::table('comments', function (Blueprint $table) { $table->index(['post_id', 'created_at']); }); Schema::table('likes', function (Blueprint $table) { $table->index(['post_id', 'user_id']); }); } ``` ### Issue 3: Implement Caching ```php // In DashboardController.php public function index() { $user = auth()->user(); $cacheKey = "dashboard_posts_{$user->id}"; $posts = Cache::remember($cacheKey, 300, function() use ($user) { return $user->posts() ->with(['comments' => function($query) { $query->latest()->limit(5); }, 'likes', 'author']) ->latest() ->paginate(10); }); return view('dashboard', compact('posts')); } ``` --- ## ✅ Step 6: Verify the Fix After implementing the changes, let's test again: ```bash # Run migrations php artisan migrate # Clear caches php artisan cache:clear php artisan config:clear # Record new traces php artisan chronotrace:record --routes="dashboard*" --duration=5m ``` Visit the dashboard again and check the new traces: ```bash # Check new performance php artisan chronotrace:list --route="dashboard*" --since="5 minutes ago" # Example improved output: ┌────────────┬─────────────────────┬────────┬──────────┬─────────────────┬──────────┐ │ Trace ID │ Timestamp │ Method │ Status │ Route │ Duration │ ├────────────┼─────────────────────┼────────┼──────────┼─────────────────┼──────────┤ │ fast_001 │ 2024-08-06 15:30:15 │ GET │ 200 │ dashboard │ 156ms │ │ fast_002 │ 2024-08-06 15:32:42 │ GET │ 200 │ dashboard │ 89ms │ │ fast_003 │ 2024-08-06 15:35:18 │ GET │ 200 │ dashboard │ 134ms │ └────────────┴─────────────────────┴────────┴──────────┴─────────────────┴──────────┘ ``` ### Analyze Optimized Queries ```bash php artisan chronotrace:replay fast_001 --filter=database ``` ``` ┌─ DATABASE EVENTS (3 queries, 89ms total) ───────────────────┐ │ [+0ms] SELECT * FROM users WHERE id = ? [123] (5ms) │ Connection: mysql, Rows: 1 │ │ [+12ms] SELECT * FROM user_settings WHERE user_id = ? [123] (3ms) │ Connection: mysql, Rows: 1 │ │ [+25ms] SELECT posts.*, comments.*, likes.* FROM posts │ LEFT JOIN comments ON posts.id = comments.post_id │ LEFT JOIN likes ON posts.id = likes.post_id │ WHERE posts.user_id = ? │ ORDER BY posts.created_at DESC │ LIMIT 10 OFFSET 0 [123] (81ms) ✅ │ Connection: mysql, Rows: 10 (with relationships) └──────────────────────────────────────────────────────────────────────────────┘ ``` **Performance Improvement:** - ✅ **95% faster**: From 3,245ms to 156ms - ✅ **15 queries → 3 queries**: Eliminated N+1 problems - ✅ **Fewer rows**: Pagination reduces data transfer - ✅ **Indexed queries**: All queries using proper indexes --- ## 📈 Advanced Debugging Techniques ### Comparing Before/After Performance ```bash # Compare query performance over time php artisan chronotrace:list --route="dashboard*" --since="1 hour ago" --format=json | jq '.[] | {timestamp, duration, query_count}' ``` ### Identifying Query Patterns ```bash # Find all slow database queries across traces php artisan chronotrace:list --min-duration=1000 | \ xargs -I {} php artisan chronotrace:replay {} --filter=database --min-duration=100 ``` ### Memory Usage Analysis ```bash # Check memory usage in traces php artisan chronotrace:replay slow_001 --memory-analysis ``` ``` ┌─ MEMORY ANALYSIS ────────────────────────────────────────────┐ │ Peak Memory: 45.2MB (at +2,180ms during comments query) │ │ Memory Growth: +38MB from start to peak │ │ Largest Allocation: comments collection (15.8MB) │ │ Recommendation: Use pagination and select specific columns │ └──────────────────────────────────────────────────────────────┘ ``` --- ## 🎯 Other Common Database Issues ### Detecting Missing Indexes Look for queries with high execution time and row counts: ```bash # Queries taking >100ms php artisan chronotrace:replay trace_id --filter=database --min-duration=100 ``` **Red flags:** - `SELECT` with `WHERE` clause taking >50ms - Queries scanning many rows but returning few - `ORDER BY` without corresponding index ### Identifying Inefficient Eloquent Usage Common patterns to watch for: ```php // ❌ Bad: N+1 queries $users = User::all(); foreach ($users as $user) { $user->posts->count(); // N+1 query } // ✅ Good: Eager loading with counts $users = User::withCount('posts')->get(); // ❌ Bad: Loading unnecessary data $posts = Post::all(); // Loads all columns // ✅ Good: Select only needed columns $posts = Post::select(['id', 'title', 'created_at'])->get(); ``` ### Cache Hit/Miss Analysis ```bash # Analyze cache performance alongside database queries php artisan chronotrace:replay trace_id --filter=database,cache ``` Look for: - Cache misses followed by expensive database queries - Opportunities to cache query results - Cache keys that could be optimized --- ## 📋 Database Debugging Checklist ### Before Optimizing - [ ] Enable ChronoTrace recording for target routes - [ ] Generate representative test traffic - [ ] Identify slow requests (>1 second) - [ ] Analyze database events in slow traces ### During Analysis - [ ] Count total queries per request - [ ] Identify queries taking >100ms - [ ] Look for N+1 query patterns - [ ] Check for missing indexes (high row scans) - [ ] Verify pagination is used for large datasets ### After Optimizing - [ ] Add database indexes for slow queries - [ ] Implement eager loading for relationships - [ ] Add pagination for large result sets - [ ] Implement caching for expensive queries - [ ] Re-test and compare performance ### Ongoing Monitoring - [ ] Set up alerts for slow database queries - [ ] Monitor query count trends - [ ] Regular index analysis - [ ] Cache hit rate monitoring --- ## 🔧 Pro Tips ### 1. Use Query Comments for Tracking ```php // Add comments to identify query sources DB::select('SELECT /* Dashboard:user_posts */ * FROM posts WHERE user_id = ?', [$userId]); ``` ### 2. Enable MySQL Slow Query Log ```bash # In MySQL configuration slow_query_log = 1 long_query_time = 0.1 # Log queries >100ms ``` ### 3. Monitor Query Execution Plans ```sql -- Use EXPLAIN to analyze query performance EXPLAIN SELECT * FROM posts WHERE user_id = 123 ORDER BY created_at DESC; ``` ### 4. Implement Database Query Monitoring ```php // In AppServiceProvider DB::listen(function ($query) { if ($query->time > 100) { // Queries >100ms Log::warning('Slow query detected', [ 'sql' => $query->sql, 'bindings' => $query->bindings, 'time' => $query->time ]); } }); ``` --- ## 📚 Related Documentation - **[Basic Usage](Basic-Usage.md)** - Learn fundamental ChronoTrace workflows - **[Performance Analysis](Example-Performance-Analysis.md)** - Advanced performance debugging - **[Configuration](Configuration.md)** - Configure database event capture - **[Production Monitoring](Production-Monitoring.md)** - Monitor database performance in production --- **Result:** Dashboard loading time reduced from **3.2 seconds to 150ms** - a **95% improvement** using ChronoTrace to identify and fix database performance bottlenecks!