From 5faf5139ef2a86c8e0b62ac3ed75beeb1361a8b8 Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 6 Mar 2026 01:22:28 +0100 Subject: [PATCH] feat: add comprehensive logging to soundboard voice/play pipeline MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - 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 --- server/src/plugins/soundboard/index.ts | 61 ++++++++++++++++++++------ 1 file changed, 47 insertions(+), 14 deletions(-) diff --git a/server/src/plugins/soundboard/index.ts b/server/src/plugins/soundboard/index.ts index 9515f2b..d7ef5b9 100644 --- a/server/src/plugins/soundboard/index.ts +++ b/server/src/plugins/soundboard/index.ts @@ -225,15 +225,22 @@ const partyActive = new Set(); const nowPlaying = new Map(); const connectedSince = new Map(); +// ── Logging helper ── +const SB = '[Soundboard]'; + // ── Voice Lifecycle ── async function ensureConnectionReady(connection: VoiceConnection, channelId: string, guildId: string, guild: any): Promise { - try { await entersState(connection, VoiceConnectionStatus.Ready, 15_000); return connection; } catch {} - try { connection.rejoin({ channelId, selfDeaf: false, selfMute: false }); await entersState(connection, VoiceConnectionStatus.Ready, 15_000); return connection; } catch {} + console.log(`${SB} ensureConnectionReady: guild=${guildId} channel=${channelId} status=${connection.state.status}`); + 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 {} 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 }); - try { await entersState(newConn, VoiceConnectionStatus.Ready, 15_000); return newConn; } - catch { try { newConn.destroy(); } catch {} guildAudioState.delete(guildId); throw new Error('Voice connection failed after 3 attempts'); } + try { await entersState(newConn, VoiceConnectionStatus.Ready, 15_000); console.log(`${SB} Connection ready (fresh)`); return newConn; } + 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) { @@ -245,37 +252,43 @@ function attachVoiceLifecycle(state: GuildAudioState, guild: any) { let isReconnecting = false; 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) { reconnectAttempts = 0; isReconnecting = false; if (!connectedSince.has(state.guildId)) connectedSince.set(state.guildId, new Date().toISOString()); + console.log(`${SB} Voice READY for guild=${state.guildId}`); return; } - if (isReconnecting) return; + if (isReconnecting) { console.log(`${SB} Already reconnecting, skipping ${newS.status}`); return; } try { 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)]); } catch { - if (reconnectAttempts < MAX_RECONNECT_ATTEMPTS) { reconnectAttempts++; connection.rejoin({ channelId: state.channelId, selfDeaf: false, selfMute: false }); } - else { reconnectAttempts = 0; try { connection.destroy(); } catch {} + 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; 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 }); state.connection = nc; nc.subscribe(state.player); attachVoiceLifecycle(state, guild); } } } else if (newS.status === VoiceConnectionStatus.Destroyed) { + console.warn(`${SB} Connection destroyed, recreating...`); connectedSince.delete(state.guildId); 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); } else if (newS.status === VoiceConnectionStatus.Connecting || newS.status === VoiceConnectionStatus.Signalling) { isReconnecting = true; + console.log(`${SB} Waiting for Ready from ${newS.status}...`); try { await entersState(connection, VoiceConnectionStatus.Ready, 15_000); } - catch { + catch (e) { 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 }); } - 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 }); 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; } @@ -284,12 +297,14 @@ function attachVoiceLifecycle(state: GuildAudioState, guild: any) { let _pluginCtx: PluginContext | null = null; async function playFilePath(guildId: string, channelId: string, filePath: string, volume?: number, relativeKey?: string): Promise { + console.log(`${SB} playFilePath: guild=${guildId} channel=${channelId} file=${path.basename(filePath)} vol=${volume ?? 'default'}`); const ctx = _pluginCtx!; 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); 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 player = createAudioPlayer({ behaviors: { noSubscriber: NoSubscriberBehavior.Play } }); connection.subscribe(player); @@ -297,6 +312,9 @@ async function playFilePath(guildId: string, channelId: string, filePath: string guildAudioState.set(guildId, state); state.connection = await ensureConnectionReady(connection, channelId, guildId, 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 @@ -362,12 +380,25 @@ async function playFilePath(guildId: string, channelId: string, filePath: string if (resource.volume) resource.volume.setVolume(useVolume); 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.currentResource = resource; state.currentVolume = useVolume; const soundLabel = relativeKey ? path.parse(relativeKey).name : path.parse(filePath).name; nowPlaying.set(guildId, soundLabel); + console.log(`${SB} Now playing: "${soundLabel}" in guild=${guildId}`); sseBroadcast({ type: 'soundboard_nowplaying', plugin: 'soundboard', guildId, name: soundLabel }); if (relativeKey) incrementPlaysFor(relativeKey); } @@ -730,16 +761,18 @@ const soundboardPlugin: Plugin = { app.post('/api/soundboard/play', async (req, res) => { try { 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; 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 { 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); await playFilePath(guildId, channelId, filePath, volume, relKey); 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) => {