Skip to content
Merged
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
7 changes: 7 additions & 0 deletions .changeset/startup-profile-summary.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,7 @@
---
"wrangler": minor
---

Graduate `wrangler check startup` from alpha and show bundle size and a local timing summary

The command no longer prints an alpha warning. It now reports its local profile window, sampled active, garbage collection, and idle time alongside the raw and compressed bundle sizes. The existing measurement warning continues to distinguish these local measurements from startup time measured on Cloudflare.
62 changes: 62 additions & 0 deletions packages/wrangler/src/__tests__/startup-profiling.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import {
writeWranglerConfig,
} from "@cloudflare/workers-utils/test-helpers";
import { afterEach, beforeEach, describe, test } from "vitest";
import { summarizeStartupProfile } from "../check/commands";
import { logger } from "../logger";
import { collectCLIOutput } from "./helpers/collect-cli-output";
import { mockConsoleMethods } from "./helpers/mock-console";
Expand Down Expand Up @@ -33,6 +34,13 @@ describe("wrangler check startup", () => {
expect(std.out).toContain(
`CPU Profile has been written to worker-startup.cpuprofile`
);
expect(std.out).toMatch(/Bundle: \d+\.\d{2} KiB \/ gzip: \d+\.\d{2} KiB/);
expect(std.out).toContain("Local startup profile:");
expect(std.out).toContain("Profile window:");
expect(std.out).toContain("Sampled time:");
expect(std.out).toContain("Active:");
expect(std.out).toContain("Idle:");
expect(std.out).toContain("Samples:");

await expect(
readFile("worker-startup.cpuprofile", "utf8")
Expand Down Expand Up @@ -160,3 +168,57 @@ describe("wrangler check startup", () => {
).resolves.toContain("callFrame");
});
});

describe("summarizeStartupProfile", () => {
test("separates active, garbage collection, and idle samples", ({
expect,
}) => {
expect(
summarizeStartupProfile({
nodes: [
{
id: 1,
callFrame: {
functionName: "(idle)",
scriptId: "0",
url: "",
lineNumber: -1,
columnNumber: -1,
},
},
{
id: 2,
callFrame: {
functionName: "(garbage collector)",
scriptId: "0",
url: "",
lineNumber: -1,
columnNumber: -1,
},
},
{
id: 3,
callFrame: {
functionName: "startup",
scriptId: "1",
url: "index.js",
lineNumber: 0,
columnNumber: 0,
},
},
],
startTime: 1_000,
endTime: 8_000,
samples: [1, 2, 3],
timeDeltas: [1_000, 2_000, 3_000],
})
).toEqual({
profileWindow: 7_000,
sampledTime: 6_000,
activeTime: 5_000,
garbageCollectionTime: 2_000,
idleTime: 1_000,
sampleCount: 3,
});
});
});
91 changes: 86 additions & 5 deletions packages/wrangler/src/check/commands.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ import { randomUUID } from "node:crypto";
import events from "node:events";
import { readFile, writeFile } from "node:fs/promises";
import path from "node:path";
import { gzipSync } from "node:zlib";
import { log } from "@cloudflare/cli-shared-helpers";
import { spinnerWhile } from "@cloudflare/cli-shared-helpers/interactive";
import { getWranglerTmpDir, UserError } from "@cloudflare/workers-utils";
Expand All @@ -17,16 +18,27 @@ import {
} from "../deployment-bundle/module-collection";
import { logger } from "../logger";
import type { Config } from "@cloudflare/workers-utils";
import type Protocol from "devtools-protocol";
import type { ModuleDefinition } from "miniflare";
import type { FormData, FormDataEntryValue } from "undici";

const mimeTypeModuleType = flipObject(moduleTypeMimeType);
const ONE_KIB_BYTES = 1024;
Comment thread
dario-piotrowicz marked this conversation as resolved.

export interface StartupProfileSummary {
profileWindow: number;
sampledTime: number;
activeTime: number;
garbageCollectionTime: number;
idleTime: number;
sampleCount: number;
}

export const checkNamespace = createNamespace({
metadata: {
description: "☑︎ Run checks on your Worker",
owner: "Workers: Authoring and Testing",
status: "alpha",
status: "stable",
hidden: true,
},
});
Expand Down Expand Up @@ -79,16 +91,28 @@ async function checkStartupHandler(
});
logger.resetLoggerLevel();
}
const parsedWorkerBundle = await parseFormDataFromFile(workerBundle);
const bundleSize = await getBundleSize(parsedWorkerBundle);
const cpuProfileResult = await spinnerWhile({
promise: analyseBundle(workerBundle),
promise: analyseBundleProfile(parsedWorkerBundle),
startMessage: "Analysing",
endMessage: chalk.green("Startup phase analysed"),
});
const startupSummary = summarizeStartupProfile(cpuProfileResult);

await writeFile(outfile, JSON.stringify(await cpuProfileResult));

log(
[
`Bundle: ${(bundleSize.size / ONE_KIB_BYTES).toFixed(2)} KiB / gzip: ${(bundleSize.gzipSize / ONE_KIB_BYTES).toFixed(2)} KiB`,
"",
"Local startup profile:",
` Profile window: ${formatMicroseconds(startupSummary.profileWindow)}`,
` Sampled time: ${formatMicroseconds(startupSummary.sampledTime)}`,
` Active: ${formatMicroseconds(startupSummary.activeTime)} (including ${formatMicroseconds(startupSummary.garbageCollectionTime)} garbage collection)`,
` Idle: ${formatMicroseconds(startupSummary.idleTime)}`,
` Samples: ${startupSummary.sampleCount}`,
"",
`CPU Profile has been written to ${outfile}. Load it into the Chrome DevTools profiler (or directly in VSCode) to view a flamegraph.`,
"",
"Note that the CPU Profile was measured on your Worker running locally on your machine, which has a different CPU than when your Worker runs on Cloudflare.",
Expand All @@ -98,6 +122,54 @@ async function checkStartupHandler(
);
}

function formatMicroseconds(microseconds: number): string {
return `${(microseconds / 1000).toFixed(1)} ms`;
}

async function getBundleSize(workerBundle: FormData) {
const modules: Blob[] = [];
for (const entry of workerBundle.values()) {
if (entry instanceof Blob && entry.type !== "application/source-map") {
modules.push(entry);
}
}
const bundle = new Blob(modules);
return {
size: bundle.size,
gzipSize: gzipSync(await bundle.arrayBuffer()).byteLength,
};
}

export function summarizeStartupProfile(
profile: Protocol.Profiler.Profile
): StartupProfileSummary {
const nodes = new Map(profile.nodes.map((node) => [node.id, node]));
const samples = profile.samples ?? [];
const timeDeltas = profile.timeDeltas ?? [];
let sampledTime = 0;
let idleTime = 0;
let garbageCollectionTime = 0;

for (const [index, timeDelta] of timeDeltas.entries()) {
sampledTime += timeDelta;
const functionName = nodes.get(samples[index] ?? 0)?.callFrame.functionName;
if (functionName === "(idle)") {
idleTime += timeDelta;
} else if (functionName === "(garbage collector)") {
garbageCollectionTime += timeDelta;
}
}

return {
profileWindow: profile.endTime - profile.startTime,
sampledTime,
activeTime: sampledTime - idleTime,
garbageCollectionTime,
idleTime,
sampleCount: samples.length,
};
}

export const checkStartupCommand = createCommand({
args: {
outfile: {
Expand Down Expand Up @@ -139,7 +211,7 @@ export const checkStartupCommand = createCommand({
metadata: {
description: "⌛ Profile your Worker's startup performance",
owner: "Workers: Authoring and Testing",
status: "alpha",
status: "stable",
},
behaviour: {
suggestSkillsAfterHandler: true,
Expand Down Expand Up @@ -211,6 +283,12 @@ async function parseFormDataFromFile(file: string): Promise<FormData> {
export async function analyseBundle(
workerBundle: string | FormData
): Promise<Record<string, unknown>> {
return { ...(await analyseBundleProfile(workerBundle)) };
}

async function analyseBundleProfile(
workerBundle: string | FormData
): Promise<Protocol.Profiler.Profile> {
if (typeof workerBundle === "string") {
workerBundle = await parseFormDataFromFile(workerBundle);
}
Expand Down Expand Up @@ -256,9 +334,12 @@ export async function analyseBundle(
ws.send(JSON.stringify({ id: 1, method: "Profiler.enable", params: {} }));
ws.send(JSON.stringify({ id: 2, method: "Profiler.start", params: {} }));

const cpuProfileResult = new Promise<Record<string, unknown>>((accept) => {
const cpuProfileResult = new Promise<Protocol.Profiler.Profile>((accept) => {
ws.addEventListener("message", (e) => {
const data = JSON.parse(e.data as string);
const data = JSON.parse(e.data as string) as {
method?: string;
result: { profile: Protocol.Profiler.Profile };
};
if (data.method === "Profiler.stop") {
void mf.dispose().then(() => accept(data.result.profile));
}
Expand Down
Loading