Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[wrangler] feat: source map logged strings #4423

Merged
merged 2 commits into from
Dec 15, 2023
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
9 changes: 9 additions & 0 deletions .changeset/lazy-gifts-train.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
---
"wrangler": minor
---

feat: apply source mapping to logged strings

Previously, Wrangler would only apply source mapping to uncaught exceptions. This meant if you caught an exception and logged its stack trace, the call sites would reference built JavaScript files as opposed to source files. This change looks for stack traces in logged messages, and tries to source map them.

Note source mapping is only applied when outputting logs. `Error#stack` does not return a source mapped stack trace. This means the actual runtime value of `new Error().stack` and the output from `console.log(new Error().stack)` may be different.
5 changes: 4 additions & 1 deletion fixtures/worker-app/src/index.js
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import { now } from "./dep";
import { randomBytes } from "isomorphic-random-example";
import { now } from "./dep";
import { logErrors } from "./log";

console.log("startup log");

Expand All @@ -24,6 +25,8 @@ export default {
request.cf
);

logErrors();

await fetch(new URL("http://example.com"));
await fetch(
new Request("http://example.com", { method: "POST", body: "foo" })
Expand Down
12 changes: 12 additions & 0 deletions fixtures/worker-app/src/log.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
// Make sure built JavaScript file doesn't use the same line numbers
interface Output {
thing: 42;
}

export function logErrors(): Output {
console.log(new Error("logged error one"));
console.log(new Error("logged error two").stack);
console.log({ error: new Error("logged error three") });

return { thing: 42 };
}
11 changes: 11 additions & 0 deletions fixtures/worker-app/tests/index.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,17 @@ describe("'wrangler dev' correctly renders pages", () => {
const output = getOutput();
expect(output).toContain("startup log");
expect(output).toContain("request log");

// Check logged strings are source mapped
expect(output).toMatch(
/Error: logged error one.+fixtures\/worker-app\/src\/log.ts:7:14/s
);
expect(output).toMatch(
/Error: logged error two.+fixtures\/worker-app\/src\/log.ts:8:14/s
);
expect(output).toMatch(
/Error: logged error three.+fixtures\/worker-app\/src\/log.ts:9:23/s
);
});

it("uses `workerd` condition when bundling", async ({ expect }) => {
Expand Down
2 changes: 1 addition & 1 deletion packages/miniflare/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -41,12 +41,12 @@
"miniflare": "bootstrap.js"
},
"dependencies": {
"@cspotcode/source-map-support": "0.8.1",
"acorn": "^8.8.0",
"acorn-walk": "^8.2.0",
"capnp-ts": "^0.7.0",
"exit-hook": "^2.2.1",
"glob-to-regexp": "^0.4.1",
"source-map-support": "0.5.21",
"stoppable": "^1.1.0",
"undici": "^5.22.1",
"workerd": "1.20231030.0",
Expand Down
4 changes: 2 additions & 2 deletions packages/miniflare/src/plugins/core/errors/index.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
import fs from "fs";
import path from "path";
import { fileURLToPath } from "url";
import type { UrlAndMap } from "source-map-support";
import type { UrlAndMap } from "@cspotcode/source-map-support";
import { z } from "zod";
import { Request, Response } from "../../../http";
import { Log } from "../../../shared";
Expand Down Expand Up @@ -49,7 +49,7 @@ interface SourceFile {
}

// Try to read a file from the file-system, returning undefined if not found
function maybeGetDiskFile(filePath: string): SourceFile | undefined {
function maybeGetDiskFile(filePath: string): Required<SourceFile> | undefined {
try {
const contents = fs.readFileSync(filePath, "utf8");
return { path: filePath, contents };
Expand Down
20 changes: 12 additions & 8 deletions packages/miniflare/src/plugins/core/errors/sourcemap.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import assert from "assert";
import type { Options } from "source-map-support";
import type { Options } from "@cspotcode/source-map-support";
import { parseStack } from "./callsite";

const sourceMapInstallBaseOptions: Options = {
Expand All @@ -8,6 +8,7 @@ const sourceMapInstallBaseOptions: Options = {
handleUncaughtExceptions: false,
// Don't hook Node `require` function
hookRequire: false,
redirectConflictingLibrary: false,

// Make sure we're using fresh copies of files (i.e. between `setOptions()`)
emptyCacheBetweenOperations: true,
Expand Down Expand Up @@ -36,10 +37,10 @@ export function getSourceMapper(): SourceMapper {
// always updated, load a fresh copy, by resetting then restoring the
// `require` cache.

const originalSupport = require.cache["source-map-support"];
delete require.cache["source-map-support"];
const support: typeof import("source-map-support") = require("source-map-support");
require.cache["source-map-support"] = originalSupport;
const originalSupport = require.cache["@cspotcode/source-map-support"];
delete require.cache["@cspotcode/source-map-support"];
const support: typeof import("@cspotcode/source-map-support") = require("@cspotcode/source-map-support");
require.cache["@cspotcode/source-map-support"] = originalSupport;

const originalPrepareStackTrace = Error.prepareStackTrace;
support.install(sourceMapInstallBaseOptions);
Expand All @@ -50,10 +51,13 @@ export function getSourceMapper(): SourceMapper {
sourceMapper = (retrieveSourceMap, error) => {
support.install({
...sourceMapInstallBaseOptions,
retrieveFile(file: string): string | null {
retrieveFile(_file: string): string {
// `retrieveFile` should only be called by the default implementation of
// `retrieveSourceMap`, so we shouldn't need to implement it
assert.fail(`Unexpected retrieveFile(${JSON.stringify(file)}) call`);
// `retrieveSourceMap`, which will only be called if `retrieveSourceMap`
// failed. In that case, return an empty string so the default
// implementation fails too (can't find `// sourceMappingURL` comment
// in empty string).
return "";
},
retrieveSourceMap,
});
Expand Down
20 changes: 14 additions & 6 deletions packages/miniflare/test/plugins/core/errors/index.spec.ts
Original file line number Diff line number Diff line change
@@ -1,14 +1,14 @@
import assert from "assert";
import fs from "fs/promises";
import path from "path";
import { fileURLToPath } from "url";
import { fileURLToPath, pathToFileURL } from "url";
import test from "ava";
import Protocol from "devtools-protocol";
import esbuild from "esbuild";
import { DeferredPromise, Log, LogLevel, Miniflare, fetch } from "miniflare";
import type { RawSourceMap } from "source-map";
import NodeWebSocket from "ws";
import { escapeRegexp, useTmp } from "../../../test-shared";
import { escapeRegexpComponent, useTmp } from "../../../test-shared";

const FIXTURES_PATH = path.resolve(
__dirname,
Expand All @@ -26,6 +26,12 @@ const MODULES_ENTRY_PATH = path.join(FIXTURES_PATH, "modules.ts");
const DEP_ENTRY_PATH = path.join(FIXTURES_PATH, "nested/dep.ts");
const REDUCE_PATH = path.join(FIXTURES_PATH, "reduce.ts");

function pathOrUrlRegexp(filePath: string): `(${string}|${string})` {
return `(${escapeRegexpComponent(filePath)}|${escapeRegexpComponent(
pathToFileURL(filePath).href
)})`;
}

test("source maps workers", async (t) => {
// Build fixtures
const tmp = await useTmp(t);
Expand Down Expand Up @@ -135,8 +141,8 @@ addEventListener("fetch", (event) => {
let error = await t.throwsAsync(mf.dispatchFetch("http://localhost"), {
message: "unnamed",
});
const serviceWorkerEntryRegexp = escapeRegexp(
`${SERVICE_WORKER_ENTRY_PATH}:6:16`
const serviceWorkerEntryRegexp = new RegExp(
`${pathOrUrlRegexp(SERVICE_WORKER_ENTRY_PATH)}:6:16`
);
t.regex(String(error?.stack), serviceWorkerEntryRegexp);
error = await t.throwsAsync(mf.dispatchFetch("http://localhost/a"), {
Expand All @@ -148,7 +154,9 @@ addEventListener("fetch", (event) => {
error = await t.throwsAsync(mf.dispatchFetch("http://localhost/b"), {
message: "b",
});
const modulesEntryRegexp = escapeRegexp(`${MODULES_ENTRY_PATH}:5:17`);
const modulesEntryRegexp = new RegExp(
`${pathOrUrlRegexp(MODULES_ENTRY_PATH)}:5:17`
);
t.regex(String(error?.stack), modulesEntryRegexp);
error = await t.throwsAsync(mf.dispatchFetch("http://localhost/c"), {
message: "c",
Expand All @@ -174,7 +182,7 @@ addEventListener("fetch", (event) => {
instanceOf: TypeError,
message: "Dependency error",
});
const nestedRegexp = escapeRegexp(`${DEP_ENTRY_PATH}:4:16`);
const nestedRegexp = new RegExp(`${pathOrUrlRegexp(DEP_ENTRY_PATH)}:4:16`);
t.regex(String(error?.stack), nestedRegexp);

// Check source mapping URLs rewritten
Expand Down
4 changes: 2 additions & 2 deletions packages/miniflare/test/test-shared/asserts.ts
Original file line number Diff line number Diff line change
Expand Up @@ -18,9 +18,9 @@ export function isWithin(
);
}

export function escapeRegexp(value: string): RegExp {
export function escapeRegexpComponent(value: string): string {
// From https://developer.mozilla.org/en-US/docs/Web/JavaScript/Guide/Regular_expressions#escaping
return new RegExp(value.replace(/[.*+?^${}()|[\]\\]/g, "\\$&"));
return value.replace(/[.*+?^${}()|[\]\\]/g, "\\$&");
}

export function flaky(
Expand Down
2 changes: 1 addition & 1 deletion packages/wrangler/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -102,6 +102,7 @@
},
"dependencies": {
"@cloudflare/kv-asset-handler": "^0.2.0",
"@cspotcode/source-map-support": "0.8.1",
"@esbuild-plugins/node-globals-polyfill": "^0.2.3",
"@esbuild-plugins/node-modules-polyfill": "^0.2.2",
"blake3-wasm": "^2.1.5",
Expand All @@ -113,7 +114,6 @@
"resolve.exports": "^2.0.2",
"selfsigned": "^2.0.1",
"source-map": "0.6.1",
"source-map-support": "0.5.21",
"xxhash-wasm": "^1.0.1"
},
"devDependencies": {
Expand Down
2 changes: 2 additions & 0 deletions packages/wrangler/scripts/deps.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,8 @@ export const EXTERNAL_DEPENDENCIES = [
// todo - bundle miniflare too
"selfsigned",
"source-map",
// CommonJS module using `module.require()` which isn't provided by `esbuild`
"@cspotcode/source-map-support",
"@esbuild-plugins/node-globals-polyfill",
"@esbuild-plugins/node-modules-polyfill",
"chokidar",
Expand Down
4 changes: 4 additions & 0 deletions packages/wrangler/src/dev/inspect.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import {
isAllowedSourcePath,
} from "../api/startDevWorker/bundle-allowed-paths";
import { logger } from "../logger";
import { getSourceMappedString } from "../sourcemap";
import type { EsbuildBundle } from "../dev/use-esbuild";
import type Protocol from "devtools-protocol";
import type { RawSourceMap } from "source-map";
Expand Down Expand Up @@ -57,6 +58,9 @@ export function logConsoleMessage(
case "undefined":
case "symbol":
case "bigint":
if (typeof ro.value === "string") {
ro.value = getSourceMappedString(ro.value);
}
petebacondarwin marked this conversation as resolved.
Show resolved Hide resolved
args.push(ro.value);
break;
case "function":
Expand Down
5 changes: 3 additions & 2 deletions packages/wrangler/src/dev/miniflare.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import { ModuleTypeToRuleType } from "../deployment-bundle/module-collection";
import { withSourceURLs } from "../deployment-bundle/source-url";
import { getHttpsOptions } from "../https-options";
import { logger } from "../logger";
import { getSourceMappedString } from "../sourcemap";
import { updateCheck } from "../update-check";
import type { Config } from "../config";
import type {
Expand Down Expand Up @@ -462,7 +463,7 @@ export function handleRuntimeStdio(stdout: Readable, stderr: Readable) {

// anything not exlicitly handled above should be logged as info (via stdout)
else {
logger.info(chunk);
logger.info(getSourceMappedString(chunk));
}
});

Expand Down Expand Up @@ -501,7 +502,7 @@ export function handleRuntimeStdio(stdout: Readable, stderr: Readable) {

// anything not exlicitly handled above should be logged as an error (via stderr)
else {
logger.error(chunk);
logger.error(getSourceMappedString(chunk));
}
});
}
Expand Down
Loading
Loading