mirror of
https://github.com/misskey-dev/misskey.git
synced 2026-07-25 07:25:04 +02:00
enhance: 新しいLoggerのコア実装 (#17714)
* enhance: impl logger core * fix order
This commit is contained in:
@@ -3,80 +3,59 @@
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import cluster from 'node:cluster';
|
||||
import chalk from 'chalk';
|
||||
import { default as convertColor } from 'color-convert';
|
||||
import { format as dateFormat } from 'date-fns';
|
||||
import { bindThis } from '@/decorators.js';
|
||||
import { envOption } from './env.js';
|
||||
import { logManager } from './logging/logging-runtime.js';
|
||||
import type { LogLevel, LoggerContext } from './logging/types.js';
|
||||
import type { Keyword } from 'color-convert';
|
||||
|
||||
type Context = {
|
||||
name: string;
|
||||
color?: Keyword;
|
||||
};
|
||||
|
||||
type Level = 'error' | 'success' | 'warning' | 'debug' | 'info';
|
||||
|
||||
/**
|
||||
* ロガー名の階層と従来の公開APIを提供する薄い窓口です。
|
||||
* 出力条件の判断や整形はLogManagerとLogBackendへ委譲します。
|
||||
*/
|
||||
// eslint-disable-next-line import/no-default-export
|
||||
export default class Logger {
|
||||
private context: Context;
|
||||
private parentLogger: Logger | null = null;
|
||||
private context: readonly LoggerContext[];
|
||||
|
||||
/** 指定した名前を起点とするLoggerを作成します。 */
|
||||
constructor(context: string, color?: Keyword) {
|
||||
this.context = {
|
||||
this.context = [{
|
||||
name: context,
|
||||
color: color,
|
||||
};
|
||||
color,
|
||||
}];
|
||||
}
|
||||
|
||||
/**
|
||||
* 現在のロガーを親として、下位の名前を持つLoggerを作成します。
|
||||
*/
|
||||
@bindThis
|
||||
public createSubLogger(context: string, color?: Keyword): Logger {
|
||||
const logger = new Logger(context, color);
|
||||
logger.parentLogger = this;
|
||||
logger.context = [...this.context, ...logger.context];
|
||||
return logger;
|
||||
}
|
||||
|
||||
/**
|
||||
* 従来APIの引数を共通形式へ変換し、LogManagerへ渡します。
|
||||
*/
|
||||
@bindThis
|
||||
private log(level: Level, message: string, data?: Record<string, any> | null, important = false, subContexts: Context[] = []): void {
|
||||
if (envOption.quiet) return;
|
||||
|
||||
if (this.parentLogger) {
|
||||
this.parentLogger.log(level, message, data, important, [this.context].concat(subContexts));
|
||||
return;
|
||||
}
|
||||
|
||||
const time = dateFormat(new Date(), 'HH:mm:ss');
|
||||
const worker = cluster.isPrimary ? '*' : cluster.worker!.id;
|
||||
const l =
|
||||
level === 'error' ? important ? chalk.bgRed.white('ERR ') : chalk.red('ERR ') :
|
||||
level === 'warning' ? chalk.yellow('WARN') :
|
||||
level === 'success' ? important ? chalk.bgGreen.white('DONE') : chalk.green('DONE') :
|
||||
level === 'debug' ? chalk.gray('VERB') :
|
||||
level === 'info' ? chalk.blue('INFO') :
|
||||
null;
|
||||
const contexts = [this.context].concat(subContexts).map(d => d.color ? chalk.rgb(...convertColor.keyword.rgb(d.color))(d.name) : chalk.white(d.name));
|
||||
const m =
|
||||
level === 'error' ? chalk.red(message) :
|
||||
level === 'warning' ? chalk.yellow(message) :
|
||||
level === 'success' ? chalk.green(message) :
|
||||
level === 'debug' ? chalk.gray(message) :
|
||||
level === 'info' ? message :
|
||||
null;
|
||||
|
||||
let log = `${l} ${worker}\t[${contexts.join(' ')}]\t${m}`;
|
||||
if (envOption.withLogTime) log = chalk.gray(time) + ' ' + log;
|
||||
|
||||
const args: unknown[] = [important ? chalk.bold(log) : log];
|
||||
if (data != null) {
|
||||
args.push(data);
|
||||
}
|
||||
console.log(...args);
|
||||
private log(level: LogLevel, message: string, data?: Record<string, any> | null, important = false, legacyLevel?: 'success'): void {
|
||||
logManager.write({
|
||||
level,
|
||||
message,
|
||||
context: this.context,
|
||||
compatibility: {
|
||||
legacyLevel,
|
||||
important,
|
||||
data,
|
||||
},
|
||||
});
|
||||
}
|
||||
|
||||
/** 処理を継続できない状況を記録します。 */
|
||||
@bindThis
|
||||
public error(x: string | Error, data?: Record<string, any> | null, important = false): void { // 実行を継続できない状況で使う
|
||||
public error(x: string | Error, data?: Record<string, any> | null, important = false): void {
|
||||
if (x instanceof Error) {
|
||||
// Error本体も第2引数へ残し、従来どおりスタックなどを確認できるようにします。
|
||||
data = data ?? {};
|
||||
data.e = x;
|
||||
this.log('error', x.toString(), data, important);
|
||||
@@ -87,25 +66,27 @@ export default class Logger {
|
||||
}
|
||||
}
|
||||
|
||||
/** 処理は継続できるものの、改善が必要な状況を記録します。 */
|
||||
@bindThis
|
||||
public warn(message: string, data?: Record<string, any> | null, important = false): void { // 実行を継続できるが改善すべき状況で使う
|
||||
this.log('warning', message, data, important);
|
||||
public warn(message: string, data?: Record<string, any> | null, important = false): void {
|
||||
this.log('warn', message, data, important);
|
||||
}
|
||||
|
||||
/** 処理が成功したことを、従来のDONE表示で記録します。 */
|
||||
@bindThis
|
||||
public succ(message: string, data?: Record<string, any> | null, important = false): void { // 何かに成功した状況で使う
|
||||
this.log('success', message, data, important);
|
||||
public succ(message: string, data?: Record<string, any> | null, important = false): void {
|
||||
this.log('info', message, data, important, 'success');
|
||||
}
|
||||
|
||||
/** 開発者向けの調査情報を記録します。 */
|
||||
@bindThis
|
||||
public debug(message: string, data?: Record<string, any> | null, important = false): void { // デバッグ用に使う(開発者に必要だが利用者に不要な情報)
|
||||
if (process.env.NODE_ENV !== 'production' || envOption.verbose) {
|
||||
this.log('debug', message, data, important);
|
||||
}
|
||||
public debug(message: string, data?: Record<string, any> | null, important = false): void {
|
||||
this.log('debug', message, data, important);
|
||||
}
|
||||
|
||||
/** 通常の動作状況を記録します。 */
|
||||
@bindThis
|
||||
public info(message: string, data?: Record<string, any> | null, important = false): void { // それ以外
|
||||
public info(message: string, data?: Record<string, any> | null, important = false): void {
|
||||
this.log('info', message, data, important);
|
||||
}
|
||||
}
|
||||
|
||||
21
packages/backend/src/logging/LogBackend.ts
Normal file
21
packages/backend/src/logging/LogBackend.ts
Normal file
@@ -0,0 +1,21 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import type { LogRecord } from './types.js';
|
||||
|
||||
/**
|
||||
* 整形済みのログを実際の出力先へ渡すための共通窓口です。
|
||||
* Loggerを特定の出力形式へ依存させず、後から出力先を追加できるようにします。
|
||||
*/
|
||||
export interface LogBackend {
|
||||
/** ログを一件出力します。 */
|
||||
write(record: LogRecord): void;
|
||||
|
||||
/** 保留中の出力がある場合に、すべて書き出します。 */
|
||||
flush?(): void | Promise<void>;
|
||||
|
||||
/** 出力先が持つ資源を解放します。 */
|
||||
close?(): void | Promise<void>;
|
||||
}
|
||||
94
packages/backend/src/logging/LogManager.ts
Normal file
94
packages/backend/src/logging/LogManager.ts
Normal file
@@ -0,0 +1,94 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import cluster from 'node:cluster';
|
||||
import process from 'node:process';
|
||||
import { envOption } from '@/env.js';
|
||||
import type { LogBackend } from './LogBackend.js';
|
||||
import type { LogRecordInput } from './types.js';
|
||||
|
||||
/** ログを出力したプロセスを識別するための情報です。 */
|
||||
export type LogProcessInfo = {
|
||||
readonly processId: number;
|
||||
readonly isPrimary: boolean;
|
||||
readonly workerId: number | null;
|
||||
};
|
||||
|
||||
/**
|
||||
* 実行環境から取得する値をまとめた依存関係です。
|
||||
* テストでは固定値へ差し替え、時刻やプロセス状態に左右されないようにします。
|
||||
*/
|
||||
export type LogManagerDependencies = {
|
||||
readonly now: () => Date;
|
||||
readonly getProcessInfo: () => LogProcessInfo;
|
||||
readonly isQuiet: () => boolean;
|
||||
readonly isVerbose: () => boolean;
|
||||
readonly getNodeEnv: () => string | undefined;
|
||||
};
|
||||
|
||||
const defaultDependencies: LogManagerDependencies = {
|
||||
now: () => new Date(),
|
||||
getProcessInfo: () => ({
|
||||
processId: process.pid,
|
||||
isPrimary: cluster.isPrimary,
|
||||
workerId: cluster.isPrimary ? null : (cluster.worker?.id ?? null),
|
||||
}),
|
||||
isQuiet: () => envOption.quiet,
|
||||
isVerbose: () => envOption.verbose,
|
||||
getNodeEnv: () => process.env.NODE_ENV,
|
||||
};
|
||||
|
||||
/**
|
||||
* ログの出力可否を判断し、すべての出力先で共通となる情報を付加します。
|
||||
* Loggerと出力先の間に置くことで、設定や共通情報の扱いを一か所へ集約します。
|
||||
*/
|
||||
export class LogManager {
|
||||
private backend: LogBackend;
|
||||
private readonly dependencies: LogManagerDependencies;
|
||||
|
||||
/**
|
||||
* 出力先と実行環境から値を取得する処理を受け取ります。
|
||||
* 実行環境の取得処理は、必要な項目だけテスト用に差し替えられます。
|
||||
*/
|
||||
constructor(backend: LogBackend, dependencies: Partial<LogManagerDependencies> = {}) {
|
||||
this.backend = backend;
|
||||
this.dependencies = {
|
||||
...defaultDependencies,
|
||||
...dependencies,
|
||||
};
|
||||
}
|
||||
|
||||
/**
|
||||
* 以後のログを書き込む出力先を切り替えます。
|
||||
* 作成済みのLoggerにも切り替えを反映するため、LogManager側で保持します。
|
||||
*/
|
||||
public setBackend(backend: LogBackend): void {
|
||||
this.backend = backend;
|
||||
}
|
||||
|
||||
/**
|
||||
* 出力条件を確認し、共通情報を付加して出力先へ渡します。
|
||||
*/
|
||||
public write(input: LogRecordInput): void {
|
||||
// `quiet`は他の条件より優先し、ログに付随する情報の取得も行いません。
|
||||
if (this.dependencies.isQuiet()) return;
|
||||
|
||||
// 本番環境のデバッグログは、明示的に`verbose`が指定された場合だけ出力します。
|
||||
if (input.level === 'debug' && this.dependencies.getNodeEnv() === 'production' && !this.dependencies.isVerbose()) return;
|
||||
|
||||
const processInfo = this.dependencies.getProcessInfo();
|
||||
// 呼び出し側の配列を共有せず、親から末端までの順序を固定します。
|
||||
const context = [...input.context];
|
||||
this.backend.write({
|
||||
...input,
|
||||
context,
|
||||
timestamp: this.dependencies.now().toISOString(),
|
||||
loggerName: context.map(segment => segment.name).join('.'),
|
||||
processId: processInfo.processId,
|
||||
isPrimary: processInfo.isPrimary,
|
||||
workerId: processInfo.workerId,
|
||||
});
|
||||
}
|
||||
}
|
||||
82
packages/backend/src/logging/PrettyConsoleBackend.ts
Normal file
82
packages/backend/src/logging/PrettyConsoleBackend.ts
Normal file
@@ -0,0 +1,82 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import chalk from 'chalk';
|
||||
import { default as convertColor } from 'color-convert';
|
||||
import { format as dateFormat } from 'date-fns';
|
||||
import { envOption } from '@/env.js';
|
||||
import type { LogBackend } from './LogBackend.js';
|
||||
import type { LogRecord } from './types.js';
|
||||
|
||||
/** Pretty形式の出力処理が外部から受け取る依存関係です。 */
|
||||
export type PrettyConsoleBackendDependencies = {
|
||||
readonly output: (...args: unknown[]) => void;
|
||||
readonly withLogTime: () => boolean;
|
||||
};
|
||||
|
||||
const defaultDependencies: PrettyConsoleBackendDependencies = {
|
||||
output: (...args) => console.log(...args),
|
||||
withLogTime: () => envOption.withLogTime,
|
||||
};
|
||||
|
||||
/**
|
||||
* 人が読みやすい従来形式へ整形し、コンソールへ出力します。
|
||||
* 色、ラベル、時刻などの見た目だけを担当し、出力可否はLogManagerへ任せます。
|
||||
*/
|
||||
export class PrettyConsoleBackend implements LogBackend {
|
||||
private readonly dependencies: PrettyConsoleBackendDependencies;
|
||||
|
||||
/**
|
||||
* 出力処理と時刻表示の判定処理を受け取ります。
|
||||
* 省略時は従来どおり、標準のコンソールと環境設定を使用します。
|
||||
*/
|
||||
constructor(dependencies: Partial<PrettyConsoleBackendDependencies> = {}) {
|
||||
this.dependencies = {
|
||||
...defaultDependencies,
|
||||
...dependencies,
|
||||
};
|
||||
}
|
||||
|
||||
/**
|
||||
* 共通のログを従来形式へ整形して一件出力します。
|
||||
*/
|
||||
public write(record: LogRecord): void {
|
||||
const legacyLevel = record.compatibility?.legacyLevel;
|
||||
// `fatal`は重大なエラーとして扱い、従来の`important`と同じ強調表示にします。
|
||||
const important = record.level === 'fatal' || (record.compatibility?.important ?? false);
|
||||
const presentationLevel = record.level === 'fatal' ? 'error' : (legacyLevel ?? record.level);
|
||||
const label =
|
||||
presentationLevel === 'error' ? important ? chalk.bgRed.white('ERR ') : chalk.red('ERR ') :
|
||||
presentationLevel === 'warn' ? chalk.yellow('WARN') :
|
||||
presentationLevel === 'success' ? important ? chalk.bgGreen.white('DONE') : chalk.green('DONE') :
|
||||
presentationLevel === 'debug' ? chalk.gray('VERB') :
|
||||
presentationLevel === 'info' ? chalk.blue('INFO') :
|
||||
null;
|
||||
const contexts = record.context.map(context => context.color
|
||||
? chalk.rgb(...convertColor.keyword.rgb(context.color))(context.name)
|
||||
: chalk.white(context.name));
|
||||
const message =
|
||||
presentationLevel === 'error' ? chalk.red(record.message) :
|
||||
presentationLevel === 'warn' ? chalk.yellow(record.message) :
|
||||
presentationLevel === 'success' ? chalk.green(record.message) :
|
||||
presentationLevel === 'debug' ? chalk.gray(record.message) :
|
||||
presentationLevel === 'info' ? record.message :
|
||||
null;
|
||||
// 主プロセスは従来どおり「*」、子プロセスはワーカー番号で識別します。
|
||||
const worker = record.isPrimary ? '*' : record.workerId;
|
||||
|
||||
let log = `${label} ${worker}\t[${contexts.join(' ')}]\t${message}`;
|
||||
if (this.dependencies.withLogTime()) {
|
||||
log = chalk.gray(dateFormat(new Date(record.timestamp), 'HH:mm:ss')) + ' ' + log;
|
||||
}
|
||||
|
||||
// `data`は文字列へ埋め込まず、第2引数として渡す従来の挙動を維持します。
|
||||
const args: unknown[] = [important ? chalk.bold(log) : log];
|
||||
if (record.compatibility?.data != null) {
|
||||
args.push(record.compatibility.data);
|
||||
}
|
||||
this.dependencies.output(...args);
|
||||
}
|
||||
}
|
||||
13
packages/backend/src/logging/logging-runtime.ts
Normal file
13
packages/backend/src/logging/logging-runtime.ts
Normal file
@@ -0,0 +1,13 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import { LogManager } from './LogManager.js';
|
||||
import { PrettyConsoleBackend } from './PrettyConsoleBackend.js';
|
||||
|
||||
/**
|
||||
* プロセス内のすべてのLoggerが共有するLogManagerです。
|
||||
* Logger作成後も同じLogManagerを参照するため、出力先の切り替えを一括で反映できます。
|
||||
*/
|
||||
export const logManager = new LogManager(new PrettyConsoleBackend());
|
||||
50
packages/backend/src/logging/types.ts
Normal file
50
packages/backend/src/logging/types.ts
Normal file
@@ -0,0 +1,50 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import type { Keyword } from 'color-convert';
|
||||
|
||||
/** ログの重要度を表します。 */
|
||||
export type LogLevel = 'debug' | 'info' | 'warn' | 'error' | 'fatal';
|
||||
|
||||
/**
|
||||
* ロガー名を構成する一要素です。
|
||||
* 色はPretty形式での表示だけに使い、ログの意味には影響させません。
|
||||
*/
|
||||
export type LoggerContext = {
|
||||
readonly name: string;
|
||||
readonly color?: Keyword;
|
||||
};
|
||||
|
||||
/**
|
||||
* 従来のコンソール表示を維持するための情報です。
|
||||
* 構造化ログの項目と混同しないよう、互換用の領域へ分離しています。
|
||||
*/
|
||||
export type LogCompatibility = {
|
||||
readonly legacyLevel?: 'success';
|
||||
readonly important?: boolean;
|
||||
readonly data?: Record<string, unknown> | null;
|
||||
};
|
||||
|
||||
/**
|
||||
* 呼び出し側からLogManagerへ渡す、時刻などを付加する前のログです。
|
||||
*/
|
||||
export type LogRecordInput = {
|
||||
readonly level: LogLevel;
|
||||
readonly message: string;
|
||||
readonly context: readonly LoggerContext[];
|
||||
readonly compatibility?: LogCompatibility;
|
||||
};
|
||||
|
||||
/**
|
||||
* 出力先へ渡すログです。
|
||||
* LogManagerが時刻やプロセス情報を付加するため、出力形式に依存せず利用できます。
|
||||
*/
|
||||
export type LogRecord = LogRecordInput & {
|
||||
readonly timestamp: string;
|
||||
readonly loggerName: string;
|
||||
readonly processId: number;
|
||||
readonly isPrimary: boolean;
|
||||
readonly workerId: number | null;
|
||||
};
|
||||
125
packages/backend/test/unit/logging/LogManager.ts
Normal file
125
packages/backend/test/unit/logging/LogManager.ts
Normal file
@@ -0,0 +1,125 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import { describe, expect, test, vi } from 'vitest';
|
||||
import { LogManager } from '@/logging/LogManager.js';
|
||||
import type { LogBackend } from '@/logging/LogBackend.js';
|
||||
import type { LogRecordInput } from '@/logging/types.js';
|
||||
|
||||
/** テストで使う最小構成のログ入力を作成します。 */
|
||||
function createInput(level: LogRecordInput['level'] = 'info'): LogRecordInput {
|
||||
return {
|
||||
level,
|
||||
message: 'message',
|
||||
context: [
|
||||
{ name: 'queue', color: 'red' },
|
||||
{ name: 'deliver', color: 'blue' },
|
||||
],
|
||||
};
|
||||
}
|
||||
|
||||
/** 実行環境を固定したLogManagerと、出力確認用の関数を作成します。 */
|
||||
function createManager(options: {
|
||||
quiet?: boolean;
|
||||
verbose?: boolean;
|
||||
nodeEnv?: string;
|
||||
isPrimary?: boolean;
|
||||
workerId?: number | null;
|
||||
} = {}) {
|
||||
const write = vi.fn<LogBackend['write']>();
|
||||
const manager = new LogManager({ write }, {
|
||||
now: () => new Date('2025-01-02T03:04:05.678Z'),
|
||||
getProcessInfo: () => ({
|
||||
processId: 1234,
|
||||
isPrimary: options.isPrimary ?? true,
|
||||
workerId: options.workerId ?? null,
|
||||
}),
|
||||
isQuiet: () => options.quiet ?? false,
|
||||
isVerbose: () => options.verbose ?? false,
|
||||
getNodeEnv: () => options.nodeEnv ?? 'development',
|
||||
});
|
||||
|
||||
return { manager, write };
|
||||
}
|
||||
|
||||
describe('LogManager', () => {
|
||||
test('adds logger and process metadata while preserving root-to-leaf context order', () => {
|
||||
const { manager, write } = createManager();
|
||||
const input = createInput();
|
||||
|
||||
manager.write(input);
|
||||
|
||||
expect(write).toHaveBeenCalledOnce();
|
||||
expect(write).toHaveBeenCalledWith({
|
||||
...input,
|
||||
context: [
|
||||
{ name: 'queue', color: 'red' },
|
||||
{ name: 'deliver', color: 'blue' },
|
||||
],
|
||||
timestamp: '2025-01-02T03:04:05.678Z',
|
||||
loggerName: 'queue.deliver',
|
||||
processId: 1234,
|
||||
isPrimary: true,
|
||||
workerId: null,
|
||||
});
|
||||
expect(write.mock.calls[0][0].context).not.toBe(input.context);
|
||||
});
|
||||
|
||||
test('records worker process metadata', () => {
|
||||
const { manager, write } = createManager({ isPrimary: false, workerId: 7 });
|
||||
|
||||
manager.write(createInput());
|
||||
|
||||
expect(write.mock.calls[0][0]).toMatchObject({
|
||||
processId: 1234,
|
||||
isPrimary: false,
|
||||
workerId: 7,
|
||||
});
|
||||
});
|
||||
|
||||
test('does not call the backend in quiet mode', () => {
|
||||
const { manager, write } = createManager({ quiet: true, verbose: true });
|
||||
|
||||
manager.write(createInput('fatal'));
|
||||
manager.write(createInput('debug'));
|
||||
|
||||
expect(write).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
test('writes debug logs outside production', () => {
|
||||
const { manager, write } = createManager({ nodeEnv: 'development' });
|
||||
|
||||
manager.write(createInput('debug'));
|
||||
|
||||
expect(write).toHaveBeenCalledOnce();
|
||||
});
|
||||
|
||||
test('suppresses debug logs in production by default', () => {
|
||||
const { manager, write } = createManager({ nodeEnv: 'production' });
|
||||
|
||||
manager.write(createInput('debug'));
|
||||
|
||||
expect(write).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
test('writes debug logs in verbose production mode', () => {
|
||||
const { manager, write } = createManager({ nodeEnv: 'production', verbose: true });
|
||||
|
||||
manager.write(createInput('debug'));
|
||||
|
||||
expect(write).toHaveBeenCalledOnce();
|
||||
});
|
||||
|
||||
test('uses a replaced backend for subsequent records', () => {
|
||||
const { manager, write } = createManager();
|
||||
const replacementWrite = vi.fn<LogBackend['write']>();
|
||||
|
||||
manager.setBackend({ write: replacementWrite });
|
||||
manager.write(createInput());
|
||||
|
||||
expect(write).not.toHaveBeenCalled();
|
||||
expect(replacementWrite).toHaveBeenCalledOnce();
|
||||
});
|
||||
});
|
||||
103
packages/backend/test/unit/logging/Logger.ts
Normal file
103
packages/backend/test/unit/logging/Logger.ts
Normal file
@@ -0,0 +1,103 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import { beforeEach, describe, expect, test, vi } from 'vitest';
|
||||
import type { LogRecordInput } from '@/logging/types.js';
|
||||
|
||||
const mocks = vi.hoisted(() => ({
|
||||
write: vi.fn<(input: LogRecordInput) => void>(),
|
||||
}));
|
||||
|
||||
vi.mock('@/logging/logging-runtime.js', () => ({
|
||||
logManager: {
|
||||
write: mocks.write,
|
||||
},
|
||||
}));
|
||||
|
||||
import Logger from '@/logger.js';
|
||||
|
||||
describe('Logger', () => {
|
||||
beforeEach(() => {
|
||||
mocks.write.mockReset();
|
||||
});
|
||||
|
||||
test('passes immutable multi-level root-to-leaf context to the manager', () => {
|
||||
const root = new Logger('root', 'red');
|
||||
const child = root.createSubLogger('child', 'green');
|
||||
const leaf = child.createSubLogger('leaf', 'blue');
|
||||
|
||||
leaf.info('from leaf');
|
||||
root.info('from root');
|
||||
|
||||
expect(mocks.write.mock.calls[0][0]).toMatchObject({
|
||||
level: 'info',
|
||||
message: 'from leaf',
|
||||
context: [
|
||||
{ name: 'root', color: 'red' },
|
||||
{ name: 'child', color: 'green' },
|
||||
{ name: 'leaf', color: 'blue' },
|
||||
],
|
||||
});
|
||||
expect(mocks.write.mock.calls[1][0].context).toEqual([
|
||||
{ name: 'root', color: 'red' },
|
||||
]);
|
||||
});
|
||||
|
||||
test('maps succ to info with the legacy success presentation', () => {
|
||||
new Logger('root').succ('completed', { count: 1 }, true);
|
||||
|
||||
expect(mocks.write).toHaveBeenCalledWith({
|
||||
level: 'info',
|
||||
message: 'completed',
|
||||
context: [{ name: 'root', color: undefined }],
|
||||
compatibility: {
|
||||
legacyLevel: 'success',
|
||||
important: true,
|
||||
data: { count: 1 },
|
||||
},
|
||||
});
|
||||
});
|
||||
|
||||
test('uses Error.toString and adds the Error to existing data', () => {
|
||||
const logger = new Logger('root');
|
||||
const error = new TypeError('broken');
|
||||
const data: Record<string, unknown> = { requestId: 'request' };
|
||||
|
||||
logger.error(error, data, true);
|
||||
|
||||
expect(data).toEqual({ requestId: 'request', e: error });
|
||||
expect(mocks.write).toHaveBeenCalledWith({
|
||||
level: 'error',
|
||||
message: 'TypeError: broken',
|
||||
context: [{ name: 'root', color: undefined }],
|
||||
compatibility: {
|
||||
legacyLevel: undefined,
|
||||
important: true,
|
||||
data,
|
||||
},
|
||||
});
|
||||
});
|
||||
|
||||
test('creates data containing the Error when none is supplied', () => {
|
||||
const error = new Error('broken');
|
||||
|
||||
new Logger('root').error(error);
|
||||
|
||||
expect(mocks.write.mock.calls[0][0].compatibility?.data).toEqual({ e: error });
|
||||
});
|
||||
|
||||
test('keeps public methods bound when called separately', () => {
|
||||
const logger = new Logger('root');
|
||||
const info = logger.info;
|
||||
|
||||
info('bound');
|
||||
|
||||
expect(mocks.write).toHaveBeenCalledWith(expect.objectContaining({
|
||||
level: 'info',
|
||||
message: 'bound',
|
||||
context: [{ name: 'root', color: undefined }],
|
||||
}));
|
||||
});
|
||||
});
|
||||
147
packages/backend/test/unit/logging/PrettyConsoleBackend.ts
Normal file
147
packages/backend/test/unit/logging/PrettyConsoleBackend.ts
Normal file
@@ -0,0 +1,147 @@
|
||||
/*
|
||||
* SPDX-FileCopyrightText: syuilo and misskey-project
|
||||
* SPDX-License-Identifier: AGPL-3.0-only
|
||||
*/
|
||||
|
||||
import { describe, expect, test, vi } from 'vitest';
|
||||
import type { LogRecord } from '@/logging/types.js';
|
||||
|
||||
type Formatter = ((value: unknown) => string) & { white?: Formatter };
|
||||
|
||||
const chalkMock = vi.hoisted(() => {
|
||||
const format = (name: string): Formatter => (value: unknown) => `<${name}>${String(value)}</${name}>`;
|
||||
const bgRed = format('bgRed');
|
||||
bgRed.white = format('bgRed.white');
|
||||
const bgGreen = format('bgGreen');
|
||||
bgGreen.white = format('bgGreen.white');
|
||||
|
||||
return {
|
||||
red: format('red'),
|
||||
yellow: format('yellow'),
|
||||
green: format('green'),
|
||||
gray: format('gray'),
|
||||
blue: format('blue'),
|
||||
white: format('white'),
|
||||
bold: format('bold'),
|
||||
bgRed,
|
||||
bgGreen,
|
||||
rgb: (red: number, green: number, blue: number) => format(`rgb:${red},${green},${blue}`),
|
||||
};
|
||||
});
|
||||
|
||||
vi.mock('chalk', () => ({
|
||||
default: chalkMock,
|
||||
}));
|
||||
|
||||
import { PrettyConsoleBackend } from '@/logging/PrettyConsoleBackend.js';
|
||||
|
||||
/** Pretty形式のテストで使う共通のログを作成します。 */
|
||||
function createRecord(overrides: Partial<LogRecord> = {}): LogRecord {
|
||||
return {
|
||||
level: 'info',
|
||||
message: 'message',
|
||||
context: [{ name: 'root' }],
|
||||
timestamp: '2025-01-02T03:04:05.678Z',
|
||||
loggerName: 'root',
|
||||
processId: 1234,
|
||||
isPrimary: true,
|
||||
workerId: null,
|
||||
...overrides,
|
||||
};
|
||||
}
|
||||
|
||||
describe('PrettyConsoleBackend', () => {
|
||||
test.each([
|
||||
{ level: 'error', label: '<red>ERR </red>', message: '<red>message</red>' },
|
||||
{ level: 'warn', label: '<yellow>WARN</yellow>', message: '<yellow>message</yellow>' },
|
||||
{ level: 'debug', label: '<gray>VERB</gray>', message: '<gray>message</gray>' },
|
||||
{ level: 'info', label: '<blue>INFO</blue>', message: 'message' },
|
||||
] as const)('formats the $level label and message', ({ level, label, message }) => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({ level }));
|
||||
|
||||
expect(output).toHaveBeenCalledWith(`${label} *\t[<white>root</white>]\t${message}`);
|
||||
});
|
||||
|
||||
test('formats legacy success as DONE while retaining the info severity', () => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({
|
||||
level: 'info',
|
||||
compatibility: { legacyLevel: 'success' },
|
||||
}));
|
||||
|
||||
expect(output).toHaveBeenCalledWith('<green>DONE</green> *\t[<white>root</white>]\t<green>message</green>');
|
||||
});
|
||||
|
||||
test('formats contexts from root to leaf using their configured colors', () => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({
|
||||
context: [
|
||||
{ name: 'root', color: 'red' },
|
||||
{ name: 'child' },
|
||||
{ name: 'leaf', color: 'blue' },
|
||||
],
|
||||
}));
|
||||
|
||||
expect(output).toHaveBeenCalledWith('<blue>INFO</blue> *\t[<rgb:255,0,0>root</rgb:255,0,0> <white>child</white> <rgb:0,0,255>leaf</rgb:0,0,255>]\tmessage');
|
||||
});
|
||||
|
||||
test('prefixes the time derived from the record timestamp when enabled', () => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => true });
|
||||
|
||||
backend.write(createRecord());
|
||||
|
||||
expect(output).toHaveBeenCalledWith('<gray>03:04:05</gray> <blue>INFO</blue> *\t[<white>root</white>]\tmessage');
|
||||
});
|
||||
|
||||
test('uses the worker id for a worker process', () => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({ isPrimary: false, workerId: 7 }));
|
||||
|
||||
expect(output).toHaveBeenCalledWith('<blue>INFO</blue> 7\t[<white>root</white>]\tmessage');
|
||||
});
|
||||
|
||||
test('bolds an important record and passes data as the second output argument', () => {
|
||||
const output = vi.fn();
|
||||
const data = { detail: 'value' };
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({
|
||||
level: 'error',
|
||||
compatibility: { important: true, data },
|
||||
}));
|
||||
|
||||
expect(output).toHaveBeenCalledWith(
|
||||
'<bold><bgRed.white>ERR </bgRed.white> *\t[<white>root</white>]\t<red>message</red></bold>',
|
||||
data,
|
||||
);
|
||||
});
|
||||
|
||||
test('treats fatal records as important errors', () => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({ level: 'fatal' }));
|
||||
|
||||
expect(output).toHaveBeenCalledWith('<bold><bgRed.white>ERR </bgRed.white> *\t[<white>root</white>]\t<red>message</red></bold>');
|
||||
});
|
||||
|
||||
test('omits null data from output arguments', () => {
|
||||
const output = vi.fn();
|
||||
const backend = new PrettyConsoleBackend({ output, withLogTime: () => false });
|
||||
|
||||
backend.write(createRecord({ compatibility: { data: null } }));
|
||||
|
||||
expect(output).toHaveBeenCalledTimes(1);
|
||||
expect(output.mock.calls[0]).toHaveLength(1);
|
||||
});
|
||||
});
|
||||
Reference in New Issue
Block a user