[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

@@ -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====")

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)

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)
 

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 = [
+        table_general_info = Table(show_edge=False, show_header=False)
-            str(bot.user),
+        table_general_info.add_row("Prefixes", ", ".join(prefixes))
-            "Prefixes: {}".format(", ".join(prefixes)),
+        table_general_info.add_row("Language", lang)
-            "Language: {}".format(lang),
+        table_general_info.add_row("Red version", red_version)
-            "Red Bot Version: {}".format(red_version),
+        table_general_info.add_row("Discord.py version", dpy_version)
-            "Discord.py Version: {}".format(dpy_version),
+        table_general_info.add_row("Storage type", data_manager.storage_type())
-            "Shards: {}".format(bot.shard_count),
-            "Storage type: {}".format(data_manager.storage_type()),
-        ]
 
-        if guilds:
+        table_counts = Table(show_edge=False, show_header=False)
-            INFO.extend(("Servers: {}".format(guilds), "Users: {}".format(users)))
+        # String conversion is needed as Rich doesn't deal with ints
-        else:
+        table_counts.add_row("Shards", str(bot.shard_count))
-            print("Ready. I'm not in any server yet!")
+        table_counts.add_row("Servers", str(guilds))
-
+        if bot.intents.members:  # Lets avoid 0 Unique Users
-        INFO.append("{} cogs with {} commands".format(len(bot.cogs), len(bot.commands)))
+            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:
-        reqs_installed = {"docs": None, "test": None}
+            bot._rich_console.print(
-        for key in reqs_installed.keys():
+                Columns(
-            reqs = [x.name for x in red_pkg._dep_map[key]]
+                    [Panel(table_general_info, title=str(bot.user.name)), Panel(table_counts)],
-            try:
+                    equal=True,
-                pkg_resources.require(reqs)
+                    align="center",
-            except DistributionNotFound:
-                reqs_installed[key] = False
-            else:
-                reqs_installed[key] = True
-
-        options = (
-            ("Voice", True),
-            ("Docs", reqs_installed["docs"]),
-            ("Tests", reqs_installed["test"]),
                 )
+            )
+        else:
+            bot._rich_console.print(Columns([Panel(table_general_info, title=str(bot.user.name))]))
 
-        on_symbol, off_symbol, ascii_border = _get_startup_screen_specs()
+        bot._rich_console.print(
-
+            "Loaded {} cogs with {} commands".format(len(bot.cogs), len(bot.commands))
-        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))
+            bot._rich_console.print(
-
+                f"\nInvite URL: {Text(invite_url, style=f'link {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"
             )
+            # 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

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:
+class RedLogRender(LogRender):
-    dpy_logger = logging.getLogger("discord")
+    def __call__(
-    dpy_logger.setLevel(logging.WARNING)
+        self,
-    base_logger = logging.getLogger("red")
+        console,
-    base_logger.setLevel(level)
+        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)
 
-    formatter = logging.Formatter(
+        row.append(Renderables(renderables))
-        "[{asctime}] [{levelname}] {name}: {message}", datefmt="%Y-%m-%d %H:%M:%S", style="{"
+        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)
+
+    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 = RedRichHandler(rich_tracebacks=True, show_path=False)
+        stdout_handler.setFormatter(rich_formatter)
+    else:
         stdout_handler = logging.StreamHandler(sys.stdout)
-    stdout_handler.setFormatter(formatter)
+        stdout_handler.setFormatter(file_formatter)
-    base_logger.addHandler(stdout_handler)
+
-    dpy_logger.addHandler(stdout_handler)
+    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)
+        fhandler.setFormatter(file_formatter)
-        base_logger.addHandler(fhandler)
+        root_logger.addHandler(fhandler)

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

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"