Pythonで複数の処理や関数の処理速度を計り自動でまとめる #Python

今回のプログラムの出力
3秒かかる処理、1.5秒かかる処理、10秒かかる処理をそれぞれ計測し時間を記録、json形式でtxtファイルに保存しています。
プログラム全体の処理速度のボトルネックの可視化に便利ではないでしょうか。

{"3 seconds": 3.0122451782226562, "1.5 seconds?": 1.5078651905059814, "10 seconds?": 10.014142513275146}

Pythonプログラムの関数毎に処理速度を計りたい。でもプログラム自体はなるべく改変したくない。普通ならprintで出力して確認すれば済みますが中規模や大規模なプログラムになるとprintは情報の掃きだめになっていたりprintしても出力されなかったり、もしかするとprint禁止というのもありえるかと思います。ログも流れが速すぎて追えない。リモート接続でCUI操作しているときはログの検索も面倒？かもしれません。
誰かの助けになるかはわかりませんが、数行程度挿入するだけでその行間の処理速度を計ってログを取ってくれるプログラムを作りました。

time_record.py

import time 
import json 
import os 
import datetime
from typing import Any, Dict, List, Tuple


class TimeRecorder:
    def __init__(self,path:str) -> None:
        self.path = path 
        self.start = time.time() 
        self.folder_name = "process_time_records"
        self.folder_init()
        self.records = [] 
        self.speeds = {}

    def get_time_stamp(self) -> None:
        today = datetime.datetime.now()
        return today.strftime('%y%m%d%M%S')

    def folder_init(self) -> None:
        os.makedirs(os.path.join(self.path, self.folder_name),exist_ok= True)

    def time_record_handler(self, section_name: str ) -> None :
        result_so_far = time.time() - self.start
        if len(self.speeds) == 0:
            result = result_so_far
        else:
            result = result_so_far - self.records[-1]
        self.speeds[section_name] = result
        self.records.append(result_so_far)

    def generate_result(self) -> None:
        destination_path = os.path.join(self.path, self.folder_name, "speeds_at_{}.txt".format(self.get_time_stamp()))
        with open(destination_path, 'w') as file:
            file.write(str(json.dumps(self.speeds)))

使い方

usage.py

from time_record import TimeRecorder
import time 

def test():
    """
    時間を計りたい関数や処理をインスタンス作成もしくは TimeRecorder().time_record_handler(str)で挟みこむ

    最後にTimeRecorder().generate_result()でpathで指定した場所の下に記録フォルダーを作りそこに結果を保存する。
    """
    path = "" #ログを残したいパスを指定する。 このパスの下にprocess_time_recordsというフォルダを自動で作って実行速度のログを保存していく。
    time_recorder = TimeRecorder(path)
    time.sleep(3)
    time_recorder.time_record_handler("3 seconds?")
    time.sleep(1.5)
    time_recorder.time_record_handler("1.5 seconds?")
    time.sleep(10)
    time_recorder.time_record_handler("10 seconds?")
    time_recorder.generate_result() #os.path.join(path, process_time_records) 以下のtxtファイルに結果を保存する

if __name__ == "__main__":
    test()

出力結果
冒頭で出しましたが再度

{"3 seconds?": 3.0122451782226562, "1.5 seconds?": 1.5078651905059814, "10 seconds?": 10.014142513275146}

それぞれ3秒かかる処理,1.5秒かかる処理、そして10秒かかる処理の時間をおおよそ正しく測定できました。
プログラム全体の高速化を行いたい時にボトルネックになっている処理を数字で確認できるため改善するべき関数にあたりを付けられるほか、json形式で保存されるのでそのままチームで共有することもできるかと思います。