• Python 日志打印之自定义logger handler


    日志打印之自定义logger handler

    By:授客 QQ1033553122

    #实践环境

    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)放自定义日志格式化类模块中,也可能导致重复执行

     

    作者:授客
    公众号:授客的知识库
    QQ:1033553122
    全国软件测试QQ交流群:7156436

    Git地址:https://gitee.com/ishouke
    友情提示:限于时间仓促,文中可能存在错误,欢迎指正、评论!
    作者五行缺钱,如果觉得文章对您有帮助,请扫描下边的二维码打赏作者,金额随意,您的支持将是我继续创作的源动力,打赏后如有任何疑问,请联系我!!!
                微信打赏                       支付宝打赏                        授课的知识库               全国软件测试交流QQ群  
                          

  • 相关阅读:
    parallel desktop ubuntu从18.04更新到20.04(包括安装Parallels Tools)
    一段奇怪的R代码
    ipynb(jupyter notebook)的git管理的比较好的方式
    对比jupyterlab和jupyter notebook
    dotfiles的管理
    macvim报出一些奇怪的错误: macvim只能从命令行启动
    CSS3学习笔记(三、选择器-续)
    CSS3学习笔记(二、选择器)
    CSS3学习笔记(一、CSS介绍、语法、引入方式)
    HTML学习笔记(四、body内常用标签)
  • 原文地址:https://www.cnblogs.com/shouke/p/14322704.html
Copyright © 2020-2023  润新知