Files
bun.sh/test/cli/run/cpu-prof.test.ts
robobun 646aede0d4 Fix CPU profiler timestamps - use setDouble() instead of setInteger() (#24206)
## Summary

Fixes CPU profiler generating invalid timestamps that Chrome DevTools
couldn't parse (though VSCode's profiler viewer accepted them).

## The Problem

CPU profiles generated by `--cpu-prof` had timestamps that were either:
1. Negative (in the original broken profile from the gist)
2. Truncated/corrupted (after initial timestamp calculation fix)

Example from the broken profile:
```json
{
  "startTime": -822663297,
  "endTime": -804820609
}
```

After initial fix, timestamps were positive but still wrong:
```json
{
  "startTime": 1573519100,  // Should be ~1761784720948727
  "endTime": 1573849434
}
```

## Root Cause

**Primary Issue**: `WTF::JSON::Object::setInteger()` has precision
issues with large values (> 2^31). When setting timestamps like
`1761784720948727` (microseconds since Unix epoch - 16 digits), the
method was truncating/corrupting them.

**Secondary Issue**: The timestamp calculation logic needed
clarification - now explicitly uses the earliest sample's wall clock
time as startTime and calculates a consistent wallClockOffset.

## The Fix

### src/bun.js/bindings/BunCPUProfiler.cpp

Changed from `setInteger()` to `setDouble()` for timestamp
serialization:

```cpp
// Before (broken):
json->setInteger("startTime"_s, static_cast<long long>(startTime));
json->setInteger("endTime"_s, static_cast<long long>(endTime));

// After (fixed):
json->setDouble("startTime"_s, startTime);
json->setDouble("endTime"_s, endTime);
```

JSON `Number` type can precisely represent integers up to 2^53 (~9
quadrillion), which is far more than needed for microsecond timestamps
(~10^15 for current dates).

Also clarified the timestamp calculation to use `wallClockStart`
directly as the profile's `startTime` and calculate a `wallClockOffset`
for converting stopwatch times to wall clock times.

### test/cli/run/cpu-prof.test.ts

Added validation that timestamps are:
- Positive
- In microseconds (> 1000000000000000, < 3000000000000000)
- Within valid Unix epoch range

## Testing

```bash
bun bd test test/cli/run/cpu-prof.test.ts
```

All tests pass 

Generated profile now has correct timestamps:
```json
{
  "startTime": 1761784720948727.2,
  "endTime": 1761784721305814
}
```

## Why VSCode Worked But Chrome DevTools Didn't

- **VSCode**: Only cares about relative timing (duration = endTime -
startTime), doesn't validate absolute timestamp ranges
- **Chrome DevTools**: Expects timestamps in microseconds since Unix
epoch (positive, ~16 digits), fails validation when timestamps are
negative, too small, or out of valid range

## References

- Gist with CPU profile format documentation:
https://gist.github.com/Jarred-Sumner/2c12da481845e20ce6a6175ee8b05a3e
- Chrome DevTools Protocol - Profiler:
https://chromedevtools.github.io/devtools-protocol/tot/Profiler/

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

---------

Co-authored-by: Claude Bot <claude-bot@bun.sh>
Co-authored-by: Claude <noreply@anthropic.com>
2025-10-29 20:55:48 -07:00

192 lines
6.2 KiB
TypeScript

import { describe, expect, test } from "bun:test";
import { readdirSync, readFileSync } from "fs";
import { bunEnv, bunExe, tempDir } from "harness";
import { join } from "path";
describe.concurrent("--cpu-prof", () => {
test("generates CPU profile with default name", async () => {
using dir = tempDir("cpu-prof", {
"test.js": `
// CPU-intensive task
function fibonacci(n) {
if (n <= 1) return n;
return fibonacci(n - 1) + fibonacci(n - 2);
}
console.log(fibonacci(20));
`,
});
const proc = Bun.spawn({
cmd: [bunExe(), "--cpu-prof", "test.js"],
cwd: String(dir),
env: bunEnv,
stdout: "pipe",
stderr: "pipe",
});
// Drain pipes to prevent deadlock
const [exitCode] = await Promise.all([proc.exited, proc.stdout.text(), proc.stderr.text()]);
// Check that a .cpuprofile file was created
const files = readdirSync(String(dir));
const profileFiles = files.filter(f => f.endsWith(".cpuprofile"));
expect(profileFiles.length).toBeGreaterThan(0);
expect(exitCode).toBe(0);
// Read and validate the profile
const profilePath = join(String(dir), profileFiles[0]);
const profileContent = readFileSync(profilePath, "utf-8");
const profile = JSON.parse(profileContent);
// Validate Chrome CPU Profiler format
expect(profile).toHaveProperty("nodes");
expect(profile).toHaveProperty("startTime");
expect(profile).toHaveProperty("endTime");
expect(profile).toHaveProperty("samples");
expect(profile).toHaveProperty("timeDeltas");
expect(Array.isArray(profile.nodes)).toBe(true);
expect(Array.isArray(profile.samples)).toBe(true);
expect(Array.isArray(profile.timeDeltas)).toBe(true);
// Validate root node
expect(profile.nodes.length).toBeGreaterThan(0);
const rootNode = profile.nodes[0];
expect(rootNode.id).toBe(1);
expect(rootNode.callFrame.functionName).toBe("(root)");
// Validate node structure
profile.nodes.forEach((node: any) => {
expect(node).toHaveProperty("id");
expect(node).toHaveProperty("callFrame");
expect(node).toHaveProperty("hitCount");
expect(node.callFrame).toHaveProperty("functionName");
expect(node.callFrame).toHaveProperty("scriptId");
expect(node.callFrame).toHaveProperty("url");
expect(node.callFrame).toHaveProperty("lineNumber");
expect(node.callFrame).toHaveProperty("columnNumber");
});
// Validate samples point to valid nodes
const nodeIds = new Set(profile.nodes.map((n: any) => n.id));
profile.samples.forEach((sample: number) => {
expect(nodeIds.has(sample)).toBe(true);
});
// Validate time deltas
expect(profile.timeDeltas.length).toBe(profile.samples.length);
// For very fast programs, start and end times might be equal or very close
expect(profile.startTime).toBeLessThanOrEqual(profile.endTime);
// CRITICAL: Validate timestamps are positive and in microseconds
// Chrome DevTools requires timestamps in microseconds since Unix epoch
// A valid timestamp should be > 1000000000000000 (around year 2001)
// and < 3000000000000000 (around year 2065)
expect(profile.startTime).toBeGreaterThan(1000000000000000);
expect(profile.startTime).toBeLessThan(3000000000000000);
expect(profile.endTime).toBeGreaterThan(1000000000000000);
expect(profile.endTime).toBeLessThan(3000000000000000);
});
test("--cpu-prof-name sets custom filename", async () => {
using dir = tempDir("cpu-prof-name", {
"test.js": `
function loop() {
const end = Date.now() + 16;
while (Date.now() < end) {}
}
loop();
`,
});
const customName = "my-profile.cpuprofile";
const proc = Bun.spawn({
cmd: [bunExe(), "--cpu-prof", "--cpu-prof-name", customName, "test.js"],
cwd: String(dir),
env: bunEnv,
stdout: "pipe",
stderr: "pipe",
});
// Drain pipes to prevent deadlock
const [exitCode] = await Promise.all([proc.exited, proc.stdout.text(), proc.stderr.text()]);
const files = readdirSync(String(dir));
expect(files).toContain(customName);
expect(exitCode).toBe(0);
});
test("--cpu-prof-dir sets custom directory", async () => {
using dir = tempDir("cpu-prof-dir", {
"test.js": `
function loop() {
const end = Date.now() + 16;
while (Date.now() < end) {}
}
loop();
`,
"profiles": {},
});
const proc = Bun.spawn({
cmd: [bunExe(), "--cpu-prof", "--cpu-prof-dir", "profiles", "test.js"],
cwd: String(dir),
env: bunEnv,
stdout: "pipe",
stderr: "pipe",
});
// Drain pipes to prevent deadlock
const [exitCode] = await Promise.all([proc.exited, proc.stdout.text(), proc.stderr.text()]);
const profilesDir = join(String(dir), "profiles");
const files = readdirSync(profilesDir);
const profileFiles = files.filter(f => f.endsWith(".cpuprofile"));
expect(profileFiles.length).toBeGreaterThan(0);
expect(exitCode).toBe(0);
});
test("profile captures function names", async () => {
using dir = tempDir("cpu-prof-functions", {
"test.js": `
function myFunction() {
let sum = 0;
for (let i = 0; i < 1000000; i++) {
sum += i;
}
return sum;
}
myFunction();
`,
});
const proc = Bun.spawn({
cmd: [bunExe(), "--cpu-prof", "test.js"],
cwd: String(dir),
env: bunEnv,
stdout: "pipe",
stderr: "pipe",
});
// Drain pipes to prevent deadlock
const [exitCode] = await Promise.all([proc.exited, proc.stdout.text(), proc.stderr.text()]);
const files = readdirSync(String(dir));
const profileFiles = files.filter(f => f.endsWith(".cpuprofile"));
expect(profileFiles.length).toBeGreaterThan(0);
const profilePath = join(String(dir), profileFiles[0]);
const profile = JSON.parse(readFileSync(profilePath, "utf-8"));
// Check that we captured some meaningful function names
const functionNames = profile.nodes.map((n: any) => n.callFrame.functionName);
expect(functionNames.some((name: string) => name !== "(root)" && name !== "(program)")).toBe(true);
expect(exitCode).toBe(0);
});
});