Example Database Debugging

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:

# Target the dashboard route
CHRONOTRACE_MODE=targeted

# In config/chronotrace.php
'targeted_routes' => [
    'dashboard',
    'dashboard/*',
    'api/dashboard/*',
],

Or start manual recording:

# 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:

# 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:

# 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:

# 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):

// 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):

// 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

// 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

// 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:

# 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:

# 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

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

# 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

# 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

# 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:

# 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:

// ❌ 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

# 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

// Add comments to identify query sources
DB::select('SELECT /* Dashboard:user_posts */ * FROM posts WHERE user_id = ?', [$userId]);

2. Enable MySQL Slow Query Log

# In MySQL configuration
slow_query_log = 1
long_query_time = 0.1  # Log queries >100ms

3. Monitor Query Execution Plans

-- Use EXPLAIN to analyze query performance
EXPLAIN SELECT * FROM posts WHERE user_id = 123 ORDER BY created_at DESC;

4. Implement Database Query Monitoring

// 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 - Learn fundamental ChronoTrace workflows
• Performance Analysis - Advanced performance debugging
• Configuration - Configure database event capture
• Production Monitoring - 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!