Qix-/better-exceptions

not work with tornado

chen19901225 opened this issue · 2 comments

env:

"sys": "win10",
"python: "python3.6.5",
"tornado": "5.0.2",
"better-excpetions": "0.2.1"

demo

# coding: utf-8
import sys
import better_exceptions
better_exceptions.hook()
from tornado import  gen
from tornado.ioloop import IOLoop


@gen.coroutine
def main():
    b = 1 + 1
    assert b == 3

def ping(loop:IOLoop, timeout=2):
    loop.add_callback(lambda : ping(loop, timeout))

if __name__ == '__main__':
    loop = IOLoop.current()
    loop.add_callback(main)
    ping(loop, timeout=1)
    loop.start()

outuput

ERROR:tornado.application:Exception in callback functools.partial(<function wrap.<locals>.null_wrapper at 0x0000018EA688B378>, <Future finished exception=AssertionError()>)
Traceback (most recent call last):
  File "C:\Python36\lib\site-packages\tornado\ioloop.py", line 759, in _run_callback
    ret = callback()
  File "C:\Python36\lib\site-packages\tornado\stack_context.py", line 276, in null_wrapper
    return fn(*args, **kwargs)
  File "C:\Python36\lib\site-packages\tornado\ioloop.py", line 780, in _discard_future_result
    future.result()
  File "C:\Python36\lib\site-packages\tornado\gen.py", line 296, in wrapper
    result = func(*args, **kwargs)
  File "C:\Python36\lib\types.py", line 248, in wrapped
    coro = func(*args, **kwargs)
  File "F:/Seafile/Nutstore/pycode/cqh_exceptions/try_tornado.py", line 12, in main
    assert b == 3
AssertionError

Thanks for reporting this bug and for the code sample!

You can fix this by adding better_exceptions.patch_logging() at the top of your main() or ping() function (but prefer a place where it will be called only once). 😉

Technical explanation follows.


So, tornado reports exceptions through the logging system. better_exceptions does patch the loggers to format the errors on the fly, it does so by modifying existing handlers and by setting the _defaultFormatter of the logging module to a custom one.

However, while creating a root handler, the basicConfig() function (used by tornardo) of the logging module makes directly use of the Formatter class rather than the default one.

As a result, if you import and hook better_exceptions before calling basicConfig(), the root logger will be configured with a non-patched formatter. Calling .hook() after basicConfig() should fix it, but this can't be done easily here as the tornardo logger configuration is delayed. Also, it worth noting that calling getLogger("some.submodule") may force a call to _fixupParents() with the side-effect of patching the existing handlers.

It is quite unfortunate that better_exceptions does not effectively patch delayed logger created with basicConfig(), but for now I do not know how to fix it without introducing ugly mocking.