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

Last Updated on 3월 16, 2021 by 태랑(정현호)



쿼리 프로파일링(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;



샘플 쿼리 조회 입니다.

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   |
+------------------------+-------+



Ref link
DBA를 위한 MySQL 운영 기술



관련된 다른 글

답글 남기기