从Mysql slave system lock延迟说开去
生活随笔
收集整理的這篇文章主要介紹了
从Mysql slave system lock延迟说开去
小編覺得挺不錯(cuò)的,現(xiàn)在分享給大家,幫大家做個(gè)參考.
本文主要分析 sql thread中system lock出現(xiàn)的原因，但是筆者并明沒有系統(tǒng)的學(xué)習(xí)過master-slave的代碼，這也是2018年的一個(gè)目標(biāo)，2018年我都排滿了，悲劇。所以如果有錯(cuò)誤請(qǐng)指出，也作為一個(gè)筆記用于后期學(xué)習(xí)。同時(shí)也給出筆者現(xiàn)在知道的幾種造成延遲的可能和延遲計(jì)算的方式。
- 本文基于5.7.17源碼
- 本文只考慮row 格式binlog
- 主要考慮DML語(yǔ)句，DDL語(yǔ)句比較簡(jiǎn)單不做考慮
一、延遲的計(jì)算方式
其實(shí)每次show slave status命令的時(shí)候后臺(tái)會(huì)調(diào)用函數(shù)show_slave_status_send_data進(jìn)行及時(shí)計(jì)算，這個(gè)延遲并不是保存在哪里的。棧幀如下：
#0 show_slave_status_send_data (thd=0x7fffd8000cd0, mi=0x38ce2e0, io_gtid_set_buffer=0x7fffd800eda0 "e859a28b-b66d-11e7-8371-000c291f347d:42-100173", sql_gtid_set_buffer=0x7fffd8011ac0 "e859a28b-b66d-11e7-8371-000c291f347d:1-100173") at /mysql/mysql-5.7.17/sql/rpl_slave.cc:3602 #1 0x0000000001867749 in show_slave_status (thd=0x7fffd8000cd0) at /mysql/mysql-5.7.17/sql/rpl_slave.cc:3982 #2 0x0000000001867bfa in show_slave_status_cmd (thd=0x7fffd8000cd0) at /mysql/mysql-5.7.17/sql/rpl_slave.cc:4102其計(jì)算方式基本就是這段代碼
time_diff= ((long)(time(0) - mi->rli->last_master_timestamp) - mi->clock_diff_with_master);稍微解釋一下：
- time(0) ：取當(dāng)前slave服務(wù)器系統(tǒng)時(shí)間。
- mi->rli->last_master_timestamp：是event common header中timestamp的時(shí)間+exetime，其中exetime只有query event才有，其他全部是0,這也導(dǎo)致了binlog row格式下的延遲最大基本是(2 乘以主庫(kù)的執(zhí)行的時(shí)間)，但是DDL的語(yǔ)句包含在query event中索引延遲最大基本就是(1 乘以 主庫(kù)執(zhí)行時(shí)間)
- mi->clock_diff_with_master：這是從庫(kù)和主庫(kù)時(shí)間的差值。
這里我們也看到event中common header中的timestamp和slave本地時(shí)間起了決定因素。因?yàn)槊看伟l(fā)起命令time(0)都會(huì)增加，所以即便event中common header中的timestamp的時(shí)間不變延遲也是不斷加大的。
另外還有一段有名的偽代碼如下：
/*The pseudo code to compute Seconds_Behind_Master:if (SQL thread is running){if (SQL thread processed all the available relay log){if (IO thread is running)print 0;elseprint NULL;}elsecompute Seconds_Behind_Master;}elseprint NULL;*/其實(shí)他也來(lái)自函數(shù) show_slave_status_send_data，有興趣的自己在看看。我就不過多解釋了。
這部分還可以參考一下淘寶內(nèi)核月報(bào)
- https://www.kancloud.cn/taobaomysql/monthly/140089
這也是后期我還要學(xué)習(xí)的文章。
二、Binlog寫入Binlog文件時(shí)間和event生成的時(shí)間
我發(fā)現(xiàn)有朋友這方面有疑問就做個(gè)簡(jiǎn)單的解釋
- binlog真正從binglog cache/tmp file寫入binlog文件是在commit的flush階段然后sync階段才落盤，傳輸是在order commit的flush后。
- event生成是在語(yǔ)句執(zhí)行期間，具體各個(gè)event生成時(shí)間如下：
所以binlog寫入到binlog文件或者什么時(shí)候傳輸?shù)絪lave和event的生成沒有什么聯(lián)系。
下面是一個(gè)小事物典型的event生命周期
三、造成延遲的可能原因
這部分是我總結(jié)現(xiàn)有的我知道的原因：
- 大事物延遲 延遲略為2*執(zhí)行時(shí)間 狀態(tài)為:reading event from the relay log
- 大表DDL延遲 延遲略為1*執(zhí)行時(shí)間 狀態(tài)為:altering table
- 長(zhǎng)期未提交的事物延遲，會(huì)造成延遲的瞬時(shí)增加
- 表上沒有主鍵或者唯一鍵 狀態(tài)為:system lock 或者 reading event from the relay log
- innodb層鎖造成延遲 狀態(tài)為:system lock 或者 reading event from the relay log
- 從庫(kù)參數(shù)設(shè)置如sync_binlog，sync_relay_log，innodb_flush_log_at_trx_commit等參數(shù)
這些原因都是我遇到過的。接下來(lái)我想分析一下從庫(kù)system lock形成的原因。
四、問題由來(lái)
問題主要是出現(xiàn)在我們的線上庫(kù)的從庫(kù)上，我們經(jīng)常發(fā)現(xiàn)某些數(shù)據(jù)量大的數(shù)據(jù)庫(kù)，sql thread經(jīng)常處于system lock狀態(tài)下，大概表現(xiàn)如下：
mysql> show processlist; +----+-------------+-----------+------+---------+------+----------------------------------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-------------+-----------+------+---------+------+----------------------------------+------------------+ | 3 | root | localhost | test | Sleep | 426 | | NULL | | 4 | system user | | NULL | Connect | 5492 | Waiting for master to send event | NULL | | 5 | system user | | NULL | Connect | 104 | System lock | NULL | | 6 | root | localhost | test | Query | 0 | starting | show processlist | +----+-------------+-----------+------+---------+------+----------------------------------+------------------+對(duì)于這個(gè)狀態(tài)官方有如下描述:
The thread has called mysql_lock_tables() and the thread state has not been updated since. This is a very general state that can occur for many reasons. For example, the thread is going to request or is waiting for an internal or external system lock for the table. This can occur when InnoDB waits for a table-level lock during execution of LOCK TABLES. If this state is being caused by requests for external locks and you are not using multiple mysqld servers that are accessing the same MyISAM tables, you can disable external system locks with the --skip-external-locking option. However, external locking is disabled by default, so it is likely that this option will have no effect. For SHOW PROFILE, this state means the thread is requesting the lock (not waiting for it).顯然不能解決我的問題，一時(shí)間也是無(wú)語(yǔ)。而我今天在測(cè)試從庫(kù)手動(dòng)加行鎖并且sql thread沖突的時(shí)候發(fā)現(xiàn)了這個(gè)狀態(tài)，因此結(jié)合gdb調(diào)試做了如下分析，希望對(duì)大家有用，也作為后期我學(xué)習(xí)的一個(gè)筆記。
五、system lock 延遲的原因
這里直接給出原因供大家直接參考:
必要條件：
由于大量的小事物如UPDATE/DELETE table where一行數(shù)據(jù)，這種只包含一行DML event的語(yǔ)句，table是一張大表。
- 這個(gè)表上沒有主鍵或者唯一鍵。
- 由于類似innodb lock堵塞，也就是slave從庫(kù)修改了數(shù)據(jù)同時(shí)和sql_thread也在修改同樣的數(shù)據(jù)。
- 確實(shí)I/O扛不住了，可以嘗試修改參數(shù)。
如果是大量的表沒有主鍵或者唯一鍵可以考慮修改參數(shù)slave_rows_search_algorithms 試試。但是innodb中不用主鍵或者主鍵不選擇好就等于自殺。
六、system lock 延遲的問題分析
下面的分析是我通過gdb代碼得出的結(jié)論可能有誤
我們知道所有的state都是mysql上層的一種狀態(tài)，如果要發(fā)生狀態(tài)的改變必須要調(diào)用THD::enter_stage來(lái)改變，而system lock則是調(diào)用mysql_lock_tables進(jìn)入的狀態(tài)，同時(shí)從庫(kù)SQL_THREAD中還有另外一種狀態(tài)重要的狀態(tài)reading event from the relay log。
這里是rpl_slave.cc handle_slave_sql函數(shù)中的很小的一部分主要用來(lái)證明我的分析。
/* Read queries from the IO/THREAD until this thread is killed */while (!sql_slave_killed(thd,rli)) //大循環(huán){THD_STAGE_INFO(thd, stage_reading_event_from_the_relay_log); //這里進(jìn)入reading event from the relay log狀態(tài)if (exec_relay_log_event(thd,rli)) //這里會(huì)先調(diào)入next_event函數(shù)讀取一條event，然后調(diào)用lock_tables但是如果不是第一次調(diào)用lock_tables則不需要調(diào)用mysql_lock_tables//邏輯在lock_tables調(diào)用mysql_lock_tables則會(huì)將狀態(tài)置為system lock，然后進(jìn)入innodb層進(jìn)行數(shù)據(jù)的查找和修改}這里還特地請(qǐng)教了阿里的印風(fēng)兄驗(yàn)證了一下mysql_lock_tables是myisam實(shí)現(xiàn)表鎖的函數(shù)innodb會(huì)設(shè)置為共享鎖。
這里我們先拋開query event/map event等。只考慮DML event
- 如果一個(gè)小事物只有一條DML event的場(chǎng)景下邏輯如下：
- 如果是一個(gè)大事物則包含了多條DML event的場(chǎng)景邏輯如下:
因此我們看到對(duì)于一個(gè)小事物我們的sql_thread會(huì)在加system lock的情況下進(jìn)行對(duì)數(shù)據(jù)進(jìn)行查找和修改，因此得出了我的結(jié)論，同時(shí)如果是innodb 層 鎖造成的sql_thread堵塞也會(huì)在持有system lock的狀態(tài)下。但是對(duì)于一個(gè)大事物則不一樣，雖然出現(xiàn)同樣的問題的但是其狀態(tài)是reading event from the relay log。所以如果出現(xiàn)system lock一般就是考慮前文給出的結(jié)論，但是前文給出的結(jié)論不一定都會(huì)引起system lock，這個(gè)要看是否是大事物。
以下的部分是我進(jìn)行g(shù)db的時(shí)候用到斷點(diǎn)和棧幀是我自己看的
七、分析中用到的斷點(diǎn)
- mysql_lock_tables 本函數(shù)更改狀態(tài)為system lock
gdb打印:p tables[0]->s->table_name - THD::enter_stage 本函數(shù)改變狀態(tài)
gdb打印:p new_stage->m_name - ha_innobase::index_read innodb查找數(shù)據(jù)接口
gdb打印:p index->table_name - ha_innobase::delete_row innodb刪除數(shù)據(jù)接口
- exec_relay_log_event 獲取event并且應(yīng)用
八、兩個(gè)棧幀
- 進(jìn)入system lock狀態(tài)
- 在system lock狀態(tài)下查找數(shù)據(jù)
作者微信：
總結(jié)
以上是生活随笔為你收集整理的从Mysql slave system lock延迟说开去的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 梦到脚底长毛什么意思
- 下一篇： 怀孕了老公做梦梦到老鼠是什么意思