Replace slow rich logging with loguru

This patch removes the rich logging with
the modern loguru logging

aprsd/cmds/webchat.py

@@ -1,7 +1,6 @@
 import datetime
 import json
 import logging
-from logging.handlers import RotatingFileHandler
 import math
 import signal
 import sys
@@ -12,7 +11,6 @@ from aprslib import util as aprslib_util
 import click
 import flask
 from flask import request
-from flask.logging import default_handler
 from flask_httpauth import HTTPBasicAuth
 from flask_socketio import Namespace, SocketIO
 from geopy.distance import geodesic
@@ -21,11 +19,13 @@ from werkzeug.security import check_password_hash, generate_password_hash
 import wrapt
 
 import aprsd
-from aprsd import cli_helper, client, conf, packets, stats, threads, utils, plugin_utils
+from aprsd import (
-from aprsd.log import rich as aprsd_logging
+    cli_helper, client, packets, plugin_utils, stats, threads, utils,
+)
+from aprsd.log import log
 from aprsd.main import cli
-from aprsd.threads import rx, tx
 from aprsd.threads import aprsd as aprsd_threads
+from aprsd.threads import rx, tx
 from aprsd.utils import trace
 
 
@@ -181,7 +181,7 @@ def _build_location_from_repeat(message):
     a = message.split(":")
     LOG.warning(a)
     if len(a) == 2:
-        callsign = a[0].replace('^ld^', '')
+        callsign = a[0].replace("^ld^", "")
         b = a[1].split(",")
         LOG.warning(b)
         if len(b) == 6:
@@ -282,13 +282,13 @@ def populate_callsign_location(callsign, data=None):
             except Exception:
                 alt = 0
             location_data = {
-                'callsign': callsign,
+                "callsign": callsign,
-                'lat': lat,
+                "lat": lat,
-                'lon': lon,
+                "lon": lon,
-                'altitude': alt,
+                "altitude": alt,
-                'lasttime': int(aprs_data["entries"][0]["lasttime"]),
+                "lasttime": int(aprs_data["entries"][0]["lasttime"]),
-                'course': float(aprs_data["entries"][0].get("course", 0)),
+                "course": float(aprs_data["entries"][0].get("course", 0)),
-                'speed': float(aprs_data["entries"][0].get("speed", 0)),
+                "speed": float(aprs_data["entries"][0].get("speed", 0)),
             }
             location_data = _calculate_location_data(location_data)
             callsign_locations[callsign] = location_data
@@ -339,7 +339,7 @@ class WebChatProcessPacketThread(rx.APRSDProcessPacketThread):
         # ok lets see if we have the location for the
         # person we just sent a message to.
         from_call = packet.get("from_call").upper()
-        if from_call == 'REPEAT':
+        if from_call == "REPEAT":
             # We got a message from REPEAT.  Is this a location message?
             message = packet.get("message_text")
             if message.startswith("^ld^"):
@@ -568,52 +568,16 @@ class SendMessageNamespace(Namespace):
         populate_callsign_location(data["callsign"])
 
 
-def setup_logging(flask_app, loglevel, quiet):
-    flask_log = logging.getLogger("werkzeug")
-    flask_app.logger.removeHandler(default_handler)
-    flask_log.removeHandler(default_handler)
-
-    log_level = conf.log.LOG_LEVELS[loglevel]
-    flask_log.setLevel(log_level)
-    date_format = CONF.logging.date_format
-
-    if CONF.logging.rich_logging and not quiet:
-        log_format = "%(message)s"
-        log_formatter = logging.Formatter(fmt=log_format, datefmt=date_format)
-        rh = aprsd_logging.APRSDRichHandler(
-            show_thread=True, thread_width=15,
-            rich_tracebacks=True, omit_repeated_times=False,
-        )
-        rh.setFormatter(log_formatter)
-        flask_log.addHandler(rh)
-
-    log_file = CONF.logging.logfile
-
-    if log_file:
-        log_format = CONF.logging.logformat
-        log_formatter = logging.Formatter(fmt=log_format, datefmt=date_format)
-        fh = RotatingFileHandler(
-            log_file, maxBytes=(10248576 * 5),
-            backupCount=4,
-        )
-        fh.setFormatter(log_formatter)
-        flask_log.addHandler(fh)
-
-
 @trace.trace
 def init_flask(loglevel, quiet):
     global socketio, flask_app
 
-    setup_logging(flask_app, loglevel, quiet)
+    log.setup_logging(loglevel, quiet)
 
     socketio = SocketIO(
         flask_app, logger=False, engineio_logger=False,
         async_mode="threading",
     )
-    # async_mode="gevent",
-    # async_mode="eventlet",
-    #    import eventlet
-    #    eventlet.monkey_patch()
 
     socketio.on_namespace(
         SendMessageNamespace(

aprsd/conf/log.py

@@ -20,21 +20,18 @@ DEFAULT_LOG_FORMAT = (
     " %(message)s - [%(pathname)s:%(lineno)d]"
 )
 
+DEFAULT_LOG_FORMAT = (
+    "<green>{time:YYYY-MM-DD HH:mm:ss.SSS}</green> | "
+    "<level>{level: <8}</level> | "
+    "<yellow>{thread.name: <18}</yellow> | "
+    "<cyan>{name}</cyan>:<cyan>{function}</cyan>:<cyan>{line}</cyan> - <level>{message}</level>"
+)
+
 logging_group = cfg.OptGroup(
     name="logging",
     title="Logging options",
 )
 logging_opts = [
-    cfg.StrOpt(
-        "date_format",
-        default=DEFAULT_DATE_FORMAT,
-        help="Date format for log entries",
-    ),
-    cfg.BoolOpt(
-        "rich_logging",
-        default=True,
-        help="Enable Rich log",
-    ),
     cfg.StrOpt(
         "logfile",
         default=None,

aprsd/log/log.py

@@ -1,13 +1,12 @@
 import logging
 from logging import NullHandler
-from logging.handlers import RotatingFileHandler
 import queue
 import sys
 
+from loguru import logger
 from oslo_config import cfg
 
 from aprsd import conf
-from aprsd.log import rich as aprsd_logging
 
 
 CONF = cfg.CONF
@@ -15,61 +14,78 @@ LOG = logging.getLogger("APRSD")
 logging_queue = queue.Queue()
 
 
+class InterceptHandler(logging.Handler):
+    def emit(self, record):
+        # get corresponding Loguru level if it exists
+        try:
+            level = logger.level(record.levelname).name
+        except ValueError:
+            level = record.levelno
+
+        # find caller from where originated the logged message
+        frame, depth = sys._getframe(6), 6
+        while frame and frame.f_code.co_filename == logging.__file__:
+            frame = frame.f_back
+            depth += 1
+
+        logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage())
+
+
 # Setup the log faciility
 # to disable log to stdout, but still log to file
 # use the --quiet option on the cmdln
-def setup_logging(loglevel, quiet):
+def setup_logging(loglevel=None, quiet=False):
-    log_level = conf.log.LOG_LEVELS[loglevel]
+    if not loglevel:
-    LOG.setLevel(log_level)
+        log_level = CONF.logging.log_level
-    date_format = CONF.logging.date_format
+    else:
-    rh = None
+        log_level = conf.log.LOG_LEVELS[loglevel]
-    fh = None
 
-    rich_logging = False
+    # intercept everything at the root logger
-    if CONF.logging.get("rich_logging", False) and not quiet:
+    logging.root.handlers = [InterceptHandler()]
-        log_format = "%(message)s"
+    logging.root.setLevel(log_level)
-        log_formatter = logging.Formatter(fmt=log_format, datefmt=date_format)
+
-        rh = aprsd_logging.APRSDRichHandler(
+    # remove every other logger's handlers
-            show_thread=True, thread_width=20,
+    # and propagate to root logger
-            rich_tracebacks=True, omit_repeated_times=False,
+    for name in logging.root.manager.loggerDict.keys():
+        logging.getLogger(name).handlers = []
+        if name in ["imapclient.imaplib", "imaplib", "imapclient", "imapclient.util"]:
+            logging.getLogger(name).propagate = False
+        else:
+            logging.getLogger(name).propagate = True
+
+    handlers = [
+        {
+            "sink": sys.stdout, "serialize": False,
+            "format": CONF.logging.logformat,
+        },
+    ]
+    if CONF.logging.logfile:
+        handlers.append(
+            {
+                "sink": CONF.logging.logfile, "serialize": False,
+                "format": CONF.logging.logformat,
+            },
         )
-        rh.setFormatter(log_formatter)
-        LOG.addHandler(rh)
-        rich_logging = True
 
-    log_file = CONF.logging.logfile
-    log_format = CONF.logging.logformat
-    log_formatter = logging.Formatter(fmt=log_format, datefmt=date_format)
-
-    if log_file:
-        fh = RotatingFileHandler(log_file, maxBytes=(10248576 * 5), backupCount=4)
-        fh.setFormatter(log_formatter)
-        LOG.addHandler(fh)
-
-    imap_logger = None
     if CONF.email_plugin.enabled and CONF.email_plugin.debug:
-        imap_logger = logging.getLogger("imapclient.imaplib")
+        imaps = [
-        imap_logger.setLevel(log_level)
+            "imapclient.imaplib", "imaplib", "imapclient",
-        if rh:
+            "imapclient.util",
-            imap_logger.addHandler(rh)
+        ]
-        if fh:
+        for name in imaps:
-            imap_logger.addHandler(fh)
+            logging.getLogger(name).propagate = True
 
     if CONF.admin.web_enabled:
         qh = logging.handlers.QueueHandler(logging_queue)
-        q_log_formatter = logging.Formatter(
+        handlers.append(
-            fmt=CONF.logging.logformat,
+            {
-            datefmt=CONF.logging.date_format,
+                "sink": qh, "serialize": False,
+                "format": CONF.logging.logformat,
+            },
         )
-        qh.setFormatter(q_log_formatter)
-        LOG.addHandler(qh)
 
-    if not quiet and not rich_logging:
+    # configure loguru
-        sh = logging.StreamHandler(sys.stdout)
+    logger.configure(handlers=handlers)
-        sh.setFormatter(log_formatter)
-        LOG.addHandler(sh)
-        if imap_logger:
-            imap_logger.addHandler(sh)
 
 
 def setup_logging_no_config(loglevel, quiet):

aprsd/log/rich.py

@@ -1,160 +0,0 @@
-from datetime import datetime
-from logging import LogRecord
-from pathlib import Path
-from typing import TYPE_CHECKING, Callable, Iterable, List, Optional, Union
-
-from rich._log_render import LogRender
-from rich.logging import RichHandler
-from rich.text import Text, TextType
-from rich.traceback import Traceback
-
-
-if TYPE_CHECKING:
-    from rich.console import Console, ConsoleRenderable, RenderableType
-    from rich.table import Table
-
-from aprsd import utils
-
-
-FormatTimeCallable = Callable[[datetime], Text]
-
-
-class APRSDRichLogRender(LogRender):
-
-    def __init__(
-        self, *args,
-        show_thread: bool = False,
-        thread_width: Optional[int] = 10,
-        **kwargs,
-    ):
-        super().__init__(*args, **kwargs)
-        self.show_thread = show_thread
-        self.thread_width = thread_width
-
-    def __call__(
-            self,
-            console: "Console",
-            renderables: Iterable["ConsoleRenderable"],
-            log_time: Optional[datetime] = None,
-            time_format: Optional[Union[str, FormatTimeCallable]] = None,
-            level: TextType = "",
-            path: Optional[str] = None,
-            line_no: Optional[int] = None,
-            link_path: Optional[str] = None,
-            thread_name: Optional[str] = None,
-    ) -> "Table":
-        from rich.containers import Renderables
-        from rich.table import Table
-
-        output = Table.grid(padding=(0, 1))
-        output.expand = True
-        if self.show_time:
-            output.add_column(style="log.time")
-        if self.show_thread:
-            rgb = str(utils.rgb_from_name(thread_name)).replace(" ", "")
-            output.add_column(style=f"rgb{rgb}", width=self.thread_width)
-        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")
-        row: List["RenderableType"] = []
-        if self.show_time:
-            log_time = log_time or console.get_datetime()
-            time_format = time_format or self.time_format
-            if callable(time_format):
-                log_time_display = time_format(log_time)
-            else:
-                log_time_display = Text(log_time.strftime(time_format))
-            if log_time_display == self._last_time and self.omit_repeated_times:
-                row.append(Text(" " * len(log_time_display)))
-            else:
-                row.append(log_time_display)
-                self._last_time = log_time_display
-        if self.show_thread:
-            row.append(thread_name)
-        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(":")
-                path_text.append(
-                    f"{line_no}",
-                    style=f"link file://{link_path}#{line_no}" if link_path else "",
-                )
-            row.append(path_text)
-
-        output.add_row(*row)
-        return output
-
-
-class APRSDRichHandler(RichHandler):
-    """APRSD's extension of rich's RichHandler to show threads.
-
-        show_thread (bool, optional): Show the name of the thread in log entry. Defaults to False.
-        thread_width (int, optional): The number of characters to show for thread name. Defaults to 10.
-     """
-
-    def __init__(
-        self, *args,
-        show_thread: bool = True,
-        thread_width: Optional[int] = 10,
-        **kwargs,
-    ):
-        super().__init__(*args, **kwargs)
-        self.show_thread = show_thread
-        self.thread_width = thread_width
-        kwargs["show_thread"] = show_thread
-        kwargs["thread_width"] = thread_width
-        self._log_render = APRSDRichLogRender(
-            show_time=True,
-            show_level=True,
-            show_path=True,
-            omit_repeated_times=False,
-            level_width=None,
-            show_thread=show_thread,
-            thread_width=thread_width,
-        )
-
-    def render(
-        self, *, record: LogRecord,
-        traceback: Optional[Traceback],
-        message_renderable: "ConsoleRenderable",
-    ) -> "ConsoleRenderable":
-        """Render log for display.
-
-        Args:
-            record (LogRecord): log Record.
-            traceback (Optional[Traceback]): Traceback instance or None for no Traceback.
-            message_renderable (ConsoleRenderable): Renderable (typically Text) containing log message contents.
-
-        Returns:
-            ConsoleRenderable: Renderable to display log.
-        """
-        path = Path(record.pathname).name
-        level = self.get_level_text(record)
-        time_format = None if self.formatter is None else self.formatter.datefmt
-        log_time = datetime.fromtimestamp(record.created)
-        thread_name = record.threadName
-
-        log_renderable = self._log_render(
-            self.console,
-            [message_renderable] if not traceback else [
-                message_renderable,
-                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,
-            thread_name=thread_name,
-        )
-        return log_renderable

dev-requirements.txt

@@ -9,8 +9,8 @@ alabaster==0.7.16         # via sphinx
 autoflake==1.5.3          # via gray
 babel==2.14.0             # via sphinx
 black==24.2.0             # via gray
-build==1.0.3              # via pip-tools
+build==1.1.1              # via pip-tools
-cachetools==5.3.2         # via tox
+cachetools==5.3.3         # via tox
 certifi==2024.2.2         # via requests
 cfgv==3.4.0               # via pre-commit
 chardet==5.2.0            # via tox
@@ -19,7 +19,7 @@ click==8.1.7              # via black, fixit, moreorless, pip-tools
 colorama==0.4.6           # via tox
 commonmark==0.9.1         # via rich
 configargparse==1.7       # via gray
-coverage[toml]==7.4.2     # via pytest-cov
+coverage[toml]==7.4.3     # via pytest-cov
 distlib==0.3.8            # via virtualenv
 docutils==0.20.1          # via sphinx
 exceptiongroup==1.2.0     # via pytest
@@ -52,7 +52,7 @@ pyflakes==3.2.0           # via autoflake, flake8
 pygments==2.17.2          # via rich, sphinx
 pyproject-api==1.6.1      # via tox
 pyproject-hooks==1.0.0    # via build, pip-tools
-pytest==8.0.1             # via -r dev-requirements.in, pytest-cov
+pytest==8.0.2             # via -r dev-requirements.in, pytest-cov
 pytest-cov==4.1.0         # via -r dev-requirements.in
 pyupgrade==3.15.1         # via gray
 pyyaml==6.0.1             # via libcst, pre-commit
@@ -71,7 +71,7 @@ toml==0.10.2              # via autoflake
 tomli==2.0.1              # via black, build, coverage, fixit, mypy, pip-tools, pyproject-api, pyproject-hooks, pytest, tox
 tox==4.13.0               # via -r dev-requirements.in
 trailrunner==1.4.0        # via fixit
-typing-extensions==4.9.0  # via black, libcst, mypy, typing-inspect
+typing-extensions==4.10.0  # via black, libcst, mypy, typing-inspect
 typing-inspect==0.9.0     # via libcst
 unify==0.5                # via gray
 untokenize==0.1.1         # via unify

requirements.in

@@ -37,3 +37,4 @@ shellingham
 geopy
 rush
 dataclasses-json
+loguru

requirements.txt

@@ -38,8 +38,9 @@ importlib-metadata==7.0.1  # via ax253, kiss3
 itsdangerous==2.1.2       # via flask
 jinja2==3.1.3             # via click-completion, flask
 kiss3==8.0.0              # via -r requirements.in
+loguru==0.7.2             # via -r requirements.in
 markupsafe==2.1.5         # via jinja2, werkzeug
-marshmallow==3.20.2       # via dataclasses-json
+marshmallow==3.21.0       # via dataclasses-json
 mypy-extensions==1.0.0    # via typing-inspect
 netaddr==1.2.1            # via oslo-config
 oslo-config==9.4.0        # via -r requirements.in
@@ -58,7 +59,7 @@ pyyaml==6.0.1             # via -r requirements.in, oslo-config
 requests==2.31.0          # via -r requirements.in, oslo-config, update-checker
 rfc3986==2.0.0            # via oslo-config
 rich==12.6.0              # via -r requirements.in
-rpyc==5.3.1               # via -r requirements.in
+rpyc==6.0.0               # via -r requirements.in
 rush==2021.4.0            # via -r requirements.in
 shellingham==1.5.4        # via -r requirements.in, click-completion
 simple-websocket==1.0.0   # via python-engineio
@@ -67,7 +68,7 @@ soupsieve==2.5            # via beautifulsoup4
 stevedore==5.2.0          # via oslo-config
 tabulate==0.9.0           # via -r requirements.in
 thesmuggler==1.0.1        # via -r requirements.in
-typing-extensions==4.9.0  # via typing-inspect
+typing-extensions==4.10.0  # via typing-inspect
 typing-inspect==0.9.0     # via dataclasses-json
 update-checker==0.18.0    # via -r requirements.in
 urllib3==2.2.1            # via requests