python日志logging配置

  • 为了不便ELK收集日志,将日志打印成json格局
  • 开发过程中,应用json格局不不便排查问题
  • 本文章应用python的logging模块,一步步减少配置,来阐明每个组件作用

原始日志

  • python能够应用两种形式打印
  • python默认打印级别为'WARNING'
import logging# 间接应用logging打印日志logging.info('info')  # 未打印logging.warning('warning')  # WARNING:root:warninglogging.error('error')  # ERROR:root:error# 应用logger打印日志logger = logging.getLogger('demo')logger.info('info')  # 未打印logger.warning('warning')  # WARNING:demo:warninglogger.error('error')  # ERROR:demo:error

应用字典配置

  • version为固定字段,目前为1
  • 将级别设置为'INFO'
import loggingimport logging.configdef use_config():    """配置日志行为"""    config = {"version": 1, "root": {"level": "INFO"}}    logging.config.dictConfig(config)use_config()# 间接应用logging打印日志logging.info('info')  # INFO:root:infologging.warning('warning')  # WARNING:root:warninglogging.error('error')  # ERROR:root:error# 应用logger打印日志logger = logging.getLogger('demo')logger.info('info')  # INFO:demo:infologger.warning('warning')  # WARNING:demo:warninglogger.error('error')  # ERROR:demo:error

记录器

  • "loggers"为指定记录器
  • "root"本质上也是记录器,python默认的记录器

    • logging间接打印日志,相当于logging.getLogger('root')
    • 没有找到记录器名字的应用默认记录器(即'root')
import loggingimport logging.configdef use_config():    """配置日志行为"""    config = {        "version": 1,        "root": {            "level": "WARNING"        },        "loggers": {            "demo": {                "level": "ERROR"            }        }    }    logging.config.dictConfig(config)use_config()# 间接应用logging打印日志logging.info('info')  # 未打印logging.warning('warning')  # WARNING:root:warninglogging.error('error')  # ERROR:root:error# 应用logger打印日志logger = logging.getLogger('demo')logger.info('info')  # 未打印logger.warning('warning')  # 未打印logger.error('error')  # ERROR:demo:error# 未找到记录器时,应用'root'记录器logger2 = logging.getLogger('demo2')logger2.info('info')  # 未打印logger2.warning('warning')  # WARNING:demo2:warninglogger2.error('error')  # ERROR:demo2:error

处理器及格式化器

  • "handlers"为处理器

    • 处理器有很多类型,能够打印屏幕、打印文件、发送邮件、发送http申请等,详情查看Useful Handlers官网文档
    • 记录器中能够指定多个处理器
    • 上面例子打印屏幕
  • "formatters"为格式化器

    • format:应用python内置格式化器格式化日志信息
import loggingimport logging.configdef use_config():    """配置日志行为"""    config = {        "version": 1,        "root": {            "level": "INFO",            "handlers": ["console_handler"]        },        "handlers": {            "console_handler": {                "class": "logging.StreamHandler",                "formatter": "console_formatter",                "stream": "ext://sys.stdout"            }        },        "formatters": {            "console_formatter": {                "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"            }        }    }    logging.config.dictConfig(config)use_config()logging.info('info')  # 2022-10-25 20:16:59,073 - root - INFO - infologging.warning('warning')  # 2022-10-25 20:16:59,073 - root - WARNING - warninglogging.error('error')  # 2022-10-25 20:16:59,074 - root - ERROR - error

自定义格式化器

  • 自定义格式化器继承logging.Formatter,重写format办法
  • 配置中,字段名应用"class"代表自定义格式化器

    • 填入导入该类的字符串,如下代码,在"log_demo.py"文件里的"MyFormatter",即为"log_demo.MyFormatter"
    • 类型导入会执行一遍代码,反复调用配置办法会增加多个处理器,导致打印多遍
    • record中有很多字段,这里不展现,自行打印查看
# log_demo.pyimport loggingimport logging.configclass MyFormatter(logging.Formatter):    def format(self, record: logging.LogRecord) -> str:        """重写日志格式化字符串"""        return f"[{record.name}] [{record.levelname}] {record.msg}"def use_config():    """配置日志行为"""    config = {        "version": 1,        "root": {            "level": "INFO",            "handlers": ["console_handler"]        },        "handlers": {            "console_handler": {                "class": "logging.StreamHandler",                "formatter": "console_formatter",                "stream": "ext://sys.stdout"            }        },        "formatters": {            "console_formatter": {                "class": "log_demo.MyFormatter"            }        }    }    logging.config.dictConfig(config)if __name__ == "__main__":    """    实例化MyFormatter类时,会执行一遍代码    将代码放在__main__里,否则会打印两遍    """    use_config()    logging.info('info') # [root] [INFO] info    logging.warning('warning') # [root] [WARNING] warning    logging.error('error') # [root] [ERROR] error

extra额定字段

  • 日志办法中有"extra"字段,丰盛日志信息
  • 打印
import loggingimport logging.configclass MyFormatter(logging.Formatter):    def format(self, record: logging.LogRecord) -> str:        """重写日志格式化字符串"""        for i in record.__dict__:            print(i, end=',')        print('')        return f"[{record.name}] [{record.levelname}] {record.msg}"def use_config():    """配置日志行为"""    config = {        "version": 1,        "root": {            "level": "INFO",            "handlers": ["console_handler"]        },        "handlers": {            "console_handler": {                "class": "logging.StreamHandler",                "formatter": "console_formatter",                "stream": "ext://sys.stdout"            }        },        "formatters": {            "console_formatter": {                "class": "log_demo.MyFormatter"            }        }    }    logging.config.dictConfig(config)if __name__ == "__main__":    """    实例化MyFormatter类时,会执行一遍代码    将代码放在__main__里,否则会打印两遍    """    use_config()    logging.info('info')    # name,msg,args,levelname,levelno,pathname,filename,module,exc_info,exc_text,stack_info,lineno,funcName,created,msecs,relativeCreated,thread,threadName,processName,process,    # [root] [INFO] info    # extra减少了'a','b',能够看到record对象也减少了'a','b'两个字段    logging.info('extra info', extra={'a': 1, 'b': 2})    # name,msg,args,levelname,levelno,pathname,filename,module,exc_info,exc_text,stack_info,lineno,funcName,created,msecs,relativeCreated,thread,threadName,processName,process,a,b,    # [root] [INFO] extra info

最终代码

  • 减少环境变量"LOG_MODE",用来管制打印行为

    • 为"json"时,打印json格局字符串,提供给ELK收集
    • 为"text"时,打印成文本模式,不便开发时查看
  • json转换时加上"ensure_ascii=False",否则中文会被转换为ASCII

代码

import osimport jsonimport loggingimport logging.configfrom datetime import datetime, timezone, timedeltaclass JsonFormatter(logging.Formatter):    __TZ = timezone(timedelta(hours=+8))    def format(self, record: logging.LogRecord) -> str:        # ELK收集须要应用带时区的工夫戳,key必须为"@timestamp"        create_time = datetime.fromtimestamp(record.created)        kv = {'@timestamp': create_time.astimezone(self.__TZ).isoformat()}        if len(record.args) > 0:            kv['message'] = record.msg % record.args        else:            kv['message'] = record.msg        # 报错信息        if record.exc_info:            kv['err_info'] = self.formatException(record.exc_info)        for k in record.__dict__:            v = getattr(record, k)            # 其余类型json转换可能报错            if v is None or isinstance(v, (int, float, bool, str)):                kv[k] = v            else:                kv[k] = str(v)        return json.dumps(kv, ensure_ascii=False)def use_config():    """配置日志行为"""    if os.environ.get('LOG_MODE') == "json":        format_data = {"class": "log_demo.JsonFormatter"}    else:        format_data = {            "format": "[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s"        }    config = {        "version": 1,        "root": {            "level": "INFO",            "handlers": ["console_handler"]        },        "handlers": {            "console_handler": {                "class": "logging.StreamHandler",                "formatter": "console_formatter",                "stream": "ext://sys.stdout"            }        },        "formatters": {            "console_formatter": format_data        }    }    logging.config.dictConfig(config)if __name__ == "__main__":    use_config()    logging.info('info')    logging.info('extra info', extra={'a': 1, 'b': 2})

text成果

# linux设置环境变量export LOG_MODE=text# windows设置环境变量set LOG_MODE=textpython log_demo.py
[2022-10-26 19:11:07,468] [root] [INFO] info[2022-10-26 19:11:07,468] [root] [INFO] extra info

json成果

# linux设置环境变量export LOG_MODE=json# windows设置环境变量set LOG_MODE=jsonpython log_demo.py
{"@timestamp": "2022-10-26T20:10:42.168191+08:00", "message": "info", "name": "root", "msg": "info", "args": "()", "levelname": "INFO", "levelno": 20, "pathname": "e:\\Work\\Code\\TestCode\\everything\\log_demo.py", "filename": "log_demo.py", "module": "log_demo", "exc_info": null, "exc_text": null, "stack_info": null, "lineno": 66, "funcName": "<module>", "created": 1666786242.168191, "msecs": 168.19095611572266, "relativeCreated": 35.9044075012207, "thread": 22716, "threadName": "MainThread", "processName": "MainProcess", "process": 19576}{"@timestamp": "2022-10-26T20:10:42.169210+08:00", "message": "extra info", "name": "root", "msg": "extra info", "args": "()", "levelname": "INFO", "levelno": 20, "pathname": "e:\\Work\\Code\\TestCode\\everything\\log_demo.py", "filename": "log_demo.py", "module": "log_demo", "exc_info": null, "exc_text": null, "stack_info": null, "lineno": 67, "funcName": "<module>", "created": 1666786242.1692102, "msecs": 169.21019554138184, "relativeCreated": 36.92364692687988, "thread": 22716, "threadName": "MainThread", "processName": "MainProcess", "process": 19576, "a": 1, "b": 2}