Question: how do I know that one user is waiting for a lock and another user is burning CPU on MySQL?
i.e. how can I create active session history on MySQL like on Oracle?
Two simple cases I’m looking at
session waiting on lock
The wait event is ” wait/io/table/sql/handler” which happens for a number of potential reasons
-> I can join to information_schema views INNODB_LOCK_WAITS & INNODB_TRX but this is heavy, and I’d rather only access those after I know there is a lock waiter.
session burning CPU
How do I know from performance schema views that the connection is active and burning CPU?
It has a wait event that shows up wait/synch/mutex/sql/THD::LOCK_thd_data
on Oracle to determine CPU, we just look at connections that are active and not waiting.
Also what is NESTING_EVENT_TYPE? I see the same thread sometime twice in events_waits_current with NESTING_EVENT_TYPE STAGE and WAIT.
On some systems for the lock test below the NESTING_EVENT_TYPE shows up as NULL and others as STAGE.
I basically want to monitor user activity and collect who is active and if they are waiting for something or if they are on CPU.
Row Lock
First user
start transaction;
update toto set id=1;Second user does
update toto set id=4; -- hangs
How do I see second user is waiting for a row lock? Here is output from
performance_schema.threads
performance_schema.events_waits_current
For a connection waiting on a lock:
select * from performance_schema.threads where thread_id=5329\G THREAD_ID: 5329 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 5223 PROCESSLIST_USER: root PROCESSLIST_HOST: localhost PROCESSLIST_DB: kylePROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 782 PROCESSLIST_STATE: updating PROCESSLIST_INFO: update toto set id=4 PARENT_THREAD_ID: NULL ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: SSL/TLS THREAD_OS_ID: 2088 RESOURCE_GROUP: USR_default select * from performance_schema.events_waits_current where thread_id=5329\G*************************** 1. row *************************** THREAD_ID: 5329 EVENT_ID: 740239187 END_EVENT_ID: NULL EVENT_NAME: wait/io/table/sql/handler SOURCE: handler.cc:2991 TIMER_START: 45606173945401364 TIMER_END: 46413477812683064 TIMER_WAIT: 807303867281700 SPINS: NULL OBJECT_SCHEMA: kyle OBJECT_NAME: toto INDEX_NAME: NULL OBJECT_TYPE: TABLEOBJECT_INSTANCE_BEGIN: 139872327141152 NESTING_EVENT_ID: 740239186 NESTING_EVENT_TYPE: STAGE OPERATION: fetch NUMBER_OF_BYTES: 61
CPU
Have user running a procedure that just burns CPU running “call minute_rollup(100000000)”. Here is output from
performance_schema.threads
performance_schema.events_waits_current
select * from performance_schema.threads where thread_id= 6273 \G *************************** 1. row *************************** THREAD_ID: 6273 NAME: thread/sql/one_connection TYPE: FOREGROUND PROCESSLIST_ID: 6167 PROCESSLIST_USER: root PROCESSLIST_HOST: localhost PROCESSLIST_DB: kylePROCESSLIST_COMMAND: Query PROCESSLIST_TIME: 668 PROCESSLIST_STATE: Opening tables PROCESSLIST_INFO: call minute_rollup(100000000) PARENT_THREAD_ID: NULL ROLE: NULL INSTRUMENTED: YES HISTORY: YES CONNECTION_TYPE: SSL/TLS THREAD_OS_ID: 2087 RESOURCE_GROUP: USR_default select * from performance_schema.events_waits_current where thread_id=6273\G THREAD_ID: 6273 EVENT_ID: 403685579 END_EVENT_ID: 403685579 EVENT_NAME: wait/synch/mutex/sql/THD::LOCK_thd_data SOURCE: sql_class.h:4142 TIMER_START: 46300974764007954 TIMER_END: 46300974764070510 TIMER_WAIT: 62556 SPINS: NULL OBJECT_SCHEMA: NULL OBJECT_NAME: NULL INDEX_NAME: NULL OBJECT_TYPE: NULLOBJECT_INSTANCE_BEGIN: 139871988613512 NESTING_EVENT_ID: 403685578 NESTING_EVENT_TYPE: STATEMENT OPERATION: lock NUMBER_OF_BYTES: NULL FLAGS: NULL
Procedure to burn CPU:
DELIMITER $$
DROP PROCEDURE IF EXISTS minute_rollup$$
CREATE PROCEDURE minute_rollup(input_number INT)
BEGIN
DECLARE counter int;
DECLARE out_number float;
set counter=0;
WHILE counter <= input_number DO
SET out_number=SQRT(rand());
SET counter = counter + 1;
END WHILE;
END$$
DELIMITER ;
call minute_rollup(100000000);
I think the trick to see if the connection is on CPU is performance_schema.events_waits_current.EVENT_ID= END_EVENT_ID then we are on CPU
select
t.thread_id,
IF(w.EVENT_ID=w.END_EVENT_ID,'CPU', w.EVENT_NAME) AS wait_event,
REPLACE( REPLACE(substr(t.PROCESSLIST_info ,1,80), '\r', '') , '\n','') sql_text
from
performance_schema.threads t
left join performance_schema.events_waits_current w on w.thread_id = t.thread_id
where
t.PROCESSLIST_STATE IS NOT NULL
and ( t.PROCESSLIST_COMMAND != 'Sleep' and t.PROCESSLIST_COMMAND != 'Daemon')
and t.PROCESSLIST_ID != CONNECTION_ID();
+-----------+-------------------------------------------+----------------------------------------------------------------------------------+
| thread_id | wait_event | sql_text |
+-----------+-------------------------------------------+----------------------------------------------------------------------------------+
| 518002247 | CPU | SELECT anon_1.anon_2_anon_3_customer_id_ AS anon_1_anon_2_anon_3_customer_id_, a |
| 518007382 | CPU | COMMIT |
| 518006817 | wait/io/table/sql/handler | SELECT anon_1.anon_2_customer_id_ AS anon_1_anon_2_customer_id_, anon_1.anon_2_c |
| 518007025 | wait/io/table/sql/handler | update customer set name=name where id_ in (2, 1); |
| 518007027 | wait/synch/cond/sql/Item_func_sleep::cond | select sleep(20) |
| 518007028 | wait/io/table/sql/handler | update customer set name=name where id_ in (8, 4); |
| 518007029 | wait/io/table/sql/handler | update customer set name=name where id_ in (6, 3); |
| 518007032 | wait/synch/cond/sql/Item_func_sleep::cond | select sleep(20) |
| 518007034 | wait/io/table/sql/handler | SELECT anon_1.anon_2_customer_id_ AS anon_1_anon_2_customer_id_, anon_1.anon_2_c |
| 518007035 | wait/synch/cond/sql/Item_func_sleep::cond | select sleep(20) |
| 518007039 | wait/io/table/sql/handler | update customer set name=name where id_ in (5, 3); |
| 518005220 | wait/io/table/sql/handler | SELECT anon_1.customer_id_ AS anon_1_customer_id_, anon_1.customer_name AS anon_ |
| 518007058 | wait/io/table/sql/handler | update customer set name=name where id_ in (4, 2); |
| 518004406 | wait/io/table/sql/handler | SELECT anon_1.anon_2_customer_id_ AS anon_1_anon_2_customer_id_, anon_1.anon_2_c |
| 518003240 | wait/io/table/sql/handler | update toto set id=4 |
+-----------+-------------------------------------------+----------------------------------------------------------------------------------+
One unusual thing is that the thread can show up more than once in events_waits_current.
select
t.thread_id,
w.NESTING_EVENT_TYPE,
IF(w.EVENT_ID=w.END_EVENT_ID,'CPU', w.EVENT_NAME) AS wait_event,
REPLACE( REPLACE(substr(t.PROCESSLIST_info ,1,80), '\r', '') , '\n','') sql_text
from
performance_schema.threads t
left join performance_schema.events_waits_current w on w.thread_id = t.thread_id
where
t.PROCESSLIST_STATE IS NOT NULL
and ( t.PROCESSLIST_COMMAND != 'Sleep' and t.PROCESSLIST_COMMAND != 'Daemon')
and t.PROCESSLIST_ID != CONNECTION_ID()
+-----------+--------------------+-------------------------------------------+----------------------------------------------------------------------------------+
| thread_id | NESTING_EVENT_TYPE | wait_event | sql_text |
+-----------+--------------------+-------------------------------------------+----------------------------------------------------------------------------------+
| 518010010 | STATEMENT | wait/io/table/sql/handler | SELECT customer.id_ AS customer_id_, customer.name AS customer_name, customer.de |
| 518010010 | WAIT | wait/io/file/sql/hash_join | SELECT customer.id_ AS customer_id_, customer.name AS customer_name, customer.de |
| 518010011 | STATEMENT | wait/io/table/sql/handler | SELECT customer.id_ AS customer_id_, customer.name AS customer_name, customer.de |
| 518010011 | WAIT | wait/io/file/sql/hash_join | SELECT customer.id_ AS customer_id_, customer.name AS customer_name, customer.de |
In the case of NESTING_EVENT_TYPE of type WAIT, I want that WAIT. IF there is no NESTING_EVENT_TYPE of type WAIT and only of type STATEMENT , then I want that wait (AFAICT) leading to a bit of a convoluted statement
select
t.thread_id,
COALESCE( ww.NESTING_EVENT_TYPE, ws.NESTING_EVENT_TYPE) NESTING_EVENT_TYPE,
IF(ws.EVENT_ID=ws.END_EVENT_ID,'CPU',
COALESCE( ww.EVENT_NAME, ws.EVENT_NAME) ) AS wait_event,
REPLACE(REPLACE(substr(t.PROCESSLIST_info,1,80),'\r',''),'\n','') sql_text
from
performance_schema.threads t
left join performance_schema.events_waits_current ww on ww.thread_id = t.thread_id
and ww.NESTING_EVENT_TYPE = 'WAIT'
left join performance_schema.events_waits_current ws on ws.thread_id = t.thread_id
and ws.NESTING_EVENT_TYPE = 'STATEMENT'
where
t.PROCESSLIST_STATE IS NOT NULL
and ( t.PROCESSLIST_COMMAND != 'Sleep' and t.PROCESSLIST_COMMAND != 'Daemon')
and t.PROCESSLIST_ID != CONNECTION_ID();+-----------+--------------------+-------------------------------------------+----------------------------------------------------------------------------------+
| thread_id | NESTING_EVENT_TYPE | wait_event | sql_text |
+-----------+--------------------+-------------------------------------------+----------------------------------------------------------------------------------+
| 518009610 | STATEMENT | wait/io/table/sql/handler | SELECT anon_1.anon_2_anon_3_customer_id_ AS anon_1_anon_2_anon_3_customer_id_, a |
| 518010002 | STATEMENT | CPU | SELECT current_schema, sql_text, digest, digest_text, timer_start, @startup_time |
| 518003240 | STATEMENT | wait/io/table/sql/handler | update toto set id=4 |
| 518010412 | STATEMENT | wait/io/table/sql/handler | SELECT anon_1.anon_2_customer_id_ AS anon_1_anon_2_customer_id_, anon_1.anon_2_c |
| 518010010 | WAIT | wait/io/file/sql/hash_join | SELECT customer.id_ AS customer_id_, customer.name AS customer_name, customer.de |
| 518010417 | WAIT | wait/io/file/sql/hash_join | SELECT anon_1.customer_id_ AS anon_1_customer_id_, anon_1.customer_name AS anon_ |
+-----------+--------------------+-------------------------------------------+----------------------------------------------------------------------------------+
It gets more confusing because in some cases there are multiple lines (only seen two, not more ) for the same thread with the same NESTING_EVENT_TYPE ( NULL in the below example)
SELECT
threads.PROCESSLIST_ID,
threads.PROCESSLIST_USER,
threads.PROCESSLIST_HOST,
threads.PROCESSLIST_COMMAND,
threads.PROCESSLIST_STATE,
current_events.TIMER_START,
current_events.TIMER_END,
current_events.TIMER_WAIT,
current_events.NESTING_EVENT_TYPE,
REPLACE(REPLACE(substr(current_events.SQL_TEXT,1,40),'\r',''),'\n','') stmt_sql_text_short,
REPLACE(REPLACE(substr(threads.PROCESSLIST_info,1,40),'\r',''),'\n','') thread_proc_info_short,
current_events.CURRENT_SCHEMA,
IF ( threads.PROCESSLIST_STATE ='User sleep','User sleep', (
IF(current_waits.EVENT_ID=current_waits.END_EVENT_ID,'CPU', current_waits.EVENT_NAME)
)) AS wait_event
FROM
performance_schema.threads AS threads
INNER JOIN performance_schema.events_statements_current AS current_events ON threads.THREAD_ID = current_events.THREAD_ID
INNER JOIN performance_schema.events_waits_current AS current_waits ON threads.THREAD_ID = current_waits.THREAD_ID
Where threads.PROCESSLIST_STATE is not NULL
+------+-----------+-------------+-----------------+--------------------+---------------------------------------------------------------------------------------------+
| PID | PLIST_CMD | PLIST_STATE | TIMER_WAIT | NESTING_EVENT_TYPE | thread_proc_info_short | wait_event |
+------+-----------+-------------+-----------------+--------------------+---------------------------------------------------------------------------------------------+
| 8539 | Query | executing | 445524154000 | NULL | INSERT INTO order_status_change (dbm_ord | wait/io/table/sql/handler |
| 8539 | Query | executing | 445580677000 | NULL | INSERT INTO order_status_change (dbm_ord | CPU |
| 8820 | Query | init | 170936000 | NULL | SELECT * from dbm_user WHERE id = 2404 | idle |
| 8820 | Query | init | 170936000 | NULL | SELECT * from dbm_user WHERE id = 2404 | wait/io/socket/sql/client_connection |
| 8730 | Query | executing | 595809657000 | NULL | INSERT INTO order_status_change (dbm_ord | wait/io/table/sql/handler |
| 8730 | Query | executing | 595869870000 | NULL | INSERT INTO order_status_change (dbm_ord | wait/synch/sxlock/innodb/lock_sys_global_rw_lock |