聊一聊Python装饰器的代码执行顺序
为什么写这篇文章？
起因是QQ群里边有人提了一个问题：之前导入模块只需要1~2秒，为什么现在变成需要2~3分钟？
我的第一感觉是：是不是导入的模块顶层代码里边，做了什么耗时的事情。隔了一天，他的问题解决了，下边是按照他的代码写了一个类似的例子：
import time
def set_log(func):
def wrap(*args, **kwargs):
return func(*args, **kwargs)
time.sleep(4)
return wrap
@set_log
def demo():
pass
为什么导入这个模块的时候，会运行time.sleep(4)，明明没有调用demo函数呀？这就要从Python装饰器代码的执行顺序说起了。
简单介绍下装饰器
在正式开始之前，先简单科普一下Python的装饰器，装饰器可以对已有的函数，添加额外的功能，甚至于完全改变函数的执行效果。举个例子，现在想统计几个函数的执行耗时，函数是这样的：
import time
import random
def a_func():
time.sleep(random.randint(1, 5))
当然，我们可以这么写
def a_func():
start_time = time.time()
time.sleep(random.randint(1, 5))
print("cost time: {}".format(time.time() - start_time))
这样带来的问题是代码的可维护性不佳，尤其你有多个函数需要计算耗时的时候，万一某天突然想去掉这些统计代码呢~
所以像这种有切面需求的场景，装饰器是一个非常漂亮的设计。
def cost_time(func):
def wrap(*args, **kwargs):
start_time = time.time()
result = func(*args, **kwargs)
print("cost time: {}".format(time.time() - start_time))
return result
return wrap
@cost_time
def a_func():
time.sleep(random.randint(1, 5))
只需要对统计耗时的函数挂上一个装饰器，结果就自动出来，无需改动之前的代码，非常方便。
Python也支持带参数的装饰器，比如刚刚的cost_time加入一个报警机制，如果函数执行耗时大于1秒，就发出警告。
def cost_time(warn=1):
def wrap(func):
def _wrap(*args, **kwargs):
start_time = time.time()
result = func(*args, **kwargs)
cost = time.time() - start_time
print("cost time: {}".format(cost))
if cost > warn:
print("warning, cost time is {} !!!".format(cost))
return result
return _wrap
return wrap
@cost_time()
def a_func():
time.sleep(random.randint(1, 5))
a_func()
执行结果：
cost time: 3.0002505779266357
warning, cost time is 3.0002505779266357 !!!
Python装饰器代码的执行顺序
回到我们的主题，首先把刚刚的例子加入一些打印：
import time
print("准备编写装饰器")
def set_log(func):
print("装饰器顶层代码")
def wrap(*args, **kwargs):
print("装饰器内层代码")
return func(*args, **kwargs)
# time.sleep(4)
print("准备返回wrap对象")
return wrap
print("准备编写demo函数")
@set_log
def demo():
print("正在运行demo函数")
if __name__ == '__main__':
print("准备运行demo函数")
demo()
运行结果是：
准备编写装饰器
准备编写demo函数
装饰器顶层代码
准备返回wrap对象
准备运行demo函数
装饰器内层代码
正在运行demo函数
所以在运行demo函数之前，已经做了：
- 准备编写装饰器
- 准备编写demo函数
- 装饰器顶层代码
- 准备返回wrap对象
也就是说，就算你没有运行demo函数，只是导入了这个模块，上边的这4件事情，都是会一一执行的。
是不是有点懵？
让我们从头开始，梳理一遍这个过程。
Python的代码是从上往下依次执行的，所以当你导入这个模块，第一句运行的代码就是
import time
然后就来到了
print("准备编写装饰器")
接着是来到了set_log装饰器函数的定义
def set_log(func):
需要注意的时候，在这里Python只运行了函数的定义语句，对于函数内部的执行，是直接跳过去的，并没有运行。
继续往下，来到了
print("准备编写demo函数")
此时重点来了，到了demo函数的定义了
@set_log
def demo():
print("正在运行demo函数")
因为代码从上往下依次运行的机制，Python解释器首先到了@set_log这句代码，@这个符号是Python提供的语法糖，它本质上是为了简化了装饰器的写法，上边的写法等于
def demo():
print("正在运行demo函数")
demo = set_log(demo)
于是Python开始执行set_log装饰器，来完成对demo函数的修饰。
def set_log(func):
print("装饰器顶层代码")
def wrap(*args, **kwargs):
print("装饰器内层代码")
return func(*args, **kwargs)
# time.sleep(4)
print("准备返回wrap对象")
return wrap
首先来到的是
print("装饰器顶层代码")
然后是装饰器内部wrap函数的定义，同样是，只运行了定义语句，跳过函数的内部执行代码
def wrap(*args, **kwargs):
然后来到了打印“准备返回wrap对象”，以及返回wrap对象，要注意，在返回了wrap函数对象后，此时demo函数，其实已经被替换成了wrap函数对象。
print("准备返回wrap对象")
return wrap
完成了对demo函数的修饰后，代码也来到了最后的调用demo函数的部分
if __name__ == '__main__':
print("准备运行demo函数")
demo()
新的重点来了~
上边说到，在装饰器内部返回了wrap对象后，demo已经被替换成了wrap函数对象了。
也就说说，运行 demo()，其实就是运行wrap()
def wrap(*args, **kwargs):
print("装饰器内层代码")
return func(*args, **kwargs)
所以代码来到了wrap的函数内部，首先当然就是打印了“装饰器内层代码”。接下来是
return func(*args, **kwargs)
这里的func是不是很眼熟？我们回去看看set_log装饰器的定义：
def set_log(func):
print("装饰器顶层代码")
def wrap(*args, **kwargs):
print("装饰器内层代码")
return func(*args, **kwargs)
# time.sleep(4)
print("准备返回wrap对象")
return wrap
func就是我们一开始传给set_log装饰器修饰的demo函数，还记得上边写的，装饰器的两种写法吗？
@set_log
def demo():
pass
# 等同于：
def demo():
pass
demo = set_log(demo)
于是代码进入到了demo函数的内部去了~
def demo():
print("正在运行demo函数")
执行完毕，最终搞定，一个装饰器的代码执行顺序就是这么走过来的。
最后，再来一个多重+带参数的装饰器的复杂一点的例子~
print("准备编写装饰器")
def set_log_first(func):
print("set_log_first装饰器顶层代码")
def wrap(*args, **kwargs):
print("set_log_first装饰器内层代码")
return func(*args, **kwargs)
print("set_log_first准备返回wrap对象")
return wrap
def set_log_second(times=1):
print("set_log_second装饰器顶层代码")
def wrap(func):
print("set_log_second装饰器中间层代码")
def _wrap(*args, **kwargs):
print("set_log_second装饰器内层代码")
return func(*args, **kwargs)
print("set_log_second准备返回中间层的_wrap对象")
return _wrap
print("set_log_second准备返回顶层的wrap对象")
return wrap
print("准备编写demo函数")
@set_log_first
@set_log_second()
def demo():
print("正在运行demo函数")
if __name__ == '__main__':
print("准备运行demo函数")
demo()
输出是~
准备编写装饰器
准备编写demo函数
set_log_second装饰器顶层代码
set_log_second准备返回顶层的wrap对象
set_log_second装饰器中间层代码
set_log_second准备返回中间层的_wrap对象
set_log_first装饰器顶层代码
set_log_first准备返回wrap对象
准备运行demo函数
set_log_first装饰器内层代码
set_log_second装饰器内层代码
正在运行demo函数
这里理解的重点就是，下边的两个写法是等价的
@set_log_first
@set_log_second()
def demo():
print("正在运行demo函数")
# 等价于
demo = set_log_first(set_log_second()(demo))
装饰器是不是很好玩呢？
