느린 로그 조회, 운영 데이터로 원인을 좁혀보기

2026-09-30 개정. 8월 기록에 이번 운영 조사 결과를 보완했습니다. 이 글은 현황과 인덱스 검토까지 다룹니다. 모듈 분리·팀 설득·적용 과정은 2편에 기록하며, 운영 적용 결과는 아직 없습니다.

로그 조회에 30초에서 1분이 걸린다는 이야기가 나왔다. 결제 장애를 조사하려고 거래번호를 검색하는데, 결과를 기다리는 데부터 시간이 들었다.

인덱스를 추가하기 전에 현재 상태부터 확인하기로 했다. 얼마나 쌓였는지, 어떤 인덱스가 있는지, 실제 조회가 어떤 계획을 선택하는지 순서대로 살펴봤다.

• 운영 조사에서 로그 테이블 네 개에 보조 인덱스가 없고, 조사한 조회 여덟 개가 모두 전체 스캔을 선택한다는 것을 확인했다.
• 거래번호·요청 식별자·기간을 따로 조회하므로, 세 컬럼을 한 인덱스로 묶는 것만으로 충분한지 검토해야 했다.
• 이번 조사는 실행계획까지다. 최종 인덱스 구성과 운영 성능 개선 폭은 아직 검증하지 않았다.

먼저, 언제 어디서 얻은 숫자인지 나눴다

8월의 작업 기록에는 거래번호 조회가 약 45.36초 걸린 EXPLAIN ANALYZE 결과가 있다. 9월 30일에는 인덱스 작업을 준비하며 운영을 다시 조사했다. 이번에는 일반 EXPLAIN까지만 실행했다.

두 결과를 같은 측정처럼 섞으면 안 된다. 과거 시간은 당시 결과이고, 이번 조사에서는 인덱스 현황과 실행계획을 확인했다. 아래 표의 행수도 실제 COUNT(*)가 아닌 InnoDB 추정치다.

SELECT VERSION() AS mysql_version,
       @@session.autocommit AS autocommit,
       @@session.time_zone AS session_time_zone;

결과는 MySQL 8.0.36, autocommit 1, 세션 시간대 +00:00이었다. 실제 조사에서는 DATABASE()로 대상 스키마도 확인했다. 시간 범위 조회는 이 세션 시간대에 맞춰 해석해야 한다.

크기만 보지 않고 인덱스 정의까지 확인했다

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

추정 행수 합계는 약 1,040만 건, data_length 합계는 약 6.65GiB였다. InnoDB에서 이 값은 클러스터드 인덱스에 할당된 공간을 나타내므로 JSON 본문만의 크기나 이번 쿼리의 디스크 읽기량으로 볼 수 없다. 크기 통계에는 캐시와 반올림도 개입할 수 있다. 테이블 통계의 의미

그래서 index_mib=0.0만으로 결론을 내리지 않고 실제 정의를 확인했다.

SELECT table_name, index_name, non_unique, seq_in_index,
       column_name, sub_part, index_type
FROM information_schema.statistics
WHERE table_schema = DATABASE()
  AND table_name IN ('request_log', 'response_log',
                     'back_request_log', 'back_response_log')
ORDER BY table_name, index_name, seq_in_index;

네 테이블 모두 PRIMARY / id / BTREE 한 개씩만 나왔다. SHOW CREATE TABLE 결과도 같았다. 정확한 표현은 인덱스가 없는 것이 아니라, PK 외 보조 인덱스가 없는 상태였다.

SHOW CREATE TABLE request_log;
SHOW CREATE TABLE response_log;
SHOW CREATE TABLE back_request_log;
SHOW CREATE TABLE back_response_log;

NULL 허용은 스키마의 속성이다. 실제 NULL 행의 존재나 개수까지 이 DDL로 확인한 것은 아니다.

DDL에서 확인한 차이도 있었다. 내부 요청·응답 로그의 거래번호는 NULL을 허용했고, 외부 응답 로그인 back_response_log에는 거래번호 컬럼 자체가 없었다. 이 응답을 거래번호로 추적하려면 요청 로그에서 correlation을 찾아 연결해야 한다. 인덱스를 추가해도 이 조회 경로는 필요하다.

조회 조건을 하나씩 넣어 실행계획을 봤다

거래번호, 요청 식별자인 correlation, 시간 범위를 나눠 조사했다. 아래 변수에는 같은 세션에서 문자열 거래번호·식별자와 유효한 시작·종료 시각을 설정해야 한다. 값의 타입과 문자셋·collation도 컬럼과 맞춰 확인한다.

공유본에는 값이 REPLACE_WITH_*로 표시돼 있다. 익명화한 것인지 미치환 값으로 실행한 것인지는 아직 확인하지 못했다. 따라서 아래 결과는 전달받은 계획의 기록이며, 실제 거래에 대한 선택도나 기간 조건의 타당성까지 검증한 자료는 아니다.

EXPLAIN SELECT id, transaction_no, correlation, create_time
FROM request_log WHERE transaction_no = @transaction_no;

EXPLAIN SELECT id, correlation, create_time
FROM request_log WHERE correlation = @correlation;

EXPLAIN SELECT id, transaction_no, correlation, create_time
FROM request_log
WHERE create_time >= @from_time AND create_time < @to_time
ORDER BY create_time DESC LIMIT 100;

다른 테이블에도 같은 형태의 조회를 적용했다. 전달받은 결과를 정리하면 다음과 같다.

여덟 계획 모두 전체 스캔을 선택했다. 기간 조회는 추가 정렬도 필요했다. 다만 rows는 실제 읽은 건수가 아니며, filesort가 디스크 정렬을 했다는 뜻도 아니다. 실제 실행시간을 알려면 별도 측정이 필요하다. MySQL EXPLAIN 설명

예를 들어 거래번호 조회의 원 결과는 다음과 같다. 빈 인덱스 필드는 읽기 쉽게 NULL로 표시했다.

table=request_log, type=ALL, possible_keys=NULL, key=NULL,
rows=4537439, filtered=10, Extra=Using where

filtered=10은 통과할 행의 비율을 10%로 추정했다는 뜻이다. 실제로 10%가 일치했다는 측정값도, 이 컬럼에 관한 모든 통계가 없다는 증거도 아니다. 조회값과 통계 상태를 확인하기 전에는 추정의 내부 원인을 단정하지 않았다.

LIMIT 100도 스캔을 100행에서 끝낸다는 보장은 아니다. 정렬된 결과를 얻으려면 후보를 먼저 찾아야 한다. 전체 스캔 계획 자체가 항상 나쁜 것은 아니지만, 소수 거래를 찾으려는 조회에서는 효율적인 접근 경로를 검토할 근거가 된다.

조사 시점의 트랜잭션·메타데이터 락 조회 결과는 비어 있었다. 계측·권한 범위 안에서 그 순간 관찰한 결과일 뿐, 느린 조회에 잠금이 전혀 관여하지 않았거나 인덱스 작업 때도 대기가 없을 것이라는 보장은 아니다.

컬럼 세 개를 묶으면 될 것 같았지만 조회 조건이 달랐다

처음에는 (transaction_no, correlation, create_time) 복합 인덱스를 생각했다. 하지만 거래번호 없이 correlation만 조회하거나 시간만 조회하는 경우도 있었다. 하나의 복합 인덱스로 이 조회들을 모두 효율적으로 처리한다고 볼 수 없었다. 컬럼을 모으기 전에 실제 WHERE와 ORDER BY를 봐야 했다. 복합 인덱스의 왼쪽 접두어 규칙

과거에는 단일 컬럼 인덱스 총 11개를 설계했다. 이번 계획만으로 그 구성이 최적이라고 확정하지는 않았다. 거래번호와 기간을 함께 쓰는지, 식별자만 찾는지, 실제로 어떤 컬럼을 읽는지 확인한 뒤 최종 구성을 정해야 한다.

다음은 실제 조회 패턴과 대조할 후보다. 전부 만들겠다는 목록은 아니다.

(transaction_no, correlation, create_time)에서 correlation 조건을 빼면, 거래번호로 범위를 좁힐 수 있어도 그 뒤의 시간 조건을 (transaction_no, create_time)과 똑같이 활용한다고 볼 수 없다. 가능한 예외 최적화를 포함해 실제 실행계획으로 비교할 부분이다. 복합 인덱스를 채택하면 같은 선두 컬럼의 단일 인덱스까지 필요한지도 검토한다.

또 이번 쿼리는 일부 컬럼만 선택했다. 장애 조사에서 headers·body까지 읽는 SELECT *를 쓴다면, 그 SQL도 따로 검증해야 한다. 보조 인덱스로 후보를 찾는 비용과 본문을 포함한 행을 읽는 비용은 다르다.

인덱스가 늘면 쓰기 때 유지할 자료구조도 늘어난다. 그러나 얼마나 느려질지는 아직 측정하지 않았다. 키의 분포만으로 특정 인덱스가 다른 둘보다 비싸다고 단정했던 기존 설명은 뺐다.

이번 조사로 확인한 것과 남은 것

보조 인덱스가 없고, 조사한 여덟 계획 모두 전체 스캔을 선택했다. 거래번호로 소수 행을 찾으려는 목적에 맞춰 인덱스를 검토할 근거는 확보했다. 다만 이번 결과만으로 조회 지연의 전부를 설명하거나 개선 배수를 예측할 수는 없다.

다음 측정에서는 실제 느린 SQL과 조회값을 고정해야 한다. 실행계획은 일반 EXPLAIN으로 먼저 비교하고, 실제 시간·읽은 행수는 부하를 확인한 별도 측정에서 기록한다. EXPLAIN ANALYZE는 쿼리를 실제 실행하므로 운영에서 무작정 반복하지 않는다. EXPLAIN ANALYZE

이제 남은 질문은 적용 순서였다. 인덱스를 만드는 동안 계속 들어오는 로그를 어떻게 처리할 것인가. 2편에서는 모듈 분리와 팀 설득, 개선 진행을 다룬다. 마지막 결과는 운영 인덱스 적용과 누적 로그 처리를 확인한 뒤 기록할 예정이다.

이번 개정에서 바로잡은 설명

기존 원고의 ‘인덱스 생성 시 통계가 갱신되지 않는다’와 ‘빌드가 대량 redo를 만든다’는 설명을 정정한다. 인덱스 추가 시 통계는 계산되며, sorted index build 자체는 redo logging을 비활성화한다. 동시 DML과 I/O 비용은 별개다. 통계, Sorted Index Builds

디스크 한계·LRU 덕분의 무영향·JSON overflow 여부를 측정 없이 확정한 설명도 제거했다. 과거 45.36초 기록은 남기되 이번 조사의 실측값으로 사용하지 않는다.