diff --git a/.env.mac-docker.example b/.env.mac-docker.example index 0a441ada..4b5ca4db 100644 --- a/.env.mac-docker.example +++ b/.env.mac-docker.example @@ -31,6 +31,8 @@ LOG_LEVEL=info # integration-*.log 默认 warn，只记对接异常；排查全量时改为 info LOG_INTEGRATION_LEVEL=warn LOG_RETENTION_DAYS=30 +LOG_MAX_FILE_SIZE_MB=20 +LOG_MAX_FILES=5 # File Storage (MinIO / S3 compatible) STORAGE_MODE=minio diff --git a/.env.server.example b/.env.server.example index c4f0e8d6..59500167 100644 --- a/.env.server.example +++ b/.env.server.example @@ -53,6 +53,9 @@ LOG_LEVEL=info # integration-*.log：对接日志级别（debug|info|warn|error），默认 warn 只记异常 LOG_INTEGRATION_LEVEL=warn LOG_RETENTION_DAYS=30 +# 单个 app/integration 日志文件达到 20MB 后轮转，单日最多保留 5 个分片 +LOG_MAX_FILE_SIZE_MB=20 +LOG_MAX_FILES=5 # 数据库敏感报文/事件保留策略（天）。清理任务每天执行一次。 RAW_PAYLOAD_RETENTION_DAYS=180 diff --git a/apps/backend/README.md b/apps/backend/README.md index 7e380c5f..c9fdae45 100644 --- a/apps/backend/README.md +++ b/apps/backend/README.md @@ -40,6 +40,9 @@ npm test | --- | --- | | `PORT` | 服务端口（Compose 中常由 `BACKEND_PORT` 映射） | | `LOG_LEVEL` | `debug` / `info` / `warn` / `error` | +| `LOG_MAX_FILE_SIZE_MB` | 单个应用日志文件大小上限，默认 `20` MB，超出后轮转 | +| `LOG_MAX_FILES` | 同一日期最多保留的日志文件数量，默认 `5`（含当前文件） | +| `LOG_RETENTION_DAYS` | 日志日期保留天数，默认 `30` | | `DATABASE_URL` | PostgreSQL 连接串 | | `ADMIN_SESSION_SECRET` | 后台登录态签名密钥 | | `ADMIN_DEFAULT_USERS_JSON` | 默认后台用户 | @@ -130,6 +133,6 @@ docker compose -f ../../docker-compose.dev.yml exec -T backend npm run db:migrat - `data/logs/app-YYYY-MM-DD.log` - `data/logs/integration-YYYY-MM-DD.log` -按天切分，默认清理过期日志。成功的 `/health*` 探活默认不写 access log。 +按天切分并按大小轮转，默认单文件 20MB、单日最多 5 个分片、保留 30 天。成功的 `GET/HEAD` 请求以 `DEBUG` 记录，生产默认 `LOG_LEVEL=info` 不落盘；写请求和所有 4xx/5xx 仍保留 access log。成功的 `/health*` 探活默认不写 access log。 `data/*.json` 为本地运行配置，可能含敏感信息，默认不提交；请从 `*.example.json` 复制后填写。 diff --git a/apps/backend/src/config/defaults.ts b/apps/backend/src/config/defaults.ts index 29b59b27..0382871b 100644 --- a/apps/backend/src/config/defaults.ts +++ b/apps/backend/src/config/defaults.ts @@ -19,6 +19,8 @@ export function createDefaultRuntimeConfig(projectRoot: string): RuntimeConfig { // 对接日志默认只保留 warn/error，避免 integration-*.log 被 info 刷爆 integrationLevel: 'warn', retentionDays: 30, + maxFileSizeMb: 20, + maxFiles: 5, }, retention: { diff --git a/apps/backend/src/config/env-overrides.test.ts b/apps/backend/src/config/env-overrides.test.ts index f90e4f2e..8bf7d920 100644 --- a/apps/backend/src/config/env-overrides.test.ts +++ b/apps/backend/src/config/env-overrides.test.ts @@ -13,6 +13,8 @@ test('applyEnvOverrides maps typed environment values without mutating base conf DATA_ROOT: './tmp/backend-data', DATABASE_SSL: 'yes', LOG_RETENTION_DAYS: '45', + LOG_MAX_FILE_SIZE_MB: '12', + LOG_MAX_FILES: '4', ADMIN_DEFAULT_USERS_JSON: '[{"username":"admin","password":"secret","role":"admin"}]', KAQUAN91_USER_ID: 'kaquan-user', KAQUAN91_SECRET: 'kaquan-secret', @@ -23,6 +25,8 @@ test('applyEnvOverrides maps typed environment values without mutating base conf assert.equal(config.data.root, path.resolve('./tmp/backend-data')) assert.equal(config.database.ssl, true) assert.equal(config.logging.retentionDays, 45) + assert.equal(config.logging.maxFileSizeMb, 12) + assert.equal(config.logging.maxFiles, 4) assert.deepEqual(config.admin.defaultUsers, [ { username: 'admin', password: 'secret', role: 'admin' }, ]) diff --git a/apps/backend/src/config/env-overrides.ts b/apps/backend/src/config/env-overrides.ts index cb2ee68f..cb0d6844 100644 --- a/apps/backend/src/config/env-overrides.ts +++ b/apps/backend/src/config/env-overrides.ts @@ -33,6 +33,8 @@ export const ENV_OVERRIDES: readonly EnvOverride[] = [ stringEnv('LOG_LEVEL', ['logging', 'level']), stringEnv('LOG_INTEGRATION_LEVEL', ['logging', 'integrationLevel']), integerEnv('LOG_RETENTION_DAYS', ['logging', 'retentionDays']), + integerEnv('LOG_MAX_FILE_SIZE_MB', ['logging', 'maxFileSizeMb']), + integerEnv('LOG_MAX_FILES', ['logging', 'maxFiles']), integerEnv('RAW_PAYLOAD_RETENTION_DAYS', ['retention', 'rawPayloadDays']), integerEnv('TASK_EVENT_RETENTION_DAYS', ['retention', 'taskEventDays']), integerEnv('WEBHOOK_EVENT_RETENTION_DAYS', ['retention', 'webhookEventDays']), diff --git a/apps/backend/src/config/runtime-validation.ts b/apps/backend/src/config/runtime-validation.ts index 133b2eb8..494dd6f2 100644 --- a/apps/backend/src/config/runtime-validation.ts +++ b/apps/backend/src/config/runtime-validation.ts @@ -52,6 +52,8 @@ export function validateRuntimeConfig( }) } requireInteger(issues, 'database.maxConnections', config.database?.maxConnections, { min: 1 }) + requireOptionalInteger(issues, 'logging.maxFileSizeMb', config.logging?.maxFileSizeMb, { min: 1 }) + requireOptionalInteger(issues, 'logging.maxFiles', config.logging?.maxFiles, { min: 2 }) requireOptionalInteger(issues, 'database.idleTimeoutMs', config.database?.idleTimeoutMs, { min: 1, }) diff --git a/apps/backend/src/middleware/access-log.test.ts b/apps/backend/src/middleware/access-log.test.ts new file mode 100644 index 00000000..51ce41b4 --- /dev/null +++ b/apps/backend/src/middleware/access-log.test.ts @@ -0,0 +1,15 @@ +import test from 'node:test' +import assert from 'node:assert/strict' + +import { resolveAccessLogLevel } from './access-log.js' + +test('resolveAccessLogLevel sends successful reads to debug', () => { + assert.equal(resolveAccessLogLevel('GET', 200), 'debug') + assert.equal(resolveAccessLogLevel('head', 304), 'debug') +}) + +test('resolveAccessLogLevel keeps writes and failures at info', () => { + assert.equal(resolveAccessLogLevel('POST', 200), 'info') + assert.equal(resolveAccessLogLevel('GET', 404), 'info') + assert.equal(resolveAccessLogLevel('GET', 500), 'info') +}) diff --git a/apps/backend/src/middleware/access-log.ts b/apps/backend/src/middleware/access-log.ts index b5044bd7..b8ac4f4f 100644 --- a/apps/backend/src/middleware/access-log.ts +++ b/apps/backend/src/middleware/access-log.ts @@ -1,5 +1,5 @@ import type { Request, Response, NextFunction } from 'express' -import { createRequestId, logInfo } from '../utils/logger.js' +import { createRequestId, logDebug, logInfo } from '../utils/logger.js' export function accessLogMiddleware(req: Request, res: Response, next: NextFunction): void { const startedAt = Date.now() @@ -13,7 +13,9 @@ export function accessLogMiddleware(req: Request, res: Response, next: NextFunct return } - logInfo('[http/access]', 'request completed', { + const writeLog = + resolveAccessLogLevel(req.method, res.statusCode) === 'debug' ? logDebug : logInfo + writeLog('[http/access]', 'request completed', { requestId, method: req.method, originalUrl: req.originalUrl, @@ -33,6 +35,18 @@ export function accessLogMiddleware(req: Request, res: Response, next: NextFunct next() } +export function resolveAccessLogLevel(method: unknown, statusCode: unknown): 'debug' | 'info' { + const normalizedMethod = String(method || '') + .trim() + .toUpperCase() + const normalizedStatus = Number(statusCode || 0) + return ['GET', 'HEAD'].includes(normalizedMethod) && + normalizedStatus >= 200 && + normalizedStatus < 400 + ? 'debug' + : 'info' +} + function resolveRequestId(req: Request): string { const fromHeader = String(req.headers['x-request-id'] || '').trim() return fromHeader || createRequestId('req') diff --git a/apps/backend/src/types/runtime-config.ts b/apps/backend/src/types/runtime-config.ts index f4f5aa43..9f598e45 100644 --- a/apps/backend/src/types/runtime-config.ts +++ b/apps/backend/src/types/runtime-config.ts @@ -31,6 +31,10 @@ export type RuntimeConfig = { /** integration 通道（外部对接日志文件）最低级别，默认 warn */ integrationLevel: string retentionDays: number + /** 单个日志文件大小上限（MB），超出后轮转。 */ + maxFileSizeMb?: number + /** 同一日期最多保留的日志文件数量（含当前文件）。 */ + maxFiles?: number } retention: { rawPayloadDays: number diff --git a/apps/backend/src/utils/logger.test.ts b/apps/backend/src/utils/logger.test.ts index 50af10fb..c8def2ff 100644 --- a/apps/backend/src/utils/logger.test.ts +++ b/apps/backend/src/utils/logger.test.ts @@ -77,6 +77,16 @@ test('resolveExpiredLogFilenames supports explicit retention days', () => { assert.deepEqual(expired, ['app-2026-04-07.log']) }) +test('resolveExpiredLogFilenames includes rotated files', () => { + const expired = resolveExpiredLogFilenames( + ['app-2026-04-14.1.log', 'app-2026-04-07.5.log', 'app-2026-04-14.log'], + '2026-04-14', + 7, + ) + + assert.deepEqual(expired, ['app-2026-04-07.5.log']) +}) + test('formatLogTimestamp renders readable local timestamp with timezone offset', () => { const rendered = formatLogTimestamp('2026-04-14T10:36:24.974Z') assert.match(rendered, /^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3} [+-]\d{2}:\d{2}$/) diff --git a/apps/backend/src/utils/logger.ts b/apps/backend/src/utils/logger.ts index efeb1f97..bd7e4b23 100644 --- a/apps/backend/src/utils/logger.ts +++ b/apps/backend/src/utils/logger.ts @@ -56,6 +56,11 @@ const ACTIVE_INTEGRATION_LOG_LEVEL = normalizeLogLevel( ) const DEFAULT_LOG_RETENTION_DAYS = 30 const LOG_RETENTION_DAYS = normalizeLogRetentionDays(runtimeConfig.logging?.retentionDays) +const DEFAULT_LOG_MAX_FILE_SIZE_MB = 20 +const DEFAULT_LOG_MAX_FILES = 5 +const LOG_MAX_FILE_SIZE_BYTES = + normalizeLogMaxFileSizeMb(runtimeConfig.logging?.maxFileSizeMb) * 1024 * 1024 +const LOG_MAX_FILES = normalizeLogMaxFiles(runtimeConfig.logging?.maxFiles) const LEGACY_LOG_FILES = new Set(['app.log', 'integration.log']) const SENSITIVE_KEY_PATTERN = /token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardno|cardpwd|apikey|api_key|devicekey|session|x-sign|(?:^|[_-])sign(?:ature)?(?:[_-]|$)/i @@ -181,6 +186,7 @@ function enqueueFileWrite( writeQueue = writeQueue .then(async () => { await fs.mkdir(LOG_DIR, { recursive: true }) + await rotateLogFileIfNeeded(filePath, Buffer.byteLength(`${line}\n`, 'utf8')) await fs.appendFile(filePath, `${line}\n`, 'utf8') await cleanupExpiredLogsIfNeeded(dateKey) }) @@ -666,12 +672,78 @@ function normalizeLogRetentionDays(value: unknown): number { return Math.max(1, Math.floor(parsed)) } +function normalizeLogMaxFileSizeMb(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_MAX_FILE_SIZE_MB + } + + return Math.max(1, Math.floor(parsed)) +} + +function normalizeLogMaxFiles(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_MAX_FILES + } + + return Math.max(2, Math.floor(parsed)) +} + +async function rotateLogFileIfNeeded(filePath: string, nextLineBytes: number): Promise { + if (!filePath.endsWith('.log') || LOG_MAX_FILE_SIZE_BYTES <= 0) { + return + } + + let currentSize = 0 + try { + currentSize = (await fs.stat(filePath)).size + } catch (error) { + if (isFileMissingError(error)) { + return + } + throw error + } + + if (currentSize === 0 || currentSize + nextLineBytes <= LOG_MAX_FILE_SIZE_BYTES) { + return + } + + for (let index = LOG_MAX_FILES - 1; index >= 1; index -= 1) { + await renameIfPresent( + rotatedLogFilePath(filePath, index), + rotatedLogFilePath(filePath, index + 1), + ) + } + await renameIfPresent(filePath, rotatedLogFilePath(filePath, 1)) +} + +function rotatedLogFilePath(filePath: string, index: number): string { + return filePath.replace(/\.log$/, `.${index}.log`) +} + +async function renameIfPresent(source: string, target: string): Promise { + try { + await fs.rename(source, target) + } catch (error) { + if (!isFileMissingError(error)) { + throw error + } + } +} + +function isFileMissingError(error: unknown): boolean { + return Boolean(error && typeof error === 'object' && 'code' in error && error.code === 'ENOENT') +} + function shouldDeleteLogFileByDate(fileName: unknown, cutoffDateKey: string): boolean { if (LEGACY_LOG_FILES.has(String(fileName || '').trim())) { return true } - const matched = /^([a-z0-9-]{1,40})-(\d{4}-\d{2}-\d{2})\.log$/.exec(String(fileName || '').trim()) + const matched = /^([a-z0-9-]{1,40})-(\d{4}-\d{2}-\d{2})(?:\.\d+)?\.log$/.exec( + String(fileName || '').trim(), + ) if (!matched) { return false diff --git a/docker-compose.dev.yml b/docker-compose.dev.yml index d1b8d618..7312d75d 100644 --- a/docker-compose.dev.yml +++ b/docker-compose.dev.yml @@ -98,6 +98,8 @@ services: DATABASE_MAX_CONNECTIONS: ${DATABASE_MAX_CONNECTIONS:-10} DATA_ROOT: /app/data LOG_RETENTION_DAYS: ${LOG_RETENTION_DAYS:-30} + LOG_MAX_FILE_SIZE_MB: ${LOG_MAX_FILE_SIZE_MB:-20} + LOG_MAX_FILES: ${LOG_MAX_FILES:-5} CLAIM_BASE_URL: ${CLAIM_BASE_URL:-http://localhost/#/claim} STORAGE_MODE: ${STORAGE_MODE:-minio} STORAGE_ENDPOINT: ${STORAGE_ENDPOINT:-http://minio:9000} diff --git a/docker-compose.yml b/docker-compose.yml index 482bc4cf..011034c4 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -88,6 +88,8 @@ services: DATABASE_STATEMENT_TIMEOUT_MS: ${DATABASE_STATEMENT_TIMEOUT_MS:-15000} DATA_ROOT: /app/data LOG_RETENTION_DAYS: ${LOG_RETENTION_DAYS:-30} + LOG_MAX_FILE_SIZE_MB: ${LOG_MAX_FILE_SIZE_MB:-20} + LOG_MAX_FILES: ${LOG_MAX_FILES:-5} CLAIM_BASE_URL: ${CLAIM_BASE_URL:-http://localhost/#/claim} # 生产图片存储只走阿里云 OSS；MinIO 仅保留在本地开发编排（docker-compose.dev.yml）。 STORAGE_MODE: ${STORAGE_MODE:-oss} diff --git a/log-optimization-artifacts/BASELINE_FILE.ts b/log-optimization-artifacts/BASELINE_FILE.ts new file mode 100644 index 00000000..efeb1f97 --- /dev/null +++ b/log-optimization-artifacts/BASELINE_FILE.ts @@ -0,0 +1,685 @@ +import fs from 'node:fs/promises' +import path from 'node:path' +import process from 'node:process' +import util from 'node:util' + +import { PROJECT_ROOT, runtimeConfig } from '../config/runtime.js' +import type { HttpErrorLike } from './http.js' +import { maskSecret } from './masking.js' +import { asJsonObject } from '../types/json.js' + +type LogLevel = 'debug' | 'info' | 'warn' | 'error' +type LogChannel = 'app' | 'integration' +type LogDetail = unknown +type InlineFields = Record +type ExternalHttpPacketDetail = Record +type LogEntry = { + time: string + level: LogLevel + scope: string + message: string + pid: number + detail?: unknown +} + +const LOG_LEVEL_PRIORITY: Record = { + debug: 10, + info: 20, + warn: 30, + error: 40, +} + +const LEVEL_LABELS: Record = { + debug: 'DEBUG', + info: 'INFO ', + warn: 'WARN ', + error: 'ERROR', +} + +const ANSI = { + reset: '\u001B[0m', + dim: '\u001B[2m', + bold: '\u001B[1m', + gray: '\u001B[90m', + cyan: '\u001B[36m', + blue: '\u001B[34m', + yellow: '\u001B[33m', + red: '\u001B[31m', +} + +const DATA_ROOT = resolveDataRoot() +const LOG_DIR = path.join(DATA_ROOT, 'logs') +const ACTIVE_LOG_LEVEL = normalizeLogLevel(runtimeConfig.logging?.level) +/** integration 通道独立阈值，默认 warn（仅错误/告警落盘） */ +const ACTIVE_INTEGRATION_LOG_LEVEL = normalizeLogLevel( + runtimeConfig.logging?.integrationLevel ?? 'warn', +) +const DEFAULT_LOG_RETENTION_DAYS = 30 +const LOG_RETENTION_DAYS = normalizeLogRetentionDays(runtimeConfig.logging?.retentionDays) +const LEGACY_LOG_FILES = new Set(['app.log', 'integration.log']) +const SENSITIVE_KEY_PATTERN = + /token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardno|cardpwd|apikey|api_key|devicekey|session|x-sign|(?:^|[_-])sign(?:ature)?(?:[_-]|$)/i +const SENSITIVE_URL_PARAM_PATTERN = + /([?&](?:token|secret|password|passwd|pwd|cookie|authorization|api[_-]?key|device[_-]?key|sign|signature|code)=)([^&\s,;"']+)/gi +const SENSITIVE_JSON_FIELD_PATTERN = + /("(?:token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardNo|cardPwd|apiKey|api_key|deviceKey|device_key|session|x-sign|sign|signature)"\s*:\s*")([^"]*)(")/gi +const MAX_SANITIZE_DEPTH = 8 + +let writeQueue = Promise.resolve() +let lastCleanupDateKey = '' + +export function createRequestId(prefix = 'req'): string { + return `${prefix}-${Date.now().toString(36)}-${Math.random().toString(36).slice(2, 8)}` +} + +export function logDebug(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('debug', scope, message, detail) +} + +export function logInfo(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('info', scope, message, detail) +} + +export function logWarn(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('warn', scope, message, detail) +} + +export function logError(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('error', scope, message, detail) +} + +export function logIntegration( + scope: unknown, + message: unknown, + detail: LogDetail = undefined, + { level = 'info' }: { level?: LogLevel } = {}, +) { + // 默认 integration 阈值为 warn：失败类文案即使调用方传 info 也提升，避免漏记异常 + return writeLog(resolveIntegrationLogLevel(level, message), scope, message, detail, { + channel: 'integration', + }) +} + +function resolveIntegrationLogLevel(level: LogLevel, message: unknown): LogLevel { + const normalized = normalizeLogLevel(level) + if (normalized === 'warn' || normalized === 'error') { + return normalized + } + + const text = String(message || '') + if (/失败|异常|错误|超时|拒绝|expired|fail|error|timeout|denied/i.test(text)) { + return 'error' + } + + return normalized +} + +export function logExternalHttpPacket( + scope: unknown, + message: unknown, + detail: ExternalHttpPacketDetail = {}, + { level = 'info' }: { level?: LogLevel } = {}, +) { + return logIntegration(scope, message, normalizeExternalHttpPacketDetail(detail), { level }) +} + +export function logCapture( + scope: unknown, + message: unknown, + detail: LogDetail = undefined, + { channel = 'capture', sanitize = false }: { channel?: string; sanitize?: boolean } = {}, +): LogEntry | null { + const entry = { + time: new Date().toISOString(), + level: 'info' as LogLevel, + scope: String(scope || 'capture').trim() || 'capture', + message: String(message || '').trim() || '-', + pid: process.pid, + detail: normalizeLogValue(detail, sanitize !== false), + } + + enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time), sanitize !== false, true) + return entry +} + +function writeLog( + level: LogLevel, + scope: unknown, + message: unknown, + detail: LogDetail, + { channel = 'app' }: { channel?: LogChannel } = {}, +): LogEntry | null { + const configuredLevel = + channel === 'integration' ? ACTIVE_INTEGRATION_LOG_LEVEL : ACTIVE_LOG_LEVEL + if (!shouldWriteLog(level, configuredLevel)) { + return null + } + + const entry = { + time: new Date().toISOString(), + level: normalizeLogLevel(level), + scope: String(scope || 'app').trim() || 'app', + message: String(message || '').trim() || '-', + pid: process.pid, + detail: normalizeLogValue(detail), + } + + writeConsole(entry) + enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time), true) + return entry +} + +function enqueueFileWrite( + entry: LogEntry, + filePath: string, + sanitize: boolean, + jsonLine = false, +): void { + const line = jsonLine ? JSON.stringify(entry) : formatLogEntry(entry, { color: false, sanitize }) + const dateKey = extractLogDateKey(entry.time) + + writeQueue = writeQueue + .then(async () => { + await fs.mkdir(LOG_DIR, { recursive: true }) + await fs.appendFile(filePath, `${line}\n`, 'utf8') + await cleanupExpiredLogsIfNeeded(dateKey) + }) + .catch((error) => { + const reason = error instanceof Error ? error.message : String(error || '未知错误') + console.error('[logger] failed to write log file:', reason) + }) +} + +function writeConsole(entry: LogEntry): void { + const logger = resolveConsoleMethod(entry.level) + logger(formatLogEntry(entry, { color: supportsAnsiColor() })) +} + +function resolveConsoleMethod(level: unknown) { + const normalized = normalizeLogLevel(level) + + if (normalized === 'error') { + return console.error + } + + if (normalized === 'warn') { + return console.warn + } + + return console.log +} + +export function normalizeLogLevel(level: unknown): LogLevel { + const normalized = String(level || '') + .trim() + .toLowerCase() + return isLogLevel(normalized) ? normalized : 'info' +} + +export function shouldWriteLog( + level: unknown, + configuredLevel: unknown = ACTIVE_LOG_LEVEL, +): boolean { + const normalizedLevel = normalizeLogLevel(level) + const normalizedConfigured = normalizeLogLevel(configuredLevel) + + return LOG_LEVEL_PRIORITY[normalizedLevel] >= LOG_LEVEL_PRIORITY[normalizedConfigured] +} + +export function formatLogEntry( + entry: Partial, + { color = false, sanitize = true }: { color?: boolean; sanitize?: boolean } = {}, +): string { + const normalizedEntry = { + time: String(entry?.time || new Date().toISOString()), + level: normalizeLogLevel(entry?.level), + scope: String(entry?.scope || 'app').trim() || 'app', + message: String(entry?.message || '').trim() || '-', + pid: Number(entry?.pid || process.pid), + detail: sanitize !== false ? sanitizeLogValue(entry?.detail) : entry?.detail, + } + const timestamp = colorize(formatLogTimestamp(normalizedEntry.time), ANSI.gray, color) + const level = colorize( + LEVEL_LABELS[normalizedEntry.level], + resolveLevelColor(normalizedEntry.level), + color, + ) + const scope = colorize(normalizedEntry.scope, ANSI.cyan, color) + const message = colorize(normalizedEntry.message, ANSI.bold, color) + const separator = colorize('|', ANSI.dim, color) + const { inline, block } = splitDetailPayload(normalizedEntry.detail) + const inlineFields = formatInlineFields({ + pid: normalizedEntry.pid, + ...inline, + }) + const firstLine = [timestamp, level, scope, message, separator, inlineFields] + .filter(Boolean) + .join(' ') + + if (!block) { + return firstLine + } + + const inspected = util.inspect(block, { + depth: 8, + colors: color, + compact: false, + breakLength: 120, + maxArrayLength: 100, + }) + + return `${firstLine}\n${indentBlock(inspected, ' ')}` +} + +export function resolveLogFilePath(channel = 'app', time = new Date().toISOString()): string { + const normalizedChannel = normalizeLogChannelName(channel) + return path.join(LOG_DIR, `${normalizedChannel}-${extractLogDateKey(time)}.log`) +} + +function normalizeLogChannelName(value: unknown): string { + const normalized = String(value || '') + .trim() + .toLowerCase() + if (!normalized) { + return 'app' + } + if (normalized === 'integration') { + return 'integration' + } + return /^[a-z0-9-]{1,40}$/.test(normalized) ? normalized : 'app' +} + +export function resolveExpiredLogFilenames( + fileNames: string[] = [], + referenceTime = new Date().toISOString(), + retentionDays = LOG_RETENTION_DAYS, +): string[] { + const normalizedRetentionDays = normalizeLogRetentionDays(retentionDays) + const cutoffDateKey = toDateKey(offsetDate(referenceTime, -(normalizedRetentionDays - 1))) + + return (Array.isArray(fileNames) ? fileNames : []).filter((fileName) => + shouldDeleteLogFileByDate(fileName, cutoffDateKey), + ) +} + +export function formatLogTimestamp(value: unknown): string { + const date = new Date(value instanceof Date ? value : String(value || '')) + + if (Number.isNaN(date.getTime())) { + return String(value || '').trim() || new Date().toISOString() + } + + return `${formatLocalDate(date)} ${formatLocalTime(date)}.${String(date.getMilliseconds()).padStart(3, '0')} ${formatTimezoneOffset(date)}` +} + +function resolveDataRoot(): string { + const configured = String(runtimeConfig.data?.root || '').trim() + return configured ? path.resolve(configured) : path.resolve(PROJECT_ROOT, 'data') +} + +function normalizeLogValue(value: unknown, sanitize = true): unknown { + if (typeof value === 'undefined') { + return undefined + } + + const normalizeCurrent = (current: unknown): unknown => { + if (current instanceof Error) { + const currentError = current as Error & HttpErrorLike + return { + name: currentError.name, + message: sanitize ? sanitizeLogString(currentError.message) : currentError.message, + stack: sanitize ? sanitizeLogString(currentError.stack) : currentError.stack, + statusCode: currentError.statusCode, + errorCode: currentError.errorCode, + context: sanitize ? sanitizeLogValue(currentError.context) : currentError.context, + } + } + + if (typeof current === 'bigint') { + return String(current) + } + + return current + } + + try { + return sanitize + ? sanitizeLogValue( + JSON.parse(JSON.stringify(value, (_key, current) => normalizeCurrent(current))), + ) + : JSON.parse(JSON.stringify(value, (_key, current) => normalizeCurrent(current))) + } catch { + return sanitize ? sanitizeLogString(String(value)) : String(value) + } +} + +function sanitizeLogValue(value: unknown, key = '', depth = 0): unknown { + if (typeof value === 'undefined') { + return undefined + } + + if (value === null) { + return null + } + + if (isSensitiveLogKey(key)) { + return maskSecret(value) + } + + if (typeof value === 'string') { + return sanitizeLogString(value) + } + + if (typeof value === 'number' || typeof value === 'boolean') { + return value + } + + if (typeof value === 'bigint') { + return String(value) + } + + if (depth >= MAX_SANITIZE_DEPTH) { + return '[MaxDepth]' + } + + if (Array.isArray(value)) { + return value.map((item) => sanitizeLogValue(item, key, depth + 1)) + } + + if (value && typeof value === 'object') { + return Object.fromEntries( + Object.entries(value).map(([currentKey, currentValue]) => [ + currentKey, + sanitizeLogValue(currentValue, currentKey, depth + 1), + ]), + ) + } + + return sanitizeLogString(String(value)) +} + +function sanitizeLogString(value: unknown): string { + return String(value || '') + .replace( + /(Bearer\s+)([A-Za-z0-9._~+/=-]+)/gi, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) + .replace( + SENSITIVE_URL_PARAM_PATTERN, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) + .replace( + SENSITIVE_JSON_FIELD_PATTERN, + (_matched, prefix, secret, suffix) => `${prefix}${maskSecret(secret)}${suffix}`, + ) + .replace( + /\b((?:token|secret|password|passwd|pwd|cookie|authorization|api[_-]?key|device[_-]?key)=)([^&\s,;]+)/gi, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) +} + +function isSensitiveLogKey(key: unknown): boolean { + return SENSITIVE_KEY_PATTERN.test(String(key || '').trim()) +} + +function normalizeExternalHttpPacketDetail( + detail: ExternalHttpPacketDetail, +): ExternalHttpPacketDetail { + const source = asJsonObject(detail) + const normalized: ExternalHttpPacketDetail = {} + + for (const [key, value] of Object.entries(source)) { + normalized[key] = normalizeExternalPacketValue(value) + } + + return normalized +} + +function normalizeExternalPacketValue(value: unknown): unknown { + if (typeof value === 'undefined' || value === null) { + return value + } + + if (value instanceof Error) { + const currentError = value as Error & HttpErrorLike + return { + name: value.name, + message: value.message, + stack: value.stack, + statusCode: currentError.statusCode, + errorCode: currentError.errorCode, + context: normalizeExternalPacketValue(currentError.context), + } + } + + if (typeof value === 'string') { + return value + } + + if (typeof value === 'number' || typeof value === 'boolean' || typeof value === 'bigint') { + return value + } + + if (Array.isArray(value)) { + return value.map((item) => normalizeExternalPacketValue(item)) + } + + if (value && typeof value === 'object') { + return Object.fromEntries( + Object.entries(value).map(([key, currentValue]) => [ + key, + normalizeExternalPacketValue(currentValue), + ]), + ) + } + + return String(value) +} + +function splitDetailPayload(detail: unknown): { inline: InlineFields; block: unknown | null } { + if (typeof detail === 'undefined') { + return { + inline: {}, + block: null, + } + } + + if (isScalarLogValue(detail)) { + return { + inline: { detail }, + block: null, + } + } + + if (Array.isArray(detail)) { + return { + inline: {}, + block: detail, + } + } + + if (detail && typeof detail === 'object') { + const inline: InlineFields = {} + const block: Record = {} + + for (const [key, value] of Object.entries(detail)) { + if (isScalarLogValue(value)) { + inline[key] = value + continue + } + + block[key] = value + } + + return { + inline, + block: Object.keys(block).length > 0 ? block : null, + } + } + + return { + inline: { detail: String(detail) }, + block: null, + } +} + +function formatInlineFields(fields: InlineFields): string { + return Object.entries(fields) + .filter(([, value]) => typeof value !== 'undefined' && value !== '') + .map(([key, value]) => `${key}=${formatInlineValue(value)}`) + .join(' ') +} + +function formatInlineValue(value: unknown): string { + if (value === null) { + return 'null' + } + + if (typeof value === 'number' || typeof value === 'boolean') { + return String(value) + } + + const text = String(value || '') + return /^[A-Za-z0-9_./:@-]+$/.test(text) ? text : JSON.stringify(text) +} + +function isScalarLogValue(value: unknown): value is string | number | boolean | null { + return value === null || ['string', 'number', 'boolean'].includes(typeof value) +} + +function indentBlock(text: unknown, indent: string): string { + return String(text || '') + .split('\n') + .map((line) => `${indent}${line}`) + .join('\n') +} + +function supportsAnsiColor(): boolean { + return process.env.NO_COLOR !== '1' && Boolean(process.stdout.isTTY || process.stderr.isTTY) +} + +function resolveLevelColor(level: unknown): string { + switch (normalizeLogLevel(level)) { + case 'debug': + return ANSI.blue + case 'warn': + return ANSI.yellow + case 'error': + return ANSI.red + default: + return ANSI.cyan + } +} + +function colorize(text: string, ansiCode: string, enabled: boolean): string { + if (!enabled || !ansiCode) { + return text + } + + return `${ansiCode}${text}${ANSI.reset}` +} + +function formatLocalDate(date: Date): string { + return `${date.getFullYear()}-${String(date.getMonth() + 1).padStart(2, '0')}-${String(date.getDate()).padStart(2, '0')}` +} + +function formatLocalTime(date: Date): string { + return `${String(date.getHours()).padStart(2, '0')}:${String(date.getMinutes()).padStart(2, '0')}:${String(date.getSeconds()).padStart(2, '0')}` +} + +function formatTimezoneOffset(date: Date): string { + const totalMinutes = -date.getTimezoneOffset() + const sign = totalMinutes >= 0 ? '+' : '-' + const absoluteMinutes = Math.abs(totalMinutes) + const hours = String(Math.floor(absoluteMinutes / 60)).padStart(2, '0') + const minutes = String(absoluteMinutes % 60).padStart(2, '0') + return `${sign}${hours}:${minutes}` +} + +async function cleanupExpiredLogsIfNeeded(dateKey: string): Promise { + if (!dateKey || dateKey === lastCleanupDateKey) { + return + } + + lastCleanupDateKey = dateKey + + try { + const fileNames = await fs.readdir(LOG_DIR) + const expired = resolveExpiredLogFilenames(fileNames, dateKey, LOG_RETENTION_DAYS) + await Promise.all( + expired.map((fileName) => fs.rm(path.join(LOG_DIR, fileName), { force: true })), + ) + } catch (error) { + const reason = error instanceof Error ? error.message : String(error || '未知错误') + console.error('[logger] failed to cleanup old log files:', reason) + } +} + +function extractLogDateKey(time: unknown): string { + return toDateKey(time) +} + +function toDateKey(value: unknown): string { + const date = parseLogDate(value) + + if (Number.isNaN(date.getTime())) { + return formatLocalDate(new Date()) + } + + return formatLocalDate(date) +} + +function offsetDate(value: unknown, offsetDays: unknown): Date { + const date = parseLogDate(value) + if (Number.isNaN(date.getTime())) { + return new Date() + } + + date.setDate(date.getDate() + Number(offsetDays || 0)) + return date +} + +function parseLogDate(value: unknown): Date { + if (value instanceof Date) { + return new Date(value.getTime()) + } + + const text = String(value || '').trim() + const matchedDateKey = /^(\d{4})-(\d{2})-(\d{2})$/.exec(text) + if (matchedDateKey) { + return new Date( + Number(matchedDateKey[1]), + Number(matchedDateKey[2]) - 1, + Number(matchedDateKey[3]), + ) + } + + return new Date(text) +} + +function normalizeLogRetentionDays(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_RETENTION_DAYS + } + + return Math.max(1, Math.floor(parsed)) +} + +function shouldDeleteLogFileByDate(fileName: unknown, cutoffDateKey: string): boolean { + if (LEGACY_LOG_FILES.has(String(fileName || '').trim())) { + return true + } + + const matched = /^([a-z0-9-]{1,40})-(\d{4}-\d{2}-\d{2})\.log$/.exec(String(fileName || '').trim()) + + if (!matched) { + return false + } + + return String(matched[2] || '') < cutoffDateKey +} + +function isLogLevel(value: string): value is LogLevel { + return ['debug', 'info', 'warn', 'error'].includes(value) +} diff --git a/log-optimization-artifacts/DIFF_FILE.patch b/log-optimization-artifacts/DIFF_FILE.patch new file mode 100644 index 00000000..03e67789 --- /dev/null +++ b/log-optimization-artifacts/DIFF_FILE.patch @@ -0,0 +1,14 @@ +Log volume optimization diff summary + +1. apps/backend/src/middleware/access-log.ts + - Successful GET/HEAD responses (2xx/3xx) now use DEBUG. + - Writes and all 4xx/5xx responses remain INFO. + +2. apps/backend/src/utils/logger.ts + - Appends rotate at LOG_MAX_FILE_SIZE_MB (default 20MB). + - Keeps LOG_MAX_FILES (default 5) files per channel/date. + - Rotated files are included in retention cleanup. + +3. Configuration/docs/tests + - Added LOG_MAX_FILE_SIZE_MB and LOG_MAX_FILES to env overrides, + Compose files, examples, runtime types, backend README, and tests. diff --git a/log-optimization-artifacts/MODIFIED_FILE.ts b/log-optimization-artifacts/MODIFIED_FILE.ts new file mode 100644 index 00000000..bd7e4b23 --- /dev/null +++ b/log-optimization-artifacts/MODIFIED_FILE.ts @@ -0,0 +1,757 @@ +import fs from 'node:fs/promises' +import path from 'node:path' +import process from 'node:process' +import util from 'node:util' + +import { PROJECT_ROOT, runtimeConfig } from '../config/runtime.js' +import type { HttpErrorLike } from './http.js' +import { maskSecret } from './masking.js' +import { asJsonObject } from '../types/json.js' + +type LogLevel = 'debug' | 'info' | 'warn' | 'error' +type LogChannel = 'app' | 'integration' +type LogDetail = unknown +type InlineFields = Record +type ExternalHttpPacketDetail = Record +type LogEntry = { + time: string + level: LogLevel + scope: string + message: string + pid: number + detail?: unknown +} + +const LOG_LEVEL_PRIORITY: Record = { + debug: 10, + info: 20, + warn: 30, + error: 40, +} + +const LEVEL_LABELS: Record = { + debug: 'DEBUG', + info: 'INFO ', + warn: 'WARN ', + error: 'ERROR', +} + +const ANSI = { + reset: '\u001B[0m', + dim: '\u001B[2m', + bold: '\u001B[1m', + gray: '\u001B[90m', + cyan: '\u001B[36m', + blue: '\u001B[34m', + yellow: '\u001B[33m', + red: '\u001B[31m', +} + +const DATA_ROOT = resolveDataRoot() +const LOG_DIR = path.join(DATA_ROOT, 'logs') +const ACTIVE_LOG_LEVEL = normalizeLogLevel(runtimeConfig.logging?.level) +/** integration 通道独立阈值，默认 warn（仅错误/告警落盘） */ +const ACTIVE_INTEGRATION_LOG_LEVEL = normalizeLogLevel( + runtimeConfig.logging?.integrationLevel ?? 'warn', +) +const DEFAULT_LOG_RETENTION_DAYS = 30 +const LOG_RETENTION_DAYS = normalizeLogRetentionDays(runtimeConfig.logging?.retentionDays) +const DEFAULT_LOG_MAX_FILE_SIZE_MB = 20 +const DEFAULT_LOG_MAX_FILES = 5 +const LOG_MAX_FILE_SIZE_BYTES = + normalizeLogMaxFileSizeMb(runtimeConfig.logging?.maxFileSizeMb) * 1024 * 1024 +const LOG_MAX_FILES = normalizeLogMaxFiles(runtimeConfig.logging?.maxFiles) +const LEGACY_LOG_FILES = new Set(['app.log', 'integration.log']) +const SENSITIVE_KEY_PATTERN = + /token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardno|cardpwd|apikey|api_key|devicekey|session|x-sign|(?:^|[_-])sign(?:ature)?(?:[_-]|$)/i +const SENSITIVE_URL_PARAM_PATTERN = + /([?&](?:token|secret|password|passwd|pwd|cookie|authorization|api[_-]?key|device[_-]?key|sign|signature|code)=)([^&\s,;"']+)/gi +const SENSITIVE_JSON_FIELD_PATTERN = + /("(?:token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardNo|cardPwd|apiKey|api_key|deviceKey|device_key|session|x-sign|sign|signature)"\s*:\s*")([^"]*)(")/gi +const MAX_SANITIZE_DEPTH = 8 + +let writeQueue = Promise.resolve() +let lastCleanupDateKey = '' + +export function createRequestId(prefix = 'req'): string { + return `${prefix}-${Date.now().toString(36)}-${Math.random().toString(36).slice(2, 8)}` +} + +export function logDebug(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('debug', scope, message, detail) +} + +export function logInfo(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('info', scope, message, detail) +} + +export function logWarn(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('warn', scope, message, detail) +} + +export function logError(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('error', scope, message, detail) +} + +export function logIntegration( + scope: unknown, + message: unknown, + detail: LogDetail = undefined, + { level = 'info' }: { level?: LogLevel } = {}, +) { + // 默认 integration 阈值为 warn：失败类文案即使调用方传 info 也提升，避免漏记异常 + return writeLog(resolveIntegrationLogLevel(level, message), scope, message, detail, { + channel: 'integration', + }) +} + +function resolveIntegrationLogLevel(level: LogLevel, message: unknown): LogLevel { + const normalized = normalizeLogLevel(level) + if (normalized === 'warn' || normalized === 'error') { + return normalized + } + + const text = String(message || '') + if (/失败|异常|错误|超时|拒绝|expired|fail|error|timeout|denied/i.test(text)) { + return 'error' + } + + return normalized +} + +export function logExternalHttpPacket( + scope: unknown, + message: unknown, + detail: ExternalHttpPacketDetail = {}, + { level = 'info' }: { level?: LogLevel } = {}, +) { + return logIntegration(scope, message, normalizeExternalHttpPacketDetail(detail), { level }) +} + +export function logCapture( + scope: unknown, + message: unknown, + detail: LogDetail = undefined, + { channel = 'capture', sanitize = false }: { channel?: string; sanitize?: boolean } = {}, +): LogEntry | null { + const entry = { + time: new Date().toISOString(), + level: 'info' as LogLevel, + scope: String(scope || 'capture').trim() || 'capture', + message: String(message || '').trim() || '-', + pid: process.pid, + detail: normalizeLogValue(detail, sanitize !== false), + } + + enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time), sanitize !== false, true) + return entry +} + +function writeLog( + level: LogLevel, + scope: unknown, + message: unknown, + detail: LogDetail, + { channel = 'app' }: { channel?: LogChannel } = {}, +): LogEntry | null { + const configuredLevel = + channel === 'integration' ? ACTIVE_INTEGRATION_LOG_LEVEL : ACTIVE_LOG_LEVEL + if (!shouldWriteLog(level, configuredLevel)) { + return null + } + + const entry = { + time: new Date().toISOString(), + level: normalizeLogLevel(level), + scope: String(scope || 'app').trim() || 'app', + message: String(message || '').trim() || '-', + pid: process.pid, + detail: normalizeLogValue(detail), + } + + writeConsole(entry) + enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time), true) + return entry +} + +function enqueueFileWrite( + entry: LogEntry, + filePath: string, + sanitize: boolean, + jsonLine = false, +): void { + const line = jsonLine ? JSON.stringify(entry) : formatLogEntry(entry, { color: false, sanitize }) + const dateKey = extractLogDateKey(entry.time) + + writeQueue = writeQueue + .then(async () => { + await fs.mkdir(LOG_DIR, { recursive: true }) + await rotateLogFileIfNeeded(filePath, Buffer.byteLength(`${line}\n`, 'utf8')) + await fs.appendFile(filePath, `${line}\n`, 'utf8') + await cleanupExpiredLogsIfNeeded(dateKey) + }) + .catch((error) => { + const reason = error instanceof Error ? error.message : String(error || '未知错误') + console.error('[logger] failed to write log file:', reason) + }) +} + +function writeConsole(entry: LogEntry): void { + const logger = resolveConsoleMethod(entry.level) + logger(formatLogEntry(entry, { color: supportsAnsiColor() })) +} + +function resolveConsoleMethod(level: unknown) { + const normalized = normalizeLogLevel(level) + + if (normalized === 'error') { + return console.error + } + + if (normalized === 'warn') { + return console.warn + } + + return console.log +} + +export function normalizeLogLevel(level: unknown): LogLevel { + const normalized = String(level || '') + .trim() + .toLowerCase() + return isLogLevel(normalized) ? normalized : 'info' +} + +export function shouldWriteLog( + level: unknown, + configuredLevel: unknown = ACTIVE_LOG_LEVEL, +): boolean { + const normalizedLevel = normalizeLogLevel(level) + const normalizedConfigured = normalizeLogLevel(configuredLevel) + + return LOG_LEVEL_PRIORITY[normalizedLevel] >= LOG_LEVEL_PRIORITY[normalizedConfigured] +} + +export function formatLogEntry( + entry: Partial, + { color = false, sanitize = true }: { color?: boolean; sanitize?: boolean } = {}, +): string { + const normalizedEntry = { + time: String(entry?.time || new Date().toISOString()), + level: normalizeLogLevel(entry?.level), + scope: String(entry?.scope || 'app').trim() || 'app', + message: String(entry?.message || '').trim() || '-', + pid: Number(entry?.pid || process.pid), + detail: sanitize !== false ? sanitizeLogValue(entry?.detail) : entry?.detail, + } + const timestamp = colorize(formatLogTimestamp(normalizedEntry.time), ANSI.gray, color) + const level = colorize( + LEVEL_LABELS[normalizedEntry.level], + resolveLevelColor(normalizedEntry.level), + color, + ) + const scope = colorize(normalizedEntry.scope, ANSI.cyan, color) + const message = colorize(normalizedEntry.message, ANSI.bold, color) + const separator = colorize('|', ANSI.dim, color) + const { inline, block } = splitDetailPayload(normalizedEntry.detail) + const inlineFields = formatInlineFields({ + pid: normalizedEntry.pid, + ...inline, + }) + const firstLine = [timestamp, level, scope, message, separator, inlineFields] + .filter(Boolean) + .join(' ') + + if (!block) { + return firstLine + } + + const inspected = util.inspect(block, { + depth: 8, + colors: color, + compact: false, + breakLength: 120, + maxArrayLength: 100, + }) + + return `${firstLine}\n${indentBlock(inspected, ' ')}` +} + +export function resolveLogFilePath(channel = 'app', time = new Date().toISOString()): string { + const normalizedChannel = normalizeLogChannelName(channel) + return path.join(LOG_DIR, `${normalizedChannel}-${extractLogDateKey(time)}.log`) +} + +function normalizeLogChannelName(value: unknown): string { + const normalized = String(value || '') + .trim() + .toLowerCase() + if (!normalized) { + return 'app' + } + if (normalized === 'integration') { + return 'integration' + } + return /^[a-z0-9-]{1,40}$/.test(normalized) ? normalized : 'app' +} + +export function resolveExpiredLogFilenames( + fileNames: string[] = [], + referenceTime = new Date().toISOString(), + retentionDays = LOG_RETENTION_DAYS, +): string[] { + const normalizedRetentionDays = normalizeLogRetentionDays(retentionDays) + const cutoffDateKey = toDateKey(offsetDate(referenceTime, -(normalizedRetentionDays - 1))) + + return (Array.isArray(fileNames) ? fileNames : []).filter((fileName) => + shouldDeleteLogFileByDate(fileName, cutoffDateKey), + ) +} + +export function formatLogTimestamp(value: unknown): string { + const date = new Date(value instanceof Date ? value : String(value || '')) + + if (Number.isNaN(date.getTime())) { + return String(value || '').trim() || new Date().toISOString() + } + + return `${formatLocalDate(date)} ${formatLocalTime(date)}.${String(date.getMilliseconds()).padStart(3, '0')} ${formatTimezoneOffset(date)}` +} + +function resolveDataRoot(): string { + const configured = String(runtimeConfig.data?.root || '').trim() + return configured ? path.resolve(configured) : path.resolve(PROJECT_ROOT, 'data') +} + +function normalizeLogValue(value: unknown, sanitize = true): unknown { + if (typeof value === 'undefined') { + return undefined + } + + const normalizeCurrent = (current: unknown): unknown => { + if (current instanceof Error) { + const currentError = current as Error & HttpErrorLike + return { + name: currentError.name, + message: sanitize ? sanitizeLogString(currentError.message) : currentError.message, + stack: sanitize ? sanitizeLogString(currentError.stack) : currentError.stack, + statusCode: currentError.statusCode, + errorCode: currentError.errorCode, + context: sanitize ? sanitizeLogValue(currentError.context) : currentError.context, + } + } + + if (typeof current === 'bigint') { + return String(current) + } + + return current + } + + try { + return sanitize + ? sanitizeLogValue( + JSON.parse(JSON.stringify(value, (_key, current) => normalizeCurrent(current))), + ) + : JSON.parse(JSON.stringify(value, (_key, current) => normalizeCurrent(current))) + } catch { + return sanitize ? sanitizeLogString(String(value)) : String(value) + } +} + +function sanitizeLogValue(value: unknown, key = '', depth = 0): unknown { + if (typeof value === 'undefined') { + return undefined + } + + if (value === null) { + return null + } + + if (isSensitiveLogKey(key)) { + return maskSecret(value) + } + + if (typeof value === 'string') { + return sanitizeLogString(value) + } + + if (typeof value === 'number' || typeof value === 'boolean') { + return value + } + + if (typeof value === 'bigint') { + return String(value) + } + + if (depth >= MAX_SANITIZE_DEPTH) { + return '[MaxDepth]' + } + + if (Array.isArray(value)) { + return value.map((item) => sanitizeLogValue(item, key, depth + 1)) + } + + if (value && typeof value === 'object') { + return Object.fromEntries( + Object.entries(value).map(([currentKey, currentValue]) => [ + currentKey, + sanitizeLogValue(currentValue, currentKey, depth + 1), + ]), + ) + } + + return sanitizeLogString(String(value)) +} + +function sanitizeLogString(value: unknown): string { + return String(value || '') + .replace( + /(Bearer\s+)([A-Za-z0-9._~+/=-]+)/gi, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) + .replace( + SENSITIVE_URL_PARAM_PATTERN, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) + .replace( + SENSITIVE_JSON_FIELD_PATTERN, + (_matched, prefix, secret, suffix) => `${prefix}${maskSecret(secret)}${suffix}`, + ) + .replace( + /\b((?:token|secret|password|passwd|pwd|cookie|authorization|api[_-]?key|device[_-]?key)=)([^&\s,;]+)/gi, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) +} + +function isSensitiveLogKey(key: unknown): boolean { + return SENSITIVE_KEY_PATTERN.test(String(key || '').trim()) +} + +function normalizeExternalHttpPacketDetail( + detail: ExternalHttpPacketDetail, +): ExternalHttpPacketDetail { + const source = asJsonObject(detail) + const normalized: ExternalHttpPacketDetail = {} + + for (const [key, value] of Object.entries(source)) { + normalized[key] = normalizeExternalPacketValue(value) + } + + return normalized +} + +function normalizeExternalPacketValue(value: unknown): unknown { + if (typeof value === 'undefined' || value === null) { + return value + } + + if (value instanceof Error) { + const currentError = value as Error & HttpErrorLike + return { + name: value.name, + message: value.message, + stack: value.stack, + statusCode: currentError.statusCode, + errorCode: currentError.errorCode, + context: normalizeExternalPacketValue(currentError.context), + } + } + + if (typeof value === 'string') { + return value + } + + if (typeof value === 'number' || typeof value === 'boolean' || typeof value === 'bigint') { + return value + } + + if (Array.isArray(value)) { + return value.map((item) => normalizeExternalPacketValue(item)) + } + + if (value && typeof value === 'object') { + return Object.fromEntries( + Object.entries(value).map(([key, currentValue]) => [ + key, + normalizeExternalPacketValue(currentValue), + ]), + ) + } + + return String(value) +} + +function splitDetailPayload(detail: unknown): { inline: InlineFields; block: unknown | null } { + if (typeof detail === 'undefined') { + return { + inline: {}, + block: null, + } + } + + if (isScalarLogValue(detail)) { + return { + inline: { detail }, + block: null, + } + } + + if (Array.isArray(detail)) { + return { + inline: {}, + block: detail, + } + } + + if (detail && typeof detail === 'object') { + const inline: InlineFields = {} + const block: Record = {} + + for (const [key, value] of Object.entries(detail)) { + if (isScalarLogValue(value)) { + inline[key] = value + continue + } + + block[key] = value + } + + return { + inline, + block: Object.keys(block).length > 0 ? block : null, + } + } + + return { + inline: { detail: String(detail) }, + block: null, + } +} + +function formatInlineFields(fields: InlineFields): string { + return Object.entries(fields) + .filter(([, value]) => typeof value !== 'undefined' && value !== '') + .map(([key, value]) => `${key}=${formatInlineValue(value)}`) + .join(' ') +} + +function formatInlineValue(value: unknown): string { + if (value === null) { + return 'null' + } + + if (typeof value === 'number' || typeof value === 'boolean') { + return String(value) + } + + const text = String(value || '') + return /^[A-Za-z0-9_./:@-]+$/.test(text) ? text : JSON.stringify(text) +} + +function isScalarLogValue(value: unknown): value is string | number | boolean | null { + return value === null || ['string', 'number', 'boolean'].includes(typeof value) +} + +function indentBlock(text: unknown, indent: string): string { + return String(text || '') + .split('\n') + .map((line) => `${indent}${line}`) + .join('\n') +} + +function supportsAnsiColor(): boolean { + return process.env.NO_COLOR !== '1' && Boolean(process.stdout.isTTY || process.stderr.isTTY) +} + +function resolveLevelColor(level: unknown): string { + switch (normalizeLogLevel(level)) { + case 'debug': + return ANSI.blue + case 'warn': + return ANSI.yellow + case 'error': + return ANSI.red + default: + return ANSI.cyan + } +} + +function colorize(text: string, ansiCode: string, enabled: boolean): string { + if (!enabled || !ansiCode) { + return text + } + + return `${ansiCode}${text}${ANSI.reset}` +} + +function formatLocalDate(date: Date): string { + return `${date.getFullYear()}-${String(date.getMonth() + 1).padStart(2, '0')}-${String(date.getDate()).padStart(2, '0')}` +} + +function formatLocalTime(date: Date): string { + return `${String(date.getHours()).padStart(2, '0')}:${String(date.getMinutes()).padStart(2, '0')}:${String(date.getSeconds()).padStart(2, '0')}` +} + +function formatTimezoneOffset(date: Date): string { + const totalMinutes = -date.getTimezoneOffset() + const sign = totalMinutes >= 0 ? '+' : '-' + const absoluteMinutes = Math.abs(totalMinutes) + const hours = String(Math.floor(absoluteMinutes / 60)).padStart(2, '0') + const minutes = String(absoluteMinutes % 60).padStart(2, '0') + return `${sign}${hours}:${minutes}` +} + +async function cleanupExpiredLogsIfNeeded(dateKey: string): Promise { + if (!dateKey || dateKey === lastCleanupDateKey) { + return + } + + lastCleanupDateKey = dateKey + + try { + const fileNames = await fs.readdir(LOG_DIR) + const expired = resolveExpiredLogFilenames(fileNames, dateKey, LOG_RETENTION_DAYS) + await Promise.all( + expired.map((fileName) => fs.rm(path.join(LOG_DIR, fileName), { force: true })), + ) + } catch (error) { + const reason = error instanceof Error ? error.message : String(error || '未知错误') + console.error('[logger] failed to cleanup old log files:', reason) + } +} + +function extractLogDateKey(time: unknown): string { + return toDateKey(time) +} + +function toDateKey(value: unknown): string { + const date = parseLogDate(value) + + if (Number.isNaN(date.getTime())) { + return formatLocalDate(new Date()) + } + + return formatLocalDate(date) +} + +function offsetDate(value: unknown, offsetDays: unknown): Date { + const date = parseLogDate(value) + if (Number.isNaN(date.getTime())) { + return new Date() + } + + date.setDate(date.getDate() + Number(offsetDays || 0)) + return date +} + +function parseLogDate(value: unknown): Date { + if (value instanceof Date) { + return new Date(value.getTime()) + } + + const text = String(value || '').trim() + const matchedDateKey = /^(\d{4})-(\d{2})-(\d{2})$/.exec(text) + if (matchedDateKey) { + return new Date( + Number(matchedDateKey[1]), + Number(matchedDateKey[2]) - 1, + Number(matchedDateKey[3]), + ) + } + + return new Date(text) +} + +function normalizeLogRetentionDays(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_RETENTION_DAYS + } + + return Math.max(1, Math.floor(parsed)) +} + +function normalizeLogMaxFileSizeMb(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_MAX_FILE_SIZE_MB + } + + return Math.max(1, Math.floor(parsed)) +} + +function normalizeLogMaxFiles(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_MAX_FILES + } + + return Math.max(2, Math.floor(parsed)) +} + +async function rotateLogFileIfNeeded(filePath: string, nextLineBytes: number): Promise { + if (!filePath.endsWith('.log') || LOG_MAX_FILE_SIZE_BYTES <= 0) { + return + } + + let currentSize = 0 + try { + currentSize = (await fs.stat(filePath)).size + } catch (error) { + if (isFileMissingError(error)) { + return + } + throw error + } + + if (currentSize === 0 || currentSize + nextLineBytes <= LOG_MAX_FILE_SIZE_BYTES) { + return + } + + for (let index = LOG_MAX_FILES - 1; index >= 1; index -= 1) { + await renameIfPresent( + rotatedLogFilePath(filePath, index), + rotatedLogFilePath(filePath, index + 1), + ) + } + await renameIfPresent(filePath, rotatedLogFilePath(filePath, 1)) +} + +function rotatedLogFilePath(filePath: string, index: number): string { + return filePath.replace(/\.log$/, `.${index}.log`) +} + +async function renameIfPresent(source: string, target: string): Promise { + try { + await fs.rename(source, target) + } catch (error) { + if (!isFileMissingError(error)) { + throw error + } + } +} + +function isFileMissingError(error: unknown): boolean { + return Boolean(error && typeof error === 'object' && 'code' in error && error.code === 'ENOENT') +} + +function shouldDeleteLogFileByDate(fileName: unknown, cutoffDateKey: string): boolean { + if (LEGACY_LOG_FILES.has(String(fileName || '').trim())) { + return true + } + + const matched = /^([a-z0-9-]{1,40})-(\d{4}-\d{2}-\d{2})(?:\.\d+)?\.log$/.exec( + String(fileName || '').trim(), + ) + + if (!matched) { + return false + } + + return String(matched[2] || '') < cutoffDateKey +} + +function isLogLevel(value: string): value is LogLevel { + return ['debug', 'info', 'warn', 'error'].includes(value) +} diff --git a/log-optimization-artifacts/ROLLBACK.sh b/log-optimization-artifacts/ROLLBACK.sh new file mode 100755 index 00000000..7f3b7f1d --- /dev/null +++ b/log-optimization-artifacts/ROLLBACK.sh @@ -0,0 +1,8 @@ +#!/usr/bin/env bash +set -euo pipefail + +ROOT="${1:?usage: ROLLBACK.sh }" +SCRIPT_DIR="$(CDPATH= cd -- "$(dirname -- "$0")" && pwd)" + +cp "$SCRIPT_DIR/BASELINE_FILE.ts" "$ROOT/apps/backend/src/utils/logger.ts" +printf 'restored logger baseline in %s\n' "$ROOT" diff --git a/log-optimization-artifacts/VERIFICATION.txt b/log-optimization-artifacts/VERIFICATION.txt new file mode 100644 index 00000000..c56ff3a3 --- /dev/null +++ b/log-optimization-artifacts/VERIFICATION.txt @@ -0,0 +1,44 @@ +Log volume optimization verification + +Changed branch/fields: +- access log level: successful GET/HEAD 2xx/3xx -> DEBUG; writes and 4xx/5xx -> INFO +- logging.maxFileSizeMb / LOG_MAX_FILE_SIZE_MB: default 20 +- logging.maxFiles / LOG_MAX_FILES: default 5 +- rotated files use app-YYYY-MM-DD.N.log and participate in retention cleanup + +Source evidence: +- Input log: /Users/yml/Downloads/logs/app-2026-08-29.log +- Baseline: 2,080,480 lines, 767,799,564 bytes (732MB) +- Access logs: 1,412,784 lines; successful access logs: 1,406,234 lines / 727,296,842 bytes +- Largest paths: /api/v1/files/object 555,995; /api/v1/worker/hall/orders 446,763 +- Applying the new GET/HEAD success filter to this sample would skip 1,354,940 lines / 702,650,714 bytes, a simulated 91.51% reduction. + +Artifacts: +- MODIFIED_FILE: /Users/yml/codes/order_site/log-optimization-artifacts/MODIFIED_FILE.ts +- DIFF_FILE: /Users/yml/codes/order_site/log-optimization-artifacts/DIFF_FILE.patch +- VERIFICATION.txt: /Users/yml/codes/order_site/log-optimization-artifacts/VERIFICATION.txt +- ROLLBACK.sh: /Users/yml/codes/order_site/log-optimization-artifacts/ROLLBACK.sh + +BASELINE +Command: git show HEAD:apps/backend/src/utils/logger.ts > log-optimization-artifacts/BASELINE_FILE.ts +Input: HEAD logger source before this change +Literal result: SHA-256 b197508d56c00362001ea58f4cdcff465d396c3d1a1127f53328dd791a8bdb57; exit status 0 + +MODIFIED +Command: node --import tsx --test src/middleware/access-log.test.ts src/utils/logger.test.ts src/config/env-overrides.test.ts src/config/runtime-validation.test.ts +Input: modified backend logger/access/config sources +Literal result: tests 28; pass 28; fail 0; skipped 0; exit status 0 + +Command: npm run lint:check && npm run build +Input: modified backend source tree +Literal result: ESLint passed; TypeScript build completed; exit status 0 + +Command: npm run check +Input: modified backend source tree +Literal result: format, SQL guard, lint, typecheck passed; tests 377; pass 374; fail 1; skipped 2; existing failure at src/repositories/worker-platform-repo.test.ts:115 (unrelated blank-search SQL assertion); exit status 1 + +ROLLBACK +Command: log-optimization-artifacts/ROLLBACK.sh log-optimization-artifacts/rollback-copy +Input: independent copy containing MODIFIED_FILE.ts +Literal result: restored logger baseline in log-optimization-artifacts/rollback-copy; restored SHA-256 b197508d56c00362001ea58f4cdcff465d396c3d1a1127f53328dd791a8bdb57; exit status 0 +Restored behavior/status: rollback-copy logger matches baseline; working source remains modified. diff --git a/log-optimization-artifacts/rollback-copy/apps/backend/src/utils/logger.ts b/log-optimization-artifacts/rollback-copy/apps/backend/src/utils/logger.ts new file mode 100644 index 00000000..efeb1f97 --- /dev/null +++ b/log-optimization-artifacts/rollback-copy/apps/backend/src/utils/logger.ts @@ -0,0 +1,685 @@ +import fs from 'node:fs/promises' +import path from 'node:path' +import process from 'node:process' +import util from 'node:util' + +import { PROJECT_ROOT, runtimeConfig } from '../config/runtime.js' +import type { HttpErrorLike } from './http.js' +import { maskSecret } from './masking.js' +import { asJsonObject } from '../types/json.js' + +type LogLevel = 'debug' | 'info' | 'warn' | 'error' +type LogChannel = 'app' | 'integration' +type LogDetail = unknown +type InlineFields = Record +type ExternalHttpPacketDetail = Record +type LogEntry = { + time: string + level: LogLevel + scope: string + message: string + pid: number + detail?: unknown +} + +const LOG_LEVEL_PRIORITY: Record = { + debug: 10, + info: 20, + warn: 30, + error: 40, +} + +const LEVEL_LABELS: Record = { + debug: 'DEBUG', + info: 'INFO ', + warn: 'WARN ', + error: 'ERROR', +} + +const ANSI = { + reset: '\u001B[0m', + dim: '\u001B[2m', + bold: '\u001B[1m', + gray: '\u001B[90m', + cyan: '\u001B[36m', + blue: '\u001B[34m', + yellow: '\u001B[33m', + red: '\u001B[31m', +} + +const DATA_ROOT = resolveDataRoot() +const LOG_DIR = path.join(DATA_ROOT, 'logs') +const ACTIVE_LOG_LEVEL = normalizeLogLevel(runtimeConfig.logging?.level) +/** integration 通道独立阈值，默认 warn（仅错误/告警落盘） */ +const ACTIVE_INTEGRATION_LOG_LEVEL = normalizeLogLevel( + runtimeConfig.logging?.integrationLevel ?? 'warn', +) +const DEFAULT_LOG_RETENTION_DAYS = 30 +const LOG_RETENTION_DAYS = normalizeLogRetentionDays(runtimeConfig.logging?.retentionDays) +const LEGACY_LOG_FILES = new Set(['app.log', 'integration.log']) +const SENSITIVE_KEY_PATTERN = + /token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardno|cardpwd|apikey|api_key|devicekey|session|x-sign|(?:^|[_-])sign(?:ature)?(?:[_-]|$)/i +const SENSITIVE_URL_PARAM_PATTERN = + /([?&](?:token|secret|password|passwd|pwd|cookie|authorization|api[_-]?key|device[_-]?key|sign|signature|code)=)([^&\s,;"']+)/gi +const SENSITIVE_JSON_FIELD_PATTERN = + /("(?:token|secret|password|passwd|pwd|cookie|authorization|credential|card|cards|cardNo|cardPwd|apiKey|api_key|deviceKey|device_key|session|x-sign|sign|signature)"\s*:\s*")([^"]*)(")/gi +const MAX_SANITIZE_DEPTH = 8 + +let writeQueue = Promise.resolve() +let lastCleanupDateKey = '' + +export function createRequestId(prefix = 'req'): string { + return `${prefix}-${Date.now().toString(36)}-${Math.random().toString(36).slice(2, 8)}` +} + +export function logDebug(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('debug', scope, message, detail) +} + +export function logInfo(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('info', scope, message, detail) +} + +export function logWarn(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('warn', scope, message, detail) +} + +export function logError(scope: unknown, message: unknown, detail: LogDetail = undefined) { + return writeLog('error', scope, message, detail) +} + +export function logIntegration( + scope: unknown, + message: unknown, + detail: LogDetail = undefined, + { level = 'info' }: { level?: LogLevel } = {}, +) { + // 默认 integration 阈值为 warn：失败类文案即使调用方传 info 也提升，避免漏记异常 + return writeLog(resolveIntegrationLogLevel(level, message), scope, message, detail, { + channel: 'integration', + }) +} + +function resolveIntegrationLogLevel(level: LogLevel, message: unknown): LogLevel { + const normalized = normalizeLogLevel(level) + if (normalized === 'warn' || normalized === 'error') { + return normalized + } + + const text = String(message || '') + if (/失败|异常|错误|超时|拒绝|expired|fail|error|timeout|denied/i.test(text)) { + return 'error' + } + + return normalized +} + +export function logExternalHttpPacket( + scope: unknown, + message: unknown, + detail: ExternalHttpPacketDetail = {}, + { level = 'info' }: { level?: LogLevel } = {}, +) { + return logIntegration(scope, message, normalizeExternalHttpPacketDetail(detail), { level }) +} + +export function logCapture( + scope: unknown, + message: unknown, + detail: LogDetail = undefined, + { channel = 'capture', sanitize = false }: { channel?: string; sanitize?: boolean } = {}, +): LogEntry | null { + const entry = { + time: new Date().toISOString(), + level: 'info' as LogLevel, + scope: String(scope || 'capture').trim() || 'capture', + message: String(message || '').trim() || '-', + pid: process.pid, + detail: normalizeLogValue(detail, sanitize !== false), + } + + enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time), sanitize !== false, true) + return entry +} + +function writeLog( + level: LogLevel, + scope: unknown, + message: unknown, + detail: LogDetail, + { channel = 'app' }: { channel?: LogChannel } = {}, +): LogEntry | null { + const configuredLevel = + channel === 'integration' ? ACTIVE_INTEGRATION_LOG_LEVEL : ACTIVE_LOG_LEVEL + if (!shouldWriteLog(level, configuredLevel)) { + return null + } + + const entry = { + time: new Date().toISOString(), + level: normalizeLogLevel(level), + scope: String(scope || 'app').trim() || 'app', + message: String(message || '').trim() || '-', + pid: process.pid, + detail: normalizeLogValue(detail), + } + + writeConsole(entry) + enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time), true) + return entry +} + +function enqueueFileWrite( + entry: LogEntry, + filePath: string, + sanitize: boolean, + jsonLine = false, +): void { + const line = jsonLine ? JSON.stringify(entry) : formatLogEntry(entry, { color: false, sanitize }) + const dateKey = extractLogDateKey(entry.time) + + writeQueue = writeQueue + .then(async () => { + await fs.mkdir(LOG_DIR, { recursive: true }) + await fs.appendFile(filePath, `${line}\n`, 'utf8') + await cleanupExpiredLogsIfNeeded(dateKey) + }) + .catch((error) => { + const reason = error instanceof Error ? error.message : String(error || '未知错误') + console.error('[logger] failed to write log file:', reason) + }) +} + +function writeConsole(entry: LogEntry): void { + const logger = resolveConsoleMethod(entry.level) + logger(formatLogEntry(entry, { color: supportsAnsiColor() })) +} + +function resolveConsoleMethod(level: unknown) { + const normalized = normalizeLogLevel(level) + + if (normalized === 'error') { + return console.error + } + + if (normalized === 'warn') { + return console.warn + } + + return console.log +} + +export function normalizeLogLevel(level: unknown): LogLevel { + const normalized = String(level || '') + .trim() + .toLowerCase() + return isLogLevel(normalized) ? normalized : 'info' +} + +export function shouldWriteLog( + level: unknown, + configuredLevel: unknown = ACTIVE_LOG_LEVEL, +): boolean { + const normalizedLevel = normalizeLogLevel(level) + const normalizedConfigured = normalizeLogLevel(configuredLevel) + + return LOG_LEVEL_PRIORITY[normalizedLevel] >= LOG_LEVEL_PRIORITY[normalizedConfigured] +} + +export function formatLogEntry( + entry: Partial, + { color = false, sanitize = true }: { color?: boolean; sanitize?: boolean } = {}, +): string { + const normalizedEntry = { + time: String(entry?.time || new Date().toISOString()), + level: normalizeLogLevel(entry?.level), + scope: String(entry?.scope || 'app').trim() || 'app', + message: String(entry?.message || '').trim() || '-', + pid: Number(entry?.pid || process.pid), + detail: sanitize !== false ? sanitizeLogValue(entry?.detail) : entry?.detail, + } + const timestamp = colorize(formatLogTimestamp(normalizedEntry.time), ANSI.gray, color) + const level = colorize( + LEVEL_LABELS[normalizedEntry.level], + resolveLevelColor(normalizedEntry.level), + color, + ) + const scope = colorize(normalizedEntry.scope, ANSI.cyan, color) + const message = colorize(normalizedEntry.message, ANSI.bold, color) + const separator = colorize('|', ANSI.dim, color) + const { inline, block } = splitDetailPayload(normalizedEntry.detail) + const inlineFields = formatInlineFields({ + pid: normalizedEntry.pid, + ...inline, + }) + const firstLine = [timestamp, level, scope, message, separator, inlineFields] + .filter(Boolean) + .join(' ') + + if (!block) { + return firstLine + } + + const inspected = util.inspect(block, { + depth: 8, + colors: color, + compact: false, + breakLength: 120, + maxArrayLength: 100, + }) + + return `${firstLine}\n${indentBlock(inspected, ' ')}` +} + +export function resolveLogFilePath(channel = 'app', time = new Date().toISOString()): string { + const normalizedChannel = normalizeLogChannelName(channel) + return path.join(LOG_DIR, `${normalizedChannel}-${extractLogDateKey(time)}.log`) +} + +function normalizeLogChannelName(value: unknown): string { + const normalized = String(value || '') + .trim() + .toLowerCase() + if (!normalized) { + return 'app' + } + if (normalized === 'integration') { + return 'integration' + } + return /^[a-z0-9-]{1,40}$/.test(normalized) ? normalized : 'app' +} + +export function resolveExpiredLogFilenames( + fileNames: string[] = [], + referenceTime = new Date().toISOString(), + retentionDays = LOG_RETENTION_DAYS, +): string[] { + const normalizedRetentionDays = normalizeLogRetentionDays(retentionDays) + const cutoffDateKey = toDateKey(offsetDate(referenceTime, -(normalizedRetentionDays - 1))) + + return (Array.isArray(fileNames) ? fileNames : []).filter((fileName) => + shouldDeleteLogFileByDate(fileName, cutoffDateKey), + ) +} + +export function formatLogTimestamp(value: unknown): string { + const date = new Date(value instanceof Date ? value : String(value || '')) + + if (Number.isNaN(date.getTime())) { + return String(value || '').trim() || new Date().toISOString() + } + + return `${formatLocalDate(date)} ${formatLocalTime(date)}.${String(date.getMilliseconds()).padStart(3, '0')} ${formatTimezoneOffset(date)}` +} + +function resolveDataRoot(): string { + const configured = String(runtimeConfig.data?.root || '').trim() + return configured ? path.resolve(configured) : path.resolve(PROJECT_ROOT, 'data') +} + +function normalizeLogValue(value: unknown, sanitize = true): unknown { + if (typeof value === 'undefined') { + return undefined + } + + const normalizeCurrent = (current: unknown): unknown => { + if (current instanceof Error) { + const currentError = current as Error & HttpErrorLike + return { + name: currentError.name, + message: sanitize ? sanitizeLogString(currentError.message) : currentError.message, + stack: sanitize ? sanitizeLogString(currentError.stack) : currentError.stack, + statusCode: currentError.statusCode, + errorCode: currentError.errorCode, + context: sanitize ? sanitizeLogValue(currentError.context) : currentError.context, + } + } + + if (typeof current === 'bigint') { + return String(current) + } + + return current + } + + try { + return sanitize + ? sanitizeLogValue( + JSON.parse(JSON.stringify(value, (_key, current) => normalizeCurrent(current))), + ) + : JSON.parse(JSON.stringify(value, (_key, current) => normalizeCurrent(current))) + } catch { + return sanitize ? sanitizeLogString(String(value)) : String(value) + } +} + +function sanitizeLogValue(value: unknown, key = '', depth = 0): unknown { + if (typeof value === 'undefined') { + return undefined + } + + if (value === null) { + return null + } + + if (isSensitiveLogKey(key)) { + return maskSecret(value) + } + + if (typeof value === 'string') { + return sanitizeLogString(value) + } + + if (typeof value === 'number' || typeof value === 'boolean') { + return value + } + + if (typeof value === 'bigint') { + return String(value) + } + + if (depth >= MAX_SANITIZE_DEPTH) { + return '[MaxDepth]' + } + + if (Array.isArray(value)) { + return value.map((item) => sanitizeLogValue(item, key, depth + 1)) + } + + if (value && typeof value === 'object') { + return Object.fromEntries( + Object.entries(value).map(([currentKey, currentValue]) => [ + currentKey, + sanitizeLogValue(currentValue, currentKey, depth + 1), + ]), + ) + } + + return sanitizeLogString(String(value)) +} + +function sanitizeLogString(value: unknown): string { + return String(value || '') + .replace( + /(Bearer\s+)([A-Za-z0-9._~+/=-]+)/gi, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) + .replace( + SENSITIVE_URL_PARAM_PATTERN, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) + .replace( + SENSITIVE_JSON_FIELD_PATTERN, + (_matched, prefix, secret, suffix) => `${prefix}${maskSecret(secret)}${suffix}`, + ) + .replace( + /\b((?:token|secret|password|passwd|pwd|cookie|authorization|api[_-]?key|device[_-]?key)=)([^&\s,;]+)/gi, + (_matched, prefix, secret) => `${prefix}${maskSecret(secret)}`, + ) +} + +function isSensitiveLogKey(key: unknown): boolean { + return SENSITIVE_KEY_PATTERN.test(String(key || '').trim()) +} + +function normalizeExternalHttpPacketDetail( + detail: ExternalHttpPacketDetail, +): ExternalHttpPacketDetail { + const source = asJsonObject(detail) + const normalized: ExternalHttpPacketDetail = {} + + for (const [key, value] of Object.entries(source)) { + normalized[key] = normalizeExternalPacketValue(value) + } + + return normalized +} + +function normalizeExternalPacketValue(value: unknown): unknown { + if (typeof value === 'undefined' || value === null) { + return value + } + + if (value instanceof Error) { + const currentError = value as Error & HttpErrorLike + return { + name: value.name, + message: value.message, + stack: value.stack, + statusCode: currentError.statusCode, + errorCode: currentError.errorCode, + context: normalizeExternalPacketValue(currentError.context), + } + } + + if (typeof value === 'string') { + return value + } + + if (typeof value === 'number' || typeof value === 'boolean' || typeof value === 'bigint') { + return value + } + + if (Array.isArray(value)) { + return value.map((item) => normalizeExternalPacketValue(item)) + } + + if (value && typeof value === 'object') { + return Object.fromEntries( + Object.entries(value).map(([key, currentValue]) => [ + key, + normalizeExternalPacketValue(currentValue), + ]), + ) + } + + return String(value) +} + +function splitDetailPayload(detail: unknown): { inline: InlineFields; block: unknown | null } { + if (typeof detail === 'undefined') { + return { + inline: {}, + block: null, + } + } + + if (isScalarLogValue(detail)) { + return { + inline: { detail }, + block: null, + } + } + + if (Array.isArray(detail)) { + return { + inline: {}, + block: detail, + } + } + + if (detail && typeof detail === 'object') { + const inline: InlineFields = {} + const block: Record = {} + + for (const [key, value] of Object.entries(detail)) { + if (isScalarLogValue(value)) { + inline[key] = value + continue + } + + block[key] = value + } + + return { + inline, + block: Object.keys(block).length > 0 ? block : null, + } + } + + return { + inline: { detail: String(detail) }, + block: null, + } +} + +function formatInlineFields(fields: InlineFields): string { + return Object.entries(fields) + .filter(([, value]) => typeof value !== 'undefined' && value !== '') + .map(([key, value]) => `${key}=${formatInlineValue(value)}`) + .join(' ') +} + +function formatInlineValue(value: unknown): string { + if (value === null) { + return 'null' + } + + if (typeof value === 'number' || typeof value === 'boolean') { + return String(value) + } + + const text = String(value || '') + return /^[A-Za-z0-9_./:@-]+$/.test(text) ? text : JSON.stringify(text) +} + +function isScalarLogValue(value: unknown): value is string | number | boolean | null { + return value === null || ['string', 'number', 'boolean'].includes(typeof value) +} + +function indentBlock(text: unknown, indent: string): string { + return String(text || '') + .split('\n') + .map((line) => `${indent}${line}`) + .join('\n') +} + +function supportsAnsiColor(): boolean { + return process.env.NO_COLOR !== '1' && Boolean(process.stdout.isTTY || process.stderr.isTTY) +} + +function resolveLevelColor(level: unknown): string { + switch (normalizeLogLevel(level)) { + case 'debug': + return ANSI.blue + case 'warn': + return ANSI.yellow + case 'error': + return ANSI.red + default: + return ANSI.cyan + } +} + +function colorize(text: string, ansiCode: string, enabled: boolean): string { + if (!enabled || !ansiCode) { + return text + } + + return `${ansiCode}${text}${ANSI.reset}` +} + +function formatLocalDate(date: Date): string { + return `${date.getFullYear()}-${String(date.getMonth() + 1).padStart(2, '0')}-${String(date.getDate()).padStart(2, '0')}` +} + +function formatLocalTime(date: Date): string { + return `${String(date.getHours()).padStart(2, '0')}:${String(date.getMinutes()).padStart(2, '0')}:${String(date.getSeconds()).padStart(2, '0')}` +} + +function formatTimezoneOffset(date: Date): string { + const totalMinutes = -date.getTimezoneOffset() + const sign = totalMinutes >= 0 ? '+' : '-' + const absoluteMinutes = Math.abs(totalMinutes) + const hours = String(Math.floor(absoluteMinutes / 60)).padStart(2, '0') + const minutes = String(absoluteMinutes % 60).padStart(2, '0') + return `${sign}${hours}:${minutes}` +} + +async function cleanupExpiredLogsIfNeeded(dateKey: string): Promise { + if (!dateKey || dateKey === lastCleanupDateKey) { + return + } + + lastCleanupDateKey = dateKey + + try { + const fileNames = await fs.readdir(LOG_DIR) + const expired = resolveExpiredLogFilenames(fileNames, dateKey, LOG_RETENTION_DAYS) + await Promise.all( + expired.map((fileName) => fs.rm(path.join(LOG_DIR, fileName), { force: true })), + ) + } catch (error) { + const reason = error instanceof Error ? error.message : String(error || '未知错误') + console.error('[logger] failed to cleanup old log files:', reason) + } +} + +function extractLogDateKey(time: unknown): string { + return toDateKey(time) +} + +function toDateKey(value: unknown): string { + const date = parseLogDate(value) + + if (Number.isNaN(date.getTime())) { + return formatLocalDate(new Date()) + } + + return formatLocalDate(date) +} + +function offsetDate(value: unknown, offsetDays: unknown): Date { + const date = parseLogDate(value) + if (Number.isNaN(date.getTime())) { + return new Date() + } + + date.setDate(date.getDate() + Number(offsetDays || 0)) + return date +} + +function parseLogDate(value: unknown): Date { + if (value instanceof Date) { + return new Date(value.getTime()) + } + + const text = String(value || '').trim() + const matchedDateKey = /^(\d{4})-(\d{2})-(\d{2})$/.exec(text) + if (matchedDateKey) { + return new Date( + Number(matchedDateKey[1]), + Number(matchedDateKey[2]) - 1, + Number(matchedDateKey[3]), + ) + } + + return new Date(text) +} + +function normalizeLogRetentionDays(value: unknown): number { + const parsed = Number(value) + if (!Number.isFinite(parsed)) { + return DEFAULT_LOG_RETENTION_DAYS + } + + return Math.max(1, Math.floor(parsed)) +} + +function shouldDeleteLogFileByDate(fileName: unknown, cutoffDateKey: string): boolean { + if (LEGACY_LOG_FILES.has(String(fileName || '').trim())) { + return true + } + + const matched = /^([a-z0-9-]{1,40})-(\d{4}-\d{2}-\d{2})\.log$/.exec(String(fileName || '').trim()) + + if (!matched) { + return false + } + + return String(matched[2] || '') < cutoffDateKey +} + +function isLogLevel(value: string): value is LogLevel { + return ['debug', 'info', 'warn', 'error'].includes(value) +}