Intermittent disconnects

[oscar-b]

The bot is working really well, most of the time! :) However, sometimes it stops streaming, disconnects, rejoins and continues.

There's nothing in the log, is there a way to increase the log level?

[oscar-b]

This is what I have in the log, but it's been disconnecting more than this.

2023/09/27 21:17:54 [DG0] voice.go:399:wsListen() voice endpoint rotterdam8853.discord.media:443 websocket closed unexpectantly, websocket: close 1006 (abnormal closure): unexpected EOF
2023/09/28 19:53:22 [DG0] voice.go:399:wsListen() voice endpoint rotterdam363.discord.media:443 websocket closed unexpectantly, websocket: close 1001 (going away)
2023/09/28 19:53:22 [DG0] voice.go:199:Close() error closing websocket, websocket: close sent
2023/10/02 20:28:53 [DG0] voice.go:399:wsListen() voice endpoint rotterdam1981.discord.media:443 websocket closed unexpectantly, websocket: close 1006 (abnormal closure): unexpected EOF
2023/10/02 20:40:29 [DG0] voice.go:399:wsListen() voice endpoint rotterdam1981.discord.media:443 websocket closed unexpectantly, websocket: close 1006 (abnormal closure): unexpected EOF
2023/10/02 21:20:56 [DG0] voice.go:399:wsListen() voice endpoint rotterdam1981.discord.media:443 websocket closed unexpectantly, websocket: close 1006 (abnormal closure): unexpected EOF
2023/10/06 23:31:28 [DG0] voice.go:530:wsHeartbeat() error sending heartbeat to voice endpoint rotterdam3503.discord.media:443, websocket: close sent
{"level":"error","ts":"2023-10-07T19:48:39Z","logger":"interactionHandler","caller":"bot/player.go:268","msg":"failed to play playlist","guildID":"80555577431822336","error":"while sending audio data: while stopping to speak: no VoiceConnection websocket","stacktrace":"github.com/Trojan295/discord-airplay/pkg/bot.(*GuildPlayer).Run\n\t/src/pkg/bot/player.go:268\ngithub.com/Trojan295/discord-airplay/pkg/discord.(*InteractionHandler).GuildCreate.func1\n\t/src/pkg/discord/interactions.go:84"}

[oscar-b]

@Trojan295 I found the AIR_DEBUG variable, but it doesn't tell me much more. It stops playing after 9 minutes? The second attempt had another video queued (nothing logged when adding that).

Also worth adding that this worked better in the initial version, so either 9301d4b caused this, or YouTube/Discord is actively blocking this?

2023-10-17T09:12:33Z	INFO	airplay/airplay.go:111	airplay is now running.  Press CTRL-C to exit.
2023-10-17T09:12:33Z	INFO	interactionHandler	discord/interactions.go:81	connected to guild	{"guildID": "80555577431822336"}
2023-10-17T09:13:24Z	DEBUG	interactionHandler	bot/player.go:286	joining voice channel	{"guildID": "80555577431822336", "channel": "80574740627980288"}
2023-10-17T09:13:26Z	DEBUG	interactionHandler	bot/player.go:328	sending audio stream	{"guildID": "80555577431822336", "title": "James Hype - Get Closer, London - Full Set", "url": "https://www.youtube.com/watch?v=oVOuXYtqi6I"}
2023-10-17T09:22:51Z	DEBUG	interactionHandler	bot/player.go:340	stopped playing	{"guildID": "80555577431822336", "title": "James Hype - Get Closer, London - Full Set", "url": "https://www.youtube.com/watch?v=oVOuXYtqi6I"}
2023-10-17T09:22:51Z	DEBUG	interactionHandler	bot/player.go:301	playlist is empty	{"guildID": "80555577431822336"}
2023-10-17T09:22:51Z	DEBUG	interactionHandler	bot/player.go:292	leaving voice channel	{"guildID": "80555577431822336", "channel": "80574740627980288"}

2023-10-17T09:29:32Z	DEBUG	interactionHandler	bot/player.go:286	joining voice channel	{"guildID": "80555577431822336", "channel": "80574740627980288"}
2023-10-17T09:29:34Z	DEBUG	interactionHandler	bot/player.go:328	sending audio stream	{"guildID": "80555577431822336", "title": "10 Hours of The Screaming Sheep", "url": "https://www.youtube.com/watch?v=SjHUb7NSrNk&ab_channel=Grayhyaena"}
2023-10-17T09:38:10Z	DEBUG	interactionHandler	bot/player.go:340	stopped playing	{"guildID": "80555577431822336", "title": "10 Hours of The Screaming Sheep", "url": "https://www.youtube.com/watch?v=SjHUb7NSrNk&ab_channel=Grayhyaena"}
2023-10-17T09:38:11Z	DEBUG	interactionHandler	bot/player.go:328	sending audio stream	{"guildID": "80555577431822336", "title": "The Most Annoying Sound 10 Hours", "url": "https://youtu.be/ms8aFrVVv-w?si=h9wGzCWm9q4aMUPP"}
2023-10-17T09:45:18Z	DEBUG	interactionHandler	bot/player.go:340	stopped playing	{"guildID": "80555577431822336", "title": "The Most Annoying Sound 10 Hours", "url": "https://youtu.be/ms8aFrVVv-w?si=h9wGzCWm9q4aMUPP"}
2023-10-17T09:45:18Z	DEBUG	interactionHandler	bot/player.go:301	playlist is empty	{"guildID": "80555577431822336"}
2023-10-17T09:45:18Z	DEBUG	interactionHandler	bot/player.go:292	leaving voice channel	{"guildID": "80555577431822336", "channel": "80574740627980288"}

[Trojan295]

@oscar-b could you check the image ghcr.io/trojan295/discord-airplay:pr-6 (or this PR #6).

I think there are two issues:

1. yt-dlp fails for longer videos. Looks this is connected to the way how the bot processes the audio - it downloads it continuously using just a small (100KB) buffer. The HTTP chunk size used by yt-dlp is much larger, so I guess it times out and stops playing. I set the --http-chunk-size 100K in this PR.

2. Second issue (with Discord) looks very similar to Voice websocket closed unexpectedly at random times bwmarrin/discordgo#829. Looks there is some fix merged to master, but it was not released. I pinpointed the discord-go library to the latest commit, to see, if it helps.

[oscar-b]

@Trojan295 initial testing so far is positive, it hasn't stopped for an hour or so

[oscar-b]

We got two hickups yesterday, but it recovered and resumed playing after re-joining:

2023/10/18 23:01:00 [DG0] voice.go:403:wsListen() voice endpoint rotterdam5214.discord.media:443 websocket closed unexpectantly, websocket: close 1006 (abnormal closure): unexpected EOF
2023/10/18 23:15:51 [DG0] voice.go:403:wsListen() voice endpoint rotterdam5214.discord.media:443 websocket closed unexpectantly, websocket: close 1006 (abnormal closure): unexpected EOF

Besides that, it's been stable!