この記事は Zenn に公開した記事の再掲です（原文・最新版: https://zenn.dev/acs_developer/articles/sqlite-connection-leak-launchd-maxfiles ）。
macOSのLaunchAgentで常駐させている自作のローカルWeb UI（ジョブキュー付き）が、ある朝から画面を開けなくなった。
厄介だったのは、落ちていないことだった。プロセスはrunning、ポートはLISTENのまま。それでもHTTPだけが通らない。最後に正常アクセスできたのは約36時間前だった。
この記事は、その状態から原因をファイルディスクリプタ（FD）の枯渇まで詰め、sqlite3のcontext managerの仕様に行き着いた記録である。
症状
$ curl -sS http://127.0.0.1:8000/
curl: (56) Recv failure: Connection reset by peer
同じことが、別経路（VPN越しのアクセス）でも起きた。経路に依存しない、つまりネットワーク側ではなくプロセス側の問題だと分かる。
一方で、素朴なヘルスチェックはすべて正常だった。
- LaunchAgentのジョブ: 稼働中
- Pythonプロセス: 生存
- 対象ポート:
LISTENのまま - データ格納先のディスク: マウント済み
「プロセスは生きている」「ポートは開いている」「でも接続が即座にリセットされる」という3点セットは、アプリの例外ではなくプロセスがそれ以上リソースを取れない状態を疑うサインになる。TCPの接続要求をaccept()できなければ、アプリのログには何も残らないまま接続がリセットされるからだ。
犯人を数える
そこでプロセスが掴んでいるFDを数えた。
# プロセスのFD総数
lsof -p 780 | wc -l
# 何を掴んでいるのか、種類別に
lsof -p 780 | awk '{print $NF}' | sort | uniq -c | sort -rn | head
結果が明快だった。
| 掴んでいるもの | 本数 |
|---|---|
queue.db |
122 |
queue.db-wal |
121 |
| その他（ソケット等） | 残り |
| 合計 | 255 |
そしてこのプロセスの上限は、
$ launchctl limit maxfiles
maxfiles 256 unlimited
255 / 256。1本の余裕もない。新しいHTTP接続のためのソケットが作れないので、接続はaccept()される前にリセットされる。curlから見ればConnection reset by peer、アプリから見れば「何も起きていない」。ログが空だった理由もこれで説明がつく。
WALモードのSQLiteは接続1本につき本体と-walの両方を開く。だから122対121というほぼ1:1のペアになる。この対称性は「接続がN本漏れている」ことの分かりやすい指紋だった。
原因: with conn: は close しない
漏らしていたのはここだった。
# Before
def db():
conn = sqlite3.connect(DB_PATH)
conn.row_factory = sqlite3.Row
return conn
# 呼び出し側
with db() as conn:
conn.execute("UPDATE jobs SET state = ? WHERE id = ?", (state, job_id))
with db() as conn: は、見た目がファイルのwith open()と同じなので閉じている気になる。しかしsqlite3.Connectionのcontext managerが面倒を見るのはトランザクションだけである。正常終了でcommit()、例外でrollback()。close()はしない。
つまり上のコードは、リクエストのたびに接続を1本ずつ増やしていく。GC任せで回収されることもあるが、参照が残る書き方や長命なプロセスでは当てにならない。ローカルで数回叩く分には何の問題も出ず、常駐して数日動いたときだけ顕在化する。今回、最後の正常アクセスから障害発覚まで約36時間かかったのはそのためだ。
修正
contextlib.contextmanagerで包み、finallyで必ず閉じる。
import sqlite3
import contextlib
@contextlib.contextmanager
def db():
conn = sqlite3.connect(DB_PATH)
conn.row_factory = sqlite3.Row
try:
yield conn
conn.commit()
except Exception:
conn.rollback()
raise
finally:
conn.close()
呼び出し側はwith db() as conn:のまま変えなくていい。挙動だけが変わる。
同じ見落としがもう1箇所あった。ワーカー起動時にログファイルを開いて子プロセスへ渡す処理で、親プロセス側のFDを閉じていなかった。ここもwith open(...) as f:で即座に閉じるようにした。子プロセスはfork/execの時点で複製済みのFDを持つので、親が閉じても書き込みは続く。
テストのために、DBパスを環境変数で差し替えられるようにもした。実サービスのキューを壊さずにライフサイクルを検証するためである。
DB_PATH = os.environ.get("APP_DB_PATH", DEFAULT_DB_PATH)
「直った」を数字で確認する
FDリークは、直したつもりで直っていないことが起きやすい。目視ではなく増分で確認した。
1. テスト環境で300回
DBパスを差し替えたうえで、状態取得APIを300回呼ぶテストを書いた。結果はFD増分3以下（テスト実行そのものが持つ揺れの範囲）。修正前ならここで300本近く増えている。
2. 実サービスで120回
処理中ジョブが0件のタイミングでサービスを再起動し、実物に対して同じことをした。
BEFORE=$(lsof -p "$PID" | wc -l)
for i in $(seq 1 120); do curl -s -o /dev/null "http://127.0.0.1:8000/api/state"; done
AFTER=$(lsof -p "$PID" | wc -l)
echo "$BEFORE -> $AFTER"
結果は23 -> 23。120リクエストを通してFD総数が1本も動かなかった。再起動後は両経路ともHTTP 200、保持データ（登録済みプロファイル2件・履歴4件・出力4件）も欠落なしを確認している。
学び
-
プロセスが生きていて接続だけ死ぬときは、リソース上限を先に疑う。 アプリのログを追っても何も出ない。
accept()できない障害はアプリより下のレイヤで起きている -
常駐プロセスの上限は、対話シェルの上限と違う。 手元のシェルで
ulimit -nを見ても意味がない。この環境ではLaunchAgent側のsoftmaxfilesが256で、そこが実際の天井だった。プロセスに適用されている値を直接確認すること -
with conn:はトランザクション境界であって、リソース境界ではない。sqlite3だけでなく、context managerを持つ接続系オブジェクト全般で確認しておく価値がある -
リーク修正の検証は「N回叩いて増分を測る」に尽きる。 実測で
23 -> 23まで出せば、主観の入る余地がない
上限を引き上げる（maxfilesを増やす）対処もあるが、それは枯渇までの時間を延ばすだけで、リークがある限りいつか同じ場所に戻る。数える → 閉じる → 増分ゼロを実測する、の順で潰すのが確実だった。
検証の記録や関連ツールはACS Developerで公開しています。