analyzing-blackfire-profiles

What this skill does

# Blackfire Performance Investigation

Systematic approach to analyzing Blackfire.io performance profiles using Chrome browser automation.

## Prerequisites

- Chrome browser with Claude-in-Chrome MCP extension
- Access to Blackfire.io (profile URL)

---

## CRITICAL: Sidebar Fix (MUST DO FIRST)

**STOP! Before ANY callgraph analysis, you MUST apply this JavaScript fix.**

The default Blackfire UI truncates function names (e.g., `...ecute(...)`) making analysis **impossible**. This fix is **NON-NEGOTIABLE**.

```javascript
document.querySelector('.graph-pane').style.position = 'static';
document.querySelectorAll('div').forEach(d => {
  if(d.style.cssText.includes('position: fixed') && d.style.cssText.includes('height: 100%'))
    d.style.width = '1400px';
});
```

**When to apply:** Immediately after navigating to any Blackfire profile, BEFORE reading the callgraph.

**What it does:** Hides the visual graph and widens the sidebar to show full function names like `Doctrine\ORM\UnitOfWork::computeChangeSet` instead of `...Work::compu...`.

**If you skip this:** You cannot identify functions, making all subsequent analysis meaningless.

---

## Investigation Workflow

```
┌─────────────────────────────────────────────────────────────┐
│  STEP 0: APPLY SIDEBAR FIX (MANDATORY - DO THIS FIRST!)    │
│  └─ Run JavaScript fix immediately after page load         │
├─────────────────────────────────────────────────────────────┤
│  STEP 1: HEADER TRIAGE (5 seconds)                         │
│  └─ Identify bottleneck TYPE: I/O vs CPU vs Memory         │
├─────────────────────────────────────────────────────────────┤
│  STEP 2: BRANCH TO SPECIALIZED VIEW                        │
│  ├─ I/O-bound  → SQL/HTTP view first                       │
│  ├─ CPU-bound  → Callgraph first                           │
│  └─ Unclear    → "All" view to disambiguate                │
├─────────────────────────────────────────────────────────────┤
│  STEP 3: CALLGRAPH DEEP DIVE                               │
│  └─ Three-sort → Drill-down → Focused view                 │
├─────────────────────────────────────────────────────────────┤
│  STEP 4: RECOMMENDATIONS + TIMELINE (if needed)            │
└─────────────────────────────────────────────────────────────┘
```

---

### 1. Header Triage (Decision Point)

**This is the most important step.** The header tells you WHERE to look next.

After navigation, read the header bar metrics:

```
┌──────────────┬──────────────┬──────────────┬──────────────┬──────────────┐
│  Wall Time   │   I/O Wait   │     CPU      │    Memory    │   Network    │
│    15.4 s    │    4.78 s    │    10.6 s    │    165 MB    │    2.9 MB    │
└──────────────┴──────────────┴──────────────┴──────────────┴──────────────┘
```

#### Branching Decision Tree

**Calculate the dominant dimension:**

| If Header Shows | Bottleneck Type | Next Step |
|-----------------|-----------------|-----------|
| **I/O Wait > 50% of Wall Time** | I/O-bound (database, network) | → Go to **SQL/HTTP View** |
| **CPU > 50% of Wall Time** | CPU-bound (computation) | → Go to **Callgraph** |
| **~50/50 split or unclear** | Mixed workload | → Use **"All" View** to disambiguate |
| **Memory very high** | Memory-bound | → Check hydration count, then Callgraph |

**Example calculations:**
- Wall Time 15.4s, I/O 4.78s (31%), CPU 10.6s (69%) → **CPU-bound** → Callgraph first
- Wall Time 10s, I/O 7s (70%), CPU 3s (30%) → **I/O-bound** → SQL view first
- Wall Time 8s, I/O 4s (50%), CPU 4s (50%) → **Unclear** → Use "All" view

#### Why This Matters

> **"Optimize the dominating bottleneck first."** - Performance Engineering Principle

If the profile is 70% I/O wait, drilling into CPU-heavy functions wastes time. The header tells you which tool to use:
- High I/O → SQL view will show the slow queries
- High CPU → Callgraph will show the heavy functions

---

### 2A. SQL/HTTP View (For I/O-Bound Profiles)

**Use this when:** Header shows I/O Wait > 50% of Wall Time

Click **SQL** in left sidebar for database analysis.

**What to check:**
- **Calls column** - Anything >50 is likely N+1 pattern
- **Time column** - Slow individual queries
- Sort by Calls descending (default) to see worst offenders

**Red flags:**

| Pattern | Threshold |
|---------|-----------|
| Same query repeated | >50 calls |
| High entity count | >1000 |
| Total queries | >100 for simple page |

Click **HTTP** for external API calls:
- External service calls (Elasticsearch, APIs)
- Call counts and timing
- **Red flag:** >10 external calls per request

**After SQL/HTTP analysis:** Proceed to Callgraph (Step 3) to find the CODE causing these queries.

---

### 2B. "All" View (For Unclear/Mixed Profiles)

**Use this when:** Header shows ~50/50 split between I/O and CPU, or you need per-function dimensional breakdown.

Click **"All"** button in the header bar (next to "Wall Time").

**What "All" view provides:**
- Per-function breakdown of ALL dimensions side-by-side
- See which specific functions are I/O-heavy vs CPU-heavy
- Columns: Time, I/O Wait, CPU, Memory, Network (each with % Excl / % Incl)

**When to use:**
- Header totals are ambiguous (~50/50)
- You suspect different functions have different bottleneck types
- Need to see the full picture before drilling down

**After "All" view analysis:** Click the specific dimension header (Wall Time, CPU, etc.) to switch to that focused view for deeper analysis.

---

### 3. Callgraph Analysis (Primary Deep Dive)

Click **Callgraph** in left sidebar. This is the most powerful view for finding root causes.

#### Step 1: Apply Sidebar Full-Width Fix (MANDATORY)

**Run this immediately** - default view truncates function names making analysis impossible:

```javascript
document.querySelector('.graph-pane').style.position = 'static';
document.querySelectorAll('div').forEach(d => {
  if(d.style.cssText.includes('position: fixed') && d.style.cssText.includes('height: 100%'))
    d.style.width = '1400px';
});
```

This hides the graph and widens the sidebar to show full names like `Doctrine\ORM\UnitOfWork::computeChangeSet`.

#### Step 2: Understand the Columns

| Column | What It Shows | Best For |
|--------|---------------|----------|
| **Function calls** | Full function name with namespace | Identifying what code is running |
| **% Excl.** | Time spent IN this function (not children) | Finding hot spots - where time actually burns |
| **% Incl.** | Time spent in function + all children | Understanding call hierarchy top-down |
| **Calls** | Number of times function was called | Detecting N+1 patterns and loops |

#### Step 3: Three-Sort Analysis Workflow

**This is the core debugging workflow.** Use all three sorts:

##### Sort 1: % Excl. (Default) - Find Hot Spots
- **Red bars = hot spots** - functions consuming most exclusive time
- Look for: Application code with big red bars (your code, not framework)
- Common hot spots: `PDOStatement::execute`, `ObjectHydrator::*`, event listeners

##### Sort 2: Calls (Click header) - Find N+1 and Loops
Click "Calls" column to sort by call count descending.

| Call Count | Likely Issue |
|------------|--------------|
| >100K | Framework overhead from too many entities |
| >10K | Possible N+1 or excessive lazy loading |
| >1K | Worth investigating if exclusive time is also high |

**Pattern recognition:**
- `hydrateColumnInfo` 900K+ calls → too many entities hydrated
- `postLoad` listener count ≈ number of entities loaded

##### Sort 3: % Incl. (Click header) - Understand Call Hierarchy
- Shows the **call chain from entry point** down
- First rows: `main()` → `Kernel::handle` → `Controller::action`
- Helps identify: Which controller/action is profiled, major code paths

#### Step 4: Drill-Down Analysis (Function Details Panel)

**Click any function row** to open the details panel.

**Panel Structure:**

1. **Callers Section** (orange bar at top)
    - "↓ N times (X%)" = caller invoked it N times
    - Click to expand caller details

2. **Function Metrics**