MySQL 쿼리 프로파일링(Query Profiling)

Last Updated on 1월 4, 2024 by Jade(정현호)

안녕하세요
이번 포스팅에서는 쿼리 수행 시 여러 성능 지표나 통계를 확인할 수 있는 Query Profiling 에 대해서 확인해보려고 합니다.

Contents

쿼리 프로파일링(Query Profiling)
쿼리 프로파일링 활성화
프로파일링 사용
쿼리 프로파일링 비활성화
Reference

쿼리 프로파일링(Query Profiling)

MySQL 에서 쿼리가 처리되는 동안 각 단계별 작업에 시간이 얼마나 걸렸는지 확인할 수 있는 기능을 제공하며 쿼리 프로파일링(Query Profiling) 기능을 제공하고 있습니다.

쿼리 프로파일링(Query Profiling) 는 MySQL 5.1 이상에서 부 터 지원합니다.

기본적으로 활성화돼 있지 않기 때문에 사용시 먼저 프로파일링 기능을 활성화해야 합니다.

mysql> show variables like '%profiling%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| profiling              | OFF   |
+------------------------+-------+

사용할 예제 데이터베이스 와 테이블 목록입니다.

mysql> use employees;
mysql> show tables;
+---------------------+
| Tables_in_employees |
+---------------------+
| departments         |
| dept_emp            |
| dept_manager        |
| employees           |
| salaries            |
| titles              |
+---------------------+

쿼리 프로파일링 활성화

쿼리 프로파일링를 사용하기 위해서는 먼저 활성화가 필요 합니다.

활성화는 아래와 같이 수행하면 됩니다.

mysql> set profiling=1;

Query Profiling 를 사용하기 위해서 테스트 쿼리를 수행하도록 하겠습니다.

mysql> select * 
from employees
where emp_no=10001;


mysql> select count(*) 
from employees 
where emp_no between 10001 and 12000
group by first_name;

프로파일링 사용

show profiles

쿼리 프로파일링의 쿼리 목록은 아래와 같이 수행할 수 있습니다.

mysql> show profiles;
+----------+------------+----------------------------------------+
| Query_ID | Duration   | Query                                  |
+----------+------------+----------------------------------------+
|        1 | 0.00019375 | select *                               |
|          |            | from employees                         |
|          |            | where emp_no=10001                     |
|        2 | 0.00212875 | select count(*)                        |
|          |            | from employees                         |
|          |            | where emp_no between 10001 and 12000   |
|          |            | group by first_name                    |
+----------+------------+----------------------------------------+

profiling_history_size

profiling 정보는 모두 저장되는 것이 아니고 profiling_history_size 에 설정된 만큼 저장이 됩니다.

mysql> show variables like '%profiling_history_size%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| profiling_history_size | 15    |
+------------------------+-------+

기본 값으로 최근 15개의 쿼리에 대해서 저장되며 최대 100까지 설정이 가능 합니다.

FOR QUERY

특정 쿼리의 상세 프로파일링 정보를 조회하려면 for query [쿼리번호] 를 사용하면 됩니다.
위에서 언급한 쿼리번호는 위의 show profiles 에서 조회한 Query_ID 입니다.

mysql> show profile for query 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000049 |
| checking permissions | 0.000005 |
| Opening tables       | 0.000014 |
| init                 | 0.000018 |
| System lock          | 0.000007 |
| optimizing           | 0.000006 |
| statistics           | 0.000044 |
| preparing            | 0.000007 |
| executing            | 0.000002 |
| Sending data         | 0.000010 |
| end                  | 0.000003 |
| query end            | 0.000005 |
| closing tables       | 0.000005 |
| freeing items        | 0.000010 |
| cleaning up          | 0.000011 |
+----------------------+----------+

mysql> show profile for query 2;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000049 |
| checking permissions | 0.000005 |
| Opening tables       | 0.000012 |
| init                 | 0.000015 |
| System lock          | 0.000006 |
| optimizing           | 0.000006 |
| statistics           | 0.000040 |
| preparing            | 0.000008 |
| Creating tmp table   | 0.000016 |
| Sorting result       | 0.000003 |
| executing            | 0.000002 |
| Sending data         | 0.001631 |
| Creating sort index  | 0.000292 |
| end                  | 0.000003 |
| query end            | 0.000005 |
| removing tmp table   | 0.000003 |
| query end            | 0.000002 |
| closing tables       | 0.000004 |
| freeing items        | 0.000019 |
| cleaning up          | 0.000009 |
+----------------------+----------+

아래와 같이 INFORMATION_SCHEMA.PROFILING 를 조회하여도 동일한 결과를 확인할 수 있습니다.

mysql> SELECT STATE, FORMAT(DURATION, 6) AS DURATION 
FROM INFORMATION_SCHEMA.PROFILING 
WHERE QUERY_ID = 1 ORDER BY SEQ;

각 쿼리의 프로파일링 정보 중에 CPU 나 MEMORY 또는 DISK 와 관련된 내용만 구분할 수 있다.

mysql> show profile cpu for query 1;
+----------------------+----------+----------+------------+
| Status               | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| starting             | 0.000049 | 0.000034 |   0.000010 |
| checking permissions | 0.000005 | 0.000003 |   0.000001 |
| Opening tables       | 0.000014 | 0.000011 |   0.000003 |
| init                 | 0.000018 | 0.000014 |   0.000004 |
| System lock          | 0.000007 | 0.000005 |   0.000002 |
| optimizing           | 0.000006 | 0.000004 |   0.000001 |
| statistics           | 0.000044 | 0.000035 |   0.000011 |
| preparing            | 0.000007 | 0.000004 |   0.000001 |
| executing            | 0.000002 | 0.000002 |   0.000000 |
| Sending data         | 0.000010 | 0.000007 |   0.000003 |
| end                  | 0.000003 | 0.000002 |   0.000000 |
| query end            | 0.000005 | 0.000004 |   0.000001 |
| closing tables       | 0.000005 | 0.000004 |   0.000002 |
| freeing items        | 0.000010 | 0.000008 |   0.000002 |
| cleaning up          | 0.000011 | 0.000008 |   0.000002 |
+----------------------+----------+----------+------------+

CPU 키워드 대신에 BLOCK ID 와 MEMORY, SOURCE 키워드도 사용이 가능 합니다.

• BLOCK ID

mysql> show profile BLOCK IO for query 1;
+----------------------+----------+--------------+---------------+
| Status               | Duration | Block_ops_in | Block_ops_out |
+----------------------+----------+--------------+---------------+
| starting             | 0.000049 |            0 |             0 |
| checking permissions | 0.000005 |            0 |             0 |
| Opening tables       | 0.000014 |            0 |             0 |
| init                 | 0.000018 |            0 |             0 |
| System lock          | 0.000007 |            0 |             0 |
| optimizing           | 0.000006 |            0 |             0 |
| statistics           | 0.000044 |            0 |             0 |
| preparing            | 0.000007 |            0 |             0 |
| executing            | 0.000002 |            0 |             0 |
| Sending data         | 0.000010 |            0 |             0 |
| end                  | 0.000003 |            0 |             0 |
| query end            | 0.000005 |            0 |             0 |
| closing tables       | 0.000005 |            0 |             0 |
| freeing items        | 0.000010 |            0 |             0 |
| cleaning up          | 0.000011 |            0 |             0 |
+----------------------+----------+--------------+---------------+

• MEMORY

mysql> show profile MEMORY for query 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000049 |
| checking permissions | 0.000005 |
| Opening tables       | 0.000014 |
| init                 | 0.000018 |
| System lock          | 0.000007 |
| optimizing           | 0.000006 |
| statistics           | 0.000044 |
| preparing            | 0.000007 |
| executing            | 0.000002 |
| Sending data         | 0.000010 |
| end                  | 0.000003 |
| query end            | 0.000005 |
| closing tables       | 0.000005 |
| freeing items        | 0.000010 |
| cleaning up          | 0.000011 |
+----------------------+----------+

• SOURCE

mysql> show profile SOURCE for query 2;
+----------------------+----------+---------------------------+----------------------+-------------+
| Status               | Duration | Source_function           | Source_file          | Source_line |
+----------------------+----------+---------------------------+----------------------+-------------+
| starting             | 0.000049 | NULL                      | NULL                 |        NULL |
| checking permissions | 0.000005 | check_access              | sql_authorization.cc |         809 |
| Opening tables       | 0.000012 | open_tables               | sql_base.cc          |        5815 |
| init                 | 0.000015 | handle_query              | sql_select.cc        |         128 |
| System lock          | 0.000006 | mysql_lock_tables         | lock.cc              |         330 |
| optimizing           | 0.000006 | optimize                  | sql_optimizer.cc     |         158 |
| statistics           | 0.000040 | optimize                  | sql_optimizer.cc     |         374 |
| preparing            | 0.000008 | optimize                  | sql_optimizer.cc     |         482 |
| Creating tmp table   | 0.000016 | create_intermediate_table | sql_executor.cc      |         223 |
| Sorting result       | 0.000003 | make_tmp_tables_info      | sql_select.cc        |        3849 |
| executing            | 0.000002 | exec                      | sql_executor.cc      |         126 |
| Sending data         | 0.001631 | exec                      | sql_executor.cc      |         202 |
| Creating sort index  | 0.000292 | sort_table                | sql_executor.cc      |        2621 |
| end                  | 0.000003 | handle_query              | sql_select.cc        |         206 |
| query end            | 0.000005 | mysql_execute_command     | sql_parse.cc         |        4956 |
| removing tmp table   | 0.000003 | free_tmp_table            | sql_tmp_table.cc     |        2413 |
| query end            | 0.000002 | free_tmp_table            | sql_tmp_table.cc     |        2442 |
| closing tables       | 0.000004 | mysql_execute_command     | sql_parse.cc         |        5009 |
| freeing items        | 0.000019 | mysql_parse               | sql_parse.cc         |        5622 |
| cleaning up          | 0.000009 | dispatch_command          | sql_parse.cc         |        1931 |
+----------------------+----------+---------------------------+----------------------+-------------+

쿼리 프로파일링 비활성화

쿼리 프로파일링의 기능 비 활성화는 시스템 변수를 다시 0 으로 설정하면 됩니다.

mysql> set profiling=0;


mysql> show variables like '%profiling%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| profiling              | OFF   |
+------------------------+-------+

Reference

Reference Book
• DBA를 위한 MySQL 운영 기술

관련된 다른 글

MySQL xtrabackup 을 이용한 replication 구성

Xtrabackup(Innobackupex) 를 통한 백업을 슬레이브 서버로 전송하여 복구를 통해 replication 을 구성

MySQL8 invisible columns

MySQL 은 MySQL 8.0.23부터 invisible columns을 지원합니다 invisible columns은 일반적으로 쿼리에 숨겨져 있지만 명시 적으로 참조되는 경우 액세스 할 수 있습니다.

MySQL8 해시조인(Hash Join)

MySQL 에서는 오랜 기간 조인의 Method가 nested loop join 방식만 지원되어왔습니다

MySQL NOW()와 SYSDATE()의 차이

MySQL 에서는 현재 시각을 조회하는 함수로 NOW() 와 SYSDATE 함수가 있으며 현재의 시간을 반환하는 같은 기능을 수행합니다

MySQL Delete 문 성능 - IN절에서 서브쿼리 사용시 - Multiple Delete / CTAS

MySQL 은 전통적으로 서브쿼리 최적화에 약한 면모를 보이고 있습니다 5.6 버전에서 개선되어( subquery materialization) 서브쿼리가 내부적으로 조인 형태로 변경되어 성능적 개선이 되었으나 여전히 서브쿼리 사용은 확인이 필요 합니다.

MySQL - Percona Toolkit - ONLINE-SCHEMA-CHANGE

Percona Toolkit 는 Percona 사에서 개발한 오픈소스 기반의 MySQL/MariaDB 의 유틸리티로 기술지원 시 사용하던 유용한 기능의 유틸리티 도구를 하나로 묶은 패키지 입니다.

Jade(정현호)

Principal DBA(MySQL, AWS Aurora, Oracle)
핀테크 서비스인 핀다에서 데이터베이스를 운영하고 있어요(at finda.co.kr)
Previous - 당근마켓, 위메프, Oracle Korea ACS / Fedora Kor UserGroup 운영중

Database 외에도 NoSQL , Linux , Python, Cloud, Http/PHP CGI 등에도 관심이 있습니다
purityboy83@gmail.com / admin@hoing.io

hoing.io

bug.mysql.com

Statistics

MySQL 쿼리 프로파일링(Query Profiling)

쿼리 프로파일링(Query Profiling)

쿼리 프로파일링 활성화

프로파일링 사용

쿼리 프로파일링 비활성화

Reference

You may also like...

쿼리 프로파일링(Query Profiling)

쿼리 프로파일링 활성화

프로파일링 사용

쿼리 프로파일링 비활성화

Reference

You may also like...

MySQL - JSON 데이터를 Index를 사용하여 조회하기

MySQL - InnoDB Cluster(클러스터) - (6) - 인스턴스 숨기기(접속 라우팅 비활성화) 및 라우터 다중화 - Multi MySQL Router

MySQL 5.7 설치 (Source Compile&binary) on CentOS 7