---
title: "Benchmark the Pipeline"
description: "Wrap each pipeline stage with a stopwatch and log the durations. The numbers are boring, but they're the only way to know whether the next lesson's snapshot work actually does anything."
canonical_url: "https://vercel.com/academy/vercel-sandbox/benchmark-the-pipeline"
md_url: "https://vercel.com/academy/vercel-sandbox/benchmark-the-pipeline.md"
docset_id: "vercel-academy"
doc_version: "1.0"
last_updated: "2026-05-17T22:48:15.564Z"
content_type: "lesson"
course: "vercel-sandbox"
course_title: "Vercel Sandbox"
prerequisites:  []
---

<agent-instructions>
Vercel Academy — structured learning, not reference docs.
Lessons are sequenced.
Adapt commands to the human's actual environment (OS, package manager, shell, editor) — detect from project context or ask, don't assume.
The lesson shows one path; if the human's project diverges, adapt concepts to their setup.
Preserve the learning goal over literal steps.
Quizzes are pedagogical — engage, don't spoil.
Quiz answers are included for your reference.
</agent-instructions>

# Benchmark the Pipeline

# Measure Before You Optimize

You can't optimize what you don't measure. Or you can, but you'll waste a week speeding up the thing that wasn't slow.

The pipeline works end-to-end now: validate → boot Sandbox → clone → collect → install → test → analyze → report. Some of those stages are fast and some are slow, and right now we have no idea which is which. Before we add snapshots in the next lesson, let's get the baseline.

## Outcome

Add timing measurements around each stage in `src/cli.ts` (or the lifecycle, your call), and print a per-stage breakdown plus total runtime at the end of every review.

## Fast Track

1. Define a `time(label, fn)` helper that wraps an async function and logs its duration.
2. Wrap each pipeline stage in the CLI with `time`.
3. Track total runtime separately and print a summary at the end.

## Hands-on exercise

Open `src/cli.ts` and add the helper plus the timing wrappers. The cleanest spot for the helper is at the top of the file:

```ts
import { Command } from 'commander';
import { runSandboxLifecycle } from './sandbox-lifecycle';
import { analyzeRepository } from './analyze';
import { parseTestFailures } from './test-runner';

function isValidGitHubRepoUrl(input: string): boolean {
  return /^https:\/\/github\.com\/[\w.-]+\/[\w.-]+\/?$/.test(input);
}

async function time<T>(label: string, fn: () => Promise<T>): Promise<T> {
  const startedAt = Date.now();
  try {
    return await fn();
  } finally {
    const durationMs = Date.now() - startedAt;
    console.log(`  ⏱  ${label}: ${durationMs}ms`);
  }
}

const program = new Command();

program
  .name('repo-review')
  .description('Clone and review a GitHub repository in a Sandbox')
  .version('0.1.0');

program
  .command('review <repoUrl>')
  .description('Run a Sandbox review against a GitHub repository URL')
  .action(async (repoUrl: string) => {
    if (!isValidGitHubRepoUrl(repoUrl)) {
      console.error(`Invalid GitHub repository URL: ${repoUrl}`);
      console.error('Expected format: https://github.com/<owner>/<repo>');
      process.exitCode = 2;
      return;
    }

    console.log(`Reviewing ${repoUrl}...`);
    const totalStart = Date.now();

    try {
      const lifecycle = await time('sandbox lifecycle', () => runSandboxLifecycle(repoUrl));
      const aiReview = lifecycle.files.length === 0
        ? { overallRisk: 'low' as const, findings: [] }
        : await time('ai analysis', () => analyzeRepository(lifecycle.files));

      const testFindings = parseTestFailures(
        `${lifecycle.testResult.stdout}\n${lifecycle.testResult.stderr}`
      );

      const combined = {
        overallRisk: testFindings.length > 0 ? 'high' as const : aiReview.overallRisk,
        aiFindings: aiReview.findings,
        testFindings
      };

      console.log(`\nOverall risk: ${combined.overallRisk}`);
      console.log(`AI findings: ${combined.aiFindings.length}`);
      for (const finding of combined.aiFindings) {
        console.log(`  [${finding.severity}] ${finding.summary} (${finding.file})`);
      }
      console.log(`Test findings: ${combined.testFindings.length}`);
      for (const finding of combined.testFindings) {
        console.log(`  [${finding.severity}] ${finding.details}`);
      }

      console.log(`\nTotal: ${Date.now() - totalStart}ms`);
    } catch (error) {
      console.error('Review failed:', error instanceof Error ? error.message : error);
      process.exitCode = 1;
    }
  });

program.parse();
```

The `time` helper uses `try/finally` so we log the duration even when the wrapped function throws. Knowing "ai analysis failed after 18 seconds" is way more useful than just knowing it failed.

Right now the per-stage breakdown is coarse (just lifecycle + analysis). The lifecycle itself does several big things internally (boot, clone, install, test). If you want sub-stage timing inside the lifecycle, you can add the same `time` helper there. For now, the rough split is enough to see where the seconds go.

\*\*Warning: Troubleshooting: timing shows 0ms\*\*

If a stage prints `0ms`, something synchronous returned before any real work happened. Check that the function actually awaits something inside.

\*\*Note: Troubleshooting: Date.now is good enough\*\*

For benchmarking at the second/minute scale, `Date.now()` is fine. `performance.now()` gets you fractional milliseconds, which we don't need here. Don't overthink it.

## Try It

```bash
pnpm review https://github.com/vercel/examples
```

Expected output:

```txt
Reviewing https://github.com/vercel/examples...
  ⏱  sandbox lifecycle: 24180ms
  ⏱  ai analysis: 7240ms

Overall risk: low
AI findings: 2
  ...
Test findings: 0

Total: 31420ms
```

Two takeaways from a real run.

First, the lifecycle dominates. Most of the 24 seconds is `pnpm install`, which we'll attack with snapshots next lesson.

Second, the AI analysis is fixed overhead. Smaller prompts will be faster, larger ones slower, but it doesn't scale with repo size the way `install` does.

Knowing this, the snapshot work in 5.2 is justified. Without these numbers it would have been a guess.

## Commit

```bash
git add src/cli.ts
git commit -m "feat(cli): add per-stage timing and total runtime"
```

## Done-When

- [ ] `time(label, fn)` helper logs duration even when the wrapped function throws
- [ ] Each major stage is wrapped in `time`
- [ ] Total runtime prints at the end of every successful review
- [ ] Timing also prints when a stage fails (so we know where time was spent before the error)

## Solution

```ts title="src/cli.ts (helper)"
async function time<T>(label: string, fn: () => Promise<T>): Promise<T> {
  const startedAt = Date.now();
  try {
    return await fn();
  } finally {
    const durationMs = Date.now() - startedAt;
    console.log(`  ⏱  ${label}: ${durationMs}ms`);
  }
}
```


---

[Full course index](/academy/llms.txt) · [Sitemap](/academy/sitemap.md)