[issue42097] Python 3.7.9 logging/threading/fork hang

[Andrew de Quincey]

Andrew de Quincey <Adq at tvsquared.com> added the comment:

Debugging a bit more shows our code is deadlocked at:
  File "/usr/lib/python3.7/logging/__init__.py", line 219, in _acquireLock
    _lock.acquire()
  File "/usr/lib/python3.7/logging/config.py", line 501, in configure
    logging._acquireLock()
  File "/usr/lib/python3.7/logging/config.py", line 800, in dictConfig
    dictConfigClass(config).configure()
  File "/home/backend/backend/lib/request.py", line 591, in init
    logging.config.dictConfig(getLoggingDict(loglevel=self.loglevel))



Looking at other threads, I found this:
  File "/usr/lib/python3.7/logging/__init__.py", line 219, in _acquireLock
    _lock.acquire()
  File "/usr/lib/python3.7/logging/__init__.py", line 776, in _removeHandlerRef
    acquire()
  Garbage-collecting
  File "/home/backend/backend/lib/common/log/logstash.py", line 13, in fix_log_message
    for k, v in logmessage.items():
  File "/home/backend/backend/lib/common/log/logstash.py", line 14, in fix_log_message
    logmessage[k] = self.fix_log_message(v)
  File "/home/backend/backend/lib/common/log/logstash.py", line 14, in fix_log_message
    logmessage[k] = self.fix_log_message(v)
  File "/home/backend/backend/lib/common/log/logstash.py", line 14, in fix_log_message
    logmessage[k] = self.fix_log_message(v)
  File "/home/backend/backend/lib/common/log/logstash.py", line 66, in format
    return self.serialize(self.fix_log_message(message))
  File "/home/backend/venv/lib/python3.7/site-packages/logstash/handler_tcp.py", line 25, in makePickle
    return self.formatter.format(record) + b'\n'
  File "/usr/lib/python3.7/logging/handlers.py", line 631, in emit
    s = self.makePickle(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 894, in handle
    self.emit(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 1586, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 1524, in handle
    self.callHandlers(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 1514, in _log
    self.handle(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 1378, in info
    self._log(INFO, msg, args, **kwargs)



It looks like its trying to free a lock that is already locked during garbage collection?

----------

_______________________________________
Python tracker <report at bugs.python.org>
<https://bugs.python.org/issue42097>
_______________________________________