Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

BUG-3536 - fix RichHandler not handling exception #3557

Open
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

jakub-mrow
Copy link

@jakub-mrow jakub-mrow commented Nov 10, 2024

Type of changes

  • Bug fix
  • New feature
  • Documentation / docstrings
  • Tests
  • Other

Checklist

  • I've run the latest black with default args on new code.
  • I've updated CHANGELOG.md and CONTRIBUTORS.md where appropriate.
  • I've added tests for new code.
  • I accept that @willmcgugan may be pedantic in the code review.

Description

RichHandler does not handle exceptions raised while formatting the log message, unlike default builtin Python handlers. The issue lies in emit method implementation.

Fixes #3536

rich/logging.py Outdated
@@ -131,7 +131,11 @@ def get_level_text(self, record: LogRecord) -> Text:

def emit(self, record: LogRecord) -> None:
"""Invoked by logging."""
message = self.format(record)
try:
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since there's a fair bit of logic below which may also fail, I'd lean towards wrapping the entire method implementation within the try block, similar to the approach used in StreamHandler:

    def emit(self, record):
        """
        Emit a record.

        If a formatter is specified, it is used to format the record.
        The record is then written to the stream with a trailing newline.  If
        exception information is present, it is formatted using
        traceback.print_exception and appended to the stream.  If the stream
        has an 'encoding' attribute, it is used to determine how to do the
        output to the stream.
        """
        try:
            msg = self.format(record)
            stream = self.stream
            # issue 35046: merged two stream.writes into one.
            stream.write(msg + self.terminator)
            self.flush()
        except RecursionError:  # See issue 36272
            raise
        except Exception:
            self.handleError(record)

I've just tested your solution with log.warning("hello {}", 123) and found that another exception is raised from the following line:

        message_renderable = self.render_message(record, message)

To keep the original implementation clean, you may want to consider something like this:

    ...
    def _emit(self, record: LogRecord) -> None:
        ...
        # original emit implementation
        ...

    def emit(self, record: LogRecord) -> None:
        try:
            return self._emit(record)
        except Exception:
            self.handleError(record)

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the feedback, I am gonna apply the changes

Copy link

@snejus snejus left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Now that's much better!

[ins] In [21]: class Obj:
          ...:     def __str__(self):
          ...:         return 1 / 0

[ins] In [22]: log.warning("hello, %s", Obj())
--- Logging error ---
Traceback (most recent call last):
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/rich/logging.py", line 134, in emit
    return self._emit(record)
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/rich/logging.py", line 140, in _emit
    message = self.format(record)
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 929, in format
    return fmt.format(record)
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 668, in format
    record.message = record.getMessage()
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 373, in getMessage
    msg = msg % self.args
  File "<ipython-input-21-435b0030d1a2>", line 3, in __str__
    return 1 / 0
ZeroDivisionError: division by zero
Call stack:
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/bin/ptipython", line 8, in <module>
    sys.exit(run())
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/ptpython/entry_points/run_ptipython.py", line 72, in run
    embed(
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/ptpython/ipython.py", line 323, in embed
    shell(header=header, stack_depth=2, compile_flags=compile_flags)
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/terminal/embed.py", line 251, in __call__
    self.mainloop(
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/terminal/embed.py", line 343, in mainloop
    self.interact()
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/terminal/interactiveshell.py", line 881, in interact
    self.run_cell(code, store_history=True)
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/core/interactiveshell.py", line 3009, in run_cell
    result = self._run_cell(
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/core/interactiveshell.py", line 3064, in _run_cell
    result = runner(coro)
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/core/async_helpers.py", line 129, in _pseudo_sync_runner
    coro.send(None)
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/core/interactiveshell.py", line 3269, in run_cell_async
    has_raised = await self.run_ast_nodes(code_ast.body, cell_name,
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/core/interactiveshell.py", line 3448, in run_ast_nodes
    if await self.run_code(code, result, async_=asy):
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/IPython/core/interactiveshell.py", line 3508, in run_code
    exec(code_obj, self.user_global_ns, self.user_ns)
  File "<ipython-input-22-2a9d22421568>", line 1, in <module>
    log.warning("hello, %s", Obj())
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 1458, in warning
    self._log(WARNING, msg, args, **kwargs)
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 1589, in _log
    self.handle(record)
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 1599, in handle
    self.callHandlers(record)
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 1661, in callHandlers
    hdlr.handle(record)
  File "/home/sarunas/.local/share/pyenv/versions/3.8/lib/python3.8/logging/__init__.py", line 954, in handle
    self.emit(record)
  File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.8/lib/python3.8/site-packages/rich/logging.py", line 136, in emit
    self.handleError(record)
Message: 'hello, %s'
Arguments: (<__main__.Obj object at 0x7f34ad95bd60>,)

Let's wait and see what @willmcgugan thinks 😃

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

RichHandler does not handle log formatting exceptions
2 participants