mirror of
https://github.com/ZHANGTIANYAO1/teamspeak-music-bot.git
synced 2026-10-01 20:42:50 +08:00
Add diagnostic logging for playback pipeline debugging
Adds info-level logs at each stage of the audio pipeline to help diagnose why playback produces no audible output: - FFmpeg first PCM data received - FFmpeg process exit code - FFmpeg stderr (errors/HTTP/stream info at info level) - First opus frame encoded and emitted - First voice packet sent to TeamSpeak - Error catching in frame encoding loop https://claude.ai/code/session_01EjpEsC2GCsvwbu4n3XC8EE
This commit is contained in:
2 files changed
+48
-10
No files matched your search
+35
-9
@@ -109,11 +109,12 @@ export class AudioPlayer extends EventEmitter {
|
||||
this.logger.debug({ ffmpeg: ffmpegBin }, "Using ffmpeg binary");
|
||||
this.ffmpeg = spawn(ffmpegBin, args, { stdio: ["ignore", "pipe", "pipe"] });
|
||||
|
||||
this.ffmpeg.stderr!.on("data", (data: Buffer) => {
|
||||
this.logger.debug({ stderr: data.toString().trimEnd() }, "FFmpeg stderr");
|
||||
});
|
||||
|
||||
let gotFirstData = false;
|
||||
this.ffmpeg.stdout!.on("data", (chunk: Buffer) => {
|
||||
if (!gotFirstData) {
|
||||
gotFirstData = true;
|
||||
this.logger.info({ bytes: chunk.length }, "FFmpeg: first PCM data received");
|
||||
}
|
||||
this.pcmBuffer = Buffer.concat([this.pcmBuffer, chunk]);
|
||||
// Backpressure: pause FFmpeg stdout when buffer is too large
|
||||
if (this.pcmBuffer.length > AudioPlayer.BUFFER_HIGH_WATER && !this.ffmpegPaused && this.ffmpeg?.stdout) {
|
||||
@@ -122,7 +123,8 @@ export class AudioPlayer extends EventEmitter {
|
||||
}
|
||||
});
|
||||
|
||||
this.ffmpeg.on("close", () => {
|
||||
this.ffmpeg.on("close", (code) => {
|
||||
this.logger.info({ exitCode: code, gotData: gotFirstData, framesPlayed: this.framesPlayed }, "FFmpeg process closed");
|
||||
if (this.sessionId === playSessionId) {
|
||||
this.ffmpeg = null; // Signal frame loop that no more data is coming
|
||||
}
|
||||
@@ -135,6 +137,17 @@ export class AudioPlayer extends EventEmitter {
|
||||
}
|
||||
});
|
||||
|
||||
// Log FFmpeg stderr at info level for debugging playback issues
|
||||
this.ffmpeg.stderr!.on("data", (data: Buffer) => {
|
||||
const msg = data.toString().trimEnd();
|
||||
// Log important FFmpeg messages at info level
|
||||
if (msg.includes("Error") || msg.includes("error") || msg.includes("HTTP") || msg.includes("Opening") || msg.includes("Stream")) {
|
||||
this.logger.info({ ffmpegStderr: msg }, "FFmpeg stderr");
|
||||
} else {
|
||||
this.logger.debug({ stderr: msg }, "FFmpeg stderr");
|
||||
}
|
||||
});
|
||||
|
||||
this.state = "playing";
|
||||
this.startFrameLoop();
|
||||
}
|
||||
@@ -191,10 +204,23 @@ export class AudioPlayer extends EventEmitter {
|
||||
this.ffmpegPaused = false;
|
||||
}
|
||||
|
||||
const adjusted = this.applyVolume(pcmFrame);
|
||||
const opusFrame = this.encoder.encode(adjusted);
|
||||
this.emit("frame", opusFrame);
|
||||
this.framesPlayed++;
|
||||
try {
|
||||
const adjusted = this.applyVolume(pcmFrame);
|
||||
const opusFrame = this.encoder.encode(adjusted);
|
||||
this.emit("frame", opusFrame);
|
||||
this.framesPlayed++;
|
||||
|
||||
if (this.framesPlayed === 1) {
|
||||
this.logger.info({ opusBytes: opusFrame.length }, "First audio frame encoded and emitted");
|
||||
}
|
||||
// Log every ~10 seconds (500 frames * 20ms = 10s)
|
||||
if (this.framesPlayed % 500 === 0) {
|
||||
this.logger.debug({ framesPlayed: this.framesPlayed, elapsed: this.getElapsed() }, "Playback progress");
|
||||
}
|
||||
} catch (err) {
|
||||
this.logger.error({ err }, "Error encoding/sending audio frame");
|
||||
this.emit("error", err as Error);
|
||||
}
|
||||
}
|
||||
|
||||
private applyVolume(pcm: Buffer): Buffer {
|
||||
|
||||
@@ -175,9 +175,21 @@ export class TS3Client extends EventEmitter {
|
||||
}
|
||||
}
|
||||
|
||||
private voiceFramesSent = 0;
|
||||
|
||||
sendVoiceData(opusFrame: Buffer): void {
|
||||
if (!this.client || this.disconnecting) return;
|
||||
this.client.sendVoice(opusFrame, 5);
|
||||
try {
|
||||
this.client.sendVoice(opusFrame, 5);
|
||||
this.voiceFramesSent++;
|
||||
if (this.voiceFramesSent === 1) {
|
||||
this.logger.info({ opusBytes: opusFrame.length, clientId: this.clientId }, "First voice packet sent to TeamSpeak");
|
||||
}
|
||||
} catch (err) {
|
||||
if (this.voiceFramesSent === 0) {
|
||||
this.logger.error({ err }, "Failed to send first voice packet");
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
getIdentityExport(): string {
|
||||
|
||||
Reference in new issue
Block a user