木曜の夜、定期タスクの日次ログを半年ぶんならべて、結果を一覧にしようとしました。
欲しかったのは単純な表です。どの日に、どのタスクが、SUCCESS だったか FAILED だったか。ログには毎回 Status: の行を書いてきたつもりでしたので、grep 一本で終わると考えていました。
結果は、読めたのが約半分でした。
files=519 entries=1076
読めた段: {'strict': 526, 'silent': 515, 'body': 24, 'header': 11}
手元の日次ログ 519 ファイル・1,076 件のうち、Status: 行から結果を読めたのは 526 件です。残りの半分近く(515 件)は、結果を示す語がどこにも見つかりませんでした。
ここからは、原因の切り分けと、正規表現を広げる道をやめた理由、最終行に「印」を1行だけ足す方式の作り方をお伝えします。個人開発の運用で定期タスクが増えた方の、参考になれば幸いです。
読めなかった半分は、月ごとに増えていました
まず、読めなかった件を月別に数えました。
3月はほぼ全件が読めています。ところが6月に一気に崩れ、そのまま戻っていません。
原因は、書式が壊れたことではありませんでした。定期タスクの種類が増えるたびに、それぞれが自分の書式でログを書き始めたのです。朝の更新、昼の見直し、統合作業、トラブル調査。6月以降で結果の語がなかった 448 件をファイル名で分けると、日次の本体ファイルが 166 件、見直し系(_brushup_am など)が 232 件、残り 50 件が統合作業やトラブル調査でした。
どのログも、書いた時点の私には読めるものでした。人が読むには問題がなく、機械が読もうとしたときに初めて困るのです。この種の負債は、気づくまで静かに溜まっていくのだと、今回あらためて感じました。
測定スクリプト — どの段で読めたかを一緒に記録します
数字を出したスクリプトを、そのまま載せます。ポイントは、結果を拾うだけでなく「どの段で拾えたか」を数えている点です。
#!/usr/bin/env python3
"""日次ログ(空行区切りの自由書式)から、1件ごとの結果を読み出す。
上から順に試し、どの段で読めたかも記録する(strict → header → body → silent)。"""
import re, sys, glob, collections, pathlib
WORDS = r"(SUCCESS|FAILED|PENDING_PUSH|PENDING|SKIPPED_DUPLICATE|SKIPPED|SKIP)"
HEAD = re.compile(r"^\[(?:\d{4}-\d\d-\d\d|\d\d:\d\d|[\w-]+ \d\d:\d\d)[^\]\n]*\]", re.M) # 行頭が日付か時刻の [..] だけを1件の始まりとみなす
STRICT = re.compile(rf"^\s*[-*]?\s*Status:\s*{WORDS}", re.M) # 決められた書式
INHEAD = re.compile(rf"^\[[^\]\n]+\]\s*{WORDS}", re.M) # [task 15:00] SUCCESS 型
LOOSE = re.compile(rf"\b{WORDS}\b") # 本文のどこかに書かれている
def split_entries(text):
starts = [m.start() for m in HEAD.finditer(text)]
if not starts:
return [text] if text.strip() else []
starts.append(len(text))
return [text[a:b] for a, b in zip(starts, starts[1:])]
def classify(block):
for name, rx in (("strict", STRICT), ("header", INHEAD), ("body", LOOSE)):
m = rx.search(block)
if m:
return name, m.group(1)
return "silent", None
def main(log_dir):
by_method, by_status, silent_files = collections.Counter(), collections.Counter(), []
files = sorted(glob.glob(str(pathlib.Path(log_dir) / "20??-??-??*.txt")))
for f in files:
blocks = split_entries(pathlib.Path(f).read_text(encoding="utf-8", errors="ignore"))
if not blocks:
silent_files.append((f, "empty")); continue
for b in blocks:
method, status = classify(b)
by_method[method] += 1
if status: by_status[status] += 1
else: silent_files.append((f, "no-status"))
print(f"files={len(files)} entries={sum(by_method.values())}")
print("読めた段:", dict(by_method))
print("結果 :", dict(by_status.most_common()))
print("読めなかった:", len(silent_files))
for f, why in silent_files[:5]:
print(" ", pathlib.Path(f).name, why)
if __name__ == "__main__":
main(sys.argv[1])
実行は、ログのあるディレクトリを渡すだけです。
python3 ledger_scan_status_fallback.py /path/to/log_dir
四つの段は、上から順に試します。strict は決めた書式(Status: SUCCESS)、header は [タスク名 15:00] SUCCESS のように見出し行に書かれた型、body は本文のどこかに語が出てくる型、どれも当たらなければ silent です。
silent の件数が、そのまま「機械から見て黙っているログ」の量になります。自分のログでも、まず3分でこの数字を出してみてください。
正規表現を広げても、拾えたのは 35 件でした
ここで私は、段を増やせば取り戻せると期待しました。header と body を足した結果が、上の 11 件と 24 件、合わせて 35 件です。全体(1,076 件)の約3%にすぎません。
しかも、広げた分には副作用がありました。body の段が拾った 24 件を目で確認したところ、結果ではない語を拾った例が混ざっていました。
無応答サーバーを残した検証 → FAILED in 2,032 ms
これは、見直し作業の中で行った検証の出力です。タスクの結果ではありません。それでも本文に FAILED が書かれているので、緩い正規表現は、この件を「失敗したタスク」として数えます。
予想と逆でした。読めない件を減らそうと正規表現を緩めるほど、誤報が増えます。 結果を示す語は、本文の中では結果以外の意味でも使われるからです。
そこで方針を変えました。ログを読む側を賢くするのをやめ、書く側が最終行に決まった形の印を1本だけ残します。
書き手の側: 最終行に1行だけ残す関数
印の仕様は、次の四つだけです。
- 1行で、タブ区切り(
RESULT・日付・タスク名・状態・補足)
- 状態は
SUCCESS SKIPPED PENDING FAILED の四つだけ。それ以外は書かせない
- 専用のファイルに追記する(人が読む日次ログとは分ける)
- 日付は JST に固定する
# source して使う。最後の工程で必ず1回呼ぶ: log_result <task> <STATUS> [detail]
log_result() {
local task="$1" status="$2" detail="${3:-}" day
case "$status" in SUCCESS|SKIPPED|PENDING|FAILED) ;; *) echo "log_result: 未知の状態 '$status'" >&2; return 2;; esac
day="$(TZ=Asia/Tokyo date +%F)"
detail="${detail//$'\t'/ }"; detail="${detail//$'\n'/ }" # 1行・タブなしに潰す
printf 'RESULT\t%s\t%s\t%s\t%s\n' "$day" "$task" "$status" "$detail" >> "${LOG_DIR:?LOG_DIR 未設定}/_results.tsv"
}
状態の綴りを間違えたときに return 2 で止めているのは、印そのものの信頼性を守るためです。PENDINGG のような綴りが一件でも紛れると、読む側は「未知の状態」を扱う分岐を抱え続けることになります。書く時点で弾けば、読む側は四つの語だけ知っていれば済みます。
補足欄のタブと改行を空白に潰しているのも、同じ理由です。補足にタブが入ると列がずれ、読む側が行を捨てる羽目になります。
使い方は、タスクの最後の工程で呼ぶだけです。
source "$HOME/scripts/log_result.sh"
log_result daily-content SUCCESS "push=abc123"
読み手の側: 朝に1コマンドで、動くはずのタスクを点検します
印を残しても、読む側が「期待するタスク」を知らなければ、何も言わずに止まったタスクには気づけません。ログに行がないことは、読み手が「あるはずだった」と知って初めて異常になります。 そのため、点検スクリプトには期待するタスクと曜日を持たせました。
#!/usr/bin/env python3
"""朝の点検: 期待するタスクごとに、その日の RESULT 行を探して判定する。
使い方: morning_check_results.py <LOG_DIR> [YYYY-MM-DD] 終了コード 0=全部OK / 1=要確認あり"""
import sys, csv, datetime, pathlib, collections
EXPECTED = { # タスク名: 動く曜日 (月=0 … 日=6)。毎日なら全曜日
"daily-content": set(range(7)),
"premium-thu": {3},
}
OK_STATES = {"SUCCESS", "SKIPPED"} # SKIPPED は「理由つきで止めた」ので異常扱いしない
def load(path):
latest, bad = {}, 0
if not path.exists():
return latest, bad
with path.open(encoding="utf-8") as fh:
for row in csv.reader(fh, delimiter="\t"):
if len(row) < 4 or row[0] != "RESULT":
bad += 1; continue # 壊れた行は数えて先へ進む
_, day, task, status, *rest = row
latest[(day, task)] = (status, rest[0] if rest else "") # 同じ日は後勝ち
return latest, bad
def main():
log_dir = pathlib.Path(sys.argv[1])
day = sys.argv[2] if len(sys.argv) > 2 else datetime.date.today().isoformat()
wd = datetime.date.fromisoformat(day).weekday()
latest, bad = load(log_dir / "_results.tsv")
problems = []
for task, weekdays in EXPECTED.items():
if wd not in weekdays:
continue
status, detail = latest.get((day, task), ("MISSING", "印が1行もありません"))
mark = "ok " if status in OK_STATES else "NG "
print(f"{mark}{task:<14}{status:<8}{detail}")
if status not in OK_STATES:
problems.append(task)
if bad:
print(f"(読めない行 {bad} 件)")
sys.exit(1 if problems else 0)
if __name__ == "__main__":
main()
動作確認は、試験用の印ファイルで行いました(実際のログではありません)。同じ日に失敗と成功が混ざる場合と、壊れた行、期待したのに印のない場合を入れてあります。
--- 木曜 (2026-10-22)
ok daily-content SUCCESS retry ok
NG premium-thu MISSING 印が1行もありません
(読めない行 1 件)
exit=1
daily-content は同じ日に FAILED と SUCCESS が並んでいても、後勝ちで ok になります。再試行で復旧した日を異常として数えたくなかったためです。一方 premium-thu は印が一度も書かれていないので MISSING、終了コードは 1 になります。
この終了コード 1 を、別の通知に繋ぐだけで「何も言わずに止まった朝」に気づけます。
手元のタスクに入れる手順 — 私は次の順番で進めました
- 測定スクリプトを実ログに当てて、
silent の割合を出します(ここで10%を超えたら、印を足す価値が十分にあると見ています)
log_result.sh を置き、タスク1本の最終工程にだけ log_result を足します
- 1週間ほど動かし、印ファイルが想定どおりに増えるのを確かめてから、他のタスクへ広げます
- 期待タスクの一覧を点検スクリプトに書き、終了コード 1 を通知へ繋ぎます
最初から全タスクに入れるより、1本で試してから広げる方を私は勧めます。状態の語や補足欄の書き方に迷いが出るのは、たいてい最初の1本目だからです。
落とし穴は三つありました
一つ目は、後勝ちは途中の失敗を隠すことです。再試行の最後が SUCCESS なら、その日は ok と表示されます。再試行がどれだけ起きているかを後から振り返りたい場合は、点検側ではなく印ファイルの生の行を残しておく必要があります。点検は「今日の結論」、印ファイルは「経過の記録」と役割を分けました。
二つ目は、期待タスクの一覧が古くなることです。タスクを止めたのに一覧から消し忘れると、毎朝 MISSING が出ます。逆に、新しいタスクを足したのに一覧へ入れ忘れると、そのタスクは一生点検されません。タスクを増減する手順に「一覧を直す」の一行を入れました。
三つ目は、過去のログを印に直そうとしないことです。515 件の silent を推測で埋める誘惑はありましたが、やめました。推測した状態を事実のように並べると、点検の意味がなくなります。過去は過去のまま、今日から印を残します。それが一番安全だったと、私は考えております。
判断と結び
私が選んだのは、読む側を賢くすることではなく、書く側の約束を1行に絞ることでした。ログは人が読むものとして自由に書き続けて構いません。機械が読むものだけを、最終行に別の形で残します。
ログの書式は揃えようとせず、機械が読む1行だけを分けて残します。 今回の収穫は、この一文に尽きるのかもしれません。
もし手元に長く動かしているタスクがあれば、まず測定スクリプトで silent の割合を出してみてください。その数字が、印を足すかどうかの判断材料になります。関連して、終了前に成果物そのものを検査する考え方は 「成功」と記録されたのに成果がゼロだった に、ログが前日分を上書きしていた件は 無人タスクのログが前日分を上書きしていた に書き残しております。