조건을 안 걸면 빠릅니다 — 45초짜리 로그 조회의 정체

제가 운영하는 QR 결제 중계 플랫폼은 오가는 HTTP 요청·응답을 전부 DB에 적재합니다. 결제 장애가 나면 이 로그가 1차 증거입니다. 어느 거래가 어느 단계에서 어떤 응답을 받았는지, 여기 말고는 볼 곳이 없습니다.

그런데 그 조회가 45초 걸렸습니다.

이상한 건 따로 있었습니다. 조건을 안 걸면 빨랐습니다. select * from request_log는 즉시 나오는데, where transaction_no = '...'를 붙이면 45초를 기다려야 했습니다. 보통은 반대입니다. 조건이 결과를 줄여주니까요.

이 글은 그 모순을 추적하고, 인덱스 구성을 확정하기까지 판단이 몇 번 뒤집혔는지에 대한 기록입니다.

결론부터 요약합니다.

• 원인: 4개 로그 테이블에 인덱스가 PK 하나뿐. 조건 조회는 전부 풀스캔이었고, "조건 없으면 빠른" 건 클라이언트가 붙인 LIMIT 500 때문이었습니다
• 결정: 단일 컬럼 인덱스 11개. VIEW는 만들려다 뺐고, 반영 경로는 환경별로 셋으로 나눴습니다
• 다음: 인덱스가 치르는 값, 운영에 넣는 법, 그리고 검증은 2편에서 다룹니다

1️⃣ "조건이 없으면 빠르다"는 착시

먼저 테이블 상태부터 봤습니다.

SELECT table_name, table_rows,
       ROUND(data_length /1024/1024, 1) AS data_mb,
       ROUND(index_length/1024/1024, 1) AS index_mb
FROM information_schema.tables
WHERE table_schema = DATABASE()
  AND table_name IN ('request_log','response_log','back_request_log','back_response_log');

index_length가 네 테이블 모두 정확히 0.0입니다. PK는 클러스터드 인덱스라 data_length에 포함되므로, 세컨더리 인덱스가 하나도 없다는 뜻입니다. 엔티티에 @Table(name = "request_log")만 있고 인덱스 선언이 없었으니 당연한 결과였습니다.

여기까지는 예상대로입니다. 문제는 "그런데 왜 조건 없는 조회는 빨랐나"입니다.

클라이언트가 LIMIT 500을 자동으로 붙이고 있었습니다. DataGrip을 비롯한 대부분의 DB 클라이언트는 결과 그리드를 보호하려고 조건 없는 SELECT에 페이지 크기 제한을 겁니다. 앞의 500행만 읽고 즉시 반환하니 빠를 수밖에 없습니다.

반면 WHERE transaction_no = '...'는 조건에 맞는 행이 어디 있는지 모르므로 끝까지 읽어야 합니다. 500행에서 멈출 수 없습니다. 같은 테이블인데 한쪽은 500행, 한쪽은 382만 행을 읽고 있었던 겁니다.

EXPLAIN ANALYZE가 이걸 그대로 보여줬습니다.

-> Filter: (request_log.transaction_no = ...)
     (cost=86661 rows=372663) (actual time=45358..45361 rows=1 loops=1)
    -> Table scan on request_log
         (cost=86661 rows=3.73e+6) (actual time=1.21..41174 rows=3.82e+6 loops=1)

읽어야 할 지점이 세 군데입니다.

첫째, 382만 행을 전부 읽어 1행을 얻었습니다. 선택도가 382만분의 1입니다. 인덱스가 이보다 더 잘 들어맞는 조건은 존재하지 않습니다.

둘째, 41.17초가 순수 테이블 스캔입니다. 2,207MB를 41.17초에 읽었으니 초당 약 54MB. 디스크 처리량 한계에 붙어 있습니다. 이건 쿼리를 아무리 다듬어도 안 줄어듭니다. 읽는 양 자체를 줄여야 합니다.

셋째, 옵티마이저 추정이 rows=372663인데 실제는 1입니다. 37만 배 틀렸습니다.

이건 옵티마이저가 멍청해서가 아니라 줄 수 있는 정보가 없어서입니다. InnoDB의 인덱스 통계는 전수 조사가 아니라 페이지 샘플링입니다(innodb_stats_persistent_sample_pages, 기본 20페이지). 그런데 인덱스가 없으면 샘플링할 대상 자체가 없습니다. 카디널리티를 추정할 근거가 0이니 MySQL은 filtered 에 고정 상수 10 을 꽂습니다. 실행계획의 추정 통과 행수 372,663도 3,726,611의 10% 언저리입니다 — 컬럼 분포를 계산한 값이 아니라 기본값에서 나온 숫자입니다.

이 숫자가 중요한 이유는, 인덱스를 만든 직후에도 통계는 자동으로 정확해지지 않기 때문입니다. 그래서 2편에서 ANALYZE TABLE을 반드시 돌립니다.

행이 유난히 무거운 이유도 있었습니다. 이 테이블들은 headers와 body를 json 컬럼으로 들고 있습니다. 370만 행에 2.2GB — 행당 평균 600바이트입니다.

여기서 InnoDB의 저장 방식이 한 겹 더 얹힙니다. 행 하나가 페이지(기본 16KB)의 절반을 넘지 못하므로, 큰 json 값은 행에 20바이트 포인터만 남기고 오버플로 페이지로 빠집니다. 그래서 풀스캔이 읽는 2.2GB는 "행들이 촘촘히 들어찬 2.2GB"가 아니라, 클러스터드 인덱스 리프와 오버플로 페이지가 섞인 2.2GB입니다. 스루풋이 초당 54MB에 그친 데는 이 산재도 몫이 있습니다.

이 사실은 2편에서 한 번 더 돌아옵니다 — 인덱스로 행을 1건으로 좁혀도 SELECT *면 그 오버플로 페이지를 다시 읽어야 하기 때문입니다.

⚠️ 정정 (2026-08). 위 두 문단의 오버플로 설명은 틀렸습니다. 나중에 직접 재보고 알았습니다.

InnoDB에서 값이 페이지 밖으로 빠지는 조건은 "행이 페이지의 절반을 넘을 때"인데, 그 경계를 실측하니 이 스키마에서 8,105바이트까지는 페이지 안에 그대로 들어가고 8,106바이트부터 나갑니다. 그런데 이 테이블은 바로 위에 적은 대로 행당 평균 600바이트예요. 임계값의 13분의 1입니다. 같은 성격의 2.1KB JSON을 재현한 테이블에서도 DATA_LENGTH ÷ COUNT(*)가 2,739바이트로 나왔고요. 오버플로가 아니라 인라인입니다.

그럼 SELECT *일 때 붙던 추가 페이지 요청은 뭐였을까요. 재보니 행마다 정확히 하나씩 붙습니다(25만 행에 249,832회). 오버플로라면 큰 값을 가진 행에만 붙어야 하는데 그렇지 않았어요. 📄 BLOB 계열 컬럼이 끼면 InnoDB의 프리페치 캐시가 꺼진다고 알려져 있고 그러면 이 숫자와 맞아떨어지는데, 소스로 확인하진 못했습니다.

자세한 측정은 『타지 않는 인덱스』 1장과 5장에 있습니다. 틀린 채로 두지 않되 지우지도 않으려고 원문은 그대로 남깁니다.

2️⃣ 50만 건인 줄 알았습니다

부끄러운 얘기를 하나 하겠습니다. 저는 이 테이블이 50만 건인 줄 알고 설계를 시작했습니다.

50만 건 기준으로 세운 적용 계획은 이랬습니다. "ALTER TABLE이 테이블당 수 초에서 수십 초 걸릴 것이다. 온라인 DDL로 돌리면 된다." 실제로 50만 건이었다면 맞는 계산입니다.

측정값을 받고 나서 이 계획을 다시 썼습니다. 370만 행에 2.2GB짜리 테이블의 인덱스 3개 빌드는 수 분 단위입니다. 그리고 수 분이라는 시간이 함정을 열어젖힙니다.

innodb_online_alter_log_max_size. MySQL은 온라인 ALTER가 도는 동안 들어온 변경을 별도 로그에 쌓았다가 마지막에 반영합니다. 이 로그가 기본 128MB이고, 넘치면 ALTER가 실패하며 지금까지 한 작업이 전부 버려집니다.

이 테이블들은 결제 요청마다 INSERT되는 핫패스입니다. 50만 건 규모에서 수십 초짜리 작업이었다면 신경 쓸 일이 아니었습니다. 수 분짜리 작업이 되는 순간 실제 위험이 됩니다.

수 분이 열어젖히는 함정은 이것만이 아니었지만 — 메타데이터 락, redo 압박, 복제 지연 — 그건 2편에서 따로 다룹니다. 여기서 하고 싶은 말은 다른 것입니다.

측정이 바꾼 건 설계가 아니라 적용 절차였습니다. 인덱스 구성은 그대로였지만, 언제 어떤 순서로 어떤 설정을 만지고 칠 것인가가 전부 달라졌습니다. "규모를 모르는 채 세운 계획은 규모가 드러나면 대개 절차부터 무너진다"가 이번에 얻은 감각입니다.

그래서 적용 순서를 작은 테이블 → 큰 테이블로 잡았습니다.

back_response_log (380k)  →  back_request_log (384k)
  →  response_log (3.6M)  →  request_log (3.7M)

앞의 두 개는 금방 끝납니다. 여기서 온라인 DDL이 실제로 통과하는지, 얼마나 걸리는지를 확인한 뒤 2GB짜리로 넘어갑니다. 절차를 싼 곳에서 검증하고 비싼 곳에 적용하는 겁니다.

그리고 ALTER 문에 두 가지를 명시했습니다.

ALTER TABLE request_log
    ADD INDEX idx_request_log_transaction_no (transaction_no),
    ADD INDEX idx_request_log_correlation (correlation),
    ADD INDEX idx_request_log_create_time (create_time),
    ALGORITHM = INPLACE, LOCK = NONE;

한 테이블의 인덱스를 한 ALTER 문에 묶었습니다. 세 번 나눠 치면 테이블을 세 번 훑습니다. 2.2GB를 세 번 읽는 것과 한 번 읽는 것의 차이입니다.

ALGORITHM=INPLACE, LOCK=NONE을 명시했습니다. 이걸 생략하면 MySQL이 알아서 고르는데, 조건이 안 맞을 때 조용히 테이블 복사(COPY) 방식으로 떨어져 운영 중 테이블이 잠깁니다. 명시하면 조건을 못 맞출 경우 에러로 실패합니다.

결제 로그 INSERT가 핫패스인 상황에서는 실패하는 편이 낫습니다. 실패는 눈에 보이지만, 조용히 잠기는 건 장애가 난 뒤에야 압니다.

3️⃣ 인덱스로 못 푸는 게 하나 있었습니다

네 테이블 중 하나, back_response_log에는 transaction_no 컬럼이 아예 없었습니다. 엔티티에도 그 필드가 없습니다. 이 테이블은 correlation이 유일한 진입점입니다.

거래번호로 이 테이블을 찾으려면 요청 로그와 조인해야 합니다. 인덱스로는 풀 수 없는 스키마 문제입니다.

세 가지 안을 놓고 고민했습니다.

컬럼 추가를 기각한 이유는 비용입니다. 엔티티를 고치면 라이브러리 재배포를 기다려야 하고, 기존 38만 행에 backfill UPDATE를 돌려야 합니다. 조회 편의 하나를 위해 치를 값이 아니었습니다.

VIEW는 실제로 만들려다 뺐습니다. 이점이 "거래번호가 없다는 걸 매번 기억하지 않아도 된다" 하나뿐이었기 때문입니다.

성능 이점은 0입니다. MySQL은 이런 단순 조인 뷰를 MERGE 알고리즘으로 처리합니다 — 뷰 정의를 바깥 쿼리에 풀어 넣으므로 실행 계획이 수동 JOIN과 완전히 같습니다. 바깥의 WHERE transaction_no = ?도 그대로 인덱스로 내려갑니다.

역으로, 뷰가 해로워지는 조건도 여기서 갈립니다. 뷰에 집계·UNION·DISTINCT처럼 머지할 수 없는 요소가 들어가면 MySQL은 TEMPTABLE 알고리즘으로 떨어져 뷰를 임시 테이블로 먼저 실체화합니다. 그러면 바깥 WHERE가 인덱스로 내려가지 못하고, 임시 테이블 전체를 만든 뒤 거기서 거릅니다. 지금 필요한 조인은 MERGE로 처리되므로 손해는 없지만, "뷰를 하나 만들어 두자"가 나중에 집계 한 줄을 얹는 순간 조용히 성능이 뒤집히는 구조이기도 합니다.

반면 비용은 실재했습니다. 제 작업 환경은 망 분리라 DB 객체가 하나 늘면 폐쇄망으로 옮길 대상이 하나 늡니다. 뷰는 엔티티에도 남지 않아 코드에서 추적되지 않습니다.

"VIEW는 요즘 안 쓰는 추세 아니냐"는 통념은 절반만 맞습니다. 기피되는 건 애플리케이션이 뷰에 의존하는 경우입니다. 운영자가 손으로 치는 ad-hoc 조회용 뷰는 그 정도로 논쟁적이지 않습니다. 이번에 뺀 이유는 "요즘 안 쓰니까"가 아니라 "이 환경에서 이점보다 비용이 크니까" 입니다.

결국 JOIN 쿼리를 문서로 남겼습니다. 이관 부담이 없고 어느 환경에서든 복사해 쓸 수 있습니다.

4️⃣ 인덱스를 세 곳에 넣어야 했습니다

인덱스를 정의할 자리가 하나가 아니었습니다. 이게 이 작업에서 가장 헷갈리는 부분이었고, 실수하면 조용히 어긋나는 지점이기도 합니다.

점선 두 개가 핵심입니다. 엔티티의 @Table(indexes = ...)는 인덱스를 만들지 않습니다.

ddl-auto: none이기 때문입니다. Hibernate가 스키마에 손대지 않는 설정이므로, 엔티티에 인덱스를 아무리 정확히 선언해도 운영 DB에는 아무 일도 일어나지 않습니다. 그 선언이 실제로 인덱스를 만드는 건 ddl-auto: create-drop인 테스트 환경뿐입니다.

그럼 왜 선언했느냐. 스키마를 코드에 남기기 위해서입니다. 6개월 뒤에 엔티티만 보고 "이 테이블엔 인덱스가 없구나"라고 오해하는 걸 막습니다.

여기서 자연스럽게 따라오는 함정이 하나 있습니다. 엔티티와 마이그레이션의 인덱스 이름이 어긋나면, 테스트 환경과 운영 환경이 서로 다른 인덱스를 갖게 됩니다. 테스트에서만 도는 쿼리 계획과 운영의 쿼리 계획이 달라지는 겁니다. 그래서 11개 이름이 세 곳에서 완전히 일치하는지를 기계로 대조했습니다.

운영을 따로 뺀 이유는 더 단순합니다. 운영 프로파일은 마이그레이션 도구가 꺼져 있습니다. 그래서 같은 SQL을 사람이 실행할 스크립트로 별도 전달합니다.

그리고 로컬 개발용 초기화 스키마에는 일부러 넣지 않았습니다. MySQL의 CREATE INDEX에는 IF NOT EXISTS가 없습니다(MariaDB와 다릅니다). 초기화 스키마와 마이그레이션 양쪽에 인덱스를 두면, 볼륨을 새로 만들 때 초기화 스키마가 인덱스를 만든 뒤 마이그레이션이 같은 인덱스를 또 만들려다 Duplicate key name으로 애플리케이션 기동이 실패합니다.

친절하게 "로컬에도 넣어두자"고 하는 순간 깨지는 종류의 함정입니다. 인덱스의 단일 진실 원천은 마이그레이션 하나로 정리했습니다.

5️⃣ 곁가지에서 나온 발견 — 예외가 나면 반대쪽이 빕니다

조사 쿼리를 문서로 남기려고 로깅 코드를 읽다가, 인덱스만으로는 못 고치는 걸 하나 찾았습니다.

프론트 구간(외부 → 우리)의 로깅 필터는 이렇게 생겼습니다.

try {
    filterChain.doFilter(request, response);
    storeRequestLog(request);            // ← try 안, doFilter 다음
} finally {
    storeResponseLog(request, response); // ← 항상 실행
}

doFilter가 예외를 던지면 요청 로그를 건너뛰고 응답 로그만 남습니다. 백엔드 구간(우리 → 결제사)은 정반대입니다. 요청 로그를 먼저 쓰고 외부 호출을 하므로, 타임아웃이면 응답 로그가 안 남습니다.

JOIN 기준을 잘못 잡으면 정작 보고 싶은 건이 결과에서 빠집니다. 프론트 구간을 요청 로그 기준으로 LEFT JOIN하면 예외로 끝난 건이 통째로 사라집니다 — 장애 조사에서 제일 궁금한 것들이 말이죠. 기준을 응답 로그로 잡으면 요청 쪽이 NULL인 행이 곧 "요청 처리 중 예외" 진단 신호가 됩니다.

하나 더 있었습니다. 요청 로그의 거래번호는 요청 본문에서, 응답 로그의 거래번호는 응답 본문에서 추출합니다. 거래번호가 서버에서 채번되는 최초 요청이면 요청 본문엔 없습니다. 즉 요청 로그만 거래번호로 뒤지면 최초 요청을 못 찾습니다.

인덱스 구성에 correlation이 네 테이블 모두 들어간 실질적 이유가 이것이었습니다. 거래번호로 못 찾는 행을 correlation으로 되짚어야 하니까요.

여기까지가 진단과 설계입니다.

이번 작업에서 가장 값졌던 건 인덱스를 건 것 자체가 아니라, "조건 없으면 빠른데"라는 한 문장을 그냥 넘기지 않은 것이었습니다. 그 모순이 없었다면 클라이언트가 LIMIT을 붙이고 있다는 걸 몰랐을 테고, "왜 이 쿼리만 느리지"를 한참 더 헤맸을 겁니다.

그런데 인덱스를 넣기로 정하는 것과 실제로 운영에 넣는 것은 다른 일이었습니다. 11개를 얹으면 쓰기가 얼마나 비싸지는지, LOCK=NONE이 정말 무중단인지, 그리고 나아졌다는 걸 어떻게 증명할지 — 2편에서 이어집니다.