diff --git a/src/audio/ffmpeg-diagnostics.test.ts b/src/audio/ffmpeg-diagnostics.test.ts new file mode 100644 index 0000000..fb75db5 --- /dev/null +++ b/src/audio/ffmpeg-diagnostics.test.ts @@ -0,0 +1,83 @@ +import { describe, it, expect } from "vitest"; +import { PassThrough } from "node:stream"; +import { collectFfmpegDiagnostics } from "./ffmpeg-diagnostics.js"; + +async function finish(stream: PassThrough): Promise { + const ended = new Promise((resolve) => stream.once("end", resolve)); + stream.end(); + await ended; +} + +describe("bounded FFmpeg diagnostics", () => { + for (const [label, line, expected] of [ + ["an apostrophe in the real FFmpeg URL error format", "Error opening input file http://127.0.0.1:9/audio?filename=artist's-song&api_key=quoted-secret.", "Error opening input file [URL omitted]"], + ["a space in URL userinfo", 'Error opening input file https://user:space secret@cdn.example/audio?token=space-secret.', "Error opening input file [URL omitted]"], + ["multiple URLs", 'Error opening inputs https://cdn.example/a?filename=artist\'s-song&key=first-secret and https://cdn.example/b?token=second-secret', "Error opening inputs [URL omitted]"], + ["quotes and spaces in a request target", "GET /audio?filename=artist's song&api_key=request-secret HTTP/1.1", "GET /audio?[query omitted]"], + ["an apostrophe in a Bearer value", "Token rejected Bearer prefix'quoted bearer-secret", "Token rejected Bearer [omitted]"], + ]) { + it(`omits the entire sensitive suffix after ${label}`, async () => { + const stream = new PassThrough(); + const diagnostics = collectFfmpegDiagnostics(stream); + stream.write(line + "\n"); + await finish(stream); + expect(diagnostics.getTail()).toBe(expected); + }); + } + + for (const splitDelimiter of [false, true]) { + it(`omits folded authentication values with ${splitDelimiter ? "chunk-split" : "intact"} CRLF`, async () => { + const stream = new PassThrough(); + const diagnostics = collectFfmpegDiagnostics(stream); + stream.write(`Authorization: Basic header-secret\r${splitDelimiter ? "" : "\n"}`); + if (splitDelimiter) stream.write("\n"); + stream.write(" continuation-secret\r\nHTTP error 401\r\n"); + await finish(stream); + expect(diagnostics.getTail()).toContain("HTTP error 401"); + expect(diagnostics.getTail()).not.toContain("header-secret"); + expect(diagnostics.getTail()).not.toContain("continuation-secret"); + }); + } + + it("redacts URLs and headers split across arbitrary byte and UTF-8 boundaries", async () => { + const stream = new PassThrough(); + const diagnostics = collectFfmpegDiagnostics(stream); + const payload = Buffer.from("解码失败 https://user:user-secret@cdn.example/audio?token=query-secret#fragment-secret\rCookie: cookie-secret\nAuthorization: Bearer bearer-secret\nGET /audio?token=request-secret HTTP/1.1\nfinal error"); + for (const byte of payload) stream.write(Buffer.from([byte])); + await finish(stream); + expect(diagnostics.getTail()).toContain("解码失败"); + expect(diagnostics.getTail()).toContain("final error"); + for (const secret of ["user-secret", "query-secret", "fragment-secret", "cookie-secret", "bearer-secret", "request-secret"]) { + expect(diagnostics.getTail()).not.toContain(secret); + } + }); + + it("omits oversized raw lines without retaining an unsafe credential suffix", async () => { + const stream = new PassThrough(); + const diagnostics = collectFfmpegDiagnostics(stream); + stream.write("Cookie: " + "x".repeat(100000)); + stream.write("oversized-secret\r\n folded-oversized-secret\r\nHTTP error 403\n"); + await new Promise((resolve) => setImmediate(resolve)); + expect(diagnostics.getTail()).toContain("HTTP error 403"); + expect(diagnostics.getTail()).not.toContain("oversized-secret"); + stream.write("decoder warning\n".repeat(10000)); + stream.write("last useful error\n"); + await finish(stream); + expect(diagnostics.getTail().length).toBeLessThanOrEqual(4096); + expect(diagnostics.getTail()).toContain("last useful error"); + expect(diagnostics.getTail()).not.toContain("oversized-secret"); + }); + + it("withholds an incomplete credential line until it can be safely sanitized", async () => { + const stream = new PassThrough(); + const diagnostics = collectFfmpegDiagnostics(stream); + stream.write("decoder warning\nhttps://user:partial-secret@"); + await new Promise((resolve) => setImmediate(resolve)); + expect(diagnostics.getTail()).toContain("decoder warning"); + expect(diagnostics.getTail()).not.toContain("partial-secret"); + stream.write("cdn.example/audio?token=last-secret"); + await finish(stream); + expect(diagnostics.getTail()).not.toContain("partial-secret"); + expect(diagnostics.getTail()).not.toContain("last-secret"); + }); +}); diff --git a/src/audio/ffmpeg-diagnostics.ts b/src/audio/ffmpeg-diagnostics.ts new file mode 100644 index 0000000..701da7a --- /dev/null +++ b/src/audio/ffmpeg-diagnostics.ts @@ -0,0 +1,93 @@ +import type { Readable } from "node:stream"; +import { StringDecoder } from "node:string_decoder"; + +const MAX_LINE_CHARS = 2048; +const MAX_TAIL_CHARS = 4096; + +export interface FfmpegDiagnostics { + getTail(): string; +} + +/** + * Drain independently of the PCM pipe: unread stderr can block FFmpeg even + * when stdout is being consumed. Keep only complete, sanitized lines. Never + * retain a suffix of an oversized raw line: it may have lost its URL/header + * prefix and would no longer be possible to redact safely. + */ +export function collectFfmpegDiagnostics(stderr: Readable | null): FfmpegDiagnostics { + let tail = ""; + let pending = ""; + let discardLine = false; + let suppressHeaderContinuation = false; + let previousCR = false; + const decoder = new StringDecoder("utf8"); + + const append = (text: string): void => { + if (text) previousCR = false; + if (discardLine) return; + if (pending.length + text.length > MAX_LINE_CHARS) { + pending = ""; + discardLine = true; + return; + } + pending += text; + }; + + const finishLine = (): void => { + if (discardLine) { + tail = (tail + "[oversized diagnostic line omitted]\n").slice(-MAX_TAIL_CHARS); + // An omitted line may be an authentication header. Omit folded values. + suppressHeaderContinuation = true; + } else if (pending) { + const line = pending + .replace(/\x1b\[[0-?]*[ -/]*[@-~]/g, "") + .replace(/[\x00-\x08\x0b\x0c\x0e-\x1f\x7f]/g, ""); + const authHeader = /\b(?:cookie|set-cookie|authorization|proxy-authorization)\s*[:=]/i.test(line); + if (authHeader || (suppressHeaderContinuation && /^\s/.test(line))) { + tail = (tail + "[authentication header omitted]\n").slice(-MAX_TAIL_CHARS); + suppressHeaderContinuation = true; + } else { + suppressHeaderContinuation = false; + const sanitized = line + // URLs and credentials can contain quotes or spaces. Keep the error + // prefix only; guessing a closing delimiter could expose a suffix. + .replace(/\b[a-z][a-z\d+.-]*:\/\/[\s\S]*/i, "[URL omitted]") + // FFmpeg can also print a request target without the scheme/host. + .replace(/\?[\s\S]*/, "?[query omitted]") + .replace(/\bBearer\s+[\s\S]*/i, "Bearer [omitted]"); + tail = (tail + sanitized + "\n").slice(-MAX_TAIL_CHARS); + } + } else { + suppressHeaderContinuation = false; + } + pending = ""; + discardLine = false; + }; + + const consume = (text: string): void => { + const separators = /[\r\n]/g; + let start = 0; + for (let match = separators.exec(text); match; match = separators.exec(text)) { + append(text.slice(start, match.index)); + if (match[0] === "\n" && previousCR) { + previousCR = false; + } else { + finishLine(); + previousCR = match[0] === "\r"; + } + start = match.index + 1; + } + append(text.slice(start)); + }; + + stderr?.on("data", (chunk: Buffer) => consume(decoder.write(chunk))); + stderr?.on("end", () => { + consume(decoder.end()); + finishLine(); + }); + // Resume explicitly as attaching a listener does not resume an already + // paused Readable. No player pause/backpressure operation touches stderr. + stderr?.resume(); + + return { getTail: () => tail.trimEnd() }; +} diff --git a/src/audio/player.test.ts b/src/audio/player.test.ts index d19b36f..9dd96ca 100644 --- a/src/audio/player.test.ts +++ b/src/audio/player.test.ts @@ -2,10 +2,20 @@ import { describe, it, expect, vi } from "vitest"; import { mkdtempSync, writeFileSync, existsSync } from "node:fs"; import { tmpdir } from "node:os"; import { join } from "node:path"; -import { Readable } from "node:stream"; +import { Readable, PassThrough } from "node:stream"; +import { EventEmitter } from "node:events"; +import { spawn, type ChildProcess } from "node:child_process"; +import pino from "pino"; import { buildFfmpegArgs, shouldUsePowerShellDownload, cleanupTempDir, shouldEndOnStall, volumeToFactor, AudioPlayer } from "./player.js"; import type { Logger } from "../logger.js"; +// Only replace process creation in the regression cases below. Their pipes, +// write callbacks and backpressure are real OS resources, rather than mocks. +vi.mock("node:child_process", async (importOriginal) => { + const actual = await importOriginal(); + return { ...actual, spawn: vi.fn(actual.spawn) }; +}); + function getHeadersArg(args: string[]): string { const idx = args.indexOf("-headers"); if (idx === -1) return ""; @@ -36,6 +46,12 @@ describe("buildFfmpegArgs", () => { expect(args).not.toContain("-headers"); }); + it("disables periodic progress stats for both network and file inputs", () => { + for (const input of ["https://example.com/song.mp3", "C:/temp/song.audio"]) { + expect(buildFfmpegArgs(input, 0)).toContain("-nostats"); + } + }); + it("includes resilient reconnect flags for all URLs", () => { const args = buildFfmpegArgs("https://example.com/song.mp3", 0); expect(args).toContain("-reconnect"); @@ -224,6 +240,249 @@ const silentLogger = { }, } as unknown as Logger; +describe("AudioPlayer FFmpeg stderr handling", () => { + const producer = ` + const pressure = 'decoder diagnostic\\n'.repeat(180000); + process.stderr.write(pressure, () => { + process.stderr.write('HTTP error 403 for https://user:password@cdn.example/audio?token=signed-secret#fragment-secret\\n'); + process.stderr.write('Cookie: cookie-secret\\nAuthorization: Bearer bearer-secret\\n'); + process.stderr.write('final decoder failure', () => { + process.stdout.write(Buffer.alloc(7680), () => process.exit(1)); + }); + }); + `; + + function recordedLogger() { + const records: Array<{ level: string; fields: Record; message: string }> = []; + const capture = (level: string) => (fields: Record, message: string) => { + records.push({ level, fields, message }); + }; + return { + records, + logger: { ...silentLogger, info: capture("info"), warn: capture("warn") } as unknown as Logger, + }; + } + + async function pipeProducer(script: string) { + const actual = await vi.importActual("node:child_process"); + let child!: ChildProcess; + let requestedArgs: readonly string[] = []; + let closed!: Promise; + vi.mocked(spawn).mockImplementationOnce((_command, args, options) => { + requestedArgs = args ?? []; + child = actual.spawn(process.execPath, ["-e", script], options); + closed = new Promise((resolve) => child.once("close", resolve)); + return child; + }); + return { + get child() { return child; }, + get args() { return requestedArgs; }, + get closed() { return closed; }, + }; + } + + for (const path of ["URL", "temp file"] as const) { + it(`drains the ${path} child stderr so a large diagnostic write cannot block PCM output`, async () => { + const { records, logger } = recordedLogger(); + const producerProcess = await pipeProducer(producer); + const player = new AudioPlayer(logger); + let frameCount = 0; + player.on("frame", () => frameCount++); + let deadline: ReturnType | undefined; + try { + if (path === "URL") { + player.play("https://cdn.example/audio?token=input-secret"); + } else { + // The real downloader marks playing before calling this file path. + const internal = player as unknown as { + state: string; + spawnFfmpegFromFile(file: string, seek: number, session: number): void; + }; + internal.state = "playing"; + internal.spawnFfmpegFromFile("downloaded.audio", 0, player.getPlaybackSessionId()); + } + const outcome = await Promise.race([ + producerProcess.closed, + new Promise((resolve) => { + deadline = setTimeout(() => resolve("stderr blocked audio output"), 1500); + }), + ]); + expect(outcome).toBe(1); + expect(producerProcess.args).toContain("-nostats"); + await vi.waitFor(() => expect(frameCount).toBeGreaterThan(0)); + const exit = records.find((record) => record.message === "FFmpeg exited"); + expect(exit?.fields.stderr).toContain("final decoder failure"); + expect(exit?.fields.stderr).toContain("HTTP error 403"); + const logged = JSON.stringify(records); + for (const secret of ["password", "signed-secret", "fragment-secret", "cookie-secret", "bearer-secret", "input-secret"]) { + expect(logged).not.toContain(secret); + } + expect(String(exit?.fields.stderr).length).toBeLessThanOrEqual(4096); + } finally { + if (deadline) clearTimeout(deadline); + player.stop(); + if (producerProcess.child.exitCode === null) producerProcess.child.kill("SIGKILL"); + await producerProcess.closed; + } + }); + + it(`does not expose the ${path} input credentials through serialized spawn errors`, async () => { + const actual = await vi.importActual("node:child_process"); + let child!: ChildProcess; + let closed!: Promise; + vi.mocked(spawn).mockImplementationOnce((_command, args, options) => { + child = actual.spawn(join(tmpdir(), "tsbot-ffmpeg-does-not-exist"), args, options); + closed = new Promise((resolve) => child.once("close", () => resolve())); + return child; + }); + const player = new AudioPlayer(silentLogger); + const emitted = new Promise((resolve) => player.once("error", resolve)); + try { + const input = "https://user:spawn-password@cdn.example/audio?token=spawn-secret"; + if (path === "URL") { + player.play(input); + } else { + (player as unknown as { spawnFfmpegFromFile(file: string, seek: number, session: number): void }) + .spawnFfmpegFromFile(input, 0, player.getPlaybackSessionId()); + } + const error = await emitted; + expect(error).toBeInstanceOf(Error); + expect(error.message).toContain("ENOENT"); + const serialized = JSON.stringify(pino.stdSerializers.err(error)); + expect(serialized).not.toContain("spawn-secret"); + expect(serialized).not.toContain("spawn-password"); + await closed; + } finally { + player.stop(); + } + }); + } + + it("logs intentional stop signals at info level", async () => { + const { records, logger } = recordedLogger(); + const producerProcess = await pipeProducer("process.stdout.write(Buffer.from([0])); setInterval(() => {}, 1000);"); + const player = new AudioPlayer(logger); + try { + player.play("https://cdn.example/audio"); + await new Promise((resolve) => producerProcess.child.stdout!.once("data", () => resolve())); + player.stop(); + await producerProcess.closed; + const exit = records.find((record) => record.message === "FFmpeg exited"); + expect(exit?.level).toBe("info"); + } finally { + player.stop(); + if (producerProcess.child.exitCode === null) producerProcess.child.kill("SIGKILL"); + await producerProcess.closed; + } + }); + + it("reports a sanitized diagnostic tail when a child exits from an unexpected signal", async () => { + const { records, logger } = recordedLogger(); + const child = Object.assign(new EventEmitter(), { + pid: undefined, + stdout: new PassThrough(), + stderr: new PassThrough(), + }); + vi.mocked(spawn).mockReturnValueOnce(child as unknown as ChildProcess); + const player = new AudioPlayer(logger); + try { + player.play("https://cdn.example/audio"); + child.stderr.write("decoder crashed for https://cdn.example/audio?token=signal-secret"); + const ended = new Promise((resolve) => child.stderr.once("end", resolve)); + child.stderr.end(); + await ended; + child.emit("exit", null, "SIGSEGV"); + child.emit("close", null, "SIGSEGV"); + const exit = records.find((record) => record.message === "FFmpeg exited"); + expect(exit?.level).toBe("warn"); + expect(exit?.fields.signal).toBe("SIGSEGV"); + expect(exit?.fields.stderr).toContain("decoder crashed"); + expect(JSON.stringify(records)).not.toContain("signal-secret"); + } finally { + player.stop(); + child.stdout.destroy(); + child.stderr.destroy(); + } + }); + + it("keeps draining an old child's stderr without mixing its late diagnostics or exit into a new session", async () => { + const { records, logger } = recordedLogger(); + const makeChild = () => Object.assign(new EventEmitter(), { + pid: undefined, + stdout: new PassThrough(), + stderr: new PassThrough(), + }); + const oldChild = makeChild(); + const newChild = makeChild(); + vi.mocked(spawn) + .mockReturnValueOnce(oldChild as unknown as ChildProcess) + .mockReturnValueOnce(newChild as unknown as ChildProcess); + const player = new AudioPlayer(logger); + try { + player.play("https://cdn.example/old"); + const oldSession = player.getPlaybackSessionId(); + player.play("https://cdn.example/new"); + const newSession = player.getPlaybackSessionId(); + oldChild.stderr.write("old late decoder failure https://cdn.example/old?token=old-secret\n".repeat(1000)); + newChild.stderr.write("new decoder failure\n"); + await new Promise((resolve) => setImmediate(resolve)); + expect(oldChild.stderr.readableLength).toBe(0); + oldChild.emit("exit", 1, null); + oldChild.stderr.end(); + oldChild.emit("close", 1, null); + expect(player.getState()).toBe("playing"); + vi.useFakeTimers(); + const internal = player as unknown as { frameLoopRunning: boolean; startFrameLoop(): void }; + internal.frameLoopRunning = false; + internal.startFrameLoop(); + vi.advanceTimersByTime(6000); + const stall = records.find((record) => record.message === "FFmpeg stopped outputting data, ending track"); + expect(stall?.fields.sessionId).toBe(newSession); + expect(stall?.fields.stderr).toContain("new decoder failure"); + expect(stall?.fields.stderr).not.toContain("old late decoder failure"); + const oldExit = records.find((record) => record.message === "FFmpeg exited"); + expect(oldExit?.fields.sessionId).toBe(oldSession); + expect(JSON.stringify(records)).not.toContain("old-secret"); + } finally { + vi.useRealTimers(); + player.stop(); + oldChild.stdout.destroy(); + oldChild.stderr.destroy(); + newChild.stdout.destroy(); + newChild.stderr.destroy(); + } + }); + + it("includes the current child's sanitized diagnostic tail when the stall watchdog ends playback", async () => { + const { records, logger } = recordedLogger(); + const producerProcess = await pipeProducer(` + process.stderr.write('HTTP error 403: https://cdn.example/audio?token=stall-secret\\n'); + process.stdout.write(Buffer.from([0])); + setInterval(() => {}, 1000); + `); + const player = new AudioPlayer(logger); + try { + player.play("https://cdn.example/audio"); + await new Promise((resolve) => producerProcess.child.stdout!.once("data", () => resolve())); + vi.useFakeTimers(); + // Restart scheduling under the test clock, without changing EOF state. + const internal = player as unknown as { frameLoopRunning: boolean; startFrameLoop(): void }; + internal.frameLoopRunning = false; + internal.startFrameLoop(); + vi.advanceTimersByTime(6000); + const stall = records.find((record) => record.message === "FFmpeg stopped outputting data, ending track"); + expect(stall?.fields.stderr).toContain("HTTP error 403"); + expect(JSON.stringify(records)).not.toContain("stall-secret"); + expect(player.getState()).toBe("idle"); + } finally { + vi.useRealTimers(); + player.stop(); + if (producerProcess.child.exitCode === null) producerProcess.child.kill("SIGKILL"); + await producerProcess.closed; + } + }); +}); + function applyPlayerVolume(player: AudioPlayer, pcm: Buffer): Buffer { return ( player as unknown as { applyVolume(input: Buffer): Buffer } diff --git a/src/audio/player.ts b/src/audio/player.ts index 19d5397..c526062 100644 --- a/src/audio/player.ts +++ b/src/audio/player.ts @@ -7,6 +7,7 @@ import { join } from "node:path"; import { createOpusEncoder, PCM_FRAME_BYTES, type Encoder } from "./encoder.js"; import type { Readable } from "node:stream"; import type { Logger } from "../logger.js"; +import { collectFfmpegDiagnostics, type FfmpegDiagnostics } from "./ffmpeg-diagnostics.js"; const require = createRequire(import.meta.url); const ffmpegPath: string | null = require("ffmpeg-static"); @@ -52,6 +53,17 @@ export function getFfmpegCommand(): string { return resolvedFfmpeg; } +function safeFfmpegSpawnError(err: Error): Error { + // Node spawn errors include spawnargs; Pino's Error serializer copies them, + // including the signed input URL. Preserve a known OS category only. + const allowedCodes = new Set(["ENOENT", "EACCES", "EPERM", "ENOEXEC", "EMFILE", "ENFILE", "ENOMEM", "EAGAIN", "EINVAL"]); + const code = (err as NodeJS.ErrnoException).code; + const safeCode = typeof code === "string" && allowedCodes.has(code) ? code : undefined; + const safeError = new Error(`FFmpeg failed to start${safeCode ? ` (${safeCode})` : ""}`); + if (safeCode) Object.assign(safeError, { code: safeCode }); + return safeError; +} + const BROWSER_UA = "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36"; @@ -74,7 +86,7 @@ export function cleanupTempDir(dir: string): void { } export function buildFfmpegArgs(url: string, seekSeconds: number): string[] { - const args: string[] = []; + const args: string[] = ["-nostats"]; const isHttp = /^https?:\/\//i.test(url); const isBilibili = isHttp && (url.includes("bilivideo") || url.includes("bilibili")); @@ -167,6 +179,8 @@ const FRAME_DURATION_MS = 20; export class AudioPlayer extends EventEmitter { private ffmpeg: ChildProcess | null = null; + private ffmpegDiagnostics: FfmpegDiagnostics | null = null; + private readonly intentionalCleanup = new WeakSet(); private encoder: Encoder; private state: PlayerState = "idle"; private volume = 75; @@ -258,6 +272,9 @@ export class AudioPlayer extends EventEmitter { const ffmpegBin = getFfmpegCommand(); this.ffmpeg = spawn(ffmpegBin, args, { stdio: ["ignore", "pipe", "pipe"] }); + const child = this.ffmpeg; + const diagnostics = collectFfmpegDiagnostics(child.stderr); + this.ffmpegDiagnostics = diagnostics; const currentPid = this.ffmpeg.pid; if (currentPid) { @@ -280,7 +297,6 @@ export class AudioPlayer extends EventEmitter { this.ffmpeg.on("exit", (code, signal) => { if (currentPid) globalActivePids.delete(currentPid); - this.logger.info({ pid: currentPid, code, signal }, "FFmpeg exited"); // 只有当前会话的进程结束才置空变量 if (this.sessionId === currentSessionId) { @@ -288,11 +304,21 @@ export class AudioPlayer extends EventEmitter { } }); + // close follows stderr's end, so final unterminated diagnostics are ready. + this.ffmpeg.on("close", (code, signal) => { + const context = { pid: currentPid, sessionId: currentSessionId, code, signal }; + if (!this.intentionalCleanup.has(child) && ((typeof code === "number" && code !== 0) || signal !== null)) { + this.logger.warn({ ...context, stderr: diagnostics.getTail() }, "FFmpeg exited"); + } else { + this.logger.info(context, "FFmpeg exited"); + } + }); + this.ffmpeg.on("error", (err) => { if (this.sessionId === currentSessionId) { this.spawnFailed = true; this.consecutiveFailures++; - this.emit("error", err); + this.emit("error", safeFfmpegSpawnError(err)); } }); @@ -332,10 +358,7 @@ export class AudioPlayer extends EventEmitter { ); this.downloader = ps; - let stderrTail = ""; - ps.stderr!.on("data", (chunk: Buffer) => { - stderrTail = (stderrTail + chunk.toString()).slice(-500); - }); + const diagnostics = collectFfmpegDiagnostics(ps.stderr); ps.on("exit", (code, signal) => { if (this.sessionId !== sessionId) { @@ -344,7 +367,6 @@ export class AudioPlayer extends EventEmitter { } this.downloader = null; if (code !== 0) { - this.logger.warn({ code, signal, stderr: stderrTail }, "PowerShell download failed"); this.spawnFailed = true; this.consecutiveFailures++; this.state = "idle"; @@ -356,6 +378,12 @@ export class AudioPlayer extends EventEmitter { this.spawnFfmpegFromFile(tempFile, seekSeconds, sessionId); }); + ps.on("close", (code, signal) => { + if (!this.intentionalCleanup.has(ps) && ((typeof code === "number" && code !== 0) || signal !== null)) { + this.logger.warn({ pid: ps.pid, sessionId, code, signal, stderr: diagnostics.getTail() }, "PowerShell download failed"); + } + }); + ps.on("error", (err) => { if (this.sessionId !== sessionId) return; this.downloader = null; @@ -386,6 +414,9 @@ export class AudioPlayer extends EventEmitter { const args = buildFfmpegArgs(tempFile, seekSeconds); const ffmpegBin = getFfmpegCommand(); this.ffmpeg = spawn(ffmpegBin, args, { stdio: ["ignore", "pipe", "pipe"] }); + const child = this.ffmpeg; + const diagnostics = collectFfmpegDiagnostics(child.stderr); + this.ffmpegDiagnostics = diagnostics; const currentPid = this.ffmpeg.pid; if (currentPid) { @@ -405,7 +436,6 @@ export class AudioPlayer extends EventEmitter { this.ffmpeg.on("exit", (code, signal) => { if (currentPid) globalActivePids.delete(currentPid); - this.logger.info({ pid: currentPid, code, signal }, "FFmpeg exited"); if (this.sessionId === sessionId) { this.ffmpeg = null; if (this.currentTempDir === tempDirToCleanup) this.currentTempDir = null; @@ -413,11 +443,20 @@ export class AudioPlayer extends EventEmitter { if (tempDirToCleanup) cleanupTempDir(tempDirToCleanup); }); + this.ffmpeg.on("close", (code, signal) => { + const context = { pid: currentPid, sessionId, code, signal }; + if (!this.intentionalCleanup.has(child) && ((typeof code === "number" && code !== 0) || signal !== null)) { + this.logger.warn({ ...context, stderr: diagnostics.getTail() }, "FFmpeg exited"); + } else { + this.logger.info(context, "FFmpeg exited"); + } + }); + this.ffmpeg.on("error", (err) => { if (this.sessionId === sessionId) { this.spawnFailed = true; this.consecutiveFailures++; - this.emit("error", err); + this.emit("error", safeFfmpegSpawnError(err)); } }); @@ -543,6 +582,7 @@ export class AudioPlayer extends EventEmitter { // 立即清空缓冲区,确保切歌瞬间静音 ( this.pcmBuffer = Buffer.alloc(0); + this.ffmpegDiagnostics = null; if (this.ffmpeg) { const procToKill = this.ffmpeg; @@ -557,6 +597,7 @@ export class AudioPlayer extends EventEmitter { if (this.downloader) { const ps = this.downloader; this.downloader = null; + this.intentionalCleanup.add(ps); try { ps.kill("SIGTERM"); } catch { /* already gone */ } } @@ -580,6 +621,7 @@ export class AudioPlayer extends EventEmitter { } private forceCleanup(proc: ChildProcess, pid: number): void { + this.intentionalCleanup.add(proc); if (!globalActivePids.has(pid)) return; try { @@ -664,6 +706,7 @@ export class AudioPlayer extends EventEmitter { duration: this.currentSongDuration, remaining: Math.round(this.currentSongDuration - elapsed), nearEnd: isNearEnd, + stderr: this.ffmpegDiagnostics?.getTail() ?? "", }, "FFmpeg stopped outputting data, ending track"); this.frameLoopRunning = false; // The outer gate guarantees state==="playing" here, so no !=="idle"