# 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: ```bash # 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: ```php // 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: ```bash # 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: ```bash # 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:** ```php // 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:** ```php // 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:** ```php // 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:** ```php // 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:** ```php 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:** ```php 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:** ```php // 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: ```bash # 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 ```bash # 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 ```bash 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 ```bash # 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 ```php // 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 ```php // 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 ```php // 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 ```bash # Profile memory usage in traces php artisan chronotrace:replay trace_id --memory-profile ``` ### 3. Load Testing with Performance Monitoring ```bash # 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 - **[Database Debugging](Example-Database-Debugging.md)** - Specific database optimization techniques - **[API Integration Debugging](Example-API-Debugging.md)** - External API optimization - **[Configuration](Configuration.md)** - Performance-related configuration - **[Production Monitoring](Production-Monitoring.md)** - Ongoing performance monitoring --- **Result:** Checkout performance improved by **85%** - from 8.5 seconds to 1.2 seconds, with **65% memory reduction** and **91% faster external API calls**!