search

angelobreuer / Lavalink4NET

Lavalink4NET is a Lavalink wrapper with node clustering, caching and custom players for .NET with support for Discord.Net, DSharpPlus, Remora, and NetCord.
https://lavalink4net.angelobreuer.de/
MIT License
150 stars 27 forks source link

Disconnect on VoiceState change #62

Closed Arasfon closed 3 years ago

Arasfon commented 3 years ago

Description When you change bot's VoiceState (e.g. server mute, move bot to another voice channel) it simply disconnects without any error (see additional context), i can't find anything in my code that calls Disconnect, so i think there's something with the library. I tried looking into sources, but i didn't find anything that can help with my issue.

To Reproduce Steps to reproduce the behavior:

  1. Play something
  2. Mute bot on the server

Expected behavior Bot should not be disconnected from voice channel

Versions Lavalink4NET 1.5.5 Discord.Net v2.3.0-dev-20201028.4 (no difference in behavior at stable, but dev handles reconnections better)

Additional context In Lavalink4NET logs:

[Lavalink4NET.LavalinkNode]: Voice WebSocket was closed for player: 66311...13
Close Code: NormalClosure (1000, Reason: , By Remote: No

In Lavalink server logs i see

{"op":"destroy", "guildId":"..."}

and nothing abnormal except the line above.

angelobreuer commented 3 years ago

Hello @Arasfon,

Can you attach to the PlayerDisconnected event of your Lavalink node? Is there an event triggered if your issue occurs and what is contained in the event arguments (e.g. disconnect reason)?

The bot should normally only disconnect if...

Additionally, does your client cache voice states?

I will further investigate the issue (e.g. trying to reproduce, etc.) when I am at home.

Thanks for your issue report. Angelo Breuer

Arasfon commented 3 years ago

WebSocketClosed in PlayerDisconnected and Stop on Player (my player has modified OnTrackEnd event to support queue looping): image

Arasfon commented 3 years ago

I've cloned library and referenced it directly, after debugging i've found out that bot disconnects after line 587 in LavalinkPlayer.cs https://github.com/angelobreuer/Lavalink4NET/blob/10d50a3b49bff0ff9ccf5c6f2d025dd2f30d5062/src/Lavalink4NET/Player/LavalinkPlayer.cs#L587-L588 i'll try to investigate further as far as i can.

angelobreuer commented 3 years ago

Hello @Arasfon,

I have tried to reproduce your issue but with no luck: https://github.com/angelobreuer/Lavalink4NET.I62Repro

I tried to move the bot around voice channel and muted/unmuted the bot several times, but the bot did not disconnect.

I've cloned library and referenced it directly, after debugging i've found out that bot disconnects after line 587 in LavalinkPlayer.cs

That's interesting, does your Lavalink server output any useful log output? Does the voice state contain a voice channel set to 0 or null?

Thanks in advance! Angelo Breuer

Arasfon commented 3 years ago

@angelobreuer, thanks for your response. I cloned your repro repo, filled in token, etc, but when i tried to mute my recently created bot it disconnected. At first, i thought intents are the cause of such strange behavior (because they were disabled), but no, i enabled them and issue still persists. So there is something with my lavalink server, or my pc and i can't imagine what can be wrong. In debug, voice state contains valid channel's ids, so it works as expected. Lavalink server logs doesn't show much (log is going right after audio bytes doesn't show up): https://pastebin.com/0At7QwgJ Logs without Trace (from another try): https://pastebin.com/ByeRkXN5

angelobreuer commented 3 years ago

@Arasfon

Thanks for attaching your logs, they helped a lot.

 // Lavalink4NET sent voice state update
{"op":"voiceUpdate","guildId":"599608864484098069","sessionId":"38657624b74affed34c194bfae1466aa","event":{"token":"96fae1a9d915675d","guild_id":599608864484098069,"endpoint":"russia150.discord.media:443"}}

// Magma library disconnects from the old voice server.
Disconnecting... 

// Just a notice that a close code is encoded (see: RFC6455, WebSockets)
Encoding WebSocket Frame opCode=8 length=2 

// Lavalink notifies Lavalink4NET that the connection to the voice server was closed
Sent {"op":"event","reason":"","code":1000,"byRemote":false,"type":"WebSocketClosedEvent","guildId":"599608864484098069"} 

// Reconnects to Russian voice server endpoint
Connecting to wss://russia150.discord.media:443/?v=4 

[ some log entries were skipped for oversight ]

// Means that the Lavalink node received a close code
UT025003: Decoding WebSocket Frame with opCode 1

// Notification that the decoding of the payload that invokes the player destroy was received
Handling TextMessage payload=[{"op":"des..], byteCount=47, last=true] in StandardWebSocketSession[id=57178fa7-ffe9-6f03-9e57-9362f375d39b, uri=/]

// Player destroy payload
{"op":"destroy","guildId":"599608864484098069"}

My guess on that is that there is something like a "race condition" that does the following two things at the same time:

After that, the Lavalink node may try to start the session anyway, but discord won't allow it because the bot is no longer in the voice channel.

I have noticed that if I mute my bot server-wide, then I get the following log:

{"op":"voiceUpdate","guildId":"[redacted]","sessionId":"[redacted]","event":{"token":"[redacted]","guild_id":[redacted],"endpoint":"eu-central479.discord.media:443"}}
Discarding received connection request because it is identical to the already existing connection. If you really want to reconnect, send a disconnect request first.

Your Lavalink logs do not print that the voice states are identical instead your Lavalink node reconnects to the voice server regardless of it is already connected to it, normally even this should work fine, which you can see in your logs:

This is unintended behaviour which should not happen, and I think this may be your issue.

I've also tried to reproduce your issue with a client wrapper that is unreliable with the old voice state property, but Magma (the library that Lavalink uses for voice WebSocket communication) manages to detect the duplicate voice state/server update which may be failing in your case.

Now I made a patch that resolves the problems/thoughts mentioned above; also, I removed the old voice state tracking functionality. Lavalink4NET does no longer have to rely on the voice states supplied by the client wrappers. The patch also adds that Lavalink4NET does not send duplicate voice state updates if the voice state is the same (except mute, deaf, live, etc.), and I think this can probably solve your issue.

If you want you can try out the patch: I've compiled the following assemblies, so you can easily copy them over your files (You can copy them over the files put in the bin/Debug or bin/Release folder, note these may be overridden if you recompile your bot).

Lavalink4NET-1.5.5-7b81811c579abe9aea6beb3511526aa52d0fbc35.zip

What Lavalink/Java version are you using?

For testing, I used the following packages/libraries/applications:

Arasfon commented 3 years ago

Thanks you very much, @angelobreuer ! Issue with muting bot is resolved, however, when i move bot through some channels the issue still persists. And there's something new - when voiceState equals null, i suppose, (e.g. user leaves channel) DiscordClientWrapper throws an exception: image

Java version is the same, Discord.Net is the same, and Lavalink4NET is your's patched version. Concerning Lavalink. This version somehow does not work for me. It throws exceptions so tracks does not play via youtube, it can't find tracks, and it's very strange overall. I was using last Lavalink version (3.3.2.1) I am on Windows 10 x64, if that matters.

angelobreuer commented 3 years ago

Good news! I can reproduce the issue since I updated to the last Lavalink version. This also explains this strange behaviour occurs. In the changelog comparing our both versions, Magma was replaced by Koe: https://github.com/Frederikam/Lavalink/compare/3.3.1.4...master.

I think that there is maybe a bug in Lavalink/Koe because if the connection is already established to the voice channel, and the voice state update is resent, the WebSocket fails to reconnect to the voice server.

There seems to be a possibility to fix the mute, deaf, move bug but I do not think that I can fix voice server changes because when the voice server changes it is essential to resend the voice state/server update which will cause the bug to occur.

I will further investigate the issue if the bug is really on Lavalink's side, but I've prepared a hotfix for you (abf2c6d9c555683ef06e5b7e76c922011fc48329):

Lavalink4NET-abf2c6d9c555683ef06e5b7e76c922011fc48329.zip

I've also fixed the NullReferenceException when you leave a voice channel.

Also, please let me know if your issue with searching YouTube videos stills persists (Maybe this is somehow related to https://github.com/Frederikam/Lavalink/issues/384?).

Still, I recommend downgrading to Lavalink v3.3.1.4 (the latest release before Magma replacement), voice server changes should work fine there.

I've noticed that Koe fails to send a new speaking payload to the voice gateway, this is because the voice state update sent before is no longer happening and the bot will play music/audio without showing the speaking indicator.

angelobreuer commented 3 years ago

I've now found the issue; the new behaviour is that Lavalink4NET ignores WebSocket closes as Lavalink handles them by itself. The problem came up because Magma was more tolerant for voice state updates than Koe. Koe is not able to switch voice channels correctly without having the problem that the speaking indicator does not show up. So now Lavalink directly redirects the voice states to Lavalink.

I've tried channel move, disconnects, voice server changes, muting and deafening of the bot and it seems to work fine.

Could you please try out the following patch and tell me if the issue persists in https://github.com/angelobreuer/Lavalink4NET/commit/fa1bb337283fdf89e39c62530ba60e3d3354be7d):

Lavalink4NET-fa1bb337283fdf89e39c62530ba60e3d3354be7d.zip

Thank you a lot! Angelo Breuer

Arasfon commented 3 years ago

I was writing about 3.3.1.4 not working because of fixes implemented in later versions, but did not have time to complete it, as you sent new patch. All is working correctly now! Thank you very much!

angelobreuer commented 3 years ago

Perfect! Thank you for your time. I will deploy a patch then (v1.6).