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

한국어 원문으로 표시합니다.

목표

"어제 오후에 몇 건 실패했대요" 라는 신고를 받았는데 그 구간의 로그가 없습니다. 로그 말고 다른 흔적으로 시각을 좁히고, 다음번에는 로그가 남도록 만드는 데까지 갑니다.

환경

/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    설정 파일

만들 것

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

단계

현장을 만듭니다.
데이터가 로그다. created_at 을 분 단위로 묶어 실패가 몰린 분을 찾습니다. 평소 값도 함께 적어야 '몰렸다' 가 증명됩니다.
접근 로그에서 비어 있는 구간을 찾고, 오류 로그가 어디부터 남아 있는지도 적습니다. 사라진 범위를 알아야 조사 범위가 정해집니다.
로그가 아닌 흔적을 세 가지 이상 모읍니다. 파일 수정 시각만이 아니라 부팅·프로세스·패키지·인증서 중에서도 하나 이상.
시각을 대조해 후보를 좁힙니다. 배제한 후보와 그 근거도 적으세요.
watch.sh — 시각과 관찰값을 주기적으로 남깁니다. 채점기가 직접 돌립니다.
next.md — 로그 문장 · 보존 기간 · 상관 ID · 지표, 네 가지를 구체적으로.
정리합니다.

참고

2단계에서 짚을 분은 하나가 아닙니다. 실패가 몰린 구간이 여러 분에 걸쳐 있으니 그중 어느 분을 짚어도 됩니다 — 다만 그 분의 건수와 평소 값을 함께 적어야 합니다.

5단계에서 시각이 맞는 것은 상관관계이지 인과가 아닙니다. 그 구분을 문서에 적어 두는 것이 나중에 엉뚱한 것을 되돌리는 일을 막습니다.

로그가 사라진 현장 만들기

현장을 만듭니다.

지시문의 준비 블록을 그대로 돌립니다. 오류 로그가 사고 구간부터 없는 것이 이 실습의 전제입니다.

데이터가 로그다

데이터가 로그다. created_at 을 분 단위로 묶어 실패가 몰린 분을 찾습니다. 평소 값도 함께 적어야 '몰렸다' 가 증명됩니다.

created_at 을 분 단위(substr(created_at,1,16))로 묶어 FAILED 를 세어 보세요. 값이 튀는 분이 사고 시각입니다. 평소 값도 함께 적어야 비교가 됩니다.

없다는 사실도 증거다

접근 로그에서 비어 있는 구간을 찾고, 오류 로그가 어디부터 남아 있는지도 적습니다. 사라진 범위를 알아야 조사 범위가 정해집니다.

접근 로그를 분 단위로 세면 0줄인 구간이 보입니다. 그리고 오류 로그의 첫 줄이 몇 시인지도 확인하세요 — 어디까지 사라졌는지를 알아야 조사 범위가 정해집니다.

로그가 아닌 흔적을 모은다

로그가 아닌 흔적을 세 가지 이상 모읍니다. 파일 수정 시각만이 아니라 부팅·프로세스·패키지·인증서 중에서도 하나 이상.

파일 수정 시각(ls -l --time-style), 부팅 시각(uptime -s), 프로세스 시작(ps -eo lstart), 패키지 설치(/var/log/dpkg.log) 중 세 가지 이상. 흔적은 시각과 함께여야 대조할 수 있습니다.

시각을 대조해 좁힌다

시각을 대조해 후보를 좁힙니다. 배제한 후보와 그 근거도 적으세요.

사고 시작 시각 직전에 바뀐 것을 찾습니다. 배제한 후보와 그 근거도 적으세요. 그리고 시각이 맞는 것은 상관관계이지 인과가 아니라는 점도.

지금 진행 중이라면 사후 계측

watch.sh — 시각과 관찰값을 주기적으로 남깁니다. 채점기가 직접 돌립니다.

재현되는 동안 시각과 관찰값을 주기적으로 남깁니다. 거칠어도 아무것도 없는 것보다 낫고, 다음 회의에서 유일한 근거가 됩니다. 채점기가 이 스크립트를 직접 돌립니다.

다음엔 이번보다 빨리

next.md — 로그 문장 · 보존 기간 · 상관 ID · 지표, 네 가지를 구체적으로.

로그 문장 · 보존 기간 · 상관 ID · 지표 네 가지입니다. '무엇을 얼마로' 까지 적어야 실행됩니다 — 지금 보존이 24시간이라는 사실도 함께.

정리

정리합니다.

사고 시각 · 로그가 없었다는 사실 · 의심 대상 · 재발 방지. 그리고 '없다는 사실도 증거였다' 는 이번 조사의 핵심을 빠뜨리지 마세요.