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 https://github.com/Trojan295/discord-airplay/pull/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 https://github.com/bwmarrin/discordgo/issues/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!