Skip to content
Closed
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
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ import { VatWorkerServiceCommandMethod } from '@ocap/kernel';
import type { PostMessageTarget } from '@ocap/streams/browser';
import { TestDuplexStream } from '@ocap/test-utils/streams';
import type { Logger } from '@ocap/utils';
import { delay, makeLogger } from '@ocap/utils';
import { delay, makeMockLogger } from '@ocap/utils';
import { describe, it, expect, beforeEach, vi } from 'vitest';

import type { VatWorkerClientStream } from './VatWorkerClient.ts';
Expand Down Expand Up @@ -97,7 +97,7 @@ describe('ExtensionVatWorkerClient', () => {

beforeEach(async () => {
stream = await TestDuplexStream.make(() => undefined);
clientLogger = makeLogger('[test client]');
clientLogger = makeMockLogger();
client = new ExtensionVatWorkerClient(
stream as unknown as VatWorkerClientStream,
clientLogger,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ import type { VatConfig, VatId, VatWorkerServiceCommand } from '@ocap/kernel';
import type { PostMessageTarget } from '@ocap/streams/browser';
import { TestDuplexStream } from '@ocap/test-utils/streams';
import type { Logger } from '@ocap/utils';
import { delay, makeLogger } from '@ocap/utils';
import { delay, makeMockLogger } from '@ocap/utils';
import { describe, it, expect, beforeEach, vi, afterEach } from 'vitest';
import type { Mock } from 'vitest';

Expand Down Expand Up @@ -121,7 +121,7 @@ describe('ExtensionVatWorkerServer', () => {

beforeEach(async () => {
workers = [];
logger = makeLogger('[test server]');
logger = makeMockLogger();
stream = await TestDuplexStream.make(() => undefined);
server = new ExtensionVatWorkerServer(
stream as unknown as VatWorkerServerStream,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,15 @@ import { describe, it, expect, vi, beforeEach } from 'vitest';

import { loggingMiddleware, logger } from './logging.ts';

// Replace the imported logger with a test logger we can spy on
vi.mock(
'@ocap/utils',
async (importOriginal: () => Promise<{ makeMockLogger: () => unknown }>) => {
const { makeMockLogger } = await importOriginal();
return { makeLogger: makeMockLogger };
},
);

describe('loggingMiddleware', () => {
let engine: JsonRpcEngine;

Expand Down
4 changes: 2 additions & 2 deletions packages/kernel/src/VatHandle.test.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
import { delay } from '@ocap/test-utils';
import { TestDuplexStream } from '@ocap/test-utils/streams';
import type { Logger } from '@ocap/utils';
import { makeLogger } from '@ocap/utils';
import { makeMockLogger } from '@ocap/utils';
import { describe, it, expect, vi, beforeEach } from 'vitest';
import type { MockInstance } from 'vitest';

Expand Down Expand Up @@ -75,7 +75,7 @@ describe('VatHandle', () => {
});

it('throws if the stream throws', async () => {
const logger = makeLogger(`[vat v0]`);
const logger = makeMockLogger();
const { stream } = await makeVat(logger);
const logErrorSpy = vi.spyOn(logger, 'error');
await stream.receiveInput(NaN);
Expand Down
2 changes: 1 addition & 1 deletion packages/utils/src/index.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
export type { Logger } from './logger.ts';
export { makeLogger } from './logger.ts';
export { makeLogger, makeMockLogger } from './logger.ts';
export { delay, makeCounter } from './misc.ts';
export { stringify } from './stringify.ts';
export type { ExtractGuardType, PromiseCallbacks, TypeGuard } from './types.ts';
Expand Down
61 changes: 60 additions & 1 deletion packages/utils/src/logger.test.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
import { describe, it, expect, vi } from 'vitest';

import { makeLogger } from './logger.ts';
import { DEFAULT_LEVEL, makeLogger, makeMockLogger } from './logger.ts';
import type { Logger, LoggerContext } from './logger.ts';

describe('makeLogger', () => {
const consoleMethod = ['log', 'debug', 'info', 'warn', 'error'] as const;
Expand Down Expand Up @@ -48,4 +49,62 @@ describe('makeLogger', () => {
subLogger.log('foo');
expect(consoleSpy).toHaveBeenCalledWith('[vat 0x01]', '(process)', 'foo');
});

it('uses the provided transports', () => {
const noOpTransport = vi.fn();
const testLogger = makeLogger('test', console, [noOpTransport]);
testLogger.log('foo');
expect(noOpTransport).toHaveBeenCalledWith(
{ level: 'log', tags: ['test'] },
'foo',
);
});

it('logs transport errors to console.error', () => {
const consoleErrorSpy = vi.spyOn(console, 'error');
const error = new Error('transport error');
const errorTransport = vi.fn().mockImplementation(() => {
throw error;
});
const testLogger = makeLogger('test', console, [errorTransport]);
testLogger.log('foo');
expect(consoleErrorSpy).toHaveBeenCalledWith(
expect.stringMatching(/dispatch failed/u),
error,
);
});

type TestLogger = Logger & {
dispatch: (context: LoggerContext, ...args: unknown[]) => void;
};

it('does not output to console when silent', () => {
const consoleMethodSpys = consoleMethod.map((method) =>
vi.spyOn(console, method),
);
const testLogger = makeLogger('test') as TestLogger;
testLogger.dispatch({ level: 'silent' }, 'foo');
for (const spy of consoleMethodSpys) {
expect(spy.mock.calls).toHaveLength(0);
}
});

it(`logs to ${DEFAULT_LEVEL} by default`, () => {
const consoleMethodSpy = vi.spyOn(console, DEFAULT_LEVEL as keyof Console);
const testLogger = makeLogger('test') as TestLogger;
testLogger.dispatch({ tags: ['test'] }, 'foo');
expect(consoleMethodSpy).toHaveBeenCalledWith('test', 'foo');
});
});

describe('makeMockLogger', () => {
it('returns a mock logger with the expected methods', () => {
const mockLogger = makeMockLogger();
expect(mockLogger).toBeDefined();
expect(mockLogger.log).toBeDefined();
expect(mockLogger.debug).toBeDefined();
expect(mockLogger.info).toBeDefined();
expect(mockLogger.warn).toBeDefined();
expect(mockLogger.error).toBeDefined();
});
});
112 changes: 84 additions & 28 deletions packages/utils/src/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,45 +3,101 @@
*/
const consoleMethods = ['log', 'debug', 'info', 'warn', 'error'] as const;

export type Logger<Label extends string = string> = {
label: Label;
} & Console;
export type Logger = Console & { tags?: string[] };

type LoggerMethod = keyof Console & (typeof consoleMethods)[number];
export type LogLevel = (typeof consoleMethods)[number] | 'silent';

export const DEFAULT_LEVEL: LogLevel = 'info';

export type LoggerContext = {
level?: LogLevel;
tags?: string[];
};

export type Transport = (context: LoggerContext, ...args: unknown[]) => void;

const consoleTransport: Transport = (context, ...args) => {
const method = {
log: console.log,
debug: console.debug,
info: console.info,
warn: console.warn,
error: console.error,
silent: () => undefined,
}[context.level ?? DEFAULT_LEVEL];
method(...[...(context.tags ?? []), ...args]);
};

/**
* Make a proxy console which prepends the given label to its outputs.
*
* @param label - The label with which to prefix console outputs.
* @param baseConsole - The base console to log to.
* @param transports - A list of methods which deliver the logs to storage, terminal, etc.
* @returns A console prefixed with the given label.
*/
export const makeLogger = <Label extends string>(
label: Label,
baseConsole: Console = console,
): Logger<Label> => {
/**
* Prepends the label to the beginning of the args of the baseConsole method.
*
* @param methodName - The method to prefix.
* @returns The modified method.
*/
const prefixed = (
methodName: LoggerMethod,
): [LoggerMethod, Console[typeof methodName]] => {
const method: Console[typeof methodName] = baseConsole[methodName];
return [
methodName,
((message?: unknown, ...optionalParams: unknown[]) =>
method(
label,
...(message ? [message, ...optionalParams] : optionalParams),
)) as Console[typeof methodName],
];
baseConsole: Logger = console,
transports: Transport[] = [],
): Logger => {
const dispatch = (context: LoggerContext, ...args: unknown[]): void => {
const errors = [consoleTransport, ...transports]
.map((transport) => {
try {
transport(context, ...args);
return undefined;
} catch (error) {
return error;
}
})
.filter(Boolean);
if (errors.length > 0) {
console.error('logging dispatch failed:', ...errors);
}
};

const isLogLevel = (method: string): method is LogLevel => {
return ['silent', ...consoleMethods].includes(method as LogLevel);
};

return {
label,
...Object.fromEntries(consoleMethods.map(prefixed)),
} as Logger<Label>;
const tags = [...(baseConsole.tags ?? []), label];

return new Proxy(
{ ...baseConsole },
{
get(_target, prop: string, _receiver) {
if (prop === 'dispatch') {
return dispatch;
}
if (prop === 'tags') {
return tags;
}
if (isLogLevel(prop)) {
return (...args: unknown[]) =>
dispatch({ tags, level: prop }, ...args);
}
Comment on lines +76 to +79
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is probably better to store and reference these aliases instead of creating a new arrow function with every access.

return baseConsole[prop as keyof typeof baseConsole];
},
},
);
};

/**
* Creates a test logger with stable method references that tests can easily spy on.
* All logger methods are implemented as no-ops but have stable references for spying.
*
* @returns A Logger instance with stable method references
*/
export const makeMockLogger = (): Logger => {
const logger: Record<string, unknown> = {};

// Create stable method references for all console methods
consoleMethods.forEach((method) => {
logger[method] = (..._args: unknown[]): void => {
// No-op implementation
};
});

return logger as unknown as Logger;
};
Loading