Concurrency In Python 简明教程

Benchmarking and Profiling

在本章中，我们了解基准测试和性能测量工具如何帮助解决性能问题。

In this chapter, we will learn how benchmarking and profiling help in addressing performance issues.

假设我们编写了一个代码，它也给出了期望的结果，但是如果我们希望更快地运行此代码，因为需求已经改变，该怎么办。在这种情况下，我们需要找出我们代码的哪些部分正在拖慢整个程序。在这种情况下，基准测试和性能测量工具可能会有所帮助。

Suppose we had written a code and it is giving the desired result too but what if we want to run this code a bit faster because the needs have changed. In this case, we need to find out what parts of our code are slowing down the entire program. In this case, benchmarking and profiling can be useful.

What is Benchmarking?

基准测试的目标是通过与标准进行比较来评估一些东西。然而，这里出现的一个问题是什么是基准测试，以及为什么我们需要它来进行软件编程。对代码进行基准测试表示代码执行速度有多快以及瓶颈在哪里。进行基准测试的一个主要原因是它可以优化代码。

Benchmarking aims at evaluating something by comparison with a standard. However, the question that arises here is that what would be the benchmarking and why we need it in case of software programming. Benchmarking the code means how fast the code is executing and where the bottleneck is. One major reason for benchmarking is that it optimizes the code.

How does benchmarking work?

如果我们讨论基准测试的工作原理，我们需要从将整个程序作为当前状态之一进行基准测试开始，然后我们可以组合微基准测试，然后将程序分解成更小的程序。为了找到我们程序中的瓶颈并对其进行优化。换句话说，我们可以将其理解为将大而困难的问题分解成一系列更小和更简单的问题，以便对它们进行优化。

If we talk about the working of benchmarking, we need to start by benchmarking the whole program as one current state then we can combine micro benchmarks and then decompose a program into smaller programs. In order to find the bottlenecks within our program and optimize it. In other words, we can understand it as breaking the big and hard problem into series of smaller and a bit easier problems for optimizing them.

Python module for benchmarking

在 Python 中，我们有一个用于基准测试的默认模块，称为 timeit 。借助 timeit 模块，我们可以在主程序中测量小型 Python 代码执行所需的时间。

In Python, we have a by default module for benchmarking which is called timeit. With the help of the timeit module, we can measure the performance of small bit of Python code within our main program.

Example

在以下 Python 脚本中，我们导入 timeit 模块，它进一步测量执行两个函数 - functionA 和 functionB - 所花费的时间：

In the following Python script, we are importing the timeit module, which further measures the time taken to execute two functions – functionA and functionB −

import timeit
import time
def functionA():
   print("Function A starts the execution:")
   print("Function A completes the execution:")
def functionB():
   print("Function B starts the execution")
   print("Function B completes the execution")
start_time = timeit.default_timer()
functionA()
print(timeit.default_timer() - start_time)
start_time = timeit.default_timer()
functionB()
print(timeit.default_timer() - start_time)

运行上述脚本后，我们将获得如下所示的两个函数的执行时间。

After running the above script, we will get the execution time of both the functions as shown below.

Output

Function A starts the execution:
Function A completes the execution:
0.0014599495514175942
Function B starts the execution
Function B completes the execution
0.0017024724827479076

Writing our own timer using the decorator function

在 Python 中，我们可以创建我们自己的计时器，它们的行为会像 timeit 模块一样。借助 decorator 函数即可完成此操作。以下是自定义计时器的示例 −

In Python, we can create our own timer, which will act just like the timeit module. It can be done with the help of the decorator function. Following is an example of the custom timer −

import random
import time

def timer_func(func):

   def function_timer(*args, **kwargs):
   start = time.time()
   value = func(*args, **kwargs)
   end = time.time()
   runtime = end - start
   msg = "{func} took {time} seconds to complete its execution."
      print(msg.format(func = func.__name__,time = runtime))
   return value
   return function_timer

@timer_func
def Myfunction():
   for x in range(5):
   sleep_time = random.choice(range(1,3))
   time.sleep(sleep_time)

if __name__ == '__main__':
   Myfunction()

上述 python 脚本有助于导入随机时间模块。我们创建了 timer_func() 装饰器函数。它有内部的 function_timer() 函数。现在，嵌套函数将在调用通过的函数之前获取时间。然后，它等待函数返回并获取结束时间。通过这种方式，我们最终可以让 Python 脚本打印执行时间。该脚本会生成如下所示的输出。

The above python script helps in importing random time modules. We have created the timer_func() decorator function. This has the function_timer() function inside it. Now, the nested function will grab the time before calling the passed in function. Then it waits for the function to return and grabs the end time. In this way, we can finally make python script print the execution time. The script will generate the output as shown below.

Output

Myfunction took 8.000457763671875 seconds to complete its execution.

What is profiling?

有时，程序员想要测量某些属性，比如程序的内存使用量、时间复杂度或特定指令的使用情况，以测量程序的实际性能。此类程序测量称为分析。分析使用动态程序来进行此类测量。

Sometimes the programmer wants to measure some attributes like the use of memory, time complexity or usage of particular instructions about the programs to measure the real capability of that program. Such kind of measuring about program is called profiling. Profiling uses dynamic program analysis to do such measuring.

在后续部分中，我们将会了解用于分析的不同 Python 模块。

In the subsequent sections, we will learn about the different Python Modules for Profiling.

cProfile – the inbuilt module

cProfile 是用于分析的 Python 内置模块。该模块是开销合理的 C 扩展，这使其适用于分析运行时间较长的程序。运行它后，它会记录所有函数和执行时间。它非常强大，但有时有点难以解释和使用。在以下示例中，我们在下面代码中使用了 cProfile −

cProfile is a Python built-in module for profiling. The module is a C-extension with reasonable overhead that makes it suitable for profiling long-running programs. After running it, it logs all the functions and execution times. It is very powerful but sometimes a bit difficult to interpret and act on. In the following example, we are using cProfile on the code below −

Example

def increment_global():

   global x
   x += 1

def taskofThread(lock):

   for _ in range(50000):
   lock.acquire()
   increment_global()
   lock.release()

def main():
   global x
   x = 0

   lock = threading.Lock()

   t1 = threading.Thread(target=taskofThread, args=(lock,))
   t2 = threading.Thread(target= taskofThread, args=(lock,))

   t1.start()
   t2.start()

   t1.join()
   t2.join()

if __name__ == "__main__":
   for i in range(5):
      main()
   print("x = {1} after Iteration {0}".format(i,x))

上述代码保存在 thread_increment.py 文件中。现在，在命令行中使用 cProfile 运行代码，如下所示 −

The above code is saved in the thread_increment.py file. Now, execute the code with cProfile on the command line as follows −

(base) D:\ProgramData>python -m cProfile thread_increment.py
x = 100000 after Iteration 0
x = 100000 after Iteration 1
x = 100000 after Iteration 2
x = 100000 after Iteration 3
x = 100000 after Iteration 4
      3577 function calls (3522 primitive calls) in 1.688 seconds

   Ordered by: standard name

   ncalls tottime percall cumtime percall filename:lineno(function)

   5 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:103(release)
   5 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:143(__init__)
   5 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:147(__enter__)
   … … … …

从上述输出中，清楚的是 cProfile 打印出已调用的所有 3577 个函数，以及占用每个函数的时间和调用次数。以下是我们在输出中获得的列 −

From the above output, it is clear that cProfile prints out all the 3577 functions called, with the time spent in each and the number of times they have been called. Followings are the columns we got in output −

  1. ncalls − It is the number of calls made.

  2. tottime − It is the total time spent in the given function.

  3. percall − It refers to the quotient of tottime divided by ncalls.

  4. cumtime − It is the cumulative time spent in this and all subfunctions. It is even accurate for recursive functions.

  5. percall − It is the quotient of cumtime divided by primitive calls.

  6. filename:lineno(function) − It basically provides the respective data of each function.