python效能優化之函式執行時間分析

adison發表於2019-01-13
Python優化函式

最近發現專案API請求比較慢，通過抓包發現主要是response時間太長，於是就開始進行優化工作。優化工作的關鍵一步是定位出問題的瓶頸，對於優化速度來說，從優化函式執行時間這個維度去切入是一個不錯的選擇。

本文側重分析，不展開如何優化

利器

工欲善其事，必先利其器，我們需要一套方便高效的工具記錄函式執行時間。說是一套工具，但對於一個簡單專案或者日常開發來說，實現一個工具類足矣，由於實現比較簡單，直接上程式碼：

from functools import wraps

import cProfile
from line_profiler import LineProfiler

import time


def func_time(f):
    """
    簡單記錄執行時間
    :param f:
    :return:
    """

    @wraps(f)
    def wrapper(*args, **kwargs):
        start = time.time()
        result = f(*args, **kwargs)
        end = time.time()
        print f.__name__, 'took', end - start, 'seconds'
        return result

    return wrapper


def func_cprofile(f):
    """
    內建分析器
    """

    @wraps(f)
    def wrapper(*args, **kwargs):
        profile = cProfile.Profile()
        try:
            profile.enable()
            result = f(*args, **kwargs)
            profile.disable()
            return result
        finally:
            profile.print_stats(sort='time')

    return wrapper



try:
    from line_profiler import LineProfiler


    def func_line_time(follow=[]):
        """
        每行程式碼執行時間詳細報告
        :param follow: 內部呼叫方法
        :return:
        """
        def decorate(func):
            @wraps(func)
            def profiled_func(*args, **kwargs):
                try:
                    profiler = LineProfiler()
                    profiler.add_function(func)
                    for f in follow:
                        profiler.add_function(f)
                    profiler.enable_by_count()
                    return func(*args, **kwargs)
                finally:
                    profiler.print_stats()

            return profiled_func

        return decorate

except ImportError:
    def func_line_time(follow=[]):
        "Helpful if you accidentally leave in production!"
        def decorate(func):
            @wraps(func)
            def nothing(*args, **kwargs):
                return func(*args, **kwargs)

            return nothing

        return decorate
複製程式碼

原始程式碼可以參考gist

如下，實現了3個裝飾器函式func_time,func_cprofile,func_line_time,分別對應

  1. 簡單輸出函式的執行時間
  2. 利用python自帶的內建分析包cProfile 分析，它主要統計函式呼叫以及每個函式所佔的cpu時間
  3. 利用line_profiler開源專案,它可以統計每行程式碼的執行次數和執行時間。

使用說明

我們以一個簡單的迴圈例子來說明一下,

def test():
    for x in range(10000000):
        print x
複製程式碼
  • func_time

關於func_time我覺得沒什麼好說的，就是簡單輸出下函式呼叫時間，這個在我們粗略統計函式執行時間的時候可以使用

如下：

@func_time
def test():
    for x in range(10000000):
        print x
# 輸出
test took 6.10190296173 seconds
複製程式碼
  • func_cprofile

cProfile是python內建包，基於lsprof的用C語言實現的擴充套件應用，執行開銷比較合理，沒有外部依賴，適合做快速的概要測試

@func_cprofile
def test():
 for x in range(10000000):
     print x
# 輸出
      3 function calls in 6.249 seconds

Ordered by: internal time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    6.022    6.022    6.249    6.249 test.py:41(test)
     1    0.227    0.227    0.227    0.227 {range}
     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
複製程式碼

輸出說明：

單位為秒

  1. 第一行告訴我們一共有3個函式被呼叫。

    正常開發過程，第一行更多是輸出類似194 function calls (189 primiive calls) in 0.249 seconds，(189 primiive calls)表示189個是原生（primitive）呼叫，表明這些呼叫不涉及遞迴

  2. ncalls表示函式的呼叫次數，如果這一列有兩個數值，表示有遞迴呼叫，第一個是總呼叫次數，第二個是原生呼叫次數。

  3. tottime是函式內部消耗的總時間（不包括呼叫其他函式的時間）。

  4. percall是tottime除以ncalls，表示每次呼叫平均消耗時間。

  5. cumtime是之前所有子函式消耗時間的累積和。

  6. percall是cumtime除以原生呼叫的數量，表示該函式呼叫時，每個原生呼叫的平均消耗時間。

  7. filename:lineno(function)為被分析函式所在檔名、行號、函式名。

  • func_line_time

line_profiler可以生成非常直接和詳細的報告，但它系統開銷很大，會比實際執行時間慢一個數量級

@func_line_time()
def test():
    for x in range(10000000):
        print x
# 輸出
Timer unit: 1e-06 s

Total time: 14.4183 s
File: /xx/test.py
Function: test at line 41

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    41                                           @func_line_time()
    42                                           def test():
    43  10000001    4031936.0      0.4     28.0      for x in range(10000000):
    44  10000000   10386347.0      1.0     72.0          print x
複製程式碼

輸出說明：

單位為微秒

  1. Total Time：測試程式碼的總執行時間

  2. Line:程式碼行號

  3. Hits：表示每行程式碼執行的次數

  4. Time：每行程式碼執行的總時間

  5. Per Hits：每行程式碼執行一次的時間

  6. % Time：每行程式碼執行時間的百分比

總結

日常開發中，可以使用func_time,func_cprofile做基本檢查，定位大致問題，使用func_line_time進行更細緻的深入檢查。

注：func_line_time 還可以檢查函式內部呼叫的函式執行時間，通過follow引數指定對應的內部呼叫的函式宣告即可，該引數是個陣列，也就是說可以檢查多個內部呼叫的函式

相關文章