Python 日志打印之自定义logger handler

日志打印之自定义logger handler

By:授客 QQ：1033553122

#实践环境

WIN 10

Python 3.6.5

#实践代码

handler.py

#!/usr/bin/env python

# -*- coding:utf-8 -*-

'''

@Author : shouke

'''

import logging

import logging.config

class MyLogHandler(logging.Handler, object):

    """

    自定义日志handler

    """

    def __init__(self, name, other_attr=None, **kwargs):

        logging.Handler.__init__(self)

        print('初始化自定义日志处理器：', name)

        print('其它属性值：', other_attr)

    def emit(self, record):

        """

        emit函数为自定义handler类时必重写的函数，这里可以根据需要对日志消息做一些处理，比如发送日志到服务器

        发出记录(Emit a record)

        """

        try:

            msg = self.format(record)

            print('获取到的消息为：', msg)

            for item in dir(record):

                if item in ['process', 'processName', 'thread', 'threadName']:

                    print(item, '：', getattr(record, item))

        except Exception:

            self.handleError(record)

# 测试

logging.basicConfig()

logger = logging.getLogger("logger")

logger.setLevel(logging.INFO)

my_log_handler = MyLogHandler('LoggerHandler')

logger.addHandler(my_log_handler)

logger.info('hello，shouke')

运行handler.py，结果输出如下

初始化自定义日志处理器： LoggerHandler

其它属性值： None

获取到的消息为： hello，shouke

process ： 27932

processName ： MainProcess

thread ： 45464

threadName ： MainThread

INFO:logger:hello，shouke

#通过字典配置添加自定义handler

mytest.py(与handler.py位于同一层级目录)

#!/usr/bin/env python

# -*- coding:utf-8 -*-

#

#

# '''

# @CreateTime: 2020/12/29 14:08

# @Author : shouke

# '''

#

import logging

import logging.config

LOGGING_CONFIG = {

    "version": 1,

    "disable_existing_loggers": False,

    "formatters": {

        "default": {

            "format":"%(asctime)s %(filename)s %(lineno)s %(levelname)s ： %(message)s",

        },

        "plain": {

            "format": "%(message)s",

        }

    },

    "handlers": {

        "customer_handler":{

            "class":"study.MyLogHandler",

            "formatter":"default",

            # 注意，class，formatter，level，filters之外的参数将默认传递给由class指定类的构造函数

            "name":"LoggerHandler",

            "other_attr":"something others"

        },

        "console": {

            "class": "logging.StreamHandler",

            "formatter": "default",

        },

    },

    "loggers": {

        "customer_logger":{

            "handlers": ["customer_handler", "console"],

            "level": logging.INFO,

            "propagate": False,

        }

    }

}

logging.config.dictConfig(LOGGING_CONFIG)

logger = logging.getLogger('customer_logger')

logger.info('hello，shouke')

运行mytest.py，输出结果如下

初始化自定义日志处理器： LoggerHandler

其它属性值： something others

获取到的消息为： 2021-01-01 17:51:54,661 mytest.py 48 INFO ： hello，shouke

process ： 36280

processName ： MainProcess

thread ： 37316

threadName ： MainThread

INFO:logger:hello，shouke

2021-01-01 17:51:54,661 mytest5.py 48 INFO ： hello，shouke。

##问题：为什么mytest.py中的代码，不能放在study.py中？

如下，在study.py模块，MyLogHandler类之后追加下述代码

LOGGING_CONFIG = {

    "version": 1,

    "disable_existing_loggers": False,

    "formatters": {

        "default": {

            "format":"%(asctime)s %(filename)s %(lineno)s %(levelname)s ： %(message)s",

        }

    },

    "handlers": {

        "customer_handler":{

            "class":"study.MyLogHandler",

            "formatter":"default",

            "name":"LoggerHandler",

            "other_attr":"something others"

        }

    },

    "loggers": {

        "customer_logger":{

            "handlers": ["customer_handler"],

            "level": logging.INFO,

            "propagate": False,

        }

    }

}

logging.config.dictConfig(LOGGING_CONFIG)

logger = logging.getLogger('customer_logger')

logger.info('hello，shouke')

运行mytest.py，输出结果如下

初始化自定义日志处理器： LoggerHandler

其它属性值： something others

获取到的消息为： 2021-01-09 10:48:24,090 study.py 66 INFO ： hello，shouke

process ： 17276

processName ： MainProcess

thread ： 14516

threadName ： MainThread

初始化自定义日志处理器： LoggerHandler

其它属性值： something others

获取到的消息为： 2021-01-09 10:48:24,090 study.py 66 INFO ： hello，shouke

process ： 17276

processName ： MainProcess

thread ： 14516

threadName ： MainThread

如上，可以看到，自定义类构造函数被重复执行，日志消息被重复处理

##原因分析

logging.config.dictConfig(config)函数内部调用了DictConfigurator(config).configure()，而configure函数内DictConfigurator部，根据incremental，handlers等当前日志配置，被执行的分支代码中，会调用

DictConfigurator类实例的configure_handler()方法，该方法中，根据当前配置，又会再次调用DictConfigurator类实例的resolve(self, s)方法，参数s接收handler中class配置项目的值。具体代码如下：

class DictConfigurator(BaseConfigurator):

    # ... 略

    def resolve(self, s):

        """

        Resolve strings to objects using standard import and attribute

        syntax.

        """

        name = s.split('.') # 本例中，s为study.MyLogHandler

        used = name.pop(0)  # used 为study

        try:

            found = self.importer(used) # 这里importer = staticmethod(__import__) # 所以此处代码等同于__import__(used) # 这里导入自定义日志处理器所在模块会导致模块中的logging.config.dictConfig(config)代码再次被执行

            for frag in name:

                used += '.' + frag

                try:

                    found = getattr(found, frag)

                except AttributeError:

                    self.importer(used)

                    found = getattr(found, frag)

            return found

        except ImportError:

            e, tb = sys.exc_info()[1:]

            v = ValueError('Cannot resolve %r: %s' % (s, e))

            v.__cause__, v.__traceback__ = e, tb

            raise v

    def configure_formatter(self, config):

        """Configure a formatter from a dictionary."""

        if '()' in config:

            factory = config['()'] # for use in exception handler

            try:

                result = self.configure_custom(config)

            except TypeError as te:

                if "'format'" not in str(te):

                    raise

                #Name of parameter changed from fmt to format.

                #Retry with old name.

                #This is so that code can be used with older Python versions

                #(e.g. by Django)

                config['fmt'] = config.pop('format')

                config['()'] = factory

                result = self.configure_custom(config)

        else:

            fmt = config.get('format', None)

            dfmt = config.get('datefmt', None)

            style = config.get('style', '%')

            cname = config.get('class', None)

            if not cname:

                c = logging.Formatter

            else:

                c = _resolve(cname)

            result = c(fmt, dfmt, style)

        return result

    # ... 略

    def configure_handler(self, config):

        """Configure a handler from a dictionary."""

        config_copy = dict(config)  # for restoring in case of error

        formatter = config.pop('formatter', None)

        if formatter:

            try:

                formatter = self.config['formatters'][formatter]

            except Exception as e:

                raise ValueError('Unable to set formatter '

                                 '%r: %s' % (formatter, e))

        level = config.pop('level', None)

        filters = config.pop('filters', None)

        if '()' in config:

            c = config.pop('()')

            if not callable(c):

                c = self.resolve(c)

            factory = c

        else:

            cname = config.pop('class')

            klass = self.resolve(cname)

            #Special case for handler which refers to another handler

            if issubclass(klass, logging.handlers.MemoryHandler) and\

                'target' in config:

                try:

                    th = self.config['handlers'][config['target']]

                    if not isinstance(th, logging.Handler):

                        config.update(config_copy)  # restore for deferred cfg

                        raise TypeError('target not configured yet')

                    config['target'] = th

                except Exception as e:

                    raise ValueError('Unable to set target handler '

                                     '%r: %s' % (config['target'], e))

            elif issubclass(klass, logging.handlers.SMTPHandler) and\

                'mailhost' in config:

                config['mailhost'] = self.as_tuple(config['mailhost'])

            elif issubclass(klass, logging.handlers.SysLogHandler) and\

                'address' in config:

                config['address'] = self.as_tuple(config['address'])

            factory = klass

        props = config.pop('.', None)

        kwargs = dict([(k, config[k]) for k in config if valid_ident(k)])

        try:

            result = factory(**kwargs)

        except TypeError as te:

            if "'stream'" not in str(te):

                raise

            #The argument name changed from strm to stream

            #Retry with old name.

            #This is so that code can be used with older Python versions

            #(e.g. by Django)

            kwargs['strm'] = kwargs.pop('stream')

            result = factory(**kwargs)

        if formatter:

            result.setFormatter(formatter)

        if level is not None:

            result.setLevel(logging._checkLevel(level))

        if filters:

            self.add_filters(result, filters)

        if props:

            for name, value in props.items():

                setattr(result, name, value)

        return result

至此，logging.config.dictConfig(config)放自定义日志处理类模块中，导致自定义日志处理类重复被执行的原因已经清楚了。

configure函数内部，根据incremental，handlers等当前日志配置，被执行的分支代码中，也可能执行DictConfigurator类实例的configure_formatter()方法，类似的，该方法中也会调用一个名为_resolve的方法，具体代码如下

def _resolve(name):

    """Resolve a dotted name to a global object."""

    name = name.split('.')

    used = name.pop(0)

    found = __import__(used)

    for n in name:

        used = used + '.' + n

        try:

            found = getattr(found, n)

        except AttributeError:

            __import__(used)

            found = getattr(found, n)

    return found

如果自定义Formatter，把logging.config.dictConfig(config)放自定义日志格式化类模块中，也可能导致重复执行

巴特西

Python 日志打印之自定义logger handler

最新文章

热门文章