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
24 changes: 20 additions & 4 deletions apps/webapp/app/services/logger.server.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import type { LogLevel } from "@trigger.dev/core/logger";
import { Logger } from "@trigger.dev/core/logger";
import { Logger, redact } from "@trigger.dev/core/logger";
import { patchConsoleToTelnet, startTelnetLogServer } from "@trigger.dev/core/v3/telnetLogServer";
import { sensitiveDataReplacer } from "./sensitiveDataReplacer";
import { AsyncLocalStorage } from "async_hooks";
Expand All @@ -12,24 +12,40 @@ export function trace<T>(fields: Record<string, unknown>, fn: () => T): T {
return currentFieldsStore.run(fields, fn);
}

// The keys below aren't already in the Logger's default deny-list. Passing them here means the
// extra data sent to Sentry gets the same redaction as the stdout line, instead of bypassing it.
const SENTRY_EXTRA_FILTERED_KEYS = ["examples", "connectionString"];

Logger.onError = (message, ...args) => {
const error = extractErrorFromArgs(args);
const extra = redact(flattenArgs(args), SENTRY_EXTRA_FILTERED_KEYS) as Record<string, unknown>;

if (error) {
captureException(error, {
captureException(redactError(error), {
extra: {
message,
...flattenArgs(args),
...extra,
},
});
Comment thread
coderabbitai[bot] marked this conversation as resolved.
} else {
Comment thread
carderne marked this conversation as resolved.
captureMessage(message, {
level: "error",
extra: flattenArgs(args),
extra,
});
}
};

function redactError(error: Error): Error {
const redactedError = new Error(redact(error.message) as string);
redactedError.name = error.name;

if (error.stack) {
redactedError.stack = redact(error.stack) as string;
}

return redactedError;
}

function extractErrorFromArgs(args: Array<Record<string, unknown> | undefined>) {
for (const arg of args) {
if (arg && "error" in arg && arg.error instanceof Error) {
Expand Down
69 changes: 69 additions & 0 deletions apps/webapp/test/logger.server.onError.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,69 @@
import { beforeEach, describe, expect, it, vi } from "vitest";

const captureExceptionMock = vi.fn();
const captureMessageMock = vi.fn();

vi.mock("@sentry/remix", () => ({
captureException: captureExceptionMock,
captureMessage: captureMessageMock,
}));

describe("logger.server Logger.onError", () => {
beforeEach(() => {
captureExceptionMock.mockClear();
captureMessageMock.mockClear();
vi.spyOn(console, "error").mockImplementation(() => {});
});

it("redacts the extra payload sent to Sentry on the captureMessage path", async () => {
const { logger } = await import("~/services/logger.server");

logger.error("something failed", {
payload: { secret: "do-not-leak" },
apiKey: "tr_prod_should_not_leak",
});

expect(captureMessageMock).toHaveBeenCalledTimes(1);
const [, options] = captureMessageMock.mock.calls[0] as [string, { extra: unknown }];

expect(JSON.stringify(options.extra)).not.toContain("do-not-leak");
expect(JSON.stringify(options.extra)).not.toContain("tr_prod_should_not_leak");
});

it("redacts the exception and extra payload sent to Sentry", async () => {
const { logger } = await import("~/services/logger.server");
const error = new Error("tr_prod_should_not_leak");
error.stack = "Bearer secret-token";

logger.error("boom", {
error,
payload: { secret: "do-not-leak" },
});

expect(captureExceptionMock).toHaveBeenCalledTimes(1);
const [capturedError, options] = captureExceptionMock.mock.calls[0] as [
Error,
{ extra: unknown },
];

expect(capturedError).not.toBe(error);
expect(capturedError.message).not.toContain("tr_prod_should_not_leak");
expect(capturedError.stack).not.toContain("secret-token");
expect(JSON.stringify(options.extra)).not.toContain("do-not-leak");
});

it("still forwards non-sensitive extra fields", async () => {
const { logger } = await import("~/services/logger.server");

logger.error("something failed", { runId: "run_123", keep: "this stays" });

expect(captureMessageMock).toHaveBeenCalledTimes(1);
const [, options] = captureMessageMock.mock.calls[0] as [
string,
{ extra: Record<string, unknown> },
];

expect(options.extra.runId).toBe("run_123");
expect(options.extra.keep).toBe("this stays");
});
});
162 changes: 132 additions & 30 deletions packages/core/src/logger.ts
Comment thread
carderne marked this conversation as resolved.
Comment thread
ericallam marked this conversation as resolved.
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,53 @@ export type LogLevel = "log" | "error" | "warn" | "info" | "debug" | "verbose";

const logLevels: Array<LogLevel> = ["log", "error", "warn", "info", "debug", "verbose"];

// Applied to every Logger instance, on top of whatever a caller passes in as `filteredKeys`.
// Keeps the previous "opt-in, per-instance" list from being the only thing standing between a
// logged object and a credential or piece of customer content that happens to share its name.
const DEFAULT_FILTERED_KEYS = [
"authorization",
"token",
"apikey",
"secretkey",
"accesstoken",
"refreshtoken",
"password",
"jwt",
"payload",
"output",
"metadata",
"seedmetadata",
"input",
"email",
"headers",
"completedwaitpoints",
];
Comment thread
carderne marked this conversation as resolved.

// Belt-and-braces value-shape check: catches secrets anywhere in values that land under a field
// name we didn't think to deny-list (a trigger.dev API key, bearer token, or OpenAI-style key).
const SECRET_VALUE_PATTERN = /(tr_[a-zA-Z0-9_-]{4,}|sk-[a-zA-Z0-9_-]{4,}|Bearer\s+\S+)/;
Comment thread
carderne marked this conversation as resolved.

// Per-field and per-structure caps so a single unbounded object (a run payload, a batch of
// items, a DB row) can't blow up log line size or CPU. Truncation keeps the field present and
// queryable rather than dropping it.
const MAX_STRING_LENGTH = 8192;
const MAX_ARRAY_LENGTH = 100;
const MAX_DEPTH = 10;

function buildFilteredKeySet(filteredKeys: string[]): Set<string> {
const set = new Set(DEFAULT_FILTERED_KEYS);

for (const key of filteredKeys) {
set.add(key.toLowerCase());
}

return set;
}

export class Logger {
#name: string;
readonly #level: number;
#filteredKeys: string[] = [];
#filteredKeys: Set<string> = new Set(DEFAULT_FILTERED_KEYS);
#jsonReplacer?: (key: string, value: unknown) => unknown;
#additionalFields: () => Record<string, unknown>;

Expand All @@ -39,7 +82,7 @@ export class Logger {
) {
this.#name = name;
this.#level = logLevels.indexOf((env.TRIGGER_LOG_LEVEL ?? level) as LogLevel);
this.#filteredKeys = filteredKeys;
this.#filteredKeys = buildFilteredKeySet(filteredKeys);
this.#jsonReplacer = createReplacer(jsonReplacer);
this.#additionalFields = additionalFields ?? (() => ({}));
}
Expand All @@ -48,7 +91,7 @@ export class Logger {
return new Logger(
this.#name,
logLevels[this.#level],
this.#filteredKeys,
Array.from(this.#filteredKeys),
this.#jsonReplacer,
() => ({ ...this.#additionalFields(), ...fields })
);
Expand Down Expand Up @@ -115,8 +158,8 @@ export class Logger {
// Get the current context from trace if it exists
const currentSpan = trace.getSpan(context.active());

const structuredError = extractStructuredErrorFromArgs(...args);
const structuredMessage = extractStructuredMessageFromArgs(...args);
const structuredError = extractStructuredErrorFromArgs(this.#filteredKeys, ...args);
const structuredMessage = extractStructuredMessageFromArgs(this.#filteredKeys, ...args);

const structuredLog = {
...structureArgs(safeJsonClone(args) as Record<string, unknown>[], this.#filteredKeys),
Expand Down Expand Up @@ -153,38 +196,52 @@ export class Logger {
// Detect if args is an error object
// Or if args contains an error object at the "error" key
// In both cases, return the error object as a structured error
function extractStructuredErrorFromArgs(...args: Array<Record<string, unknown> | undefined>) {
const error = args.find((arg) => arg instanceof Error) as Error | undefined;
// Run every field through the same filter/truncation used for the rest of the log line, so an
// error's message/stack/metadata (which can embed request or row data verbatim) gets the same
// treatment as everything else, instead of bypassing it.
function extractStructuredErrorFromArgs(
filteredKeys: Set<string>,
...args: Array<Record<string, unknown> | undefined>
) {
const error = args.find((arg) => arg instanceof Error) as
| (Error & { metadata?: unknown })
| undefined;

if (error) {
return {
message: error.message,
stack: error.stack,
message: filterKeys(error.message, filteredKeys),
stack: filterKeys(error.stack, filteredKeys),
name: error.name,
metadata: "metadata" in error ? error.metadata : undefined,
metadata: "metadata" in error ? filterKeys(error.metadata, filteredKeys) : undefined,
};
}

const structuredError = args.find((arg) => arg?.error);

if (structuredError && structuredError.error instanceof Error) {
const nestedError = structuredError.error as Error & { metadata?: unknown };

return {
message: structuredError.error.message,
stack: structuredError.error.stack,
name: structuredError.error.name,
metadata: "metadata" in structuredError.error ? structuredError.error.metadata : undefined,
message: filterKeys(nestedError.message, filteredKeys),
stack: filterKeys(nestedError.stack, filteredKeys),
name: nestedError.name,
metadata:
"metadata" in nestedError ? filterKeys(nestedError.metadata, filteredKeys) : undefined,
};
}
Comment thread
devin-ai-integration[bot] marked this conversation as resolved.

return;
}

function extractStructuredMessageFromArgs(...args: Array<Record<string, unknown> | undefined>) {
function extractStructuredMessageFromArgs(
filteredKeys: Set<string>,
...args: Array<Record<string, unknown> | undefined>
) {
// Check to see if there is a `message` key in the args, and if so, return it
const structuredMessage = args.find((arg) => arg?.message);

if (structuredMessage) {
return structuredMessage.message;
return filterKeys(structuredMessage.message, filteredKeys);
}

return;
Expand Down Expand Up @@ -221,37 +278,65 @@ function safeJsonClone(obj: unknown) {
}
}

// If args is has a single item that is an object, return that object
function structureArgs(args: Array<Record<string, unknown>>, filteredKeys: string[] = []) {
if (!args) {
// `args` has already been through safeJsonClone, so this only has to filter/truncate it, not
// clone it again. If there's exactly one arg, return it directly (unwrapped) so it can be spread
// onto the structured log; otherwise filter every arg and return the array. Filtering runs
// regardless of arg count, so a multi-arg call gets the same redaction as the common single-arg
// case.
function structureArgs(
args: Array<Record<string, unknown>> | undefined,
filteredKeys: Set<string> = new Set()
) {
if (!args || args.length === 0) {
return;
}

if (args.length === 0) {
return;
}
const filteredArgs = args.map((arg) => filterKeys(arg, filteredKeys));

if (args.length === 1 && typeof args[0] === "object") {
return filterKeys(JSON.parse(JSON.stringify(args[0], bigIntReplacer)), filteredKeys);
if (filteredArgs.length === 1) {
return filteredArgs[0];
}

return args;
return filteredArgs;
}

// Recursively filter out keys from an object, including nested objects, and arrays
function filterKeys(obj: unknown, keys: string[]): any {
// Recursively filter out keys from an object, including nested objects and arrays. Also caps
// string length, array length and recursion depth, and redacts string values that look like a
// secret regardless of which key they were found under.
function filterKeys(obj: unknown, keys: Set<string>, depth = 0): any {
if (typeof obj === "string") {
if (SECRET_VALUE_PATTERN.test(obj)) {
return `[filtered ${prettyPrintBytes(obj)}]`;
}

return truncateString(obj);
}

if (typeof obj !== "object" || obj === null) {
return obj;
}

if (depth >= MAX_DEPTH) {
return "[max depth exceeded]";
}

if (Array.isArray(obj)) {
return obj.map((item) => filterKeys(item, keys));
const isTruncated = obj.length > MAX_ARRAY_LENGTH;
const items = (isTruncated ? obj.slice(0, MAX_ARRAY_LENGTH) : obj).map((item) =>
filterKeys(item, keys, depth + 1)
);

if (isTruncated) {
items.push(`[truncated ${obj.length - MAX_ARRAY_LENGTH} more items]`);
}

return items;
}

const filteredObj: any = {};

for (const [key, value] of Object.entries(obj)) {
if (keys.includes(key)) {
if (keys.has(key.toLowerCase())) {
if (value) {
filteredObj[key] = `[filtered ${prettyPrintBytes(value)}]`;
} else {
Expand All @@ -260,12 +345,29 @@ function filterKeys(obj: unknown, keys: string[]): any {
continue;
}

filteredObj[key] = filterKeys(value, keys);
filteredObj[key] = filterKeys(value, keys, depth + 1);
}

return filteredObj;
}

function truncateString(value: string): string {
if (value.length <= MAX_STRING_LENGTH) {
return value;
}

return `${value.slice(0, MAX_STRING_LENGTH)}...[truncated ${
value.length - MAX_STRING_LENGTH
} chars]`;
}

// Runs a value through the same default-deny-list + truncation pipeline every Logger applies to
// its own log lines. For destinations that receive log arguments through a side channel (e.g. an
// error reporting `onError` hook) rather than through `Logger#structuredLog` itself.
export function redact(value: unknown, filteredKeys: string[] = []): unknown {
return filterKeys(value, buildFilteredKeySet(filteredKeys));
}
Comment thread
carderne marked this conversation as resolved.

function prettyPrintBytes(value: unknown): string {
if (env.NODE_ENV === "production") {
return "skipped size";
Expand Down
Loading
Loading