Profiling — measuring where time and memory are actually spent in code

Concept

Profiling — measuring WHERE a program spends its time and memory during execution. Profiling identifies which functions are called, how often, and how long they take. The output is used to find bottlenecks.

Profiling vs benchmarking:

• Profiling: Instrument a real or representative workload. See the full picture — what's slow, what's called too often, what allocates memory.
• Benchmarking: Measure the speed of a specific operation in isolation (see eng-20-008).

Types of profilers:

• Sampling profiler: Periodically takes a snapshot of the call stack. Low overhead. Less precise but good enough for most purposes.
• Tracing profiler: Records EVERY function call. High precision but significant overhead — not for production.

PHP profiling tools:

• Xdebug (profiling mode): Generates cachegrind files. View with KCacheGrind or Webgrind. Detailed but slow — development only.
• Blackfire: SaaS profiling tool. Low-overhead agent for staging/production profiling. Timeline, call graph, performance assertions.
• Tideways: Similar to Blackfire, popular in the Laravel community.
• Clockwork / Laravel Telescope: Lightweight dev-time profiling of queries, cache, queue, requests.

What to look for in a profile:

• Functions with HIGH self time (most time spent in the function itself).
• Functions called MANY times unexpectedly (N+1 pattern).
• Memory allocation hotspots.
• Slow SQL queries (always show up in profiles — integrate with query log).

Profile-driven optimization: Don't guess which part is slow. Profile first, optimize the actual bottleneck. "Premature optimization is the root of all evil" — Knuth. Profile THEN optimize.

Code Example

<?php
// XDEBUG PROFILING — generate cachegrind file
// php.ini:
// xdebug.mode=profile
// xdebug.output_dir=/tmp/xdebug-profiles
// xdebug.profiler_output_name=callgrind.out.%p.%H

// Trigger with ?XDEBUG_PROFILE=1 in URL or always-on with:
// xdebug.start_with_request=yes

// Then view: kcachegrind /tmp/xdebug-profiles/callgrind.out.*
// Shows: call tree, time per function, cumulative time, call count

// BLACKFIRE — production-safe profiler
// Install agent on server, then:
// blackfire curl https://example.com/api/orders

// Outputs:
// Wall Time:  245ms
// CPU Time:   180ms
// I/O Time:   65ms
// Memory:     8.4MB
//
// Call graph highlights:
// Illuminate\Database\Connection::select: 25ms (10 calls — likely N+1!)
// App\Services\PricingEngine::calculate:  180ms (called 500 times — unexpected!)

// TELESCOPE — lightweight dev profiling
// Automatically records:
// - All SQL queries with bindings and time
// - Cache hits/misses
// - Queue jobs
// - Mail
// - HTTP requests/responses
// Access at: /telescope

// MANUAL TIMING for quick profiling
function profiledQuery(): array
{
    $start = microtime(true);
    DB::enableQueryLog();

    $result = Order::with('items.product')
        ->where('status', 'pending')
        ->get();

    $queries = DB::getQueryLog();
    $total   = (microtime(true) - $start) * 1000;

    foreach ($queries as $q) {
        echo sprintf("[%.2fms] %s\n", $q['time'], $q['query']);
    }
    echo "Total: {$total}ms, Queries: " . count($queries) . "\n";

    return $result->toArray();
}