Python の with 文で処理時間を計測する

コードの実行時間を計測するのは、パフォーマンス分析やデバッグでよく行う作業です。コンテキストマネージャを使えば、計測したい部分を with ブロックで囲むだけで簡単に時間を測れます。

シンプルなタイマー

基本的な処理時間計測のコンテキストマネージャです。

import time
from contextlib import contextmanager

@contextmanager
def timer(label="処理"):
    start = time.time()
    yield
    elapsed = time.time() - start
    print(f"{label}: {elapsed:.4f}秒")

with timer("ソート"):
    data = list(range(1000000, 0, -1))
    data.sort()
# ソート: 0.0823秒

クラスベースの実装

より多機能なタイマーをクラスで実装することもできます。

import time

class Timer:
    def __init__(self, label="処理"):
        self.label = label
        self.elapsed = 0
    
    def __enter__(self):
        self.start = time.perf_counter()
        return self
    
    def __exit__(self, *args):
        self.elapsed = time.perf_counter() - self.start
        print(f"{self.label}: {self.elapsed:.4f}秒")

with Timer("計算") as t:
    sum(range(10000000))

print(f"記録された時間: {t.elapsed:.4f}秒")

time.perf_counter() は time.time() より高精度な計測が可能です。

ネストした計測

複数の処理を個別に計測できます。

with timer("全体"):
    with timer("データ生成"):
        data = [i ** 2 for i in range(100000)]
    
    with timer("フィルタリング"):
        filtered = [x for x in data if x % 2 == 0]
    
    with timer("合計計算"):
        total = sum(filtered)

# データ生成: 0.0156秒
# フィルタリング: 0.0089秒
# 合計計算: 0.0023秒
# 全体: 0.0271秒

累積時間の計測

同じ処理を複数回実行して、累積時間を計測するクラスです。

import time

class AccumulatingTimer:
    def __init__(self, label="処理"):
        self.label = label
        self.total = 0
        self.count = 0
    
    def __enter__(self):
        self.start = time.perf_counter()
        return self
    
    def __exit__(self, *args):
        self.total += time.perf_counter() - self.start
        self.count += 1
    
    def report(self):
        avg = self.total / self.count if self.count > 0 else 0
        print(f"{self.label}: 合計 {self.total:.4f}秒, "
              f"回数 {self.count}, 平均 {avg:.4f}秒")

db_timer = AccumulatingTimer("DB操作")

for i in range(5):
    with db_timer:
        time.sleep(0.1)  # DBアクセスをシミュレート

db_timer.report()
# DB操作: 合計 0.5012秒, 回数 5, 平均 0.1002秒

実用的な例：関数デコレータとの併用

タイマーをデコレータとしても使えるようにする例です。

import time
from contextlib import contextmanager
from functools import wraps

@contextmanager
def timer(label="処理"):
    start = time.perf_counter()
    yield
    print(f"{label}: {time.perf_counter() - start:.4f}秒")

def timed(func):
    @wraps(func)
    def wrapper(*args, **kwargs):
        with timer(func.__name__):
            return func(*args, **kwargs)
    return wrapper

@timed
def slow_function():
    time.sleep(0.5)
    return "完了"

result = slow_function()
# slow_function: 0.5003秒

処理時間の計測は、ボトルネックの特定やパフォーマンス改善に欠かせません。コンテキストマネージャを使えば、計測コードをきれいに分離できます。