PROFILE
툴을 사용하는 것보다는 console 에서 작업하는것을 추천합니다. 이유는 show profiles 시에 DBMS입장에서 실행된 쿼리를 가지는데, 프로파일할 쿼리보다 툴 자체에서 실행된 쿼리 들이 많아 보는데 짜증날 수 있음.
1. 설정
(1) 확인
profiling 설정을 확인합니다. 0이면 OFF, 1이면 ON
MariaDB [employees]> select @@profiling
-> ;
+-------------+
| @@profiling |
+-------------+
| 0 |
+-------------+
1 row in set (0.00 sec)
(2) 설정
set profiling = 1;
MariaDB [employees]> select @@profiling;
+-------------+
| @@profiling |
+-------------+
| 1 |
+-------------+
1 row in set (0.00 sec)
(3) profiling history size 변경
SET @@profiling_history_size = 100
2. profile, profiles
(1) profiles
profile 된 쿼리 리스트를 조회한다.
MariaDB [employees]> SET @@profiling_history_size = 10; 히스토리사이즈를 변경합니다. 디폴트를 15, 최대값은 100, 최소값은 0이다.
Query OK, 0 rows affected (0.00 sec)
MariaDB [employees]> show profiles;
+----------+------------+------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+------------------------------------------------------------------------------+
| 56 | 0.00034800 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 57 | 0.00036000 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 58 | 0.00009800 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 59 | 0.00031800 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 60 | 0.00034000 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 61 | 0.00033700 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 62 | 0.00035000 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 63 | 0.00034200 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 64 | 0.00007600 | SELECT name, test, score, avg(score) from student group by name, test, score |
| 65 | 0.00007400 | SELECT name, test, score, avg(score) from student group by name, test, score |
+----------+------------+------------------------------------------------------------------------------+
(2) profile
show profile 은 마지막 쿼리에 대한 프로파일 조회.
MariaDB [employees]> show profile;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000048 |
| checking permissions | 0.000005 |
| Opening tables | 0.000013 |
| After opening tables | 0.000005 |
... ...
| freeing items | 0.000006 |
| updating status | 0.000013 |
| cleaning up | 0.000003 |
+----------------------+----------+
24 rows in set (0.00 sec)
특정 Query_ID 프로파일을 보기.
MariaDB [employees]> show profile for query 66;
+-----------------+----------+
| Status | Duration |
+-----------------+----------+
| starting | 0.000027 |
... ...
| cleaning up | 0.000004 |
+-----------------+----------+
4 rows in set (0.01 sec)
3. profile 결과 내용 보기
(1) 결과 내용 보기
MariaDB [employees]> select * from employees;
MariaDB [employees]> show profile;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000037 | (시작)
| checking permissions | 0.000005 | (사용권한확인)
| Opening tables | 0.000012 | (테이블열기)
| After opening tables | 0.000007 | (테이블을 연 후에)
| System lock | 0.000004 | (시스템잠금)
| Table lock | 0.000006 | (테이블잠금)
| init | 0.000018 | (초기화)
| optimizing | 0.000007 | (최적화)
| statistics | 0.000010 | (통계)
| preparing | 0.000014 | (준비)
| executing | 0.000004 | (실행)
| Sending data | 0.212919 | (데이터보내기)
| end | 0.000010 | (끝)
| query end | 0.000009 | (질의끝)
| closing tables | 0.000005 | (테이블닫기)
| Unlocking tables | 0.000012 | (잠금해제테이블)
| freeing items | 0.000006 | (항목해방)
| updating status | 0.000029 | (상태업데이트)
| cleaning up | 0.000003 | (청소)
+----------------------+----------+
19 rows in set (0.00 sec)
MariaDB [employees]> show profiles;
+----------+------------+------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+------------------------------------------------------------------------------+
| 68 | 0.21311700 | select * from employees |
+----------+------------+------------------------------------------------------------------------------+
1 rows in set (0.00 sec)
(2) 추가 정보 표시.
사용할 수 있는 타입 (TYPE).
ALL : 모든 정보를 표시.
BLOCK IO : 블록 입력 및 출력 작업의 횟수를 표시.
CONTEXT SWITCHES : 자발적 및 비자발적 인 컨텍스트 스위치의 수를 표시.
CPU : 사용자 및 시스템 CPU 사용 시간을 표시.
IPC : 보내고, 받은 메시지의 수를 표시.
PAGE FAULTS : (페이지 오류) 주 페이지 오류 및 부 페이지 오류 수를 표시.
SOURCE : 함수가 발생하는 파일의 이름과 행 번호와 함께 소스 코드의 함수 이름을 표시.
SWAPS : 스왑 카운트 표시.
결과 컬럼 설명
https://mariadb.com/kb/en/library/information-schema-profiling-table/ 참조.
|
Column Name |
Description |
|
QUERY_ID |
Query_ID. |
|
SEQ |
동일한 QUERY_ID를 갖는 행의 표시 순서를 보여주는 일련 번호 |
|
STATE |
프로파일링 상태 |
|
DURATION |
명령문이 현재 상태에 있었던 시간 (초). |
|
CPU_USER |
사용자 CPU 사용량 (초) |
|
CPU_SYSTEM |
시스템 CPU 사용량 (초). |
|
CONTEXT_VOLUNTARY |
자발적 컨텍스트 전환의 수. (Number of voluntary context switches.) |
|
CONTEXT_INVOLUNTARY |
무의식적 인 컨텍스트 전환의 수. (Number of involuntary context switches.) |
|
BLOCK_OPS_IN |
블록 입력 조작의 수. (Number of block input operations.) |
|
BLOCK_OPS_OUT |
블록 출력 조작의 수. (Number of block output operations.) |
|
MESSAGES_SENT |
전송 된 통신 수. (Number of communications sent.) |
|
MESSAGES_RECEIVED |
수신 된 통신 수. (Number of communications received.) |
|
PAGE_FAULTS_MAJOR |
메이저 페이지 폴트의 수. (Number of major page faults.) |
|
PAGE_FAULTS_MINOR |
마이너 페이지 폴트의 수. (Number of minor page faults.) |
|
SWAPS |
스왑의 수. (Number of swaps.) |
|
SOURCE_FUNCTION |
프로파일 된 상태로 실행되는 소스 코드의 기능. (Function in the source code executed by the profiled state.) |
|
SOURCE_FILE |
프로파일 링 된 상태로 실행 된 소스 코드의 파일. (File in the source code executed by the profiled state.) |
|
SOURCE_LINE |
프로파일 링 된 상태로 실행 된 소스 코드의 행. (Line in the source code executed by the profiled state.) |
MariaDB [employees]> show profile cpu for query 68;
+----------------------+----------+----------+------------+
| Status | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| starting | 0.000037 | 0.000031 | 0.000005 |
| checking permissions | 0.000005 | 0.000004 | 0.000002 |
| Opening tables | 0.000012 | 0.000011 | 0.000001 |
| After opening tables | 0.000007 | 0.000006 | 0.000001 |
| System lock | 0.000004 | 0.000002 | 0.000002 |
| Table lock | 0.000006 | 0.000004 | 0.000001 |
| init | 0.000018 | 0.000017 | 0.000001 |
| optimizing | 0.000007 | 0.000006 | 0.000002 |
| statistics | 0.000010 | 0.000009 | 0.000001 |
| preparing | 0.000014 | 0.000013 | 0.000002 |
| executing | 0.000004 | 0.000001 | 0.000001 |
| Sending data | 0.212919 | 0.195294 | 0.012750 |
| end | 0.000010 | 0.000007 | 0.000014 |
| query end | 0.000009 | 0.000016 | 0.000009 |
| closing tables | 0.000005 | 0.000020 | 0.000010 |
| Unlocking tables | 0.000012 | 0.000019 | 0.000013 |
| freeing items | 0.000006 | 0.000004 | 0.000001 |
| updating status | 0.000029 | 0.000009 | 0.000016 |
| cleaning up | 0.000003 | 0.000002 | 0.000001 |
+----------------------+----------+----------+------------+
19 rows in set (0.00 sec)
MariaDB [employees]> show profile block io for query 68;
+----------------------+----------+--------------+---------------+
| Status | Duration | Block_ops_in | Block_ops_out |
+----------------------+----------+--------------+---------------+
| starting | 0.000037 | 0 | 0 |
| checking permissions | 0.000005 | 0 | 0 |
| Opening tables | 0.000012 | 0 | 0 |
| After opening tables | 0.000007 | 0 | 0 |
| System lock | 0.000004 | 0 | 0 |
| Table lock | 0.000006 | 0 | 0 |
| init | 0.000018 | 0 | 0 |
| optimizing | 0.000007 | 0 | 0 |
| statistics | 0.000010 | 0 | 0 |
| preparing | 0.000014 | 0 | 0 |
| executing | 0.000004 | 0 | 0 |
| Sending data | 0.212919 | 0 | 0 |
| end | 0.000010 | 0 | 0 |
| query end | 0.000009 | 0 | 0 |
| closing tables | 0.000005 | 0 | 0 |
| Unlocking tables | 0.000012 | 0 | 0 |
| freeing items | 0.000006 | 0 | 0 |
| updating status | 0.000029 | 0 | 0 |
| cleaning up | 0.000003 | 0 | 0 |
+----------------------+----------+--------------+---------------+
19 rows in set (0.00 sec)
MariaDB [employees]> show profile all for query 68;
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function | Source_file | Source_line |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
| starting | 0.000037 | 0.000031 | 0.000005 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |
| checking permissions | 0.000005 | 0.000004 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | check_access | sql_parse.cc | 6609 |
| Opening tables | 0.000012 | 0.000011 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | open_tables | sql_base.cc | 3858 |
| After opening tables | 0.000007 | 0.000006 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | open_tables | sql_base.cc | 4105 |
| System lock | 0.000004 | 0.000002 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock.cc | 339 |
| Table lock | 0.000006 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock.cc | 344 |
| init | 0.000018 | 0.000017 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_select | sql_select.cc | 3701 |
| optimizing | 0.000007 | 0.000006 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize_inner | sql_select.cc | 1187 |
| statistics | 0.000010 | 0.000009 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize_inner | sql_select.cc | 1523 |
| preparing | 0.000014 | 0.000013 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize_inner | sql_select.cc | 1549 |
| executing | 0.000004 | 0.000001 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | exec_inner | sql_select.cc | 3343 |
| Sending data | 0.212919 | 0.195294 | 0.012750 | 0 | 1016 | 0 | 0 | 2747 | 0 | 0 | 0 | 0 | exec_inner | sql_select.cc | 3525 |
| end | 0.000010 | 0.000007 | 0.000014 | 0 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_select | sql_select.cc | 3736 |
| query end | 0.000009 | 0.000016 | 0.000009 | 0 | 2 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 6219 |
| closing tables | 0.000005 | 0.000020 | 0.000010 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | close_thread_tables | sql_base.cc | 714 |
| Unlocking tables | 0.000012 | 0.000019 | 0.000013 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_unlock_tables | lock.cc | 426 |
| freeing items | 0.000006 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_parse | sql_parse.cc | 7917 |
| updating status | 0.000029 | 0.000009 | 0.000016 | 0 | 1 | 0 | 0 | 3 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 2356 |
| cleaning up | 0.000003 | 0.000002 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 2380 |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+---------------+-------------+
'Database > maria' 카테고리의 다른 글
| FIND_IN_SET (0) | 2023.12.28 |
|---|---|
| explain (0) | 2018.01.30 |
| foreign-keys (0) | 2018.01.30 |
| window functions 윈도우 함수. (0) | 2018.01.26 |
| macOS 에 maria db 설치 및 test db 생성 (0) | 2018.01.26 |