长年打log突然提出一个问题,logging模块是如何定位到打印log的具体位置(文件、函数、行)的呢?以下从logging模块的源码解决这个问题。
调用栈分析
当代码运行到
logging.debug('debug')
的时候,我们来看看发生了什么。
函数调用路径如下:
函数 | 函数内调用 |
---|---|
logging.debug | Logger()._log |
Logger()._log | Logger().findCaller、 Logger().makeRecord |
Logger().findCaller | currentframe |
currentframe | sys.exc_info |
makeRecord | 调用的函数与本文关系不大 |
以下详细分析这些函数的细节
currentframe函数
currentframe
函数的作用是返回当前的栈帧。实现是制造并捕获一个异常,并通过sys.exc_info函数得到这个异常的信息,实现简单而巧妙。
currentframe函数的实现
def currentframe():
"""Return the frame object for the caller's stack frame."""
try:
raise Exception
except:
return sys.exc_info()[2].tb_frame.f_back
sys.exc_info
函数获取当前正在处理的异常类,exc_type、exc_value、exc_traceback是当前处理的异常详细信息三元组(type, value, traceback)。
sys.exc_info()[2]
返回当前异常的栈,调用tb_frame
返回当前异常的帧,也就是该函数raise Exception
的异常帧,打印log的目的是查看log具体的位置,所以当前的信息肯定是不需要的,所以调用f_back
得到他的outer层,并返回。
此时我们返回到父函数findCaller
findCaller
findCaller
继续子函数currentframe
的f_back
功能,在while循环里面不断追溯上游捕抓Exception的位置,直到当前栈所在文件不是当前的文件_srcfile
为止,实现如下:
def findCaller(self):
f = currentframe() # 调用上面提到的currentframe函数
if f is not None:
f = f.f_back
rv = "(unknown file)", 0, "(unknown function)"
while hasattr(f, "f_code"): # 利用f_code属性
co = f.f_code
filename = os.path.normcase(co.co_filename)
if filename == _srcfile: # 如果上游捕抓的位置是当前文件,那么继续上溯,最终得到打印log的位置
f = f.f_back # 继续上溯
continue
rv = (co.co_filename, f.f_lineno, co.co_name) # 文件名、行数和函数名
break
return rv
# _srcfile定义
_srcfile = os.path.normcase(currentframe.__code__.co_filename) # currentframe函数和findCaller函数在同一个文件里面
返回的rv也是一个三元组(filename、lineno、co_name),包含打印log的文件名、代码行数、函数名字。到这为止,打印log需要的信息就收集到了。
总结
log日志信息的实现是利用异常的捕获机制去做的,我们知道当抛出一个异常的时候,异常会一步一步往上抛,直到得到处理或者程序异常结束为止,这样就一定可以追溯到源头。
另外可以看到,在寻找_srcfile
的时候,调用了__code__
来返回当前代码所属的文件名;在findCaller
里用frame.f_lineno
来获取代码行,用co.co_name
来获取当前函数的名字;等等。可见,得益于强大自省的特性,整体实现简单明了。