MySQL EXPLAIN ANALYZE

 

 

MySQL의 EXPLAIN ANALYZE 읽어보기

 

테스트 DBMS: MySQL 8.0.35

 

본 문서는 StartUP Tuning(for MySQL) 강의의 일부를 책의 서술 형태로 정리한 문서입니다. 가장 아래에 PDF 버젼으로도 첨부드리니 필요하신 분은 다운 받아가시기 바랍니다.

 

SQL의 성능에 문제가 있을 때 우리가 가장 먼저 할 일은 실행계획을 살펴보는 것입니다. MySQL은 8버전부터 EXPLAIN ANALYZE 기능을 지원합니다. EXPLAIN ANALYZE는 “실제 실행된” SQL의 실행계획을 Tree 형태로 보여줍니다. 실제 실행계획은 SQL 성능 개선할 때 매우 유용한 기능입니다.
아래 SQL은 T_ORD_BIG 테이블에서 특정 일자의 데이터를 조회해 고객ID(CUS_ID)별 주문 건수를 구하는 SQL입니다. EXPLAIN ANALYZE를 사용했으므로 SQL의 실행 결과가 아닌 SQL을 처리한 과정에 해당하는 실행계획을 결과로 얻을 수 있습니다.

EXPLAIN ANALYZE
SELECT T1.CUS_ID ,COUNT(*) CNT
FROM   T_ORD_BIG T1 
WHERE  T1.ORD_DT = STR_TO_DATE('20170103','%Y%m%d')
GROUP BY T1.CUS_ID;

 

위 SQL을 실행하면 약 5.9초 정도의 시간이 걸리며, 아래와 같은 실제 실행계획이 출력됩니다. (지면상 실행계획의 일부 내용은 생략했습니다.)

-> Table scan on <temporary>  (actual time=5992..5992 rows=9 loops=1)
    -> Aggregate using temporary table  (actual time=5992..5992 rows=9 loops=1)
        -> Filter: (t1.ORD_DT = ('20170103')) (actual time=35.4..5985 rows=18000 loops=1)
            -> Table scan on T1 (actual time=0.0889..5303 rows=6.09e+6 loops=1)

 

Tree 형태의 실행계획은 일반적으로 가장 최하위 자식(Child) 단계부터 부모(Parent) 단계로 가면서 처리가 됩니다. 그러므로 위 실행계획의 흐름은 4->3->2->1 순서가 됩니다.

 

---

[Tip]
실행계획은 SQL의 내부적인 처리 흐름을 보여줄 뿐, 실제 DB 내부적인 처리 순서를 완벽하게 표현해주지는 않습니다.
4->3->2->1이란 순서가 4가 완료된 후 3이 실행되고, 3이 완료되면 2가 실행된다고 말하기는 어렵습니다.
4가 완료된 후 3이 처리되었을 수도 있으며, 4가 처리되면서 3이 동시에 처리될 수도 있습니다.
실행계획을 통해 내부적인 처리 순서를 완벽히 파악하기 보다는 전반적인 흐름을 이해하는 것에 초점을 맞추는 것이 좋습니다.

---

 

실행 계획의 처리 흐름대로 따라가면서 각 단계를 하나씩 살펴보도록 하겠습니다

 

4번 라인: Table scan on T1

가장 첫 번째 단계인 4번 라인을 보면, Table scan이란 작업이 실행되고 있습니다.

Table scan이란 테이블 전체를 검색하는 것을 뜻합니다. 테이블에 1억 건이 있다면 1억 건 전부를, 10억 건이 있다면 10억 건 전부를 검색했음을 뜻합니다.

Table scan 뒤에는 대상 테이블의 별칭이 적혀 있습니다.

현재 실행계획에는 Table scan on T1 이라고 표시되어 있습니다. 실행한 SQL의 FROM 절에서 T_ORD_BIG에 T1이란 별칭을 사용했습니다. 그러므로 Table scan의 대상이 T_ORD_BIG임을 알 수 있습니다.

감사하게도 실제 실행계획에는 해당 단계별로 수행된 시간과 처리한 건수의 정보를 actual 항목에 표시해 줍니다. 이와 같은 실제 처리된 정보는 SQL 튜닝에 매우 유용합니다. 4번 라인의 Table scan의 actual 정보는 다음과 같습니다.

• Table scan on T1 (actual time=0.0889..5303 rows=6.09e+6 loops=1)

actual의 time 부분을 살펴보면 0.0859..5303로 표시되어 있습니다.

이는 해당 단계가 0.0859ms에 시작해 5303ms에 종료되었음을 뜻합니다. 5303ms는 약 5.3초입니다. 위 SQL은 총 실행 시간이 5.9초 정도가 걸립니다. 그 중에 4번 라인의 Table scan이 5.3초로 대부분을 차지하고 있는 상황입니다.

actual 항목 중에 rows 부분도 주의 깊게 살펴봐야 합니다. rows는 해당 단계가 끝났을 때 추출된 실제 데이터 건수입니다.

여기에는 6.09e+6이라고 표시되어 있습니다. 이는 과학적 표기법(또는 지수 표기법) 형태의 수치로서 구글이나 GPT를 통해 일반적인 숫자로 환산해보면 6,090,000 입니다. 다시 말해 Table scan 단계에서 추출된 데이터는 6,090,000 건입니다.

이 수치는 정확히 T_ORD_BIG의 현재 데이터 건 수와 일치합니다. Table Scan에서 테이블 전체 데이터를 읽었다는 것을 알 수 있으며, 이 과정이 5.3초 정도가 걸렸음을 알 수 있습니다.

 

3번 라인: Filter

Table scan을 거쳐 다음 실행되는 단계는 3번 라인의 Filter입니다. Filter는 특정 조건을 사용해 데이터를 걸러내는 처리를 하는 작업입니다.

MySQL의 Filter 단계에는 Filter로 사용된 조건이 같이 표시됩니다. 3번 라인의 실행계획을 통해 ORD_DT 조건에 대해 Filter가 처리된 것을 알 수 있습니다.

• Filter: (t1.ORD_DT = ('20170103')) (actual time=35.4..5985 rows=18000 loops=1)

 

actual 항목을 보면 time 부분이 35.4..5985입니다. 35.4ms에 시작해 5985ms에 해당 단계가 완료되었습니다. 처리되는 시간대가 4번 단계의 Table scan과 겹치는 것으로 보아 3번과 4번이 동시에 처리되는 작업임을 유추할 수 있습니다. 실제로도 테이블의 데이터를 검색하면서 Filter 작업이 동시에 이루어집니다. 다만, MySQL의 Tree 실행계획에서는 별도 단계로 표시해준 것입니다. 다른 DBMS의 경우는 3번과 4번 단계를 하나의 단계로 표현해주기도 합니다.

3번 단계의 rows를 보면 18,000입니다. 4번 단계의 rows는 6,090,000이었습니다. 4번->3번 흐름으로 SQL이 처리되므로 6,090,000 건의 데이터에 접근해 결과적으로 18,000 건만 남았다고 해석할 수 있습니다. 이를 역산해보면 6,072,000 건((6,090,000-18,000)의 데이터가 4번에서 3번 단계를 거치면서 버려진 것입니다. 버려졌다는 것은 SQL 결과를 만드는데 불필요하다는 뜻입니다.

그러므로 이러한 불필요한 접근을 줄일 수 있다면 SQL 성능이 개선될 수 있습니다. 이는 다음 번에 이야기하기로 하고 계속해서 실행계획을 읽어 나가도록 하겠습니다.

 

2번 라인: Aggregate

2번 라인의 Aggregate는 데이터를 집계 처리하는 작업입니다.

• Aggregate using temporary table  (actual time=5992..5992 rows=9 loops=1)

 

현재 우리가 실행한 SQL에는 “GROUP BY T1.CUS_ID”가 포함되어 있습니다. 그러므로 DB 내부적으로 Aggregate 작업을 거쳐 집계된(GROUP BY) 결과를 만들어냅니다. actual 항목의 time을 보면  5992..5992로 5.9초에 시작해 5.9초에 끝난 것을 알 수 있습니다. 시작과 종료 시간이 0.000초로 매우 빨리 처리된 것입니다.

Aggregate를 거쳐 만들어진 결과 건수는 9입니다. actual의 rows를 보면 알 수 있습니다. Aggregate의 결과는 9건이지만, Aggregate를 수행한 대상 건수는 몇 건일까요? 바로 이전 실행 단계인 3번 라인의 Filter의 rows에 그 정답이 있습니다. 3번 라인의 Filter의 rows는 18,000 이었습니다. 그러므로 18,000 건의 데이터가 Aggregate 작업으로 공급되었으며, 18,000 건의 데이터를 집계해 9 건의 결과를 만든 것입니다.

이처럼 rows 항목은 이전 단계와 비교해 보는 것이 좋습니다. 각 실행 단계를 거치면서 데이터 양이 어떻게 변하는지 추적할 수 있으며, 이를 통해 과도한 데이터 흐름이 있는 단계를 찾아낼 수 있습니다.

1번 라인: Table scan on <temporary>

1번 라인의 처리 내용을 살펴보면 4번 라인과 마찬가지로 Table scan을 하고 있습니다.

• Table scan on <temporary>  (actual time=5992..5992 rows=9 loops=1)

다만 1번 라인의 Table scan 대상은 <temporary>라는 임시 테이블입니다. 이 임시 테이블은 2번 라인의 Aggregate를 거쳐 내부적으로 만들어진 테이블입니다. Aggregate 단계에서 9건의 데이터가 만들어졌으므로 <temporary>에는 당연히 9 건의 데이터만 담겨 있습니다. 9건의 데이터를 Table scan하는 작업은 매우 빠릅니다.

사실 실행 계획의 가장 마지막 단계는 SQL의 최종 결과를 단순 출력하는 단계로 대부분의 경우 주의 깊게 볼 필요는 없습니다.

 

지금까지의 내용을 기억하면서 아래 SQL과 실행계획을 다시 한번 꼼꼼하게 살펴보시기 바랍니다. 어느 부분이 현재 SQL의 가장 큰 문제인지 진단해볼 수 있을까요? 해결법은 찾지 못하더라도, 어느 부분이 가장 문제가 있다고 말할 수는 있어야 합니다.

EXPLAIN ANALYZE
SELECT T1.CUS_ID ,COUNT(*) CNT
FROM   T_ORD_BIG T1 
WHERE  T1.ORD_DT = STR_TO_DATE('20170103','%Y%m%d')
GROUP BY T1.CUS_ID;

-> Table scan on <temporary>  (actual time=5992..5992 rows=9 loops=1)
    -> Aggregate using temporary table  (actual time=5992..5992 rows=9 loops=1)
        -> Filter: (t1.ORD_DT = ('20170103')) (actual time=35.4..5985 rows=18000 loops=1)
            -> Table scan on T1 (actual time=0.0889..5303 rows=6.09e+6 loops=1)

해결법은 기회가 된다면 다음 글에 이어서 적어보도록 하겠습니다. 감사합니다.

 

아래는 지금까지의 내용을 PDF로 정리한 문서입니다.

20240424_StartUPTuning_실행계획.pdf

0.35MB

 

 

StartUP Tuning 오프라인 강의에서는 지금까지 설명한 내용을 아래와 같은 슬라이드로 설명합니다.

 

 

 

[StartUP Tuning]

• SQL 입문을 넘어선 MySQL을 활용한 SQL 튜닝 입문 교육
• 2024년 5월 주말 오프라인 교육 과정을 모집중: https://cafe.naver.com/dbian/7717

StartUP Tuning - MySQL/MariaDB를 활용한 SQL 튜닝 입문

​

[StartUP SQL]

• 데이터 분석가, 개발자, 기획자를 위한 SQL 입문 교육
• 교육용 슬라이드 전체 무료 오픈: https://sweetquant.tistory.com/497

StartUP SQL 소개 및 목차

​