fix(desktop): harden persistent diagnostic logging

This commit is contained in:
Qiuner
2026-08-17 18:57:24 +08:00
parent 7e918c2f7d
commit e7dfcd4e94
8 changed files with 205 additions and 32 deletions
+38 -2
View File
@@ -1,4 +1,5 @@
import type { LogFileSink } from './log-files.ts'
import { maskSecrets } from './mask-secrets.ts'
/** Logger for Electron-main-scope messages that bypass Cordis `ctx.logger`. */
export interface DesktopLogger {
@@ -8,13 +9,48 @@ export interface DesktopLogger {
errorCause(cause: unknown): void
}
/** Process events needed to make uncaught exceptions observable and fatal. */
export interface DesktopUncaughtExceptionProcess {
once(event: 'uncaughtException', listener: (error: Error) => void): unknown
off(event: 'uncaughtException', listener: (error: Error) => void): unknown
}
/** Persist the first uncaught exception before requesting a fatal exit. */
export function installDesktopUncaughtExceptionLogging(
proc: DesktopUncaughtExceptionProcess,
logger: DesktopLogger,
exit: (code: number) => void,
): () => void {
let handled = false
const handler = (error: Error): void => {
if (handled) return
handled = true
proc.off('uncaughtException', handler)
logger.errorCause(error)
exit(1)
}
proc.once('uncaughtException', handler)
return () => { proc.off('uncaughtException', handler) }
}
/** DesktopLogger that writes to the shared sink and mirrors to process.stderr. */
export class ElectronStderrLogger implements DesktopLogger {
constructor(private readonly sink: LogFileSink) {}
/** Accept one fail-loud stderr diagnostic through the persistent logger. */
write(chunk: string): boolean {
this.error(chunk.replace(/\r?\n$/u, ''))
return true
}
error(message: string): void {
this.sink.write('error', message)
process.stderr.write(`${message}\n`)
const masked = maskSecrets(message)
try {
this.sink.write('error', masked)
} catch {
// Persistent diagnostics are best-effort; stderr must remain available.
}
process.stderr.write(`${masked}\n`)
}
errorCause(cause: unknown): void {
+1 -2
View File
@@ -1,7 +1,6 @@
import { Logger, type Exporter, type Message } from '@deepseek-ai/cordis'
import { shouldEmit, type LogLevel } from './log-level.ts'
import { LogFileSink } from './log-files.ts'
import { maskSecrets } from './mask-secrets.ts'
function localTimestamp(ts: number): string {
const d = new Date(ts)
@@ -40,6 +39,6 @@ export class FileExporter implements Exporter {
private render(message: Message): string {
const level = message.type.charAt(0).toUpperCase()
const body = Logger.format(this, message)
return maskSecrets(`${localTimestamp(message.ts)} [${level}] [${message.name}] ${body}`)
return `${localTimestamp(message.ts)} [${level}] [${message.name}] ${body}`
}
}
+4 -2
View File
@@ -4,6 +4,7 @@ import {
import { join } from 'node:path'
import type { LogType } from './log-level.ts'
import { isErrorType } from './log-level.ts'
import { maskSecrets } from './mask-secrets.ts'
/** Sink configuration with its size ceilings. */
export interface LogFileSinkOptions {
@@ -46,8 +47,9 @@ export class LogFileSink {
write(type: LogType, line: string): void {
const suffix = localDateSuffix(new Date())
if (suffix !== this.currentDate) this.rollDate(suffix)
this.append('all', line)
if (isErrorType(type)) this.append('error', line)
const masked = maskSecrets(line)
this.append('all', masked)
if (isErrorType(type)) this.append('error', masked)
}
/** Write a startup header line to the current full-log file (before ordinary lines). */
+31 -24
View File
@@ -18,7 +18,11 @@ import {
installDesktopPnpmRuntime,
} from './desktop-runtime-environment.ts'
import { desktopProductVersion, ElectronDesktopRuntime } from './electron-runtime.ts'
import { ElectronStderrLogger } from './desktop-logger.ts'
import {
ElectronStderrLogger,
installDesktopUncaughtExceptionLogging,
type DesktopLogger,
} from './desktop-logger.ts'
import { FileExporter } from './file-exporter.ts'
import { DESKTOP_SETTINGS_NAMESPACE, type DesktopSettings } from './index.ts'
import { LogFileSink } from './log-files.ts'
@@ -52,19 +56,18 @@ const BIN_NAME = 'dsh-plugin-desktop'
const PRODUCT_NAME = 'DSH Desktop'
/** Report profile recovery without changing startup or rollback outcomes. */
function notifyProfileRecovery(runtime: ElectronDesktopRuntime, body: string): void {
function notifyProfileRecovery(runtime: ElectronDesktopRuntime, logger: DesktopLogger, body: string): void {
try {
runtime.updates.notify({ title: 'Unable to Open Profile', body })
} catch (cause) {
process.stderr.write(
`${BIN_NAME}: failed to show profile recovery notification: ${cause instanceof Error ? cause.message : String(cause)}\n`,
)
logger.error(`${BIN_NAME}: failed to show profile recovery notification: ${cause instanceof Error ? cause.message : String(cause)}`)
}
}
/** Report optional user UI plugins skipped to keep startup recoverable. */
function notifySkippedOptionalEntries(
runtime: ElectronDesktopRuntime,
logger: DesktopLogger,
entries: readonly SkippedOptionalEntry[],
): void {
if (entries.length === 0) return
@@ -76,22 +79,21 @@ function notifySkippedOptionalEntries(
body: `${names[0]} is not installed in this profile${suffix}.`,
})
} catch (cause) {
process.stderr.write(
`${BIN_NAME}: failed to show skipped plugin notification: ${cause instanceof Error ? cause.message : String(cause)}\n`,
)
logger.error(`${BIN_NAME}: failed to show skipped plugin notification: ${cause instanceof Error ? cause.message : String(cause)}`)
}
}
/** Surface path/volume risks that otherwise become obscure sandbox or pnpm failures later. */
function warnWindowsVolumeConcerns(concerns: readonly WindowsVolumeConcern[]): void {
function warnWindowsVolumeConcerns(logger: DesktopLogger, concerns: readonly WindowsVolumeConcern[]): void {
for (const concern of concerns) {
process.stderr.write(`${BIN_NAME}: Windows volume warning: ${formatWindowsVolumeConcern(concern)}\n`)
logger.error(`${BIN_NAME}: Windows volume warning: ${formatWindowsVolumeConcern(concern)}`)
}
}
/** Notify once after the UI is ready; stderr carries the exact paths. */
function notifyWindowsVolumeConcerns(
runtime: ElectronDesktopRuntime,
logger: DesktopLogger,
concerns: readonly WindowsVolumeConcern[],
): void {
if (concerns.length === 0) return
@@ -101,9 +103,7 @@ function notifyWindowsVolumeConcerns(
body: `${concerns[0]?.label ?? 'A configured path'} is on a volume that may break sandboxed commands or plugin installs.`,
})
} catch (cause) {
process.stderr.write(
`${BIN_NAME}: failed to show Windows volume warning: ${cause instanceof Error ? cause.message : String(cause)}\n`,
)
logger.error(`${BIN_NAME}: failed to show Windows volume warning: ${cause instanceof Error ? cause.message : String(cause)}`)
}
}
@@ -120,6 +120,7 @@ async function start(): Promise<void> {
let profileStatePath: string | undefined
let shutdown: DesktopShutdown | undefined
let removeShutdownRequests: (() => void) | undefined
let removeUncaughtExceptionLogging: (() => void) | undefined
let disposeDshRuntime: (() => void) | undefined
let disposePnpmRuntime: (() => void) | undefined
let fileExporter: FileExporter | undefined
@@ -132,17 +133,16 @@ async function start(): Promise<void> {
logSink.purgeOlderThan(7)
logSink.writeHeader(`--- ${BIN_NAME} ${PRODUCT_NAME} ${desktopProductVersion()} ${process.platform} node ${process.version} run ${Date.now()} ---`)
const electronLogger = new ElectronStderrLogger(logSink)
process.on('uncaughtException', (error) => { electronLogger.errorCause(error) })
process.on('unhandledRejection', (reason) => {
electronLogger.error(`dsh-plugin-desktop: unhandled rejection: ${reason instanceof Error ? reason.stack ?? reason.message : String(reason)}`)
})
const nativeExit = createDesktopExitCoordinator(
{
prepareToQuit: () => { runtime.prepareToQuit() },
relaunch: () => { app.relaunch() },
exit: code => { app.exit(code) },
},
() => { removeShutdownRequests?.() },
() => {
removeShutdownRequests?.()
removeUncaughtExceptionLogging?.()
},
)
let restartRequested = false
runtime = new ElectronDesktopRuntime(async () => {
@@ -176,6 +176,11 @@ async function start(): Promise<void> {
finalExit,
)
const requestQuit = (code: number): void => { void shutdown.request(code) }
removeUncaughtExceptionLogging = installDesktopUncaughtExceptionLogging(
process,
electronLogger,
requestQuit,
)
removeShutdownRequests = installShutdownRequests(process, app, requestQuit)
app.on('second-instance', () => { runtime.show() })
@@ -195,12 +200,12 @@ async function start(): Promise<void> {
{ label: 'desktop user data', path: app.getPath('userData') },
{ label: 'DSH home', path: homeDir },
])
warnWindowsVolumeConcerns(windowsVolumeConcerns)
warnWindowsVolumeConcerns(electronLogger, windowsVolumeConcerns)
const failLoudProcess: FailLoudProcess = {
on: (event, handler) => process.on(event, handler),
off: (event, handler) => process.off(event, handler),
stderr: process.stderr,
stderr: electronLogger,
exit: finalExit,
}
installFailLoud(BIN_NAME, failLoudProcess, async () => {
@@ -322,16 +327,17 @@ async function start(): Promise<void> {
homeDir: prepared.homeDir,
})
await runtime.mountScheduled()
notifySkippedOptionalEntries(runtime, prepared.skippedOptionalEntries)
notifyWindowsVolumeConcerns(runtime, windowsVolumeConcerns)
notifySkippedOptionalEntries(runtime, electronLogger, prepared.skippedOptionalEntries)
notifyWindowsVolumeConcerns(runtime, electronLogger, windowsVolumeConcerns)
if (profileStartup.rolledBackFrom !== undefined) {
notifyProfileRecovery(
runtime,
electronLogger,
`Reopened last-known-good profile ${activeProfileName}.`,
)
}
} catch (cause) {
process.stderr.write(`${BIN_NAME}: ${cause instanceof Error ? cause.stack ?? cause.message : String(cause)}\n`)
electronLogger.errorCause(cause)
let exitCode = 1
if (profileStartup !== undefined && profileStatePath !== undefined) {
const retryLastKnownGood = profileStartup.profileName !== profileStartup.state.lastKnownGood
@@ -342,11 +348,12 @@ async function start(): Promise<void> {
exitCode = 0
notifyProfileRecovery(
runtime,
electronLogger,
`Reopening last-known-good profile ${profileStartup.state.lastKnownGood}.`,
)
}
} catch (stateCause) {
process.stderr.write(`${BIN_NAME}: failed to roll back desktop profile state: ${stateCause instanceof Error ? stateCause.message : String(stateCause)}\n`)
electronLogger.error(`dsh-plugin-desktop: failed to roll back desktop profile state: ${stateCause instanceof Error ? stateCause.message : String(stateCause)}`)
}
}
await shutdown.request(exitCode)
+26 -1
View File
@@ -1,20 +1,45 @@
/** Mask secret-shaped substrings in a rendered log line. */
const MASK = '****'
const COOKIE_HEADER = /\b(Set-Cookie|Cookie)\s*:[^\r\n]*/giu
const WEB_URL = /https?:\/\/[^\s<>"']+/giu
const SENSITIVE_QUERY_KEY = /(?:auth|code|credential|key|password|secret|signature|token)/iu
const NAMED_SECRET = /\b(api[_-]?key|auth|client[_-]?secret|credential|password|passwd|refresh[_-]?token|secret|session(?:id)?|signature|token)\b(\s*[:=]\s*)[^\s,;&]+/giu
/** Secret-shaped patterns applied in order to a rendered log line. */
const SECRET_PATTERNS: readonly RegExp[] = [
/\bsk-[A-Za-z0-9]{12,}/gu, // OpenAI/DeepSeek-style sk- keys
/\b[a-zA-Z0-9]{32,}\b/gu, // long hex/base64 tokens
/Bearer\s+[A-Za-z0-9._-]+/giu, // Authorization bearer tokens
/Basic\s+[A-Za-z0-9+/]+={0,2}/giu, // Authorization basic credentials
]
function maskUrl(raw: string): string {
const trailing = /[),.;]+$/u.exec(raw)?.[0] ?? ''
const value = trailing === '' ? raw : raw.slice(0, -trailing.length)
try {
const url = new URL(value)
if (url.username !== '') url.username = MASK
if (url.password !== '') url.password = MASK
for (const name of url.searchParams.keys()) {
if (SENSITIVE_QUERY_KEY.test(name)) url.searchParams.set(name, MASK)
}
return `${url.href}${trailing}`
} catch {
return raw
}
}
/** Replace secret-shaped substrings, preserving a short leading prefix. */
export function maskSecrets(text: string): string {
let out = text
.replace(COOKIE_HEADER, (_match, name: string) => `${name}: ${MASK}`)
.replace(WEB_URL, maskUrl)
.replace(NAMED_SECRET, (_match, name: string, separator: string) => `${name}${separator}${MASK}`)
for (const pattern of SECRET_PATTERNS) {
out = out.replace(pattern, (match) => {
if (match.startsWith('Bearer')) return 'Bearer ****'
const authorizationScheme = /^(Bearer|Basic)/iu.exec(match)?.[1]
if (authorizationScheme !== undefined) return `${authorizationScheme} ****`
return `${match.slice(0, 3)}${MASK}`
})
}
@@ -1,8 +1,12 @@
import { EventEmitter } from 'node:events'
import { mkdtempSync, readFileSync } from 'node:fs'
import { tmpdir } from 'node:os'
import { join } from 'node:path'
import { describe, expect, it, vi } from 'vitest'
import { ElectronStderrLogger } from '../src/desktop-logger.ts'
import {
ElectronStderrLogger,
installDesktopUncaughtExceptionLogging,
} from '../src/desktop-logger.ts'
import { LogFileSink } from '../src/log-files.ts'
function todaySuffix(): string {
@@ -43,4 +47,68 @@ describe('ElectronStderrLogger', () => {
const day = todaySuffix()
expect(readFileSync(join(dir, `dsh-${day}.log`), 'utf8')).toContain('crash here')
})
it('masks secrets in the file and stderr outputs', () => {
const { s, dir } = sink()
const stderrSpy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true)
const logger = new ElectronStderrLogger(s)
logger.error('request failed with Bearer abc.def.secret')
const day = todaySuffix()
const text = readFileSync(join(dir, `dsh-${day}.log`), 'utf8')
expect(text).toContain('Bearer ****')
expect(text).not.toContain('abc.def.secret')
expect(stderrSpy).toHaveBeenCalledWith('request failed with Bearer ****\n')
stderrSpy.mockRestore()
})
it('accepts fail-loud stderr chunks without adding a second newline', () => {
const { s, dir } = sink()
const stderrSpy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true)
const logger = new ElectronStderrLogger(s)
logger.write('dsh-plugin-desktop: fatal load failure: Bearer abc.def.secret\n')
const day = todaySuffix()
const text = readFileSync(join(dir, `dsh-${day}.log`), 'utf8')
expect(text).toContain('fatal load failure: Bearer ****\n')
expect(text).not.toContain('abc.def.secret')
expect(stderrSpy).toHaveBeenCalledWith('dsh-plugin-desktop: fatal load failure: Bearer ****\n')
stderrSpy.mockRestore()
})
it('logs the first uncaught exception and requests a fatal exit', () => {
const { s, dir } = sink()
const stderrSpy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true)
const logger = new ElectronStderrLogger(s)
const proc = new EventEmitter()
const exit = vi.fn()
const remove = installDesktopUncaughtExceptionLogging(proc, logger, exit)
proc.emit('uncaughtException', new Error('fatal Bearer abc.def.secret'))
proc.emit('uncaughtException', new Error('second failure'))
const day = todaySuffix()
const text = readFileSync(join(dir, `dsh-${day}.log`), 'utf8')
expect(text).toContain('fatal Bearer ****')
expect(text).not.toContain('abc.def.secret')
expect(text).not.toContain('second failure')
expect(exit).toHaveBeenCalledOnce()
expect(exit).toHaveBeenCalledWith(1)
expect(proc.listenerCount('uncaughtException')).toBe(0)
remove()
stderrSpy.mockRestore()
})
it('falls back to masked stderr when the file sink fails', () => {
const { s } = sink()
vi.spyOn(s, 'write').mockImplementation(() => { throw new Error('disk full') })
const stderrSpy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true)
const logger = new ElectronStderrLogger(s)
expect(() => { logger.error('failed with Bearer abc.def.secret') }).not.toThrow()
expect(stderrSpy).toHaveBeenCalledWith('failed with Bearer ****\n')
stderrSpy.mockRestore()
})
})
@@ -67,4 +67,15 @@ describe('LogFileSink', () => {
expect(text.split('\n')[0]).toBe('--- dsh 2.0.0 darwin run 123 ---')
expect(text).toContain('after header')
})
it('masks secrets at the file boundary', () => {
const { s, dir } = sink()
s.write('error', 'Authorization: Bearer abc.def.secret')
const day = todaySuffix()
const text = readFileSync(join(dir, `dsh-${day}.log`), 'utf8')
expect(text).toContain('Bearer ****')
expect(text).not.toContain('abc.def.secret')
})
})
@@ -14,6 +14,31 @@ describe('maskSecrets', () => {
expect(masked).not.toContain('abc.def.ghi')
})
it('masks basic authorization credentials', () => {
const masked = maskSecrets('Authorization: Basic dXNlcjpwYXNzd29yZA==')
expect(masked).toBe('Authorization: Basic ****')
expect(masked).not.toContain('dXNlcjpwYXNzd29yZA==')
})
it('masks cookie header values', () => {
const masked = maskSecrets('Cookie: session=short-secret; theme=dark')
expect(masked).toBe('Cookie: ****')
expect(masked).not.toContain('short-secret')
})
it('masks URL userinfo and sensitive query values', () => {
const masked = maskSecrets('GET https://user:[email protected]/api?token=short&mode=fast')
expect(masked).toBe('GET https://****:****@example.com/api?token=****&mode=fast')
expect(masked).not.toContain('user:pass')
expect(masked).not.toContain('token=short')
})
it('masks named secret fields even when their values are short', () => {
const masked = maskSecrets('api_key=short password: hunter2 mode=fast')
expect(masked).toBe('api_key=**** password: **** mode=fast')
expect(masked).not.toContain('hunter2')
})
it('leaves ordinary prose untouched', () => {
expect(maskSecrets('hello world, profile "desktop"')).toBe('hello world, profile "desktop"')
})