From 34d2cbb1cd2242a72281e3e09aba9a5c6e04909c Mon Sep 17 00:00:00 2001 From: imbytecat Date: Sat, 25 Apr 2026 16:24:00 +0800 Subject: [PATCH] =?UTF-8?q?refactor(logging):=20=E4=BA=8C=E6=AC=A1?= =?UTF-8?q?=E5=AE=A1=E8=AE=A1=E4=BF=AE=E5=A4=8D=20oracle=20=E6=BC=8F?= =?UTF-8?q?=E6=8E=89=E7=9A=84=E5=8F=AF=E8=A7=82=E6=B5=8B=E6=80=A7=E7=BC=BA?= =?UTF-8?q?=E5=8F=A3=E4=B8=8E=E5=8D=A0=E4=BD=8D=E7=AC=A6=E5=86=97=E4=BD=99?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 二次深度审计发现： 1. shutdown.ts SIGINT/SIGTERM 路径完全沉默——生产环境 k8s pod 终止时 操作者在日志里看不到任何痕迹。补 getLogger(['shutdown']) 三条日志： - "Draining for shutdown" {signal, graceMs} (优雅关停起点) - "Forcing exit on repeated signal" {signal} (二次信号强制退出) - "DB pool closed, exiting" (干净退出确认) 2. interceptors.ts 与 shutdown.ts 的 {error}/{signal} 占位符在 JSON 模式 下导致 message 字段重复 inspect 转义 properties 里的同一份内容 （Error/对象会被 JSON.stringify 内联进 message，引号被反斜杠转义）。 规则收敛：占位符仅用于"想要内联渲染"的基本类型（id、count、duration）， 对象/Error 直接放 properties，message 保持人类可读短句。 3. AGENTS.md Logging 段更新示例与规则，反映实际最佳实践。 端到端验证（compose + Postgres 18-alpine）： - /api/rpc/todo/list 成功 → logger=db level=INFO 输出 SQL ✓ - /api/rpc/todo/create 校验失败 → logger=api level=ERROR message="Unhandled error in ORPC handler" 干净，properties.error 完整保留 code/status/message/data 字段 ✓ - SIGTERM → 三条 shutdown logger 事件按预期输出 ✓ - typecheck / test 3/3 / build / compile 117M 全绿 ✓ --- AGENTS.md | 4 ++-- src/server/api/interceptors.ts | 2 +- src/server/plugins/shutdown.ts | 15 +++++++++++---- 3 files changed, 14 insertions(+), 7 deletions(-) diff --git a/AGENTS.md b/AGENTS.md index 305c8fd..2552c97 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -131,11 +131,11 @@ All server-side logging goes through `src/server/logger.ts`, a thin wrapper over import { getLogger } from '@/server/logger' const logger = getLogger(['feature', 'subsystem']) logger.info('Created todo {id}', { id }) -logger.error('DB write failed: {err}', { err }) +logger.error('DB write failed', { error }) ``` - Categories are hierarchical arrays — they show up as dot-paths in JSON output (`"logger":"feature.subsystem"`) and let you filter by prefix when shipping logs. -- The `{name}` placeholders in the message string are filled from the second-arg properties object. Don't string-concatenate or template-literal — that defeats structured logging. +- The `{name}` placeholders are for **primitive** values you want rendered inline (numbers, short strings, IDs). For objects, errors, and anything multi-field, omit the placeholder and just pass the value in properties — `logger.error('Auth failed', { error, userId })` keeps the message clean while properties stay structured. Never string-concatenate or template-literal — that defeats structured logging. - Format is `pretty` (icons + ANSI) on TTY, `json` (one-line JSON) when piped — perfect for Loki/Datadog/CloudWatch ingestion. Override with `LOG_FORMAT`. - Drizzle SQL queries are logged at `info` under category `['db']` when `LOG_DB=true`, via `@logtape/drizzle-orm`'s `DrizzleLogger` adapter (constructed in `src/server/db/index.ts`). The `info` level is intentional: flipping `LOG_DB=true` alone is enough — no need to also lower `LOG_LEVEL`. - `src/server/api/interceptors.ts` calls `getLogger(['api']).error(...)` from `logError`. CLI subcommands lazy-import the logger inside `run()` — they are still required to be side-effect-free at module top (citty eager-loads for `--help`). diff --git a/src/server/api/interceptors.ts b/src/server/api/interceptors.ts index f88d7a6..cfbbd8c 100644 --- a/src/server/api/interceptors.ts +++ b/src/server/api/interceptors.ts @@ -5,7 +5,7 @@ import { getLogger } from '@/server/logger' const logger = getLogger(['api']) export const logError = (error: unknown) => { - logger.error('Unhandled error in ORPC handler: {error}', { error }) + logger.error('Unhandled error in ORPC handler', { error }) } export const handleValidationError = (error: unknown) => { diff --git a/src/server/plugins/shutdown.ts b/src/server/plugins/shutdown.ts index 1f54272..097ed79 100644 --- a/src/server/plugins/shutdown.ts +++ b/src/server/plugins/shutdown.ts @@ -1,21 +1,28 @@ import { db } from '@/server/db' +import { getLogger } from '@/server/logger' export default () => { if (import.meta.dev) return + const logger = getLogger(['shutdown']) let exiting = false - const shutdown = () => { + const shutdown = (signal: NodeJS.Signals) => { if (exiting) { + logger.warn('Forcing exit on repeated signal', { signal }) process.exit(0) } exiting = true + logger.info('Draining for shutdown', { signal, graceMs: 500 }) setTimeout(() => { - db.$client.end().finally(() => process.exit(0)) + db.$client.end().finally(() => { + logger.info('DB pool closed, exiting') + process.exit(0) + }) }, 500) } - process.on('SIGINT', shutdown) - process.on('SIGTERM', shutdown) + process.on('SIGINT', () => shutdown('SIGINT')) + process.on('SIGTERM', () => shutdown('SIGTERM')) }