首页 文章

Python Logger 在未捕获的异常后停止记录

提问于
浏览
11

我们的烧瓶应用程序使用的本机python Logger 似乎在发生异常后停止写入日志 . 每次停止之前记录的最后一个条目是描述异常的消息 . 通常,下一条消息是after_request中的代码写入的消息,但是对于 Logger 停止的情况,永远不会写出after_request消息 .

什么可能导致这个?

注意:我最初在Serverfault(https://serverfault.com/questions/655683/python-logger-stops-logging)上发布了这个问题,认为这是一个基础设施问题 . 但是现在我们已经将问题缩小到异常之后发生的问题,这个问题可能更适合Stackoverflow .

更新[2015年12月22日]:

Logger 实例化:

logging.addLevelName(Config.LOG_AUDIT_LEVEL_NUM, Config.LOG_AUDIT_LEVEL_NAME)

logger = logging.getLogger(Config.LOGGER_NAME)
logger.setLevel(Config.LOG_LEVEL)

handler = SysLogHandler(address='/dev/log', facility=SysLogHandler.LOG_LOCAL3)
handler.setLevel(Config.LOG_LEVEL)

formatter = log_formatter()
handler.setFormatter(formatter)
logger.addHandler(handler)

log_formatter:

class log_formatter(logging.Formatter):

    def __init__(self,
                 fmt=None,
                 datefmt=None,
                 json_cls=None,
                 json_default=_default_json_default):
        """
        :param fmt: Config as a JSON string, allowed fields;
               extra: provide extra fields always present in logs
               source_host: override source host name
        :param datefmt: Date format to use (required by logging.Formatter
            interface but not used)
        :param json_cls: JSON encoder to forward to json.dumps
        :param json_default: Default JSON representation for unknown types,
                             by default coerce everything to a string
        """

        if fmt is not None:
            self._fmt = json.loads(fmt)
        else:
            self._fmt = {}
        self.json_default = json_default
        self.json_cls = json_cls

        if 'extra' not in self._fmt:
            self.defaults = {}
        else:
            self.defaults = self._fmt['extra']

        try:
            self.source_host = socket.gethostname()
        except:
            self.source_host = ""

    def format(self, record):
        """
        Format a log record to JSON, if the message is a dict
        assume an empty message and use the dict as additional
        fields.
        """

        fields = record.__dict__.copy()
        aux_fields = [
            'relativeCreated', 'process', 'args', 'module', 'funcName', 'name',
            'thread', 'created', 'threadName', 'msecs', 'filename', 'levelno',
            'processName', 'pathname', 'lineno', 'levelname'
        ]
        for k in aux_fields:
            del fields[k]

        if isinstance(record.msg, dict):
            fields.update(record.msg)
            fields.pop('msg')
            msg = ""
        else:
            msg = record.getMessage()

        if 'msg' in fields:
            fields.pop('msg')

        if 'exc_info' in fields:
            if fields['exc_info']:
                formatted = tb.format_exception(*fields['exc_info'])
                fields['exception'] = formatted
            fields.pop('exc_info')

        if 'exc_text' in fields and not fields['exc_text']:
            fields.pop('exc_text')

        logr = self.defaults.copy()

        logr = {
            'timestamp': datetime.datetime.utcnow().strftime('%Y-%m-%dT%H:%M:%S.%fZ'),
            'host': self.source_host,
        }
        logr.update(self._build_fields(logr, fields))

        if msg:
            logr['message'] = msg

        something = json.dumps(logr, default=self.json_default, cls=self.json_cls)
        return something

    def _build_fields(self, defaults, fields):
        return dict(defaults.get('fields', {}).items() + fields.items())

更新[01/03/2015]:

回答问题:

Is the application still working after the exception?

是的,应用程序继续运行 .

Which type of exception is raised and what's the cause of it?

内部/自定义异常 . 由于不同类型的异常,Logger已停止 .

Are you using threads in you application?

是的,该应用程序由gunicorn线程 .

How is the logging library used?

我们使用默认的FileHandler,SysLogHandler和自定义格式化程序(输出JSON)

Does it log on a file? Does it use log rotation?

是的,它记录到一个文件,但没有轮换 .

2 回答

  • 0

    您没有提供足够的信息 .

    异常后应用程序是否仍然有效?引发了哪种类型的异常以及它的原因是什么?你在应用程序中使用线程吗?如何使用日志库?它是否登录文件?它是否使用日志轮换?

    假设您在应用程序中使用线程,解释是该异常导致Thread关闭,因此您将看不到该特定线程的任何活动 . 您还应该注意应用程序的问题 .

    如果应用程序仍在工作但变为静默,我的猜测是日志库未正确配置 . 正如您在Serverfault上报告的那样,在添加了fluentd之后似乎出现了问题,这可能与您的应用程序使用日志库的方式不太一致 .

  • 1

    关于 after_request ,来自文档:

    从Flask 0.7开始,如果发生未处理的异常,则可能不会在请求结束时执行此函数 .

    至于您的日志记录问题,可能是您的调试标志设置为true,这将导致调试器启动并可能停止日志记录 .

    参考文献:
    http://flask.pocoo.org/docs/0.10/api/#flask.Flask.after_request
    http://flask.pocoo.org/docs/0.10/errorhandling/#working-with-debuggers

相关问题