Python watchdogでフォルダ監視を仕込んだら、自分の保存で無限ループしてCPU98%まで行った話

「フォルダに何か落ちたら、勝手に走るやつ書きたいな」

地方の小さな事務所で、夜になって人気がなくなった部屋で、この手の自動化スクリプトを書くのが習慣になっています。日中はバタバタしていて落ち着いて書けないので、静かな時間にコーヒーを淹れて、エディタを開く。

業務自動化を書いていると、3ヶ月に1回くらいこの欲求が出てきます。共有フォルダにCSVがコピーされたら、Pythonが起きて、加工して、別フォルダに吐く。ユーザーは何も操作しなくていい。

理屈は単純です。Pythonにはwatchdogというライブラリがあって、pip install watchdogして20行くらい書けば、それっぽいフォルダ監視Botが動きます。実際、最初の30分は感動するくらい順調でした。

問題はその30分後でした。

目次

やりたかったのは本当に小さいこと

業務で使っているフォルダ構成はこんな感じです。

C:\work\watch_in\     ← ここにCSVが落ちる
C:\work\watch_out\    ← ここに整形後のCSVを吐く
C:\work\watch_log\    ← ここに処理ログを吐く

やりたかったのは、watch_inにCSVが新しく置かれたら、整形してwatch_outに書く。それだけです。150行で済む話のはずでした。

しかも一度書けば、深夜の手作業がまるごと消える。心が躍りました。

最初の20行は本当にすぐ動いた

watchdogの最小サンプルは公開ドキュメントにあって、ほぼコピペで動きます。実際にやってみた最初のコードはこんな感じでした。

import time
from pathlib import Path
from watchdog.events import FileSystemEventHandler
from watchdog.observers import Observer

WATCH_DIR = Path(r"C:\work\watch_in")
OUT_DIR = Path(r"C:\work\watch_out")
LOG_DIR = Path(r"C:\work\watch_log")


class Handler(FileSystemEventHandler):
    def on_created(self, event):
        if event.is_directory:
            return
        src = Path(event.src_path)
        if src.suffix.lower() != ".csv":
            return
        process(src)


def process(src: Path) -> None:
    out = OUT_DIR / src.name
    out.write_bytes(src.read_bytes())
    log = LOG_DIR / "watchdog.log"
    log.parent.mkdir(parents=True, exist_ok=True)
    with log.open("a", encoding="utf-8") as f:
        f.write(f"processed: {src.name}\n")


if __name__ == "__main__":
    observer = Observer()
    observer.schedule(Handler(), str(WATCH_DIR), recursive=True)
    observer.start()
    try:
        while True:
            time.sleep(1)
    finally:
        observer.stop()
        observer.join()

私の環境では、これでCSVを1枚watch_inに置くと、ちゃんとwatch_outに同じファイルが現れて、watch_log\watchdog.logに1行追記されました。

「やった、これで本番投入できる」と思った瞬間が、後から振り返ると地獄の入口でした。

異変は本番フォルダに切り替えた瞬間に起きた

検証用の小さなフォルダで動いたので、私は雑に本番フォルダに切り替えました。

WATCH_DIR = Path(r"C:\work")

実は本番ではログも、出力CSVも、全部C:\workの下にぶら下がっていました。深く考えずrecursive=Trueのまま、上の階層をまるごと監視対象にしたわけです。

夜10時、空調の低い音だけがする部屋で、スクリプトを起動してテスト用のCSVを1枚watch_inに置きました。すると、コンソールがすごい勢いで流れ始めました。

processed: test01.csv
processed: test01.csv
processed: test01.csv
processed: test01.csv
processed: test01.csv
...

10秒で127行。30秒で532行。タスクマネージャを開くと、PythonプロセスがCPU使用率98%に張りついていました。

その間、ログファイルwatchdog.logは、47分間で4.2GBまで膨らんでいました。静かだったはずの夜の事務所で、ノートPCのファンだけが、聞いたことのない高さで叫び続けていました。CPU98%の数字が、薄暗い部屋の中で妙に明るく見えていたのを覚えています。

何が起きていたのか

落ち着いて整理すると、原因はシンプルです。

  1. test01.csvwatch_inに置く
  2. Handler.on_createdが走る
  3. process()watch_out\test01.csvを書く
  4. その書き込みがC:\work配下の「新規作成イベント」として再びHandlerに届く
  5. Handlerがまた走る
  6. 同じくwatch_log\watchdog.logへの追記もイベントとして拾われる
  7. 2と6が連鎖して止まらなくなる

つまり、自分の出力が自分の監視対象に含まれていたわけです。これを業界用語で「フィードバックループ」と呼ぶらしい、と後で知りました。Slack通知やメール送信を組み合わせていたら、47分間で数千通のメールが飛んでいたはずです。

最初はエラーが出たわけでもなく、例外も投げず、ただ静かにCPUとディスクが燃えていく。watchdogは仕事を真面目にこなしていたのに、設計した私が悪いという、いちばん辛い種類の失敗でした。

落ち着いて書き直した最小構成

教訓を1行で書くと、監視対象と出力対象を絶対に同じ階層に置かないです。これを物理レイアウトとコードの両方で担保します。

落ち着いてから書き直したフォルダ構成はこうしました。

C:\work_pipeline\
    in\           ← 監視対象。ここしか見ない
    out\          ← 監視対象の外
    log\          ← 監視対象の外
    state\        ← 処理済みファイル名を覚える場所

Observerが見るのはin\だけ、recursive=False。出力は完全に別ディレクトリ。これだけで原理的に再発しません。

そのうえで、コードにも保険を3段重ねしました。

import json
import time
from pathlib import Path
from threading import Lock
from watchdog.events import FileSystemEventHandler
from watchdog.observers import Observer

BASE = Path(r"C:\work_pipeline")
WATCH_DIR = BASE / "in"
OUT_DIR = BASE / "out"
LOG_DIR = BASE / "log"
STATE_FILE = BASE / "state" / "processed.json"

WATCH_DIR.mkdir(parents=True, exist_ok=True)
OUT_DIR.mkdir(parents=True, exist_ok=True)
LOG_DIR.mkdir(parents=True, exist_ok=True)
STATE_FILE.parent.mkdir(parents=True, exist_ok=True)


def load_state() -> set[str]:
    if not STATE_FILE.exists():
        return set()
    return set(json.loads(STATE_FILE.read_text(encoding="utf-8")))


def save_state(state: set[str]) -> None:
    STATE_FILE.write_text(json.dumps(sorted(state)), encoding="utf-8")


class Handler(FileSystemEventHandler):
    def __init__(self) -> None:
        self.lock = Lock()
        self.state = load_state()

    def on_created(self, event):
        if event.is_directory:
            return
        src = Path(event.src_path)
        if src.suffix.lower() != ".csv":
            return
        if src.parent.resolve() != WATCH_DIR.resolve():
            return
        with self.lock:
            if src.name in self.state:
                return
            self._wait_until_stable(src)
            self._process(src)
            self.state.add(src.name)
            save_state(self.state)

    def _wait_until_stable(self, path: Path, timeout: float = 5.0) -> None:
        last = -1
        deadline = time.time() + timeout
        while time.time() < deadline:
            try:
                size = path.stat().st_size
            except FileNotFoundError:
                return
            if size == last and size > 0:
                return
            last = size
            time.sleep(0.3)

    def _process(self, src: Path) -> None:
        out = OUT_DIR / src.name
        out.write_bytes(src.read_bytes())
        log = LOG_DIR / "watchdog.log"
        with log.open("a", encoding="utf-8") as f:
            f.write(f"{time.strftime('%Y-%m-%d %H:%M:%S')} processed: {src.name}\n")


if __name__ == "__main__":
    observer = Observer()
    observer.schedule(Handler(), str(WATCH_DIR), recursive=False)
    observer.start()
    try:
        while True:
            time.sleep(1)
    except KeyboardInterrupt:
        pass
    finally:
        observer.stop()
        observer.join()

保険の3段は、src.parent.resolve() != WATCH_DIR.resolve()で監視対象外を弾く、processed.jsonで既処理を覚える、_wait_until_stableでファイル書き込み完了を待つ、の3点です。これで同じCSVが2回処理されることも、書きかけのファイルを掴むこともなくなりました。

私が47分後にやった3つの確認手順

コードを書き直しただけでは正直まだ不安だったので、本番投入前に毎回確認する3項目を固定しました。各項目をh3で章立てし、チェックリストとして紙に印刷して机に貼っています。

確認1: 監視対象と出力先を`Path.resolve()`で並べて目視

監視対象パスと出力先パスをPath.resolve()で絶対パスに展開し、コンソールに2行で並べて出力します。1文字でも被っていないか、目で追います。C:\work\inC:\work\outのように親が同じだと、後でrecursive=Trueに戻した瞬間に再発するので、親まで分けるのが安心です。

確認2: 監視対象を意図的に汚すテスト

監視対象フォルダに、わざとログっぽいファイルを書き込むテストを1本作っておきます。processed.jsonの件数が増えなければ、自己干渉ループは塞がっていると判断します。

確認3: 5分間放置してCPU使用率を眺める

これがいちばん効きます。watchdogは例外も出さず静かに暴走するので、起動して5分間、何もせずタスクマネージャのCPU使用率を眺めます。5%以下に張りつかないなら、どこかでループが起きていると疑います。ログ追記の暴走は、ファンの音より先に数字に出ます。

それでも残った最後の落とし穴

最後にひとつだけ補足を。watchdogのon_createdは、Windowsだとファイル書き込み完了前に発火することがあります。CSVが書き込み途中なのに開きにいって、空っぽのファイルを処理してしまう、というやつです。

これも実際にやってみてハマりました。10MBのCSVを置いた瞬間に処理が走って、0行のまま出力されました。エラーすら出ません。

対策は上のコードに入れた_wait_until_stableで、ファイルサイズが2回連続で同じになるまで待つ、という雑なロジックです。完璧ではありませんが、私の運用では4ヶ月止まっていません。

静かなフォルダの先にある世界

地方の小さな事務所で、watchdogが今日も静かにin\フォルダだけを見ています。CSVが落ちる、3秒でout\に整形済みファイルが現れる、ログに1行追記される。これだけのことが、47分のCPU98%の先にようやくたどり着いた景色です。

派手な機械学習でもAIエージェントでもない、シンプルなフォルダ監視Botですが、毎日30分の単純作業をまるごと消してくれます。watchdogを試す方には、最初の20行で感動した直後に、必ず「監視対象と出力先が分離されているか」だけ思い出してほしいです。

私のように、ノートPCのファンが叫ぶ夜を過ごさないために。

よかったらシェアしてね!
  • URLをコピーしました!
  • URLをコピーしました!

この記事を書いた人

コメント

コメントする

目次