[장애 이력 자동 작성 도구4] 로그 수집 스크립트 작성(OOM Killed 상황)

계획

1. Redis 설치 - 완료
2. Redis에 장애 발생시키기 - 완료
3. 장애 로그를 수집하는 스크립트 작성(OOM Killed 상황부터 구현 시작)
4. 두레이 태스크로 등록
5. Redis 센티널 설치 -> 마스터 다운, 복제 지연 등 상황 재현 -> 로그 수집 스크립트 작성

3번부터 계속

---

스크립트가 해야 할 일 정리

1. 대상 서버(hostname) 결정

   └── 인자 있으면 → SSH로 원격 수집

   └── 인자 없으면 → 로컬에서 직접 수집

 

2. 장애 발생 시각 역추적

후보

   └── dmesg에서 OOM Kill timestamp

   └── journalctl에서 redis 재시작 timestamp

   └── 포트 down/up 흔적

 

3. 장애 해결 시각 감지

후보

   └── redis-cli ping 성공 시점

   └── 마지막 재시작 후 30초 이상 kill 없음

 

4. 수집한 로그로 타임라인 구성

 

5. Output 출력 (사내 양식)

---

2. 장애 발생 시각 역추적 관련 추가 조사

 

dmesg는 간단한 커널 로그 확인에 적합하고, journal은 좀 더 폭넓은 로그 관리를 위한 도구

OOM Kill은 dmesg와 journalctl만 조사해도 충분하지만, 다른 시나리오는 추가 소스가 필요할 수 있음

장애 유형	추가로 필요한 소스
OOM Kill	dmesg + journalctl ✅
디스크 full	df, iostat
CPU 병목	/proc/stat, psutil
Too many connections	redis-cli INFO
Segfault	/var/log/syslog

 

dmesg는 journalctl보다 장애 발생 시각을 정확히 탐지하지 못함 => journalctl만 사용하기로 결정

이유

dmesg는 journalctl과 달리 '실제 시간' 단위로 로그를 기록하는 게 아니라, 부팅 이후 지금까지 경과한 '초'나 특정 dmesg 이벤트가 발생했을 당시까지 경과한 '초'처럼 초 단위로만 로그를 기록함

datetime.now(현재 시각)과 uptime(dmesg 부팅 이후 현재 시각까지 경과한 초)는 서로 동기화되지 않았기 때문에, 둘 사이의 미세한 타이밍 차이가 누적되어 몇 초의 오차가 발생함

---

스크립트 실행 방법 예시

  python3 collect_redis_incident.py                   # 로컬 실행
  python3 collect_redis_incident.py user@hostname     # 원격 실행 (SSH)

 

고려 사항

 

스크립트는 정상화 이후 한번만 실행할 목적으로 만들어짐

(장애 발생 때 한번 실행해놓은 뒤 장애 정상화 시점까지 백그라운드에서 장애 정상화 여부를 주기적으로 polling할 경우, 이미 장애가 발생한 서버에 부하를 줌)

물론, 정상화 이전에 스크립트를 실행해도 타임라인이 생성되도록 만들었으며, 스크립트 재실행 권장 메시지를 출력함

 

원래는 hostname(infa-testsrv-cb801)만 input으로 받으려 했으나, 이렇게 하면 ssh_user 이름 정보(irteamsu)를 코드 내에 하드코딩해 저장하지 않는 이상 ssh_user를 알 방법이 없음. 그래서 ssh_user도 input으로 받기로 결정함

 

참고

스크립트를 cb801 로컬에서 직접 실행 시, irteamsu에서 해야 함(스크립트 내부에서 sudo 권한 필요)

---

스크립트 실행 테스트 성공 스크린샷

로컬 실행 성공

 

hcon 서버에서 ssh irteamsu@cb801로 원격 실행 성공

---

코드 작성 시 고려한 부분

1. run 함수(명령어를 로컬 또는 ssh원격으로 실행하고 stdout 반환)에서 stdout 결과 문자열 반환 실패에 대한 예외 처리 개선

=> 명령 타임아웃(30초) 초과, 명령 권한 오류, 빈 결과 시 예외처리 로직 추가

 

2. 오늘 발생한 장애 로그만을 분석하는 로직으로 인해 발생한 '날짜 경계 문제'(23시~01시 동안 발생한 장애를 놓침) 해결

=> 스크립트 실행 시점 기준, 가장 최근에 발생한 '장애 로그 묶음'을 찾아 반환

장애 이벤트 간 간격이 5분 이상이면 별개 장애로 판단하고 가장 최근 묶음만 반환

5분 선정 이유: 장애 중 kill 간격은 최대 10초 수준이므로 5분은 충분한 경계라 판단

 

3. 정상화 판단 기준을 'Redis Started 이후 kill 없이 30초 지속'으로 결정

이유

전제: systemd는 Redis가 죽으면 자동 재시작을 진행함

OOM Kill 직후 systemd가 redis를 재시작하는 데 걸리는 시간은 로그 상 1~3초

재시작 직후 메모리 채우기 스크립트(Insert 작업)가 남아있으면 보통 2~5초 내에 다시 kill됨

=> 장애 상황에서는 kill 이벤트 간격이 최대 10초 수준이므로, 넉넉잡아 30초 동안 kill이 없으면 정상화로 판단해도 무방

---

시행착오

 

문제 상황

1. 장애 정상화 2시간 이후 'sudo systemctl status redis-server'로 Redis 상태를 확인해보면 active(running) 상태지만, 스크립트를 정상화 이후 실행해도 '장애 해결 진행 중'이라고 나옴

=> 로그 파싱 시 journalctl 출력 형식에 어긋나 문제 발생, strip()으로 해결

 

2. 로그에는 OOM Kill, Redis 재시작 등 다양한 로그가 기록되지만, 최종 output에는 OOM Kill 외의 다른 타임라인을 출력하지 못함

=> 1번 문제 해결로 자동 해결(strip으로 공백 제거 후 파싱)

---

코드 개선 여지

1: 12월 31일→1월 1일 걸친 장애는 연도 파싱이 틀어질 수 있음

2: 4280:X 24 Feb 2026 02:58:46.125 형태로 로그가 수집되는 것도 잘 파싱할 수 있나? (지금은 한글로 2월 27 15:00:13 나오는 걸 파싱한 상황)

3: killed_by_signal 원인 세분화 (OOM vs 외부 kill 구분) => dmesg 교차 검증, Journalctl 앞뒤 문맥 확인(가장 간단하고 현실적) 중 택1

 

고도화 후보군

1. 가장 최근에 발생한 장애 로그 묶음 '하나만' 타임라인을 정리하는 현재 방식 대신, 타임라인이 정리되지 않은 모든 장애를 타임라인으로 정리할 것인지 => 직전 장애 두레이 태스크 정보를 get으로 받아와야 하나?