From df462a48f2f10ae341f476130fdadf4784d26b93 Mon Sep 17 00:00:00 2001 From: Sujay Jayakar Date: Thu, 5 Sep 2024 18:23:01 -0400 Subject: [PATCH] Add in a Honeycomb reporter for config pushes (#29573) GitOrigin-RevId: 04b61c54119f90f16d972ab98744ad82e82ab257 --- src/cli/lib/components.ts | 187 ++++++++++++++++++++++++-------------- src/cli/lib/deploy2.ts | 37 ++++++++ src/cli/lib/tracing.ts | 179 ++++++++++++++++++++++++++++++++++++ 3 files changed, 335 insertions(+), 68 deletions(-) create mode 100644 src/cli/lib/tracing.ts diff --git a/src/cli/lib/components.ts b/src/cli/lib/components.ts index 19c6f6c..c783cb2 100644 --- a/src/cli/lib/components.ts +++ b/src/cli/lib/components.ts @@ -11,7 +11,12 @@ import { getFunctionsDirectoryPath, readProjectConfig, } from "./config.js"; -import { finishPush, startPush, waitForSchema } from "./deploy2.js"; +import { + finishPush, + reportPushCompleted, + startPush, + waitForSchema, +} from "./deploy2.js"; import { version } from "../version.js"; import { PushOptions, runNonComponentsPush } from "./push.js"; import { ensureHasConvexDependency, functionsDir } from "./utils/utils.js"; @@ -37,7 +42,7 @@ import { withTmpDir } from "../../bundler/fs.js"; import { ROOT_DEFINITION_FILENAME } from "./components/constants.js"; import { handleDebugBundlePath } from "./debugBundlePath.js"; import chalk from "chalk"; -import { StartPushResponse } from "./deployApi/startPush.js"; +import { StartPushRequest, StartPushResponse } from "./deployApi/startPush.js"; import { deploymentSelectionFromOptions, fetchDeploymentCredentialsProvisionProd, @@ -46,6 +51,7 @@ import { FinishPushDiff, DeveloperIndexConfig, } from "./deployApi/finishPush.js"; +import { Reporter, Span } from "./tracing.js"; export async function runCodegen(ctx: Context, options: CodegenOptions) { // This also ensures the current directory is the project root. @@ -63,12 +69,18 @@ export async function runCodegen(ctx: Context, options: CodegenOptions) { deploymentSelection, ); - await startComponentsPushAndCodegen(ctx, projectConfig, configPath, { - ...options, - ...credentials, - generateCommonJSApi: options.commonjs, - verbose: options.dryRun, - }); + await startComponentsPushAndCodegen( + ctx, + Span.noop(), + projectConfig, + configPath, + { + ...options, + ...credentials, + generateCommonJSApi: options.commonjs, + verbose: options.dryRun, + }, + ); } else { if (options.init) { await doInitCodegen(ctx, functionsDirectoryPath, false, { @@ -104,6 +116,7 @@ export async function runPush(ctx: Context, options: PushOptions) { async function startComponentsPushAndCodegen( ctx: Context, + parentSpan: Span, projectConfig: ProjectConfig, configPath: string, options: { @@ -142,46 +155,47 @@ async function startComponentsPushAndCodegen( // Create a list of relevant component directories. These are just for knowing // while directories to bundle in bundleDefinitions and bundleImplementations. // This produces a bundle in memory as a side effect but it's thrown away. - // - // This is the very first time we traverse the component graph. - // We're just traversing to discover - const { components, dependencyGraph } = await componentGraph( - ctx, - absWorkingDir, - rootComponent, - verbose, + const { components, dependencyGraph } = await parentSpan.enterAsync( + "componentGraph", + () => componentGraph(ctx, absWorkingDir, rootComponent, verbose), ); changeSpinner(ctx, "Generating server code..."); - await withTmpDir(async (tmpDir) => { - await doInitialComponentCodegen(ctx, tmpDir, rootComponent, options); - for (const directory of components.values()) { - await doInitialComponentCodegen(ctx, tmpDir, directory, options); - } - }); + await parentSpan.enterAsync("doInitialComponentCodegen", () => + withTmpDir(async (tmpDir) => { + await doInitialComponentCodegen(ctx, tmpDir, rootComponent, options); + for (const directory of components.values()) { + await doInitialComponentCodegen(ctx, tmpDir, directory, options); + } + }), + ); changeSpinner(ctx, "Bundling component definitions..."); // This bundles everything but the actual function definitions const { appDefinitionSpecWithoutImpls, componentDefinitionSpecsWithoutImpls, - } = await bundleDefinitions( - ctx, - absWorkingDir, - dependencyGraph, - rootComponent, - // Note that this *includes* the root component. - [...components.values()], + } = await parentSpan.enterAsync("bundleDefinitions", () => + bundleDefinitions( + ctx, + absWorkingDir, + dependencyGraph, + rootComponent, + // Note that this *includes* the root component. + [...components.values()], + ), ); changeSpinner(ctx, "Bundling component schemas and implementations..."); const { appImplementation, componentImplementations } = - await bundleImplementations( - ctx, - rootComponent, - [...components.values()], - projectConfig.node.externalPackages, - verbose, + await parentSpan.enterAsync("bundleImplementations", () => + bundleImplementations( + ctx, + rootComponent, + [...components.values()], + projectConfig.node.externalPackages, + verbose, + ), ); if (options.debugBundlePath) { const { config: localConfig } = await configFromProjectConfig( @@ -246,55 +260,84 @@ async function startComponentsPushAndCodegen( ); return null; } + logStartPushSizes(parentSpan, startPushRequest); changeSpinner(ctx, "Uploading functions to Convex..."); - const startPushResponse = await startPush( - ctx, - options.url, - startPushRequest, - verbose, + const startPushResponse = await parentSpan.enterAsync("startPush", (span) => + startPush(ctx, span, options.url, startPushRequest, verbose), ); verbose && console.log("startPush:"); verbose && console.dir(startPushResponse, { depth: null }); changeSpinner(ctx, "Generating TypeScript bindings..."); - await withTmpDir(async (tmpDir) => { - await doFinalComponentCodegen( - ctx, - tmpDir, - rootComponent, - rootComponent, - startPushResponse, - options, - ); - for (const directory of components.values()) { + await parentSpan.enterAsync("doFinalComponentCodegen", () => + withTmpDir(async (tmpDir) => { await doFinalComponentCodegen( ctx, tmpDir, rootComponent, - directory, + rootComponent, startPushResponse, options, ); - } - }); + for (const directory of components.values()) { + await doFinalComponentCodegen( + ctx, + tmpDir, + rootComponent, + directory, + startPushResponse, + options, + ); + } + }), + ); changeSpinner(ctx, "Running TypeScript..."); - await typeCheckFunctionsInMode(ctx, options.typecheck, rootComponent.path); - for (const directory of components.values()) { - await typeCheckFunctionsInMode(ctx, options.typecheck, directory.path); - } + await parentSpan.enterAsync("typeCheckFunctionsInMode", async () => { + await typeCheckFunctionsInMode(ctx, options.typecheck, rootComponent.path); + for (const directory of components.values()) { + await typeCheckFunctionsInMode(ctx, options.typecheck, directory.path); + } + }); return startPushResponse; } +function logStartPushSizes(span: Span, startPushRequest: StartPushRequest) { + let v8Size = 0; + let v8Count = 0; + let nodeSize = 0; + let nodeCount = 0; + + for (const componentDefinition of startPushRequest.componentDefinitions) { + for (const module of componentDefinition.functions) { + if (module.environment === "isolate") { + v8Size += module.source.length + (module.sourceMap ?? "").length; + v8Count += 1; + } else if (module.environment === "node") { + nodeSize += module.source.length + (module.sourceMap ?? "").length; + nodeCount += 1; + } + } + } + span.setProperty("v8_size", v8Size.toString()); + span.setProperty("v8_count", v8Count.toString()); + span.setProperty("node_size", nodeSize.toString()); + span.setProperty("node_count", nodeCount.toString()); +} + export async function runComponentsPush( ctx: Context, options: PushOptions, configPath: string, projectConfig: ProjectConfig, ) { + const reporter = new Reporter(); + const pushSpan = Span.root(reporter, "runComponentsPush"); + pushSpan.setProperty("cli_version", version); + await ensureHasConvexDependency(ctx, "push"); if (options.dryRun) { @@ -305,25 +348,33 @@ export async function runComponentsPush( }); } - const startPushResponse = await startComponentsPushAndCodegen( - ctx, - projectConfig, - configPath, - options, + const startPushResponse = await pushSpan.enterAsync( + "startComponentsPushAndCodegen", + (span) => + startComponentsPushAndCodegen( + ctx, + span, + projectConfig, + configPath, + options, + ), ); if (!startPushResponse) { return; } - await waitForSchema(ctx, options.adminKey, options.url, startPushResponse); + await pushSpan.enterAsync("waitForSchema", (span) => + waitForSchema(ctx, span, options.adminKey, options.url, startPushResponse), + ); - const finishPushResponse = await finishPush( - ctx, - options.adminKey, - options.url, - startPushResponse, + const finishPushResponse = await pushSpan.enterAsync("finishPush", (span) => + finishPush(ctx, span, options.adminKey, options.url, startPushResponse), ); printDiff(ctx, finishPushResponse, options); + pushSpan.end(); + + // Asynchronously report that the push completed. + void reportPushCompleted(ctx, options.adminKey, options.url, reporter); } function printDiff( diff --git a/src/cli/lib/deploy2.ts b/src/cli/lib/deploy2.ts index a5533cc..7301459 100644 --- a/src/cli/lib/deploy2.ts +++ b/src/cli/lib/deploy2.ts @@ -25,10 +25,12 @@ import chalk from "chalk"; import { getTargetDeploymentName } from "./deployment.js"; import { deploymentDashboardUrlPage } from "../dashboard.js"; import { finishPushDiff, FinishPushDiff } from "./deployApi/finishPush.js"; +import { Reporter, Span } from "./tracing.js"; /** Push configuration2 to the given remote origin. */ export async function startPush( ctx: Context, + span: Span, url: string, request: StartPushRequest, verbose?: boolean, @@ -49,6 +51,9 @@ export async function startPush( const response = await fetch("/api/deploy2/start_push", { body: JSON.stringify(request), method: "POST", + headers: { + traceparent: span.encodeW3CTraceparent(), + }, }); return startPushResponse.parse(await response.json()); } catch (error: unknown) { @@ -90,6 +95,7 @@ const SCHEMA_TIMEOUT_MS = 10_000; export async function waitForSchema( ctx: Context, + span: Span, adminKey: string, url: string, startPush: StartPushResponse, @@ -111,6 +117,9 @@ export async function waitForSchema( timeoutMs: SCHEMA_TIMEOUT_MS, }), method: "POST", + headers: { + traceparent: span.encodeW3CTraceparent(), + }, }); currentStatus = schemaStatus.parse(await response.json()); } catch (error: unknown) { @@ -182,6 +191,7 @@ export async function waitForSchema( export async function finishPush( ctx: Context, + span: Span, adminKey: string, url: string, startPush: StartPushResponse, @@ -196,6 +206,9 @@ export async function finishPush( dryRun: false, }), method: "POST", + headers: { + traceparent: span.encodeW3CTraceparent(), + }, }); return finishPushDiff.parse(await response.json()); } catch (error: unknown) { @@ -212,3 +225,27 @@ export type AppDefinitionConfigWithoutImpls = Omit< AppDefinitionConfig, "schema" | "functions" | "auth" >; + +export async function reportPushCompleted( + ctx: Context, + adminKey: string, + url: string, + reporter: Reporter, +) { + const fetch = deploymentFetch(url, adminKey); + try { + const response = await fetch("/api/deploy2/report_push_completed", { + body: JSON.stringify({ + adminKey, + spans: reporter.spans, + }), + method: "POST", + }); + await response.json(); + } catch (error: unknown) { + logFailure( + ctx, + "Error: Unable to report push completed to " + url + ": " + error, + ); + } +} diff --git a/src/cli/lib/tracing.ts b/src/cli/lib/tracing.ts new file mode 100644 index 0000000..f8332e6 --- /dev/null +++ b/src/cli/lib/tracing.ts @@ -0,0 +1,179 @@ +import crypto from "node:crypto"; + +type TraceId = string; // u128 +type SpanId = string; // u64 + +type Nanoseconds = bigint; + +// base64 URL encoded little endian +type SerializedNanoseconds = string; + +export class Reporter { + spans: CompletedSpan[] = []; + + emit(span: CompletedSpan) { + this.spans.push(span); + } +} + +type EventRecord = { + name: string; + timestampUnixNs: Nanoseconds; + properties: Record; +}; + +export class Span { + private properties: Record = {}; + private events: EventRecord[] = []; + + private constructor( + private reporter: Reporter | undefined, + private traceId: TraceId, + private parentId: SpanId, + private spanId: SpanId, + private beginTimeUnixNs: Nanoseconds, + private name: string, + ) {} + + static noop() { + return new Span( + undefined, + randomTraceId(), + randomSpanId(), + randomSpanId(), + unixTimeNs(), + "", + ); + } + + static root(reporter: Reporter, name: string) { + const traceId = randomTraceId(); + const parentId = emptySpanId(); + const spanId = randomSpanId(); + const beginTimeUnixNs = unixTimeNs(); + return new Span(reporter, traceId, parentId, spanId, beginTimeUnixNs, name); + } + + setProperty(key: string, value: string) { + this.properties[key] = value; + } + + childSpan(name: string): Span { + const spanId = randomSpanId(); + const beginTimeUnixNs = unixTimeNs(); + return new Span( + this.reporter, + this.traceId, + this.spanId, + spanId, + beginTimeUnixNs, + name, + ); + } + + enter(name: string, f: (span: Span) => T): T { + const childSpan = this.childSpan(name); + try { + const result = f(childSpan); + childSpan.end(); + return result; + } finally { + childSpan.end(); + } + } + + async enterAsync(name: string, f: (span: Span) => Promise): Promise { + const childSpan = this.childSpan(name); + try { + return await f(childSpan); + } finally { + childSpan.end(); + } + } + + end() { + const endTimeUnixNs = unixTimeNs(); + const durationNs = endTimeUnixNs - this.beginTimeUnixNs; + const span = { + traceId: this.traceId, + parentId: this.parentId, + spanId: this.spanId, + beginTimeUnixNs: serializeNanoseconds(this.beginTimeUnixNs), + durationNs: serializeNanoseconds(durationNs), + name: this.name, + properties: this.properties, + events: this.events.map((event) => ({ + name: event.name, + timestampUnixNs: serializeNanoseconds(event.timestampUnixNs), + properties: event.properties, + })), + }; + if (this.reporter) { + this.reporter.emit(span); + } + } + + encodeW3CTraceparent() { + // Encode traceId and spanId as a big-endian hex strings. + const traceIdBytes = Buffer.from(this.traceId, "base64url"); + const traceIdBigInt = + traceIdBytes.readBigUInt64LE(0) | + (traceIdBytes.readBigUInt64LE(8) << 64n); + const traceIdHex = traceIdBigInt.toString(16).padStart(32, "0"); + + const spanIdBytes = Buffer.from(this.spanId, "base64url"); + const spanIdBigInt = spanIdBytes.readBigUInt64LE(0); + const spanIdHex = spanIdBigInt.toString(16).padStart(16, "0"); + + return `00-${traceIdHex}-${spanIdHex}-01`; + } +} + +function randomTraceId() { + return Buffer.from(crypto.getRandomValues(new Uint8Array(16))).toString( + "base64url", + ); +} + +function emptySpanId() { + return Buffer.from(new Uint8Array(8)).toString("base64url"); +} + +function randomSpanId() { + return Buffer.from(crypto.getRandomValues(new Uint8Array(8))).toString( + "base64url", + ); +} + +function unixTimeNs() { + // Note that as a unix nanosecond timestamp, performance.timeOrigin * 1000 is less than + // Number.MAX_SAFE_INTEGER, so multiply by 1000 to convert to microseconds, round, convert + // to bigint, and then multiply again to convert to nanoseconds. + return ( + BigInt(Math.floor(performance.timeOrigin * 1000)) * 1000n + + BigInt(Math.floor(performance.now() * 1000)) * 1000n + ); +} + +function serializeNanoseconds(ns: Nanoseconds): SerializedNanoseconds { + const buffer = Buffer.alloc(8); + buffer.writeBigUInt64LE(ns, 0); + return buffer.toString("base64url"); +} + +type CompletedSpan = { + traceId: TraceId; + parentId: SpanId; + spanId: SpanId; + beginTimeUnixNs: SerializedNanoseconds; + durationNs: SerializedNanoseconds; + name: string; + properties: Record; + events: SerializedEventRecord[]; +}; + +type SerializedEventRecord = { + name: string; + timestampUnixNs: SerializedNanoseconds; + properties: Record; +};