From ab80f46d2e50dca1f8d200552a54726acc4191e6 Mon Sep 17 00:00:00 2001 From: Kowlin Date: Wed, 23 Dec 2020 05:11:44 +0100 Subject: [PATCH] [Core] Rich logging for not so rich people (#4577) * Pop stash * add rich to setup * Added forceful enabling of rich logging * revert some unintended pushed * Fix possible unbound var Fix possible 0 members w/out members intent * One day I won't forget to do style passes * So this is a thing apperently... * Bump rich to 9.5.1 * Lock secondary deps * Different stuff, see the full commit description for more info - Change few things from print to log.info - put the log handlers on the root logger instead of individual loggers - capture warnings to a logger * Modify log handler to show logger name * Add a Triboolian to force disable rich * Style checks * shortened time, added logger name... again. * aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa * Style & linking * Be or not to be? Whatever man, it's 4:30 in the morning, goto sleep >.< * Reintroduce outdated message. Co-authored-by: jack1142 <6032823+jack1142@users.noreply.github.com> --- redbot/__main__.py | 4 +- redbot/core/bot.py | 8 +- redbot/core/cli.py | 14 ++++ redbot/core/events.py | 98 +++++++++++------------ redbot/logging.py | 173 ++++++++++++++++++++++++++++++++++++++--- setup.cfg | 4 +- tools/primary_deps.ini | 1 + 7 files changed, 236 insertions(+), 66 deletions(-) diff --git a/redbot/__main__.py b/redbot/__main__.py index f79607ca5..ee0d171eb 100644 --- a/redbot/__main__.py +++ b/redbot/__main__.py @@ -335,7 +335,9 @@ async def run_bot(red: Red, cli_flags: Namespace) -> None: await driver_cls.initialize(**data_manager.storage_details()) redbot.logging.init_logging( - level=cli_flags.logging_level, location=data_manager.core_data_path() / "logs" + level=cli_flags.logging_level, + location=data_manager.core_data_path() / "logs", + force_rich_logging=cli_flags.rich_logging, ) log.debug("====Basic Config====") diff --git a/redbot/core/bot.py b/redbot/core/bot.py index 37537868e..866d5c30e 100644 --- a/redbot/core/bot.py +++ b/redbot/core/bot.py @@ -29,6 +29,7 @@ from typing import ( overload, ) from types import MappingProxyType +from rich.console import Console import discord from discord.ext import commands as dpy_commands @@ -221,6 +222,9 @@ class RedBase( self._deletion_requests: MutableMapping[int, asyncio.Lock] = weakref.WeakValueDictionary() + # Although I see the use of keeping this public, lets rather make it private. + self._rich_console = Console() + def set_help_formatter(self, formatter: commands.help.HelpFormatterABC): """ Set's Red's help formatter. @@ -878,7 +882,7 @@ class RedBase( packages.insert(0, "permissions") to_remove = [] - print("Loading packages...") + log.info("Loading packages...") for package in packages: try: spec = await self._cog_mgr.find_cog(package) @@ -901,7 +905,7 @@ class RedBase( for package in to_remove: packages.remove(package) if packages: - print("Loaded packages: " + ", ".join(packages)) + log.info("Loaded packages: " + ", ".join(packages)) if self.rpc_enabled: await self.rpc.initialize(self.rpc_port) diff --git a/redbot/core/cli.py b/redbot/core/cli.py index b05a7f875..129bd7b86 100644 --- a/redbot/core/cli.py +++ b/redbot/core/cli.py @@ -249,6 +249,20 @@ def parse_cli_flags(args): " to see what each intent does.\n" "This flag can be used multiple times to specify multiple intents.", ) + parser.add_argument( + "--force-rich-logging", + action="store_true", + dest="rich_logging", + default=None, + help="Forcefully enables the Rich logging handlers. This is normally enabled for supported active terminals.", + ) + parser.add_argument( + "--force-disable-rich-logging", + action="store_false", + dest="rich_logging", + default=None, + help="Forcefully disables the Rich logging handlers.", + ) args = parser.parse_args(args) diff --git a/redbot/core/events.py b/redbot/core/events.py index f961e1356..8838b43dc 100644 --- a/redbot/core/events.py +++ b/redbot/core/events.py @@ -33,10 +33,15 @@ from .utils._internal_utils import ( ) from .utils.chat_formatting import inline, bordered, format_perms_list, humanize_timedelta +from rich.table import Table +from rich.columns import Columns +from rich.panel import Panel +from rich.text import Text + log = logging.getLogger("red") init() -INTRO = r""" +INTRO = r"""[red] ______ _ ______ _ _ ______ _ | ___ \ | | | _ (_) | | | ___ \ | | | |_/ /___ __| | ______ | | | |_ ___ ___ ___ _ __ __| | | |_/ / ___ | |_ @@ -52,7 +57,7 @@ def init_events(bot, cli_flags): @bot.event async def on_connect(): if bot._uptime is None: - print("Connected to Discord. Getting ready...") + log.info("Connected to Discord. Getting ready...") @bot.event async def on_ready(): @@ -83,36 +88,35 @@ def init_events(bot, cli_flags): red_pkg = pkg_resources.get_distribution("Red-DiscordBot") dpy_version = discord.__version__ - INFO = [ - str(bot.user), - "Prefixes: {}".format(", ".join(prefixes)), - "Language: {}".format(lang), - "Red Bot Version: {}".format(red_version), - "Discord.py Version: {}".format(dpy_version), - "Shards: {}".format(bot.shard_count), - "Storage type: {}".format(data_manager.storage_type()), - ] + table_general_info = Table(show_edge=False, show_header=False) + table_general_info.add_row("Prefixes", ", ".join(prefixes)) + table_general_info.add_row("Language", lang) + table_general_info.add_row("Red version", red_version) + table_general_info.add_row("Discord.py version", dpy_version) + table_general_info.add_row("Storage type", data_manager.storage_type()) - if guilds: - INFO.extend(("Servers: {}".format(guilds), "Users: {}".format(users))) - else: - print("Ready. I'm not in any server yet!") - - INFO.append("{} cogs with {} commands".format(len(bot.cogs), len(bot.commands))) + table_counts = Table(show_edge=False, show_header=False) + # String conversion is needed as Rich doesn't deal with ints + table_counts.add_row("Shards", str(bot.shard_count)) + table_counts.add_row("Servers", str(guilds)) + if bot.intents.members: # Lets avoid 0 Unique Users + table_counts.add_row("Unique Users", str(users)) outdated_red_message = "" + rich_outdated_message = "" with contextlib.suppress(aiohttp.ClientError, asyncio.TimeoutError): pypi_version, py_version_req = await fetch_latest_red_version_info() outdated = pypi_version and pypi_version > red_version_info if outdated: - INFO.append( - "Outdated version! {} is available " - "but you're using {}".format(pypi_version, red_version) - ) outdated_red_message = _( "Your Red instance is out of date! {} is the current " "version, however you are using {}!" ).format(pypi_version, red_version) + rich_outdated_message = ( + f"[red]Outdated version![/red]\n" + f"[red]!!![/red]Version {pypi_version} is available, " + f"but you're using {red_version}[red]!!![/red]" + ) current_python = platform.python_version() extra_update = _( "\n\nWhile the following command should work in most scenarios as it is " @@ -163,41 +167,33 @@ def init_events(bot, cli_flags): ).format(py_version=current_python, req_py=py_version_req) outdated_red_message += extra_update - INFO2 = [] + bot._rich_console.print(INTRO) + if guilds: + bot._rich_console.print( + Columns( + [Panel(table_general_info, title=str(bot.user.name)), Panel(table_counts)], + equal=True, + align="center", + ) + ) + else: + bot._rich_console.print(Columns([Panel(table_general_info, title=str(bot.user.name))])) - reqs_installed = {"docs": None, "test": None} - for key in reqs_installed.keys(): - reqs = [x.name for x in red_pkg._dep_map[key]] - try: - pkg_resources.require(reqs) - except DistributionNotFound: - reqs_installed[key] = False - else: - reqs_installed[key] = True - - options = ( - ("Voice", True), - ("Docs", reqs_installed["docs"]), - ("Tests", reqs_installed["test"]), + bot._rich_console.print( + "Loaded {} cogs with {} commands".format(len(bot.cogs), len(bot.commands)) ) - on_symbol, off_symbol, ascii_border = _get_startup_screen_specs() - - for option, enabled in options: - enabled = on_symbol if enabled else off_symbol - INFO2.append("{} {}".format(enabled, option)) - - print(Fore.RED + INTRO) - print(Style.RESET_ALL) - print(bordered(INFO, INFO2, ascii_border=ascii_border)) - if invite_url: - print("\nInvite URL: {}\n".format(invite_url)) - - if not guilds: - print( - "Looking for a quick guide on setting up Red? https://docs.discord.red/en/stable/getting_started.html\n" + bot._rich_console.print( + f"\nInvite URL: {Text(invite_url, style=f'link {invite_url}')}" ) + # We generally shouldn't care if the client supports it or not as Rich deals with it. + if not guilds: + bot._rich_console.print( + f"Looking for a quick guide on setting up Red? Checkout {Text('https://start.discord.red', style='link https://start.discord.red}')}" + ) + if rich_outdated_message: + bot._rich_console.print(rich_outdated_message) if not bot.owner_ids: # we could possibly exit here in future diff --git a/redbot/logging.py b/redbot/logging.py index 676a8de30..9ae895723 100644 --- a/redbot/logging.py +++ b/redbot/logging.py @@ -2,7 +2,19 @@ import logging.handlers import pathlib import re import sys -from typing import List, Tuple, Optional + +from typing import List, Tuple, Optional, Union +from logging import LogRecord +from datetime import datetime # This clearly never leads to confusion... +from os import isatty + +from rich._log_render import LogRender +from rich.containers import Renderables +from rich.logging import RichHandler +from rich.table import Table +from rich.text import Text +from rich.traceback import Traceback + MAX_OLD_LOGS = 8 @@ -97,20 +109,158 @@ class RotatingFileHandler(logging.handlers.RotatingFileHandler): self.stream = self._open() -def init_logging(level: int, location: pathlib.Path) -> None: - dpy_logger = logging.getLogger("discord") - dpy_logger.setLevel(logging.WARNING) +class RedLogRender(LogRender): + def __call__( + self, + console, + renderables, + log_time=None, + time_format=None, + level="", + path=None, + line_no=None, + link_path=None, + logger_name=None, + ): + output = Table.grid(padding=(0, 1)) + output.expand = True + if self.show_time: + output.add_column(style="log.time") + if self.show_level: + output.add_column(style="log.level", width=self.level_width) + output.add_column(ratio=1, style="log.message", overflow="fold") + if self.show_path and path: + output.add_column(style="log.path") + if logger_name: + output.add_column() + row = [] + if self.show_time: + log_time = log_time or console.get_datetime() + log_time_display = log_time.strftime(time_format or self.time_format) + if log_time_display == self._last_time: + row.append(Text(" " * len(log_time_display))) + else: + row.append(Text(log_time_display)) + self._last_time = log_time_display + if self.show_level: + row.append(level) + + row.append(Renderables(renderables)) + if self.show_path and path: + path_text = Text() + path_text.append(path, style=f"link file://{link_path}" if link_path else "") + if line_no: + path_text.append(f":{line_no}") + row.append(path_text) + + if logger_name: + logger_name_text = Text() + logger_name_text.append(f"[{logger_name}]") + row.append(logger_name_text) + + output.add_row(*row) + return output + + +class RedRichHandler(RichHandler): + """Adaptation of Rich's RichHandler to manually adjust the path to a logger name""" + + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self._log_render = RedLogRender( + show_time=self._log_render.show_time, + show_level=self._log_render.show_level, + show_path=self._log_render.show_path, + level_width=self._log_render.level_width, + ) + + def emit(self, record: LogRecord) -> None: + """Invoked by logging.""" + path = pathlib.Path(record.pathname).name + level = self.get_level_text(record) + message = self.format(record) + time_format = None if self.formatter is None else self.formatter.datefmt + log_time = datetime.fromtimestamp(record.created) + + traceback = None + if self.rich_tracebacks and record.exc_info and record.exc_info != (None, None, None): + exc_type, exc_value, exc_traceback = record.exc_info + assert exc_type is not None + assert exc_value is not None + traceback = Traceback.from_exception( + exc_type, + exc_value, + exc_traceback, + width=self.tracebacks_width, + extra_lines=self.tracebacks_extra_lines, + theme=self.tracebacks_theme, + word_wrap=self.tracebacks_word_wrap, + show_locals=self.tracebacks_show_locals, + locals_max_length=self.locals_max_length, + locals_max_string=self.locals_max_string, + ) + message = record.getMessage() + + use_markup = getattr(record, "markup") if hasattr(record, "markup") else self.markup + if use_markup: + message_text = Text.from_markup(message) + else: + message_text = Text(message) + + if self.highlighter: + message_text = self.highlighter(message_text) + if self.KEYWORDS: + message_text.highlight_words(self.KEYWORDS, "logging.keyword") + + self.console.print( + self._log_render( + self.console, + [message_text] if not traceback else [message_text, traceback], + log_time=log_time, + time_format=time_format, + level=level, + path=path, + line_no=record.lineno, + link_path=record.pathname if self.enable_link_path else None, + logger_name=record.name, + ) + ) + + +def init_logging( + level: int, location: pathlib.Path, force_rich_logging: Union[bool, None] +) -> None: + root_logger = logging.getLogger() + base_logger = logging.getLogger("red") base_logger.setLevel(level) + dpy_logger = logging.getLogger("discord") + dpy_logger.setLevel(logging.WARNING) + warnings_logger = logging.getLogger("py.warnings") + warnings_logger.setLevel(logging.WARNING) - formatter = logging.Formatter( + enable_rich_logging = False + + if isatty(0) and force_rich_logging is None: + # Check if the bot thinks it has a active terminal. + enable_rich_logging = True + elif force_rich_logging is True: + enable_rich_logging = True + + file_formatter = logging.Formatter( "[{asctime}] [{levelname}] {name}: {message}", datefmt="%Y-%m-%d %H:%M:%S", style="{" ) + if enable_rich_logging is True: + rich_formatter = logging.Formatter("{message}", datefmt="[%X]", style="{") - stdout_handler = logging.StreamHandler(sys.stdout) - stdout_handler.setFormatter(formatter) - base_logger.addHandler(stdout_handler) - dpy_logger.addHandler(stdout_handler) + stdout_handler = RedRichHandler(rich_tracebacks=True, show_path=False) + stdout_handler.setFormatter(rich_formatter) + else: + stdout_handler = logging.StreamHandler(sys.stdout) + stdout_handler.setFormatter(file_formatter) + + root_logger.addHandler(stdout_handler) + logging.captureWarnings(True) if not location.exists(): location.mkdir(parents=True, exist_ok=True) @@ -146,6 +296,7 @@ def init_logging(level: int, location: pathlib.Path) -> None: backupCount=MAX_OLD_LOGS, encoding="utf-8", ) + for fhandler in (latest_fhandler, all_fhandler): - fhandler.setFormatter(formatter) - base_logger.addHandler(fhandler) + fhandler.setFormatter(file_formatter) + root_logger.addHandler(fhandler) diff --git a/setup.cfg b/setup.cfg index f96340750..b3568e619 100644 --- a/setup.cfg +++ b/setup.cfg @@ -43,6 +43,7 @@ install_requires = chardet==3.0.4 click==7.1.2 colorama==0.4.3 + commonmark==0.9.1 contextlib2==0.6.0.post1 discord.py==1.5.1 distro==1.5.0; sys_platform == "linux" @@ -50,11 +51,13 @@ install_requires = idna==2.10 markdown==3.2.2 multidict==4.7.6 + Pygments==2.6.1 python-dateutil==2.8.1 python-Levenshtein-wheels==0.13.1 pytz==2020.1 PyYAML==5.3.1 Red-Lavalink==0.7.1 + rich==9.5.1 schema==0.7.2 six==1.15.0 tqdm==4.48.0 @@ -71,7 +74,6 @@ docs = Jinja2==2.11.2 MarkupSafe==1.1.1 packaging==20.4 - Pygments==2.6.1 pyparsing==2.4.7 requests==2.24.0 snowballstemmer==2.0.0 diff --git a/tools/primary_deps.ini b/tools/primary_deps.ini index 1b0bf5bc3..3ee79a8b3 100644 --- a/tools/primary_deps.ini +++ b/tools/primary_deps.ini @@ -22,6 +22,7 @@ install_requires = python-Levenshtein-wheels PyYAML Red-Lavalink + rich schema tqdm uvloop; sys_platform != "win32" and platform_python_implementation == "CPython"