diff --git a/musicbot/__init__.py b/musicbot/__init__.py index d6ecb2af3..3975f75a1 100644 --- a/musicbot/__init__.py +++ b/musicbot/__init__.py @@ -1,3 +1 @@ -from .bot import MusicBot - -__all__ = ["MusicBot"] +# Just empty for now... diff --git a/musicbot/bot.py b/musicbot/bot.py index df3abffc2..775c320d0 100644 --- a/musicbot/bot.py +++ b/musicbot/bot.py @@ -8,6 +8,8 @@ import random import re import shutil +import signal +import socket import ssl import sys import time @@ -26,6 +28,9 @@ from .aliases import Aliases, AliasesDefault from .config import Config, ConfigDefaults from .constants import ( + DEFAULT_PING_SLEEP, + DEFAULT_PING_TARGET, + DEFAULT_PING_TIMEOUT, DISCORD_MSG_CHAR_LIMIT, EMOJI_CHECK_MARK_BUTTON, EMOJI_CROSS_MARK_BUTTON, @@ -34,6 +39,7 @@ EMOJI_PREV_ICON, ) from .constants import VERSION as BOTVERSION +from .constants import VOICE_CLIENT_MAX_RETRY_CONNECT, VOICE_CLIENT_RECONNECT_TIMEOUT from .constructs import GuildSpecificData, Response from .entry import StreamPlaylistEntry, URLPlaylistEntry from .filecache import AudioFileCache @@ -77,6 +83,12 @@ discord.GroupChannel, discord.PartialMessageable, ] +GuildMessageableChannels = Union[ + discord.TextChannel, + discord.Thread, + discord.VoiceChannel, + discord.StageChannel, +] # Voice Channels that MusicBot Can connect to. VoiceableChannel = Union[ discord.VoiceChannel, @@ -101,15 +113,8 @@ def __init__( aliases_file: Optional[pathlib.Path] = None, use_certifi: bool = False, ) -> None: + log.info("Initializing MusicBot %s", BOTVERSION) load_opus_lib() - try: - sys.stdout.write(f"\x1b]2;MusicBot {BOTVERSION}\x07") - except (TypeError, OSError): - log.warning( - "Failed to set terminal Title via escape sequences.", exc_info=True - ) - - print() if config_file is None: config_file = ConfigDefaults.options_file @@ -121,12 +126,17 @@ def __init__( aliases_file = AliasesDefault.aliases_file self.use_certifi: bool = use_certifi - self.players: Dict[int, MusicPlayer] = {} self.exit_signal: ExitSignals = None + self._os_signal: Optional[signal.Signals] = None + self._ping_peer_addr: str = "" + self.network_outage: bool = False + self.on_ready_count: int = 0 self.init_ok: bool = False + self.logout_called: bool = False self.cached_app_info: Optional[discord.AppInfo] = None self.last_status: Optional[discord.BaseActivity] = None - self.autojoin_channels: Set[VoiceableChannel] = set() + self.players: Dict[int, MusicPlayer] = {} + self.autojoinable_channels: Set[VoiceableChannel] = set() self.config = Config(config_file) @@ -142,8 +152,6 @@ def __init__( self.filecache = AudioFileCache(self) self.downloader = downloader.Downloader(self) - log.info("Starting MusicBot %s", BOTVERSION) - if not self.autoplaylist: log.warning("Autoplaylist is empty, disabling.") self.config.auto_playlist = False @@ -234,8 +242,115 @@ async def setup_hook(self) -> None: log.info("Initialized, now connecting to discord.") # this creates an output similar to a progress indicator. muffle_discord_console_log() + self.loop.create_task(self._test_network()) - def _get_owner( + async def _test_network(self) -> None: + """ + A self looping method that tests network connectivity. + This will call to the systems ping command and use its return status. + """ + if self.logout_called: + log.noise("Network ping test is closing down.") # type: ignore[attr-defined] + return + + # Resolve the given target to speed up pings. + ping_target = self._ping_peer_addr + if not self._ping_peer_addr: + try: + ai = socket.getaddrinfo(DEFAULT_PING_TARGET, 80) + self._ping_peer_addr = ai[0][4][0] + ping_target = self._ping_peer_addr + except OSError: + log.warning("Could not resolve ping target.") + ping_target = DEFAULT_PING_TARGET + + # Make a ping call based on OS. + ping_path = shutil.which("ping") + if not ping_path: + log.warning("Could not locate path to `ping` system executable.") + ping_path = "ping" + + ping_cmd: List[str] = [] + if os.name == "nt": + # Windows ping -w uses milliseconds. + t = 1000 * DEFAULT_PING_TIMEOUT + ping_cmd = [ping_path, "-n", "1", "-w", str(t), ping_target] + else: + t = DEFAULT_PING_TIMEOUT + ping_cmd = [ping_path, "-c", "1", "-w", str(t), ping_target] + + # execute the ping command. + try: + p = await asyncio.create_subprocess_exec( + ping_cmd[0], + *ping_cmd[1:], + stdout=asyncio.subprocess.DEVNULL, + stderr=asyncio.subprocess.DEVNULL, + ) + ping_status = await p.wait() + except OSError: + log.error( + "Your environment may not allow the `ping` system command. Early network outage detection will not function.", + exc_info=self.config.debug_mode, + ) + return + + # Ping success, network up. + if ping_status == 0: + if self.network_outage: + self.on_network_up() + self.network_outage = False + + # Ping failed, network down. + else: + if not self.network_outage: + self.on_network_down() + self.network_outage = True + + # Sleep before next ping. + try: + await asyncio.sleep(DEFAULT_PING_SLEEP) + except asyncio.exceptions.CancelledError: + log.noise("Network ping test cancelled.") # type: ignore[attr-defined] + return + + # set up the next ping task if possible. + if self.loop and not self.logout_called: + self.loop.create_task(self._test_network(), name="MB_PingTest") + + def on_network_up(self) -> None: + """ + Event called by MusicBot when it detects network returned from outage. + """ + log.info("MusicBot detected network is available again.") + for gid, player in self.players.items(): + if player.is_paused and not player.paused_auto: + if not player.voice_client.is_connected(): + log.warning( + "VoiceClient is not connected, waiting to resume MusicPlayer..." + ) + continue + log.info("Resuming playback of player: (%s) %s", gid, repr(player)) + player.guild_or_net_unavailable = False + player.resume() + player.guild_or_net_unavailable = False + + def on_network_down(self) -> None: + """ + Event called by MusicBot when it detects network outage. + """ + log.info("MusicBot detected a network outage.") + for gid, player in self.players.items(): + if player.is_playing: + log.info( + "Pausing MusicPlayer due to network availability: (%s) %s", + gid, + repr(player), + ) + player.pause() + player.guild_or_net_unavailable = True + + def _get_owner_member( self, *, server: Optional[discord.Guild] = None, voice: bool = False ) -> Optional[discord.Member]: """ @@ -250,41 +365,99 @@ def _get_owner( server.members if server else self.get_all_members(), ) log.noise( # type: ignore[attr-defined] - "Looking for owner (voice:%s) and got: %s", voice, owner + "Looking for owner (in guild: %s) (required voice: %s) and got: %s", + server, + voice, + owner, ) return owner - async def _join_startup_channels(self, channels: Set[VoiceableChannel]) -> None: + async def _auto_join_channels( + self, + from_resume: bool = False, + ) -> None: """ Attempt to join voice channels that have been configured in options. - Also checks for existing voice sessions and attempts to resume - connection and playback. + Also checks for existing voice sessions and attempts to resume them. + If self.on_ready_count is 0, it will also run owner auto-summon logic. """ - joined_servers = set() - channel_map = {c.guild: c for c in channels} + log.info("Checking for channels to auto-join or resume...") + joined_servers: Set[discord.Guild] = set() + channel_map = {c.guild: c for c in self.autojoinable_channels} + + # Check guilds for a resumable channel, conditionally override with owner summon. + resuming = False for guild in self.guilds: - if guild.unavailable or guild in channel_map: + # TODO: test that this, guild_unavailable hasn't fired in testing yet + # but that don't mean this wont break due to fragile API out-of-order packets... + if guild.unavailable: + log.warning( + "Guild not available, cannot join: %s/%s", guild.id, guild.name + ) continue + # Check for a resumable channel. if guild.me.voice and guild.me.voice.channel: log.info( - "Found resumable voice channel %s/%s", - guild.name, + "Found resumable voice channel: %s in guild: %s", guild.me.voice.channel.name, + guild.name, ) + + # override an existing auto-join if bot was previously in a different channel. + if ( + guild in channel_map + and guild.me.voice.channel != channel_map[guild] + ): + log.info( + "Will try resuming voice session instead of Auto-Joining channel: %s", + channel_map[guild].name, + ) channel_map[guild] = guild.me.voice.channel + resuming = True - if self.config.auto_summon: - owner = self._get_owner(server=guild, voice=True) + # Check if we should auto-summon to the owner, but only on startup. + if self.config.auto_summon and not from_resume: + owner = self._get_owner_member(server=guild, voice=True) if owner and owner.voice and owner.voice.channel: - log.info('Found owner in "%s"', owner.voice.channel.name) + log.info( + "Found owner in voice channel: %s", owner.voice.channel.name + ) + if guild in channel_map: + if resuming: + log.info( + "Ignoring resumable channel, AutoSummon to owner in channel: %s", + owner.voice.channel.name, + ) + else: + log.info( + "Ignoring Auto-Join channel, AutoSummon to owner in channel: %s", + owner.voice.channel.name, + ) channel_map[guild] = owner.voice.channel for guild, channel in channel_map.items(): + log.everything( # type: ignore[attr-defined] + "AutoJoin Channel Map Item:\n %r\n %r", guild, channel + ) if guild in joined_servers: log.info( - 'Already joined a channel in "%s", skipping', + 'Already joined a channel in "%s", skipping channel: %s', + guild.name, + channel.name, + ) + continue + + if ( + isinstance( + guild.voice_client, (discord.VoiceClient, discord.StageChannel) + ) + and guild.voice_client.is_connected() + ): + log.info( + "Already connected to channel: %s in guild: %s", + guild.voice_client.channel.name, guild.name, ) continue @@ -293,60 +466,63 @@ async def _join_startup_channels(self, channels: Set[VoiceableChannel]) -> None: channel, (discord.VoiceChannel, discord.StageChannel) ): log.info( - "Attempting to join %s/%s", + "Attempting to join channel: %s/%s in guild: %s", channel.guild.name, channel.name, + channel.guild, ) - chperms = channel.permissions_for(guild.me) + player = self.get_player_in(guild) - if not chperms.connect: - log.info( - 'Cannot join channel "%s", no permission.', - channel.name, - ) - continue + if player: + # TODO: Get serialization of last playback position working. + log.info("Discarding MusicPlayer and making a new one...") + await self.disconnect_voice_client(guild) - if not chperms.speak: - log.info( - 'Will not join channel "%s", no permission to speak.', - channel.name, - ) - continue + try: + player = await self.get_player( + channel, + create=True, + deserialize=self.config.persistent_queue, + ) + """ + if self.server_data[guild.id].availability_paused: + log.debug( + "Setting availability of player in guild: %s", + guild, + ) + self.server_data[guild.id].availability_paused = False - try: - player = await self.get_player( - channel, create=True, deserialize=self.config.persistent_queue - ) - joined_servers.add(guild) + if self.server_data[guild.id].auto_paused: + self.server_data[guild.id].auto_paused = False + #""" - log.info( - "Joined %s/%s", - channel.guild.name, - channel.name, - ) + if player.is_stopped and len(player.playlist) > 0: + player.play() - if player.is_stopped: - player.play() + if self.config.auto_playlist and len(player.playlist) == 0: + await self.on_player_finished_playing(player) - if self.config.auto_playlist: - if not player.playlist.entries: + except (TypeError, exceptions.PermissionsError): + continue + + else: + log.debug("MusicBot will make a new MusicPlayer now...") + try: + player = await self.get_player( + channel, + create=True, + deserialize=self.config.persistent_queue, + ) + + if player.is_stopped and len(player.playlist) > 0: + player.play() + + if self.config.auto_playlist and len(player.playlist) == 0: await self.on_player_finished_playing(player) - # TODO: drill down through the above code and find what exceptions - # we actually want to be handling here. - except Exception: # pylint: disable=broad-exception-caught - log.debug( - "Error joining %s/%s", - channel.guild.name, - channel.name, - exc_info=True, - ) - log.error( - "Failed to join %s/%s", - channel.guild.name, - channel.name, - ) + except (TypeError, exceptions.PermissionsError): + continue if channel and not isinstance( channel, (discord.VoiceChannel, discord.StageChannel) @@ -368,10 +544,15 @@ async def _wait_delete_msg( try: await asyncio.sleep(after) except asyncio.CancelledError: - log.exception("_wait_delete_msg sleep caught exception. bailing.") + log.warning( + "Cancelled delete for message (ID: %s): %s", + message.id, + message.content, + ) return if not self.is_closed(): + await self.safe_delete_message(message, quiet=True) async def _check_ignore_non_voice(self, msg: discord.Message) -> bool: @@ -448,13 +629,21 @@ async def remove_url_from_autoplaylist( if delete_from_ap: log.info("Updating autoplaylist file...") + + def _filter_replace(line: str, url: str) -> str: + target = line.strip() + if target == url: + return f"# Removed # {url}" + return line + # read the original file in and remove lines with the URL. # this is done to preserve the comments and formatting. try: apl = pathlib.Path(self.config.auto_playlist_file) - data = apl.read_text(encoding="utf8") - data = data.replace(song_url, f"#Removed# {song_url}") - apl.write_text(data, encoding="utf8") + data = apl.read_text(encoding="utf8").split("\n") + data = [_filter_replace(x, song_url) for x in data] + text = "\n".join(data) + apl.write_text(text, encoding="utf8") except (OSError, PermissionError, FileNotFoundError): log.exception("Failed to save autoplaylist file.") self.filecache.remove_autoplay_cachemap_entry_by_url(song_url) @@ -514,78 +703,225 @@ async def get_voice_client(self, channel: VoiceableChannel) -> discord.VoiceClie :raises: TypeError If `channel` is not a discord.VoiceChannel or discord.StageChannel + + :raises: musicbot.exceptions.PermissionsError + If MusicBot does not have permissions required to join or speak in the `channel`. """ if not isinstance(channel, (discord.VoiceChannel, discord.StageChannel)): raise TypeError("Channel passed must be a voice channel") - # TODO: await for ready here? + # Check if MusicBot has required permissions to join in channel. + chperms = channel.permissions_for(channel.guild.me) + if not chperms.connect: + log.error( + "MusicBot does not have permission to Connect in channel: %s", + channel.name, + ) + raise exceptions.PermissionsError( + f"MusicBot does not have permission to Connect in channel: `{channel.name}`", + expire_in=30, + ) + if not chperms.speak: + log.error( + "MusicBot does not have permission to Speak in channel: %s", + channel.name, + ) + raise exceptions.PermissionsError( + f"MusicBot does not have permission to Speak in channel: `{channel.name}`", + expire_in=30, + ) # check for and return bots VoiceClient if we already have one. vc = channel.guild.voice_client - if vc and isinstance(vc, discord.VoiceClient): - return vc + if vc and isinstance(vc, (discord.VoiceClient, discord.StageChannel)): + # make sure it is usable + if vc.is_connected(): + log.voicedebug( # type: ignore[attr-defined] + "Reusing bots VoiceClient from guild: %s", channel.guild + ) + return vc + # or otherwise we kill it and start fresh. + log.voicedebug( # type: ignore[attr-defined] + "Forcing disconnect on stale VoiceClient in guild: %s", channel.guild + ) + try: + # TODO: do we need disconnect(force=True) + await vc.disconnect() + except (asyncio.exceptions.CancelledError, asyncio.exceptions.TimeoutError): + if self.config.debug_mode: + log.warning("Disconnect failed or was cancelled?") + + # Otherwise we need to connect to the given channel. + max_timeout = VOICE_CLIENT_RECONNECT_TIMEOUT * VOICE_CLIENT_MAX_RETRY_CONNECT + attempts = 0 + while True: + attempts += 1 + timeout = attempts * VOICE_CLIENT_RECONNECT_TIMEOUT + if timeout > max_timeout: + log.critical( + "MusicBot is unable to connect to the channel right now: %s", + channel, + ) + raise exceptions.CommandError( + "MusicBot could not connect to the channel. Try again later, or restart the bot if this continues." + ) - # otherwise we need to connect to the given channel. - client: discord.VoiceClient = await channel.connect(timeout=30, reconnect=True) - if isinstance(channel, discord.StageChannel): try: - await channel.guild.me.edit(suppress=False) - await channel.guild.change_voice_state( - channel=channel, - self_mute=False, + client: discord.VoiceClient = await channel.connect( + timeout=timeout, + reconnect=True, self_deaf=self.config.self_deafen, ) + log.voicedebug( # type: ignore[attr-defined] + "MusicBot has a VoiceClient now..." + ) + break + except asyncio.exceptions.TimeoutError: + log.warning( + "Retrying connection after a timeout error (%s) while trying to connect to: %s", + attempts, + channel, + ) + except asyncio.exceptions.CancelledError as e: + log.exception( + "MusicBot VoiceClient connection attempt was cancelled. No retry." + ) + raise exceptions.CommandError( + "MusicBot connection to voice was cancelled. This is odd. Maybe restart?" + ) from e + + # TODO: look into Stage channel handling and test this at some point. + if isinstance(channel, discord.StageChannel): + try: + await channel.guild.me.edit(suppress=False) except (discord.Forbidden, discord.HTTPException): log.exception("Something broke in StageChannel handling.") - else: - await channel.guild.change_voice_state( - channel=channel, - self_mute=False, - self_deaf=self.config.self_deafen, - ) + return client async def disconnect_voice_client(self, guild: discord.Guild) -> None: """ - Check for a client in the given `guild` and disconnect it gracefully. - The player will be removed to MusicBot.players list, and associated - event timers will be reset. + Check for a MusicPlayer in the given `guild` and close it's VoiceClient + gracefully then remove the MusicPlayer instance and reset any timers on + the guild for player/channel inactivity. """ - vc = self.voice_client_in(guild) - if not vc: - return - if guild.id in self.players: + log.info("Disconnecting a MusicPlayer in guild: %s", guild) player = self.players.pop(guild.id) await self.reset_player_inactivity(player) + # reset channel inactivity. if self.config.leave_inactive_channel: event = self.server_data[guild.id].get_event("inactive_vc_timer") if event.is_active() and not event.is_set(): event.set() + if player.voice_client: + log.debug("Disconnecting VoiceClient before we kill the MusicPlayer.") + try: + await player.voice_client.disconnect() + except ( + asyncio.exceptions.CancelledError, + asyncio.exceptions.TimeoutError, + ): + if self.config.debug_mode: + log.warning("The disconnect failed or was cancelledd.") + + # ensure the player is dead and gone. player.kill() + del player + + # Double check for voice objects. + for vc in self.voice_clients: + if not isinstance(vc, discord.VoiceClient): + log.debug( + "MusicBot has a VoiceProtocol that is not a VoiceClient. Disconnecting anyway..." + ) + try: + await vc.disconnect(force=True) + except ( + asyncio.exceptions.CancelledError, + asyncio.exceptions.TimeoutError, + ): + if self.config.debug_mode: + log.warning("The disconnect failed or was cancelled.") + continue + + if vc.guild and vc.guild == guild: + log.debug("Disconnecting a rogue VoiceClient in guild: %s", guild) + try: + await vc.disconnect() + except ( + asyncio.exceptions.CancelledError, + asyncio.exceptions.TimeoutError, + ): + if self.config.debug_mode: + log.warning("The disconnect failed or was cancelled.") await self.update_now_playing_status() - await vc.disconnect() async def disconnect_all_voice_clients(self) -> None: """ - Loop over all available self.voice_clients and use their guild id - to disconnect their VoiceClient... + Loop over all references that may have a VoiceClient and ensure they are + closed and disposed of in the case of MusicPlayer. """ + # Disconnect from all guilds. + for guild in self.guilds: + await self.disconnect_voice_client(guild) + + # Double check for detached voice clients. for vc in self.voice_clients: if isinstance(vc, discord.VoiceClient): - await self.disconnect_voice_client(vc.guild) + log.warning("Disconnecting a non-guild VoiceClient...") + try: + await vc.disconnect() + except ( + asyncio.exceptions.CancelledError, + asyncio.exceptions.TimeoutError, + ): + log.warning("The disconnect failed or was cancelled.") else: log.warning( - "Hmm, our voice_clients list contains a non-VoiceClient object?" + "MusicBot.voice_clients list contains a non-VoiceClient object?\n" + "The object is actually of type: %s", + type(vc), ) + # Triple check we don't have rogue players. This would be a bug. + player_gids = list(self.players.keys()) + for gid in player_gids: + player = self.players[gid] + log.warning( + "We still have a MusicPlayer ref in guild (%s): %s", + gid, + repr(player), + ) + del self.players[gid] + def get_player_in(self, guild: discord.Guild) -> Optional[MusicPlayer]: - """Get a MusicPlayer in the given guild, but do not create a new player.""" - return self.players.get(guild.id) + """ + Get a MusicPlayer in the given guild, but do not create a new player. + MusicPlayer returned from this method may not be connected to a voice channel! + """ + p = self.players.get(guild.id) + if log.getEffectiveLevel() <= logging.EVERYTHING: # type: ignore[attr-defined] + log.voicedebug( # type: ignore[attr-defined] + "Guild (%s) wants a player, optional: %s", guild, repr(p) + ) + + if log.getEffectiveLevel() <= logging.VOICEDEBUG: # type: ignore[attr-defined] + if p and not p.voice_client: + log.error( + "[BUG] MusicPlayer is missing a VoiceClient some how. You should probably restart the bot." + ) + if p and p.voice_client and not p.voice_client.is_connected(): + # This is normal if the bot is still connecting to voice, or + # if the player has been pointedly disconnected. + log.warning("MusicPlayer has a VoiceClient that is not connected.") + log.noise("MusicPlayer obj: %r", p) # type: ignore[attr-defined] + log.noise("VoiceClient obj: %r", p.voice_client) # type: ignore[attr-defined] + return p async def get_player( self, @@ -594,16 +930,31 @@ async def get_player( *, deserialize: bool = False, ) -> MusicPlayer: - """Get a MusicPlayer in the given guild, creating one if needed.""" + """ + Get a MusicPlayer in the given guild, creating or deserializing one if needed. + + :raises: TypeError + If given `channel` is not a discord.VoiceChannel or discord.StageChannel + :raises: musicbot.exceptions.PermissionsError + If MusicBot is not permitted to join the given `channel`. + """ guild = channel.guild + log.voicedebug( # type: ignore[attr-defined] + "Getting a MusicPlayer for guild: %s In Channel: %s Will Create: %s Deserialize: %s", + guild, + channel, + create, + deserialize, + ) + async with self.aiolocks[_func_() + ":" + str(guild.id)]: if deserialize: voice_client = await self.get_voice_client(channel) player = await self.deserialize_queue(guild, voice_client) if player: - log.debug( + log.voicedebug( # type: ignore[attr-defined] "Created player via deserialization for guild %s with %s entries", guild.id, len(player.playlist), @@ -661,7 +1012,7 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: Event called by MusicPlayer when playback of an entry is started. """ log.debug("Running on_player_play") - self._handle_guild_auto_pause(player) + await self._handle_guild_auto_pause(player) await self.reset_player_inactivity(player) await self.update_now_playing_status() # manage the cache since we may have downloaded something. @@ -675,14 +1026,11 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: if self.config.write_current_song: await self.write_current_song(player.voice_client.channel.guild, entry) - channel = entry.meta.get("channel", None) - author = entry.meta.get("author", None) - - if channel and author: - author_perms = self.permissions.for_user(author) + if entry.channel and entry.author: + author_perms = self.permissions.for_user(entry.author) if ( - author not in player.voice_client.channel.members + entry.author not in player.voice_client.channel.members and author_perms.skip_when_absent ): newmsg = self.str.get( @@ -691,7 +1039,7 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: ).format( channel=player.voice_client.channel.name, title=entry.title, - author=entry.meta["author"].name, + author=entry.author.name, ) player.skip() elif self.config.now_playing_mentions: @@ -699,7 +1047,7 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: "on_player_play-onChannel_playingMention", "{author} - your song {title} is now playing in {channel}!", ).format( - author=entry.meta["author"].mention, + author=entry.author.mention, title=entry.title, channel=player.voice_client.channel.name, ) @@ -710,7 +1058,7 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: ).format( channel=player.voice_client.channel.name, title=entry.title, - author=entry.meta["author"].name, + author=entry.author.name, ) else: @@ -720,17 +1068,17 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: "Now playing automatically added entry {title} in {channel}!", ).format(title=entry.title, channel=player.voice_client.channel.name) + guild = player.voice_client.guild + last_np_msg = self.server_data[guild.id].last_np_msg + np_channel: Optional[MessageableChannel] = None if newmsg: - if self.config.dm_nowplaying and author: - await self.safe_send_message(author, newmsg) + if self.config.dm_nowplaying and entry.author: + await self.safe_send_message(entry.author, newmsg) return - if self.config.no_nowplaying_auto and not author: + if self.config.no_nowplaying_auto and entry.from_auto_playlist: return - guild = player.voice_client.guild - last_np_msg = self.server_data[guild.id].last_np_msg - if self.config.nowplaying_channels: for potential_channel_id in self.config.nowplaying_channels: potential_channel = self.get_channel(potential_channel_id) @@ -741,20 +1089,14 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: continue if potential_channel and potential_channel.guild == guild: - channel = potential_channel + np_channel = potential_channel break - if channel: - pass - elif not channel and last_np_msg: - channel = last_np_msg.channel - else: - log.debug("no channel to put now playing message into") - return + if not np_channel and last_np_msg: + np_channel = last_np_msg.channel + content = self._gen_embed() if self.config.embeds: - content = self._gen_embed() - if entry.thumbnail_url: content.set_image(url=entry.thumbnail_url) else: @@ -770,8 +1112,29 @@ async def on_player_play(self, player: MusicPlayer, entry: EntryTypes) -> None: content.title = newmsg # send it in specified channel + if not np_channel: + log.debug("no channel to put now playing message into") + return + + # Don't send the same now-playing message more than once. + # This prevents repeated messages when players reconnect. + last_subject = self.server_data[guild.id].last_played_song_subject + if ( + last_np_msg is not None + and player.current_entry is not None + and last_subject + and last_subject == player.current_entry.url + ): + log.debug("ignored now-playing message as it was already posted.") + return + + if player.current_entry: + self.server_data[guild.id].last_played_song_subject = ( + player.current_entry.url + ) + self.server_data[guild.id].last_np_msg = await self.safe_send_message( - channel, + np_channel, content if self.config.embeds else newmsg, expire_in=30 if self.config.delete_nowplaying else 0, ) @@ -820,6 +1183,20 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non Event called by MusicPlayer when playback has finished without error. """ log.debug("Running on_player_finished_playing") + if not self.loop or (self.loop and self.loop.is_closed()): + log.debug("Event loop is closed, nothing else to do here.") + return + + if self.logout_called: + log.debug("Logout under way, ignoring this event.") + return + + if not player.voice_client.is_connected(): + log.debug( + "VoiceClient says it is not connected, nothing else we can do here." + ) + return + if self.config.leave_after_queue_empty: guild = player.voice_client.guild if len(player.playlist.entries) == 0: @@ -841,8 +1218,8 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non if not next_entry: break - channel = next_entry.meta.get("channel", None) - author = next_entry.meta.get("author", None) + channel = next_entry.channel + author = next_entry.author if not channel or not author: break @@ -875,13 +1252,12 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non and not player.current_entry and self.config.auto_playlist ): + # NOTE: self.autoplaylist will only contain links loaded from the file. + # while player.autoplaylist may contain links expanded from playlists. + # the only issue is that links from a playlist might fail and fire + # remove event, but no link will be removed since none will match. if not player.autoplaylist: if not self.autoplaylist: - # TODO: When I add playlist expansion, make sure that's not happening during this check. - # @Fae: Could lock this but it probably isn't needed. - # - if `self.autoplaylist` is already empty, and the last entry was a playlist URL - # - then queued songs from that URL go into the `player.playlist`, not into `self.autoplaylist`. - # So if it's empty, it will stay that way unless someone is actively adding URLs when this fires. log.warning("No playable songs in the autoplaylist, disabling.") self.config.auto_playlist = False else: @@ -902,23 +1278,25 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non info = await self.downloader.extract_info( song_url, download=False, process=True ) - except youtube_dl.utils.DownloadError as e: - if "YouTube said:" in e.args[0]: - # url is bork, remove from list and put in removed list - log.error("Error processing youtube url:\n%s", e.args[0]) - else: - # Probably an error from a different extractor, but I've only seen youtube's - log.error('Error processing "%s": %s', song_url, e) + except youtube_dl.utils.DownloadError as e: + log.error( + 'Error while downloading song "%s": %s', + song_url, + e, + ) await self.remove_url_from_autoplaylist( song_url, ex=e, delete_from_ap=self.config.remove_ap ) continue - except Exception as e: # pylint: disable=broad-exception-caught + except ( + exceptions.ExtractionError, + youtube_dl.utils.YoutubeDLError, + ) as e: log.error( - 'Error processing "%s": %s', + 'Error extracting song "%s": %s', song_url, e, exc_info=True, @@ -929,17 +1307,29 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non ) continue + except exceptions.MusicbotException: + log.exception( + "MusicBot needs to stop the autoplaylist extraction and bail." + ) + return + except Exception: + log.exception( + "MusicBot got an unhandled exception in player finished event." + ) + break + if info.has_entries: - await player.playlist.import_from_info( - info, - channel=None, - author=None, - head=False, - is_autoplaylist=True, + log.info( + "Expanding auto playlist with entries extracted from: %s", + info.url, ) + entries = info.get_entries_objects() + pl_urls: List[str] = [] + for entry in entries: + pl_urls.append(entry.url) - # Do I check the initial conditions again? - # not (not player.playlist.entries and not player.current_entry and self.config.auto_playlist) + player.autoplaylist = pl_urls + player.autoplaylist + continue try: await player.playlist.add_entry_from_info( @@ -947,7 +1337,6 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non channel=None, author=None, head=False, - is_autoplaylist=True, ) except ( exceptions.ExtractionError, @@ -957,13 +1346,11 @@ async def on_player_finished_playing(self, player: MusicPlayer, **_: Any) -> Non "Error adding song from autoplaylist: %s", str(e), ) - log.debug("", exc_info=True) + log.debug("Exception data for above error:", exc_info=True) continue - break if not self.autoplaylist: - # TODO: When I add playlist expansion, make sure that's not happening during this check log.warning("No playable songs in the autoplaylist, disabling.") self.config.auto_playlist = False @@ -994,39 +1381,34 @@ async def on_player_entry_added( and not entry.from_auto_playlist # TODO: and self.config.autoplaylist_autoskip ): + log.debug("Automatically skipping auto-playlist entry for queued entry.") player.skip() # Only serialize the queue for user-added tracks, unless deferred - if ( - entry.meta.get("author") - and entry.meta.get("channel") - and not defer_serialize - ): + if entry.author and entry.channel and not defer_serialize: await self.serialize_queue(player.voice_client.channel.guild) async def on_player_error( self, player: MusicPlayer, # pylint: disable=unused-argument - entry: EntryTypes, + entry: Optional[EntryTypes], ex: Optional[Exception], **_: Any, ) -> None: """ Event called by MusicPlayer when an entry throws an error. """ - author = entry.meta.get("author", None) - channel = entry.meta.get("channel", None) - if channel and author: + if entry and entry.channel: song = entry.title or entry.url await self.safe_send_message( - channel, + entry.channel, # TODO: i18n / UI stuff f"Playback failed for song: `{song}` due to error:\n```\n{ex}\n```", ) else: log.exception("Player error", exc_info=ex) - async def update_now_playing_status(self) -> None: + async def update_now_playing_status(self, set_offline: bool = False) -> None: """Inspects available players and ultimately fire change_presence()""" activity = None # type: Optional[discord.BaseActivity] status = discord.Status.online # type: discord.Status @@ -1037,6 +1419,24 @@ async def update_now_playing_status(self) -> None: # However all other details in the client might be wrong or missing. # Example: Youtube url shows "Twitch" in client profile info. + # if requested, try to set the bot offline. + if set_offline: + activity = discord.Activity( + type=discord.ActivityType.custom, + state="", + name="Custom Status", # seemingly required. + ) + await self.change_presence( + status=discord.Status.invisible, activity=activity + ) + self.last_status = activity + return + + # We ignore player related status when logout is called. + if self.logout_called: + log.debug("Logout under way, ignoring status update event.") + return + playing = sum(1 for p in self.players.values() if p.is_playing) paused = sum(1 for p in self.players.values() if p.is_paused) total = len(self.players) @@ -1111,6 +1511,8 @@ async def serialize_queue( """ Serialize the current queue for a server's player to json. """ + if not self.config.persistent_queue: + return player = self.get_player_in(guild) if not player: @@ -1136,6 +1538,8 @@ async def deserialize_queue( """ Deserialize a saved queue for a server into a MusicPlayer. If no queue is saved, returns None. """ + if not self.config.persistent_queue: + return None if playlist is None: playlist = Playlist(self) @@ -1173,50 +1577,6 @@ async def write_current_song( with open(path, "w", encoding="utf8") as f: f.write(entry.title) - async def _on_ready_sanity_checks(self) -> None: - """ - Run all sanity checks that should be run in/just after on_ready event. - """ - # Ensure AppInfo is loaded. - if not self.cached_app_info: - log.debug("Getting application info.") - self.cached_app_info = await self.application_info() - - # Ensure folders exist - await self._scheck_ensure_env() - - # TODO: Server permissions check - # TODO: pre-expand playlists in autoplaylist? - - # config/permissions async validate? - await self._scheck_configs() - - async def _scheck_ensure_env(self) -> None: - """ - Startup check to make sure guild/server specific directories are - available in the data directory. - Additionally populate a text file to map guild ID to their names. - """ - log.debug("Ensuring data folders exist") - for guild in self.guilds: - pathlib.Path(f"data/{guild.id}/").mkdir(exist_ok=True) - - with open("data/server_names.txt", "w", encoding="utf8") as f: - for guild in sorted(self.guilds, key=lambda s: int(s.id)): - f.write(f"{guild.id}: {guild.name}\n") - - self.filecache.delete_old_audiocache(remove_dir=True) - - async def _scheck_configs(self) -> None: - """ - Startup check to handle late validation of config and permissions. - """ - log.debug("Validating config") - await self.config.async_validate(self) - - log.debug("Validating permissions config") - await self.permissions.async_validate(self) - ####################################################################################################################### async def safe_send_message( @@ -1300,9 +1660,7 @@ async def safe_send_message( try: await asyncio.sleep(retry_after) except asyncio.CancelledError: - log.exception( - "Sleep in send message caught exception, bailing out." - ) + log.warning("Cancelled message retry for: %s", content) return msg return await self.safe_send_message(dest, content, **kwargs) @@ -1434,9 +1792,7 @@ async def safe_edit_message( try: await asyncio.sleep(retry_after) except asyncio.CancelledError: - log.exception( - "Sleep in edit message caught exception, bailing out." - ) + log.warning("Cancelled message edit for: %s", message) return None return await self.safe_edit_message( message, new, send_if_fail=send_if_fail, quiet=quiet @@ -1449,67 +1805,136 @@ async def safe_edit_message( return None - async def shutdown_cleanup(self) -> None: + def _setup_windows_signal_handler(self) -> None: """ - Function which forces closure on connections and pending tasks. - Much scrutiny required herein. - Probably due for further refactoring. + Windows needs special handling for Ctrl+C signals to play nice with asyncio + so this method sets up signals with access to bot event loop. + This enables capturing KeyboardInterrupt and using it to cleanly shut down. """ - try: # make sure discord.Client is closed. - await self.close() # changed in d.py 2.0 - except Exception: # pylint: disable=broad-exception-caught - log.exception("Issue while closing discord client session.") + if os.name != "nt": + return - try: # make sure discord.http.connector is closed. - # This may be a bug in aiohttp or within discord.py handling of it. - # Have read aiohttp 4.x is supposed to fix this, but have not verified. - if self.http.connector: - await self.http.connector.close() - except Exception: # pylint: disable=broad-exception-caught - log.exception("Issue while closing discord aiohttp connector.") + # method used to set the above member. + def set_windows_signal(sig: int, _frame: Any) -> None: + self._os_signal = signal.Signals(sig) - try: # make sure our aiohttp session is closed. - if self.session: - await self.session.close() - except Exception: # pylint: disable=broad-exception-caught - log.exception("Issue while closing our aiohttp session.") + # method used to periodically check for a signal, and process it. + async def check_windows_signal() -> None: + while True: + if self.logout_called: + break + + if self._os_signal is None: + try: + await asyncio.sleep(1) + except asyncio.CancelledError: + break + else: + await self.on_os_signal(self._os_signal, self.loop) + self._os_signal = None - # now cancel all pending tasks, except for run.py::main() - for task in asyncio.all_tasks(loop=self.loop): - coro = task.get_coro() + # register interrupt signal Ctrl+C to be trapped. + signal.signal(signal.SIGINT, set_windows_signal) + # and start the signal checking loop. + asyncio.create_task(check_windows_signal()) - if ( - hasattr(coro, "__name__") - and coro.__name__ == "main" - and task.get_name().lower() == "task-1" - ): - continue + async def on_os_signal( + self, sig: signal.Signals, _loop: asyncio.AbstractEventLoop + ) -> None: + """ + On Unix-like/Linux OS, this method is called automatically on the event + loop for signals registered in run.py. + On Windows, this method is called by custom signal handling set up at + the start of run_musicbot(). + This allows MusicBot to handle external signals and triggering a clean + shutdown of MusicBot in response to them. - task.cancel() - try: - await task - except asyncio.CancelledError: - pass + It essentially just calls logout, and the rest of MusicBot tear-down is + finished up in `MusicBot.run_musicbot()` instead. + + Signals handled here are registered with the event loop in run.py. + """ + # This print facilitates putting '^C' on its own line in the terminal. + print() + log.warning("Caught a signal from the OS: %s", sig.name) - # TODO: rename this instead of overriding client run maybe. - async def run(self) -> None: # type: ignore[override] + try: + if self and not self.logout_called: + log.info("Disconnecting and closing down MusicBot...") + await self.logout() + except Exception as e: + log.exception("Exception thrown while handling interrupt signal!") + raise KeyboardInterrupt() from e + + async def run_musicbot(self) -> None: + """ + This method is to be used in an event loop to start the MusicBot. + It handles cleanup of bot session, while the event loop is closed separately. + """ + # Windows specifically needs some help with signals. + self._setup_windows_signal_handler() + + # handle start up and teardown. try: await self.start(*self.config.auth) + log.info("MusicBot is now doing shutdown steps...") + if self.exit_signal is None: + self.exit_signal = exceptions.TerminateSignal() except discord.errors.LoginFailure as e: - # TODO: this message might be misleading, add token check. raise exceptions.HelpfulError( - "Bot cannot login, bad credentials.", - "Fix your token in the options file. " + preface="Failed login to discord API!", + issue="MusicBot cannot login to discord, is your token correct?", + solution="Fix your token in the options.ini config file.\n" "Remember that each field should be on their own line.", + footnote="Note: If you are certain your token is correct, this may be due to a Discord API outage.", ) from e finally: - try: - await self.shutdown_cleanup() - except Exception: # pylint: disable=broad-exception-caught - log.error("Error in cleanup", exc_info=True) + # Inspect all waiting tasks and either cancel them or let them finish. + pending_tasks = [] + for task in asyncio.all_tasks(loop=self.loop): + # Don't cancel run_musicbot task, we need it to finish cleaning. + if task == asyncio.current_task(): + continue + + tname = task.get_name() + coro = task.get_coro() + coro_name = "[unknown]" + if coro and hasattr(coro, "__qualname__"): + coro_name = getattr(coro, "__qualname__", "[unknown]") + + if ( + tname.startswith("Signal_SIG") + or coro_name == "URLPlaylistEntry._download" + ): + log.debug("Will wait for task: %s (%s)", tname, coro_name) + pending_tasks.append(task) + else: + log.debug("Will try to cancel task: %s (%s)", tname, coro_name) + task.cancel() + pending_tasks.append(task) + + # wait on any pending tasks. + if pending_tasks: + log.debug("Awaiting pending tasks...") + await asyncio.gather(*pending_tasks, return_exceptions=True) + await asyncio.sleep(0.5) + + # ensure connector is closed. + if self.http.connector: + log.debug("Closing HTTP Connector.") + await self.http.connector.close() + await asyncio.sleep(0.5) + + # ensure the session is closed. + if self.session: + log.debug("Closing aiohttp session.") + await self.session.close() + await asyncio.sleep(0.5) + + # if anything set an exit signal, we should raise it here. if self.exit_signal: raise self.exit_signal @@ -1517,6 +1942,10 @@ async def logout(self) -> None: """ Disconnect all voice clients and signal MusicBot to close it's connections to discord. """ + log.noise("Logout has been called.") # type: ignore[attr-defined] + await self.update_now_playing_status(set_offline=True) + + self.logout_called = True await self.disconnect_all_voice_clients() return await super().close() @@ -1542,7 +1971,8 @@ async def on_resumed(self) -> None: Event called by discord.py when the client resumed an existing session. https://discordpy.readthedocs.io/en/stable/api.html#discord.on_resume """ - log.info("\nReconnected to discord.\n") + log.info("MusicBot resumed a session with discord.") + await self._auto_join_channels(from_resume=True) async def on_ready(self) -> None: """ @@ -1551,41 +1981,39 @@ async def on_ready(self) -> None: See documentations for specifics: https://discordpy.readthedocs.io/en/stable/api.html#discord.on_ready """ - mute_discord_console_log() - log.debug("Connection established, ready to go.") + if self.on_ready_count == 0: + await self._on_ready_once() + self.init_ok = True - # Set the handler name if we have it. I don't know why, but we do. - if self.ws._keep_alive: # pylint: disable=protected-access - self.ws._keep_alive.name = ( # pylint: disable=protected-access - "Gateway Keepalive" - ) - else: - log.error( - "Failed to set WebSocket KeepAlive handler name, handler not available." - ) + await self._on_ready_always() + self.on_ready_count += 1 - if self.init_ok: - log.debug("Received additional READY event, may have failed to resume") - return + log.debug("Finish on_ready") - await self._on_ready_sanity_checks() + async def _on_ready_once(self) -> None: + """ + A version of on_ready that will only ever be called once, at first login. + """ + mute_discord_console_log() + log.debug("Logged in, now getting MusicBot ready...") if not self.user: log.critical("ClientUser is somehow none, we gotta bail...") - return + self.exit_signal = exceptions.TerminateSignal() + raise self.exit_signal - self.init_ok = True - - ################################ + # Start the environment checks. Generate folders/files dependent on Discord data. + # Also takes care of app-info and auto OwnerID updates. + await self._on_ready_sanity_checks() log.info( - "Connected: %s/%s#%s", + "MusicBot: %s/%s#%s", self.user.id, self.user.name, self.user.discriminator, ) - owner = self._get_owner(voice=True) or self._get_owner() + owner = self._get_owner_member() if owner and self.guilds: log.info( "Owner: %s/%s#%s\n", @@ -1645,6 +2073,7 @@ async def on_ready(self) -> None: # for s in self.guilds: # await self._load_guild_options(s) + # validate bound channels and log them. if self.config.bound_channels: # Get bound channels by ID, and validate that we can use them. text_chlist: Set[MessageableChannel] = set() @@ -1675,7 +2104,14 @@ async def on_ready(self) -> None: log.info("Bound to text channels:") for valid_ch in text_chlist: guild_name = "PrivateChannel" - ch_name = type(valid_ch).__name__ + if isinstance(valid_ch, discord.DMChannel): + ch_name = "Unknown User DM" + if valid_ch.recipient: + ch_name = f"DM: {valid_ch.recipient.name}" + elif isinstance(valid_ch, discord.PartialMessageable): + ch_name = "Unknown Partial Channel" + else: + ch_name = valid_ch.name or f"Unnamed Channel: {valid_ch.id}" if valid_ch.guild: guild_name = valid_ch.guild.name log.info(" - %s/%s", guild_name, ch_name) @@ -1684,6 +2120,9 @@ async def on_ready(self) -> None: else: log.info("Not bound to any text channels") + print(flush=True) # new line in console. + + # validate and display auto-join channels. if self.config.autojoin_channels: vc_chlist: Set[VoiceableChannel] = set() invalids: Set[int] = set() @@ -1715,154 +2154,197 @@ async def on_ready(self) -> None: # Update config data to be reliable later. self.config.autojoin_channels.difference_update(invalids) # Store the channel objects for later use. - self.autojoin_channels = vc_chlist + self.autojoinable_channels = vc_chlist + + # log what we're connecting to. + if vc_chlist: + log.info("Autojoining voice channels:") + for ch in vc_chlist: + log.info(" - %s/%s", ch.guild.name.strip(), ch.name.strip()) + + else: + log.info("Not autojoining any voice channels") + + else: + log.info("Not autojoining any voice channels") + + # Display and log the config settings. + if self.config.show_config_at_start: + self._on_ready_log_configs() + + # we do this after the config list because it's a lot easier to notice here + if self.config.missing_keys: + conf_warn = exceptions.HelpfulError( + preface="Detected missing config options!", + issue="Your options.ini file is missing some options. Defaults will be used for this session.\n" + f"Here is a list of options we think are missing:\n {', '.join(self.config.missing_keys)}", + solution="Check the example_options.ini file for newly added options and copy them to your config.", + ) + log.warning(str(conf_warn)[1:]) + + # self.loop.create_task(self._on_ready_call_later()) + + async def _on_ready_always(self) -> None: + """ + A version of on_ready that will be called on every event. + """ + if self.on_ready_count > 0: + log.debug("Event on_ready has fired %s times", self.on_ready_count) + self.loop.create_task(self._on_ready_call_later()) + + async def _on_ready_call_later(self) -> None: + """ + A collection of calls scheduled for execution by _on_ready_once + """ + await self.update_now_playing_status() + await self._auto_join_channels() + + async def _on_ready_sanity_checks(self) -> None: + """ + Run all sanity checks that should be run in/just after on_ready event. + """ + # Ensure AppInfo is loaded. + if not self.cached_app_info: + log.debug("Getting application info.") + self.cached_app_info = await self.application_info() + + # Ensure folders exist + await self._on_ready_ensure_env() + + # TODO: Server permissions check + # TODO: pre-expand playlists in autoplaylist? + + # Ensure configs are valid / auto OwnerID is updated. + await self._on_ready_validate_configs() + + async def _on_ready_ensure_env(self) -> None: + """ + Startup check to make sure guild/server specific directories are + available in the data directory. + Additionally populate a text file to map guild ID to their names. + """ + log.debug("Ensuring data folders exist") + for guild in self.guilds: + pathlib.Path(f"data/{guild.id}/").mkdir(exist_ok=True) - # log what we're connecting to. - if vc_chlist: - log.info("Autojoining voice channels:") - for ch in vc_chlist: - log.info(" - %s/%s", ch.guild.name.strip(), ch.name.strip()) + with open("data/server_names.txt", "w", encoding="utf8") as f: + for guild in sorted(self.guilds, key=lambda s: int(s.id)): + f.write(f"{guild.id}: {guild.name}\n") - else: - log.info("Not autojoining any voice channels") + self.filecache.delete_old_audiocache(remove_dir=True) - else: - log.info("Not autojoining any voice channels") + async def _on_ready_validate_configs(self) -> None: + """ + Startup check to handle late validation of config and permissions. + """ + log.debug("Validating config") + await self.config.async_validate(self) - if self.config.show_config_at_start: - print(flush=True) - log.info("Options:") + log.debug("Validating permissions config") + await self.permissions.async_validate(self) - log.info(" Command prefix: %s", self.config.command_prefix) - log.info(" Default volume: %d%%", int(self.config.default_volume * 100)) - log.info( - " Skip threshold: %d votes or %.0f%%", - self.config.skips_required, - (self.config.skip_ratio_required * 100), - ) - log.info( - " Now Playing @mentions: %s", - ["Disabled", "Enabled"][self.config.now_playing_mentions], - ) - log.info( - " Auto-Summon: %s", ["Disabled", "Enabled"][self.config.auto_summon] - ) - log.info( - " Auto-Playlist: %s (order: %s)", - ["Disabled", "Enabled"][self.config.auto_playlist], - ["sequential", "random"][self.config.auto_playlist_random], - ) - log.info( - " Auto-Pause: %s", ["Disabled", "Enabled"][self.config.auto_pause] - ) - log.info( - " Delete Messages: %s", - ["Disabled", "Enabled"][self.config.delete_messages], - ) - if self.config.delete_messages: - log.info( - " Delete Invoking: %s", - ["Disabled", "Enabled"][self.config.delete_invoking], - ) - log.info( - " Delete Nowplaying: %s", - ["Disabled", "Enabled"][self.config.delete_nowplaying], - ) - log.info( - " Debug Mode: %s", ["Disabled", "Enabled"][self.config.debug_mode] - ) - log.info( - " Downloaded songs will be %s", - ["deleted", "saved"][self.config.save_videos], - ) - if self.config.save_videos and self.config.storage_limit_days: - log.info( - " Delete if unused for %d days", self.config.storage_limit_days - ) - if self.config.save_videos and self.config.storage_limit_bytes: - size = format_size_from_bytes(self.config.storage_limit_bytes) - log.info(" Delete if size exceeds %s", size) + def _on_ready_log_configs(self) -> None: + """ + Shows information about configs, including missing keys. + No validation is done in this method, only display/logs. + """ - if self.config.status_message: - log.info(" Status message: %s", self.config.status_message) - log.info( - " Write current songs to file: %s", - ["Disabled", "Enabled"][self.config.write_current_song], - ) - log.info( - " Author insta-skip: %s", - ["Disabled", "Enabled"][self.config.allow_author_skip], - ) - log.info(" Embeds: %s", ["Disabled", "Enabled"][self.config.embeds]) - log.info( - " Spotify integration: %s", - ["Disabled", "Enabled"][self.config.spotify_enabled], - ) - log.info( - " Legacy skip: %s", ["Disabled", "Enabled"][self.config.legacy_skip] - ) - log.info( - " Leave non owners: %s", - ["Disabled", "Enabled"][self.config.leavenonowners], - ) - log.info( - " Leave inactive VC: %s", - ["Disabled", "Enabled"][self.config.leave_inactive_channel], - ) - if self.config.leave_inactive_channel: - log.info( - " Timeout: %s seconds", - self.config.leave_inactive_channel_timeout, - ) - log.info( - " Leave at song end/empty queue: %s", - ["Disabled", "Enabled"][self.config.leave_after_queue_empty], - ) - log.info( - " Leave when player idles: %s", - "Disabled" if self.config.leave_player_inactive_for == 0 else "Enabled", - ) - if self.config.leave_player_inactive_for: - log.info( - " Timeout: %d seconds", self.config.leave_player_inactive_for - ) - log.info( - " Self Deafen: %s", ["Disabled", "Enabled"][self.config.self_deafen] - ) + print(flush=True) + log.info("Options:") + + log.info(" Command prefix: %s", self.config.command_prefix) + log.info(" Default volume: %d%%", int(self.config.default_volume * 100)) + log.info( + " Skip threshold: %d votes or %.0f%%", + self.config.skips_required, + (self.config.skip_ratio_required * 100), + ) + log.info( + " Now Playing @mentions: %s", + ["Disabled", "Enabled"][self.config.now_playing_mentions], + ) + log.info(" Auto-Summon: %s", ["Disabled", "Enabled"][self.config.auto_summon]) + log.info( + " Auto-Playlist: %s (order: %s)", + ["Disabled", "Enabled"][self.config.auto_playlist], + ["sequential", "random"][self.config.auto_playlist_random], + ) + log.info(" Auto-Pause: %s", ["Disabled", "Enabled"][self.config.auto_pause]) + log.info( + " Delete Messages: %s", + ["Disabled", "Enabled"][self.config.delete_messages], + ) + if self.config.delete_messages: log.info( - " Per-server command prefix: %s", - ["Disabled", "Enabled"][self.config.enable_options_per_guild], + " Delete Invoking: %s", + ["Disabled", "Enabled"][self.config.delete_invoking], ) log.info( - " Search List: %s", ["Disabled", "Enabled"][self.config.searchlist] + " Delete Nowplaying: %s", + ["Disabled", "Enabled"][self.config.delete_nowplaying], ) + log.info(" Debug Mode: %s", ["Disabled", "Enabled"][self.config.debug_mode]) + log.info( + " Downloaded songs will be %s", + ["deleted", "saved"][self.config.save_videos], + ) + if self.config.save_videos and self.config.storage_limit_days: + log.info(" Delete if unused for %d days", self.config.storage_limit_days) + if self.config.save_videos and self.config.storage_limit_bytes: + size = format_size_from_bytes(self.config.storage_limit_bytes) + log.info(" Delete if size exceeds %s", size) + + if self.config.status_message: + log.info(" Status message: %s", self.config.status_message) + log.info( + " Write current songs to file: %s", + ["Disabled", "Enabled"][self.config.write_current_song], + ) + log.info( + " Author insta-skip: %s", + ["Disabled", "Enabled"][self.config.allow_author_skip], + ) + log.info(" Embeds: %s", ["Disabled", "Enabled"][self.config.embeds]) + log.info( + " Spotify integration: %s", + ["Disabled", "Enabled"][self.config.spotify_enabled], + ) + log.info(" Legacy skip: %s", ["Disabled", "Enabled"][self.config.legacy_skip]) + log.info( + " Leave non owners: %s", + ["Disabled", "Enabled"][self.config.leavenonowners], + ) + log.info( + " Leave inactive VC: %s", + ["Disabled", "Enabled"][self.config.leave_inactive_channel], + ) + if self.config.leave_inactive_channel: log.info( - " Round Robin Queue: %s", - ["Disabled", "Enabled"][self.config.round_robin_queue], + " Timeout: %s seconds", + self.config.leave_inactive_channel_timeout, ) - + log.info( + " Leave at song end/empty queue: %s", + ["Disabled", "Enabled"][self.config.leave_after_queue_empty], + ) + log.info( + " Leave when player idles: %s", + "Disabled" if self.config.leave_player_inactive_for == 0 else "Enabled", + ) + if self.config.leave_player_inactive_for: + log.info(" Timeout: %d seconds", self.config.leave_player_inactive_for) + log.info(" Self Deafen: %s", ["Disabled", "Enabled"][self.config.self_deafen]) + log.info( + " Per-server command prefix: %s", + ["Disabled", "Enabled"][self.config.enable_options_per_guild], + ) + log.info(" Search List: %s", ["Disabled", "Enabled"][self.config.searchlist]) + log.info( + " Round Robin Queue: %s", + ["Disabled", "Enabled"][self.config.round_robin_queue], + ) print(flush=True) - await self.update_now_playing_status() - - # maybe option to leave the ownerid blank and generate a random command for the owner to use - # wait_for_message is pretty neato - - await self._join_startup_channels(self.autojoin_channels) - - # we do this after the config stuff because it's a lot easier to notice here - if self.config.missing_keys: - log.warning( - "Your config file is missing some options. If you have recently updated, " - "check the example_options.ini file to see if there are new options available to you. " - "The options missing are: %s", - self.config.missing_keys, - ) - print(flush=True) - - log.debug("Finish on_ready") - self.is_ready_done = True - def _gen_embed(self) -> discord.Embed: """Provides a basic template for embeds""" e = discord.Embed() @@ -2508,49 +2990,116 @@ async def _do_playlist_checks( ) return True - def _handle_guild_auto_pause(self, player: MusicPlayer) -> None: + async def _handle_guild_auto_pause(self, player: MusicPlayer, _lc: int = 0) -> None: """ Check the current voice client channel for members and determine if the player should be paused automatically. This is distinct from Guild availability pausing, which happens - when Discord has outages. + when Discord or the network has outages. """ if not self.config.auto_pause: + if player.paused_auto: + player.paused_auto = False return - if not player.voice_client: + if self.network_outage: + log.debug("Ignoring auto-pause due to network outage.") return - channel = player.voice_client.channel + if not player.voice_client or not player.voice_client.channel: + log.voicedebug( # type: ignore[attr-defined] + "MusicPlayer has no VoiceClient or has no channel data, cannot process auto-pause." + ) + if player.paused_auto: + player.paused_auto = False + return + channel = player.voice_client.channel guild = channel.guild - auto_paused = self.server_data[guild.id].auto_paused + + lock = self.aiolocks[f"auto_pause:{guild.id}"] + if lock.locked(): + log.debug("Already processing auto-pause, ignoring this event.") + return + + async with lock: + if not player.voice_client.is_connected(): + if self.loop: + naptime = 3 * (1 + _lc) + log.warning( + "%sVoiceClient not connected, waiting %s seconds to handle auto-pause in guild: %s", + "[Bug] " if _lc > 12 else "", + naptime, + player.voice_client.guild, + ) + try: + await asyncio.sleep(naptime) + except asyncio.CancelledError: + log.debug("Auto-pause waiting was cancelled.") + return + + _lc += 1 + f_player = self.get_player_in(player.voice_client.guild) + if player != f_player: + log.info( + "A new MusicPlayer is being connected, ignoring old auto-pause event." + ) + return + + if f_player is not None: + self.loop.create_task( + self._handle_guild_auto_pause(f_player, _lc=_lc) + ) + return is_empty = is_empty_voice_channel( channel, include_bots=self.config.bot_exception_ids ) - if is_empty and not auto_paused and player.is_playing: + if is_empty and player.is_playing: log.info( "Playing in an empty voice channel, running auto pause for guild: %s", guild, ) player.pause() - self.server_data[guild.id].auto_paused = True + player.paused_auto = True - elif not is_empty and auto_paused and player.is_paused: + elif not is_empty and player.paused_auto: log.info("Previously auto paused player is unpausing for guild: %s", guild) - player.resume() - self.server_data[guild.id].auto_paused = False + player.paused_auto = False + if player.is_paused: + player.resume() async def _do_cmd_unpause_check( - self, player: Optional[MusicPlayer], channel: MessageableChannel + self, + player: Optional[MusicPlayer], + channel: MessageableChannel, + author: discord.Member, + message: discord.Message, ) -> None: """ Checks for paused player and resumes it while sending a notice. This function should not be called from _cmd_play(). """ + if not player or not player.voice_client or not player.voice_client.channel: + return + + if not author.voice or not author.voice.channel: + return + + if player and player.voice_client and player.voice_client.channel: + pvc = player.voice_client.channel + avc = author.voice.channel + perms = self.permissions.for_user(author) + if pvc != avc and perms.summonplay: + await self.cmd_summon(author.guild, author, message) + return + + if pvc != avc and not perms.summonplay: + return + if player and player.is_paused: + player.resume() await self.safe_send_message( channel, self.str.get( @@ -2559,13 +3108,12 @@ async def _do_cmd_unpause_check( ), expire_in=30, ) - player.resume() async def cmd_play( self, message: discord.Message, _player: Optional[MusicPlayer], - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -2585,7 +3133,7 @@ async def cmd_play( it will use the metadata (e.g song name and artist) to find a YouTube equivalent of the song. Streaming from Spotify is not possible. """ - await self._do_cmd_unpause_check(_player, channel) + await self._do_cmd_unpause_check(_player, channel, author, message) return await self._cmd_play( message, @@ -2603,7 +3151,7 @@ async def cmd_shuffleplay( self, message: discord.Message, _player: Optional[MusicPlayer], - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -2616,7 +3164,7 @@ async def cmd_shuffleplay( Like play command but explicitly shuffles entries before adding them to the queue. """ - await self._do_cmd_unpause_check(_player, channel) + await self._do_cmd_unpause_check(_player, channel, author, message) await self._cmd_play( message, @@ -2642,7 +3190,7 @@ async def cmd_playnext( self, message: discord.Message, _player: Optional[MusicPlayer], - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -2662,7 +3210,7 @@ async def cmd_playnext( it will use the metadata (e.g song name and artist) to find a YouTube equivalent of the song. Streaming from Spotify is not possible. """ - await self._do_cmd_unpause_check(_player, channel) + await self._do_cmd_unpause_check(_player, channel, author, message) return await self._cmd_play( message, @@ -2680,7 +3228,7 @@ async def cmd_playnow( self, message: discord.Message, _player: Optional[MusicPlayer], - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -2700,7 +3248,7 @@ async def cmd_playnow( it will use the metadata (e.g song name and artist) to find a YouTube equivalent of the song. Streaming from Spotify is not possible. """ - await self._do_cmd_unpause_check(_player, channel) + await self._do_cmd_unpause_check(_player, channel, author, message) # attempt to queue the song, but used the front of the queue and skip current playback. return await self._cmd_play( @@ -2918,7 +3466,7 @@ async def _cmd_play_compound_link( self, message: discord.Message, player: MusicPlayer, - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -2996,7 +3544,7 @@ async def _cmd_play( self, message: discord.Message, _player: Optional[MusicPlayer], - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -3269,7 +3817,7 @@ async def _cmd_play( async def cmd_stream( self, _player: Optional[MusicPlayer], - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -3286,7 +3834,7 @@ async def cmd_stream( streams, especially on poor connections. You have been warned. """ - await self._do_cmd_unpause_check(_player, channel) + await self._do_cmd_unpause_check(_player, channel, author, message) if _player: player = _player @@ -3381,7 +3929,7 @@ async def cmd_search( self, message: discord.Message, player: MusicPlayer, - channel: MessageableChannel, + channel: GuildMessageableChannels, guild: discord.Guild, author: discord.Member, permissions: PermissionGroup, @@ -3741,7 +4289,7 @@ async def cmd_np( ) entry = player.current_entry - entry_author = player.current_entry.meta.get("author", None) + entry_author = player.current_entry.author if entry_author: np_text = self.str.get( @@ -3767,6 +4315,10 @@ async def cmd_np( url=entry.url, ) + # TODO: i18n + if entry.from_auto_playlist: + np_text += "\n`via autoplaylist`" + if self.config.embeds: content = self._gen_embed() content.title = action_text @@ -3822,39 +4374,10 @@ async def cmd_summon( ) ) - voice_client = self.voice_client_in(guild) - if voice_client and guild == author.voice.channel.guild: - await voice_client.move_to(author.voice.channel) + player = self.get_player_in(guild) + if player and player.voice_client and guild == author.voice.channel.guild: + await player.voice_client.move_to(author.voice.channel) else: - # move to _verify_vc_perms? - chperms = author.voice.channel.permissions_for(guild.me) - - if not chperms.connect: - log.warning( - "Cannot join channel '%s', no permission.", - author.voice.channel.name, - ) - raise exceptions.CommandError( - self.str.get( - "cmd-summon-noperms-connect", - "Cannot join channel `{0}`, no permission to connect.", - ).format(author.voice.channel.name), - expire_in=25, - ) - - if not chperms.speak: - log.warning( - "Cannot join channel '%s', no permission to speak.", - author.voice.channel.name, - ) - raise exceptions.CommandError( - self.str.get( - "cmd-summon-noperms-speak", - "Cannot join channel `{0}`, no permission to speak.", - ).format(author.voice.channel.name), - expire_in=25, - ) - player = await self.get_player( author.voice.channel, create=True, @@ -3864,9 +4387,6 @@ async def cmd_summon( if player.is_stopped: player.play() - if self.config.auto_playlist: - await self.on_player_finished_playing(player) - log.info( "Joining %s/%s", author.voice.channel.guild.name, @@ -4011,9 +4531,7 @@ async def cmd_remove( if permissions.remove or author == user: try: entry_indexes = [ - e - for e in player.playlist.entries - if e.meta.get("author", None) == user + e for e in player.playlist.entries if e.author == user ] for entry in entry_indexes: player.playlist.entries.remove(entry) @@ -4069,16 +4587,17 @@ async def cmd_remove( expire_in=20, ) - if permissions.remove or author == player.playlist.get_entry_at_index( - idx - 1 - ).meta.get("author", None): + if ( + permissions.remove + or author == player.playlist.get_entry_at_index(idx - 1).author + ): entry = player.playlist.delete_entry_at_index((idx - 1)) - if entry.meta.get("channel", False) and entry.meta.get("author", False): + if entry.channel and entry.author: return Response( self.str.get( "cmd-remove-reply-author", "Removed entry `{0}` added by `{1}`" ) - .format(entry.title, entry.meta["author"].name) + .format(entry.title, entry.author.name) .strip() ) @@ -4146,7 +4665,7 @@ async def cmd_skip( ) current_entry = player.current_entry - entry_author = current_entry.meta.get("author", None) + entry_author = current_entry.author entry_author_id = 0 if entry_author: entry_author_id = entry_author.id @@ -4586,8 +5105,8 @@ async def cmd_queue( prog_str = f"`[{song_progress}/{song_total}]`" # TODO: Honestly the meta info could use a typed interface too. - cur_entry_channel = player.current_entry.meta.get("channel", None) - cur_entry_author = player.current_entry.meta.get("author", None) + cur_entry_channel = player.current_entry.channel + cur_entry_author = player.current_entry.author if cur_entry_channel and cur_entry_author: current_progress = self.str.get( "cmd-queue-playing-author", @@ -4603,6 +5122,8 @@ async def cmd_queue( "cmd-queue-playing-noauthor", "Currently playing: `{0}`\nProgress: {1}\n", ).format(player.current_entry.title, prog_str) + # TODO: i18n + current_progress += "`via autoplaylist`\n" # calculate start and stop slice indices start_index = limit_per_page * page_number @@ -4625,12 +5146,10 @@ async def cmd_queue( log.debug("Skipped the current playlist entry.") continue - item_channel = item.meta.get("channel", None) - item_author = item.meta.get("author", None) - if item_channel and item_author: + if item.channel and item.author: embed.add_field( name=f"Entry #{idx}", - value=f"Title: `{item.title}`\nAdded by: `{item_author.name}`", + value=f"Title: `{item.title}`\nAdded by: `{item.author.name}`", inline=False, ) else: @@ -5147,6 +5666,22 @@ async def cmd_disconnect(self, guild: discord.Guild) -> CommandResponse: delete_after=20, ) + # check for a raw voice client instead. + for vc in self.voice_clients: + if not hasattr(vc.channel, "guild"): + log.warning( + "MusicBot found a %s with no guild! This could be a problem.", + type(vc), + ) + continue + + if vc.channel.guild and vc.channel.guild == guild: + await self.disconnect_voice_client(guild) + return Response( + "Disconnected a playerless voice client? [BUG]", + delete_after=30, + ) + raise exceptions.CommandError( self.str.get( "cmd-disconnect-no-voice", "Not currently connected to `{0.name}`" @@ -5333,7 +5868,10 @@ async def cmd_breakpoint(self) -> CommandResponse: @dev_only async def cmd_objgraph( - self, channel: MessageableChannel, func: str = "most_common_types()" + self, + message: discord.Message, # pylint: disable=unused-argument + channel: MessageableChannel, + func: str = "most_common_types()", ) -> CommandResponse: """ Interact with objgraph to make it spill the beans. @@ -5955,6 +6493,21 @@ async def on_inactivity_timeout_expired( ) await self.disconnect_voice_client(guild) + async def on_connect(self) -> None: + """Event called by discord.py when the Client has connected to the API.""" + if self.init_ok: + log.info("MusicBot has become connected.") + + async def on_disconnect(self) -> None: + """Event called by discord.py any time bot is disconnected, or fails to connect.""" + log.info("MusicBot has become disconnected.") + + async def on_socket_event_type(self, event_type: str) -> None: + """Event called by discord.py on any socket event.""" + log.everything( # type: ignore[attr-defined] + "Got a Socket Event: %s", event_type + ) + async def on_voice_state_update( self, member: discord.Member, @@ -5966,13 +6519,12 @@ async def on_voice_state_update( https://discordpy.readthedocs.io/en/stable/api.html#discord.on_voice_state_update """ if not self.init_ok: - log.warning("before init_ok") # TODO: remove after coverage testing + if self.config.debug_mode: + log.warning( + "VoiceState updated before on_ready finished" + ) # TODO: remove after coverage testing return # Ignore stuff before ready - if not self.is_ready(): - # TODO: remove after coverage testing - log.warning("before is_ready") - if self.config.leave_inactive_channel: guild = member.guild event = self.server_data[guild.id].get_event("inactive_vc_timer") @@ -6023,20 +6575,108 @@ async def on_voice_state_update( ) event.set() - if ( - member == self.user and not after.channel and before.channel - ): # if bot was disconnected from channel - await self.disconnect_voice_client(before.channel.guild) - return + # Voice stat updates for bot itself. + if member == self.user: + # check if bot was disconnected from a voice channel + if not after.channel and before.channel and not self.network_outage: + if await self._handle_api_disconnect(before): + return if before.channel: player = self.get_player_in(before.channel.guild) if player: - self._handle_guild_auto_pause(player) + await self._handle_guild_auto_pause(player) if after.channel: player = self.get_player_in(after.channel.guild) if player: - self._handle_guild_auto_pause(player) + await self._handle_guild_auto_pause(player) + + async def _handle_api_disconnect(self, before: discord.VoiceState) -> bool: + """ + Method called from on_voice_state_update when MusicBot is disconnected from voice. + """ + if not before.channel: + log.debug("VoiceState disconnect before.channel is None.") + return False + + o_guild = self.get_guild(before.channel.guild.id) + # These conditions are usually met when a user disconnects bot via menus. + if ( + o_guild is not None + and o_guild.id in self.players + and isinstance(o_guild.voice_client, discord.VoiceClient) + and not o_guild.voice_client.is_connected() + ): + log.info( + "MusicBot was disconnected from the voice channel, likely by a user." + ) + await self.disconnect_voice_client(o_guild) + return True + + # These conditions are met when API terminates a voice client. + if ( + o_guild is not None + and o_guild.id in self.players + and o_guild.voice_client is None + ): + log.info( + "MusicBot was disconnected from the voice channel, likely by Discord API." + ) + await self.disconnect_voice_client(o_guild) + + # reconnect if the guild is configured to auto-join. + bcgid = before.channel.guild.id + if any(bcgid == ch.guild.id for ch in self.autojoinable_channels): + # Look for the last channel we were in. + target_channel = self.get_channel(before.channel.id) + if not target_channel: + # fall back to the configured channel. + target_channel = discord.utils.find( + lambda c: c.guild.id == bcgid, + self.autojoinable_channels, + ) + + if not isinstance( + target_channel, (discord.VoiceChannel, discord.StageChannel) + ): + log.error( + "Cannot use auto-join channel with type: %s in guild: %s", + type(target_channel), + before.channel.guild, + ) + return True + + if not target_channel: + log.error( + "Cannot find the auto-joined channel, was it deleted? Guild: %s", + before.channel.guild, + ) + return True + + log.info( + "Reconnecting to auto-joined guild on channel: %s", + target_channel, + ) + try: + r_player = await self.get_player( + target_channel, create=True, deserialize=True + ) + + if r_player.is_stopped: + r_player.play() + + except (TypeError, exceptions.PermissionsError): + log.warning( + "Cannot auto join channel: %s", + before.channel, + exc_info=True, + ) + return True + + # TODO: If bot has left a server but still had a client, we should kill it. + # if o_guild is None and before.channel.guild.id in self.players: + + return False async def on_guild_join(self, guild: discord.Guild) -> None: """ @@ -6048,7 +6688,7 @@ async def on_guild_join(self, guild: discord.Guild) -> None: # Leave guilds if the owner is not a member and configured to do so. if self.config.leavenonowners: # Get the owner so we can notify them of the leave via DM. - owner = self._get_owner(voice=True) or self._get_owner() + owner = self._get_owner_member() if owner: # check for the owner in the guild. check = guild.get_member(owner.id) @@ -6089,30 +6729,37 @@ async def on_guild_available(self, guild: discord.Guild) -> None: if not self.init_ok: return # Ignore pre-ready events - log.debug('Guild "%s" has become available.', guild.name) + log.info('Guild "%s" has become available.', guild.name) player = self.get_player_in(guild) - if player and player.is_paused: - av_paused = self.server_data[guild.id].availability_paused + """ + if player and player.voice_client and not player.voice_client.is_connected(): + # TODO: really test this, I hope and pray I need not bother here... + log.warning("MusicBot has a MusicPlayer with no VoiceClient!") + return + #""" - if av_paused: - log.debug( - 'Resuming player in "%s" due to availability.', - guild.name, - ) - self.server_data[guild.id].availability_paused = False - player.resume() + if player and player.is_paused and player.guild_or_net_unavailable: + log.debug( + 'Resuming player in "%s" due to availability.', + guild.name, + ) + player.guild_or_net_unavailable = False + player.resume() + + if player: + player.guild_or_net_unavailable = False async def on_guild_unavailable(self, guild: discord.Guild) -> None: """ - Event called by discord.py when a guild becomes unavailable. + Event called by discord.py when Discord API says a guild is unavailable. https://discordpy.readthedocs.io/en/stable/api.html#discord.on_guild_unavailable """ if not self.init_ok: return # Ignore pre-ready events. - log.debug('Guild "%s" has become unavailable.', guild.name) + log.info('Guild "%s" has become unavailable.', guild.name) player = self.get_player_in(guild) @@ -6121,9 +6768,11 @@ async def on_guild_unavailable(self, guild: discord.Guild) -> None: 'Pausing player in "%s" due to unavailability.', guild.name, ) - self.server_data[guild.id].availability_paused = True player.pause() + if player: + player.guild_or_net_unavailable = True + async def on_guild_update( self, before: discord.Guild, after: discord.Guild ) -> None: @@ -6175,12 +6824,3 @@ async def on_guild_channel_update( log.everything( # type: ignore[attr-defined] f"Channel attribute {name} is now: {a_val} -- Was: {b_val}" ) - - def voice_client_in(self, guild: discord.Guild) -> Optional[discord.VoiceClient]: - """ - Check for and return discord.VoiceClient object if one exists for the given `guild`. - """ - for vc in self.voice_clients: - if isinstance(vc, discord.VoiceClient) and vc.guild == guild: - return vc - return None diff --git a/musicbot/config.py b/musicbot/config.py index 10363648e..8c9b234d0 100644 --- a/musicbot/config.py +++ b/musicbot/config.py @@ -30,23 +30,6 @@ log = logging.getLogger(__name__) -def get_all_keys( - conf: Union["ExtendedConfigParser", configparser.ConfigParser] -) -> List[str]: - """ - Gather all config keys for all sections of a ConfigParser into a list. - This -will- return duplicate keys if they happen to exist in config. - - :param: conf: A loaded config parser object. - """ - sects = dict(conf.items()) - keys = [] - for k in sects: - s = sects[k] - keys += list(s.keys()) - return keys - - def create_file_ifnoexist( path: pathlib.Path, content: Optional[Union[str, List[str]]] ) -> None: @@ -78,7 +61,7 @@ def __init__(self, config_file: pathlib.Path) -> None: self.config_file = config_file self.find_config() - config = ExtendedConfigParser(interpolation=None) + config = ExtendedConfigParser() config.read(config_file, encoding="utf-8") confsections = { @@ -351,11 +334,14 @@ def check_changes(self, conf: "ExtendedConfigParser") -> None: """ exfile = pathlib.Path(EXAMPLE_OPTIONS_FILE) if exfile.is_file(): - usr_keys = get_all_keys(conf) - exconf = configparser.ConfigParser(interpolation=None) + usr_keys = conf.fetch_all_keys() + exconf = ExtendedConfigParser() if not exconf.read(exfile, encoding="utf-8"): + log.error( + "Cannot detect changes in config, example options file is missing." + ) return - ex_keys = get_all_keys(exconf) + ex_keys = exconf.fetch_all_keys() if set(usr_keys) != set(ex_keys): self.missing_keys = set(ex_keys) - set( usr_keys @@ -689,6 +675,28 @@ class ExtendedConfigParser(configparser.ConfigParser): for issues detected with the values. """ + def __init__(self) -> None: + super().__init__(interpolation=None) + + def optionxform(self, optionstr: str) -> str: + """ + This is an override for ConfigParser key parsing. + by default ConfigParser uses str.lower() we just return to keep the case. + """ + return optionstr + + def fetch_all_keys(self) -> List[str]: + """ + Gather all config keys for all sections of this config into a list. + This -will- return duplicate keys if they happen to exist in config. + """ + sects = dict(self.items()) + keys = [] + for k in sects: + s = sects[k] + keys += list(s.keys()) + return keys + def getownerid( self, section: str, diff --git a/musicbot/constants.py b/musicbot/constants.py index c777b406f..9f039f059 100644 --- a/musicbot/constants.py +++ b/musicbot/constants.py @@ -47,8 +47,23 @@ # VOICEDEBUG, FFMPEG, NOISY, or EVERYTHING DEFAULT_LOG_LEVEL: str = "INFO" +# Default target FQDN or IP to ping with network tester. +DEFAULT_PING_TARGET: str = "discord.com" +# Max time in seconds that ping should wait for response. +DEFAULT_PING_TIMEOUT: int = 2 +# Time in seconds to wait between pings. +DEFAULT_PING_SLEEP: float = 0.8 + +# Minimum number of seconds to wait for a VoiceClient to connect. +VOICE_CLIENT_RECONNECT_TIMEOUT: int = 5 +# Maximum number of retry attempts to make for VoiceClient connection. +# Each retry increases the timeout by multiplying attempts by the above timeout. +VOICE_CLIENT_MAX_RETRY_CONNECT: int = 5 + +# Maximum number of threads MusicBot will use for downloading and extracting info. DEFAULT_MAX_INFO_DL_THREADS: int = 2 +# Maximum number of seconds to wait for HEAD request on media files. DEFAULT_MAX_INFO_REQUEST_TIMEOUT: int = 10 # Discord and other API constants diff --git a/musicbot/constructs.py b/musicbot/constructs.py index d672e3628..e1307ec27 100644 --- a/musicbot/constructs.py +++ b/musicbot/constructs.py @@ -80,8 +80,7 @@ def __init__(self, bot: "MusicBot") -> None: # Members below are available for public use. self.last_np_msg: Optional["discord.Message"] = None - self.availability_paused: bool = False - self.auto_paused: bool = False + self.last_played_song_subject: str = "" # create a task to load any persistent guild options. # in theory, this should work out fine. diff --git a/musicbot/downloader.py b/musicbot/downloader.py index e81361d10..930bd1037 100644 --- a/musicbot/downloader.py +++ b/musicbot/downloader.py @@ -20,7 +20,7 @@ from yt_dlp.utils import UnsupportedError from .constants import DEFAULT_MAX_INFO_DL_THREADS, DEFAULT_MAX_INFO_REQUEST_TIMEOUT -from .exceptions import ExtractionError +from .exceptions import ExtractionError, MusicbotException from .spotify import Spotify if TYPE_CHECKING: @@ -239,6 +239,9 @@ async def extract_info( :returns: YtdlpResponseDict object containing sanitized extraction data. + :raises: musicbot.exceptions.MusicbotError + if event loop is closed and cannot be used for extraction. + :raises: musicbot.exceptions.ExtractionError for errors in MusicBot's internal filtering and pre-processing of extraction queries. @@ -284,7 +287,9 @@ async def extract_info( data["__header_data"] = headers or None data["__expected_filename"] = self.ytdl.prepare_filename(data) - # log data only for debug and higher verbosity levels. + """ + # disabled since it is only needed for working on extractions. + # logs data only for debug and higher verbosity levels. self._sanitize_and_log( data, # these fields are here because they are often very lengthy. @@ -292,6 +297,7 @@ async def extract_info( # as needed, but maybe not commit these changes redact_fields=["automatic_captions", "formats", "heatmap"], ) + """ return YtdlpResponseDict(data) async def _filtered_extract_info( @@ -308,6 +314,9 @@ async def _filtered_extract_info( :returns: Dictionary of data returned from extract_info() or other integration. Serialization ready. + :raises: musicbot.exceptions.MusicbotError + if event loop is closed and cannot be used for extraction. + :raises: musicbot.exceptions.ExtractionError for errors in MusicBot's internal filtering and pre-processing of extraction queries. @@ -323,6 +332,13 @@ async def _filtered_extract_info( log.noise(f"Called extract_info with: '{song_subject}', {args}, {kwargs}") # type: ignore[attr-defined] as_stream_url = kwargs.pop("as_stream", False) + # check if loop is closed and exit. + if (self.bot.loop and self.bot.loop.is_closed()) or not self.bot.loop: + log.warning( + "Cannot run extraction, loop is closed. (This is normal on shutdowns.)" + ) + raise MusicbotException("Cannot continue extraction, event loop is closed.") + # handle extracting spotify links before ytdl get a hold of them. if ( "open.spotify.com" in song_subject.lower() diff --git a/musicbot/entry.py b/musicbot/entry.py index 4e026bb64..8f96c1a76 100644 --- a/musicbot/entry.py +++ b/musicbot/entry.py @@ -4,14 +4,17 @@ import os import re import shutil -from typing import TYPE_CHECKING, Any, Callable, Dict, List, Optional +from typing import TYPE_CHECKING, Any, Callable, Dict, List, Optional, Union -from discord.abc import GuildChannel -from yt_dlp.utils import ContentTooShortError # type: ignore[import-untyped] +import discord +from yt_dlp.utils import ( # type: ignore[import-untyped] + ContentTooShortError, + YoutubeDLError, +) from .constructs import Serializable from .downloader import YtdlpResponseDict -from .exceptions import ExtractionError, InvalidDataError +from .exceptions import ExtractionError, InvalidDataError, MusicbotException from .spotify import Spotify if TYPE_CHECKING: @@ -24,6 +27,12 @@ else: AsyncFuture = asyncio.Future +GuildMessageableChannels = Union[ + discord.Thread, + discord.TextChannel, + discord.VoiceChannel, + discord.StageChannel, +] log = logging.getLogger(__name__) @@ -44,7 +53,6 @@ def __init__(self) -> None: self.filename: str = "" self.downloaded_bytes: int = 0 self.cache_busted: bool = False - self.from_auto_playlist: bool = False self._is_downloading: bool = False self._is_downloaded: bool = False self._waiting_futures: List[AsyncFuture] = [] @@ -166,14 +174,14 @@ async def run_command(command: List[str]) -> bytes: class URLPlaylistEntry(BasePlaylistEntry): - SERIAL_VERSION: int = 2 # version for serial data checks. + SERIAL_VERSION: int = 3 # version for serial data checks. def __init__( self, playlist: "Playlist", info: YtdlpResponseDict, - from_apl: bool = False, - **meta: Dict[str, Any], + author: Optional["discord.Member"] = None, + channel: Optional[GuildMessageableChannels] = None, ) -> None: """ Create URL Playlist entry that will be downloaded for playback. @@ -190,7 +198,6 @@ def __init__( self.filecache: "AudioFileCache" = playlist.bot.filecache self.info: YtdlpResponseDict = info - self.from_auto_playlist = from_apl if self.duration is None: log.info( @@ -200,9 +207,18 @@ def __init__( self.title, ) - self.meta: Dict[str, Any] = meta + self.author: Optional["discord.Member"] = author + self.channel: Optional[GuildMessageableChannels] = channel + self.aoptions: str = "-vn" + @property + def from_auto_playlist(self) -> bool: + """Returns true if the entry has an author or a channel.""" + if self.author is not None or self.channel is not None: + return False + return True + @property def url(self) -> str: """Gets a playable URL from this entries info.""" @@ -254,15 +270,8 @@ def __json__(self) -> Dict[str, Any]: "info": self.info.data, "downloaded": self.is_downloaded, "filename": self.filename, - "meta": { - name: { - "type": obj.__class__.__name__, - "id": obj.id, - "name": obj.name, - } - for name, obj in self.meta.items() - if obj - }, + "author_id": self.author.id if self.author else None, + "channel_id": self.channel.id if self.channel else None, "aoptions": self.aoptions, } ) @@ -296,35 +305,63 @@ def _deserialize( raw_json["downloaded"] if playlist.bot.config.save_videos else False ) filename = raw_json["filename"] if downloaded else None - meta: Dict[str, Any] = {} - # TODO: Better [name] fallbacks - if "channel" in raw_json["meta"]: - # int() it because persistent queue from pre-rewrite days saved ids as strings - meta["channel"] = playlist.bot.get_channel( - int(raw_json["meta"]["channel"]["id"]) - ) - if not meta["channel"]: + channel_id = raw_json.get("channel_id", None) + if channel_id: + o_channel = playlist.bot.get_channel(int(channel_id)) + + if not o_channel: log.warning( - "Deserialized URLPlaylistEntry Cannot find channel with id: %s", - raw_json["meta"]["channel"]["id"], + "Deserialized URLPlaylistEntry cannot find channel with id: %s", + raw_json["channel_id"], ) - meta.pop("channel") - elif "author" in raw_json["meta"] and isinstance( - meta["channel"], GuildChannel + + if isinstance( + o_channel, + ( + discord.Thread, + discord.TextChannel, + discord.VoiceChannel, + discord.StageChannel, + ), ): - # int() it because persistent queue from pre-rewrite days saved ids as strings - meta["author"] = meta["channel"].guild.get_member( - int(raw_json["meta"]["author"]["id"]) + channel = o_channel + else: + log.warning( + "Deserialized URLPlaylistEntry has the wrong channel type: %s", + type(o_channel), ) - if not meta["author"]: + channel = None + else: + channel = None + + author_id = raw_json.get("author_id", None) + if author_id: + if isinstance( + channel, + ( + discord.Thread, + discord.TextChannel, + discord.VoiceChannel, + discord.StageChannel, + ), + ): + author = channel.guild.get_member(int(author_id)) + + if not author: log.warning( - "Deserialized URLPlaylistEntry Cannot find author with id: %s", - raw_json["meta"]["author"]["id"], + "Deserialized URLPlaylistEntry cannot find author with id: %s", + raw_json["author_id"], ) - meta.pop("author") + else: + author = None + log.warning( + "Deserialized URLPlaylistEntry has an author ID but no channel for lookup!", + ) + else: + author = None - entry = cls(playlist, info, **meta) + entry = cls(playlist, info, author=author, channel=channel) entry.filename = filename return entry @@ -604,9 +641,14 @@ async def _really_download(self) -> None: log.error("Download failed, not retrying! Reason: %s", str(e)) self.cache_busted = True raise ExtractionError(str(e)) from e - except Exception as e: + except YoutubeDLError as e: + # as a base exception for any exceptions raised by yt_dlp. raise ExtractionError(str(e)) from e + except Exception as e: + log.exception("Extraction encountered an unhandled exception.") + raise MusicbotException(str(e)) from e + log.info("Download complete: %s", self.url) if info is None: @@ -623,14 +665,14 @@ async def _really_download(self) -> None: class StreamPlaylistEntry(BasePlaylistEntry): - SERIAL_VERSION = 2 + SERIAL_VERSION = 3 def __init__( self, playlist: "Playlist", info: YtdlpResponseDict, - from_apl: bool = False, - **meta: Dict[str, Any], + author: Optional["discord.Member"] = None, + channel: Optional[GuildMessageableChannels] = None, ) -> None: """ Create Stream Playlist entry that will be sent directly to ffmpeg for playback. @@ -644,11 +686,19 @@ def __init__( self.playlist: "Playlist" = playlist self.info: YtdlpResponseDict = info - self.from_auto_playlist = from_apl - self.meta: Dict[str, Any] = meta + + self.author: Optional["discord.Member"] = author + self.channel: Optional[GuildMessageableChannels] = channel self.filename: str = self.url + @property + def from_auto_playlist(self) -> bool: + """Returns true if the entry has an author or a channel.""" + if self.author is not None or self.channel is not None: + return False + return True + @property def url(self) -> str: """get extracted url if available or otherwise return the input subject""" @@ -699,15 +749,8 @@ def __json__(self) -> Dict[str, Any]: "version": StreamPlaylistEntry.SERIAL_VERSION, "info": self.info.data, "filename": self.filename, - "meta": { - name: { - "type": obj.__class__.__name__, - "id": obj.id, - "name": obj.name, - } - for name, obj in self.meta.items() - if obj - }, + "author_id": self.author.id if self.author else None, + "channel_id": self.channel.id if self.channel else None, } ) @@ -731,35 +774,63 @@ def _deserialize( try: info = YtdlpResponseDict(raw_json["info"]) filename = raw_json["filename"] - meta: Dict[str, Any] = {} - # TODO: Better [name] fallbacks - if "channel" in raw_json["meta"]: - # int() it because persistent queue from pre-rewrite days saved ids as strings - meta["channel"] = playlist.bot.get_channel( - int(raw_json["meta"]["channel"]["id"]) - ) - if not meta["channel"]: + channel_id = raw_json.get("channel_id", None) + if channel_id: + o_channel = playlist.bot.get_channel(int(channel_id)) + + if not o_channel: log.warning( - "Deserialized StreamPlaylistEntry Cannot find channel with id: %s", - raw_json["meta"]["channel"]["id"], + "Deserialized StreamPlaylistEntry cannot find channel with id: %s", + raw_json["channel_id"], ) - meta.pop("channel") - elif "author" in raw_json["meta"] and isinstance( - meta["channel"], GuildChannel + + if isinstance( + o_channel, + ( + discord.Thread, + discord.TextChannel, + discord.VoiceChannel, + discord.StageChannel, + ), ): - # int() it because persistent queue from pre-rewrite days saved ids as strings - meta["author"] = meta["channel"].guild.get_member( - int(raw_json["meta"]["author"]["id"]) + channel = o_channel + else: + log.warning( + "Deserialized StreamPlaylistEntry has the wrong channel type: %s", + type(o_channel), ) - if not meta["author"]: + channel = None + else: + channel = None + + author_id = raw_json.get("author_id", None) + if author_id: + if isinstance( + channel, + ( + discord.Thread, + discord.TextChannel, + discord.VoiceChannel, + discord.StageChannel, + ), + ): + author = channel.guild.get_member(int(author_id)) + + if not author: log.warning( - "Deserialized StreamPlaylistEntry Cannot find author with id: %s", - raw_json["meta"]["author"]["id"], + "Deserialized StreamPlaylistEntry cannot find author with id: %s", + raw_json["author_id"], ) - meta.pop("author") + else: + author = None + log.warning( + "Deserialized StreamPlaylistEntry has an author ID but no channel for lookup!", + ) + else: + author = None - entry = cls(playlist, info, **meta) + entry = cls(playlist, info, author=author, channel=channel) entry.filename = filename return entry except (ValueError, KeyError, TypeError) as e: diff --git a/musicbot/exceptions.py b/musicbot/exceptions.py index 6122306b3..55f6f13bf 100644 --- a/musicbot/exceptions.py +++ b/musicbot/exceptions.py @@ -56,7 +56,7 @@ class FFmpegWarning(MusicbotException): # Some issue retrieving something from Spotify's API or processing it. -class SpotifyError(MusicbotException): +class SpotifyError(ExtractionError): pass @@ -124,7 +124,9 @@ def _pretty_wrap(text: str, pretext: str, *, width: int = -1) -> str: pretext = pretext.rstrip() + "\n" width = shutil.get_terminal_size().columns - lines = textwrap.wrap(text, width=width - 5) + lines = [] + for line in text.split("\n"): + lines += textwrap.wrap(line, width=width - 5) lines = [ (" " + line).rstrip().ljust(width - 1).rstrip() + "\n" for line in lines ] diff --git a/musicbot/permissions.py b/musicbot/permissions.py index da9971946..0cf675b81 100644 --- a/musicbot/permissions.py +++ b/musicbot/permissions.py @@ -91,7 +91,7 @@ def __init__(self, perms_file: pathlib.Path, grant_all: List[int]) -> None: :param: grant_all: a list of discord User IDs to grant permissive defaults. """ self.perms_file = perms_file - self.config = ExtendedConfigParser(interpolation=None) + self.config = ExtendedConfigParser() if not self.config.read(self.perms_file, encoding="utf-8"): example_file = PermissionsDefaults.example_perms_file diff --git a/musicbot/player.py b/musicbot/player.py index e178a2017..c65a51364 100644 --- a/musicbot/player.py +++ b/musicbot/player.py @@ -66,6 +66,9 @@ def get_progress(self) -> float: return self.progress * 0.02 def cleanup(self) -> None: + log.noise( # type: ignore[attr-defined] + "Cleanup got called on the audio source: %s", repr(self) + ) self._source.cleanup() @@ -94,6 +97,8 @@ def __init__( self.state: MusicPlayerState = MusicPlayerState.STOPPED self.skip_state: SkipState = SkipState() self.karaoke_mode: bool = False + self.guild_or_net_unavailable: bool = False + self.paused_auto: bool = False self._volume = bot.config.default_volume self._play_lock = asyncio.Lock() @@ -147,6 +152,9 @@ def on_entry_failed(self, entry: EntryTypes, error: Exception) -> None: def skip(self) -> None: """Skip the current playing entry but just killing playback.""" + log.noise( # type: ignore[attr-defined] + "MusicPlayer.skip() is called: %s", repr(self) + ) self._kill_current_player() def stop(self) -> None: @@ -154,6 +162,9 @@ def stop(self) -> None: Immediately halt playback, killing current player source, setting state to stopped and emitting an event. """ + log.noise( # type: ignore[attr-defined] + "MusicPlayer.stop() is called: %s", repr(self) + ) self.state = MusicPlayerState.STOPPED self._kill_current_player() @@ -166,6 +177,13 @@ def resume(self) -> None: If MusicPlayer was paused but the VoiceClient player is missing, do something odd and set state to playing but kill the player... """ + if self.guild_or_net_unavailable: + log.warning("Guild or network unavailable, cannot resume playback.") + return + + log.noise( # type: ignore[attr-defined] + "MusicPlayer.resume() is called: %s", repr(self) + ) if self.is_paused and self._current_player: self._current_player.resume() self.state = MusicPlayerState.PLAYING @@ -183,6 +201,9 @@ def pause(self) -> None: """ Suspend player audio playback and emit an event, if the player was playing. """ + log.noise( # type: ignore[attr-defined] + "MusicPlayer.pause() is called: %s", repr(self) + ) if self.is_playing: self.state = MusicPlayerState.PAUSED @@ -202,6 +223,9 @@ def kill(self) -> None: Set the state of the bot to Dead, clear all events and playlists, then kill the current VoiceClient source player. """ + log.noise( # type: ignore[attr-defined] + "MusicPlayer.kill() is called: %s", repr(self) + ) self.state = MusicPlayerState.DEAD self.playlist.clear() self._events.clear() @@ -286,18 +310,31 @@ def play(self, _continue: bool = False) -> None: :param: _continue: Force a player that is not dead or stopped to start a new playback source anyway. """ + log.noise( # type: ignore[attr-defined] + "MusicPlayer.play() is called: %s", repr(self) + ) self.loop.create_task(self._play(_continue=_continue)) async def _play(self, _continue: bool = False) -> None: """ Plays the next entry from the playlist, or resumes playback of the current entry if paused. """ - if self.is_paused and self._current_player: - return self.resume() - if self.is_dead: + log.voicedebug( # type: ignore[attr-defined] + "MusicPlayer is dead, cannot play." + ) + return + + if self.guild_or_net_unavailable: + log.warning("Guild or network unavailable, cannot start playback.") return + if self.is_paused and self._current_player: + log.voicedebug( # type: ignore[attr-defined] + "MusicPlayer was previously paused, resuming current player." + ) + return self.resume() + async with self._play_lock: if self.is_stopped or _continue: try: @@ -342,8 +379,8 @@ async def _play(self, _continue: bool = False) -> None: self.volume, ) ) - log.debug( - "Playing %s using %s", repr(self._source), repr(self.voice_client) + log.voicedebug( # type: ignore[attr-defined] + "Playing %r using %r", self._source, self.voice_client ) self.voice_client.play(self._source, after=self._playback_finished) diff --git a/musicbot/playlist.py b/musicbot/playlist.py index a7f236c5e..755127a34 100644 --- a/musicbot/playlist.py +++ b/musicbot/playlist.py @@ -15,6 +15,8 @@ Union, ) +import discord + from .constructs import Serializable from .entry import StreamPlaylistEntry, URLPlaylistEntry from .exceptions import ExtractionError, InvalidDataError, WrongEntryTypeError @@ -23,8 +25,6 @@ if TYPE_CHECKING: import asyncio - import discord - from .bot import MusicBot from .downloader import YtdlpResponseDict from .player import MusicPlayer @@ -32,12 +32,19 @@ # type aliases EntryTypes = Union[URLPlaylistEntry, StreamPlaylistEntry] +GuildMessageableChannels = Union[ + discord.VoiceChannel, + discord.StageChannel, + discord.Thread, + discord.TextChannel, +] + log = logging.getLogger(__name__) class Playlist(EventEmitter, Serializable): """ - A playlist that manages the list of songs that will be played. + A playlist that manages the queue of songs that will be played. """ def __init__(self, bot: "MusicBot") -> None: @@ -91,10 +98,10 @@ async def add_stream_from_info( self, info: "YtdlpResponseDict", *, + author: Optional["discord.Member"] = None, + channel: Optional[GuildMessageableChannels] = None, head: bool = False, defer_serialize: bool = False, - is_autoplaylist: bool = False, - **meta: Any, ) -> Tuple[StreamPlaylistEntry, int]: """ Use the given `info` to create a StreamPlaylistEntry and add it @@ -106,7 +113,6 @@ async def add_stream_from_info( :param: head: Toggle adding to the front of the queue. :param: defer_serialize: Signal to defer serialization steps. Useful if many entries are added at once - :param: meta: Any additional info to add to the entry. :returns: A tuple with the entry object, and its position in the queue. """ @@ -117,8 +123,8 @@ async def add_stream_from_info( entry = StreamPlaylistEntry( self, info, - from_apl=is_autoplaylist, - **meta, + author=author, + channel=channel, ) self._add_entry(entry, head=head, defer_serialize=defer_serialize) return entry, len(self.entries) @@ -127,10 +133,10 @@ async def add_entry_from_info( self, info: "YtdlpResponseDict", *, + author: Optional["discord.Member"] = None, + channel: Optional[GuildMessageableChannels] = None, head: bool = False, defer_serialize: bool = False, - is_autoplaylist: bool = False, - **meta: Any, ) -> Tuple[EntryTypes, int]: """ Checks given `info` to determine if media is streaming or has a @@ -141,7 +147,6 @@ async def add_entry_from_info( :param info: The extraction data of the song to add to the playlist. :param head: Add to front of queue instead of the end. :param defer_serialize: Signal that serialization steps should be deferred. - :param meta: Any additional metadata to add to the playlist entry. :returns: the entry & it's position in the queue. @@ -163,7 +168,7 @@ async def add_entry_from_info( # check if this is a stream, just in case. if info.is_stream: log.debug("Entry info appears to be a stream, adding stream entry...") - return await self.add_stream_from_info(info, head=head, **meta) + return await self.add_stream_from_info(info, head=head) # TODO: Extract this to its own function if info.extractor in ["generic", "Dropbox"]: @@ -183,7 +188,7 @@ async def add_entry_from_info( log.warning( "Got text/html for content-type, this might be a stream." ) - return await self.add_stream_from_info(info, head=head, **meta) + return await self.add_stream_from_info(info, head=head) # TODO: Check for shoutcast/icecast elif not content_type.startswith(("audio/", "video/")): @@ -196,7 +201,7 @@ async def add_entry_from_info( log.noise( # type: ignore[attr-defined] f"Adding URLPlaylistEntry for: {info.get('__input_subject')}" ) - entry = URLPlaylistEntry(self, info, from_apl=is_autoplaylist, **meta) + entry = URLPlaylistEntry(self, info, author=author, channel=channel) self._add_entry(entry, head=head, defer_serialize=defer_serialize) return entry, (1 if head else len(self.entries)) @@ -205,8 +210,8 @@ async def import_from_info( info: "YtdlpResponseDict", head: bool, ignore_video_id: str = "", - is_autoplaylist: bool = False, - **meta: Any, + author: Optional["discord.Member"] = None, + channel: Optional[GuildMessageableChannels] = None, ) -> Tuple[List[EntryTypes], int]: """ Validates the songs from `info` and queues them to be played. @@ -216,14 +221,12 @@ async def import_from_info( :param: info: YoutubeDL extraction data containing multiple entries. :param: head: Toggle adding the entries to the front of the queue. - :param: meta: Any additional metadata to add to the playlist entries. """ position = 1 if head else len(self.entries) + 1 entry_list = [] baditems = 0 entries = info.get_entries_objects() author_perms = None - author = meta.get("author", None) defer_serialize = True if author: @@ -297,8 +300,8 @@ async def import_from_info( item, head=head, defer_serialize=defer_serialize, - is_autoplaylist=is_autoplaylist, - **meta, + author=author, + channel=channel, ) entry_list.append(entry) except (WrongEntryTypeError, ExtractionError): @@ -320,7 +323,7 @@ def get_next_song_from_author( Get the next song in the queue that was added by the given `author` """ for entry in self.entries: - if entry.meta.get("author", None) == author: + if entry.author == author: return entry return None @@ -330,10 +333,10 @@ def reorder_for_round_robin(self) -> None: Reorders the queue for round-robin """ new_queue: Deque[EntryTypes] = deque() - all_authors: List["discord.User"] = [] + all_authors: List["discord.abc.User"] = [] for entry in self.entries: - author = entry.meta.get("author", None) + author = entry.author if author and author not in all_authors: all_authors.append(author) @@ -469,7 +472,7 @@ async def estimate_time_until( def count_for_user(self, user: "discord.abc.User") -> int: """Get a sum of entries added to the playlist by the given `user`""" - return sum(1 for e in self.entries if e.meta.get("author", None) == user) + return sum(1 for e in self.entries if e.author == user) def __json__(self) -> Dict[str, Any]: return self._enclose_json({"entries": list(self.entries)}) diff --git a/musicbot/utils.py b/musicbot/utils.py index b30dd1327..3a0b4a859 100644 --- a/musicbot/utils.py +++ b/musicbot/utils.py @@ -49,6 +49,8 @@ def _add_logger_level(levelname: str, level: int, *, func_name: str = "") -> Non _func_prototype = ( "def {logger_func_name}(self, message, *args, **kwargs):\n" " if self.isEnabledFor({levelname}):\n" + " if os.name == 'nt':\n" + " kwargs.setdefault('stacklevel', 1)\n" " self._log({levelname}, message, args, **kwargs)" ) @@ -132,26 +134,27 @@ def setup_loggers() -> None: if COLORLOG_LOADED: sformatter = colorlog.LevelFormatter( fmt={ - "DEBUG": "{log_color}[{levelname}:{module}] {message}", - "INFO": "{log_color}{message}", - "WARNING": "{log_color}{levelname}: {message}", - "ERROR": "{log_color}[{levelname}:{module}] {message}", + # Organized by level number in descending order. "CRITICAL": "{log_color}[{levelname}:{module}] {message}", - "EVERYTHING": "{log_color}[{levelname}:{module}] {message}", - "NOISY": "{log_color}[{levelname}:{module}] {message}", + "ERROR": "{log_color}[{levelname}:{module}] {message}", + "WARNING": "{log_color}{levelname}: {message}", + "INFO": "{log_color}{message}", + "DEBUG": "{log_color}[{levelname}:{module}] {message}", "VOICEDEBUG": "{log_color}[{levelname}:{module}][{relativeCreated:.9f}] {message}", "FFMPEG": "{log_color}[{levelname}:{module}][{relativeCreated:.9f}] {message}", + "NOISY": "{log_color}[{levelname}:{module}] {message}", + "EVERYTHING": "{log_color}[{levelname}:{module}] {message}", }, log_colors={ - "DEBUG": "cyan", - "INFO": "white", - "WARNING": "yellow", - "ERROR": "red", "CRITICAL": "bold_red", - "EVERYTHING": "bold_cyan", - "NOISY": "bold_white", - "FFMPEG": "bold_purple", + "ERROR": "red", + "WARNING": "yellow", + "INFO": "white", + "DEBUG": "cyan", "VOICEDEBUG": "purple", + "FFMPEG": "bold_purple", + "NOISY": "bold_white", + "EVERYTHING": "bold_cyan", }, style="{", datefmt="", @@ -182,6 +185,9 @@ def setup_loggers() -> None: # initially set discord logging to debug, it will be changed when config is loaded. dlogger.setLevel(logging.DEBUG) + # Set a flag to indicate our logs are open. + setattr(logging, "_mb_logs_open", True) + def muffle_discord_console_log() -> None: """ @@ -206,7 +212,8 @@ def mute_discord_console_log() -> None: for h in dlogger.handlers: if getattr(h, "terminator", None) == "": dlogger.removeHandler(h) - print() + # for console output cariage return post muffled log string. + print() def set_logging_level(level: int, override: bool = False) -> None: @@ -254,9 +261,14 @@ def set_logging_rotate_date_format(sftime: str) -> None: def shutdown_loggers() -> None: """Removes all musicbot and discord log handlers""" + if not hasattr(logging, "_mb_logs_open"): + return + # This is the last log line of the logger session. log.info("MusicBot loggers have been called to shutdown.") + setattr(logging, "_mb_logs_open", False) + logger = logging.getLogger("musicbot") for handler in logger.handlers: handler.flush() @@ -286,6 +298,9 @@ def rotate_log_files(max_kept: int = -1, date_fmt: str = "") -> None: :param: max_kept: number of old logs to keep. :param: date_fmt: format compatible with datetime.strftime() for rotated filename. """ + if hasattr(logging, "_mb_logs_rotated"): + return + # Use the input arguments or fall back to settings or defaults. if max_kept <= -1: max_kept = getattr(logging, "mb_max_logs_kept", DEFAULT_LOGS_KEPT) @@ -342,6 +357,8 @@ def rotate_log_files(max_kept: int = -1, date_fmt: str = "") -> None: if path.is_file(): path.unlink() + setattr(logging, "_mb_logs_rotated", True) + def load_file( filename: pathlib.Path, skip_commented_lines: bool = True, comment_char: str = "#" diff --git a/run.bat b/run.bat index 1c1641f32..9f8283f32 100644 --- a/run.bat +++ b/run.bat @@ -21,14 +21,14 @@ ENDLOCAL IF EXIST %SYSTEMROOT%\py.exe ( - CMD /k %SYSTEMROOT%\py.exe -3 run.py + CMD /k %SYSTEMROOT%\py.exe -3 run.py %* EXIT ) python --version > NUL 2>&1 IF %ERRORLEVEL% NEQ 0 GOTO nopython -CMD /k python run.py +CMD /k python run.py %* GOTO end :nopython diff --git a/run.py b/run.py index b82348f4a..5d4bbde19 100644 --- a/run.py +++ b/run.py @@ -8,14 +8,14 @@ import os import pathlib import shutil +import signal import ssl import subprocess import sys import textwrap import time -import traceback from base64 import b64decode -from typing import List, Tuple, Union +from typing import Any, Callable, Coroutine, List, Optional, Tuple, Union from musicbot.constants import ( DEFAULT_LOGS_KEPT, @@ -35,7 +35,7 @@ # protect dependency import from stopping the launcher try: - import aiohttp + from aiohttp.client_exceptions import ClientConnectorCertificateError except ImportError: pass @@ -169,7 +169,7 @@ def run(cls, command: str, check_output: bool = False) -> Union[bytes, int]: @classmethod def run_python_m( - cls, args: List[str], check_output: bool = False + cls, args: List[str], check_output: bool = False, quiet: bool = True ) -> Union[bytes, int]: """ Use subprocess check_call or check_output to run a pip module @@ -178,15 +178,14 @@ def run_python_m( :param: check_output: Use check_output rather than check_call. """ + cmd_args = [sys.executable, "-m", "pip"] + args if check_output: - return subprocess.check_output( - [sys.executable, "-m", "pip"] + args, - stderr=subprocess.DEVNULL, - ) - return subprocess.check_call( - [sys.executable, "-m", "pip"] + args, - stdout=subprocess.DEVNULL, - ) + if quiet: + return subprocess.check_output(cmd_args, stderr=subprocess.DEVNULL) + return subprocess.check_output(cmd_args) + if quiet: + return subprocess.check_call(cmd_args, stdout=subprocess.DEVNULL) + return subprocess.check_call(cmd_args) @classmethod def run_install( @@ -246,7 +245,11 @@ def check_updates(cls) -> int: return 0 @classmethod - def run_upgrade_requirements(cls, get_output: bool = False) -> Union[str, int]: + def run_upgrade_requirements( + cls, + get_output: bool = False, + quiet: bool = True, + ) -> Union[str, int]: """ Uses a subprocess call to run python using sys.executable. Runs `pip install --no-warn-script-location --no-input -U -r ./requirements.txt` @@ -275,6 +278,7 @@ def run_upgrade_requirements(cls, get_output: bool = False) -> Union[str, int]: "requirements.txt", ], check_output=get_output, + quiet=quiet, ) if isinstance(raw_data, bytes): pip_data = raw_data.decode("utf8").strip() @@ -315,7 +319,7 @@ def bugger_off(msg: str = "Press enter to continue . . .", code: int = 1) -> Non sys.exit(code) -def sanity_checks(args: argparse.Namespace, optional: bool = True) -> None: +def sanity_checks(args: argparse.Namespace) -> None: """ Run a collection of pre-startup checks to either automatically correct issues or inform the user of how to correct them. @@ -339,7 +343,7 @@ def sanity_checks(args: argparse.Namespace, optional: bool = True) -> None: log.info("Required checks passed.") """Optional Checks""" - if not optional: + if not args.do_start_checks: return # Check disk usage @@ -418,6 +422,8 @@ def req_ensure_py3() -> None: "Could not find Python 3.8 or higher. Please run the bot using Python 3.8" ) bugger_off() + else: + log.info("Python version: %s", sys.version) def req_check_deps() -> None: @@ -621,7 +627,15 @@ def log_levels_int(level_name: str) -> int: "--no-checks", dest="do_start_checks", action="store_false", - help="Skip all startup checks, including the update check.", + help="Skip all optional startup checks, including the update check.", + ) + + # Skip update checks option. + ap.add_argument( + "--no-disk-check", + dest="no_disk_check", + action="store_true", + help="Skip only the disk space check at startup.", ) # Skip update checks option. @@ -691,12 +705,38 @@ def log_levels_int(level_name: str) -> int: return args -def respawn_bot_process(pybin: str = "") -> None: +def setup_signal_handlers( + loop: asyncio.AbstractEventLoop, + callback: Callable[ + [signal.Signals, asyncio.AbstractEventLoop], Coroutine[Any, Any, None] + ], +) -> None: + """ + This function registers signal handlers with the event loop to help it close + with more grace when various OS signals are sent to this process. + """ + if os.name == "nt": + return + + def handle_signal(sig: signal.Signals, loop: asyncio.AbstractEventLoop) -> None: + """Creates and asyncio task to handle the signal on the event loop.""" + asyncio.create_task(callback(sig, loop), name=f"Signal_{sig.name}") + + # Linux/Unix signals we should clean up for. + sigs = [signal.SIGTERM, signal.SIGINT, signal.SIGHUP] + + for sig in sigs: + loop.add_signal_handler(sig, handle_signal, sig, loop) + + # set a flag to prevent adding more of the same handlers on soft restart. + setattr(loop, "_sig_handler_set", True) + + +def respawn_bot_process() -> None: """ Use a platform dependent method to restart the bot process, without an external process/service manager. - This uses either the given `pybin` executable path or sys.executable - to run the bot using the arguments currently in sys.argv + This uses the sys.executable and sys.argv to restart the bot. This function attempts to make sure all buffers are flushed and logging is shut down before restarting the new process. @@ -707,9 +747,7 @@ def respawn_bot_process(pybin: str = "") -> None: On Windows OS this will use subprocess.Popen to create a new console where the new bot is started, with a new PID, and exit this instance. """ - if not pybin: - pybin = sys.executable - exec_args = [pybin] + sys.argv + exec_args = [sys.executable] + sys.argv shutdown_loggers() rotate_log_files() @@ -723,11 +761,11 @@ def respawn_bot_process(pybin: str = "") -> None: # Seemed like the best way to avoid a pile of processes While keeping clean output in the shell. # There is seemingly no way to get the same effect as os.exec* on unix here in windows land. # The moment we end our existing instance, control is returned to the starting shell. - with subprocess.Popen( + subprocess.Popen( # pylint: disable=consider-using-with exec_args, creationflags=subprocess.CREATE_NEW_CONSOLE, # type: ignore[attr-defined] - ): - log.debug("Opened new MusicBot instance. This terminal can now be closed!") + ) + print("Opened a new MusicBot instance. This terminal can be safely closed!") sys.exit(0) else: # On Unix/Linux/Mac this should immediately replace the current program. @@ -736,62 +774,148 @@ def respawn_bot_process(pybin: str = "") -> None: os.execlp(exec_args[0], *exec_args) -async def main( - args: argparse.Namespace, -) -> Union[RestartSignal, TerminateSignal, None]: +def set_console_title() -> None: """ - All of the MusicBot starts here. + Attempts to set the console window title using the current version string. + On windows, this method will try to enable ANSI Escape codes by enabling + virtual terminal processing or by calling an empty sub-shell. + """ + # On windows, if colorlog isn't loaded already, ANSI escape codes probably + # wont work like we expect them to. + # This code attempts to solve that using ctypes and cursed windows-isms. + # or if that fails (it shouldn't) it falls back to another cursed trick. + if os.name == "nt": + try: + # if colorama fails to import we can assume setup_logs didn't load it. + import colorama # type: ignore[import-untyped] + + # if it works, then great, one less thing to worry about right??? + colorama.just_fix_windows_console() + except ImportError: + # This might only work for Win 10+ + from ctypes import windll # type: ignore[attr-defined] + + k32 = windll.kernel32 + # For info on SetConsoleMode, see: + # https://learn.microsoft.com/en-us/windows/console/setconsolemode + # For info on GetStdHandle, see: + # https://learn.microsoft.com/en-us/windows/console/getstdhandle + try: + k32.SetConsoleMode(k32.GetStdHandle(-11), 7) + except Exception: # pylint: disable=broad-exception-caught + # If it didn't work, fall back to this cursed trick... + # Since console -does- support ANSI escapes, but turns them off, + # This sort of beats the current console buffer over the head with + # the sub-shell's and then cannot disable the mode in parent shell. + try: + # No version info for this, testing needed. + os.system("") + except Exception: # pylint: disable=broad-exception-caught + # if this failed too, we're just out of luck. + pass + + # Update the console title, ignore if it fails. + try: + sys.stdout.write(f"\x1b]2;MusicBot {BOTVERSION}\x07") + except (TypeError, OSError): + pass - :param: args: some arguments parsed from the command line. - :returns: Oddly, returns rather than raises a *Signal or nothing. +def main() -> None: """ - # TODO: this function may not need to be async. + All of the MusicBot starts here. + """ + # Attempt to set console title. + set_console_title() + + # take care of loggers right away + setup_loggers() + + # parse arguments before any logs, so --help does not make an empty log. + cli_args = parse_cli_args() + + # Log file creation is deferred until this first write. + log.info("Loading MusicBot version: %s", BOTVERSION) + log.info("Log opened: %s", time.ctime()) + + # Check if run.py is in the current working directory. + run_py_dir = os.path.dirname(os.path.realpath(__file__)) + if run_py_dir != os.getcwd(): + # if not, verify musicbot and .git folders exists and change directory. + run_mb_dir = pathlib.Path(run_py_dir).joinpath("musicbot") + run_git_dir = pathlib.Path(run_py_dir).joinpath(".git") + if run_mb_dir.is_dir() and run_git_dir.is_dir(): + log.warning("Changing working directory to: %s", run_py_dir) + os.chdir(run_py_dir) + else: + log.critical( + "Cannot start the bot! You started `run.py` in the wrong directory" + " and we could not locate `musicbot` and `.git` folders to verify" + " a new directory location." + ) + log.error( + "For best results, start `run.py` from the same folder you cloned MusicBot into.\n" + "If you did not use git to clone the repository, you are strongly urged to." + ) + time.sleep(3) # make sure they see the message. + sys.exit(127) # Handle startup checks, if they haven't been skipped. - if args.do_start_checks: - sanity_checks(args) - else: - log.info("Skipped startup checks.") + sanity_checks(cli_args) exit_signal: Union[RestartSignal, TerminateSignal, None] = None - tried_requirementstxt = False - use_certifi = False - tryagain = True - - loops = 0 - max_wait_time = 60 + event_loop: Optional[asyncio.AbstractEventLoop] = None + tried_requirementstxt: bool = False + use_certifi: bool = False + retries: int = 0 + max_wait_time: int = 60 - while tryagain: + while True: # Maybe I need to try to import stuff first, then actually import stuff # It'd save me a lot of pain with all that awful exception type checking m = None try: - from musicbot import MusicBot # pylint: disable=import-outside-toplevel + # Prevent re-import of MusicBot + if "MusicBot" not in dir(): + from musicbot.bot import ( # pylint: disable=import-outside-toplevel + MusicBot, + ) + + # py3.8 made ProactorEventLoop default on windows. + # py3.12 deprecated using get_event_loop(), we need new_event_loop(). + event_loop = asyncio.new_event_loop() + asyncio.set_event_loop(event_loop) + # init some of bot, but don't run it yet. m = MusicBot(use_certifi=use_certifi) - await m.run() - except ( - ssl.SSLCertVerificationError, - aiohttp.client_exceptions.ClientConnectorCertificateError, - ) as e: - if isinstance( - e, aiohttp.client_exceptions.ClientConnectorCertificateError - ) and isinstance(e.__cause__, ssl.SSLCertVerificationError): + # register system signal handlers with the event loop. + if not getattr(event_loop, "_sig_handler_set", False): + setup_signal_handlers(event_loop, m.on_os_signal) + + # let the MusicBot run free! + event_loop.run_until_complete(m.run_musicbot()) + retries = 0 + + except (ssl.SSLCertVerificationError, ClientConnectorCertificateError) as e: + # For aiohttp, we need to look at the cause. + if isinstance(e, ClientConnectorCertificateError) and isinstance( + e.__cause__, ssl.SSLCertVerificationError + ): e = e.__cause__ else: log.critical( "Certificate error is not a verification error, not trying certifi and exiting." ) + log.exception("Here is the exact error, it could be a bug.") break # In case the local trust store does not have the cert locally, we can try certifi. # We don't want to patch working systems with a third-party trust chain outright. # These verify_code values come from OpenSSL: https://www.openssl.org/docs/man1.0.2/man1/verify.html if e.verify_code == 20: # X509_V_ERR_UNABLE_TO_GET_ISSUER_CERT_LOCALLY - if use_certifi: + if use_certifi: # already tried it. log.exception( "Could not get Issuer Certificate even with certifi!\n" "Try running: %s -m pip install --upgrade certifi ", @@ -807,6 +931,7 @@ async def main( "Could not get Issuer Certificate from default trust store, trying certifi instead." ) use_certifi = True + retries += 1 continue except SyntaxError: @@ -816,13 +941,24 @@ async def main( log.exception("Syntax error (this is a bug, not your fault)") break - except ImportError: - if args.no_install_deps: - log.error( - "Error importing MusicBot or it's dependency packages.\n" - "The `--no-install-deps` option is set, so MusicBot will exit now." + except ImportError as e: + if cli_args.no_install_deps: + helpfulerr = HelpfulError( + preface="Cannot start MusicBot due to an error!", + issue=( + f"Error: {str(e)}\n" + "This is an error importing MusicBot or a dependency package." + ), + solution=( + "You need to manually install dependency packages via pip.\n" + "Or launch without `--no-install-deps` and MusicBot will try to install them for you." + ), + footnote=( + "You have the `--no-install-deps` option set." + "Normally MusicBot attempts " + ), ) - log.exception("This is the exception which caused the above error: ") + log.error(str(helpfulerr)) break if not PIP.works(): @@ -841,30 +977,41 @@ async def main( if not tried_requirementstxt: tried_requirementstxt = True - log.exception("Error importing dependencies while starting bot.") - err = PIP.run_upgrade_requirements(get_output=True) + log.info( + "Attempting to install MusicBot dependency packages automatically...\n" + ) + pip_exit_code = PIP.run_upgrade_requirements(quiet=False) - if err: # TODO: add the specific error check back. - # The proper thing to do here is tell the user to fix - # their install, not help make it worse or insecure. - # Comprehensive return codes aren't really a feature of pip, - # If we need to read the log, then so does the user. + # If pip ran without issue, it should return 0 status code. + if pip_exit_code: print() - log.critical( - "This is not recommended! You can try to %s to install dependencies anyways.", - ["use sudo", "run as admin"][sys.platform.startswith("win")], + dep_error = HelpfulError( + preface="MusicBot dependencies may not be installed!", + issue="We didn't get a clean exit code from `pip` install.", + solution=( + "You will need to manually install dependency packages.\n" + "MusicBot tries to use the following command, so modify as needed:\n" + " pip install -U -r ./requirements.txt" + ), + footnote="You can also ask for help in MusicBot support server: https://discord.gg/bots", ) + log.critical(str(dep_error)) break print() - log.info("Ok lets hope it worked") + log.info("OK, lets hope that worked!") print() - else: - log.error( - "MusicBot got an ImportError after trying to install packages. MusicBot must exit..." - ) - log.exception("The exception which caused the above error: ") - break + shutdown_loggers() + rotate_log_files() + setup_loggers() + retries += 1 + continue + + log.error( + "MusicBot got an ImportError after trying to install packages. MusicBot must exit..." + ) + log.exception("The exception which caused the above error: ") + break except HelpfulError as e: log.info(e.message) @@ -872,110 +1019,66 @@ async def main( except TerminateSignal as e: exit_signal = e + retries = 0 break except RestartSignal as e: if e.get_name() == "RESTART_SOFT": - loops = 0 - else: - exit_signal = e - break + log.info("MusicBot is doing a soft restart...") + retries = 1 + continue + + log.info("MusicBot is doing a full process restart...") + exit_signal = e + retries = 1 + break except Exception: # pylint: disable=broad-exception-caught log.exception("Error starting bot") + break finally: - if m and (m.session or m.http.connector): - # in case we never made it to m.run(), ensure cleanup. - log.debug("Doing cleanup late.") - await m.shutdown_cleanup() - - if (not m or not m.init_ok) and not use_certifi: - if any(sys.exc_info()): - # How to log this without redundant messages... - log.warning( - "There are some exceptions that may not have been handled..." - ) - log.debug( - "Traceback output:\n%s", - "".join(traceback.format_exc()), - ) - tryagain = False - - loops += 1 + if event_loop: + log.debug("Closing event loop.") + event_loop.close() - sleeptime = min(loops * 2, max_wait_time) - if sleeptime: - log.info("Restarting in %s seconds...", sleeptime) - time.sleep(sleeptime) + sleeptime = min(retries * 2, max_wait_time) + if sleeptime: + log.info("Restarting in %s seconds...", sleeptime) + time.sleep(sleeptime) print() log.info("All done.") - return exit_signal - - -if __name__ == "__main__": - # take care of loggers right away - setup_loggers() - # parse arguments before any logs, so --help does not make an empty log. - cli_args = parse_cli_args() - - # Log file creation is deferred until this first write. - log.info("Loading MusicBot version: %s", BOTVERSION) - log.info("Log opened: %s", time.ctime()) - - # Check if run.py is in the current working directory. - run_py_dir = os.path.dirname(os.path.realpath(__file__)) - if run_py_dir != os.getcwd(): - # if not, verify musicbot and .git folders exists and change directory. - run_mb_dir = pathlib.Path(run_py_dir).joinpath("musicbot") - run_git_dir = pathlib.Path(run_py_dir).joinpath(".git") - if run_mb_dir.is_dir() and run_git_dir.is_dir(): - log.warning("Changing working directory to: %s", run_py_dir) - os.chdir(run_py_dir) - else: - log.critical( - "Cannot start the bot! You started `run.py` in the wrong directory" - " and we could not locate `musicbot` and `.git` folders to verify" - " a new directory location." - ) - log.error( - "For best results, start `run.py` from the same folder you cloned MusicBot into.\n" - "If you did not use git to clone the repository, you are strongly urged to." - ) - time.sleep(3) # make sure they see the message. - sys.exit(127) + shutdown_loggers() + rotate_log_files() - # py3.8 made ProactorEventLoop default on windows. - # py3.12 deprecated using get_event_loop(), we need new_event_loop(). - loop = asyncio.new_event_loop() - asyncio.set_event_loop(loop) - try: - exit_sig = loop.run_until_complete(main(cli_args)) - except KeyboardInterrupt: - # TODO: later this will probably get more cleanup so we can - # close other things more proper like too. - log.info("\nCaught a keyboard interrupt signal.") - shutdown_loggers() - rotate_log_files() - raise + print() - if exit_sig: - if isinstance(exit_sig, RestartSignal): - if exit_sig.get_name() == "RESTART_FULL": + if exit_signal: + if isinstance(exit_signal, RestartSignal): + if exit_signal.get_name() == "RESTART_FULL": respawn_bot_process() - elif exit_sig.get_name() == "RESTART_UPGRADE_ALL": + elif exit_signal.get_name() == "RESTART_UPGRADE_ALL": PIP.run_upgrade_requirements() GIT.run_upgrade_pull() respawn_bot_process() - elif exit_sig.get_name() == "RESTART_UPGRADE_PIP": + elif exit_signal.get_name() == "RESTART_UPGRADE_PIP": PIP.run_upgrade_requirements() respawn_bot_process() - elif exit_sig.get_name() == "RESTART_UPGRADE_GIT": + elif exit_signal.get_name() == "RESTART_UPGRADE_GIT": GIT.run_upgrade_pull() respawn_bot_process() - elif isinstance(exit_sig, TerminateSignal): - shutdown_loggers() - rotate_log_files() - sys.exit(exit_sig.exit_code) + elif isinstance(exit_signal, TerminateSignal): + sys.exit(exit_signal.exit_code) + + +if __name__ == "__main__": + try: + main() + except KeyboardInterrupt: + print("OK, we're closing!") + shutdown_loggers() + rotate_log_files() + + sys.exit(0) diff --git a/run.sh b/run.sh index 972ce96a3..7f8cb856e 100755 --- a/run.sh +++ b/run.sh @@ -1,46 +1,47 @@ #!/bin/bash -# Ensure we're in the MusicBot directory +# Assuming no files have been moved, +# make sure we're in MusicBot directory... cd "$(dirname "$BASH_SOURCE")" -# Set variables for python versions. Could probably be done cleaner, but this works. -declare -A python=(["0"]=$(python -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[0]))' || { echo "no py"; }) ["1"]=$(python -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[1]))' || { echo "no py"; }) ["2"]=$(python -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[2]))' || { echo "no py"; })) -declare -A python3=(["0"]=$(python3 -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[1]))' || { echo "no py3"; }) ["1"]=$(python3 -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[2]))' || { echo "no py3"; })) -PYTHON38_VERSION=$(python3.8 -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[1]))' || { echo "no py38"; }) -PYTHON39_VERSION=$(python3.9 -c 'import sys; version=sys.version_info[:3]; print("{0}".format(version[1]))' || { echo "no py39"; }) +# get python version as an array, check first for python3 bin. +PY_BIN="python3" +PY_VER=($(python3 -c "import sys; print('%s %s %s' % sys.version_info[:3])" || { echo "0 0 0"; })) +if [[ "${PY_VER[0]}" == "0" ]]; then + PY_VER=($(python -c "import sys; print('%s %s %s' % sys.version_info[:3])" || { echo "0 0 0"; })) + PY_BIN="python" +fi +PY_VER_MAJOR=$((${PY_VER[0]})) +PY_VER_MINOR=$((${PY_VER[1]})) +PY_VER_PATCH=$((${PY_VER[2]})) +VER_GOOD=0 + +# echo "run.sh detected $PY_BIN version: $PY_VER_MAJOR.$PY_VER_MINOR.$PY_VER_PATCH" -if [ "${python[0]}" -eq "3" ]; then # Python = 3 - if [ "${python[1]}" -eq "8" ]; then # Python = 3.8 - if [ "${python[2]}" -ge "7" ]; then # Python = 3.8.7 - python run.py - exit +# Major version must be 3+ +if [[ $PY_VER_MAJOR -ge 3 ]]; then + # If 3, minor version minimum is 3.8 + if [[ $PY_VER_MINOR -eq 8 ]]; then + # if 3.8, patch version minimum is 3.8.7 + if [[ $PY_VER_PATCH -ge 7 ]]; then + VER_GOOD=1 fi - elif [ "${python[1]}" -ge "9" ]; then # Python >= 3.9 - python run.py - exit fi -fi - -if [ "${python3[0]}" -eq "8" ]; then # Python3 = 3.8 - if [ "${python3[1]}" -ge "7" ]; then # Python3 >= 3.8.7 - python3 run.py - exit + # if 3.9+ it should work. + if [[ $PY_VER_MINOR -ge 9 ]]; then + VER_GOOD=1 fi fi -if [ "${python3[0]}" -ge "9" ]; then # Python3 >= 3.9 - python3 run.py - exit +# if we don't have a good version for python, bail. +if [[ "$VER_GOOD" == "0" ]]; then + echo "Python 3.8.7 or higher is required to run MusicBot." + exit 1 fi -if [ "$PYTHON38_VERSION" -eq "8" ]; then # Python3.8 = 3.8 - python3.8 run.py - exit -fi +# Run python using the bin name we determined via version fetch. +# We also pass all arguments from this script into python. +$PY_BIN run.py "$@" -if [ "$PYTHON39_VERSION" -eq "9" ]; then # Python3.9 = 3.9 - python3.9 run.py - exit -fi -echo "You are running an unsupported Python version." -echo "Please use a version of Python above 3.8.7." +# exit using the code that python exited with. +exit $?