ログが消えた区間を調べる

目標

「昨日の午後に何件か失敗したそうです」という報告を受けたのに、その区間のログがありません。ログ以外の痕跡で時刻を絞り、次回はログが残るようにするところまで進みます。

環境

/root/nologの下で作業します。現場は自分で作ります。これは準備であり、課題ではありません。

mkdir -p /root/nolog/logs /root/nolog/etc && cd /root/nolog
python3 - <<'PY'
import sqlite3, random, datetime
random.seed(11)
base = datetime.datetime(2026, 9, 7, 12, 0, 0)
con = sqlite3.connect('app.db'); cur = con.cursor()
cur.execute("create table orders(id integer primary key, status text, created_at text)")
rows, oid = [], 1
for m in range(240):
    t = base + datetime.timedelta(minutes=m)
    fail = random.randint(18, 26) if 123 <= m <= 126 else (1 if random.random() < 0.15 else 0)
    for _ in range(random.randint(8, 14)):
        rows.append((oid, 'PAID', (t + datetime.timedelta(seconds=random.randint(0, 59))).isoformat())); oid += 1
    for _ in range(fail):
        rows.append((oid, 'FAILED', (t + datetime.timedelta(seconds=random.randint(0, 59))).isoformat())); oid += 1
cur.executemany("insert into orders values (?,?,?)", rows); con.commit(); con.close()
with open('logs/access.log', 'w', encoding='utf-8') as f:
    for m in range(240):
        if 123 <= m <= 127: continue
        t = base + datetime.timedelta(minutes=m)
        for i in range(random.randint(5, 9)):
            f.write('%s GET /api/pay 200\n' % (t + datetime.timedelta(seconds=i * 6)).isoformat())
with open('logs/error.log', 'w', encoding='utf-8') as f:
    for m in range(130, 240):
        if random.random() < 0.2:
            f.write('%s WARN slow query 1200ms\n' % (base + datetime.timedelta(minutes=m)).isoformat())
PY
printf 'pool_size=2\ntimeout=1\n' > etc/app.conf
printf 'log_level=WARN\n' > etc/other.conf
touch -t 202609071402 etc/app.conf
touch -t 202608311000 etc/other.conf
ls -l --time-style=+%Y-%m-%dT%H:%M etc/

作られるものは、次のとおりです。

app.db            주문 2,000여 건 (status, created_at)
logs/access.log   접근 로그 — 사고 구간이 비어 있다
logs/error.log    오류 로그 — 보존 기간 때문에 뒷부분만 남았다
etc/app.conf      설정 파일
etc/other.conf    설정 파일

このコードブロックの韓国語の説明は、順に、app.dbは注文2,000件余り(status、created_at)、logs/access.logはアクセスログで事故の区間が空いている、logs/error.logはエラーログで保存期間のために後ろの部分だけが残っている、etc/app.confとetc/other.confは設定ファイル、という意味です。

作るもの

minute.txt    사고가 시작된 분과 그 근거
gap.txt       비어 있는 구간과, 로그가 사라진 범위
traces.txt    로그가 아닌 흔적 세 가지 이상
cause.txt     의심 대상과 배제한 후보
watch.sh      지금 진행 중인 문제에 붙일 사후 계측기
next.md       다음 조사를 줄이는 네 가지
report.md     정리

このコードブロックの韓国語の説明は、順に、minute.txtは事故が始まった分とその根拠、gap.txtは空いている区間とログが失われた範囲、traces.txtはログ以外の痕跡3つ以上、cause.txtは疑わしい対象と除外した候補、watch.shは今進行中の問題に付ける事後計装ツール、next.mdは次の調査を短縮する4つのこと、report.mdはまとめ、という意味です。

ステップ

現場を作ります。
データがログです。created_atを分単位でまとめて、失敗が集中した分を探します。平常値も一緒に書いて初めて、「集中した」ことが証明されます。
アクセスログで空いている区間を探し、エラーログがどこから残っているかも書きます。失われた範囲がわかって初めて、調査範囲が決まります。
ログ以外の痕跡を3つ以上集めます。ファイルの更新時刻だけでなく、起動・プロセス・パッケージ・証明書のうちから、1つ以上。
時刻を突き合わせて、候補を絞ります。除外した候補とその根拠も書いてください。
watch.sh: 時刻と観測値を定期的に残します。採点ツールが直接実行します。
next.md: ログ出力文・保存期間・相関ID・指標の4つを、具体的に書きます。
まとめます。

参考

ステップ2で指す分は、1つではありません。失敗が集中した区間が複数の分にまたがっているので、そのうちどの分を指してもかまいません。ただし、その分の件数と平常値を、一緒に書く必要があります。

ステップ5で時刻が合うものは、相関関係であって、因果ではありません。その区別をドキュメントに書いておくことが、あとで見当違いのものを元に戻す事態を防ぎます。

ログが消えた現場を作る

現場を作ります。

指示文の準備ブロックをそのまま実行します。エラーログが事故の区間からないことが、このラボの前提です。

データがログです

データがログです。created_atを分単位でまとめて、失敗が集中した分を探します。平常値も一緒に書いて初めて、「集中した」ことが証明されます。

created_atを分単位(substr(created_at,1,16))でまとめて、FAILEDを数えてみてください。値が跳ねる分が、事故の時刻です。平常値も一緒に書いて初めて、比較になります。

ないという事実も証拠

アクセスログで空いている区間を探し、エラーログがどこから残っているかも書きます。失われた範囲がわかって初めて、調査範囲が決まります。

アクセスログを分単位で数えると、0行の区間が見えます。そして、エラーログの最初の行が何時かも確認してください。どこまで消えたのかがわかって初めて、調査範囲が決まります。

ログ以外の痕跡を集める

ログ以外の痕跡を3つ以上集めます。ファイルの更新時刻だけでなく、起動・プロセス・パッケージ・証明書のうちから、1つ以上。

ファイルの更新時刻(ls -l --time-style)、起動時刻(uptime -s)、プロセスの開始(ps -eo lstart)、パッケージのインストール(/var/log/dpkg.log)のうち3つ以上。痕跡は時刻と一緒でなければ、突き合わせられません。

時刻を突き合わせて絞る

時刻を突き合わせて、候補を絞ります。除外した候補とその根拠も書いてください。

事故の開始時刻の直前に変わったものを探します。除外した候補とその根拠も書いてください。そして、時刻が合うのは相関関係であって因果ではない、という点も。

今進行中なら事後計装

watch.sh: 時刻と観測値を定期的に残します。採点ツールが直接実行します。

再現している間に、時刻と観測値を定期的に残します。荒削りでも何もないよりは優れていて、次の会議で唯一の根拠になります。採点ツールがこのスクリプトを直接実行します。

次回は今回より早く

next.md: ログ出力文・保存期間・相関ID・指標の4つを、具体的に書きます。

ログ出力文・保存期間・相関ID・指標の4つです。「何をどのくらいに」まで書いて初めて実行できます。今の保存期間が24時間だという事実も一緒に。

まとめ

まとめます。

事故の時刻・ログがなかったという事実・疑わしい対象・再発防止。そして、「ないという事実も証拠だった」というこの調査の核心を、落とさないでください。