- `logger.debug('message', async () => ({ asyncReturn: await asyncFn() }))` is now supported
- NOTE: this may result in logging occurring out of band for these calls if other events fire befor they settle
Update CI labels to direct jobs to correct servers
309 lines
12 KiB
TypeScript
309 lines
12 KiB
TypeScript
import { describe, expect, it, vi } from "vitest";
|
|
import { createLogger, isLogCallOptions, parseLoggingOverride } from "../src/index";
|
|
import type { LogEvent, LogSink } from "../src/index";
|
|
import { createSentrySink } from "../src/sentry";
|
|
|
|
function sink(): { sink: LogSink; events: LogEvent[] } {
|
|
const events: LogEvent[] = [];
|
|
return { events, sink: { emit: (event) => events.push(event) } };
|
|
}
|
|
|
|
describe("parseLoggingOverride", () => {
|
|
it("accepts a global level and a namespace-filtered level", () => {
|
|
expect(parseLoggingOverride("debug")).toEqual({ level: "debug", namespaces: [] });
|
|
expect(parseLoggingOverride("debug:WIDGET, API")).toEqual({
|
|
level: "debug",
|
|
namespaces: ["WIDGET", "API"],
|
|
});
|
|
expect(parseLoggingOverride("verbose")).toBeUndefined();
|
|
});
|
|
});
|
|
|
|
describe("isLogCallOptions", () => {
|
|
it("accepts only known option keys", () => {
|
|
expect(isLogCallOptions({ sentry: true })).toBe(true);
|
|
expect(isLogCallOptions({ suppressSentry: true })).toBe(true);
|
|
expect(isLogCallOptions({ sentry: true, suppressSentry: false })).toBe(true);
|
|
expect(isLogCallOptions({ requestId: "req_1" })).toBe(false);
|
|
expect(isLogCallOptions({ sentry: true, requestId: "req_1" })).toBe(false);
|
|
expect(isLogCallOptions({})).toBe(false);
|
|
});
|
|
});
|
|
|
|
describe("createLogger", () => {
|
|
it("uses environment defaults and never evaluates suppressed lazy data", () => {
|
|
const destination = sink();
|
|
const expensive = vi.fn(() => ({ huge: "snapshot" }));
|
|
const logger = createLogger({ environment: "production", sinks: [destination.sink] });
|
|
logger.debug("ignored", expensive);
|
|
logger.error("kept", expensive);
|
|
expect(expensive).toHaveBeenCalledTimes(1);
|
|
expect(destination.events).toHaveLength(1);
|
|
expect(destination.events[0]?.arguments).toEqual(["kept", { huge: "snapshot" }]);
|
|
expect(destination.events[0]?.async).toBeUndefined();
|
|
});
|
|
|
|
it("never starts suppressed async lazy factories", () => {
|
|
const destination = sink();
|
|
const expensive = vi.fn(async () => ({ huge: "snapshot" }));
|
|
const logger = createLogger({ environment: "production", sinks: [destination.sink] });
|
|
logger.debug("ignored", expensive);
|
|
expect(expensive).not.toHaveBeenCalled();
|
|
expect(destination.events).toHaveLength(0);
|
|
});
|
|
|
|
it("settles async lazy factories before emitting and sets async", async () => {
|
|
const destination = sink();
|
|
const factory = vi.fn(async () => ({ data: 1 }));
|
|
const logger = createLogger({ environment: "development", sinks: [destination.sink] });
|
|
logger.debug("response", factory);
|
|
expect(factory).toHaveBeenCalledTimes(1);
|
|
expect(destination.events).toHaveLength(0);
|
|
await vi.waitFor(() => expect(destination.events).toHaveLength(1));
|
|
expect(destination.events[0]).toMatchObject({
|
|
arguments: ["response", { data: 1 }],
|
|
async: true,
|
|
});
|
|
});
|
|
|
|
it("unwraps direct Promise arguments and keeps rejection reasons", async () => {
|
|
const destination = sink();
|
|
const reason = new Error("boom");
|
|
const logger = createLogger({ environment: "development", sinks: [destination.sink] });
|
|
logger.error("failed", { id: 1 }, Promise.reject(reason));
|
|
expect(destination.events).toHaveLength(0);
|
|
await vi.waitFor(() => expect(destination.events).toHaveLength(1));
|
|
expect(destination.events[0]).toMatchObject({
|
|
arguments: ["failed", { id: 1 }, reason],
|
|
async: true,
|
|
});
|
|
});
|
|
|
|
it("applies session namespace filtering to namespace descendants", () => {
|
|
const destination = sink();
|
|
const storage = { getItem: () => "debug:WIDGET" };
|
|
createLogger({
|
|
environment: "production",
|
|
namespace: "WIDGET:Button",
|
|
sessionStorage: storage,
|
|
sinks: [destination.sink],
|
|
}).debug("shown");
|
|
createLogger({
|
|
environment: "production",
|
|
namespace: "API",
|
|
sessionStorage: storage,
|
|
sinks: [destination.sink],
|
|
}).debug("hidden");
|
|
expect(destination.events.map((event) => event.arguments[0])).toEqual(["shown"]);
|
|
});
|
|
|
|
it("builds immutable child namespaces and reports failed assertions as errors", () => {
|
|
const destination = sink();
|
|
const root = createLogger({
|
|
environment: "development",
|
|
namespace: "WIDGET",
|
|
sinks: [destination.sink],
|
|
});
|
|
root.child("Button").assert(false, "missing label");
|
|
expect(root.namespace).toBe("WIDGET");
|
|
expect(destination.events[0]).toMatchObject({
|
|
level: "error",
|
|
namespace: "WIDGET:Button",
|
|
arguments: ["Assertion failed", "missing label"],
|
|
});
|
|
});
|
|
|
|
it("sends production browser errors to Sentry without writing to the console", () => {
|
|
const destination = sink();
|
|
const consoleError = vi.spyOn(console, "error").mockImplementation(() => undefined);
|
|
const logger = createLogger({
|
|
environment: "production",
|
|
runtime: "browser",
|
|
sentry: destination.sink,
|
|
});
|
|
logger.error("captured");
|
|
expect(destination.events).toHaveLength(1);
|
|
expect(destination.events[0]).toMatchObject({
|
|
sendToSentryIssue: true,
|
|
sendToSentryLogs: false,
|
|
sendToConsole: true,
|
|
});
|
|
expect(consoleError).not.toHaveBeenCalled();
|
|
consoleError.mockRestore();
|
|
});
|
|
|
|
it("forces selected events to Sentry Logs without writing them to the console", () => {
|
|
const destination = sink();
|
|
const consoleInfo = vi.spyOn(console, "info").mockImplementation(() => undefined);
|
|
const logger = createLogger({
|
|
environment: "production",
|
|
runtime: "browser",
|
|
sentry: destination.sink,
|
|
});
|
|
logger.info("Cache warmed", { sentry: true });
|
|
expect(destination.events).toHaveLength(1);
|
|
expect(destination.events[0]).toMatchObject({
|
|
level: "info",
|
|
arguments: ["Cache warmed"],
|
|
sendToSentryLogs: true,
|
|
sendToSentryIssue: false,
|
|
sendToConsole: false,
|
|
});
|
|
expect(consoleInfo).not.toHaveBeenCalled();
|
|
consoleInfo.mockRestore();
|
|
});
|
|
|
|
it("strips trailing call options from event arguments and supports data plus options", () => {
|
|
const destination = sink();
|
|
const logger = createLogger({
|
|
environment: "production",
|
|
runtime: "browser",
|
|
sentry: destination.sink,
|
|
});
|
|
logger.warn("slow", { ms: 1200 }, { sentry: true });
|
|
expect(destination.events[0]).toMatchObject({
|
|
level: "warn",
|
|
arguments: ["slow", { ms: 1200 }],
|
|
sendToSentryLogs: true,
|
|
sendToConsole: false,
|
|
});
|
|
});
|
|
|
|
it("suppresses Sentry Issues when suppressSentry is set", () => {
|
|
const destination = sink();
|
|
const logger = createLogger({
|
|
environment: "production",
|
|
runtime: "browser",
|
|
sentry: destination.sink,
|
|
});
|
|
logger.error("expected", new Error("nope"), { suppressSentry: true });
|
|
expect(destination.events).toHaveLength(1);
|
|
expect(destination.events[0]).toMatchObject({
|
|
sendToSentryIssue: false,
|
|
sendToSentryLogs: false,
|
|
arguments: ["expected", expect.any(Error)],
|
|
});
|
|
});
|
|
|
|
it("never marks events for Sentry in development", () => {
|
|
const destination = sink();
|
|
const logger = createLogger({
|
|
environment: "development",
|
|
sinks: [
|
|
destination.sink,
|
|
createSentrySink(
|
|
{
|
|
withScope: (callback) =>
|
|
callback({
|
|
setLevel: () => undefined,
|
|
setTag: () => undefined,
|
|
setExtras: () => undefined,
|
|
}),
|
|
captureException: vi.fn(),
|
|
captureMessage: vi.fn(),
|
|
logger: {
|
|
trace: vi.fn(),
|
|
debug: vi.fn(),
|
|
info: vi.fn(),
|
|
warn: vi.fn(),
|
|
error: vi.fn(),
|
|
},
|
|
},
|
|
{ logs: true },
|
|
),
|
|
],
|
|
});
|
|
logger.error("local only");
|
|
logger.info("probe", { sentry: true });
|
|
expect(destination.events).toHaveLength(2);
|
|
expect(
|
|
destination.events.every(
|
|
(event) => !event.sendToSentryIssue && !event.sendToSentryLogs,
|
|
),
|
|
).toBe(true);
|
|
});
|
|
|
|
it("keeps production Node errors on stderr as well as sending them to Sentry", () => {
|
|
const destination = sink();
|
|
const consoleError = vi.spyOn(console, "error").mockImplementation(() => undefined);
|
|
const logger = createLogger({
|
|
environment: "production",
|
|
runtime: "node",
|
|
sentry: destination.sink,
|
|
});
|
|
logger.error("captured");
|
|
expect(destination.events).toHaveLength(1);
|
|
expect(consoleError).toHaveBeenCalledTimes(1);
|
|
consoleError.mockRestore();
|
|
});
|
|
|
|
it("mirrors warn to Sentry Logs in production when logs are enabled on the sink", () => {
|
|
const destination = sink();
|
|
const logger = createLogger({
|
|
environment: "production",
|
|
runtime: "browser",
|
|
sinks: [
|
|
destination.sink,
|
|
createSentrySink(
|
|
{
|
|
withScope: () => undefined,
|
|
captureException: vi.fn(),
|
|
captureMessage: vi.fn(),
|
|
logger: {
|
|
trace: vi.fn(),
|
|
debug: vi.fn(),
|
|
info: vi.fn(),
|
|
warn: vi.fn(),
|
|
error: vi.fn(),
|
|
},
|
|
},
|
|
{ logs: true },
|
|
),
|
|
],
|
|
});
|
|
logger.warn("noisy");
|
|
logger.info("below default production logs threshold");
|
|
expect(destination.events).toHaveLength(1);
|
|
expect(destination.events[0]).toMatchObject({
|
|
level: "warn",
|
|
sendToSentryLogs: true,
|
|
sendToConsole: false,
|
|
});
|
|
});
|
|
|
|
it("mirrors info to Sentry Logs in staging when logs are enabled", () => {
|
|
const destination = sink();
|
|
const logger = createLogger({
|
|
environment: "staging",
|
|
runtime: "browser",
|
|
sinks: [
|
|
destination.sink,
|
|
createSentrySink(
|
|
{
|
|
withScope: () => undefined,
|
|
captureException: vi.fn(),
|
|
captureMessage: vi.fn(),
|
|
logger: {
|
|
trace: vi.fn(),
|
|
debug: vi.fn(),
|
|
info: vi.fn(),
|
|
warn: vi.fn(),
|
|
error: vi.fn(),
|
|
},
|
|
},
|
|
{ logs: true },
|
|
),
|
|
],
|
|
});
|
|
logger.info("visible in staging logs");
|
|
logger.debug("still below staging logs threshold");
|
|
expect(destination.events.map((event) => event.arguments[0])).toEqual([
|
|
"visible in staging logs",
|
|
]);
|
|
expect(destination.events[0]).toMatchObject({
|
|
sendToSentryLogs: true,
|
|
sendToConsole: false,
|
|
});
|
|
});
|
|
});
|