Python処理時間の計測方法｜perf_counter・timeit比較とコピペ集

Pythonで処理時間を計測するには、処理の前後で time.perf_counter() を呼び、その差を取るのが基本です。 perf_counter は短い時間を測るための高精度な時計で、OS の時刻合わせの影響を受けません。数マイクロ秒の小さなコードを比べたいときは、何万回も繰り返して測ってくれる timeit を使います。

この記事では、time.time・perf_counter・perf_counter_ns・process_time・monotonic・timeit の6つを 「精度・sleep を含むか・時計の巻き戻りの影響・用途」で比較表にし、sleep を挟んだ同じコードを全部の時計で測った実測値を並べます。そのまま貼って使える計測デコレータと with 文タイマー、timeit で最小値を見る理由、cProfile で時間のかかる箇所を探す入口まで、すべて Python 3.14.7 で実行した出力つきで解説します。

処理時間の計測方法の早見表

まずは「やりたいこと」から選ぶ表です。

次に、6つの方法の比較表です。「sleep を含むか」は下の実測で確かめています。

この記事の検証環境

• Python 3.14.7（Linux）。実測値はすべてこの環境で動かしたときの出力です
• 計測値は、マシンの性能や同時に動いているほかの処理で変わります。数値そのものより、比べ方と傾向を見てください
• 各関数の仕様（どの時計を使うか、既定の回数など）は、公式ドキュメントの time・timeit のページ（3.14）で確認しました

基本：perf_counter で処理時間を測る

いちばん短い形です。そのまま貼って動きます。

import time

start = time.perf_counter()

total = sum(i * i for i in range(1_000_000))   # 測りたい処理

elapsed = time.perf_counter() - start
print(f"{elapsed:.4f} 秒")
print(f"{elapsed * 1000:.1f} ミリ秒")

ポイントは3つです。

• perf_counter() の戻り値そのものに意味はなく、2回呼んだ差だけが意味を持ちます（公式ドキュメントにも基準点は未定義と書かれています）
• 単位は秒です。ミリ秒にするなら 1000 を掛けます
• 表示は f"{elapsed:.4f}" のように桁数を決めると読みやすくなります

6つの時計を同じコードで比べる（実測）

「CPU を使う処理」と「0.5 秒の sleep」を続けて実行し、同じ区間を5つの時計で測ります。

import time

def busy():
    return sum(i * i for i in range(2_000_000))

clocks = {
    "time.time": time.time,
    "time.perf_counter": time.perf_counter,
    "time.monotonic": time.monotonic,
    "time.process_time": time.process_time,
}
start = {name: f() for name, f in clocks.items()}
start_ns = time.perf_counter_ns()

busy()            # CPU を使う処理
time.sleep(0.5)   # 待つだけの処理

for name, f in clocks.items():
    print(f"{name:18} {f() - start[name]:.6f} 秒")
print(f"{'perf_counter_ns':18} {time.perf_counter_ns() - start_ns} ns")

実行結果（Python 3.14.7）:

time.time          0.663494 秒
time.perf_counter  0.663544 秒
time.monotonic     0.663549 秒
time.process_time  0.073499 秒
perf_counter_ns    663554858 ns

「待ち時間も含めた体感の時間」を知りたいなら perf_counter、「計算に使った CPU 時間」を知りたいなら process_time と使い分けます。通信やファイルの待ちが多い処理を process_time で測ると、実際よりずっと短い値になる点に気をつけてください。

get_clock_info で時計の性質を確認する

それぞれの時計の性質は time.get_clock_info() で調べられます。

import time

for name in ["time", "perf_counter", "monotonic", "process_time", "thread_time"]:
    i = time.get_clock_info(name)
    print(f"{name:13} resolution={i.resolution:<8} monotonic={i.monotonic!s:5} "
          f"adjustable={i.adjustable!s:5} {i.implementation}")

time          resolution=1e-09    monotonic=False adjustable=True  clock_gettime(CLOCK_REALTIME)
perf_counter  resolution=1e-09    monotonic=True  adjustable=False clock_gettime(CLOCK_MONOTONIC)
monotonic     resolution=1e-09    monotonic=True  adjustable=False clock_gettime(CLOCK_MONOTONIC)
process_time  resolution=1e-09    monotonic=True  adjustable=False clock_gettime(CLOCK_PROCESS_CPUTIME_ID)
thread_time   resolution=1e-09    monotonic=True  adjustable=False clock_gettime(CLOCK_THREAD_CPUTIME_ID)

time.time だけが monotonic=False・adjustable=True です。これが「計測には perf_counter を使う」理由です。なお、表示される値は OS によって変わります（Windows・macOS での出力は未実行です）。

time.time を計測に使うとどうなるか

time.time() は「いまの時刻」を返す時計です。パソコンやサーバーは、ネットワーク経由で定期的に時刻を合わせています。計測の途中で時刻合わせが入ると、差がずれたり、まれにマイナスになったりします。 公式ドキュメントにも、システムの時計が戻された場合は前回より小さい値を返すことがあると書かれています。

perf_counter と monotonic の違い

公式ドキュメントによると、Python 3.13 以降の perf_counter は monotonic と同じ時計を使います（上の実行結果でも、両方 CLOCK_MONOTONIC です）。動きは同じなので、意図が伝わる名前で選ぶのがおすすめです。

• 速さを測る → perf_counter
• 締め切り・タイムアウトを判定する → monotonic

perf_counter_ns を使う場面

perf_counter() は float（小数）で返すため、値が大きくなるほど細かい桁を表しにくくなります。perf_counter_ns() は整数のナノ秒で返すので、その心配がありません。

import time

t0 = time.perf_counter_ns()
t1 = time.perf_counter_ns()
print(t1 - t0, "ns")
print(type(time.perf_counter()), type(time.perf_counter_ns()))

1462 ns
<class 'float'> <class 'int'>

何も挟まずに2回呼んだだけでも、今回は 1462 ナノ秒の差が出ました。計測そのものにもわずかな時間がかかるので、マイクロ秒より短い処理は、次に紹介する繰り返し計測（timeit）が向いています。

コピペで使える計測デコレータ

関数の上に @timer と1行書くだけで、実行時間を表示するデコレータです。

import functools
import time

def timer(func):
    """関数の実行時間を表示するデコレータ"""
    @functools.wraps(func)
    def wrapper(*args, **kwargs):
        start = time.perf_counter()
        try:
            return func(*args, **kwargs)
        finally:
            elapsed = time.perf_counter() - start
            print(f"[timer] {func.__name__}: {elapsed:.4f} 秒")
    return wrapper

@timer
def total(n):
    """0 から n-1 までの二乗和"""
    return sum(i * i for i in range(n))

print(total(1_000_000))
print(total.__name__, "/", total.__doc__)

[timer] total: 0.0899 秒
333332833333500000
total / 0 から n-1 までの二乗和

functools.wraps を付けないと、total.__name__ が wrapper になり、ログやエラー表示で関数を見分けにくくなります。print を logging.getLogger(__name__).info(...) に変えれば、そのままログ出力用になります。

コピペで使える with 文タイマー

関数全体ではなく、好きな範囲だけを測りたいときは with 文が便利です。contextlib.contextmanager を使うと短く書けます。

import time
from contextlib import contextmanager

@contextmanager
def stopwatch(label="処理"):
    start = time.perf_counter()
    try:
        yield
    finally:
        print(f"[{label}] {time.perf_counter() - start:.4f} 秒")

with stopwatch("リスト作成"):
    data = [i * 2 for i in range(1_000_000)]

with stopwatch("合計"):
    total = sum(data)

[リスト作成] 0.0662 秒
[合計] 0.0094 秒

yield の位置が「with ブロックの中身が実行されるところ」です。前に開始時刻の取得、後ろに表示を書きます。

計測値をあとで使いたいとき（クラス版）

測った値を変数として受け取りたいときは、クラスで書きます。

import time

class Timer:
    def __enter__(self):
        self.start = time.perf_counter()
        return self
    def __exit__(self, *exc):
        self.elapsed = time.perf_counter() - self.start
        return False

with Timer() as t:
    sorted(range(1_000_000), reverse=True)
print(f"{t.elapsed:.4f} 秒")
print(f"{t.elapsed * 1000:.1f} ミリ秒")

0.0738 秒
73.8 ミリ秒

t.elapsed に秒数が入るので、しきい値を超えたら警告を出す、集計用のリストに追加する、といった使い方ができます。

区間ごとの内訳を出す

処理がいくつかの段階に分かれているときは、区間ごとの時間と割合を出すと、どこから手を付けるかが決めやすくなります。

import time

laps = {}
t = time.perf_counter()

data = [i for i in range(500_000)]
laps["作成"] = time.perf_counter() - t; t = time.perf_counter()

data.sort(reverse=True)
laps["並べ替え"] = time.perf_counter() - t; t = time.perf_counter()

text = ",".join(map(str, data))
laps["文字列化"] = time.perf_counter() - t

total = sum(laps.values())
for name, sec in laps.items():
    print(f"{name:6} {sec * 1000:8.2f} ms {sec / total:6.1%}")

作成        20.22 ms  27.3%
並べ替え       5.63 ms   7.6%
文字列化      48.27 ms  65.1%

この例では文字列化が全体の約65%を占めています。割合の大きい区間から見直すのが、速くするときの近道です。

timeit で小さなコードを正確に比べる

数マイクロ秒で終わるコードは、1回だけ測ると計測の誤差に埋もれます。timeit は同じコードを何万回も実行して合計時間を測ることで、小さな差を見えるようにします。

コマンドラインで使う（python -m timeit）

「数値 0〜99 をハイフンでつなぐ」3つの書き方を比べます。

python -m timeit "'-'.join(str(n) for n in range(100))"
python -m timeit "'-'.join([str(n) for n in range(100)])"
python -m timeit "'-'.join(map(str, range(100)))"

50000 loops, best of 5: 6.64 usec per loop
50000 loops, best of 5: 5.32 usec per loop
50000 loops, best of 5: 5.26 usec per loop

準備のコードは -s に分けます。-s の部分は計測に含まれません。

python -m timeit -n 1000 -r 3 -s "data = list(range(1000))" "sorted(data)"

1000 loops, best of 3: 5.13 usec per loop

-v を付けて実行すると、回数を 1 → 2 → 5 → 10 … と増やしながら 0.2 秒を超える回数を探し、最後に次のような生の値が表示されました。

raw times: 333 msec, 338 msec, 436 msec, 374 msec, 344 msec

100000 loops, best of 5: 3.33 usec per loop

5回の計測は 333〜436 ミリ秒とばらついていて、最小の 333 ミリ秒が結果に採用されていることがわかります。

コードから使う（number と repeat）

import timeit

setup = "data = list(range(1000))"
print(timeit.timeit("sum(data)", setup=setup, number=10_000))

times = timeit.repeat("sum(data)", setup=setup, number=10_000, repeat=5)
print([f"{t:.4f}" for t in times])
print(f"最小 {min(times):.4f} 秒 → 1回あたり {min(times) / 10_000 * 1e6:.2f} マイクロ秒")

0.04191830599998525
['0.0367', '0.0361', '0.0362', '0.0346', '0.0379']
最小 0.0346 秒 → 1回あたり 3.46 マイクロ秒

timeit.timeit() の戻り値は「number 回の合計秒」です。1回あたりにするには number で割ります。number の既定値は 100万回なので、重い処理をそのまま渡すと長く待つことになります。必ず number を指定しましょう。

自作の関数を測るときは、関数をそのまま渡すか、globals=globals() を付けます。

import timeit

def join_map():
    return "-".join(map(str, range(100)))

print(timeit.timeit(join_map, number=100_000))
print(timeit.timeit("join_map()", globals=globals(), number=100_000))

n, total = timeit.Timer(join_map).autorange()   # 回数を自動で決める
print(n, f"{total:.4f}")

0.5124460329999465
0.5099836159999995
50000 0.2509

1・2行目は 10万回の合計秒です。autorange() は CLI と同じ方法で回数を決め、(回数, 合計秒) を返します。3行目は「50,000 回で合計 0.2509 秒」という意味です。

平均ではなく最小値を見る理由

repeat の結果は、平均ではなく最小値（min）を見るのが基本です。公式ドキュメントにも、次の趣旨の説明があります。

• 値が大きくなる原因は、多くの場合 Python の速さの揺れではなく、同時に動いているほかの処理の割り込みである
• そのため、最小値が「そのマシンで出せる速さ」にいちばん近い
• 平均や標準偏差は、割り込みの量を表してしまうので、コード同士の比較にはあまり役立たない

上の実行結果でも、5回の値は 0.0346〜0.0379 秒と約1割の幅がありました。2つのコードを比べるときは、それぞれの最小値同士を比べます。

なお、timeit は計測中、ガベージコレクション（不要になったメモリの自動回収）を一時的に止めます。計測ごとの条件をそろえるための仕組みです（公式ドキュメントで確認）。

1回目だけ遅い・ばらつくときの扱い方

同じ処理を6回測ってみます。

import statistics
import time

def work():
    import json                      # 1回目だけ import のコストが入る
    return json.dumps(list(range(50_000)))

times = []
for i in range(6):
    s = time.perf_counter()
    work()
    times.append(time.perf_counter() - s)

print([f"{t * 1000:.2f}" for t in times], "ミリ秒")
rest = times[1:]
print(f"1回目 {times[0] * 1000:.2f} / 2回目以降の最小 {min(rest) * 1000:.2f} / "
      f"中央値 {statistics.median(rest) * 1000:.2f} / 標準偏差 {statistics.stdev(rest) * 1000:.3f}")

['12.24', '2.63', '2.37', '3.33', '3.51', '12.26'] ミリ秒
1回目 12.24 / 2回目以降の最小 2.37 / 中央値 3.33 / 標準偏差 4.184

1回目は 12.24 ミリ秒、2〜5回目は 2〜3 ミリ秒台でした。さらに今回は、6回目にも 12.26 ミリ秒という飛び抜けた値が出ています。同じマシンでほかの処理が動いたタイミングと重なったためと考えられ、1回だけの計測では判断できないことがよくわかる結果になりました。

「何を知りたいか」で見る値を決め、報告するときは回数と見た値（最小・中央値など）を一緒に書くと、あとから比べやすくなります。

時間がかかっている箇所を探す入口（cProfile）

perf_counter は「全体で何秒か」を測る道具です。「どの関数に時間がかかっているか」を知りたいときは、標準ライブラリの cProfile を使います。

import cProfile
import pstats
import time

def load():
    time.sleep(0.2)
    return list(range(300_000))

def transform(data):
    return [str(x) for x in data]

def search(items):
    return sum(1 for x in items[:2000] if x in items[:2000])

def main():
    data = load()
    items = transform(data)
    return search(items)

with cProfile.Profile() as pr:
    main()

stats = pstats.Stats(pr)
stats.sort_stats("cumulative").print_stats(6)

実行結果（Python 3.14.7、ファイル名は短く表示）:

         2009 function calls in 0.317 seconds

   Ordered by: cumulative time
   List reduced from 9 to 6 due to restriction <6>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.317    0.317 prof.py:15(main)
        1    0.019    0.019    0.221    0.221 prof.py:5(load)
        1    0.202    0.202    0.202    0.202 {built-in method time.sleep}
        1    0.068    0.068    0.068    0.068 prof.py:9(transform)
        1    0.000    0.000    0.029    0.029 prof.py:12(search)
        1    0.000    0.000    0.029    0.029 {built-in method builtins.sum}

全体 0.317 秒のうち、load が 0.221 秒で、その大半は time.sleep の 0.202 秒だと読み取れます。cumtime の大きい順に見て、次に tottime でその関数自身が重いのかを確かめるのが読み方の基本です。

スクリプト全体を調べるだけなら、コードを変えずにコマンドで実行できます。

python -m cProfile -s cumulative script.py

cProfile を付けると、付けないときより実行が遅くなります。cProfile で場所を見つけ、perf_counter や timeit で前後の差を測る、という順番が効率的です。

time.sleep の精度を確かめる

time.sleep(秒) は、指定した秒数だけ処理を止めます。指定より短くなることはなく、少し長くなるのが特徴です。公式ドキュメントにも、システム内のほかの処理の都合で、指定より長く止まることがあると書かれています。

import time

for sec in [0, 0.001, 0.01, 0.1, 1]:
    results = []
    for _ in range(5):
        s = time.perf_counter()
        time.sleep(sec)
        results.append(time.perf_counter() - s)
    avg = sum(results) / len(results)
    print(f"sleep({sec:<5}) 平均 {avg:.6f} 秒  超過 {(avg - sec) * 1000:.3f} ミリ秒")

sleep(0    ) 平均 0.000776 秒  超過 0.776 ミリ秒
sleep(0.001) 平均 0.003336 秒  超過 2.336 ミリ秒
sleep(0.01 ) 平均 0.011837 秒  超過 1.837 ミリ秒
sleep(0.1  ) 平均 0.102922 秒  超過 2.922 ミリ秒
sleep(1    ) 平均 1.001633 秒  超過 1.633 ミリ秒

今回の環境（ほかの処理も動いている共有マシン）では、指定した長さに関係なく 1〜3 ミリ秒ほど長くなりました。sleep(0.001) は実際には約 3.3 ミリ秒です。超過の大きさは OS やマシンの混み具合で変わります。

import time

start = time.perf_counter()
deadline = time.monotonic() + 0.3      # 0.3 秒後を締め切りにする
count = 0
while time.monotonic() < deadline:
    count += 1
    time.sleep(0.1)
print(count, f"{time.perf_counter() - start:.2f} 秒")

3 0.30 秒

sleep の回数を数える方法と違い、締め切りの時刻と比べる書き方なら、sleep が少し延びても全体の時間がずれません。

秒を「分・秒」の表示に変える

長い処理の結果は、125.5 秒 より 2分05.50秒 のほうが伝わります。標準ライブラリの timedelta を使う方法と、divmod で自分で組み立てる方法を並べます。

from datetime import timedelta

def fmt(seconds):
    m, s = divmod(seconds, 60)
    h, m = divmod(int(m), 60)
    return f"{h}時間{m:02}分{s:05.2f}秒" if h else f"{m}分{s:05.2f}秒"

for sec in [0.0123, 75.5, 3725.25, 90061]:
    print(f"{sec:>9} → {str(timedelta(seconds=sec)):>16} | {fmt(sec)}")
print(timedelta(seconds=round(3725.25)))

   0.0123 →   0:00:00.012300 | 0分00.01秒
     75.5 →   0:01:15.500000 | 1分15.50秒
  3725.25 →   1:02:05.250000 | 1時間02分05.25秒
    90061 →   1 day, 1:01:01 | 25時間01分01.00秒
1:02:05

timedelta は 24 時間を超えると 1 day, 1:01:01 のように日数が付きます。日付や時刻の扱いは、既存記事「Python datetimeの使い方」で詳しく解説しています。

Jupyter の %timeit（紹介）

Jupyter Notebook や IPython では、timeit をもっと手軽に使えるマジックコマンドが用意されています。

%timeit sum(range(1000))

%timeit は平均と標準偏差を表示する点が、最小値を表示する python -m timeit と異なります。今回の検証環境には Jupyter を入れていないため、この節は未実行の紹介です。

計測でつまずきやすい点と整え方

よくある質問

Q. time.time() と time.perf_counter() はどちらを使えばよいですか？ A. 処理時間の計測は perf_counter() です。分解能が高く、OS の時刻合わせの影響を受けません。time.time() は「いま何時か」を記録する用途に向いています。

Q. perf_counter は sleep の時間を含みますか？ A. 含みます。今回の実測でも、0.5 秒の sleep を挟んだ区間が約 0.66 秒と計測されました。sleep や待ち時間を除いた CPU 時間を知りたいときは process_time() を使います（同じ区間で約 0.07 秒でした）。

Q. timeit の結果は平均と最小値のどちらを見ればよいですか？ A. コード同士の比較には最小値を使います。値が大きくなる主な原因は、同時に動くほかの処理の割り込みだからです。python -m timeit の best of 5 も、5回のうち最小の値を表示しています。

Q. ミリ秒やマイクロ秒で表示するにはどうすればよいですか？ A. 秒に 1000 を掛けるとミリ秒、100万（1e6）を掛けるとマイクロ秒です。はじめから整数で扱いたいときは perf_counter_ns() でナノ秒を取得し、// 1_000_000 でミリ秒にします。

まとめ

• 処理時間の計測は time.perf_counter() の差が基本。戻り値そのものではなく、2回の差を使う
• time.time() は現在時刻の記録用。時刻合わせの影響を受けるのはこの時計だけ（adjustable=True）
• process_time() は sleep を含まない。実測で 0.66 秒と 0.07 秒の差が出た
• 関数は @timer デコレータ、範囲は with stopwatch() で、コードを大きく変えずに測れる
• 小さなコードの比較は timeit。number を指定し、repeat の最小値を見る
• 1回目は遅くなりやすく、値はばらつく。複数回測って、目的に合う値（最小・中央値）を選ぶ
• どこに時間がかかっているかは cProfile の cumtime から探す

株式会社RJCでは、Pythonの処理時間の計測方法を仲間と学び合っています。こうした知識を共有しながら、日々技術を磨いています。

株式会社RJC ― SI事業・SES事業・AI駆動開発。RJCは一緒に成長を楽しめる会社です。