performace_schema 를 이용하여 최근에 실행된 쿼리 확인하기
show processlist 와 show engine processlist 를 확인하면, 어떤 쿼리인지는 알 수 없으나 트랜잭션을 잡고 있는것을 확인할 수 있습니다. commit 되지 않은 트랜잭션이 존재한다면, MySQL InnoDB는 old image를 읽어오기 위해 시간이 지날수록 느려지고 다른 쿼리또한 lock 으로 인해 대기될 수 있습니다. 해당 쿼리를 tracking 하기 위해서는 기본적으로 performace_schema 가 ON (1) 되어 있어야 합니다. MySQL 5.6.6 이상에서는 은 기본적으로 해당값이 ON 되어 있으므로, 추가적인 설정이 필요없습니다. http://dev.mysql.com/doc/refman/5.6/en/performance-schema-system-variables.html#sysvar_performance_schema
mysql> show global variables like 'performance_schema';
+--------------------+-------+
| Variable_name | Value |
+--------------------+-------+
| performance_schema | ON |
+--------------------+-------+
1 row in set (0.00 sec)
먼저 예제를 하나 만들도록 하겠습니다. session 1 에서 테이블을 만들고, 해당 테이블에 값을 넣습니다.
Session 1>
mysql> create table p ( a int);
Query OK, 0 rows affected (0.03 sec)
mysql> begin;
Query OK, 0 rows affected (0.00 sec)
mysql> insert into p values (1);
Query OK, 1 row affected (0.00 sec)
다른 세션에서 show engine innodb status, show processlist;, information_schema.INNODB_TRX 를 조회해 보겠습니다.
Session 2>
mysql> show engine innodb statusG
------------
TRANSACTIONS
------------
Trx id counter 632685
Purge done for trx's n:o < 632684 undo n:o < 0 state: running but idle
History list length 443
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 53587, OS thread handle 0x7f6f0c0a2700, query id 498268 localhost root init
show engine innodb status
---TRANSACTION 0, not started
MySQL thread id 15918, OS thread handle 0x7f6eec0ed700, query id 498176 localhost gu cleaning up
---TRANSACTION 632684, ACTIVE 32 sec
/* 해당 transaction 이 Active 상태로 32초동안 active 상태지만, 어떤 쿼리인지는 알 수 없습니다. 단순히 test.p 테이블에 실행된 쿼리로만 짐작이 됩니다.
현재는 아무런 쿼리도 돌고 있지 않기 때문입니다. 물론 undo log entires 를 통해 DML이 실행되었을것이라고 짐작할 수 있습니다.
undo log entries 가 없는 경우도 있는데, 이는 begin; select .... 구문을 실행했기 때문입니다.
commit 이나 rollback 이 오랬동안 이루어지지 않았다면, 이또한 성능정하를 일이키는 요소입니다.
**/
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 1
sMySQL thread id 56604, OS thread handle 0x7f6f0c061700, query id 497985 localhost root cleaning up
TABLE LOCK table `test`.`p` trx id 632684 lock mode IX
mysql> show processlist;
+-------+------+-----------+-------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-------+------+-----------+-------+---------+------+-------+------------------+
| 15918 | gu | localhost | mysql | Sleep | 24 | | NULL |
| 53587 | root | localhost | NULL | Query | 0 | init | show processlist |
| 56604 | root | localhost | test | Sleep | 42 | | NULL |
+-------+------+-----------+-------+---------+------+-------+------------------+
5 rows in set (0.00 sec)
/* show processlist; 에서는 현재 해당 thread가 아무런 작업을 하고 있지 않기 때문에 Sleep 상태만을 보여줍니다.**/
mysql> select * from information_schema.INNODB_TRXG
*************************** 1. row ***************************
trx_id: 632684
trx_state: RUNNING
trx_started: 2016-01-26 04:22:10
trx_requested_lock_id: NULL
trx_wait_started: NULL
trx_weight: 2
trx_mysql_thread_id: 56604
trx_query: NULL
trx_operation_state: NULL
trx_tables_in_use: 0
trx_tables_locked: 0
trx_lock_structs: 1
trx_lock_memory_bytes: 360
trx_rows_locked: 0
trx_rows_modified: 1
trx_concurrency_tickets: 0
trx_isolation_level: REPEATABLE READ
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_adaptive_hash_timeout: 10000
trx_is_read_only: 0
trx_autocommit_non_locking: 0
1 row in set (0.00 sec)
/* information_schema.INNODB_TRX 에서는 현재 해당 thread가 아무런 작업을 하고 있지 않기 때문에 trx_rows_modified 를 통해 어떤 DML 이 실행되었고, 1개의 record를 수정한채 commit 하지 않았다는것만을 알 수 있습니다. **/
performance_schema.events_statements_current 의 데이터를 조회해 보겠습니다. 해당 테이블은 마지막에 해당 thread에서 실행된 쿼리를 저장하고 있습니다. 해당 테이블의 값을 조회하기 위해서는 performance_schema.threads 와 조인이 필요합니다. processlist 에서 보여주는 mysql 이 만든 thread와 performance_schema 에서 만든 thread 값이 다르기 때문입니다. (performance_schema.threads 는 background thread의 값도 가지고 있기 때문입니다.)
Session 2>
mysql> SELECT esc.THREAD_ID, t.processlist_id, esc.SQL_TEXT FROM performance_schema.events_statements_current esc JOIN performance_schema.threads t ON t.thread_id = esc.thread_id WHERE t.processlist_id = 56604;
+-----------+----------------+--------------------------+
| THREAD_ID | processlist_id | SQL_TEXT |
+-----------+----------------+--------------------------+
| 56624 | 56604 | insert into p values (1) |
+-----------+----------------+--------------------------+
/* process_id 가 56604 의 thread 가 실행한 마지막 쿼리가 나타납니다. 56604 값은 show engine innodb statusG 의 transaction 값 중 thread id 56604 값을 통해 알아낼 수 있습니다. **/
위는 default 로 동작되는 방법입니다. 그렇다면, 지나간 쿼리에 대해서는 어떻게 로그인을 하는지 확인해보겠습니다. - https://dev.mysql.com/doc/refman/5.6/en/performance-schema-statement-tables.html 먼저 performance_schema.setup_consumers 테이블의 events_statements_history, events_statements_history_long 의 값을 ON 시켜주어야 합니다. (default 로 events_statements_current 는 ON이 되어 있는것을 확인할 수 있습니다.)
mysql> select * from performance_schema.setup_consumers where name like 'events_statements_%';
+--------------------------------+---------+
| NAME | ENABLED |
+--------------------------------+---------+
| events_statements_current | YES |
| events_statements_history | NO |
| events_statements_history_long | NO |
+--------------------------------+---------+
3 rows in set (0.00 sec)
mysql> UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE name like 'events_statements_%';
Query OK, 2 row affected (0.06 sec)
Rows matched: 3 Changed: 2 Warnings: 0
다시 session 1에서 쿼리를 실행해 보겠습니다.
Session 1>
mysql> select * from p;
+------+
| a |
+------+
| 1 |
+------+
1 row in set (0.00 sec)
mysql> select * from p where a=1;
+------+
| a |
+------+
| 1 |
+------+
1 row in set (0.00 sec)
mysql> select * from p where a=0;
Empty set (0.00 sec)
다른 세션에서 events_statements_history_long 의 값을 조회하여 해당세션이 실행한 쿼리들을 확인할 수 있습니다.
SELECT
esh.THREAD_ID, t.processlist_id, esh.SQL_TEXT
FROM
performance_schema.events_statements_history_long esh
JOIN
performance_schema.threads t ON t.thread_id = esh.thread_id
WHERE
t.processlist_id = 56604 order by TIMER_END ASC;
+-----------+----------------+---------------------------+
| THREAD_ID | processlist_id | SQL_TEXT |
+-----------+----------------+---------------------------+
| 56624 | 56604 | select * from p |
| 56624 | 56604 | select * from p where a=1 |
| 56624 | 56604 | select * from p where a=0 |
+-----------+----------------+---------------------------+
3 rows in set (0.00 sec)
위와 같이 시간순으로 조회될 수 있습니다. 전체 쿼리를 저장할 수 있는 갯수는 아래의 설정을 통해 가능합니다. (performance_schema_events_statements_history_size, performance_schema_events_statements_history_long_size) 5.6.6 이상부터는 default 값으로 MySQL 의 현재상태를 고려하여 값이 자동으로 늘어나거나 줄어들게 됩니다. 물론 아래의 값으로 고정시킬 수도 있습니다.
https://dev.mysql.com/doc/refman/5.6/en/performance-schema-system-variables.html#sysvar_performance_schema_events_statements_history_size https://dev.mysql.com/doc/refman/5.6/en/performance-schema-system-variables.html#sysvar_performance_schema_events_statements_history_long_size