diff --git a/platform/wab/src/wab/server/loader/gen-code-bundle.ts b/platform/wab/src/wab/server/loader/gen-code-bundle.ts index 8c550dedc..dab9ebdaa 100644 --- a/platform/wab/src/wab/server/loader/gen-code-bundle.ts +++ b/platform/wab/src/wab/server/loader/gen-code-bundle.ts @@ -5,7 +5,8 @@ import { resolveProjectDeps, VersionToSync, } from "@/wab/server/loader/resolve-projects"; -import { withSpan } from "@/wab/server/util/apm-util"; +import { logger } from "@/wab/server/observability"; +import { withSpan, withTimeSpent } from "@/wab/server/util/apm-util"; import { upsertS3CacheEntry } from "@/wab/server/util/s3-util"; import { CachedCodegenOutputBundle, @@ -76,7 +77,14 @@ export async function genPublishedLoaderCodeBundle( ...(await resolveProjectDeps(dbMgr, projectVersions)), ...projectVersions, }), - `Project versions ${JSON.stringify(projectVersions)}` + undefined, + { + project_count: Object.keys(projectVersions).length, + project_ids: Object.keys(projectVersions), + projects: Object.entries(projectVersions).map( + ([id, v]) => `${id}@${v.version}` + ), + } ); await ensureDevFlags(dbMgr); @@ -217,7 +225,16 @@ async function genLoaderCodeBundleForProjectVersions( // If version is a branch name, we want to get the latest of that branch if (v.version === "latest" || maybeBranch) { // If no explicit version, then we cannot cache; just perform the codegen - return await codegenProject(projectId, v.version, v.indirect); + const { result, spentTime } = await withTimeSpent(() => + codegenProject(projectId, v.version, v.indirect) + ); + logger().info("loader-codegen-project", { + project_id: projectId, + project_version: v.version, + indirect: v.indirect, + duration_ms: spentTime, + }); + return result; } else { return await upsertS3CacheEntry< [ @@ -233,18 +250,32 @@ async function genLoaderCodeBundleForProjectVersions( indirect: v.indirect, exportOpts, }), - compute: async () => - await codegenProject(projectId, v.version, v.indirect), + compute: async () => { + const { result, spentTime } = await withTimeSpent(() => + codegenProject(projectId, v.version, v.indirect) + ); + logger().info("loader-codegen-project", { + project_id: projectId, + project_version: v.version, + indirect: v.indirect, + duration_ms: spentTime, + }); + return result; + }, serialize: (obj) => JSON.stringify(obj), deserialize: (str) => JSON.parse(str), }); } }) ), - `Projects ${JSON.stringify({ - ...projectVersions, - loaderVersion: opts.loaderVersion, - })}` + undefined, + { + platform: opts.platform, + loader_version: opts.loaderVersion, + browser_only: opts.browserOnly, + project_count: Object.keys(projectVersions).length, + project_versions: JSON.stringify(projectVersions), + } ) ); @@ -306,10 +337,18 @@ async function genLoaderCodeBundleForProjectVersions( return await bundleProjects(); } }, - `Projects ${JSON.stringify({ - ...projectVersions, - loaderVersion: opts.loaderVersion, - })}` + undefined, + { + platform: opts.platform, + loader_version: opts.loaderVersion, + browser_only: opts.browserOnly, + mode: opts.mode, + project_count: Object.keys(projectVersions).length, + project_ids: Object.keys(projectVersions), + projects: Object.entries(projectVersions).map( + ([id, v]) => `${id}@${v.version}` + ), + } ); return result; } diff --git a/platform/wab/src/wab/server/loader/module-bundler.ts b/platform/wab/src/wab/server/loader/module-bundler.ts index 942df98de..2cf044a8b 100644 --- a/platform/wab/src/wab/server/loader/module-bundler.ts +++ b/platform/wab/src/wab/server/loader/module-bundler.ts @@ -560,41 +560,51 @@ export async function bundleModules( throw new LoaderDeprecatedVersionError(); } - return withSpan("loader-bundle-esbuild", async () => { - try { - return await bundleModulesEsbuild( - dir, - codegenOutputs, - componentDeps, - opts - ); - } catch (err) { - const bundleErrorStr: string = err.toString(); - logger().error( - `Error bundling with esbuild: ${bundleErrorStr}: ${err.stack}` - ); + return withSpan( + "loader-bundle-esbuild", + async () => { try { - const errPrefix = await uploadErrorFiles(err, dir); - logger().error(`Errors uploaded: ${errPrefix}`); - } catch (err2) { - logger().error(`Error uploading error files: ${err2.toString()}`); - } + return await bundleModulesEsbuild( + dir, + codegenOutputs, + componentDeps, + opts + ); + } catch (err) { + const bundleErrorStr: string = err.toString(); + logger().error( + `Error bundling with esbuild: ${bundleErrorStr}: ${err.stack}` + ); + try { + const errPrefix = await uploadErrorFiles(err, dir); + logger().error(`Errors uploaded: ${errPrefix}`); + } catch (err2) { + logger().error(`Error uploading error files: ${err2.toString()}`); + } - const transformedBundleErrorStr = transformBundlerErrors( - bundleErrorStr, - componentRefs - ); + const transformedBundleErrorStr = transformBundlerErrors( + bundleErrorStr, + componentRefs + ); - if (transformedBundleErrorStr) { - logger().error(`transformedError: ${transformedBundleErrorStr}`); - throw new LoaderBundlingError(transformedBundleErrorStr); - } + if (transformedBundleErrorStr) { + logger().error(`transformedError: ${transformedBundleErrorStr}`); + throw new LoaderBundlingError(transformedBundleErrorStr); + } - await checkEsbuildFatalError(bundleErrorStr); + await checkEsbuildFatalError(bundleErrorStr); - throw new Error(`Error bundling with esbuild: ${bundleErrorStr}`); + throw new Error(`Error bundling with esbuild: ${bundleErrorStr}`); + } + }, + undefined, + { + platform: opts.platform, + loader_version: opts.loaderVersion, + browser_only: opts.browserOnly, + mode: opts.mode, } - }); + ); } function deriveEsbuildDefines(opts: { diff --git a/platform/wab/src/wab/server/loader/resolve-projects.ts b/platform/wab/src/wab/server/loader/resolve-projects.ts index 505130391..5c79ab127 100644 --- a/platform/wab/src/wab/server/loader/resolve-projects.ts +++ b/platform/wab/src/wab/server/loader/resolve-projects.ts @@ -77,7 +77,7 @@ export async function resolveLatestProjectVersions( opts: { prefilledOnly: boolean } = { prefilledOnly: false } ) { return withSpan( - `resolveLatestProjectVersions-${projectIdsAndTags.length}`, + "resolveLatestProjectVersions", async () => { const pkgVersions = await Promise.all( projectIdsAndTags.map((projectIdAndTag) => @@ -96,6 +96,14 @@ export async function resolveLatestProjectVersions( pkgVersion.version, ]) ); + }, + undefined, + { + project_count: projectIdsAndTags.length, + project_ids: projectIdsAndTags.map((p) => p.projectId), + projects: projectIdsAndTags.map((p) => + p.tag ? `${p.projectId}@${p.tag}` : p.projectId + ), } ); } diff --git a/platform/wab/src/wab/server/util/apm-util.ts b/platform/wab/src/wab/server/util/apm-util.ts index 753964214..28832abfc 100644 --- a/platform/wab/src/wab/server/util/apm-util.ts +++ b/platform/wab/src/wab/server/util/apm-util.ts @@ -1,11 +1,13 @@ import { logger } from "@/wab/server/observability"; import { WabPromTimer } from "@/wab/server/promstats"; +import { Properties } from "@/wab/shared/observability/Properties"; import { trace } from "@opentelemetry/api"; export async function withSpan( name: string, f: () => Promise, - msg?: string + msg?: string, + payload?: Properties ) { const start = new Date().getTime(); const promTimer = new WabPromTimer(name); @@ -14,8 +16,13 @@ export async function withSpan( try { return await f(); } finally { + const durationMs = new Date().getTime() - start; const suffix = msg ? `: ${msg}` : ""; - logger().info(`${name} took ${new Date().getTime() - start}ms${suffix}`); + logger().info(`${name} took ${durationMs}ms${suffix}`, { + operation_name: name, + duration_ms: durationMs, + ...payload, + }); promTimer.end(); span.end(); } diff --git a/platform/wab/src/wab/server/workers/codegen.ts b/platform/wab/src/wab/server/workers/codegen.ts index d2109fdeb..a2f47cc2a 100644 --- a/platform/wab/src/wab/server/workers/codegen.ts +++ b/platform/wab/src/wab/server/workers/codegen.ts @@ -231,7 +231,13 @@ export async function doGenCode( indirect, opts.scheme ), - `Project ${projectId}` + undefined, + { + project_id: projectId, + version, + revision_number: revisionNumber, + revision_id: revisionId, + } ); if (project.workspace?.teamId) { diff --git a/platform/wab/src/wab/server/workers/prefill-cloudfront.ts b/platform/wab/src/wab/server/workers/prefill-cloudfront.ts index 4c2485bef..a6ea896df 100644 --- a/platform/wab/src/wab/server/workers/prefill-cloudfront.ts +++ b/platform/wab/src/wab/server/workers/prefill-cloudfront.ts @@ -60,17 +60,6 @@ export async function prefillCloudfront( publishment.projectIds ); - const label = `Pre-filling codegen combo ${JSON.stringify( - resolvedProjectIdSpecs - )}, version=${publishment.loaderVersion}, platform=${ - publishment.platform - }, browserOnly=${publishment.browserOnly}, i18n=${JSON.stringify({ - key: publishment.i18nKeyScheme, - prefix: publishment.i18nTagPrefix, - })}, appDir=${publishment.appDir} projectIds=${JSON.stringify( - publishment.projectIds - )} pkgVersionId=${pkgVersionId}`; - await withSpan( "loader-prefill", async () => { @@ -95,7 +84,18 @@ export async function prefillCloudfront( }) ); }, - label + undefined, + { + platform: publishment.platform, + loader_version: publishment.loaderVersion, + browser_only: publishment.browserOnly, + app_dir: publishment.appDir, + i18n_key_scheme: publishment.i18nKeyScheme, + i18n_tag_prefix: publishment.i18nTagPrefix, + pkg_version_id: pkgVersionId, + project_ids: publishment.projectIds, + projects: resolvedProjectIdSpecs, + } ); }) );