优化 Webhook 列表, 优化日志系统

2026-04-14 20:02:37 +08:00
parent 215f8bb710
commit 9636167177
21 changed files with 518 additions and 20 deletions
@@ -1,15 +1,43 @@
 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'

+const LOG_LEVEL_PRIORITY = {
+  debug: 10,
+  info: 20,
+  warn: 30,
+  error: 40,
+}
+
+const LEVEL_LABELS = {
+  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 APP_LOG_FILE = path.join(LOG_DIR, 'app.log')
-const WEBHOOK_LOG_FILE = path.join(LOG_DIR, 'webhook.log')
+const ACTIVE_LOG_LEVEL = normalizeLogLevel(runtimeConfig.logging?.level)
+const LOG_RETENTION_DAYS = 7
+const LEGACY_LOG_FILES = new Set(['app.log', 'webhook.log'])

 let writeQueue = Promise.resolve()
+let lastCleanupDateKey = ''

 export function createRequestId(prefix = 'req') {
  return `${prefix}-${Date.now().toString(36)}-${Math.random().toString(36).slice(2, 8)}`
@@ -36,9 +64,13 @@ export function logWebhook(scope, message, detail, { level = 'info' } = {}) {
 }

 function writeLog(level, scope, message, detail, { channel = 'app' } = {}) {
+  if (!shouldWriteLog(level, ACTIVE_LOG_LEVEL)) {
+    return null
+  }
+
  const entry = {
    time: new Date().toISOString(),
-    level,
+    level: normalizeLogLevel(level),
    scope: String(scope || 'app').trim() || 'app',
    message: String(message || '').trim() || '-',
    pid: process.pid,
@@ -46,17 +78,19 @@ function writeLog(level, scope, message, detail, { channel = 'app' } = {}) {
  }

  writeConsole(entry)
-  enqueueFileWrite(entry, channel === 'webhook' ? WEBHOOK_LOG_FILE : APP_LOG_FILE)
+  enqueueFileWrite(entry, resolveLogFilePath(channel, entry.time))
  return entry
 }

 function enqueueFileWrite(entry, filePath) {
-  const line = JSON.stringify(entry)
+  const line = formatLogEntry(entry, { color: false })
+  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 || '未知错误')
@@ -65,29 +99,99 @@ function enqueueFileWrite(entry, filePath) {
 }

 function writeConsole(entry) {
-  const prefix = `[${entry.time}] [${entry.level}] [${entry.scope}] ${entry.message}`
  const logger = resolveConsoleMethod(entry.level)
-
-  if (typeof entry.detail === 'undefined') {
-    logger(prefix)
-    return
-  }
-
-  logger(prefix, entry.detail)
+  logger(formatLogEntry(entry, { color: supportsAnsiColor() }))
 }

 function resolveConsoleMethod(level) {
-  if (level === 'error') {
+  const normalized = normalizeLogLevel(level)
+
+  if (normalized === 'error') {
    return console.error
  }

-  if (level === 'warn') {
+  if (normalized === 'warn') {
    return console.warn
  }

  return console.log
 }

+export function normalizeLogLevel(level) {
+  const normalized = String(level || '').trim().toLowerCase()
+  return LOG_LEVEL_PRIORITY[normalized] != null ? normalized : 'info'
+}
+
+export function shouldWriteLog(level, configuredLevel = ACTIVE_LOG_LEVEL) {
+  const normalizedLevel = normalizeLogLevel(level)
+  const normalizedConfigured = normalizeLogLevel(configuredLevel)
+
+  return LOG_LEVEL_PRIORITY[normalizedLevel] >= LOG_LEVEL_PRIORITY[normalizedConfigured]
+}
+
+export function formatLogEntry(entry, { color = false } = {}) {
+  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: 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()) {
+  const normalizedChannel = String(channel || '').trim() === 'webhook' ? 'webhook' : 'app'
+  return path.join(LOG_DIR, `${normalizedChannel}-${extractLogDateKey(time)}.log`)
+}
+
+export function resolveExpiredLogFilenames(
+  fileNames = [],
+  referenceTime = new Date().toISOString(),
+  retentionDays = LOG_RETENTION_DAYS,
+) {
+  const normalizedRetentionDays = Math.max(1, Number(retentionDays) || LOG_RETENTION_DAYS)
+  const cutoffDateKey = toDateKey(offsetDate(referenceTime, -(normalizedRetentionDays - 1)))
+
+  return (Array.isArray(fileNames) ? fileNames : [])
+    .filter((fileName) => shouldDeleteLogFileByDate(fileName, cutoffDateKey))
+}
+
+export function formatLogTimestamp(value) {
+  const date = new Date(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() {
  const configured = String(runtimeConfig.data?.root || '').trim()
  return configured ? path.resolve(configured) : path.resolve(PROJECT_ROOT, 'data')
@@ -122,3 +226,175 @@ function normalizeLogValue(value) {
    return String(value)
  }
 }
+
+function splitDetailPayload(detail) {
+  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 = {}
+    const block = {}
+
+    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) {
+  return Object.entries(fields)
+    .filter(([, value]) => typeof value !== 'undefined' && value !== '')
+    .map(([key, value]) => `${key}=${formatInlineValue(value)}`)
+    .join(' ')
+}
+
+function formatInlineValue(value) {
+  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) {
+  return value === null || ['string', 'number', 'boolean'].includes(typeof value)
+}
+
+function indentBlock(text, indent) {
+  return String(text || '')
+    .split('\n')
+    .map((line) => `${indent}${line}`)
+    .join('\n')
+}
+
+function supportsAnsiColor() {
+  return process.env.NO_COLOR !== '1' && Boolean(process.stdout.isTTY || process.stderr.isTTY)
+}
+
+function resolveLevelColor(level) {
+  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, ansiCode, enabled) {
+  if (!enabled || !ansiCode) {
+    return text
+  }
+
+  return `${ansiCode}${text}${ANSI.reset}`
+}
+
+function formatLocalDate(date) {
+  return `${date.getFullYear()}-${String(date.getMonth() + 1).padStart(2, '0')}-${String(date.getDate()).padStart(2, '0')}`
+}
+
+function formatLocalTime(date) {
+  return `${String(date.getHours()).padStart(2, '0')}:${String(date.getMinutes()).padStart(2, '0')}:${String(date.getSeconds()).padStart(2, '0')}`
+}
+
+function formatTimezoneOffset(date) {
+  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) {
+  if (!dateKey || dateKey === lastCleanupDateKey) {
+    return
+  }
+
+  lastCleanupDateKey = dateKey
+
+  try {
+    const fileNames = await fs.readdir(LOG_DIR)
+    const expired = resolveExpiredLogFilenames(fileNames, `${dateKey}T00:00:00.000Z`)
+    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) {
+  const normalized = String(time || '').trim()
+  return /^\d{4}-\d{2}-\d{2}/.test(normalized) ? normalized.slice(0, 10) : toDateKey(normalized)
+}
+
+function toDateKey(value) {
+  const date = new Date(value)
+
+  if (Number.isNaN(date.getTime())) {
+    return new Date().toISOString().slice(0, 10)
+  }
+
+  return date.toISOString().slice(0, 10)
+}
+
+function offsetDate(value, offsetDays) {
+  const date = new Date(value)
+  date.setUTCDate(date.getUTCDate() + Number(offsetDays || 0))
+  return date
+}
+
+function shouldDeleteLogFileByDate(fileName, cutoffDateKey) {
+  if (LEGACY_LOG_FILES.has(String(fileName || '').trim())) {
+    return true
+  }
+
+  const matched = /^(app|webhook)-(\d{4}-\d{2}-\d{2})\.log$/.exec(String(fileName || '').trim())
+
+  if (!matched) {
+    return false
+  }
+
+  return matched[2] < cutoffDateKey
+}
@@ -0,0 +1,104 @@
+import test from 'node:test'
+import assert from 'node:assert/strict'
+
+import {
+  formatLogEntry,
+  formatLogTimestamp,
+  normalizeLogLevel,
+  resolveExpiredLogFilenames,
+  resolveLogFilePath,
+  shouldWriteLog,
+} from './logger.js'
+
+test('normalizeLogLevel falls back to info for unsupported values', () => {
+  assert.equal(normalizeLogLevel('debug'), 'debug')
+  assert.equal(normalizeLogLevel('WARN'), 'warn')
+  assert.equal(normalizeLogLevel('verbose'), 'info')
+  assert.equal(normalizeLogLevel(''), 'info')
+})
+
+test('shouldWriteLog respects configured minimum log level', () => {
+  assert.equal(shouldWriteLog('debug', 'debug'), true)
+  assert.equal(shouldWriteLog('info', 'debug'), true)
+  assert.equal(shouldWriteLog('debug', 'info'), false)
+  assert.equal(shouldWriteLog('info', 'warn'), false)
+  assert.equal(shouldWriteLog('warn', 'warn'), true)
+  assert.equal(shouldWriteLog('error', 'warn'), true)
+})
+
+test('resolveLogFilePath uses daily log file names by channel', () => {
+  assert.match(resolveLogFilePath('app', '2026-04-14T10:00:00.000Z'), /app-2026-04-14\.log$/)
+  assert.match(resolveLogFilePath('webhook', '2026-04-14T10:00:00.000Z'), /webhook-2026-04-14\.log$/)
+})
+
+test('resolveExpiredLogFilenames keeps latest seven days and ignores unknown files', () => {
+  const expired = resolveExpiredLogFilenames([
+    'app-2026-04-14.log',
+    'app-2026-04-13.log',
+    'app-2026-04-08.log',
+    'app-2026-04-07.log',
+    'webhook-2026-04-06.log',
+    'app.log',
+    'webhook.log',
+    'random.txt',
+  ], '2026-04-14T12:00:00.000Z', 7)
+
+  assert.deepEqual(expired, [
+    'app-2026-04-07.log',
+    'webhook-2026-04-06.log',
+    'app.log',
+    'webhook.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}$/)
+})
+
+test('formatLogEntry prints readable one-line output for flat details', () => {
+  const text = formatLogEntry({
+    time: '2026-04-14T10:36:24.974Z',
+    level: 'info',
+    scope: '[http/access]',
+    message: 'request completed',
+    pid: 4671,
+    detail: {
+      requestId: 'req-123',
+      method: 'GET',
+      statusCode: 401,
+    },
+  }, { color: false })
+
+  assert.match(text, /INFO\s+\[http\/access\] request completed/)
+  assert.match(text, /pid=4671/)
+  assert.match(text, /requestId=req-123/)
+  assert.match(text, /method=GET/)
+  assert.match(text, /statusCode=401/)
+  assert.doesNotMatch(text, /^\{/)
+})
+
+test('formatLogEntry prints nested detail blocks without ansi colors in file mode', () => {
+  const text = formatLogEntry({
+    time: '2026-04-14T10:36:24.974Z',
+    level: 'warn',
+    scope: '[admin/auth]',
+    message: '后台鉴权失败',
+    pid: 4671,
+    detail: {
+      statusCode: 401,
+      errorCode: 'admin_auth_required',
+      error: {
+        message: '未登录或登录已失效',
+        stack: 'Error: test',
+      },
+    },
+  }, { color: false })
+
+  assert.match(text, /WARN\s+\[admin\/auth\] 后台鉴权失败/)
+  assert.match(text, /statusCode=401/)
+  assert.match(text, /errorCode=admin_auth_required/)
+  assert.match(text, /\n  \{/)
+  assert.match(text, /未登录或登录已失效/)
+  assert.doesNotMatch(text, /\u001B\[/)
+})