Support gracefully resuming voice sessions

[trwnh]

Summary

Voice connections should be resumed whenever the websocket is closed, rather than creating an entirely new voice connection.

What is the feature request for?

The core library

The Problem

Upon a closed websocket connection, the discord.voice_client will disconnect and reconnect rapidly. This causes leave and join sounds to be played in rapid succession, which is annoying. This behaviour also seems wholly unnecessary, as regular users of regular Discord clients do not exhibit this behavior. In fact, the existing voice connection typically remains open until it times out approximately two minutes later. It would be nice if Pycord behaved in the same way, so that it was able to resume a connection within a certain timeout window.

The Ideal Solution

The voice client will transparently resume a voice session

The Current Solution

Just dealing with the fact that the bot will inevitably disconnect and reconnect, causing two rapid-fire leave/join sounds

Additional Context

Kind of a follow-up to #1567 -- Typically the debug log will look something like this.

First, the bot will be idle and sending hearbeats (voice opcode 3) and receiving hearbeat ACKs (voice opcode 6). This happens every two seconds.

2023-02-04 00:41:41,783:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471301783.
2023-02-04 00:41:41,785:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471301783}.
2023-02-04 00:41:41,791:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471301783}

2023-02-04 00:41:46,785:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471306785.
2023-02-04 00:41:46,787:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471306785}.
2023-02-04 00:41:46,789:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471306785}

2023-02-04 00:41:51,787:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471311787.
2023-02-04 00:41:51,788:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471311787}.
2023-02-04 00:41:51,790:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471311787}

Eventually, the gateway will ask to reconnect. Nothing seems out of the ordinary except that a two-second interval was skipped (timestamp 1675471356808 jumps past 1675471356810 and goes to 1675471356812). Aside from this, it seems like aiohttp is specifying data=1001 where WSCloseCode: GOING_AWAY = 1001.

2023-02-04 00:42:26,804:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471346804.
2023-02-04 00:42:26,806:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471346804}.
2023-02-04 00:42:26,808:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471346804}

2023-02-04 00:42:31,806:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471351806.
2023-02-04 00:42:31,807:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471351806}.
2023-02-04 00:42:31,810:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471351806}

2023-02-04 00:42:36,808:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471356808.
2023-02-04 00:42:36,810:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471356808}.
2023-02-04 00:42:36,817:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471356808}

2023-02-04 00:42:41,813:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471361812.
2023-02-04 00:42:41,814:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471361812}.
2023-02-04 00:42:41,820:DEBUG:discord.gateway: Received WSMessage(type=<WSMsgType.CLOSE: 8>, data=1001, extra='')
2023-02-04 00:42:41,820:ERROR:discord.voice_client: Disconnected from voice... Reconnecting in 1.58s.
Traceback (most recent call last):
  File "/srv/discord/umi/.venv/lib/python3.10/site-packages/discord/voice_client.py", line 464, in poll_voice_ws
    await self.ws.poll_event()
  File "/srv/discord/umi/.venv/lib/python3.10/site-packages/discord/gateway.py", line 935, in poll_event
    raise ConnectionClosed(self.ws, shard_id=None, code=self._close_code)
discord.errors.ConnectionClosed: Shard ID None WebSocket closed with 1001

At this point, Pycord terminates the voice handshake and issues a voice state update (gateway opcode 4) to disconnect from the voice channel (channel_id: None). This is immediately (within the same second) followed by Pycord issuing another voice state update (gateway opcode 4) to rejoin the voice channel (channel_id: 949502283228512270). An event (VOICE_STATE_UPDATE) is also dispatched (gateway opcode 0) for both of these operations.

2023-02-04 00:42:43,404:INFO:discord.voice_client: The voice handshake is being terminated for Channel ID 949502283228512270 (Guild ID 949502283228512266)
2023-02-04 00:42:43,404:DEBUG:discord.gateway: Updating our voice state to {'op': 4, 'd': {'guild_id': 949502283228512266, 'channel_id': None, 'self_mute': False, 'self_deaf': False}}.
2023-02-04 00:42:43,404:INFO:discord.voice_client: Connecting to voice...
2023-02-04 00:42:43,404:INFO:discord.voice_client: Starting voice handshake... (connection attempt 5)
2023-02-04 00:42:43,404:DEBUG:discord.gateway: Updating our voice state to {'op': 4, 'd': {'guild_id': 949502283228512266, 'channel_id': 949502283228512270, 'self_mute': False, 'self_deaf': False}}.
2023-02-04 00:42:43,466:DEBUG:discord.gateway: For Shard ID None: WebSocket Event: {'t': 'VOICE_STATE_UPDATE', 's': 1195, 'op': 0, 'd': {'member': {'user': {'username': 'umi', 'public_flags': 0, 'id': '989386214769586266', 'display_name': None, 'discriminator': '2708', 'bot': True, 'avatar_decoration': None, 'avatar': 'ba24a6e8272e904ba4f33b67d526617a'}, 'roles': ['989371319047061524', '989388112155246615'], 'premium_since': None, 'pending': False, 'nick': None, 'mute': False, 'joined_at': '2022-06-23T04:35:07.994000+00:00', 'flags': 0, 'deaf': False, 'communication_disabled_until': None, 'avatar': None}, 'user_id': '989386214769586266', 'suppress': False, 'session_id': '39bc77d36f58ca66d2f086b8762bb2ee', 'self_video': False, 'self_mute': False, 'self_deaf': False, 'request_to_speak_timestamp': None, 'mute': False, 'guild_id': '949502283228512266', 'deaf': False, 'channel_id': None}}
2023-02-04 00:42:43,467:DEBUG:discord.client: Dispatching event socket_event_type
2023-02-04 00:42:43,467:DEBUG:discord.client: Dispatching event voice_state_update
2023-02-04 00:42:43,469:DEBUG:discord.gateway: For Shard ID None: WebSocket Event: {'t': 'VOICE_STATE_UPDATE', 's': 1196, 'op': 0, 'd': {'member': {'user': {'username': 'umi', 'public_flags': 0, 'id': '989386214769586266', 'display_name': None, 'discriminator': '2708', 'bot': True, 'avatar_decoration': None, 'avatar': 'ba24a6e8272e904ba4f33b67d526617a'}, 'roles': ['989371319047061524', '989388112155246615'], 'premium_since': None, 'pending': False, 'nick': None, 'mute': False, 'joined_at': '2022-06-23T04:35:07.994000+00:00', 'flags': 0, 'deaf': False, 'communication_disabled_until': None, 'avatar': None}, 'user_id': '989386214769586266', 'suppress': False, 'session_id': '39bc77d36f58ca66d2f086b8762bb2ee', 'self_video': False, 'self_mute': False, 'self_deaf': False, 'request_to_speak_timestamp': None, 'mute': False, 'guild_id': '949502283228512266', 'deaf': False, 'channel_id': '949502283228512270'}}
2023-02-04 00:42:43,469:DEBUG:discord.client: Dispatching event socket_event_type
2023-02-04 00:42:43,470:DEBUG:discord.client: Dispatching event voice_state_update

As noted in #1567 this is usually caused by something like a voice server update. The VOICE_SERVER_UPDATE event is dispatched (gateway opcode 0) and the voice client connects to the new endpoint. Pycord will begin a voice websocket connection (voice opcode 0: Identify), receiving a Hello (voice opcode 8) and Ready (voice opcode 2) from Discord.

2023-02-04 00:42:43,470:DEBUG:discord.gateway: For Shard ID None: WebSocket Event: {'t': 'VOICE_SERVER_UPDATE', 's': 1197, 'op': 0, 'd': {'token': '0b1abd764001a120', 'guild_id': '949502283228512266', 'endpoint': 'atlanta7086.discord.media:443'}}
2023-02-04 00:42:43,470:DEBUG:discord.client: Dispatching event socket_event_type
2023-02-04 00:42:43,471:INFO:discord.voice_client: Voice handshake complete. Endpoint found atlanta7086.discord.media

2023-02-04 00:42:43,515:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 0, 'd': {'server_id': '949502283228512266', 'user_id': '989386214769586266', 'session_id': '39bc77d36f58ca66d2f086b8762bb2ee', 'token': '0b1abd764001a120'}}.

2023-02-04 00:42:43,515:DEBUG:discord.gateway: Voice websocket frame received: {'op': 8, 'd': {'v': 4, 'heartbeat_interval': 13750.0}}
2023-02-04 00:42:43,517:DEBUG:discord.gateway: Voice websocket frame received: {'op': 2, 'd': {'streams': [{'type': 'video', 'ssrc': 122802, 'rtx_ssrc': 122803, 'rid': '', 'quality': 0, 'active': False}], 'ssrc': 122801, 'port': 50022, 'modes': ['aead_aes256_gcm_rtpsize', 'aead_aes256_gcm', 'aead_xchacha20_poly1305_rtpsize', 'xsalsa20_poly1305_lite_rtpsize', 'xsalsa20_poly1305_lite', 'xsalsa20_poly1305_suffix', 'xsalsa20_poly1305'], 'ip': '66.22.223.122', 'experiments': ['fixed_keyframe_interval']}}

The new session is then established. Pycord will select a protocol (voice opcode 1) and receive a session description (voice opcode 4). Pycord also seems to issue a "speaking" command (voice opcode 5) before it immediately stops speaking.

2023-02-04 00:42:43,518:DEBUG:discord.gateway: received packet in initial_connection: b'F\x00\x01\x0050.116.43.33\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x83\x96'
2023-02-04 00:42:43,519:DEBUG:discord.gateway: detected ip: 50.116.43.33 port: 33686
2023-02-04 00:42:43,519:DEBUG:discord.gateway: received supported encryption modes: xsalsa20_poly1305_lite, xsalsa20_poly1305_suffix, xsalsa20_poly1305

2023-02-04 00:42:43,519:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 1, 'd': {'protocol': 'udp', 'data': {'address': '50.116.43.33', 'port': 33686, 'mode': 'xsalsa20_poly1305_lite'}}}.
2023-02-04 00:42:43,519:INFO:discord.gateway: selected the voice protocol for use (xsalsa20_poly1305_lite)
2023-02-04 00:42:43,521:DEBUG:discord.gateway: Voice websocket frame received: {'op': 4, 'd': {'video_codec': 'H264', 'secret_key': [248, 244, 26, 25, 103, 102, 149, 231, 19, 26, 219, 174, 254, 96, 55, 184, 72, 231, 42, 246, 249, 232, 95, 204, 15, 20, 202, 82, 95, 65, 236, 58], 'mode': 'xsalsa20_poly1305_lite', 'media_session_id': '2f8b47b463dcd2e5e30994b6a64948ff', 'audio_codec': 'opus'}}
2023-02-04 00:42:43,521:INFO:discord.gateway: received secret key for voice connection
2023-02-04 00:42:43,521:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 5, 'd': {'speaking': 1, 'delay': 0}}.
2023-02-04 00:42:43,521:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 5, 'd': {'speaking': 0, 'delay': 0}}.

Once all this is done, it triggers the VCJoin cog that I wrote to send a message whenever someone leaves or joins a voice channel.

2023-02-04 00:42:43,842:DEBUG:discord.gateway: For Shard ID None: WebSocket Event: {'t': 'MESSAGE_CREATE', 's': 1198, 'op': 0, 'd': {'type': 0, 'tts': False, 'timestamp': '2023-02-04T00:42:43.558000+00:00', 'referenced_message': None, 'pinned': False, 'mentions': [], 'mention_roles': [], 'mention_everyone': False, 'member': {'roles': ['989371319047061524', '989388112155246615'], 'premium_since': None, 'pending': False, 'nick': None, 'mute': False, 'joined_at': '2022-06-23T04:35:07.994000+00:00', 'flags': 0, 'deaf': False, 'communication_disabled_until': None, 'avatar': None}, 'id': '1071229283055435806', 'flags': 0, 'embeds': [{'type': 'rich', 'description': '**umi** left **vc**', 'author': {'proxy_icon_url': 'https://images-ext-1.discordapp.net/external/mLj7UbCPQe6CvIA4tqVYDTv2W4f-tEyGgMagyWnnZXw/%3Fsize%3D1024/https/cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png', 'name': 'umi (umi#2708)', 'icon_url': 'https://cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png?size=1024'}}], 'edited_timestamp': None, 'content': '', 'components': [], 'channel_id': '949516670630760499', 'author': {'username': 'umi', 'public_flags': 0, 'id': '989386214769586266', 'display_name': None, 'discriminator': '2708', 'bot': True, 'avatar_decoration': None, 'avatar': 'ba24a6e8272e904ba4f33b67d526617a'}, 'attachments': [], 'guild_id': '949502283228512266'}}
2023-02-04 00:42:43,842:DEBUG:discord.client: Dispatching event socket_event_type
2023-02-04 00:42:43,843:DEBUG:discord.client: Dispatching event message
2023-02-04 00:42:44,001:DEBUG:discord.http: POST https://discord.com/api/v10/channels/949516670630760499/messages with {"embeds":[{"author":{"name":"umi (umi#2708)","icon_url":"https://cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png?size=1024"},"fields":[],"type":"rich","description":"**umi** left **vc**"}]} has returned 200
2023-02-04 00:42:44,002:DEBUG:discord.http: POST https://discord.com/api/v10/channels/949516670630760499/messages has received {'id': '1071229283055435806', 'type': 0, 'content': '', 'channel_id': '949516670630760499', 'author': {'id': '989386214769586266', 'username': 'umi', 'display_name': None, 'avatar': 'ba24a6e8272e904ba4f33b67d526617a', 'avatar_decoration': None, 'discriminator': '2708', 'public_flags': 0, 'bot': True}, 'attachments': [], 'embeds': [{'type': 'rich', 'description': '**umi** left **vc**', 'author': {'name': 'umi (umi#2708)', 'icon_url': 'https://cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png?size=1024', 'proxy_icon_url': 'https://images-ext-1.discordapp.net/external/mLj7UbCPQe6CvIA4tqVYDTv2W4f-tEyGgMagyWnnZXw/%3Fsize%3D1024/https/cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png'}}], 'mentions': [], 'mention_roles': [], 'pinned': False, 'mention_everyone': False, 'tts': False, 'timestamp': '2023-02-04T00:42:43.558000+00:00', 'edited_timestamp': None, 'flags': 0, 'components': [], 'referenced_message': None}

2023-02-04 00:42:44,158:DEBUG:discord.gateway: For Shard ID None: WebSocket Event: {'t': 'MESSAGE_CREATE', 's': 1199, 'op': 0, 'd': {'type': 0, 'tts': False, 'timestamp': '2023-02-04T00:42:44.112000+00:00', 'referenced_message': None, 'pinned': False, 'mentions': [], 'mention_roles': [], 'mention_everyone': False, 'member': {'roles': ['989371319047061524', '989388112155246615'], 'premium_since': None, 'pending': False, 'nick': None, 'mute': False, 'joined_at': '2022-06-23T04:35:07.994000+00:00', 'flags': 0, 'deaf': False, 'communication_disabled_until': None, 'avatar': None}, 'id': '1071229285379092500', 'flags': 0, 'embeds': [{'type': 'rich', 'description': '**umi** joined **vc**', 'author': {'proxy_icon_url': 'https://images-ext-1.discordapp.net/external/mLj7UbCPQe6CvIA4tqVYDTv2W4f-tEyGgMagyWnnZXw/%3Fsize%3D1024/https/cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png', 'name': 'umi (umi#2708)', 'icon_url': 'https://cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png?size=1024'}}], 'edited_timestamp': None, 'content': '', 'components': [], 'channel_id': '949516670630760499', 'author': {'username': 'umi', 'public_flags': 0, 'id': '989386214769586266', 'display_name': None, 'discriminator': '2708', 'bot': True, 'avatar_decoration': None, 'avatar': 'ba24a6e8272e904ba4f33b67d526617a'}, 'attachments': [], 'guild_id': '949502283228512266'}}
2023-02-04 00:42:44,158:DEBUG:discord.client: Dispatching event socket_event_type
2023-02-04 00:42:44,158:DEBUG:discord.client: Dispatching event message
2023-02-04 00:42:44,246:DEBUG:discord.http: POST https://discord.com/api/v10/channels/949516670630760499/messages with {"embeds":[{"author":{"name":"umi (umi#2708)","icon_url":"https://cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png?size=1024"},"fields":[],"type":"rich","description":"**umi** joined **vc**"}]} has returned 200
2023-02-04 00:42:44,247:DEBUG:discord.http: POST https://discord.com/api/v10/channels/949516670630760499/messages has received {'id': '1071229285379092500', 'type': 0, 'content': '', 'channel_id': '949516670630760499', 'author': {'id': '989386214769586266', 'username': 'umi', 'display_name': None, 'avatar': 'ba24a6e8272e904ba4f33b67d526617a', 'avatar_decoration': None, 'discriminator': '2708', 'public_flags': 0, 'bot': True}, 'attachments': [], 'embeds': [{'type': 'rich', 'description': '**umi** joined **vc**', 'author': {'name': 'umi (umi#2708)', 'icon_url': 'https://cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png?size=1024', 'proxy_icon_url': 'https://images-ext-1.discordapp.net/external/mLj7UbCPQe6CvIA4tqVYDTv2W4f-tEyGgMagyWnnZXw/%3Fsize%3D1024/https/cdn.discordapp.com/avatars/989386214769586266/ba24a6e8272e904ba4f33b67d526617a.png'}}], 'mentions': [], 'mention_roles': [], 'pinned': False, 'mention_everyone': False, 'tts': False, 'timestamp': '2023-02-04T00:42:44.112000+00:00', 'edited_timestamp': None, 'flags': 0, 'components': [], 'referenced_message': None}

Finally, the bot is once again idle and everything is normal... until the next time this all happens again. The only thing out of the ordinary is that the heartbeat ACK (voice opcode 6) is intermittently received for the first few heartbeats (voice opcode 3).

2023-02-04 00:42:46,814:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471366814.
2023-02-04 00:42:46,815:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471366814}.

2023-02-04 00:42:48,516:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471368516.
2023-02-04 00:42:48,516:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471368516}.
2023-02-04 00:42:48,518:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471368516}

2023-02-04 00:42:51,816:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471371816.
2023-02-04 00:42:51,817:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471371816}.

2023-02-04 00:42:53,517:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471373517.
2023-02-04 00:42:53,517:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471373517}.
2023-02-04 00:42:53,533:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471373517}

2023-02-04 00:42:56,817:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471376817.
2023-02-04 00:42:56,818:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471376817}.

2023-02-04 00:42:58,518:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471378518.
2023-02-04 00:42:58,518:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471378518}.
2023-02-04 00:42:58,523:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471378518}

2023-02-04 00:43:01,819:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471381819.
2023-02-04 00:43:01,825:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471381819}.

2023-02-04 00:43:03,519:DEBUG:discord.gateway: Keeping shard ID None voice websocket alive with timestamp 1675471383519.
2023-02-04 00:43:03,519:DEBUG:discord.gateway: Sending voice websocket frame: {'op': 3, 'd': 1675471383519}.
2023-02-04 00:43:03,522:DEBUG:discord.gateway: Voice websocket frame received: {'op': 6, 'd': 1675471383519}