mirror of
https://github.com/oven-sh/bun
synced 2026-02-12 11:59:00 +00:00
## 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>
192 lines
6.2 KiB
TypeScript
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);
|
|
});
|
|
});
|