Skip to content

Commit

Permalink
feat: add rich exception formatting, configurable from logging.yaml (
Browse files Browse the repository at this point in the history
  • Loading branch information
Ken Payne committed Sep 5, 2022
1 parent cf3566e commit bc97d63
Show file tree
Hide file tree
Showing 7 changed files with 246 additions and 17 deletions.
6 changes: 3 additions & 3 deletions docs/src/_guide/logging.md
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ A logging.yaml contains a few key sections that you should be aware of.
A few key points to note:

1. Different handlers can use different formats. Meltano ships with [3 formatters](https://github.com/meltano/meltano/blob/main/src/meltano/core/logging/formatters.py):
- `meltano.core.logging.console_log_formatter` - A formatter that renders lines for the console, with optional colorization.
- `meltano.core.logging.console_log_formatter` - A formatter that renders lines for the console, with optional colorization. When colorization is enabled, tracebacks are formatted with the `rich` python library.
- `meltano.core.logging.json_log_formatter` - A formatter that renders lines in JSON format.
- `meltano.core.logging.key_value` - A formatter that renders lines in key=value format.
2. Different loggers can use different handlers and log at different log levels.
Expand All @@ -40,10 +40,10 @@ formatters:
format: "[%(asctime)s] [%(process)d|%(threadName)10s|%(name)s] [%(levelname)s] %(message)s"
structured_plain: # log format for structured plain text logs without colored output
(): meltano.core.logging.console_log_formatter
colors: False
colors: False # also disables `rich` traceback formatting
structured_colored: # log format for structured plain text logs WITH colored output
(): meltano.core.logging.console_log_formatter
colors: True
colors: True # also enables traceback formatting with `rich`
key_value: # log format for traditional key=value style logs
(): meltano.core.logging.key_value_formatter
sort_keys: False
Expand Down
37 changes: 36 additions & 1 deletion poetry.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

1 change: 1 addition & 0 deletions pyproject.toml
Original file line number Diff line number Diff line change
Expand Up @@ -65,6 +65,7 @@ structlog = "^21.2.0"
tzlocal = "^4.2.0"
uvicorn = {extras = ["standard"], version = "^0.17.6"}
werkzeug = ">=2.1,<=2.1.3"
rich = "^12.5.1"

[tool.poetry.extras]
infra = ["ansible"]
Expand Down
68 changes: 59 additions & 9 deletions src/meltano/core/logging/formatters.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,11 +2,16 @@

from __future__ import annotations

from typing import Sequence
from typing import Sequence, TextIO

import click
import structlog
from rich.console import Console
from rich.traceback import Traceback, install
from structlog.types import Processor

install(suppress=[click])

TIMESTAMPER = structlog.processors.TimeStamper(fmt="iso")

LEVELED_TIMESTAMPED_PRE_CHAIN = frozenset(
Expand All @@ -19,37 +24,82 @@
)


def _process_formatter(processor: Processor):
def plain_rich_traceback(sio: TextIO, exc_info: structlog.types.ExcInfo) -> None:
"""Pretty-print `exc_info` to `sio` using the rich package, with colors disabled.
To be passed into `ConsoleRenderer`'s `exception_formatter` argument.
Args:
sio: Return of open() in text mode.
exc_info: Execution info.
"""
sio.write("\n")
Console(file=sio, no_color=True).print(
Traceback.from_exception(*exc_info, show_locals=True)
)


def _process_formatter(processor: Processor) -> structlog.stdlib.ProcessorFormatter:
"""Use _process_formatter to configure a structlog.stdlib.ProcessFormatter.
It will automatically add log level and timestamp fields to any log entries not originating from structlog.
Args:
processor: A structlog message processor such as structlog.dev.ConsoleRenderer.
Returns:
A configured log processor.
"""
return structlog.stdlib.ProcessorFormatter(
processor=processor, foreign_pre_chain=LEVELED_TIMESTAMPED_PRE_CHAIN
)


def console_log_formatter(colors: bool = False) -> None:
"""Create a logging formatter for console rendering that supports colorization."""
return _process_formatter(structlog.dev.ConsoleRenderer(colors=colors))
def console_log_formatter(colors: bool = False) -> structlog.stdlib.ProcessorFormatter:
"""Create a logging formatter for console rendering that supports colorization.
Args:
colors: Add color to output.
Returns:
A configured console log formatter.
"""
exception_formatter = (
structlog.dev.rich_traceback if colors else plain_rich_traceback
)
return _process_formatter(
structlog.dev.ConsoleRenderer(
colors=colors, exception_formatter=exception_formatter
)
)


def key_value_formatter(
sort_keys: bool = False,
key_order: Sequence[str] | None = None,
drop_missing: bool = False,
) -> None:
"""Create a logging formatter that renders lines in key=value format."""
) -> structlog.stdlib.ProcessorFormatter:
"""Create a logging formatter that renders lines in key=value format.
Args:
sort_keys: Whether to sort keys when formatting.
key_order: List of keys that should be rendered in this exact order. Missing keys will be rendered as None, extra keys depending on *sort_keys* and the dict class.
drop_missing: When True, extra keys in *key_order* will be dropped rather than rendered as None.
Returns:
A configured key=value formatter.
"""
return _process_formatter(
processor=structlog.processors.KeyValueRenderer(
sort_keys=sort_keys, key_order=key_order, drop_missing=drop_missing
)
)


def json_formatter() -> None:
"""Create a logging formatter that renders lines in JSON format."""
def json_formatter() -> structlog.stdlib.ProcessorFormatter:
"""Create a logging formatter that renders lines in JSON format.
Returns:
A configured JSON formatter.
"""
return _process_formatter(processor=structlog.processors.JSONRenderer())
88 changes: 85 additions & 3 deletions src/meltano/core/logging/output_logger.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
"""Output Logger."""
from __future__ import annotations

import asyncio
Expand All @@ -19,7 +20,14 @@


class OutputLogger:
"""Output Logger."""

def __init__(self, file):
"""Instantiate an Output Logger.
Args:
file: A file to output to.
"""
self.file = file
self.stdout = sys.stdout
self.stderr = sys.stderr
Expand Down Expand Up @@ -55,25 +63,66 @@ def out(


class LineWriter:
"""Line Writer."""

def __init__(self, out):
"""Instantiate a Line Writer.
Args:
out: The location to write to.
"""
self.__out = out

def __getattr__(self, name):
"""Get attribute.
Args:
name: The attribute name.
Returns:
The specified attributes value.
"""
return getattr(self.__out, name)

def write(self, line):
"""Write a line.
Args:
line: A line to write.
"""
self.__out.writeline(line.rstrip())


class FileDescriptorWriter:
"""File Descriptor Writer."""

def __init__(self, out, fd):
"""Instantiate File Descriptor Writer.
Args:
out: Output location.
fd: A file descriptor.
"""
self.__out = out
self.__writer = os.fdopen(fd, "w")

def __getattr__(self, name):
"""Get attribute.
Args:
name: The attribute name.
Returns:
The specified attributes value.
"""
return getattr(self.__writer, name)

def isatty(self):
"""Is out location a tty.
Returns:
True if output location is a tty.
"""
return self.__out.isatty()


Expand Down Expand Up @@ -113,7 +162,9 @@ def redirect_log_handler(self) -> logging.Handler:
logging.FileHandler using an uncolorized console formatter
"""
formatter = structlog.stdlib.ProcessorFormatter(
processor=structlog.dev.ConsoleRenderer(colors=False),
processor=structlog.dev.ConsoleRenderer(
colors=False, exception_formatter=structlog.dev.plain_traceback
),
foreign_pre_chain=LEVELED_TIMESTAMPED_PRE_CHAIN,
)
handler = logging.FileHandler(self.file)
Expand All @@ -122,11 +173,23 @@ def redirect_log_handler(self) -> logging.Handler:

@contextmanager
def line_writer(self):
"""Yield a line writer instance.
Yields:
A line writer instance
"""
yield LineWriter(self)

@contextmanager
def redirect_logging(self, ignore_errors=()):
"""Redirect log entries to a temporarily added file handler."""
"""Redirect log entries to a temporarily added file handler.
Args:
ignore_errors: A tuple of Error classes to ignore.
Yields:
With the side-effect of redirecting logging.
""" # noqa: DAR401
logger = logging.getLogger()
logger.addHandler(self.redirect_log_handler)
ignored_errors = (
Expand All @@ -146,6 +209,11 @@ def redirect_logging(self, ignore_errors=()):

@asynccontextmanager
async def writer(self):
"""Yield a writer.
Yields:
A writer.
"""
read_fd, write_fd = os.pipe()

reader = asyncio.ensure_future(self._read_from_fd(read_fd))
Expand All @@ -161,18 +229,32 @@ async def writer(self):

@asynccontextmanager
async def redirect_stdout(self):
"""Redirect STDOUT.
Yields:
A writer with redirected output.
"""
async with self.writer() as stdout:
with redirect_stdout(stdout):
yield

@asynccontextmanager
async def redirect_stderr(self):
"""Redirect STDERR.
Yields:
A writer with redirected output.
"""
async with self.writer() as stderr:
with redirect_stderr(stderr):
yield

def writeline(self, line: str) -> None:
"""Write a line to the underlying structured logger, cleaning up any dangling control chars."""
"""Write a line to the underlying structured logger, cleaning up any dangling control chars.
Args:
line: A line to write.
"""
self.last_line = line
self.logger.log(self.write_level, line.rstrip(), name=self.name)

Expand Down
4 changes: 3 additions & 1 deletion src/meltano/core/logging/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,9 @@ def default_config(log_level: str) -> dict:
"formatters": {
"colored": {
"()": structlog.stdlib.ProcessorFormatter,
"processor": structlog.dev.ConsoleRenderer(colors=True),
"processor": structlog.dev.ConsoleRenderer(
colors=True, exception_formatter=structlog.dev.rich_traceback
),
"foreign_pre_chain": LEVELED_TIMESTAMPED_PRE_CHAIN,
},
},
Expand Down

0 comments on commit bc97d63

Please sign in to comment.