Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
88 changes: 88 additions & 0 deletions .claude/skills/analyze-perf-profiling/SKILL.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,88 @@
---
name: analyze-perf-profiling
description: >-
Profile grafema's OWN analysis pipeline (`grafema analyze`) by route + bottlenecks instead of
guessing. Use when analyze is slow, hangs, OOMs, or hits a scale limit. Covers the auto-emitted
JSONL profiler, the critical-path computation, the derive/enricher blind spot, the KNOWN artificial
limits (so you don't rediscover them from a crash), and host/RAM requirements.
---

# Profiling `grafema analyze` — see the route and its traffic jams

The cardinal rule: **measure the critical path FIRST; never "discover" a bottleneck from a crash or a
guessed limit.** Most analyze pain is an arbitrary cap that bites at scale or a dead analyzer daemon —
both are visible up front if you look.

## 1. The profiler is AUTOMATIC — no flag, no special mode

Every `grafema analyze` writes a JSONL profiler stream to **`.grafema/analysis-profile.jsonl`**.
Read it with the bundled tool:

```bash
node scripts/profile-analyze.mjs .grafema/analysis-profile.jsonl # phase breakdown, outliers, mem
node scripts/profile-analyze.mjs .grafema/analysis-profile.jsonl --predict 14000 # scale to N files
node scripts/profile-analyze.mjs .grafema/analysis-profile.jsonl --json # machine-readable
```

Captured: per-file (`parse_ms`/`analyze_ms`/`total_ms`/`node_count`/`edge_count`, all languages),
batch commits (`commit_ms` per `batch_index` — growth ⇒ O(N²), RFD-51), phase start/complete events,
and `rss_mb`/`cpu_s` on every event.

## 2. Critical path (the route + the jams) — one-liner from the JSONL

```bash
node -e 'const fs=require("fs");const ev=fs.readFileSync(process.argv[1],"utf8").trim().split("\n").map(l=>{try{return JSON.parse(l)}catch{return null}}).filter(Boolean);const s={},r=[];for(const e of ev){const t=e.event||e.type||"";const m=e.elapsed_ms??e.ts_ms;if(t.endsWith("_start"))s[t.replace(/_start$/,"")]=m;if(t.endsWith("_complete")){const k=t.replace(/_complete$/,"");if(s[k]!=null)r.push([k,m-s[k]])}}r.sort((a,b)=>b[1]-a[1]);const tot=r.reduce((x,y)=>x+y[1],0)||1;for(const[k,d]of r)console.log(k.padEnd(22),(d/1000).toFixed(1).padStart(8)+"s",(100*d/tot).toFixed(0)+"%")' .grafema/analysis-profile.jsonl
```

Real run (grafema self-analyze, June 2026, after the BEAM fix): `rust_resolve 52s/38%`,
`analysis 37s/27%`, `haskell_resolve 23s/17%`, `beam_resolve 13s`, `js_resolve 11s`, `compact 1.2s`.

## 3. THE BLIND SPOT — derive packs + enrichers are NOT in the JSONL

The profiler covers analysis + the resolve phases. The **derive phase (≈40 `@stdlib/*` rule packs,
~180s) and the TS enrichers run in rfdb-server / post-resolve and are NOT phase-events in the JSONL** —
this is exactly where the worst scale bugs live (cap overflows, the parallel-derive SIGSEGV, planner
q-errors). To see derive bottlenecks today, grep the verbose analyze log:

```bash
grep "Rule pack materialized" analyze.log # per-pack: pack="@stdlib/..." ms=N edges=M → packs with high ms / 0 edges
grep -E "Analysis complete|enricher|timed out" analyze.log
```

Future fix (worth doing): emit the pipeline as a **profile subgraph** — `PHASE`/`STAGE` nodes +
`METRIC` nodes (`wall_ms`, `edges_produced`, `intermediate_count`, `cap_hit`) + `PRECEDES` edges, in a
separate profile namespace. Then critical path = a Datalog query (longest `PRECEDES` chain by `wall_ms`),
dead stages = `wall_ms` high AND `edges_produced=0`, and limit-hits become standing graph facts +
a CI regression gate. The `METRIC`/`OBSERVES` node+edge types already exist (per-file `parse_ms` today).

## 4. KNOWN artificial limits — check these BEFORE assuming a real bottleneck

These conservative caps / timeouts bite at self-scale (~700k nodes). They are env-overridable
(some only on branch `fix/derive-batch-cap` and the worker branches). **For a full self-analyze run:**

```bash
RFDB_MATERIALIZE_DEADLINE_SECS=3600 RFDB_MAX_MATERIALIZED_FACTS=200000000 grafema analyze --quickstart
```

| Limit | Default | Symptom | Override |
|---|---|---|---|
| `max_intermediate_results` (derive batch) | 100k | `E-EXEC-001 ... exceeds max_intermediate_results` | `RFDB_MATERIALIZE_MAX_INTERMEDIATE` (lifted by default on fix branch) |
| `MAX_MATERIALIZED_FACTS` (planner guard) | 10M | `E-PLAN-003 ... per-rule output estimate N exceeds` — often a q-error OVERestimate (cross-product ignoring selective join keys) | `RFDB_MAX_MATERIALIZED_FACTS` |
| materialize deadline | 30s (query default) | derive aborts mid-pack | `RFDB_MATERIALIZE_DEADLINE_SECS` (default 600) |
| RFDB RPC client timeout | 60s | `RFDB … timed out after 60000ms` → enrichers SKIPPED | `RFDB_RPC_TIMEOUT_MS` / `RFDB_RPC_BULK_TIMEOUT_MS` |
| analyzer pool `request_timeout` | 120s/file | a DEAD analyzer daemon burns it per file (BEAM: 25 .ex × 120s = 241s) | fixed by liveness-probe (perf branch); else install the toolchain |

## 5. Host & toolchains

A full self-analyze peaks **~7.5–11 GB RAM / ~14 min**. Run it on **grafema-dev** (Hetzner cx53,
16 vCPU / 32 GB, `ssh grafema-dev`, `source ~/.cargo/env`), NOT the laptop or a 7 GB VM (OOM kills
rfdb-server → exit 143, which looks like a crash but is memory pressure). Missing language toolchains
make those files **skip** (elixir/mix for BEAM, swift, libclang for C/C++) — fast now, but the self-graph
is then partial for those languages. Running 2 full analyzes on the 32 GB box is the safe max (>2 OOMs).

## 6. Known standing perf debt (don't re-derive)

`REG-1128`: heavy Node.js resolve plugins do N+1 IPC walks — `type-inference 72.7s / 0 edges`,
`method-call-resolver 55s / 0 edges`, `shape-verifier 53s / 0 edges`. Fix direction = rewrite as Datalog
rules. Derive-phase plan (parallelize independent packs, hoist `derive_stats`, bound the `js_local_refs`
scope-walk) is in `_ai/self-analyze-perf-findings.md`.
177 changes: 177 additions & 0 deletions .github/workflows/self-analyze.yml
Original file line number Diff line number Diff line change
@@ -0,0 +1,177 @@
# Grafema self-analyze regression guard
#
# WHY THIS EXISTS
# ---------------
# Grafema's CI runs CodeQL "Analyze" jobs — it does NOT run *Grafema's own*
# `grafema analyze` against this repo. That gap is exactly what let a whole class
# of self-scale bugs ship silently: a derive-phase SIGSEGV (compaction vs.
# parallel-derive heap corruption) plus several conservative planner/eval caps
# (max_intermediate_results, MAX_MATERIALIZED_FACTS) that only bite when grafema
# analyzes its OWN ~714k-node / 1.33M-edge monorepo. None of that is reachable by
# the unit/integration tests, which run on tiny fixture graphs. See
# fix/derive-batch-cap (Disentinel/grafema#469).
#
# WHAT THIS JOB DOES
# ------------------
# 1. Builds grafema as it ships: pnpm build (TS) + cargo --release for the two
# native binaries the analyze pipeline spawns (rfdb-server + orchestrator).
# 2. Runs `grafema analyze` against this repo using the checked-in dogfooding
# config (.grafema/config.yaml), with the env that makes self-analyze pass.
# 3. Asserts the run reached exit 0 AND the JS enrichers actually fired — the
# graph must contain `mcp:tool` nodes (produced by the behavior enricher on
# packages/mcp/src/server.ts). A green exit with an empty graph is a silent
# failure we explicitly catch.
#
# RUNNER / SCOPE CHOICE
# ---------------------
# Runs the FULL monorepo self-analyze (not a scoped subset) so it exercises all
# ~40 derive packs — including the ones that triggered the SIGSEGV
# (@stdlib/js_local_refs) and the cap rejects (js_property_access_full). A scoped
# single-package analyze would NOT reproduce those cross-package derive paths, so
# scoping was rejected in favor of the full run.
# Runner: ubuntu-latest (GitHub-hosted: 16 GB RAM / 4 vCPU). A full self-analyze
# peaks ~7.5 GB RAM and ~14 min wall — it fits in 16 GB with headroom. The job
# timeout covers the Rust release build (~10-15 min, cached after the first run)
# plus the analyze. If a future graph outgrows 16 GB, switch `runs-on` to a larger
# GitHub-hosted runner label, or scope the analyze via `--service mcp --service
# cli` (note: --service currently takes a single name; would need a small CLI
# change or a per-service loop).
#
# NON-BLOCKING — READ BEFORE MAKING REQUIRED
# ------------------------------------------
# This job is intentionally NON-BLOCKING (continue-on-error: true) and is NOT a
# required status check. As of fix/derive-batch-cap the derive phase completes
# with 0 SIGSEGV, but the run still fails LATE on an enricher RPC 60s client
# timeout (being fixed separately on fix/enricher-rpc-timeout). Until a full
# self-analyze is green end-to-end, this job RUNS and SURFACES the result without
# blocking PRs.
#
# TODO(make-required): once fix/enricher-rpc-timeout lands and a full self-analyze
# reaches exit 0 with mcp:tool > 0 reliably, remove `continue-on-error: true`
# below AND add `self-analyze` to the branch-protection required checks for `main`
# so this class of bug can never regress silently again.

name: Self-Analyze

on:
# Run on PRs so regressions surface in review, and on the fix branch itself.
# Deliberately NOT wired into every push to main yet (it's non-blocking and
# still fails late — see header). Flip this on when made required.
pull_request:
branches: [main, ai-dev]
push:
branches: [fix/derive-batch-cap, fix/ci-self-analyze]
workflow_dispatch: {}

env:
NODE_VERSION: '22'
CARGO_TERM_COLOR: always
RUST_BACKTRACE: '1'
# Self-analyze env from fix/derive-batch-cap — lifts the interactive deadline
# and the planner fact-guard so the full 40-pack derive completes at self-scale.
RFDB_MATERIALIZE_DEADLINE_SECS: '3600'
RFDB_MAX_MATERIALIZED_FACTS: '200000000'

jobs:
self-analyze:
name: grafema analyze (self, non-blocking)
runs-on: ubuntu-latest
# Non-blocking: surface the result, never block a PR — see header TODO.
continue-on-error: true
# Generous: Rust release build (~10-15 min cold) + ~14 min analyze.
timeout-minutes: 45

steps:
- name: Checkout code
uses: actions/checkout@v4

- name: Setup pnpm
uses: pnpm/action-setup@v4

- name: Setup Node.js
uses: actions/setup-node@v4
with:
node-version: ${{ env.NODE_VERSION }}
cache: 'pnpm'

- name: Install Rust toolchain
uses: dtolnay/rust-toolchain@stable

- name: Cache cargo
uses: Swatinem/rust-cache@v2
with:
workspaces: |
packages/rfdb-server -> target
packages/grafema-orchestrator -> target
key: self-analyze

- name: Install dependencies
run: pnpm install --no-frozen-lockfile

- name: Build TS packages
run: pnpm build

# The analyze pipeline spawns two native binaries; the CLI auto-detects them
# from packages/<pkg>/target/release/ (findRfdbBinary / findOrchestratorBinary).
- name: Build rfdb-server (release)
working-directory: packages/rfdb-server
run: cargo build --release

- name: Build grafema-orchestrator (release)
working-directory: packages/grafema-orchestrator
run: cargo build --release

- name: Show free memory before analyze
run: free -h || true

# The repo ships .grafema/config.yaml (dogfooding config, full monorepo).
# --clear rebuilds from scratch; --no-auto-start is NOT used so the CLI
# brings up the freshly-built rfdb-server itself.
- name: Run grafema self-analyze
id: analyze
run: |
set -o pipefail
node packages/cli/dist/cli.js analyze --clear --verbose 2>&1 | tee /tmp/self-analyze.log
echo "Analyze exited 0."

# Assert the JS enrichers fired: the behavior enricher emits mcp:tool nodes
# for packages/mcp/src/server.ts. A clean exit with an empty graph is the
# silent-failure mode this guard exists to catch.
- name: Assert JS enrichers fired (mcp:tool nodes present)
run: |
set -o pipefail
node packages/cli/dist/cli.js query --type "mcp:tool" "" --json -l 100000 2>/dev/null > /tmp/mcp-tool.json
COUNT=$(node -e "const a=JSON.parse(require('fs').readFileSync('/tmp/mcp-tool.json','utf8')); console.log(Array.isArray(a)?a.length:0)")
echo "mcp:tool node count: $COUNT"
echo "mcp:tool nodes: $COUNT" >> "$GITHUB_STEP_SUMMARY"
if [ "$COUNT" -lt 1 ]; then
echo "::error::self-analyze produced 0 mcp:tool nodes — JS enrichers did not fire (graph is empty/incomplete)."
exit 1
fi
echo "OK: JS enrichers fired ($COUNT mcp:tool nodes)."

# Best-effort SIGSEGV / derive-reject canary. The derive phase must finish
# without a segfault or plan rejects; flag them loudly even though the job
# is non-blocking for now.
- name: Check derive phase for SIGSEGV / plan rejects
if: always()
run: |
if grep -qiE "SIGSEGV|signal: 11|segmentation fault" /tmp/self-analyze.log 2>/dev/null; then
echo "::error::SIGSEGV detected in self-analyze — derive-phase heap corruption regressed."
grep -iE "SIGSEGV|signal: 11|segmentation fault" /tmp/self-analyze.log | head >> "$GITHUB_STEP_SUMMARY" || true
exit 1
fi
if grep -qiE "plan reject|rejected by planner|MAX_MATERIALIZED_FACTS guard" /tmp/self-analyze.log 2>/dev/null; then
echo "::warning::Derive plan rejects present in self-analyze log (planner cap hit)."
fi
echo "No SIGSEGV in derive phase."

- name: Upload self-analyze log
if: always()
uses: actions/upload-artifact@v4
with:
name: self-analyze-log
path: |
/tmp/self-analyze.log
/tmp/mcp-tool.json
retention-days: 14

Check warning

Code scanning / CodeQL

Workflow does not contain permissions Medium

Actions job or workflow does not limit the permissions of the GITHUB_TOKEN. Consider setting an explicit permissions block, using the following as a minimal starting point: {contents: read}
Comment on lines +77 to +177
Loading
Loading