Redis Port 다운 증상에 대한 원인 분석 구현 - deprecated

모든 장애 상황에 대응하는 프로그램을 만들기 전에, 우선 한 알림에 대한 장애 원인 분석만 진행

 

처음 구상

장애 발생 시점부터 정상화 완료 시점까지의 이력을 시간 순서대로 뽑아내야 함

담당자가 장애 원인 파악을 위해 스크립트를 한번 돌리고, 정상화된 뒤 최종 타임라인 작성을 위해 스크립트를 한번 돌리는 식으로 진행

=> 장애 하나당 2번의 실행

 

1. Redis Port 다운 알림이 담당자에게 전송됨

Redis Port 다운 : [담당자] tc0d-lncloredn-p1901:10379 NHNCloud_LogNCrash_GOV_KR1(Redis) Redis Port is Down!

 

2. 로그 수집 스크립트 실행

실행 명령어 예시: python 파일명 알람내용복붙

스크립트 내에선 알람내용 파싱, output 추출, 로그 수집 로직 등 수행

 

3. 대상 서버에 접속해 원인 파악하기

여기선 Redis Port 다운 증상에 대한 원인만을 찾는다고 가정(실제론 각 장애별로 조사할 원인, 우선순위가 다 다를 것임)

 

[조사 우선순위]

1. OOM Killed

2. Too many connections

3. CPU 병목

4. 내부 로직 segfault

5. 디스크 full 및 병목

 

[우선순위 선정 이유]

• OS의 가용 메모리가 부족해지면 Redis는 강제로 kill당함. 죽었으므로 포트는 즉시 닫힘
• 포트 자체가 닫힌 것은 아니지만, 모니터링 에이전트가 헬스 체크를 시도한 접속이 실패하면 포트 다운으로 간주할 수 있음
• Redis는 싱글 스레드인데 keys같은 명령어를 실행하면 다른 모든 요청이 블로킹됨. 만약 모니터링 타임아웃이 발생한다면 포트 다운으로 간주할 수 있음
• segfault(패키지 충돌, 명령어 버그, RAM 불량 등)로 비정상 종료되는 경우는 안정적인 버전의 Redis에선 드문 일
• 메모리의 데이터를 디스크에 저장하는 작업에서 장애가 발생하면 Redis는 응답 불능 상태가 될 수 있음. 하지만 회사에선 Redis 데이터를 영구 저장하지 않고 캐시 목적으로만 사용한다고 들었으므로 후순위

---

개발 계획

Output 형태 예시

========================================
장애 제목        : [2025-03-15] [NHNCloud_LogNCrash] OOM Kill로 인한 Redis Port Down 발생
주요 증상        : Redis Port Down
대상 리전        : GOV_KR1
장애 접수 채널   : Dooray 알람
장애 처리 결과   : 진행중

장애 지속 시간   : 9분 48초   (발생 → 해결)
탐지 지속 시간   : 1분 48초   (발생 → 탐지)
인지 지속 시간   : 45초       (탐지 → 인지)
처리 지속 시간   : 7분 15초   (인지 → 해결)

발생 시각        : 2025-03-15 13:19:12
탐지 시각        : 2025-03-15 13:21:00
인지 시각        : 2025-03-15 13:21:45
해결 시각        : 2025-03-15 13:29:00  ← 2차 실행 시에만 기재

담당자 인지 방법 : 모니터링 알람
장애 발생 원인   : OOM Kill - 가용 메모리 부족으로 커널이 Redis 프로세스 강제 종료
장애 처리 부서   : 데이터운영팀

장애 타임라인
  13:19:12  OOM 발생 → redis-server 프로세스 강제 종료
  13:21:00  모니터링 에이전트 Port Down 탐지 및 알람 발송
  13:21:45  담당자 인지, 원인 분석 시작
  13:22:30  OOM Kill 원인 확정 (dmesg 로그 확인)
  13:28:00  redis-server 재기동 완료
  13:28:30  Port 응답 정상 확인
  13:29:00  서비스 정상화 완료
========================================

 

디렉토리 구조 예시

redis-alert-analyzer/
├── main.py                    # CLI 진입점 + 파이프라인 조립
├── parser.py                  # 알림 파싱
├── session.py                 # 1차↔2차 상태 저장/로드
├── log_collector.py           # SSH + Mock 로그 수집
├── analyzer.py                # 원인 판별 + 타임라인 추출
├── reporter.py                # Output 포맷 생성
├── config.py                  # SSH 설정, 로그 경로 등 상수
├── sessions/
│   └── 20250315_132145_tc0d-lncloredn-p1901_10379.json
├── tests/
│   ├── test_parser.py         # Phase 1
│   ├── test_session.py        # Phase 2
│   ├── test_log_collector.py  # Phase 3
│   ├── test_analyzer.py       # Phase 4
│   └── mock_logs/
│       ├── oom_dmesg.txt
│       ├── too_many_conn_redis.log
│       ├── cpu_slowlog_redis.log
│       ├── segfault_dmesg.txt
│       └── disk_full_dmesg.txt
└── output/
    └── (생성된 리포트 저장)

 

최종 계획 예시

[1차 실행]                            [2차 실행]
parse_alert()                         parse_alert()
log_collector.run()      →   저장   → session.json 로드
analyzer.analyze()       →   저장   → 파싱/로그/분석 결과 재사용
                                      resolved_at 만 추가
        ↓                                     ↓
 1차 output 출력                       최종 output 출력
 (미확인 항목 포함)                    (전체 타임라인 포함)

## 로그 수집 및 원인 분석 상세
```
우선순위 1 - OOM Kill
  수집: dmesg | grep -iE "oom|kill|out of memory"
        journalctl -u redis* --since "2 hours ago"
  판정: "Killed process" + "redis" 키워드 동시 확인
  역추적: dmesg 타임스탬프 또는 journalctl 로그 시각 → 최초 발생 시각

우선순위 2 - Too Many Connections
  수집: /var/log/redis/redis*.log 에서 "max clients" 키워드
        redis-cli -p {port} info clients (포트 생존 시)
  판정: "max number of clients reached" 로그 확인
  역추적: redis 로그 타임스탬프 → 최초 발생 시각

우선순위 3 - CPU 병목
  수집: redis-cli -p {port} slowlog get 20
        /var/log/redis/redis*.log 에서 KEYS·SCAN·BLPOP 키워드
  판정: slowlog 응답시간 > 1000ms 또는 blocking 명령어 확인
  역추적: slowlog 실행 시각 → 최초 발생 시각

우선순위 4 - Segfault
  수집: dmesg | grep segfault
        /var/log/redis/redis*.log 에서 "crashed·segfault" 키워드
  판정: redis-server 관련 segfault 로그 확인
  역추적: dmesg 타임스탬프 → 최초 발생 시각

우선순위 5 - 디스크 Full / 병목
  수집: df -h
        /var/log/redis/redis*.log 에서 BGSAVE·RDB·disk 키워드
  판정: 디스크 사용률 > 90% 또는 BGSAVE 오류 로그 확인
  역추적: redis 로그 타임스탬프 → 최초 발생 시각
```

---

## 3. 개발 순서
```
Phase 1  parser.py          알림 파싱
Phase 2  session.py         1차↔2차 상태 저장/로드
Phase 3  log_collector.py   SSH + Mock 로그 수집
Phase 4  analyzer.py        원인 판별 + 타임라인 추출
Phase 5  reporter.py        Output 포맷 생성
Phase 6  main.py            CLI 진입점 + 파이프라인 조립
Phase 7  tests/             각 Phase 완료 시 테스트 병행 작성

 

세션 파일 (sessions/{session_id}.json) 저장 내용

 

{
  "session_id": "20250315_132145_tc0d-lncloredn-p1901_10379",
  "created_at": "2025-03-15 13:21:45",
  "parsed": { "host": "...", "port": 10379, ... },
  "collected_logs": { "oom": "...", "connections": "...", ... },
  "analysis": { "cause": "OOM Kill", "timeline": [...], ... }
}

 

실행 인터페이스

# 1차 실행 (장애 발생 직후 - 원인 분석)
python main.py \
  --alert "Redis Port 다운 : [담당자] tc0d-lncloredn-p1901:10379 NHNCloud_LogNCrash_GOV_KR1(Redis) Redis Port is Down!" \
  --detected-at "2025-03-15 13:21:00"

# 2차 실행 (정상화 완료 후 - 최종 타임라인)
python main.py \
  --alert "Redis Port 다운 : [담당자] tc0d-lncloredn-p1901:10379 NHNCloud_LogNCrash_GOV_KR1(Redis) Redis Port is Down!" \
  --detected-at "2025-03-15 13:21:00" \
  --resolved-at "2025-03-15 13:29:00" \
  --final

 

parser.py 실행 테스트(실제 서버 접속 안함)

 

 

 

 

 

parser.py

핵심 기능

알림 메시지 원문 한 줄을 받아서 이후 모든 모듈이 사용할 구조화된 딕셔너리로 변환합니다. 알림 유형 판별 → 정규식 파싱 → 서비스명/리전 분리 → 시각 검증의 순서로 동작합니다.

특별히 고민한 내용

ALERT_PATTERNS 딕셔너리로 알림 유형별 파싱 규칙을 외부에 선언했습니다. 추후 CPU 사용률 초과, 메모리 부족 등 새 알림 유형이 생겼을 때 parse_alert() 함수 본체는 건드리지 않고 딕셔너리에 항목만 추가하면 됩니다.

서비스명/리전 분리를 _split_service_and_region()으로 독립시키고, REGION_SUFFIXES 리스트로 리전 패턴을 관리했습니다. 분리 로직이 파싱 로직에 묻혀있으면 새 리전 패턴 추가 시 정규식 전체를 수정해야 하지만, 이렇게 하면 리스트에 한 줄만 추가하면 됩니다.

detected_at을 HH:MM과 HH:MM:SS 두 형식 모두 허용하고 내부적으로 HH:MM:SS로 정규화했습니다. 담당자가 알림 수신 시각을 손으로 입력할 때 초 단위까지 입력하지 않는 경우가 많을 것이라 판단했습니다.

 

session.py

핵심 기능

1차 실행에서 수집/분석한 결과를 JSON으로 저장하고, 2차 실행에서 다시 불러와 resolved_at만 추가하는 방식으로 두 실행을 연결합니다. 세션 파일은 {날짜}_{시각}_{호스트}_{포트}.json 형식으로 저장됩니다.

특별히 고민한 내용

세션 ID를 acknowledged_at(인지 시각) 기반으로 생성했습니다. 처음엔 스크립트 실행 시각(datetime.now())으로 만드는 방법을 고려했는데, 그러면 1차와 2차 실행 시각이 달라서 ID가 달라집니다. 인지 시각은 1차 실행 시 고정되고 2차 실행 때도 --detected-at과 함께 동일하게 전달되므로, 같은 장애에 대해 항상 동일한 ID가 생성됩니다.

find_session()을 별도로 만들었습니다. 2차 실행 시 담당자가 세션 ID를 직접 기억해서 입력하는 건 번거롭기 때문에, 호스트+포트 조합으로 가장 최근 세션을 자동으로 찾아주도록 했습니다. 파일명 앞부분이 YYYYMMDD_HHMMSS 형식이라 문자열 내림차순 정렬이 곧 시간 역순 정렬이 됩니다.

update_logs(), update_analysis()가 새 객체를 반환하지 않고 동일 세션 딕셔너리를 직접 수정 후 반환(return session)합니다. 이렇게 하면 main.py에서 session = update_logs(session, logs) 형태로 자연스럽게 체이닝할 수 있고, 실수로 반환값을 버려도 세션이 유실되지 않습니다.

 

log_collector.py

핵심 기능

SSH 또는 Mock 파일로 dmesg와 Redis 로그를 수집한 뒤, DETECTION_RULES에 정의된 키워드로 원인별 필터링을 수행합니다. 결과는 CollectedLogs 데이터클래스에 원본 전문과 원인별 추출 결과를 함께 담아 반환합니다.

특별히 고민한 내용

수집(collect)과 판별(analyze)을 이 모듈에서 합치지 않고 분리했습니다. log_collector는 키워드에 매칭되는 라인을 뽑아내는 것까지만 하고, 어느 원인이 맞는지 우선순위 판단은 analyzer.py가 담당합니다. 만약 합쳤다면 "OOM과 segfault가 동시에 검출된 경우 무엇으로 판정하는가"같은 판단 로직이 수집 로직에 섞이게 됩니다.

원본 로그 전문(dmesg, redis_log)을 CollectedLogs에 함께 보존했습니다. 키워드 필터링 결과만 저장하면 나중에 "이 줄 전후 문맥이 어떻게 됐지?"라고 할 때 다시 서버에 접속해야 합니다. 장애 해결 이후 2차 실행 시점엔 로그가 유실됐을 수 있으므로, 1차 수집 때 원본을 세션에 통째로 저장해두는 것이 안전합니다.

mock_files 인자를 딕셔너리로 받고 DEFAULT_MOCK_FILES와 병합하는 방식을 썼습니다. 이렇게 하면 테스트에서 {"dmesg": "oom_dmesg.txt"}만 넘겨도 나머지 소스는 기본값이 채워지므로, 매 테스트마다 모든 파일을 명시할 필요가 없습니다. 또한 실제 SSH 모드와 Mock 모드가 collect() 함수 시그니처를 공유하므로 main.py에서 use_mock 플래그 하나만 바꾸면 됩니다.

---

[고민거리]

1안: 사후(장애 해결 이후) 스크립트를 한번만 실행해 장애 발생부터 해결까지의 타임라인을 정리하기

vs

2안: 장애 발생 직후 1차적으로 스크립트를 실행(원인 분석 및 휘발성 상태 정보 보존 목적) -> 1차 실행 때 수집한 정보를 사후 2차 실행에서 재활용하기

 

1안 선정 시 이유

• 구현이 간단
• 장애 원인 분석 기능은 사내 모니터링&알람 시스템이 이미 해주고 있을 수 있음
• os 커널 로그, redis 에러 로그, 전반적인 리소스 사용량 기록은 휘발되지 않으므로 이 정보만으로 타임라인을 작성해볼 수 있음

 

2안 선정 시 이유

• 사후 타임라인 작성 외, 장애 원인 분석에도 기여해 프로젝트의 가치가 높아짐
• 담당자가 정상화를 위해 시스템을 재시작하면 장애 직후 당시의 '디테일한 커넥션(클라이언트 IP) 정보', 'CPU full, OOM의 주범이 정확히 어떤 프로세스의 어떤 스레드인지', 'redis 내부 메모리 지표(메모리 단편화율, 캐시미스 비율, 명령 처리량)' 및 데이터 상태(키별 데이터 내용, ttl 등) 등은 휘발됨 => 2안 선정 시 더 많은 정보를 활용해 타임라인을 작성할 수 있음

 

 

장애 최초 발생 시각 역추적 방식 후보군

• Redis 종료/크래시 이벤트의 timestamp
• 포트 리스닝이 사라진 흔적/재시작 흔적의 첫 시각
• 헬스체크 실패(모니터링 로그)가 있으면 그 첫 시각

• • 아무것도 없으면: “탐지 시각 - (모니터링 interval + retry)” 같은 보수적 추정치

 

[질문거리]

디테일한 정보(OOM이 발생했다고 가정했을 때, 정확히 어떤 프로세스의 어떤 스레드가 주범인지)는 OS 커널 로그에 남지 않는다.

그러므로 장애 발생 직후의 휘발성 상태 정보를 가져오는게 낫지 않나?

 

하지만 장애 발생 직후, 담당자가 스크립트를 실행해 top같은 명령어로 현 시점 메모리 사용량이 높은 프로세스&스레드 ID를 가져온다면, 메모리 사용량이 높은 프로세스&스레드가 시시각각 변동돼서 정확히 어떤 ID의 프로세스가 OOM의 주범인지 알아내지 못하는 경우가 생길 수 있다. 그럼에도 이런 디테일한 정보도 수집해서 타임라인 작성에 반영해야 하나?

 

[그 외]

공통: 담당자가 알림 메시지를 보고, 직접 판단해서 필요한 상황에만 스크립트를 실행(만약 failover 메시지가 왔는데 담당자가 실행하고 싶지 않으면 실행하지 않는거고)

 

스크립트 실행은 처음에 원인 파악 용도로 한번 실행하고, 마지막에 최종 타임라인 작성 용도로 한번 실행

담당자가 원인 파악이 필요하지 않다고 느끼면 자율적으로 스크립트는 실행하지 않아도 됨