作為一個(gè)DBA, 常常實(shí)際工作中遇到各種稀奇八怪的問題。這里重點(diǎn)說一說長事務(wù)和鎖等待。
-
長事務(wù)
簡單來說就是長時(shí)間未遞交的事務(wù)。它又可分為讀長事務(wù)和寫常事務(wù)。-
讀長事務(wù)
比如研發(fā)同事連接查詢機(jī)（從庫）查詢，沒有啟用autocommit, 執(zhí)行了一個(gè)查詢SQL，沒有commit(一般執(zhí)行查詢都不會再執(zhí)行commit)，連接就這樣長時(shí)間掛起。這就造成了一個(gè)讀長事務(wù)。這個(gè)事務(wù)持有一個(gè)share_read DML鎖，它會影響對該表的DDL操作。如果這時(shí)DBA在主庫對這個(gè)表執(zhí)行了DDL操作，這個(gè)DDL操作復(fù)制到從庫的時(shí)候，會因等待MDL鎖而無法執(zhí)行。這會造成從庫復(fù)制大量延遲！還有一種讀長事務(wù)的情況就是研發(fā)人員執(zhí)行了一個(gè)復(fù)雜的統(tǒng)計(jì)類SQL，這個(gè)SQL執(zhí)行完本身就耗時(shí)很長，這也會造成長時(shí)間占用DML鎖，即使啟用了autocommit也沒用。而且還有可能大量數(shù)據(jù)文件排序造成磁盤空間耗盡。
更有甚者，程序的連接執(zhí)行了查詢，沒有commit,而程序用的是連接池，連接又不關(guān)閉。這個(gè)問題就很嚴(yán)重了。
寫長事務(wù)
寫長事務(wù)比較好理解，就是批量更新、插入，造成事務(wù)長時(shí)間執(zhí)行。還有就是事務(wù)本身邏輯比較復(fù)雜，存在鎖競爭、鎖等待。鎖等待都會有超時(shí)，超時(shí)后應(yīng)用端應(yīng)該回滾或者重試。
面對復(fù)雜的應(yīng)用場景，DBA要以不變應(yīng)萬變，這個(gè)法寶就是監(jiān)控。監(jiān)控的目的是即時(shí)發(fā)現(xiàn)，發(fā)現(xiàn)了就能即時(shí)處理。對于讀長事務(wù)，一旦超過一定閾值（比如10m）可立馬kill,對于寫操作則不能這么任性，需要結(jié)合業(yè)務(wù)來分析。
INFORMATION_SCHEMA.INNODB_TRX表中包含了當(dāng)前innodb內(nèi)部正在運(yùn)行的事務(wù)信息，包括只讀事務(wù)。這個(gè)表中給出了事務(wù)的開始時(shí)間，我們可以稍加運(yùn)算即可得到事務(wù)的運(yùn)行時(shí)間。
mysql> select t.*,to_seconds(now())-to_seconds(t.trx_started) idle_time from INFORMATION_SCHEMA.INNODB_TRX t \G *************************** 1. row *************************** trx_id: 421860487065200 trx_state: RUNNING trx_started: 2018-06-28 08:42:50 trx_requested_lock_id: NULL trx_wait_started: NULL trx_weight: 0 trx_mysql_thread_id: 207 trx_query: NULL trx_operation_state: NULL trx_tables_in_use: 0 trx_tables_locked: 0 trx_lock_structs: 0 trx_lock_memory_bytes: 1136 trx_rows_locked: 0 trx_rows_modified: 0 trx_concurrency_tickets: 0 trx_isolation_level: READ COMMITTED trx_unique_checks: 1 trx_foreign_key_checks: 1 trx_last_foreign_key_error: NULL trx_adaptive_hash_latched: 0 trx_adaptive_hash_timeout: 0 trx_is_read_only: 0 trx_autocommit_non_locking: 0 idle_time: 1164 1 row in set (0.00 sec)在結(jié)果中idle_time是計(jì)算產(chǎn)生的，也是事務(wù)的持續(xù)時(shí)間。但事務(wù)的trx_query是NUL，這并不是說事務(wù)什么也沒執(zhí)行，一個(gè)事務(wù)可能包含多個(gè)SQL，如果SQL執(zhí)行完畢就不再顯示了。當(dāng)前事務(wù)正在執(zhí)行，innodb也不知道這個(gè)事務(wù)后續(xù)還有沒有sql,啥時(shí)候會commit。 因此trx_query不能提供有意義的信息。
再看trx_is_read_only字段，它為1說明這個(gè)事務(wù)時(shí)只讀事務(wù)，雖然我只是執(zhí)行了一個(gè)select, 但它還是為0。 這是因?yàn)樗荒艽_定后續(xù)有沒有寫操作的SQL。只有在開啟事務(wù)時(shí)，使用start transaction read only,它才會是1. 如果執(zhí)行一個(gè)只讀事務(wù)，使用start transaction read only是很有好處的，這明確告訴innodb 可以采用只讀事務(wù)的流程來處理這個(gè)事務(wù)，這會節(jié)省不少數(shù)據(jù)結(jié)構(gòu)，對提升性能幫助很大。如果開啟了autocommit, 一個(gè)statement就是一個(gè)事務(wù)，如果是select操作，innodb也會采用只讀事務(wù)流程處理（這類事務(wù)統(tǒng)稱為AC-NL-RO）。對于滿足AC-NL-RO的事務(wù)也不會出現(xiàn)在show engine innodb status中。
另外一個(gè)有用的字段是trx_mysql_thread_id， 這個(gè)id就是show processlist中的會話ID。 如果需要終止事務(wù)，可kill 這個(gè)ID終止會話。
我們甚至可以通過查詢產(chǎn)生這個(gè)KILL SQL
select t.*,to_seconds(now())-to_seconds(t.trx_started) idle_time ,concat('kill ',trx_mysql_thread_id,';') kill_sql from INFORMATION_SCHEMA.INNODB_TRX t \G如果需要知道這個(gè)事務(wù)來自于哪個(gè)用戶，就要和processlist關(guān)聯(lián)查詢了
select * from information_schema.INNODB_TRX i, information_schema.processlist p where i.trx_mysql_thread_id=p.id and p.time > 60;關(guān)聯(lián)查詢可以看到更多的信息，包括用戶，包括客戶端IP等，但依然看不到SQL。如果我們想看到這個(gè)事務(wù)所有SQL，怎么辦呢？勉強(qiáng)也是可以做的到，需要開啟events_statements_history consumer，mysql5.7默認(rèn)開啟。我們需要information_schema.processlist 、performance_schema.threads 、information_schema.innodb_trx 和performance_schema.events_statements_history關(guān)聯(lián)查詢。
mysql> SELECT ps.id 'PROCESS ID',ps.user,ps.host, esh.EVENT_ID, trx.trx_started,esh.event_name 'EVENT NAME',esh.sql_text 'SQL' ,ps.time from performance_schema.events_statements_history esh join performance_schema.threads th on esh.thread_id = th.thread_id join information_schema.processlist ps on ps.id = th.processlist_id left join information_schema.innodb_trx trx on trx.trx_mysql_thread_id = ps.id where ps.time > 60 AND trx.trx_id is not null and ps.USER != 'SYSTEM_USER' order by esh.EVENT_ID; -
+------------+------+-----------+----------+---------------------+----------------------+-----------------------------+------+
| PROCESS ID | user | host | EVENT_ID | trx_started | EVENT NAME | SQL | time |
+------------+------+-----------+----------+---------------------+----------------------+-----------------------------+------+
| 207 | root | localhost | 836 | 2018-06-28 08:42:50 | statement/sql/error | start transaction read_only | 608 |
| 207 | root | localhost | 837 | 2018-06-28 08:42:50 | statement/sql/begin | start transaction read only | 608 |
| 207 | root | localhost | 838 | 2018-06-28 08:42:50 | statement/sql/select | select * from t1 limit 5 | 608 |
| 207 | root | localhost | 839 | 2018-06-28 08:42:50 | statement/sql/commit | commit | 608 |
| 207 | root | localhost | 840 | 2018-06-28 08:42:50 | statement/sql/begin | start transaction read only | 608 |
| 207 | root | localhost | 841 | 2018-06-28 08:42:50 | statement/sql/select | select * from t1 limit 5 | 608 |
| 207 | root | localhost | 842 | 2018-06-28 08:42:50 | statement/sql/commit | commit | 608 |
| 207 | root | localhost | 843 | 2018-06-28 08:42:50 | statement/sql/begin | begin | 608 |
| 207 | root | localhost | 844 | 2018-06-28 08:42:50 | statement/sql/select | select * from t1 limit 5 | 608 |
| 207 | root | localhost | 845 | 2018-06-28 08:42:50 | statement/sql/select | select * from t2 limit 5 | 608 |
+------------+------+-----------+----------+---------------------+----------------------+-----------------------------+------+
10 rows in set (0.00 sec)
遺憾的是events_statements_history這個(gè)表沒有trx_id的信息，無法按事務(wù)來分組。但按照event_id排序的結(jié)果也勉強(qiáng)可以幫助分析問題。(注意隨后一個(gè)time字段，它指的是最后一個(gè)SQL執(zhí)行后的idle時(shí)長，而不是事務(wù)執(zhí)行的精確時(shí)長)
-
鎖等待
鎖等待與長事務(wù)由密切關(guān)系，不管哪種長事務(wù)都會造成MDL鎖等待。對于MDL鎖排查MySQL5.7提供了單獨(dú)的方案（詳見這里），這里不過多分析這個(gè)鎖。對于行級鎖，mysql5.7中也提供了比較優(yōu)雅的方案，即使用 sys.innodb_lock_waits視圖
mysql> SELECT waiting_trx_id, waiting_pid, waiting_query, blocking_trx_id,blocking_pid,blocking_query FROM sys.innodb_lock_waits;
+----------------+-------------+---------------------------------------+-----------------+--------------+----------------+
| waiting_trx_id | waiting_pid | waiting_query | blocking_trx_id | blocking_pid | blocking_query |
+----------------+-------------+---------------------------------------+-----------------+--------------+----------------+
| 870773675 | 206 | update t2 set name='x' where name='a' | 870773295 | 207 | NULL |
+----------------+-------------+---------------------------------------+-----------------+--------------+----------------+
1 row in set, 3 warnings (0.00 sec)
對于mysql5.6沒有sys database的情況下，可以使用：
mysql> SELECT r.trx_state wating_trx_state, r.trx_id waiting_trx_id, r.trx_mysql_thread_Id waiting_thread,r.trx_query waiting_query,b.trx_state blocking_trx_state,b.trx_id blocking_trx_id,b.trx_mysql_thread_id blocking_thread,b.trx_query blocking_query FROM information_schema.innodb_lock_waits w INNER JOIN information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id INNER JOIN information_schema.innodb_trx r ON r.trx_id = w.requesting_trx_id \G
*************************** 1. row ***************************
wating_trx_state: LOCK WAIT
waiting_trx_id: 870773675
waiting_thread: 206
waiting_query: update t2 set name='x' where name='a'
blocking_trx_state: RUNNING
blocking_trx_id: 870773295
blocking_thread: 207
blocking_query: NULL
1 row in set, 1 warning (0.00 sec)
這兩個(gè)查詢都有一個(gè)問題，就是如果blocking_query已經(jīng)執(zhí)行完畢，但還沒有commit，這種情況下顯示為NULL. 那么這樣才能看到blocking_query呢？這與我們剛才分析長事務(wù)的方法類似，結(jié)合performance_schema相關(guān)表，構(gòu)成如下SQL：
select tmp.*,c.SQL_Text blocking_sql_text,p.Host blocking_host from (SELECT r.trx_state wating_trx_state, r.trx_id waiting_trx_id, r.trx_mysql_thread_Id waiting_thread,r.trx_query waiting_query,b.trx_state blocking_trx_state,b.trx_id blocking_trx_id,b.trx_mysql_thread_id blocking_thread,b.trx_query blocking_query FROM information_schema.innodb_lock_waits w INNER JOIN information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id INNER JOIN information_schema.innodb_trx r ON r.trx_id = w.requesting_trx_id ) tmp ,information_schema.processlist p, performance_schema.events_statements_current c,performance_schema.threads t where tmp.blocking_thread=p.id and t.thread_id= c.THREAD_ID and t.PROCESSLIST_ID=p.id \G
*************************** 1. row ***************************
wating_trx_state: LOCK WAIT
waiting_trx_id: 870773675
waiting_thread: 206
waiting_query: update t2 set name='x' where name='a'
blocking_trx_state: RUNNING
blocking_trx_id: 870773979
blocking_thread: 207
blocking_query: NULL
blocking_sql_text: update t2 set name='x' where name='a'
blocking_host: localhost
1 row in set, 1 warning (0.00 sec)
看到了吧？blocking_sql_text: update t2 set name='x' where name='a'，但這里顯示的SQL只是這個(gè)事務(wù)最后一條SQL，并不是所有的SQL，一個(gè)事務(wù)可以包含多條SQL，因?yàn)槲覀冴P(guān)聯(lián)的表是performance_schema.events_statements_current。能不能顯示事務(wù)內(nèi)所有的SQL呢？有興趣的可以去研究下。
