深入浅出Python日志打印

见贤思齐

0.引言在编程过程中，日志记录是一项非常重要的任务，无论是用于调试代码、记录系统运行状态，还是跟踪可能出现的问题，日志都能发挥重要作用。然而，许多开发者习惯使用简单的print语句来记录信息，这种方法虽然简单，但在处理复杂的日志记录任务时，会显得力不从心。Python的logging模块是Python标准库的一部分，它提供了丰富的配置选项和灵活的接口，能够帮助我们更好地进行日志记录。无论是简单的将日志消息输出到控制台，还是将日志消息发送到远程服务器，logging模块都能轻松应对。本文主要介绍python中打印日志的方法，并分享一些实践技巧，给出使用logging模块的过程中遇到问题的解决办法，帮助你更有效地使用这个工具。1.基本概念在给出具体的代码示例之前，先来了解logging模块的基本概念，理解这些基本概念是使用Pythonlogging模块的关键。1.1日志级别（LogLevels）Python的logging模块定义了五种日志级别，用于区分日志信息的重要性。从低到高依次为：DEBUG,INFO,WARNING,ERROR,CRITICAL。DEBUG：用于调试目的，记录所有详细的信息。INFO：用于记录正常运行时的事件，确认事情按预期进行。WARNING：用于表示可能的问题，它不会阻止程序运行，但可能会在将来。ERROR：用于记录更严重的问题，它阻止了程序执行某个功能。CRITICAL：用于记录非常严重的问题，可能导致程序无法运行。1.2日志记录器（Loggers）Logger是执行日志记录操作的主要接口。每个Logger实例都有一个名字，这些名字是层次化的，像文件系统路径一样，使用点分隔。这使得在应用程序的不同部分可以有细粒度的控制，包括日志消息的处理方式和日志级别。1.3日志处理器（Handlers）Handler对象负责将LogRecord分发到指定的目的地。logging模块提供了多种Handler类，可以将日志消息发送到控制台、文件、网络服务器等。你也可以创建自己的Handler类来满足特殊需求。1.4日志过滤器（Filters）Filter可以提供更细粒度的控制，决定哪些日志记录将被输出。它们可以被应用于Logger和Handler对象上，用于决定是否处理或输出特定的LogRecord。1.5日志格式化（Formatters）Formatter对象用于配置日志信息的最终顺序、结构和内容。它们可以添加时间戳、消息级别、调用者信息等。通过自定义Formatter，你可以让日志信息满足各种格式要求。2.基本用法2.1日志的初始化及分级打印上一章节中提到，logger作为日志的记录器，是可以被初始化的，logging.getLogger()函数用于返回一个Logger对象，如果没有指定name参数，将返回rootlogger。这个函数只有一个参数：name：Logger的名称，这个名称通常是模块名，比如__name__。如果没有指定name，将返回rootlogger。如果我们为getLogger()函数提供了name参数，那么它将返回一个以这个name命名的Logger对象。如果这个Logger之前已经被创建过，那么将返回之前创建的Logger对象；如果这个Logger之前没有被创建过，那么将创建一个新的Logger对象并返回。在创建新的Logger对象时，它的日志级别默认为NOTSET，处理器列表为空。如果我们为这个Logger设置了处理器，那么它就可以处理日志消息；否则，它将会忽略所有的日志消息。如果我们没有为这个Logger设置日志级别，那么它将会继承其父Logger的日志级别。最简单的方式，直接引入logging类之后就可以在需要打印日志的地方完成日志打印，这时使用的logger为rootlogger。importlogginglogging.debug('Thisisadebugmessage')logging.info('Thisisaninfomessage')logging.warning('Thisisawarningmessage')logging.error('Thisisanerrormessage')logging.critical('Thisisacriticalmessage')12345678以上输出结果为：WARNING:root:ThisisawarningmessageERROR:root:ThisisanerrormessageCRITICAL:root:Thisisacriticalmessage1234注意，debug和info级别的消息没有被输出，这是因为默认的日志级别设置为WARNING，只有此级别及以上的消息才会被记录。直接引入rootlogger时，所有的属性用的都是默认配置，正常情况下，需要单独创建一个logger.importlogging#创建一个Loggerlogger=logging.getLogger('my_logger')#设置Logger的级别logger.setLevel(logging.DEBUG)1234562.2定义Handler创建完logger之后，需要定义Handler，不同的Handler可以将日志内容输出到不同地方，logger的addHandler方法可以添加Handler，一个logger可以添加多个Handler。#创建一个Handler，用于写入日志文件file_handler=logging.FileHandler('my_logger.log')#再创建一个Handler，用于输出到控制台console_handler=logging.StreamHandler()#此处定义Handler的日志格式，代码见2.3#给Logger添加Handlerlogger.addHandler(file_handler)logger.addHandler(console_handler)123456789101112以下是Pythonlogging模块中提供的一些常见Handler类的主要功能和构造参数：Handler类主要功能构造参数StreamHandler将日志信息输出到任何可以写入的流（如：sys.stdout,sys.stderr或任何文件-like对象）。strm=NoneFileHandler将日志信息写入到磁盘文件中。filename,mode='a',encoding=None,delay=FalseRotatingFileHandler将日志信息写入到磁盘文件，并支持日志文件按大小切割。filename,mode='a',maxBytes=0,backupCount=0,encoding=None,delay=FalseTimedRotatingFileHandler将日志信息写入到磁盘文件，并支持按照某个时间间隔切割日志文件。filename,when='h',interval=1,backupCount=0,encoding=None,delay=False,utc=False,atTime=NoneSocketHandler将日志信息通过TCP/IP协议发送到网络。host,portDatagramHandler将日志信息通过UDP协议发送到网络。host,portSMTPHandler将日志信息通过电子邮件发送。mailhost,fromaddr,toaddrs,subject,credentials=None,secure=None,timeout=1.0SysLogHandler将日志信息发送到一个Unixsyslog守护进程。address=('localhost',SYSLOG_UDP_PORT),facility=LOG_USER,socktype=socket.SOCK_DGRAMNTEventLogHandler将日志信息发送到一个WindowsNT/2000/XP的事件日志。appname,dllname=None,logtype='Application'MemoryHandler将日志信息缓存到内存中，到达某个水平后或者特定的情况下再将它们写入到目标位置。capacity,flushLevel=ERROR,target=None,flushOnClose=True以上就是logging模块中提供的一些Handler类，每种Handler都有其特定的应用场景，除了上述的Handler，还可以通过继承现有的Handler，做一些个性化的定制，来满足一些特殊的需求，如笔者通过继承RotatingFileHandler，实现了RotatingFileZipHandler，当日志的大小超出大小的阈值时，将其压缩归档，以节省存储空间。2.3定义Formatter对于不同的Handler，可以定义不同的日志格式。Handler中的setFormatter方法可以定义的日志格式。#定义Handler的输出格式formatter=logging.Formatter('%(asctime)s-%(name)s-%(levelname)s-%(message)s')file_handler.setFormatter(formatter)console_handler.setFormatter(formatter)12345在Python的logging模块中，通过设置Formatter可以自定义日志信息的输出格式。Formatter使用字符串格式化操作，可以在字符串中插入一些特殊的字段，这些字段会被替换为LogRecord的相应属性。以下是一些常见的字段：%(name)s：Logger的名字。%(levelno)s：数字形式的日志级别。%(levelname)s：文本形式的日志级别。%(pathname)s：调用日志记录函数的源码文件的全路径。%(filename)s：pathname的文件名部分。%(module)s：filename的名称部分，不包括后缀。%(lineno)d：调用日志记录函数的源码所在的行号。%(funcName)s：调用日志记录函数的函数名。%(message)s：日志记录的文本内容，通过msg%args计算得到。此外，还可以使用以下字段表示日期和时间：%(asctime)s：产生日志的时间，可通过asctime属性自定义时间格式。%(created)f：LogRecord被创建的时间，表示为从UNIX纪元开始的秒数。%(relativeCreated)d：LogRecord被创建的时间，表示为相对于logging模块加载的秒数。%(msecs)d：LogRecord被创建的时间的毫秒部分。%(thread)d：线程ID。可能没有在所有平台上可用。%(threadName)s：线程名。当执行logger.info('Thisisalogmessage.')，以上定义的logger的效果为：2023-11-1523:57:27,956-my_logger-INFO-Thisisalogmessage.这将会生成包含时间、Logger名称、日志级别和日志消息的日志记录，这条记录可以在控制台和my_logger.log中看到。2.4定义Filter过滤器的工作原理是提供一个filter()方法，这个方法接受一个LogRecord对象作为参数，如果这个方法返回True，这条日志记录会被处理，如果返回False，这条日志记录会被忽略。以下是一个简单的过滤器示例，这个过滤器只允许INFO级别的日志记录通过：importloggingclassInfoFilter(logging.Filter):deffilter(self,record):returnrecord.levelno==logging.INFOlogger=logging.getLogger(__name__)handler=logging.StreamHandler()handler.addFilter(InfoFilter())logger.addHandler(handler)logger.setLevel(logging.DEBUG)logger.debug('Thisisadebugmessage')logger.info('Thisisaninfomessage')logger.warning('Thisisawarningmessage')1234567891011121314151617运行这段代码，你会看到只有"INFO:main:Thisisaninfomessage"被输出。其他的日志记录都被InfoFilter过滤掉了。在实际应用中，我们可以定义更复杂的过滤器，比如基于日志记录的其他属性（如logger的名字、日志消息的内容等）来决定是否处理这条日志记录。3.高级用法3.1使用多个处理器使用多个处理器，可以为不同的日志级别设置不同的输出目标和格式。importlogging#创建一个Loggerlogger=logging.getLogger('my_logger')logger.setLevel(logging.DEBUG)#创建一个Handler，用于写入日志文件fh=logging.FileHandler('my_logger.log')fh.setLevel(logging.WARNING)#再创建一个Handler，用于输出到控制台ch=logging.StreamHandler()ch.setLevel(logging.DEBUG)#定义Handler的输出格式formatter=logging.Formatter('%(asctime)s-%(name)s-%(levelname)s-%(message)s')fh.setFormatter(formatter)ch.setFormatter(formatter)#给Logger添加Handlerlogger.addHandler(fh)logger.addHandler(ch)#记录一条日志logger.debug('Thisisadebugmessage')1234567891011121314151617181920212223242526在这段代码中，我们创建了一个Logger，并为它添加了两个Handler：一个FileHandler用于将所有级别及以上的日志信息写入到文件，一个StreamHandler用于将WARNING级别以上的日志信息输出到控制台。通过不同的Handler，可以实现不同方式的分级记录，可以让控制台只记录关键日志，而日志文件记录详细日志，这样便于在运行中发现问题，进而到日志文件中去进一步定位问题。3.2配置日志记录器的层次结构配置日志记录器的层次结构，可以在不同的模块和组件中进行更细粒度的日志控制。importlogging#创建一个Loggerlogger=logging.getLogger('my_logger')logger.setLevel(logging.DEBUG)#创建一个名为'my_module'的子Loggermodule_logger=logging.getLogger('my_logger.my_module')module_logger.setLevel(logging.WARNING)#创建一个Handler，用于写入日志文件fh=logging.FileHandler('my_logger.log')fh.setLevel(logging.DEBUG)formatter=logging.Formatter('%(asctime)s-%(name)s-%(levelname)s-%(message)s')fh.setFormatter(formatter)#给Logger添加Handlerlogger.addHandler(fh)#使用子Logger记录一条日志module_logger.debug('Thisisadebugmessage')module_logger.warning('Thisisawarningmessage')1234567891011121314151617181920212223在这段代码中，我们创建了一个名为’my_module’的子Logger，它继承自’my_logger’这个父Logger。我们可以为每个子Logger设置不同的日志级别，以便在不同的模块和组件中进行更细粒度的日志控制。4.日志的配置除了用代码的方式实现初始化，还可以通过配置来让Logger的初始化一步到位，logger提供了三种配置方式。4.1使用logging.basicConfig()函数进行简单配置logging.basicConfig(**kwargs)函数提供了一种简单的方式来配置默认的logging模块。你可以通过关键字参数来指定日志的等级、日志格式、输出目标等。以下是一段示例代码：importlogginglogging.basicConfig(level=logging.INFO,format='%(asctime)s-%(name)s-%(levelname)s-%(message)s',filename='app.log')logging.info('Thisisaloginfo')logging.warning('Thisisalogwarning')123456789在这个例子中，我们使用logging.basicConfig()函数来配置logging模块。level参数指定了日志的等级，format参数指定了日志的格式，filename参数指定了日志的输出文件。4.2使用logging.config.dictConfig()函数加载字典配置logging.config.dictConfig(config)函数可以接受一个字典作为参数，用于配置logging模块。这个字典可以包含handlers、formatters、filters和loggers等配置信息。以下是一段示例代码：importlogging.configconfig={'version':1,'handlers':{'console':{'class':'logging.StreamHandler','level':'INFO','formatter':'simple','stream':'ext://sys.stdout',}},'root':{'level':'INFO','handlers':['console']}}logging.config.dictConfig(config)logging.info('Thisisaloginfo')123456789101112131415161718192021在这个例子中，我们定义了一个字典config，然后使用logging.config.dictConfig()函数来配置logging模块。字典中的handlers键用于定义处理器，root键用于定义rootlogger。4.3使用logging.config.fileConfig()函数加载配置文件logging.config.fileConfig(fname,defaults=None,disable_existing_loggers=True)函数可以加载一个INI格式的配置文件，用于配置logging模块。以下是一个配置文件的例子：[loggers]keys=root,sampleLogger[handlers]keys=consoleHandler[formatters]keys=sampleFormatter[logger_root]level=DEBUGhandlers=consoleHandler[logger_sampleLogger]level=DEBUGhandlers=consoleHandlerqualname=sampleLoggerpropagate=0[handler_consoleHandler]class=StreamHandlerlevel=DEBUGformatter=sampleFormatterargs=(sys.stdout,)[formatter_sampleFormatter]format=%(asctime)s-%(name)s-%(levelname)s-%(message)sdatefmt=1234567891011121314151617181920212223242526272829然后我们可以使用logging.config.fileConfig()函数来加载这个配置文件：importlogging.configlogging.config.fileConfig('logging.ini')logger=logging.getLogger('sampleLogger')logger.debug('Thisisalogdebug')1234567在这个例子中，我们使用logging.config.fileConfig()函数加载了一个名为logging.ini的配置文件，然后获取了一个名为sampleLogger的logger，并使用这个logger打印了一条debug日志。在实际使用中，建议采用logging.config.fileConfig()来配置日志文件，一方面减少了定义日志的代码量，另一方面也让日志的定义参数都集中在一个文件中，提高了可读性的同时，也便于后期维护。5.最佳实践5.1如何正确的在模块和包中使用日志记录器在每个模块或包中，都应该创建一个名为“__name__”的logger对象。这将创建一个以模块完全限定名称（全路径）为名的logger，当你查看调试输出时，将允许你清楚地看到哪个模块生成了记录项。创建logger的示例代码如下：importlogginglogger=logging.getLogger(__name__)deffunction_with_logging():logger.info('Thisisaninfomessagefrom{}module.'.format(__name__))1234567这种方式可以让你在其他模块中轻松控制日志级别，且不会影响别的模块。根logger可以通过名字为空字串来获取。5.2如何避免日志记录性能问题大量的日志记录会带来性能问题。对于加了多个Filter的情况，在你记录一条消息之前，通常需要检查它的级别是否会被logger处理。示例代码如下：iflogger.isEnabledFor(logging.INFO):logger.info("Thisisaninfomessage")123这将避免一些不必要的计算和内存分配，即使日志消息最终不会被处理。5.3如何处理多线程和多进程环境下的日志记录logging模块是线程安全的，所以你可以在多线程环境中安全地使用它。为了避免记录交错问题，你可以使用threading模块提供的Lock。示例代码如下：importloggingimportthreadinglogger=logging.getLogger(__name__)lock=threading.Lock()deffunction_with_threadsafe_logging():withlock:logger.info('Thisisathread-safeinfomessagefrom{}module.'.format(__name__))12345678910在多进程环境下，一种常见的方法是每个进程记录到一个独立的文件，或使用concurrent_log_handler包的ConcurrentRotatingFileHandler。总的来说，应用logging模块的最佳实践依赖于你的具体需求和环境。无论工程规模大小，编写清晰、整洁的日志都是专业开发者的一个标志。5.4如何用装饰器优雅地打印日志关于logging模块，可以结合装饰器使用，以下是一个使用装饰器封装日志的例子：importtimeimportloggingdefget_logger(name):logger=logging.getLogger(name)ch=logging.StreamHandler()ch.setLevel(logging.DEBUG)ch.setFormatter(logging.Formatter('%(levelname)s|%(name)s|%(message)s'))logger.addHandler(ch)returnloggerdefexec_log(func):defwrapper(*args,**kwargs):logger=get_logger(func.__name__)logger.setLevel(logging.DEBUG)logger.info('开始执行[%s]:%s'%(func.__name__,args[0]))start_time=time.time()result=func(*args,**kwargs)end_time=time.time()logger.info('执行结束,总耗时：%fs'%(end_time-start_time))logger.info('执行结果:%s'%result)returnresultreturnwrapper@exec_logdefapp(name):print(name)returnnameif__name__=='__main__':app('test1')app('test2')app('test3')12345678910111213141516171819202122232425262728293031323334在上述的例子中，采用装饰器的方法封装日志，带来的好处也是显而易见的。通过装饰器，我们可以在一个地方定义日志记录的逻辑，然后在需要记录日志的地方重复使用这个逻辑。这样就避免了在每个需要记录日志的地方重复编写日志记录的代码。同时可以将日志记录的代码从主要的业务逻辑代码中分离出来，让业务逻辑代码更加简洁，可读性更强。但是上面的代码在执行的时候会存在一个日志重复打印的问题。以上代码的输出如下：INFO|app|开始执行[app]:test1INFO|app|执行结束,总耗时：0.000000sINFO|app|执行结果:test1INFO|app|开始执行[app]:test2INFO|app|开始执行[app]:test2INFO|app|执行结束,总耗时：0.000000sINFO|app|执行结束,总耗时：0.000000sINFO|app|执行结果:test2INFO|app|执行结果:test2INFO|app|开始执行[app]:test3INFO|app|开始执行[app]:test3INFO|app|开始执行[app]:test3INFO|app|执行结束,总耗时：0.000000sINFO|app|执行结束,总耗时：0.000000sINFO|app|执行结束,总耗时：0.000000sINFO|app|执行结果:test3INFO|app|执行结果:test3INFO|app|执行结果:test312345678910111213141516171819为解决此问题，让我们进入下一节讨论的内容。5.5如何避免日志重复打印当我们在多层依赖中引入logger模块时，除了上一节中提到的装饰器，还有同时在子类和父类中定义Logger都有可能会遇到日志重复打印的问题。为解决此问题，首先需要分析日志重复的原因，在参考文章（blog.csdn.net/qq_31455841…）中，详细探讨了日志重复打印的原因。文中给出了日志重复打印的两种情况：未定义logger默认使用了RootLogger，一个python程序内全局唯一的，所有Logger对象的祖先，每次实例化返回的都是RootLogger对象通过logger=logging.getLogger(name)定义了logger该方法采用了单例模式，也就是说每次实例化返回的是同一个logger对象，在获取logger对象之后，每次都会调用logger.addHandler(handler)方法添加日志处理器，导致handlers列表添加了相同的handler（注意：日志的打印由handler控制）以此类推，调用几次就会有几个handler，然后前面打印的log就会影响后面定义的log。以5.4中的代码为例，可以采用以下几种方法解决日志重复打印的问题：定义不同的logger名以区分不同的logger比如上一节中在logging.getLogger(name)中传入不同的name以示区分。但对于同样一个业务逻辑，定义太多的logger也会带来额外的性能开销，因此可以进一步从Handler中入手。根据情况判断是否addHandlerdefget_logger(name):logger=logging.getLogger(name)ifnotlogger.handlers:ch=logging.StreamHandler()ch.setLevel(logging.DEBUG)ch.setFormatter(logging.Formatter('%(levelname)s|%(name)s|%(message)s'))logger.addHandler(ch)returnlogger123456789使用完成之后执行`removeHandlerdefexec_log(func):defwrapper(*args,**kwargs):logger=get_logger(func.__name__)logger.setLevel(logging.DEBUG)logger.info('开始执行[%s]:%s'%(func.__name__,args[0]))start_time=time.time()result=func(*args,**kwargs)end_time=time.time()logger.info('执行结束,总耗时：%fs'%(end_time-start_time))logger.info('执行结果:%s'%result)#在日志打印完成之后删除loggerforhandleinlogger.handlers:logger.removeHandler(handle)returnresultreturnwrapper123456789101112131415166全文小结我们希望通过这篇文章，读者可以全面了解Pythonlogging模块，掌握如何使用这个模块进行有效的日志记录。无论是在开发过程中调试问题，还是在生产环境中监控应用状态，日志记录都是一个非常重要的工具。通过合理地使用logging模块，我们可以更好地了解和控制我们的应用，提高开发和运维的效率。如果你对Python感兴趣，想要学习python，这里给大家分享一份Python全套学习资料，都是我自己学习时整理的，希望可以帮到你，一起加油！😝有需要的小伙伴，可以V扫描下方二维码免费领取🆓​1️⃣零基础入门①学习路线对于从来没有接触过Python的同学，我们帮你准备了详细的学习成长路线图。可以说是最科学最系统的学习路线，你可以按照上面的知识点去找对应的学习资源，保证自己学得较为全面。②路线对应学习视频还有很多适合0基础入门的学习视频，有了这些视频，轻轻松松上手Python~③练习题每节视频课后，都有对应的练习题哦，可以检验学习成果哈哈！2️⃣国内外Python书籍、文档①文档和书籍资料3️⃣Python工具包+项目源码合集①Python工具包学习Python常用的开发软件都在这里了！每个都有详细的安装教程，保证你可以安装成功哦！②Python实战案例光学理论是没用的，要学会跟着一起敲代码，动手实操，才能将自己的所学运用到实际当中去，这时候可以搞点实战案例来学习。100+实战案例源码等你来拿！③Python小游戏源码如果觉得上面的实战案例有点枯燥，可以试试自己用Python编写小游戏，让你的学习过程中增添一点趣味！4️⃣Python面试题我们学会了Python之后，有了技能就可以出去找工作啦！下面这些面试题是都来自阿里、腾讯、字节等一线互联网大厂，并且有阿里大佬给出了权威的解答，刷完这一套面试资料相信大家都能找到满意的工作。