Skip to content

Example Performance Analysis

Jump to bottom
Jean-Marc Strauven edited this page Aug 6, 2025 · 1 revision

Performance Analysis Example

Learn how to use ChronoTrace to identify and resolve application performance bottlenecks across multiple layers - database, cache, HTTP calls, and memory usage.

🎯 Scenario: E-commerce Checkout Performance

Your e-commerce checkout process is experiencing performance issues during peak hours, leading to cart abandonment and lost revenue.

The Problem

  • Checkout process taking 8-12 seconds
  • High server load during peak traffic
  • Users abandoning carts due to slow response
  • Payment timeouts occurring frequently

📊 Step 1: Establish Performance Baseline

First, let's record checkout traces to understand current performance:

# Enable sampling for checkout routes
CHRONOTRACE_MODE=targeted

# Configure targeted recording for checkout flow
php artisan chronotrace:record --routes="checkout/*,api/checkout/*" --duration=30m --sample-rate=0.5

Configuration for checkout monitoring:

// config/chronotrace.php
'targeted_routes' => [
    'checkout',
    'checkout/*',
    'api/checkout/*',
    'api/payments/*',
    'api/inventory/*',
],

🔍 Step 2: Analyze Current Performance

Let's examine the checkout traces to identify bottlenecks:

# Find slow checkout requests
php artisan chronotrace:list --route="checkout*" --min-duration=2000 --limit=10

# Example output showing performance issues:
┌────────────┬─────────────────────┬────────┬──────────┬─────────────────────┬──────────┐
│ Trace ID   │ Timestamp           │ Method │ Status   │ Route               │ Duration │
├────────────┼─────────────────────┼────────┼──────────┼─────────────────────┼──────────┤
│ slow_co1   │ 2024-08-06 14:30:15 │ POST   │ 200      │ checkout/process    │ 8,456ms  │
│ slow_co2   │ 2024-08-06 14:32:42 │ POST   │ 200      │ checkout/process    │ 9,891ms  │
│ slow_co3   │ 2024-08-06 14:35:18 │ POST   │ 422      │ checkout/process    │ 12,156ms │
│ timeout1   │ 2024-08-06 14:37:25 │ POST   │ 500      │ checkout/process    │ 30,000ms │
└────────────┴─────────────────────┴────────┴──────────┴─────────────────────┴──────────┘

📋 Step 3: Deep Dive Analysis

Let's analyze a slow checkout trace across all event types:

# Get complete picture of slow checkout
php artisan chronotrace:replay slow_co1

Complete Performance Analysis

┌─ REQUEST INFORMATION ────────────────────────────────────────┐
│ Trace ID: slow_co1                                          │
│ Method: POST /checkout/process                              │
│ Status: 200 OK                                              │
│ Duration: 8,456ms                                           │
│ Memory Peak: 128MB                                          │
│ User: customer_12345                                        │
└──────────────────────────────────────────────────────────────┘

┌─ DATABASE EVENTS (24 queries, 3,245ms total) ───────────────┐
│ [+0ms] SELECT * FROM users WHERE id = ? [12345] (5ms)
│ [+15ms] SELECT * FROM carts WHERE user_id = ? [12345] (8ms)
│ [+35ms] SELECT * FROM cart_items WHERE cart_id = ? [567] (12ms)
│ [+58ms] SELECT * FROM products WHERE id IN (?, ?, ?, ...) [89,90,91...] (245ms) ⚠️
│ [+315ms] SELECT * FROM inventory WHERE product_id IN (...) [89,90,91...] (1,890ms) ⚠️
│ [+2,225ms] UPDATE inventory SET quantity = quantity - ? WHERE product_id = ? [2, 89] (156ms)
│ [+2,395ms] UPDATE inventory SET quantity = quantity - ? WHERE product_id = ? [1, 90] (234ms)
│ [+2,645ms] INSERT INTO orders (user_id, total, status) VALUES (?, ?, ?) [12345, 299.99, 'pending'] (45ms)
│ [+2,705ms] INSERT INTO order_items (...) VALUES (...) - 5 queries (189ms)
│ [+2,915ms] SELECT * FROM shipping_rates WHERE (...) (445ms) ⚠️
│ [+3,375ms] UPDATE carts SET status = 'completed' WHERE id = ? [567] (25ms)
└──────────────────────────────────────────────────────────────┘

┌─ CACHE EVENTS (8 operations) ───────────────────────────────┐
│ [+125ms] GET product:89:details (MISS) 
│ [+130ms] GET product:90:details (MISS)
│ [+135ms] GET product:91:details (MISS)
│ [+3,400ms] GET shipping:zone:rates (MISS) ⚠️
│ [+3,420ms] SET product:89:details (TTL: 3600s)
│ [+3,425ms] SET product:90:details (TTL: 3600s)
│ [+3,430ms] SET product:91:details (TTL: 3600s)
│ [+7,890ms] SET shipping:zone:rates (TTL: 1800s)
└──────────────────────────────────────────────────────────────┘

┌─ HTTP EVENTS (3 requests) ───────────────────────────────────┐
│ [+3,455ms] POST https://payment-gateway.com/validate (2,145ms) ⚠️
│           Status: 200 OK
│           Request: {"amount": 299.99, "card": "****-****-****-1234"}
│           Response: {"status": "approved", "transaction_id": "txn_abc123"}
│
│ [+5,625ms] POST https://shipping-api.com/calculate (1,890ms) ⚠️
│           Status: 200 OK
│           Request: {"weight": 2.5, "destination": "90210"}
│           Response: {"rates": [{"service": "standard", "cost": 9.99}]}
│
│ [+7,545ms] POST https://inventory-sync.com/reserve (1,245ms) ⚠️
│           Status: 200 OK
│           Request: {"items": [{"product_id": 89, "quantity": 2}]}
│           Response: {"status": "reserved", "expires_at": "2024-08-06T15:30:15Z"}
└──────────────────────────────────────────────────────────────┘

┌─ QUEUE EVENTS (2 jobs) ──────────────────────────────────────┐
│ [+8,125ms] DISPATCH SendOrderConfirmationEmail
│           Queue: emails, Delay: 0s
│           Payload: {"order_id": 78901, "user_id": 12345}
│
│ [+8,145ms] DISPATCH UpdateInventoryMetrics  
│           Queue: analytics, Delay: 5m
│           Payload: {"product_ids": [89, 90, 91]}
└──────────────────────────────────────────────────────────────┘

🔴 Performance Issues Identified

  1. Database Bottlenecks (3.2s total):

    • Slow inventory queries (1.9s)
    • Missing indexes on product lookups
    • Sequential inventory updates instead of batch

  2. Cache Misses (Multiple misses):

    • Product details not cached
    • Shipping rates computed every time
    • No cache warming strategy

  3. External API Delays (5.3s total):

    • Payment gateway: 2.1s
    • Shipping calculator: 1.9s
    • Inventory service: 1.2s

  4. Memory Usage (128MB peak):

    • Loading full product data unnecessarily
    • Large shipping rate calculations

🛠️ Step 4: Implement Performance Optimizations

Optimization 1: Database Performance

Before:

// Inefficient inventory checking
foreach ($cartItems as $item) {
    $inventory = Inventory::where('product_id', $item->product_id)->first();
    if ($inventory->quantity < $item->quantity) {
        throw new InsufficientInventoryException();
    }
}

// Sequential inventory updates
foreach ($cartItems as $item) {
    Inventory::where('product_id', $item->product_id)
        ->decrement('quantity', $item->quantity);
}

After:

// Batch inventory checking with proper indexing
$productIds = $cartItems->pluck('product_id');
$inventories = Inventory::whereIn('product_id', $productIds)
    ->lockForUpdate() // Prevent race conditions
    ->get()
    ->keyBy('product_id');

// Validate all items at once
foreach ($cartItems as $item) {
    $inventory = $inventories[$item->product_id];
    if ($inventory->quantity < $item->quantity) {
        throw new InsufficientInventoryException($item->product_id);
    }
}

// Batch inventory updates using raw SQL
$updates = $cartItems->map(function ($item) {
    return [
        'product_id' => $item->product_id,
        'quantity' => $item->quantity
    ];
});

DB::transaction(function () use ($updates) {
    foreach ($updates as $update) {
        DB::statement(
            'UPDATE inventory SET quantity = quantity - ? WHERE product_id = ?',
            [$update['quantity'], $update['product_id']]
        );
    }
});

Add Database Indexes:

// Migration: add_checkout_performance_indexes
Schema::table('inventory', function (Blueprint $table) {
    $table->index(['product_id', 'quantity']); // For stock checking
});

Schema::table('products', function (Blueprint $table) {
    $table->index(['id', 'status', 'price']); // For product lookups
});

Schema::table('shipping_rates', function (Blueprint $table) {
    $table->index(['zone_id', 'weight_min', 'weight_max']); // For shipping calc
});

Optimization 2: Caching Strategy

Implement Multi-Level Caching:

// Product caching
class ProductService
{
    public function getProductDetails($productIds)
    {
        $cacheKey = 'products:' . implode(',', $productIds);
        
        return Cache::remember($cacheKey, 3600, function () use ($productIds) {
            return Product::whereIn('id', $productIds)
                ->with(['category', 'images'])
                ->get();
        });
    }
}

// Shipping rate caching
class ShippingService  
{
    public function calculateRates($weight, $destination)
    {
        $cacheKey = "shipping:rates:{$destination}:{$weight}";
        
        return Cache::remember($cacheKey, 1800, function () use ($weight, $destination) {
            // Expensive shipping calculation
            return $this->callShippingAPI($weight, $destination);
        });
    }
}

// Inventory caching with cache tags
class InventoryService
{
    public function getAvailableQuantity($productIds)
    {
        return Cache::tags(['inventory'])->remember(
            'inventory:' . implode(',', $productIds),
            300, // 5 minutes only for inventory
            function () use ($productIds) {
                return Inventory::whereIn('product_id', $productIds)->get();
            }
        );
    }
    
    public function updateInventory($updates)
    {
        // Update database
        $this->performInventoryUpdate($updates);
        
        // Invalidate related caches
        Cache::tags(['inventory'])->flush();
    }
}

Optimization 3: External API Optimization

Implement Async HTTP Calls:

use Illuminate\Http\Client\Pool;

class CheckoutService
{
    public function processCheckout($cartItems, $paymentData, $shippingData)
    {
        // Make parallel API calls
        $responses = Http::pool(function (Pool $pool) use ($paymentData, $shippingData, $cartItems) {
            return [
                'payment' => $pool->timeout(10)->post('https://payment-gateway.com/validate', $paymentData),
                'shipping' => $pool->timeout(8)->post('https://shipping-api.com/calculate', $shippingData),
                'inventory' => $pool->timeout(5)->post('https://inventory-sync.com/reserve', [
                    'items' => $cartItems->toArray()
                ]),
            ];
        });

        // Process responses
        if ($responses['payment']->successful() && 
            $responses['shipping']->successful() && 
            $responses['inventory']->successful()) {
            
            return $this->completeOrder($responses);
        }
        
        throw new CheckoutException('External service failure');
    }
}

Add Circuit Breaker Pattern:

class CircuitBreakerService
{
    public function callWithCircuitBreaker($service, $callback, $fallback = null)
    {
        $failures = Cache::get("circuit_breaker:{$service}:failures", 0);
        
        if ($failures >= 5) {
            if ($fallback) {
                return $fallback();
            }
            throw new ServiceUnavailableException($service);
        }
        
        try {
            $result = $callback();
            Cache::forget("circuit_breaker:{$service}:failures");
            return $result;
        } catch (Exception $e) {
            Cache::increment("circuit_breaker:{$service}:failures");
            Cache::put("circuit_breaker:{$service}:failures", $failures + 1, 300);
            throw $e;
        }
    }
}

Optimization 4: Memory Optimization

Reduce Memory Usage:

// Before: Loading full models
$products = Product::with(['images', 'reviews', 'variations'])->get();

// After: Select only needed fields
$products = Product::select(['id', 'name', 'price', 'status'])
    ->whereIn('id', $productIds)
    ->get();

// Use chunking for large datasets
Product::whereIn('id', $largeProductIdList)
    ->chunk(100, function ($products) {
        $this->processProducts($products);
    });

✅ Step 5: Measure Performance Improvements

After implementing optimizations, let's test the improvements:

# Record new checkout traces
php artisan chronotrace:record --routes="checkout*" --duration=15m

# Compare performance
php artisan chronotrace:list --route="checkout*" --since="15 minutes ago"

Performance Results

# After optimization:
┌────────────┬─────────────────────┬────────┬──────────┬─────────────────────┬──────────┐
│ Trace ID   │ Timestamp           │ Method │ Status   │ Route               │ Duration │
├────────────┼─────────────────────┼────────┼──────────┼─────────────────────┼──────────┤
│ fast_co1   │ 2024-08-06 16:30:15 │ POST   │ 200      │ checkout/process    │ 1,245ms  │
│ fast_co2   │ 2024-08-06 16:32:42 │ POST   │ 200      │ checkout/process    │ 1,156ms  │
│ fast_co3   │ 2024-08-06 16:35:18 │ POST   │ 200      │ checkout/process    │ 1,389ms  │
└────────────┴─────────────────────┴────────┴──────────┴─────────────────────┴──────────┘

Detailed Performance Analysis

php artisan chronotrace:replay fast_co1
┌─ REQUEST INFORMATION ────────────────────────────────────────┐
│ Trace ID: fast_co1                                          │
│ Method: POST /checkout/process                              │
│ Status: 200 OK                                              │
│ Duration: 1,245ms ✅ (85% improvement)                      │
│ Memory Peak: 45MB ✅ (65% reduction)                        │
│ User: customer_12345                                        │
└──────────────────────────────────────────────────────────────┘

┌─ DATABASE EVENTS (8 queries, 456ms total) ──────────────────┐
│ [+0ms] SELECT * FROM users WHERE id = ? [12345] (5ms)
│ [+15ms] SELECT * FROM carts WHERE user_id = ? [12345] (8ms)
│ [+35ms] SELECT id, name, price FROM products WHERE id IN (...) (45ms) ✅
│ [+95ms] SELECT product_id, quantity FROM inventory WHERE product_id IN (...) FOR UPDATE (89ms) ✅
│ [+195ms] UPDATE inventory SET quantity = quantity - CASE ... (234ms) ✅ Batch update
│ [+445ms] INSERT INTO orders (...) VALUES (...) (45ms)
│ [+495ms] INSERT INTO order_items (...) - Batch insert (34ms) ✅
│ [+535ms] SELECT shipping_cost FROM shipping_rates_cache WHERE zone = ? (12ms) ✅
└──────────────────────────────────────────────────────────────┘

┌─ CACHE EVENTS (6 operations) ───────────────────────────────┐
│ [+85ms] GET products:89,90,91 (HIT) ✅
│ [+90ms] GET shipping:zone:90210:2.5kg (HIT) ✅
│ [+185ms] GET inventory:89,90,91 (HIT) ✅
│ [+1,200ms] SET order:78901:confirmation (TTL: 7200s)
└──────────────────────────────────────────────────────────────┘

┌─ HTTP EVENTS (2 requests, parallel) ────────────────────────┐
│ [+545ms] POST https://payment-gateway.com/validate (456ms) ✅ Parallel
│          POST https://inventory-sync.com/reserve (423ms) ✅ Parallel
│          Status: Both 200 OK
│          Total: 456ms (was 5,280ms sequential)
└──────────────────────────────────────────────────────────────┘

📈 Performance Improvements Summary

Metric Before After Improvement
Total Duration 8,456ms 1,245ms 85% faster
Database Time 3,245ms 456ms 86% faster
Cache Hit Rate 12% 89% 77% improvement
HTTP Requests 5,280ms 456ms 91% faster
Memory Usage 128MB 45MB 65% reduction
Query Count 24 8 67% fewer

📊 Performance Monitoring Setup

Create Performance Dashboard

# Set up ongoing performance monitoring
php artisan chronotrace:record --routes="checkout*" --sample-rate=0.1 --continuous

# Create performance alerts
php artisan chronotrace:alert --route="checkout*" --threshold=2000ms --email=team@company.com

Performance Metrics Collection

// Custom performance tracking
class PerformanceMetrics
{
    public function trackCheckoutPerformance($traceId, $duration, $steps)
    {
        $metrics = [
            'trace_id' => $traceId,
            'total_duration' => $duration,
            'database_time' => $steps['database'] ?? 0,
            'cache_hit_rate' => $steps['cache_hit_rate'] ?? 0,
            'external_api_time' => $steps['http'] ?? 0,
            'memory_peak' => $steps['memory_peak'] ?? 0,
        ];
        
        // Store metrics for trending analysis
        InfluxDB::write('checkout_performance', $metrics);
    }
}

Automated Performance Testing

// Performance regression testing
class CheckoutPerformanceTest extends TestCase
{
    public function test_checkout_performance_baseline()
    {
        // Enable ChronoTrace for test
        Config::set('chronotrace.enabled', true);
        Config::set('chronotrace.mode', 'always');
        
        $startTime = microtime(true);
        
        // Perform checkout
        $response = $this->post('/checkout/process', $this->getCheckoutData());
        
        $duration = (microtime(true) - $startTime) * 1000;
        
        // Assert performance requirements
        $this->assertLessThan(2000, $duration, 'Checkout should complete under 2 seconds');
        $response->assertStatus(200);
        
        // Analyze trace for detailed assertions
        $traces = $this->getLatestTraces();
        $this->assertDatabaseQueriesLessThan($traces[0], 10);
        $this->assertMemoryUsageLessThan($traces[0], 50 * 1024 * 1024); // 50MB
    }
}

🎯 Advanced Performance Techniques

1. Database Query Optimization

// Use database query optimization
DB::enableQueryLog();

// Analyze query patterns
$queries = DB::getQueryLog();
foreach ($queries as $query) {
    if ($query['time'] > 100) {
        Log::warning('Slow query detected', $query);
    }
}

2. Memory Profiling

# Profile memory usage in traces
php artisan chronotrace:replay trace_id --memory-profile

3. Load Testing with Performance Monitoring

# Run load test while monitoring performance
php artisan chronotrace:record --duration=30m &
ab -n 1000 -c 10 http://localhost:8000/checkout/process

📋 Performance Optimization Checklist

Database Optimization

  • Identify slow queries (>100ms)
  • Add appropriate indexes
  • Implement eager loading
  • Use batch operations
  • Optimize N+1 queries

Caching Strategy

  • Cache expensive computations
  • Implement cache warming
  • Use appropriate TTL values
  • Monitor cache hit rates
  • Implement cache invalidation

External Services

  • Implement parallel HTTP calls
  • Add timeout configurations
  • Use circuit breaker pattern
  • Cache API responses
  • Implement fallback mechanisms

Memory Management

  • Select only needed columns
  • Use chunking for large datasets
  • Implement lazy loading
  • Monitor memory usage
  • Optimize object creation

📚 Related Documentation

Result: Checkout performance improved by 85% - from 8.5 seconds to 1.2 seconds, with 65% memory reduction and 91% faster external API calls!

Laravel ChronoTrace - Record and replay Laravel requests deterministically

GitHub • Packagist • License

🔗 Quick Links

📖 Popular Pages

Section Page Description
🚀 Basics Your First Trace Step-by-step beginner guide
🎛️ Config Recording Modes Choose when to record traces
🛡️ Security Security & PII Protect sensitive data
🔧 Tools Commands Complete command reference

🆘 Need Help?

ChronoTrace helps Laravel developers debug applications faster with intelligent request tracing.

Made with ❤️ by Grazulex • Documentation updated August 2024

📚 Laravel ChronoTrace Wiki

🏠 Home

🚀 Getting Started

🎯 Core Concepts

⚙️ Configuration

🔧 Commands & Tools

🏭 Advanced Usage

📖 Examples & Guides

🔍 Reference

🤝 Community

Clone this wiki locally