fluent / fluent-logger-python

A structured logger for Fluentd (Python)
http://fluentd.org/
Other
444 stars 138 forks source link

Fix closing asynchronous handler on Python 3.12. #207

Closed jgoclawski closed 4 months ago

jgoclawski commented 4 months ago

Consider the following example code:

import logging
from fluent import asynchandler

logging.basicConfig(level=logging.INFO)
l = logging.getLogger('fluent.test')
h = asynchandler.FluentHandler('app.follow', host='host', port=24224)
l.addHandler(h)
# l.info({
#   'from': 'userA',
#   'to': 'userB'
# })

On Python 3.12 this throws the following error:

Exception ignored in atexit callback: <function shutdown at 0x7ef7a54709a0>
Traceback (most recent call last):
  File "/home/x/.pyenv/versions/3.12.2/lib/python3.12/logging/__init__.py", line 2272, in shutdown
    h.close()
  File "/home/x/dev/fluent-logger-python/fluent/asynchandler.py", line 24, in close
    super().close()
  File "/home/x/dev/fluent-logger-python/fluent/handler.py", line 267, in close
    self.sender.close()
    ^^^^^^^^^^^
  File "/home/x/dev/fluent-logger-python/fluent/handler.py", line 214, in sender
    self._sender = self.getSenderInstance(
                   ^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/x/dev/fluent-logger-python/fluent/handler.py", line 240, in getSenderInstance
    return sender_class(
           ^^^^^^^^^^^^^
  File "/home/x/dev/fluent-logger-python/fluent/asyncsender.py", line 85, in __init__
    self._send_thread.start()
  File "/home/x/.pyenv/versions/3.12.2/lib/python3.12/threading.py", line 992, in start
    _start_new_thread(self._bootstrap, ())
RuntimeError: can't create new thread at interpreter shutdown

On Python 3.12 starting a new thread during interpreter shutdown raises an exception. When using fluent-logger-python such exception can happen when a process configured fluent handler, but did not use it to emit any records, so there was no sender created and no thread active. At the same time - handler is closed automatically with atexit hook (that's a good thing) by default, so on interpreter shutdown. Calling handler.close() on a handler that did not emit any logs before, makes it create a sender, so that it can be immediately closed as well. But creating a sender also tries to create a thread - and this fails.

This commit takes the following approach: use the default asyncsender when possible, but if it throws RuntimeError it means that the interpreter is shutting down - so let's use the synchronous sender instead, so that the main thread is used instead of spawning a new one.

BTW this is a common issue affecting every Python library that uses threads to send messages. Here's a similar issue for Sentry: https://github.com/getsentry/sentry-python/issues/2299 and a fix: https://github.com/getsentry/sentry-python/pull/2468

methane commented 4 months ago

Would you check #208? I think it is simpler solution.

jgoclawski commented 4 months ago

Thanks for taking the time to look into this! Closing in favour of #208.