From 667919581e604140f7caed9be9800ecf46a5c2e3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E3=81=8A=E3=81=95=E3=82=80=E3=81=AE=E3=81=B2=E3=81=A8?= <46447427+samunohito@users.noreply.github.com> Date: Wed, 15 Jul 2026 13:29:39 +0900 Subject: [PATCH] =?UTF-8?q?enhance:=20=E6=96=B0=E3=81=97=E3=81=84Logger?= =?UTF-8?q?=E3=81=AE=E3=82=B3=E3=82=A2=E5=AE=9F=E8=A3=85=20(#17714)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * enhance: impl logger core * fix order --- packages/backend/src/logger.ts | 105 +++++-------- packages/backend/src/logging/LogBackend.ts | 21 +++ packages/backend/src/logging/LogManager.ts | 94 +++++++++++ .../src/logging/PrettyConsoleBackend.ts | 82 ++++++++++ .../backend/src/logging/logging-runtime.ts | 13 ++ packages/backend/src/logging/types.ts | 50 ++++++ .../backend/test/unit/logging/LogManager.ts | 125 +++++++++++++++ packages/backend/test/unit/logging/Logger.ts | 103 ++++++++++++ .../test/unit/logging/PrettyConsoleBackend.ts | 147 ++++++++++++++++++ 9 files changed, 678 insertions(+), 62 deletions(-) create mode 100644 packages/backend/src/logging/LogBackend.ts create mode 100644 packages/backend/src/logging/LogManager.ts create mode 100644 packages/backend/src/logging/PrettyConsoleBackend.ts create mode 100644 packages/backend/src/logging/logging-runtime.ts create mode 100644 packages/backend/src/logging/types.ts create mode 100644 packages/backend/test/unit/logging/LogManager.ts create mode 100644 packages/backend/test/unit/logging/Logger.ts create mode 100644 packages/backend/test/unit/logging/PrettyConsoleBackend.ts diff --git a/packages/backend/src/logger.ts b/packages/backend/src/logger.ts index ce76f8d05e..c32b462cc0 100644 --- a/packages/backend/src/logger.ts +++ b/packages/backend/src/logger.ts @@ -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 | 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 | 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 | null, important = false): void { // 実行を継続できない状況で使う + public error(x: string | Error, data?: Record | 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 | null, important = false): void { // 実行を継続できるが改善すべき状況で使う - this.log('warning', message, data, important); + public warn(message: string, data?: Record | null, important = false): void { + this.log('warn', message, data, important); } + /** 処理が成功したことを、従来のDONE表示で記録します。 */ @bindThis - public succ(message: string, data?: Record | null, important = false): void { // 何かに成功した状況で使う - this.log('success', message, data, important); + public succ(message: string, data?: Record | null, important = false): void { + this.log('info', message, data, important, 'success'); } + /** 開発者向けの調査情報を記録します。 */ @bindThis - public debug(message: string, data?: Record | null, important = false): void { // デバッグ用に使う(開発者に必要だが利用者に不要な情報) - if (process.env.NODE_ENV !== 'production' || envOption.verbose) { - this.log('debug', message, data, important); - } + public debug(message: string, data?: Record | null, important = false): void { + this.log('debug', message, data, important); } + /** 通常の動作状況を記録します。 */ @bindThis - public info(message: string, data?: Record | null, important = false): void { // それ以外 + public info(message: string, data?: Record | null, important = false): void { this.log('info', message, data, important); } } diff --git a/packages/backend/src/logging/LogBackend.ts b/packages/backend/src/logging/LogBackend.ts new file mode 100644 index 0000000000..36d2a60bb6 --- /dev/null +++ b/packages/backend/src/logging/LogBackend.ts @@ -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; + + /** 出力先が持つ資源を解放します。 */ + close?(): void | Promise; +} diff --git a/packages/backend/src/logging/LogManager.ts b/packages/backend/src/logging/LogManager.ts new file mode 100644 index 0000000000..d31aac5daf --- /dev/null +++ b/packages/backend/src/logging/LogManager.ts @@ -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 = {}) { + 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, + }); + } +} diff --git a/packages/backend/src/logging/PrettyConsoleBackend.ts b/packages/backend/src/logging/PrettyConsoleBackend.ts new file mode 100644 index 0000000000..6af60e5efd --- /dev/null +++ b/packages/backend/src/logging/PrettyConsoleBackend.ts @@ -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 = {}) { + 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); + } +} diff --git a/packages/backend/src/logging/logging-runtime.ts b/packages/backend/src/logging/logging-runtime.ts new file mode 100644 index 0000000000..79890ad496 --- /dev/null +++ b/packages/backend/src/logging/logging-runtime.ts @@ -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()); diff --git a/packages/backend/src/logging/types.ts b/packages/backend/src/logging/types.ts new file mode 100644 index 0000000000..e65fd2195e --- /dev/null +++ b/packages/backend/src/logging/types.ts @@ -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 | 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; +}; diff --git a/packages/backend/test/unit/logging/LogManager.ts b/packages/backend/test/unit/logging/LogManager.ts new file mode 100644 index 0000000000..629be70d5c --- /dev/null +++ b/packages/backend/test/unit/logging/LogManager.ts @@ -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(); + 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(); + + manager.setBackend({ write: replacementWrite }); + manager.write(createInput()); + + expect(write).not.toHaveBeenCalled(); + expect(replacementWrite).toHaveBeenCalledOnce(); + }); +}); diff --git a/packages/backend/test/unit/logging/Logger.ts b/packages/backend/test/unit/logging/Logger.ts new file mode 100644 index 0000000000..21fa84e5bf --- /dev/null +++ b/packages/backend/test/unit/logging/Logger.ts @@ -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 = { 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 }], + })); + }); +}); diff --git a/packages/backend/test/unit/logging/PrettyConsoleBackend.ts b/packages/backend/test/unit/logging/PrettyConsoleBackend.ts new file mode 100644 index 0000000000..512facbee0 --- /dev/null +++ b/packages/backend/test/unit/logging/PrettyConsoleBackend.ts @@ -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)}`; + 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 { + 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: 'ERR ', message: 'message' }, + { level: 'warn', label: 'WARN', message: 'message' }, + { level: 'debug', label: 'VERB', message: 'message' }, + { level: 'info', label: 'INFO', 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[root]\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('DONE *\t[root]\tmessage'); + }); + + 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('INFO *\t[root child leaf]\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('03:04:05 INFO *\t[root]\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('INFO 7\t[root]\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( + 'ERR *\t[root]\tmessage', + 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('ERR *\t[root]\tmessage'); + }); + + 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); + }); +});