python性能優化之函數執行時間分析

時間 2019-11-06

原文原文鏈接

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

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

利器

工欲善其事，必先利其器，咱們須要一套方便高效的工具記錄函數運行時間。說是一套工具，但對於一個簡單項目或者平常開發來講，實現一個工具類足矣，因爲實現比較簡單，直接上代碼：github

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,分別對應app

簡單輸出函數的執行時間
利用python自帶的內置分析包cProfile 分析，它主要統計函數調用以及每一個函數所佔的cpu時間
利用line_profiler開源項目,它能夠統計每行代碼的執行次數和執行時間。

使用說明

咱們以一個簡單的循環例子來講明一下,ide

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}
複製代碼

輸出說明：優化

單位爲秒

第一行告訴咱們一共有3個函數被調用。

正常開發過程，第一行更可能是輸出相似194 function calls (189 primiive calls) in 0.249 seconds，(189 primiive calls)表示189個是原生（primitive）調用，代表這些調用不涉及遞歸
ncalls表示函數的調用次數，若是這一列有兩個數值，表示有遞歸調用，第一個是總調用次數，第二個是原生調用次數。
tottime是函數內部消耗的總時間（不包括調用其餘函數的時間）。
percall是tottime除以ncalls，表示每次調用平均消耗時間。
cumtime是以前全部子函數消耗時間的累積和。
percall是cumtime除以原生調用的數量，表示該函數調用時，每一個原生調用的平均消耗時間。
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
複製代碼