プログラム 技術

Pythonでスクリプトの処理時間計測

今回はPythonのスクリプトでの処理時間計測についてになります
スクリプト全体でのパターンとボトルネック調査時の関数ごとのパターンになります

名称バージョン
Python3.12
line_profiler5.0.0

スクリプト全体の実行時間での計測

スクリプト内に記載

まずは、シンプルにtimeを使用した計測となります

import time

start = time.perf_counter()  # 計測開始

# ===== スクリプトの処理 =====
time.sleep(2)  # ダミー処理
# ===========================

end = time.perf_counter()  # 計測終了
print(f"timeスクリプト全体の実行時間: {end - start:.3f} 秒")

次にログ出力や可読性重視したdatetimeを使用した計測となります

import time
from datetime import datetime

start = datetime.now()

# ===== スクリプトの処理 =====
time.sleep(2)
# ===========================

end = datetime.now()
print(f"datetimeスクリプト全体の実行時間: {(end - start).total_seconds():.3f} 秒")

スクリプトの中で書かずにスクリプトを実行する時間を計測する

スクリプト内には記載せず、実行する際にLinux系だとtimeコマンド、WindowsはPowerShellコマンドであるMeasure-Commandコマンドを使用します

Measure-Command { python スクリプト名.py }

# 実行すると以下のように表示される
Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 2
Milliseconds      : 80
Ticks             : 20801832

関数ごとの細かい時間（ボトルネック調査）

cProfileを使用する

cProfile を使用することで関数ごとの呼び出し回数や合計時間などを自動で集計できます

import cProfile

def func1():
    import time; time.sleep(1)

def func2():
    import time; time.sleep(0.5)

def main():
    func1()
    func2()

if __name__ == "__main__":
    profiler = cProfile.Profile()
    profiler.enable()
    main()
    profiler.disable()
    profiler.print_stats(sort="time")  # 実行時間順で表示

# 以下のように結果が表示されます #
         6 function calls in 1.501 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2    1.501    0.750    1.501    0.750 {built-in method time.sleep}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    1.501    1.501 BottleneckInvestigation.py:9(main)
        1    0.000    0.000    0.501    0.501 BottleneckInvestigation.py:6(func2)
        1    0.000    0.000    1.000    1.000 BottleneckInvestigation.py:3(func1)

行ごとの計測

line_profilerというモジュールをインストールする必要がありますが、これとkernprofコマンドを用いる事で各行の処理時間がよりわかります
kernprofコマンドについては今回は割愛とします

@profile
def func1():
    import time
    time.sleep(1)
    for i in range(3):
        time.sleep(0.2)

func1()

計測対象とする関数に対し、上記のスクリプトのように@profileと記載しておきます
そして対象となるスクリプトに対して以下のkernprofコマンドを用いて実行します

kernprof -l -v line-profiler.py

# 上記コマンドの実行結果 #
Total time: 1.60213 s
File: line-profiler.py
Function: func1 at line 1

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     1                                           @profile
     2                                           def func1():
     3         1          1.7      1.7      0.0      import time
     4         1    1000531.8    1e+06     62.5      time.sleep(1)
     5         4         66.0     16.5      0.0      for i in range(3):
     6         3     601532.5 200510.8     37.5          time.sleep(0.2)

最後に

今回はPythonスクリプトでの処理時間計測について書きました。自身の環境に適した方法で実装してみてください

会社紹介

私が所属しているアドバンスド・ソリューション株式会社(以下、ADS)は一緒に働く仲間を募集しています

会社概要
「技術」×「知恵」＝顧客課題の解決・新しい価値の創造

この方程式の実現はADSが大切にしている考えで、技術を磨き続けるgeekさと、顧客を思うloveがあってこそ実現できる世界観だと思っています
この『love & geek』の精神さえあれば、得意不得意はno problem！
技術はピカイチだけど顧客折衝はちょっと苦手。OKです。技術はまだ未熟だけど顧客と知恵を出し合って要件定義するのは大好き。OKです
凸凹な社員の集まり、色んなカラーや柄の個性が集まっているからこそ、常に新しいソリューションが生まれています

ミッション
私たちは、テクノロジーを活用し、業務や事業の生産性向上と企業進化を支援します

ホームページ
アドバンスド・ソリューション株式会社｜ADS Co., Ltd.
アドバンスド・ソリューション株式会社｜ADS Co., Ltd.

Microsoft 365／SharePoint／Power Platform／Azure による DX コンサル・シス ...

サイトへ移動

PR

-プログラム, 技術
-