diff --git a/bun.lockb b/bun.lockb index af0fdb4..e6ce3f8 100755 Binary files a/bun.lockb and b/bun.lockb differ diff --git a/package.json b/package.json index 3c3375f..cc77a8c 100644 --- a/package.json +++ b/package.json @@ -19,6 +19,7 @@ }, "dependencies": { "@ai-sdk/openai": "^0.0.13", + "@noble/ciphers": "^1.3.0", "@discordjs/opus": "^0.10.0", "@discordjs/voice": "^0.18.0", "@elysiajs/cors": "^1.4.0", diff --git a/src/features/joel/index.ts b/src/features/joel/index.ts index eb75960..ce2488b 100644 --- a/src/features/joel/index.ts +++ b/src/features/joel/index.ts @@ -7,3 +7,4 @@ export { getRandomMention, getRandomMemberMention } from "./mentions"; export { startSpontaneousMentionsCron, stopSpontaneousMentionsCron } from "./spontaneous-cron"; export { TypingIndicator } from "./typing"; export { personalities, getPersonality, buildStyledPrompt, STYLE_MODIFIERS } from "./personalities"; +export { logVoiceDependencyHealth, speakVoiceover } from "./voice"; diff --git a/src/features/joel/voice.ts b/src/features/joel/voice.ts index fb1ed44..7e467cc 100644 --- a/src/features/joel/voice.ts +++ b/src/features/joel/voice.ts @@ -8,6 +8,7 @@ import { createAudioPlayer, createAudioResource, entersState, + generateDependencyReport, getVoiceConnection, joinVoiceChannel, StreamType, @@ -25,11 +26,89 @@ const logger = createLogger("Features:Joel:Voice"); const MAX_VOICE_TEXT_LENGTH = 800; const PLAYBACK_TIMEOUT_MS = 60_000; const READY_TIMEOUT_MS = 15_000; +const VOICE_DEPENDENCY_REPORT = generateDependencyReport(); + +type VoiceDependencyHealth = { + hasEncryptionLibrary: boolean; + hasFfmpeg: boolean; + hasOpusLibrary: boolean; + report: string; +}; + +type VoiceConnectionResult = { + channelId: string | null; + connection: VoiceConnection | null; + skipReason?: string; +}; + +type VoicePlaybackEvent = { + authorId: string; + audioBytes?: number; + channelId: string | null; + connectionStatus?: string; + durationMs?: number; + errorMessage?: string; + guildId: string; + outcome: "skipped" | "success" | "error"; + playerStarted: boolean; + skipReason?: string; + textLength: number; +}; + +function extractDependencySection(startHeading: string, endHeading?: string): string { + const startToken = `${startHeading}\n`; + const startIndex = VOICE_DEPENDENCY_REPORT.indexOf(startToken); + if (startIndex === -1) { + return ""; + } + + const sectionStart = startIndex + startToken.length; + const endIndex = endHeading + ? VOICE_DEPENDENCY_REPORT.indexOf(`\n${endHeading}`, sectionStart) + : -1; + + return VOICE_DEPENDENCY_REPORT + .slice(sectionStart, endIndex === -1 ? undefined : endIndex) + .trim(); +} + +function hasInstalledDependency(section: string): boolean { + return section + .split("\n") + .some((line) => line.trim().startsWith("-") && !line.includes("not found")); +} + +function getVoiceDependencyHealth(): VoiceDependencyHealth { + const opusSection = extractDependencySection("Opus Libraries", "Encryption Libraries"); + const encryptionSection = extractDependencySection("Encryption Libraries", "FFmpeg"); + + const hasOpusLibrary = hasInstalledDependency(opusSection); + const hasEncryptionLibrary = hasInstalledDependency(encryptionSection); + const hasFfmpeg = /FFmpeg[\s\S]*- version:\s+(?!not found)/.test(VOICE_DEPENDENCY_REPORT) + && VOICE_DEPENDENCY_REPORT.includes("- libopus: yes"); + + return { + hasEncryptionLibrary, + hasFfmpeg, + hasOpusLibrary, + report: VOICE_DEPENDENCY_REPORT, + }; +} + +const voiceDependencyHealth = getVoiceDependencyHealth(); function isAbortError(error: unknown): boolean { return error instanceof Error && error.name === "AbortError"; } +function getErrorMessage(error: unknown): string { + if (error instanceof Error) { + return error.message; + } + + return typeof error === "string" ? error : "Unknown error"; +} + function resolveMentions(message: Message, content: string): string { let text = content; @@ -88,14 +167,18 @@ function attachConnectionLogging(connection: VoiceConnection, guildId: string, c }); } -async function getOrCreateConnection(message: Message) { +async function getOrCreateConnection(message: Message): Promise { const voiceChannel = message.member?.voice.channel; if (!voiceChannel) { logger.debug("No voice channel for author", { userId: message.author.id, guildId: message.guildId, }); - return null; + return { + channelId: null, + connection: null, + skipReason: "author_not_in_voice_channel", + }; } const me = message.guild.members.me ?? (await message.guild.members.fetchMe()); @@ -105,7 +188,11 @@ async function getOrCreateConnection(message: Message) { guildId: message.guildId, channelId: voiceChannel.id, }); - return null; + return { + channelId: voiceChannel.id, + connection: null, + skipReason: "missing_connect_or_speak_permission", + }; } const existing = getVoiceConnection(message.guildId); @@ -114,7 +201,10 @@ async function getOrCreateConnection(message: Message) { guildId: message.guildId, channelId: voiceChannel.id, }); - return existing; + return { + channelId: voiceChannel.id, + connection: existing, + }; } if (existing) { @@ -140,7 +230,10 @@ async function getOrCreateConnection(message: Message) { guildId: message.guildId, channelId: voiceChannel.id, }); - return connection; + return { + channelId: voiceChannel.id, + connection, + }; } catch (error) { if (isAbortError(error)) { logger.debug("Voice connection ready timeout", { @@ -152,41 +245,103 @@ async function getOrCreateConnection(message: Message) { logger.error("Voice connection failed to become ready", error); } connection.destroy(); - return null; + return { + channelId: voiceChannel.id, + connection: null, + skipReason: isAbortError(error) ? "voice_connection_ready_timeout" : "voice_connection_failed", + }; } } +export function logVoiceDependencyHealth(): void { + const payload = { + hasEncryptionLibrary: voiceDependencyHealth.hasEncryptionLibrary, + hasFfmpeg: voiceDependencyHealth.hasFfmpeg, + hasOpusLibrary: voiceDependencyHealth.hasOpusLibrary, + }; + + if (voiceDependencyHealth.hasEncryptionLibrary && voiceDependencyHealth.hasFfmpeg && voiceDependencyHealth.hasOpusLibrary) { + logger.info("Discord voice dependency health", payload); + return; + } + + logger.warn("Discord voice dependency health degraded", { + ...payload, + report: voiceDependencyHealth.report, + }); +} + export async function speakVoiceover(message: Message, content: string): Promise { + const playbackEvent: VoicePlaybackEvent = { + authorId: message.author.id, + channelId: null, + guildId: message.guildId, + outcome: "skipped", + playerStarted: false, + textLength: 0, + }; + const startedAt = Date.now(); + if (!config.elevenlabs.apiKey || !config.elevenlabs.voiceId) { logger.debug("Voiceover disabled (missing config)"); + playbackEvent.skipReason = "missing_elevenlabs_config"; + playbackEvent.durationMs = Date.now() - startedAt; + logger.info("Voice playback", playbackEvent); + return; + } + + if (!voiceDependencyHealth.hasEncryptionLibrary) { + playbackEvent.skipReason = "missing_voice_encryption_dependency"; + playbackEvent.durationMs = Date.now() - startedAt; + logger.warn("Voice playback skipped", { + ...playbackEvent, + dependencyReport: voiceDependencyHealth.report, + }); return; } const text = sanitizeForVoiceover(message, content); + playbackEvent.textLength = text.length; if (!text) { logger.debug("Voiceover skipped (empty text after sanitize)"); + playbackEvent.skipReason = "empty_text_after_sanitize"; + playbackEvent.durationMs = Date.now() - startedAt; + logger.info("Voice playback", playbackEvent); return; } let connection: VoiceConnection | null = null; try { - connection = await getOrCreateConnection(message); + const connectionResult = await getOrCreateConnection(message); + playbackEvent.channelId = connectionResult.channelId; + connection = connectionResult.connection; + if (!connection) { logger.debug("Voiceover skipped (no connection)", { guildId: message.guildId, authorId: message.author.id, + skipReason: connectionResult.skipReason, }); + playbackEvent.skipReason = connectionResult.skipReason ?? "no_connection"; return; } + logger.info("Voice playback started", { + authorId: message.author.id, + channelId: playbackEvent.channelId, + guildId: message.guildId, + textLength: playbackEvent.textLength, + }); + const voiceover = getVoiceoverService(); logger.debug("Requesting ElevenLabs voiceover", { textLength: text.length }); const audio = await voiceover.generate({ text }); logger.debug("Voiceover audio received", { bytes: audio.length }); + playbackEvent.audioBytes = audio.length; const player = createAudioPlayer(); - const resource = createAudioResource(Readable.from(audio), { + const resource = createAudioResource(Readable.from([audio]), { inputType: StreamType.Arbitrary, }); @@ -196,6 +351,7 @@ export async function speakVoiceover(message: Message, content: string): P player.on(AudioPlayerStatus.Playing, () => { logger.debug("Audio player started", { guildId: message.guildId }); + playbackEvent.playerStarted = true; }); player.on(AudioPlayerStatus.Idle, () => { @@ -205,13 +361,33 @@ export async function speakVoiceover(message: Message, content: string): P connection.subscribe(player); player.play(resource); - await entersState(player, AudioPlayerStatus.Playing, 5_000).catch(() => undefined); + const playingState = await entersState(player, AudioPlayerStatus.Playing, 5_000).catch(() => undefined); + if (!playingState) { + logger.warn("Voice playback did not enter playing state", { + authorId: message.author.id, + channelId: playbackEvent.channelId, + guildId: message.guildId, + playerStarted: playbackEvent.playerStarted, + }); + } await entersState(player, AudioPlayerStatus.Idle, PLAYBACK_TIMEOUT_MS); + playbackEvent.connectionStatus = connection.state.status; + playbackEvent.outcome = "success"; } catch (error) { + playbackEvent.connectionStatus = connection?.state.status; + playbackEvent.errorMessage = getErrorMessage(error); + playbackEvent.outcome = "error"; if (!isAbortError(error)) { logger.error("Voiceover playback failed", error); } } finally { + playbackEvent.durationMs = Date.now() - startedAt; + if (playbackEvent.outcome === "error") { + logger.warn("Voice playback", playbackEvent); + } else { + logger.info("Voice playback", playbackEvent); + } + if (connection && connection.state.status !== VoiceConnectionStatus.Destroyed) { connection.destroy(); } diff --git a/src/index.ts b/src/index.ts index 8d01364..a41adf8 100644 --- a/src/index.ts +++ b/src/index.ts @@ -16,7 +16,7 @@ import { BotClient } from "./core/client"; import { config } from "./core/config"; import { createLogger } from "./core/logger"; import { registerEvents } from "./events"; -import { stopSpontaneousMentionsCron } from "./features/joel"; +import { logVoiceDependencyHealth, stopSpontaneousMentionsCron } from "./features/joel"; import { buildWebCss, startWebCssWatcher, startWebServer } from "./web"; import { runMigrations } from "./database/migrate"; import type { FSWatcher } from "fs"; @@ -47,6 +47,7 @@ async function main(): Promise { try { // Run database migrations await runMigrations(); + logVoiceDependencyHealth(); await client.login(config.discord.token); diff --git a/src/web/index.ts b/src/web/index.ts index 2c163d8..27ee936 100644 --- a/src/web/index.ts +++ b/src/web/index.ts @@ -31,6 +31,23 @@ const logger = createLogger("Web"); const pendingStates = new Map(); const STATE_EXPIRY_MS = 5 * 60 * 1000; +function getErrorMessage(error: unknown): string { + if (error instanceof Error) { + return error.message; + } + + return typeof error === "string" ? error : "Unknown error"; +} + +function escapeHtml(value: string): string { + return value + .replaceAll("&", "&") + .replaceAll("<", "<") + .replaceAll(">", ">") + .replaceAll("\"", """) + .replaceAll("'", "'"); +} + export function createWebServer(client: BotClient) { return new Elysia() .use(html()) @@ -113,8 +130,16 @@ export function createWebServer(client: BotClient) { return new Response(null, { status: 302, headers }); } catch (err) { - logger.error("OAuth callback failed", err); - return htmlResponse("

Authentication failed

", 500); + const errorMessage = getErrorMessage(err); + logger.error("OAuth callback failed", { + codePresent: !!code, + errorMessage, + state, + }); + return htmlResponse( + `

Authentication failed

${escapeHtml(errorMessage)}

`, + 500 + ); } }) .post("/auth/logout", async ({ request }) => { diff --git a/src/web/oauth.ts b/src/web/oauth.ts index 6922b83..ddaab6a 100644 --- a/src/web/oauth.ts +++ b/src/web/oauth.ts @@ -19,6 +19,12 @@ const userGuildsCache = new Map>(); const inFlightUserRequests = new Map>(); const inFlightGuildRequests = new Map>(); +async function throwDiscordApiError(action: string, response: Response): Promise { + const bodyText = (await response.text()).slice(0, 500); + const detail = bodyText ? ` ${bodyText}` : ""; + throw new Error(`${action} failed (${response.status} ${response.statusText}).${detail}`); +} + function getFromCache(cache: Map>, key: string): T | null { const entry = cache.get(key); if (!entry) { @@ -91,7 +97,7 @@ export async function exchangeCode(code: string): Promise { }); if (!response.ok) { - throw new Error(`Failed to exchange code: ${response.statusText}`); + await throwDiscordApiError("OAuth code exchange", response); } return response.json(); @@ -112,7 +118,7 @@ export async function refreshToken(refreshToken: string): Promise }); if (!response.ok) { - throw new Error(`Failed to refresh token: ${response.statusText}`); + await throwDiscordApiError("OAuth token refresh", response); } return response.json(); @@ -137,7 +143,7 @@ export async function getUser(accessToken: string): Promise { }); if (!response.ok) { - throw new Error(`Failed to get user: ${response.statusText}`); + await throwDiscordApiError("Discord get user", response); } const user = await response.json(); @@ -173,7 +179,7 @@ export async function getUserGuilds(accessToken: string): Promise