From c4f9e2ab979cf6c1dcb950dae305630f14e8dbb4 Mon Sep 17 00:00:00 2001 From: YBF <47051132+YBFACC@users.noreply.github.com> Date: Wed, 16 Sep 2026 01:03:09 +0800 Subject: [PATCH] feat: add OneTalk diagnostic file logging --- .env.example | 2 + .../service-worker/transport/bright-client.ts | 4 ++ .../src/service-worker-entry.ts | 50 ++++++------------- .../test/onetalk-bright-client.test.js | 23 +++++++-- apps/server/src/dev-entry.ts | 34 +++++-------- .../src/websocket/diagnostic-file-log.ts | 37 ++++++++++++++ apps/server/src/websocket/diagnostics.ts | 1 + apps/server/src/websocket/handler.ts | 4 ++ apps/server/test/onetalk-websocket.test.ts | 8 ++- .../server/test/websocket-diagnostics.test.ts | 47 +++++++++++++++++ .../onetalk-contract/src/diagnostic-log.ts | 30 +++++++++++ packages/onetalk-contract/src/index.ts | 6 +++ .../test/diagnostic-log.test.ts | 37 ++++++++++++++ 13 files changed, 221 insertions(+), 62 deletions(-) create mode 100644 apps/server/src/websocket/diagnostic-file-log.ts create mode 100644 packages/onetalk-contract/src/diagnostic-log.ts create mode 100644 packages/onetalk-contract/test/diagnostic-log.test.ts diff --git a/.env.example b/.env.example index 0a52cfa..7639732 100644 --- a/.env.example +++ b/.env.example @@ -5,6 +5,8 @@ HOST=127.0.0.1 PORT=7878 DATABASE_URL=postgres://postgres:postgres@127.0.0.1:5432/trade_message_center +# 仅开发排障：将未脱敏 OneTalk WebSocket payload 写入 logs/.log；默认关闭。 +ONETALK_DIAGNOSTIC_LOG=false # Chrome 扩展临时下载签名及本地 Mind 联调页的 server-proxy OSS 上传。TMC_PACKAGE_VERSION 由 workspace 命令从根 package.json 注入；AccessKey 只能留在 server 侧环境文件。 OSS_BUCKET=sinanpilot-bucket diff --git a/apps/chrome-extension/src/onetalk/service-worker/transport/bright-client.ts b/apps/chrome-extension/src/onetalk/service-worker/transport/bright-client.ts index f168727..e9837e9 100644 --- a/apps/chrome-extension/src/onetalk/service-worker/transport/bright-client.ts +++ b/apps/chrome-extension/src/onetalk/service-worker/transport/bright-client.ts @@ -92,6 +92,7 @@ export type OneTalkBrightDiagnostic = { requestedPermissions?: OneTalkPermission[]; bindingPresent?: boolean; redactedFields?: readonly string[]; + payload?: unknown; }; export type OneTalkBrightClientOptions = { @@ -323,12 +324,14 @@ export const createOneTalkBrightClient = ( | "requestedPermissions" | "bindingPresent" | "redactedFields" + | "payload" > => ({ ...socketDiagnostic(), protocolVersion: frame.protocolVersion, connectionType: frame.connectionType, frameType: frame.type, requestId: frame.requestId, + payload: frame.payload, ...(frame.type === "ws.hello" ? { requestedPermissions: [...frame.payload.requestedPermissions], @@ -410,6 +413,7 @@ export const createOneTalkBrightClient = ( direction: "outbound", requestId: frame.requestId, frameType: frame.type, + payload: frame.payload, code: "send_failed", }); report(new OneTalkBrightClientError("send_failed", error)); diff --git a/apps/chrome-extension/src/service-worker-entry.ts b/apps/chrome-extension/src/service-worker-entry.ts index 8b19a7b..c950f8a 100644 --- a/apps/chrome-extension/src/service-worker-entry.ts +++ b/apps/chrome-extension/src/service-worker-entry.ts @@ -1,5 +1,10 @@ // 启动页面桥并管理可配置的 OneTalk 同步运行时 +import { + composeOneTalkDiagnosticLog, + isPlainRecord, + type OneTalkDiagnosticLogEvent, +} from "@trade-message-center/onetalk-contract"; import { clearOneTalkExtensionConfig, isMaskedOneTalkBinding, @@ -16,7 +21,6 @@ import { type OneTalkExtensionStorageArea, type OneTalkPopupErrorCode, } from "./onetalk/config.ts"; -import { isPlainRecord } from "@trade-message-center/onetalk-contract"; import { createOneTalkServiceWorkerSyncController, type OneTalkServiceWorkerSyncController, @@ -25,13 +29,7 @@ import { import { logOneTalkError } from "./onetalk/service-worker/error-diagnostics.ts"; import type { OneTalkServiceWorkerPort } from "./onetalk/service-worker/runtime.ts"; import { BRIGHT_WEBSOCKET_URL, ENABLE_ONE_TALK_DIAGNOSTICS } from "./onetalk/build-config.ts"; -import type { OneTalkPageDiagnostic } from "./onetalk/service-worker/runtime.ts"; -import type { OneTalkSyncEngineDiagnostic } from "./onetalk/service-worker/sync-engine.ts"; -import { - OneTalkBrightClientError, - type OneTalkBrightDiagnostic, -} from "./onetalk/service-worker/transport/bright-client.ts"; -import type { OneTalkContactProfileDiagnostic } from "./onetalk/service-worker/contact-profile-coordinator.ts"; +import { OneTalkBrightClientError } from "./onetalk/service-worker/transport/bright-client.ts"; declare const chrome: { runtime: { @@ -59,28 +57,10 @@ declare const chrome: { }; }; -type OneTalkDiagnostic = - | OneTalkBrightDiagnostic - | OneTalkPageDiagnostic - | OneTalkSyncEngineDiagnostic - | OneTalkContactProfileDiagnostic; - -const heartbeatDiagnosticText = (event: OneTalkDiagnostic): string | undefined => { - if (event.event !== "frame") return undefined; - if (event.frameType === "heartbeat.ack") return "心跳确认"; - if (event.frameType !== "heartbeat") return undefined; - return event.direction === "inbound" ? "心跳接收" : "心跳发送"; -}; - -const logOneTalkDiagnostic = (source: string, event: OneTalkDiagnostic): void => { +const logOneTalkDiagnostic = (event: T): void => { if (!ENABLE_ONE_TALK_DIAGNOSTICS) return; - const heartbeatText = heartbeatDiagnosticText(event); - if (heartbeatText !== undefined) { - console.info(`[Trade Message Center][OneTalk ${source}] ${heartbeatText}`); - return; - } - const level = event.status === "failed" || event.code ? "warn" : "info"; - console[level](`[Trade Message Center][OneTalk ${source}]`, event); + const diagnostic = composeOneTalkDiagnosticLog("extension", event); + console[diagnostic.level](diagnostic.headline, diagnostic.payload); }; const isNoPopupReceiverError = (error: unknown): boolean => { @@ -131,15 +111,13 @@ const broadcastStatus = (snapshot: OneTalkServiceWorkerSyncSnapshot): void => { }; const controller: OneTalkServiceWorkerSyncController = createOneTalkServiceWorkerSyncController({ - onBrightDiagnostic: (event: OneTalkBrightDiagnostic) => logOneTalkDiagnostic("Bright", event), - onPageDiagnostic: (event: OneTalkPageDiagnostic) => logOneTalkDiagnostic("Page", event), - onEngineDiagnostic: (event: OneTalkSyncEngineDiagnostic) => logOneTalkDiagnostic("Sync", event), - onProfileDiagnostic: (event: OneTalkContactProfileDiagnostic) => - logOneTalkDiagnostic("Profile", event), + onBrightDiagnostic: logOneTalkDiagnostic, + onPageDiagnostic: logOneTalkDiagnostic, + onEngineDiagnostic: logOneTalkDiagnostic, + onProfileDiagnostic: logOneTalkDiagnostic, onStatusChange: (snapshot) => { broadcastStatus(snapshot); - if (!ENABLE_ONE_TALK_DIAGNOSTICS) return; - console.info("[Trade Message Center][OneTalk Sync]", { + logOneTalkDiagnostic({ event: "state_snapshot", online: snapshot.engineStatus?.online ?? false, brightStatus: snapshot.connectionStatus, diff --git a/apps/chrome-extension/test/onetalk-bright-client.test.js b/apps/chrome-extension/test/onetalk-bright-client.test.js index b67b747..efcc1c8 100644 --- a/apps/chrome-extension/test/onetalk-bright-client.test.js +++ b/apps/chrome-extension/test/onetalk-bright-client.test.js @@ -356,6 +356,10 @@ test("keeps ws.error visible and uses a browser-valid client close code", () => assert.deepEqual(hello.requestedPermissions, ["read", "rebuild"]); assert.equal(hello.bindingPresent, true); assert.ok(hello.redactedFields.includes("binding")); + assert.deepEqual(hello.payload, { + binding: "binding-1", + requestedPermissions: ["read", "rebuild"], + }); const close = diagnostics.find((event) => event.event === "socket_close"); assert.equal(close.closeCode, 1000); assert.equal(close.closeReason, "binding_revoked"); @@ -373,7 +377,7 @@ test("keeps ws.error visible and uses a browser-valid client close code", () => assert.equal(JSON.stringify(diagnostics).includes(socket.url), false); assert.equal(JSON.stringify(diagnostics).includes("credential=secret"), false); assert.equal(JSON.stringify(diagnostics).includes("fragment"), false); - assert.equal(JSON.stringify(diagnostics).includes("binding-1"), false); + assert.equal(JSON.stringify(diagnostics).includes("binding-1"), true); }); for (const code of Object.values(ONETALK_ERROR_CODES)) { @@ -499,7 +503,7 @@ for (const code of [ }); } -test("diagnoses guarded sends and invalid inbound frames without payloads", () => { +test("keeps guarded-send payloads while invalid inbound frames have no decoded payload", () => { const diagnostics = []; const socket = new FakeSocket("wss://bright.example/ws"); const client = createOneTalkBrightClient({ @@ -530,11 +534,18 @@ test("diagnoses guarded sends and invalid inbound frames without payloads", () = assert.ok( diagnostics.some((event) => event.event === "frame" && event.code === "invalid_message"), ); - assert.equal(JSON.stringify(diagnostics).includes("secret-binding"), false); + const guardedSend = diagnostics.find((event) => event.event === "guarded_send"); + const invalidInbound = diagnostics.find( + (event) => event.event === "frame" && event.code === "invalid_message", + ); + assert.equal(guardedSend.payload.conversationId, "conversation-1"); + assert.equal(Object.hasOwn(invalidInbound, "payload"), false); + assert.equal(JSON.stringify(diagnostics).includes("secret-binding"), true); }); test("uses a browser-valid close code when the initial hello cannot be sent", () => { const socket = new FakeSocket("wss://bright.example/ws"); + const diagnostics = []; socket.send = () => { throw new Error("send failed"); }; @@ -544,6 +555,7 @@ test("uses a browser-valid close code when the initial hello cannot be sent", () binding: "binding-1", webSocket: () => socket, autoReconnect: false, + onDiagnostic: (event) => diagnostics.push(event), }); client.connect(); @@ -553,6 +565,11 @@ test("uses a browser-valid close code when the initial hello cannot be sent", () socket.closed.at(-1).code === 1000 || (socket.closed.at(-1).code >= 3000 && socket.closed.at(-1).code <= 4999), ); + assert.deepEqual( + diagnostics.find((event) => event.event === "frame" && event.code === "send_failed") + .payload, + { binding: "binding-1", requestedPermissions: ["read", "rebuild"] }, + ); }); test("sends a complete confirmed_sent message through the strict confirmation contract", () => { diff --git a/apps/server/src/dev-entry.ts b/apps/server/src/dev-entry.ts index 414040a..34c7478 100644 --- a/apps/server/src/dev-entry.ts +++ b/apps/server/src/dev-entry.ts @@ -6,7 +6,10 @@ import { loadEnvFile } from "node:process"; import { fileURLToPath } from "node:url"; import { startServer } from "./entry.ts"; -import type { OneTalkDiagnostic } from "./websocket/diagnostics.ts"; +import { + createOneTalkDiagnosticFileLogger, + isOneTalkDiagnosticFileLogEnabled, +} from "./websocket/diagnostic-file-log.ts"; const environmentFileNames = [".env", ".env.local", ".env.development", ".env.development.local"]; @@ -41,13 +44,6 @@ const loadEnvironmentFiles = (): string[] => { return existingFiles.map((filePath) => relative(projectRoot, filePath)); }; -const heartbeatDiagnosticText = (event: OneTalkDiagnostic): string | undefined => { - if (event.event !== "ws_frame") return undefined; - if (event.frameType === "heartbeat.ack") return "心跳确认"; - if (event.frameType !== "heartbeat") return undefined; - return event.direction === "inbound" ? "心跳接收" : "心跳发送"; -}; - /** 加载开发环境配置并启动服务。 */ const startDevelopmentServer = async (): Promise => { const loadedFiles = loadEnvironmentFiles(); @@ -56,19 +52,15 @@ const startDevelopmentServer = async (): Promise => { ? `[env] loaded ${loadedFiles.join(", ")}` : "[env] no environment file loaded", ); - await startServer( - (event) => { - const heartbeatText = heartbeatDiagnosticText(event); - if (heartbeatText !== undefined) { - console.info(`[onetalk][diagnostic] ${heartbeatText}`); - return; - } - console.info("[onetalk][diagnostic]", JSON.stringify(event)); - }, - (event) => { - console.info("[mind-auth][diagnostic]", JSON.stringify(event)); - }, - ); + const oneTalkDiagnostic = isOneTalkDiagnosticFileLogEnabled(process.env.ONETALK_DIAGNOSTIC_LOG) + ? createOneTalkDiagnosticFileLogger({ + logsDirectory: resolve(projectRoot, "logs"), + buildHash: process.env.BUILD_HASH, + }) + : undefined; + await startServer(oneTalkDiagnostic, (event) => { + console.info("[mind-auth][diagnostic]", JSON.stringify(event)); + }); }; void startDevelopmentServer().catch((error: unknown) => { diff --git a/apps/server/src/websocket/diagnostic-file-log.ts b/apps/server/src/websocket/diagnostic-file-log.ts new file mode 100644 index 0000000..79e52eb --- /dev/null +++ b/apps/server/src/websocket/diagnostic-file-log.ts @@ -0,0 +1,37 @@ +import { appendFileSync, mkdirSync } from "node:fs"; +import { join } from "node:path"; + +import { + composeOneTalkDiagnosticLog, + type OneTalkDiagnosticLogEvent, +} from "@trade-message-center/onetalk-contract"; + +const logFileName = (buildHash: string | undefined): string => { + const normalizedBuildHash = buildHash?.trim(); + if (!normalizedBuildHash) return "dev.log"; + if (!/^[a-zA-Z0-9_-]+$/u.test(normalizedBuildHash)) { + throw new Error("BUILD_HASH must contain only letters, numbers, underscores, or dashes"); + } + return `${normalizedBuildHash}.log`; +}; + +export const isOneTalkDiagnosticFileLogEnabled = (value: string | undefined): boolean => { + return value?.trim() === "true"; +}; + +export const createOneTalkDiagnosticFileLogger = (options: { + logsDirectory: string; + buildHash?: string; +}): ((event: OneTalkDiagnosticLogEvent) => void) => { + mkdirSync(options.logsDirectory, { recursive: true }); + const logPath = join(options.logsDirectory, logFileName(options.buildHash)); + + return (event) => { + const diagnostic = composeOneTalkDiagnosticLog("server", event); + appendFileSync( + logPath, + `${diagnostic.headline} ${JSON.stringify(diagnostic.payload)}\n`, + "utf8", + ); + }; +}; diff --git a/apps/server/src/websocket/diagnostics.ts b/apps/server/src/websocket/diagnostics.ts index 4544727..45f9608 100644 --- a/apps/server/src/websocket/diagnostics.ts +++ b/apps/server/src/websocket/diagnostics.ts @@ -13,6 +13,7 @@ export type OneTalkDiagnostic = { code?: string; closeCode?: number; closeReason?: string; + payload?: unknown; }; export type OneTalkDiagnosticsSink = (event: OneTalkDiagnostic) => void; diff --git a/apps/server/src/websocket/handler.ts b/apps/server/src/websocket/handler.ts index ec3e3c6..a7a17d8 100644 --- a/apps/server/src/websocket/handler.ts +++ b/apps/server/src/websocket/handler.ts @@ -142,6 +142,7 @@ const sendFrame = ( connectionType: frame.connectionType, frameType: frame.type, direction: "outbound", + payload: frame.payload, ...(code === undefined ? {} : { code }), }); if (socket.readyState !== WEBSOCKET_OPEN) { @@ -240,6 +241,7 @@ export const createOneTalkWebSocketHandler = requestId: frame.requestId, connectionType: frame.connectionType, frameType: frame.type, + payload: frame.payload, }), reportDecision: (frame, code) => reportDiagnostic(options.onDiagnostic, { @@ -247,6 +249,7 @@ export const createOneTalkWebSocketHandler = requestId: frame.requestId, connectionType: frame.connectionType, frameType: frame.type, + payload: frame.payload, code, }), }; @@ -285,6 +288,7 @@ export const createOneTalkWebSocketHandler = connectionType: frame.connectionType, frameType: frame.type, direction: "inbound", + payload: frame.payload, }), onUnauthenticatedFrame: (_socket, frame) => { sendError(frame, ONETALK_ERROR_CODES.authRequired); diff --git a/apps/server/test/onetalk-websocket.test.ts b/apps/server/test/onetalk-websocket.test.ts index 71641bd..1ab7355 100644 --- a/apps/server/test/onetalk-websocket.test.ts +++ b/apps/server/test/onetalk-websocket.test.ts @@ -1121,7 +1121,7 @@ test("publishes exact false profile updates only for newer committed profiles", } }); -test("emits only safe lifecycle fields through the injected diagnostics sink", async () => { +test("emits complete frame payloads through the injected diagnostics sink", async () => { const diagnostics: Record[] = []; const app = createApp(testConfig, { database: createDatabaseStub(), @@ -1154,7 +1154,11 @@ test("emits only safe lifecycle fields through the injected diagnostics sink", a (event) => event.event === "ws_frame" && event.frameType === "ws.hello", ), ); - assert.equal(JSON.stringify(diagnostics).includes("binding-1"), false); + assert.deepEqual(diagnostics[0].payload, { + binding: "binding-1", + requestedPermissions: ["read", "send"], + }); + assert.equal(JSON.stringify(diagnostics).includes("binding-1"), true); assert.equal(JSON.stringify(diagnostics).includes("device-1"), false); } finally { await closeApp(app, [socket]); diff --git a/apps/server/test/websocket-diagnostics.test.ts b/apps/server/test/websocket-diagnostics.test.ts index 390730d..adf69fb 100644 --- a/apps/server/test/websocket-diagnostics.test.ts +++ b/apps/server/test/websocket-diagnostics.test.ts @@ -1,10 +1,57 @@ // 验证 WebSocket 通用诊断不含旧资料投递契约 import assert from "node:assert/strict"; +import { mkdtempSync, readFileSync, rmSync } from "node:fs"; +import { join } from "node:path"; import test from "node:test"; +import { tmpdir } from "node:os"; +import { composeOneTalkDiagnosticLog } from "@trade-message-center/onetalk-contract"; +import * as diagnosticFileLog from "../src/websocket/diagnostic-file-log.ts"; import type { OneTalkDiagnostic } from "../src/websocket/diagnostics.ts"; +test("puts the WebSocket event and frame type in the diagnostic headline", () => { + const helloLog = composeOneTalkDiagnosticLog("server", { + event: "ws_frame", + frameType: "ws.hello", + }); + const closeLog = composeOneTalkDiagnosticLog("server", { event: "ws_close" }); + + assert.equal(helloLog.headline, "[server] event=ws_frame frameType=ws.hello"); + assert.equal(closeLog.headline, "[server] event=ws_close frameType=-"); +}); + +test("appends complete diagnostics to the build-hash log file", () => { + const logsDirectory = mkdtempSync(join(tmpdir(), "onetalk-diagnostic-log-")); + const payload = { binding: "binding-1", content: { text: "full message" } }; + try { + const writeDiagnostic = diagnosticFileLog.createOneTalkDiagnosticFileLogger({ + logsDirectory, + buildHash: "0123456789abcdef", + }); + writeDiagnostic({ event: "ws_frame", frameType: "ws.hello", payload }); + writeDiagnostic({ event: "ws_close" }); + + assert.equal( + readFileSync(join(logsDirectory, "0123456789abcdef.log"), "utf8"), + [ + '[server] event=ws_frame frameType=ws.hello {"binding":"binding-1","content":{"text":"full message"}}', + '[server] event=ws_close frameType=- {"event":"ws_close"}', + "", + ].join("\n"), + ); + } finally { + rmSync(logsDirectory, { recursive: true, force: true }); + } +}); + +test("keeps file diagnostics disabled unless explicitly enabled", () => { + assert.equal(typeof diagnosticFileLog.isOneTalkDiagnosticFileLogEnabled, "function"); + assert.equal(diagnosticFileLog.isOneTalkDiagnosticFileLogEnabled(undefined), false); + assert.equal(diagnosticFileLog.isOneTalkDiagnosticFileLogEnabled("false"), false); + assert.equal(diagnosticFileLog.isOneTalkDiagnosticFileLogEnabled("true"), true); +}); + test("does not accept removed profile delivery diagnostic fields", () => { const lifecycleDiagnostic: OneTalkDiagnostic = { event: "ws_close", diff --git a/packages/onetalk-contract/src/diagnostic-log.ts b/packages/onetalk-contract/src/diagnostic-log.ts new file mode 100644 index 0000000..2009c07 --- /dev/null +++ b/packages/onetalk-contract/src/diagnostic-log.ts @@ -0,0 +1,30 @@ +export type OneTalkDiagnosticLogSource = "extension" | "server"; + +export type OneTalkDiagnosticLogEvent = { + event: string; + frameType?: string; + status?: string; + code?: string; + payload?: unknown; +}; + +export type OneTalkDiagnosticLog = { + headline: string; + payload: unknown; + level: "info" | "warn"; +}; + +const payloadForLog = (event: T): unknown => { + if (!Object.hasOwn(event, "payload")) return event; + return event.payload; +}; + +/** 组合开发期 OneTalk 诊断日志，不裁剪显式携带的原始 payload。 */ +export const composeOneTalkDiagnosticLog = ( + source: OneTalkDiagnosticLogSource, + event: T, +): OneTalkDiagnosticLog => ({ + headline: `[${source}] event=${event.event} frameType=${event.frameType ?? "-"}`, + payload: payloadForLog(event), + level: event.status === "failed" || event.code !== undefined ? "warn" : "info", +}); diff --git a/packages/onetalk-contract/src/index.ts b/packages/onetalk-contract/src/index.ts index fa83ea5..13608d1 100644 --- a/packages/onetalk-contract/src/index.ts +++ b/packages/onetalk-contract/src/index.ts @@ -1,6 +1,12 @@ // 暴露 OneTalk 跨包公共协议边界 export { isOneTalkAvatarUrl, isPlainRecord } from "./guards.ts"; +export { composeOneTalkDiagnosticLog } from "./diagnostic-log.ts"; +export type { + OneTalkDiagnosticLog, + OneTalkDiagnosticLogEvent, + OneTalkDiagnosticLogSource, +} from "./diagnostic-log.ts"; export * from "./authorization.ts"; export * from "./content.ts"; export * from "./decoder.ts"; diff --git a/packages/onetalk-contract/test/diagnostic-log.test.ts b/packages/onetalk-contract/test/diagnostic-log.test.ts new file mode 100644 index 0000000..7025a97 --- /dev/null +++ b/packages/onetalk-contract/test/diagnostic-log.test.ts @@ -0,0 +1,37 @@ +import assert from "node:assert/strict"; +import test from "node:test"; + +import { composeOneTalkDiagnosticLog } from "../src/diagnostic-log.ts"; + +test("composes a source-prefixed headline and preserves the complete payload", () => { + const payload = { binding: "binding-1", content: { text: "full message" } }; + + assert.deepEqual( + composeOneTalkDiagnosticLog("extension", { + event: "frame", + frameType: "ws.hello", + payload, + }), + { + headline: "[extension] event=frame frameType=ws.hello", + payload, + level: "info", + }, + ); + assert.deepEqual(composeOneTalkDiagnosticLog("server", { event: "ws_close" }), { + headline: "[server] event=ws_close frameType=-", + payload: { event: "ws_close" }, + level: "info", + }); +}); + +test("marks failed or coded diagnostics as warnings", () => { + assert.equal( + composeOneTalkDiagnosticLog("extension", { + event: "frame", + frameType: "ws.error", + code: "binding_revoked", + }).level, + "warn", + ); +});