왜 슬로우로그가 필요한가
Redis는 단일 스레드로 명령을 순차 처리한다. 따라서 하나의 명령이 오래 걸리면 그 뒤에 대기하던 모든 요청이 함께 밀린다. 평소 P99 지연이 1ms인 서비스에서 갑자기 응답이 수백 ms로 튀는 원인은 대부분 특정 명령 하나가 이벤트 루프를 오래 점유했기 때문이다. 슬로우로그(SLOWLOG)는 실행 시간이 임계값을 넘긴 명령을 메모리에 기록해 주므로, 어떤 명령이 범인인지 재현 없이 사후에 추적할 수 있다.
슬로우로그 설정과 확인
두 개의 파라미터로 동작을 제어한다. slowlog-log-slower-than는 마이크로초 단위 임계값이고, slowlog-max-len은 보관할 항목 수다. 실무에서는 10ms(10000μs)부터 시작해 노이즈를 보며 조정한다. 참고로 여기 기록되는 시간은 네트워크 왕복이나 클라이언트 대기가 아니라 명령 실행 자체에만 걸린 시간이다.
# 실행 시간 10ms 이상 명령을 최대 256개 보관
redis-cli CONFIG SET slowlog-log-slower-than 10000
redis-cli CONFIG SET slowlog-max-len 256
# 최근 10개 조회
redis-cli SLOWLOG GET 10
# 현재 쌓인 개수 확인 후 초기화
redis-cli SLOWLOG LEN
redis-cli SLOWLOG RESETSLOWLOG GET 결과는 [ID, 유닉스 타임스탬프, 소요 μs, 명령 인자 배열, 클라이언트 IP, 클라이언트 이름] 순으로 반환된다. 타임스탬프와 인자를 함께 보면 언제 어떤 키에 대한 명령이 느렸는지 특정할 수 있다.
자주 걸리는 원인
슬로우로그에 반복해서 올라오는 명령에는 패턴이 있다. 대부분 시간 복잡도가 O(N)이며 N이 커진 경우다.
| 명령 | 복잡도 | 문제 상황 | 대안 |
|---|---|---|---|
| KEYS * | O(N) | 전체 키스페이스 스캔 | SCAN 커서 순회 |
| HGETALL | O(N) | 필드 수만 개인 대형 해시 | HSCAN, 구조 분리 |
| SMEMBERS | O(N) | 거대 집합 전체 반환 | SSCAN, SRANDMEMBER |
| DEL bigkey | O(N) | 대형 키 동기 삭제 | UNLINK(비동기) |
수집 자동화
슬로우로그는 메모리에만 남고 max-len을 넘으면 오래된 항목부터 사라진다. 장기 분석을 하려면 주기적으로 긁어 외부에 적재해야 한다. 아래는 슬로우로그를 파싱해 집계하는 예시다.
import redis
from collections import Counter
r = redis.Redis(host="localhost", port=6379)
entries = r.slowlog_get(128)
# 명령어 이름별 발생 횟수와 최대 지연 집계
stats = {}
for e in entries:
cmd = e["command"].split()[0].decode() if isinstance(
e["command"], bytes) else e["command"].split()[0]
dur = e["duration"] # 마이크로초
cur = stats.setdefault(cmd, {"count": 0, "max_us": 0})
cur["count"] += 1
cur["max_us"] = max(cur["max_us"], dur)
for cmd, s in sorted(stats.items(), key=lambda x: -x[1]["max_us"]):
print(f"{cmd:12} count={s['count']:4} max={s['max_us']/1000:.1f}ms")
r.slowlog_reset() # 중복 집계 방지이 스크립트를 1분 주기 크론이나 사이드카로 돌려 Prometheus·로키 등에 넣으면, 특정 배포나 트래픽 시간대와 지연 급증의 상관관계를 볼 수 있다.
추적에서 최적화로
범인 명령을 찾았다면 수정 방향은 명확하다. KEYS는 커서 기반 SCAN으로 바꿔 이벤트 루프를 잘게 나눠 점유하게 한다. 대형 해시·집합은 애초에 키를 샤딩해 하나의 키가 무한정 커지지 않게 설계한다. 대형 키 삭제는 DEL 대신 UNLINK로 백그라운드 스레드에 넘긴다. 또한 여러 왕복을 유발하는 로직은 파이프라인이나 Lua 스크립트로 묶되, 스크립트 자체가 O(N) 루프를 돌면 그 스크립트가 새 병목이 되므로 주의한다.
운영 시 주의점
임계값을 0으로 두면 모든 명령이 기록되어 자체가 부하가 되므로 프로덕션에서는 금물이다. 반대로 너무 높게 잡으면 중요한 지연을 놓친다. 또 하나, 슬로우로그는 명령 실행 시간만 보여주므로 여기에 안 잡히는데 클라이언트 체감 지연이 크다면 원인은 네트워크, fork를 유발하는 RDB 저장, 또는 커넥션 포화일 가능성이 높다. 이 경우 LATENCY 명령이나 INFO의 latency 관련 지표를 함께 봐야 한다. 슬로우로그는 지연 추적의 출발점이지 전부가 아니라는 점을 기억하자.