Python自動化の例「1分ごとに実行」を3方式で回し比べた——sleepループは1分で8秒ずれた

Python自動化の例を検索して「1分ごとに実行」のコードを写すとき、書き方は何通りも出てくる。while True: で処理して time.sleep(60) で待つループ、schedule ライブラリ、自力で時刻を管理する書き方だ。どれを写しても同じように動くと思ってそのまま運用に置くと、毎回少しずつ遅れ続け、気づいたときには指定時刻からずれている——ということが起きる。どの書き方が時計に忠実かは、回して測るまで分からない。

以前このサイトでは、自動化サンプルがファイルを静かに消す話を扱った。あれは「処理対象のファイル」の話で、今回測るのは別の部分——「いつ実行されるか」の時刻精度だ。手元のMacで3方式を同じ条件（1秒間隔×60回、反復ごとに約10msの擬似作業）で回し、各反復の開始時刻を time.monotonic() で記録して比べた。実行環境は次のとおり。

$ sh -c 'sw_vers; uname -m'
ProductName:		macOS
ProductVersion:		26.6.1
...
arm64
# exit=0 (18 ms)

$ python -V
Python 3.14.7
# exit=0 (11 ms)

3つの書き方を同じ条件で回し比べた

測ったのは次の3方式だ。

ひとつ目は、自動化の例でいちばん見かける素のsleepループ。測定コードでは、各反復で開始時刻・作業時間・寝過ぎを記録している。

for i in range(N):
    starts.append(time.monotonic())
    w0 = time.monotonic()
    work(SLOW_S if i == SLOW_AT else WORK_S)
    works.append(time.monotonic() - w0)
    s0 = time.monotonic()
    time.sleep(T)
    overs.append(time.monotonic() - s0 - T)

ふたつ目は schedule ライブラリ。every(1).seconds.do(job) にして、run_pending() を1ms刻みで回す駆動側のループがこうなる。

schedule.every(T).seconds.do(job)
t0 = time.monotonic()
while len(starts) < N:
    schedule.run_pending()
    time.sleep(0.001)

みっつ目は締切方式。time.sleep(T) で「何秒寝るか」を決めるのではなく、開始時刻のグリッド t0 + T*i を決めておき、そこまでの残り時間だけ寝る。

for i in range(N):
    deadline = t0 + T * i
    wait = deadline - time.monotonic()
    if wait > 0:
        time.sleep(wait)
    starts.append(time.monotonic())
    work(SLOW_S if i == SLOW_AT else WORK_S)

実際の自動化は「1分ごと」だが、1分間隔を60回そのまま回すと計測だけで1時間かかるので、1秒間隔×60回に圧縮した。ズレの構造は間隔の大きさに依存しない——試しに0.05秒間隔で回したスモークでも、実際の間隔は平均201.0msとやはり寝過ぎた分だけ伸びていた。

sleepループ：1分で8秒ずれた

素のsleepループを python naive_loop.py 60 1.0 で60回回した結果がこれだ。

$ python naive_loop.py 60 1.0
N=60 target_interval=1.0s work=0.01s slow_at=-1
actual_span=67.183s expected_span=59.000s drift=+8.183s
interval mean=1138.7ms min=1020.9ms max=1159.7ms
work mean=10.0ms sleep_overshoot mean=128.9ms
  tick   0: start=0.000s
...
  tick  59: start=67.183s
# exit=0 (68361 ms)

59秒のはずの区間が67.183秒かかり、60回で8.183秒遅れた。実際の間隔は平均1138.7msで、「1秒おき」のつもりが毎回1138.7msおきになっていた。このまま回し続ければズレは積み上がるだけだ。

ズレの内訳——sleep自体が寝過ぎていた

ズレを2つに分解した。反復ごとの「作業時間」と、「sleepが指定より余計に寝た時間（overshoot）」だ。

上のログの末尾近くが答えになっている。作業は平均10.0ms。対してsleepのオーバーシュートは平均128.9ms。つまりこのズレの主犯は作業時間ではなく、time.sleep そのものの寝過ぎだった。

作業を挟まない素の time.sleep だけを測っても同じ傾向だった。

$ python sleep_baseline.py
sleep(1.0): overshoot mean=137.6ms min=114.2ms max=150.0ms
sleep(0.1): overshoot mean=139.3ms min=91.5ms max=149.8ms
sleep(0.05): overshoot mean=132.2ms min=75.0ms max=149.2ms
# exit=0 (15620 ms)

sleep(1.0) が平均137.6ms寝過ぎ、sleep(0.05) でも平均132.2ms寝過ぎた。指定時間に関係なく寝過ぎる。しかもこれはPython固有の問題ではない。シェルの sleep 1 でも遅れた。

$ sh -c 'time sleep 1; time sleep 1; time sleep 1'

real	0m1.146s
user	0m0.001s
sys	0m0.001s

real	0m1.158s
user	0m0.002s
sys	0m0.004s

real	0m1.025s
user	0m0.003s
sys	0m0.005s
# exit=0 (3335 ms)

3回のうち1回は real 0m1.025s とほぼ狙い通りに起きており、寝過ぎにはばらつきがある。ただいずれも指定より遅く、Python側の実装ではなくOS側がタイマーの起床を遅らせている話だ。

寝過ぎの絶対量は環境依存だが、重要なのは構造のほう。反復ごとの遅れはゼロにならない限りすべて累積する。1反復の間隔は「T＋作業時間＋寝過ぎ」で、その和がループを回すたびに開始時刻を遅らせていく。

遅いジョブ1回で、以降すべてがずっと遅れる

次に、60回中の30回目にだけ0.5秒の遅い処理を挟んで回した（SLOW_S の値は検証コードの定数で、grepして確認できる）。

$ grep -n 'SLOW_S =' naive_loop.py mono_loop.py sched_lib.py
naive_loop.py:10:SLOW_S = 0.5
mono_loop.py:10:SLOW_S = 0.5
sched_lib.py:11:SLOW_S = 0.5
# exit=0 (5 ms)

$ python naive_loop.py 60 1.0 30
N=60 target_interval=1.0s work=0.01s slow_at=30
actual_span=67.918s expected_span=59.000s drift=+8.918s
interval mean=1151.2ms min=1015.4ms max=1643.6ms
...
  tick  59: start=67.918s
# exit=0 (69082 ms)

ズレは+8.918秒。遅い処理のぶんが、それ以降の全反復の開始時刻にそのまま乗った。実運用でいえば「たまに重い処理が入る」だけで、スケジュール全体が恒久的にシフトする。ずれた分が勝手に戻ることはない。

scheduleライブラリでもズレる

素のループがだめならライブラリはどうか。ここでまずつまずいた。uv pip install がそのまま落ちた。

$ uv pip install --target vendor schedule
...
Attempted to create a NULL object.
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
...
# exit=101 (17 ms)

panicして終了した。uvは諦めて、PyPIからwheelを直接取って展開する形に切り替えた。

$ sh -c 'curl -sS -L https://files.pythonhosted.org/packages/20/a7/84c96b61fd13205f2cafbe263cdb2745965974bdf3e0078f121dfeca5f02/schedule-1.2.2-py3-none-any.whl -o schedule-1.2.2.whl && python -m zipfile -e schedule-1.2.2.whl vendor/ && PYTHONPATH=vendor python -c "import schedule; print(schedule.__version__ if hasattr(schedule, \"__version__\") else \"imported ok\")"'
imported ok
# exit=0 (137 ms)

schedule 1.2.2 を vendor/ に展開して計測した。

$ sh -c 'PYTHONPATH=vendor python sched_lib.py 60'
N=60 target_interval=1.0s work=0.01s slow_at=-1 lib=schedule
actual_span=59.803s expected_span=59.000s drift=+0.803s
interval mean=1013.6ms min=1010.1ms max=1027.1ms
...
  tick  59: start=60.803s
# exit=0 (60885 ms)

素のsleepループよりはマシだが、それでも60回で+0.803秒ずれた。遅いジョブを1回挟むと+1.296秒まで増えた。

$ sh -c 'PYTHONPATH=vendor python sched_lib.py 60 30'
N=60 target_interval=1.0s work=0.01s slow_at=30 lib=schedule
actual_span=60.296s expected_span=59.000s drift=+1.296s
interval mean=1022.0ms min=1010.2ms max=1507.2ms
...
# exit=0 (61379 ms)

なぜズレるかは、vendorに展開した schedule/__init__.py を読むと分かる。Job.run() はジョブを実行したあとに次回予定を計算する。

ret = self.job_func()
self.last_run = datetime.datetime.now()
self._schedule_next_run()

さらに _schedule_next_run() は next_run = now から始めて while next_run <= now: next_run += period と足していく。つまり次回予定の基準は「前回の予定時刻」ではなく「ジョブが終わった時点の現在時刻」だ。構造は素のsleepループと同じで、処理にかかった時間がそのまま次回開始を押し出す。ライブラリに変えても、ズレの累積は止まらない。

締切方式だけ、ズレが累積しなかった

対照の締切方式の結果はこうなった。

$ python mono_loop.py 60 1.0
N=60 target_interval=1.0s work=0.01s slow_at=-1 mode=monotonic-deadline
actual_span=59.124s expected_span=59.000s drift=+0.124s
interval mean=1002.1ms min=877.6ms max=1147.4ms
  tick   0: start=0.000s (grid=0.000)
  tick  10: start=10.148s (grid=10.000)
...
  tick  59: start=59.124s
# exit=0 (59164 ms)

ズレは+0.124秒に留まった。注目点が2つある。

ひとつは、各tick自体は依然としてグリッドより遅れて始まっていることだ。tick 10 は grid=10.000 に対し start=10.148 で、寝過ぎた分だけ遅れている。sleepの寝過ぎ自体は消えていない。消えたのは累積だけで、あるtickが寝過ぎると次のtickは短く待ってグリッドに戻る（interval最小は877.6ms）。ズレが片方向に積み上がる構造だけが解消されている。

もうひとつは、遅いジョブを挟んでも効くことだ。

$ python mono_loop.py 60 1.0 30
N=60 target_interval=1.0s work=0.01s slow_at=30 mode=monotonic-deadline
actual_span=59.137s expected_span=59.000s drift=+0.137s
interval mean=1002.3ms min=915.2ms max=1123.2ms
...
# exit=0 (59184 ms)

0.5秒の遅い処理を挟んでも、ズレは+0.137秒のままだった。次回の締切は「ジョブが終わった時刻」ではなくグリッド上に固定されているので、1回の遅れが以降を引きずらない。

どの書き方を写すべきか——ズレの見積もりと使い分け

測った値を1時間あたりに換算すると、こうなる。

$ python -c '
...
naive sleepループ: drift_over_59s=+8.183s -> per_hour=499s
naive+遅いジョブ1回: drift_over_59s=+8.918s -> per_hour=544s
schedule: drift_over_59s=+0.803s -> per_hour=49s
schedule+遅いジョブ1回: drift_over_59s=+1.296s -> per_hour=79s
締切方式: drift_over_59s=+0.124s -> per_hour=8s
締切方式+遅いジョブ1回: drift_over_59s=+0.137s -> per_hour=8s
# exit=0 (24 ms)

この環境では、素のsleepループは1時間で499秒（8分強）ずれるペースだった。読者の問い——「『1分ごと』の自動化は実際に何秒ずれて、どの書き方を選べばよいか」——への答えは、「ズレ/時間 ≈ （作業時間＋sleepの寝過ぎ）× 回数」という式と、この測定値だ。寝過ぎが平均137.6msあったこの環境では、sleepループのズレは分単位まで育つ。scheduleライブラリに変えても、次回予定が「ジョブ終了時点」基準なのでズレは縮むが消えない（1時間で49秒）。ズレが累積しないのは締切方式だけだった（1時間で8秒）。

使い分けとしては、時刻が厳密に要るジョブはそもそもin-processループに任せず、cronやlaunchdのようなOS側スケジューラに渡すのが本筋だ（今回はcron自体の精度は測っていない）。in-processで回す必要があるなら、少なくとも締切方式で書く。締切方式でも各tickは寝過ぎた分だけ遅れて始まるので、「グリッドから遅れない」ことを求める用途には向かない。向いているのは「ズレが累積しない」ことで足りる用途——定期的なポーリングや緩い監視だ。

また今回の寝過ぎの大きさはこの環境の値であって、別の環境では別の値になりうる。自分の環境でどのくらいずれるかは、次の最小再現コードをそのまま回せば確かめられる。私が実際に実行したもので、結果は drift= の1行に出る。

"""sleepポーリングループの最小再現コード。回すと累積ズレ drift= が出る。"""
import time

N = 60       # 反復回数
T = 1.0      # 目標間隔（秒）
WORK = 0.01  # 1反復の作業時間（秒）

def work(seconds):
    end = time.monotonic() + seconds
    while time.monotonic() < end:
        pass

t0 = time.monotonic()
starts = []
for i in range(N):
    starts.append(time.monotonic())
    work(WORK)
    time.sleep(T)

drift = (starts[-1] - starts[0]) - T * (N - 1)
print(f"N={N} T={T}s WORK={WORK}s")
print(f"drift={drift:+.3f}s")

私の環境での実行結果はこれだった。

$ python min_repro.py
N=60 T=1.0s WORK=0.01s
drift=+7.876s
# exit=0 (68011 ms)

寝過ぎが仮に小さい環境でも、作業時間との和は反復ごとに積み上がる。どちらにしろ、sleep(T) ループの「T」は実際の間隔ではない、という点は変わらない。

関連書籍

• 退屈なことはPythonにやらせよう（オライリー・ジャパン）