在Python中记录信号

ryevplcw  于 2023-02-26  发布在  Python
关注(0)|答案(2)|浏览(130)

我有一个单线程的Python应用程序,关闭这个应用程序的标准方法是发送SIGINT,让不同的with:try: finally:块处理安全和优雅的关闭,但是,这会导致日志文件不是特别可读,因为您只是开始看到来自处理程序的消息,而没有清楚地指示正在发生什么或为什么关闭。
我尝试通过添加一个简单的信号处理程序来解决这个问题,该处理程序将在引发KeyboardInterrupt之前记录接收到的信号,如下所示:

def log_and_exit_handler(signum, stack):
    logger.info(f"Terminating due to signal {_signal.Signals(signum)}", stack_info=True)
    raise KeyboardInterrupt()
_signal.signal(_signal.SIGINT, log_and_exit_handler)

但是,在测试时,我得到了一个日志错误:

--- Logging error ---
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1029, in emit
    self.flush()
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1009, in flush
    self.stream.flush()
RuntimeError: reentrant call inside <_io.BufferedWriter name='<stderr>'>
Call stack:
  [REDACTED]
  File "[REDACTED]", line 485, in _save_checkpoint
    _logger.info(f"Checkpoint saved")
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1378, in info
    self._log(INFO, msg, args, **kwargs)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1514, in _log
    self.handle(record)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1524, in handle
    self.callHandlers(record)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1586, in callHandlers
    hdlr.handle(record)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 894, in handle
    self.emit(record)
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1029, in emit
    self.flush()
  File "/usr/local/lib/python3.7/logging/__init__.py", line 1009, in flush
    self.stream.flush()
  File "[REDACTED]", line 203, in log_and_exit_handler
    logger.info("Terminating due to signal {signal_}".format(signal_=signal_), stack_info=True)
Message: 'Terminating due to signal 2'
Arguments: ()

显然,当接收到信号时,应用程序已经在输出日志消息,并且logging模块不可重入。
是否有任何变通方法或替代方法可以安全地实现在接收信号时记录信号的目标?

tmb3ates

tmb3ates1#

我无法重现,所以无法验证这些解决方案。(您是否正在执行一些可能导致对stderr的写入过长的操作?)

避免在log_and_exit_handler中使用标准错误

默认记录器已配置为写入stderr。似乎程序在使用stderr时被中断,因此无法再次访问。实际上,您需要避免程序中可能使用的任何IO。从根记录器中删除stderr处理程序(以避免对stderr的访问尝试),并添加文件处理程序。

使用系统例外挂钩

类似的函数,但是它的默认操作是写stderr,所以应该是安全的。看起来io limition of signal handlers是众所周知的。希望通过异常钩子处理可以绕过它。

hfyxw5xn

hfyxw5xn2#

于是,我终于找到了解决办法:每当我们使用signal.pthread_sigmask()将日志消息写入STDERR时,阻塞有问题的信号,然后在之后解除阻塞。阻塞的信号不会丢失,并且会在移除阻塞后立即处理。

class SignalSafeStreamHandler(logging.StreamHandler):
    """Stream handler that blocks signals while emitting a record.

    The locks for writing to streams like STDERR are not reentrant,
    resulting in a potential logging failure if, while in the process of writing a log message,
    we process a signal and the signal handler tries to log something itself.

    This class keeps a list of signals which have handlers that might try to log anything,
    and blocks those signals for the duration of the write operation.
    After the write op is done, it unblocks the signals, allowing any that arrived during the duration to be processed.
    """

    def __init__(self, stream=None):
        super().__init__(stream=stream)

        self._signals_to_block: _tp.Set[_signal.Signals] = set()

    @property
    def signals_to_block(self) -> _tp.Set[_signal.Signals]:
        """The set of signals to block while writing to the stream"""
        return set(self._signals_to_block)

    def add_blocked_signal(self, signal: _signal.Signals) -> None:
        """Add the given signal to the list of signals to block"""
        self._signals_to_block.add(signal)

    def emit(self, record: logging.LogRecord) -> None:
        """Emit the given record; if this is the main thread, block the set signals while doing so"""

        # Only the main thread is subject to signal handling; other threads can operate normally
        if _threading.current_thread() is not _threading.main_thread():
            super().emit(record)
            return

        # We block any signals which have handlers that want to do logging while we write.
        old_blocked_signals: _tp.Set[_signal.Signals] = _signal.pthread_sigmask(
            _signal.SIG_BLOCK,
            self._signals_to_block,
        )
        try:
            # Delegate to the parent method to do the actual logging
            super().emit(record)
        finally:
            # Now we unblock the signals
            # (or, more precisely, restore the old set of blocked signals;
            # if one of those signals was already blocked when we started, it will stay that way).
            #
            # Any signals of those types which were received in the duration
            # will immediately be processed and their handlers run.
            _signal.pthread_sigmask(_signal.SIG_SETMASK, old_blocked_signals)

_root_handler = SignalSafeStreamHandler()
logging.root.addHandler(_root_handler)

def log_and_exit_handler(signum, stack):
    logger.info(f"Terminating due to signal {_signal.Signals(signum)}", stack_info=True)
    raise KeyboardInterrupt()

_signal.signal(_signal.SIGINT, log_and_exit_handler)
_root_handler.add_blocked_signal(signal)

这个解决方案可以扩展到StreamHandler之外的其他日志处理程序,例如,如果您正在登录到JournalD或DB。但是,对于写操作可能需要花费大量时间才能完成的任何处理程序,请谨慎使用它。例如,如果您正在登录到DB,而DB出现故障,则写操作将冻结,直到DB请求超时。并且你不能提前中断它,因为SIGINT在这段时间内被屏蔽了。一个可能的解决方案是使用一个单独的线程来做日志记录;只有主线程受到信号处理程序的中断。
局限性:信号屏蔽仅在Linux上可用,在Windows上不可用。

相关问题