feat: add comprehensive logging to soundboard voice/play pipeline

- Log voice state transitions (Signalling → Connecting → Ready etc.)
- Log play requests with sound name, guild, channel, file path
- Log connection creation, rejoin attempts, and failures
- Log AudioPlayer state changes and errors
- All prefixed with [Soundboard] for easy filtering

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
This commit is contained in:
Daniel 2026-03-06 01:22:28 +01:00
parent c41138f62a
commit 5faf5139ef

View file

@ -225,15 +225,22 @@ const partyActive = new Set<string>();
const nowPlaying = new Map<string, string>(); const nowPlaying = new Map<string, string>();
const connectedSince = new Map<string, string>(); const connectedSince = new Map<string, string>();
// ── Logging helper ──
const SB = '[Soundboard]';
// ── Voice Lifecycle ── // ── Voice Lifecycle ──
async function ensureConnectionReady(connection: VoiceConnection, channelId: string, guildId: string, guild: any): Promise<VoiceConnection> { async function ensureConnectionReady(connection: VoiceConnection, channelId: string, guildId: string, guild: any): Promise<VoiceConnection> {
try { await entersState(connection, VoiceConnectionStatus.Ready, 15_000); return connection; } catch {} console.log(`${SB} ensureConnectionReady: guild=${guildId} channel=${channelId} status=${connection.state.status}`);
try { connection.rejoin({ channelId, selfDeaf: false, selfMute: false }); await entersState(connection, VoiceConnectionStatus.Ready, 15_000); return connection; } catch {} try { await entersState(connection, VoiceConnectionStatus.Ready, 15_000); console.log(`${SB} Connection ready (attempt 1)`); return connection; }
catch (e) { console.warn(`${SB} Attempt 1 failed: ${(e as Error)?.message ?? e}`); }
try { connection.rejoin({ channelId, selfDeaf: false, selfMute: false }); await entersState(connection, VoiceConnectionStatus.Ready, 15_000); console.log(`${SB} Connection ready (rejoin)`); return connection; }
catch (e) { console.warn(`${SB} Rejoin failed: ${(e as Error)?.message ?? e}`); }
try { connection.destroy(); } catch {} try { connection.destroy(); } catch {}
guildAudioState.delete(guildId); guildAudioState.delete(guildId);
console.log(`${SB} Creating fresh connection (attempt 3)...`);
const newConn = joinVoiceChannel({ channelId, guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false }); const newConn = joinVoiceChannel({ channelId, guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false });
try { await entersState(newConn, VoiceConnectionStatus.Ready, 15_000); return newConn; } try { await entersState(newConn, VoiceConnectionStatus.Ready, 15_000); console.log(`${SB} Connection ready (fresh)`); return newConn; }
catch { try { newConn.destroy(); } catch {} guildAudioState.delete(guildId); throw new Error('Voice connection failed after 3 attempts'); } catch (e) { console.error(`${SB} All 3 connection attempts failed: ${(e as Error)?.message ?? e}`); try { newConn.destroy(); } catch {} guildAudioState.delete(guildId); throw new Error('Voice connection failed after 3 attempts'); }
} }
function attachVoiceLifecycle(state: GuildAudioState, guild: any) { function attachVoiceLifecycle(state: GuildAudioState, guild: any) {
@ -245,37 +252,43 @@ function attachVoiceLifecycle(state: GuildAudioState, guild: any) {
let isReconnecting = false; let isReconnecting = false;
connection.on('stateChange', async (oldS: any, newS: any) => { connection.on('stateChange', async (oldS: any, newS: any) => {
console.log(`${SB} Voice state: ${oldS.status}${newS.status} (guild=${state.guildId})`);
if (newS.status === VoiceConnectionStatus.Ready) { if (newS.status === VoiceConnectionStatus.Ready) {
reconnectAttempts = 0; isReconnecting = false; reconnectAttempts = 0; isReconnecting = false;
if (!connectedSince.has(state.guildId)) connectedSince.set(state.guildId, new Date().toISOString()); if (!connectedSince.has(state.guildId)) connectedSince.set(state.guildId, new Date().toISOString());
console.log(`${SB} Voice READY for guild=${state.guildId}`);
return; return;
} }
if (isReconnecting) return; if (isReconnecting) { console.log(`${SB} Already reconnecting, skipping ${newS.status}`); return; }
try { try {
if (newS.status === VoiceConnectionStatus.Disconnected) { if (newS.status === VoiceConnectionStatus.Disconnected) {
console.warn(`${SB} Disconnected waiting for Signalling/Connecting...`);
try { await Promise.race([entersState(connection, VoiceConnectionStatus.Signalling, 5_000), entersState(connection, VoiceConnectionStatus.Connecting, 5_000)]); } try { await Promise.race([entersState(connection, VoiceConnectionStatus.Signalling, 5_000), entersState(connection, VoiceConnectionStatus.Connecting, 5_000)]); }
catch { catch {
if (reconnectAttempts < MAX_RECONNECT_ATTEMPTS) { reconnectAttempts++; connection.rejoin({ channelId: state.channelId, selfDeaf: false, selfMute: false }); } if (reconnectAttempts < MAX_RECONNECT_ATTEMPTS) { reconnectAttempts++; console.log(`${SB} Rejoin attempt ${reconnectAttempts}/${MAX_RECONNECT_ATTEMPTS}`); connection.rejoin({ channelId: state.channelId, selfDeaf: false, selfMute: false }); }
else { reconnectAttempts = 0; try { connection.destroy(); } catch {} else { reconnectAttempts = 0; console.log(`${SB} Max reconnect attempts reached, creating fresh connection`); try { connection.destroy(); } catch {}
const nc = joinVoiceChannel({ channelId: state.channelId, guildId: state.guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false }); const nc = joinVoiceChannel({ channelId: state.channelId, guildId: state.guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false });
state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild); } state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild); }
} }
} else if (newS.status === VoiceConnectionStatus.Destroyed) { } else if (newS.status === VoiceConnectionStatus.Destroyed) {
console.warn(`${SB} Connection destroyed, recreating...`);
connectedSince.delete(state.guildId); connectedSince.delete(state.guildId);
const nc = joinVoiceChannel({ channelId: state.channelId, guildId: state.guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false }); const nc = joinVoiceChannel({ channelId: state.channelId, guildId: state.guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false });
state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild); state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild);
} else if (newS.status === VoiceConnectionStatus.Connecting || newS.status === VoiceConnectionStatus.Signalling) { } else if (newS.status === VoiceConnectionStatus.Connecting || newS.status === VoiceConnectionStatus.Signalling) {
isReconnecting = true; isReconnecting = true;
console.log(`${SB} Waiting for Ready from ${newS.status}...`);
try { await entersState(connection, VoiceConnectionStatus.Ready, 15_000); } try { await entersState(connection, VoiceConnectionStatus.Ready, 15_000); }
catch { catch (e) {
reconnectAttempts++; reconnectAttempts++;
console.warn(`${SB} Timeout waiting for Ready from ${newS.status} (attempt ${reconnectAttempts}): ${(e as Error)?.message ?? e}`);
if (reconnectAttempts < MAX_RECONNECT_ATTEMPTS) { await new Promise(r => setTimeout(r, reconnectAttempts * 2000)); isReconnecting = false; connection.rejoin({ channelId: state.channelId, selfDeaf: false, selfMute: false }); } if (reconnectAttempts < MAX_RECONNECT_ATTEMPTS) { await new Promise(r => setTimeout(r, reconnectAttempts * 2000)); isReconnecting = false; connection.rejoin({ channelId: state.channelId, selfDeaf: false, selfMute: false }); }
else { reconnectAttempts = 0; isReconnecting = false; try { connection.destroy(); } catch {} else { reconnectAttempts = 0; isReconnecting = false; console.error(`${SB} Max attempts from ${newS.status}, fresh connection`); try { connection.destroy(); } catch {}
const nc = joinVoiceChannel({ channelId: state.channelId, guildId: state.guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false }); const nc = joinVoiceChannel({ channelId: state.channelId, guildId: state.guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false });
state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild); } state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild); }
} }
} }
} catch { isReconnecting = false; } } catch (e) { console.error(`${SB} Lifecycle error: ${(e as Error)?.message ?? e}`); isReconnecting = false; }
}); });
(connection as any).__lifecycleAttached = true; (connection as any).__lifecycleAttached = true;
} }
@ -284,12 +297,14 @@ function attachVoiceLifecycle(state: GuildAudioState, guild: any) {
let _pluginCtx: PluginContext | null = null; let _pluginCtx: PluginContext | null = null;
async function playFilePath(guildId: string, channelId: string, filePath: string, volume?: number, relativeKey?: string): Promise<void> { async function playFilePath(guildId: string, channelId: string, filePath: string, volume?: number, relativeKey?: string): Promise<void> {
console.log(`${SB} playFilePath: guild=${guildId} channel=${channelId} file=${path.basename(filePath)} vol=${volume ?? 'default'}`);
const ctx = _pluginCtx!; const ctx = _pluginCtx!;
const guild = ctx.client.guilds.cache.get(guildId); const guild = ctx.client.guilds.cache.get(guildId);
if (!guild) throw new Error('Guild nicht gefunden'); if (!guild) { console.error(`${SB} Guild ${guildId} not found in cache (cached: ${ctx.client.guilds.cache.map(g => g.id).join(', ')})`); throw new Error('Guild nicht gefunden'); }
let state = guildAudioState.get(guildId); let state = guildAudioState.get(guildId);
if (!state) { if (!state) {
console.log(`${SB} No existing audio state, creating new connection...`);
const connection = joinVoiceChannel({ channelId, guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false }); const connection = joinVoiceChannel({ channelId, guildId, adapterCreator: guild.voiceAdapterCreator as any, selfMute: false, selfDeaf: false });
const player = createAudioPlayer({ behaviors: { noSubscriber: NoSubscriberBehavior.Play } }); const player = createAudioPlayer({ behaviors: { noSubscriber: NoSubscriberBehavior.Play } });
connection.subscribe(player); connection.subscribe(player);
@ -297,6 +312,9 @@ async function playFilePath(guildId: string, channelId: string, filePath: string
guildAudioState.set(guildId, state); guildAudioState.set(guildId, state);
state.connection = await ensureConnectionReady(connection, channelId, guildId, guild); state.connection = await ensureConnectionReady(connection, channelId, guildId, guild);
attachVoiceLifecycle(state, guild); attachVoiceLifecycle(state, guild);
console.log(`${SB} New voice connection established`);
} else {
console.log(`${SB} Existing audio state found, connection status=${state.connection.state.status}`);
} }
// Channel-Wechsel // Channel-Wechsel
@ -362,12 +380,25 @@ async function playFilePath(guildId: string, channelId: string, filePath: string
if (resource.volume) resource.volume.setVolume(useVolume); if (resource.volume) resource.volume.setVolume(useVolume);
state.player.stop(); state.player.stop();
console.log(`${SB} Playing resource: vol=${useVolume} normalized=${NORMALIZE_ENABLE} connStatus=${state.connection.state.status}`);
// Log player errors
state.player.removeAllListeners('error');
state.player.on('error', (err: any) => {
console.error(`${SB} AudioPlayer error: ${err?.message ?? err}`);
if (err?.resource?.metadata) console.error(`${SB} resource metadata:`, err.resource.metadata);
});
state.player.on('stateChange', (oldS: any, newS: any) => {
if (oldS.status !== newS.status) console.log(`${SB} Player state: ${oldS.status}${newS.status}`);
});
state.player.play(resource); state.player.play(resource);
state.currentResource = resource; state.currentResource = resource;
state.currentVolume = useVolume; state.currentVolume = useVolume;
const soundLabel = relativeKey ? path.parse(relativeKey).name : path.parse(filePath).name; const soundLabel = relativeKey ? path.parse(relativeKey).name : path.parse(filePath).name;
nowPlaying.set(guildId, soundLabel); nowPlaying.set(guildId, soundLabel);
console.log(`${SB} Now playing: "${soundLabel}" in guild=${guildId}`);
sseBroadcast({ type: 'soundboard_nowplaying', plugin: 'soundboard', guildId, name: soundLabel }); sseBroadcast({ type: 'soundboard_nowplaying', plugin: 'soundboard', guildId, name: soundLabel });
if (relativeKey) incrementPlaysFor(relativeKey); if (relativeKey) incrementPlaysFor(relativeKey);
} }
@ -730,16 +761,18 @@ const soundboardPlugin: Plugin = {
app.post('/api/soundboard/play', async (req, res) => { app.post('/api/soundboard/play', async (req, res) => {
try { try {
const { soundName, guildId, channelId, volume, folder, relativePath } = req.body ?? {}; const { soundName, guildId, channelId, volume, folder, relativePath } = req.body ?? {};
if (!soundName || !guildId || !channelId) { res.status(400).json({ error: 'soundName, guildId, channelId erforderlich' }); return; } console.log(`${SB} POST /play: sound=${soundName} guild=${guildId} channel=${channelId} folder=${folder ?? '-'} relPath=${relativePath ?? '-'}`);
if (!soundName || !guildId || !channelId) { console.warn(`${SB} /play missing params`); res.status(400).json({ error: 'soundName, guildId, channelId erforderlich' }); return; }
let filePath: string; let filePath: string;
if (relativePath) filePath = path.join(SOUNDS_DIR, relativePath); if (relativePath) filePath = path.join(SOUNDS_DIR, relativePath);
else if (folder) { const mp3 = path.join(SOUNDS_DIR, folder, `${soundName}.mp3`); filePath = fs.existsSync(mp3) ? mp3 : path.join(SOUNDS_DIR, folder, `${soundName}.wav`); } else if (folder) { const mp3 = path.join(SOUNDS_DIR, folder, `${soundName}.mp3`); filePath = fs.existsSync(mp3) ? mp3 : path.join(SOUNDS_DIR, folder, `${soundName}.wav`); }
else { const mp3 = path.join(SOUNDS_DIR, `${soundName}.mp3`); filePath = fs.existsSync(mp3) ? mp3 : path.join(SOUNDS_DIR, `${soundName}.wav`); } else { const mp3 = path.join(SOUNDS_DIR, `${soundName}.mp3`); filePath = fs.existsSync(mp3) ? mp3 : path.join(SOUNDS_DIR, `${soundName}.wav`); }
if (!fs.existsSync(filePath)) { res.status(404).json({ error: 'Sound nicht gefunden' }); return; } if (!fs.existsSync(filePath)) { console.warn(`${SB} Sound file not found: ${filePath}`); res.status(404).json({ error: 'Sound nicht gefunden' }); return; }
console.log(`${SB} Resolved file: ${filePath}`);
const relKey = relativePath || (folder ? `${folder}/${soundName}` : soundName); const relKey = relativePath || (folder ? `${folder}/${soundName}` : soundName);
await playFilePath(guildId, channelId, filePath, volume, relKey); await playFilePath(guildId, channelId, filePath, volume, relKey);
res.json({ ok: true }); res.json({ ok: true });
} catch (e: any) { res.status(500).json({ error: e?.message ?? 'Fehler' }); } } catch (e: any) { console.error(`${SB} /play error: ${e?.message ?? e}`); res.status(500).json({ error: e?.message ?? 'Fehler' }); }
}); });
app.post('/api/soundboard/play-url', async (req, res) => { app.post('/api/soundboard/play-url', async (req, res) => {