为什么写这篇文章？

起因是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))

装饰器是不是很好玩呢？