首页 / MYSQL / MySQL：从库出现system lock的原因

MySQL：从库出现system lock的原因

内容导读

互联网集市收集整理的这篇技术教程文章主要介绍了MySQL：从库出现system lock的原因，小编现在分享给大家，供广大互联网技能从业者学习和参考。文章包含9026字，纯文字阅读大概需要13分钟。

内容图文

导读：

作者：高鹏（网名八怪），《深入理解MySQL主从原理32讲》系列文的作者。

水平有限有误请谅解。

本文为笔者2年前写一篇说明性文章，发现很多同学都在问这个问题，因此做一次分享。

本文基于5.7.17源码
本文只考虑row格式binlog
主要考虑DML语句，DDL语句比较简单不做考虑
以单sql线程为例（非MTS）

如果要系统的学习主从原理可以参考我的《深入理解MySQL主从原理 32讲》。

一、延迟的计算方式

其实每次show slave status命令的时候后台会调用函数show_slave_status_send_data进行及时计算，这个延迟并不是保存在哪里的。栈帧如下：

#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

其计算方式基本就是这段代码

time_diff= ((long)(time(0) - mi->rli->last_master_timestamp) - mi->clock_diff_with_master);

稍微解释一下：

time(0) ：取当前slave服务器系统时间。
mi->rli->last_master_timestamp：是event common header中timestamp的时间+exetime，其中exetime只有query event才有，其他全部是0,这也导致了binlog row格式下的延迟最大基本是(2 乘以主库的执行的时间)，但是DDL的语句包含在query event中索引延迟最大基本就是(1 乘以主库执行时间)
mi->clock_diff_with_master：这是从库和主库时间的差值。

这里我们也看到event中common header中的timestamp和slave本地时间起了决定因素。因为每次发起命令time(0)都会增加，所以即便event中common header中的timestamp的时间不变延迟也是不断加大的。

另外还有一段有名的伪代码如下：

/*
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;
      else
         print NULL;
}
 else
   compute Seconds_Behind_Master;
}
else
   print NULL;
*/

其实他也来自函数 show_slave_status_send_data，有兴趣的自己在看看，我就不过多解释了。

二、Binlog写入Binlog文件时间和event生成的时间

我发现有朋友这方面有疑问就做个简单的解释：

binlog真正从binglog cache/tmp file写入binlog文件是在commit的flush阶段然后sync阶段才落盘。
event生成是在语句执行期间，具体各个event生成时间如下：

1、如果没有显示开启事物，Gtid event/query event/map event/dml event/xid event均是命令发起时间。

2、如果显示开始事物 Gtid event/xid event是commit命令发起时间，其他event是dml语句发起时间。

所以binlog Event写入到binlog文件和Event的中的时间没有什么联系。下面是一个小事物典型的event生命周期，这是工具infobin生成的：

>GtidEvent:Pos:234(0Xea) N_pos:299(0X12b) Time:1513135186Event_size:65(bytes)
Gtid:31704d8a-da74-11e7-b6bf-52540a7d243:100009 last_committed=0 sequence_number=1
-->QueryEvent:Pos:299(0X12b) N_Pos:371(0X173) Time:1513135186Event_size:72(bytes)
Exe_time:0Use_db:test Statment(35b-trun):BEGIN/*!Trx begin!*/Gno:100009
---->MapEvent:Pos371(0X173) N_pos:415(0X19f) Time:1513135186Event_size:44(bytes)
TABLE_ID:108 DB_NAME:test TABLE_NAME:a Gno:100009
------>InsertEvent:Pos:415(0X19f) N_pos:455(0X1c7) Time:1513135186Event_size:40(bytes)
Dml on table: test.a  table_id:108Gno:100009
>XidEvent:Pos:455(0X1c7) N_Pos:486(0X1e6) Time:1513135186Event_size:31(bytes)
COMMIT; /*!Trx end*/Gno:100009

三、造成延迟的可能原因

这部分是我总结现有的我知道的原因：

大事物延迟，延迟略为2执行时间，状态为:reading event from the relay log
大表DDL延迟，延迟略为1执行时间，状态为:altering table
长期未提交的事物延迟，会造成延迟的瞬时增加
表上没有主键或者唯一键，状态为:system lock或者reading event from the relay log
Innodb层锁造成延迟，状态为:system lock或者reading event from the relay log
从库参数设置如sync_binlog，sync_relay_log，Innodb_flush_log_at_trx_commit等参数

这些原因都是我遇到过的。接下来我想分析一下从库system lock形成的原因。

四、问题由来

问题主要是出现在我们的线上库的从库上，我们经常发现某些数据量大的数据库，sql thread经常处于system lock状态下，大概表现如下：

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 |
+---+--------------+-----------+---------+---------+------+----------------------------------+------------------+

对于这个状态官方有如下描述:

The thread has called MySQL_lock_tables() and the thread state has not been updated since.
Thisis a very general state that can occur for many reasons.
For example, the thread is going to request oris waiting for an internalor external system lockfor the
table. This can occur whenInnodb waits for a table-level lock during execution of LOCK TABLES.
Ifthis state is being caused by requests for external locks and you are notusing 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 bydefault, 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).

显然不能解决我的问题，一时间也是无语。而我今天在测试从库手动加行锁并且sql thread冲突的时候发现了这个状态，因此结合gdb调试做了如下分析，希望对大家有用，也作为后期我学习的一个笔记。

五、system lock 延迟的原因

这里先直接给出原因供大家直接参考，简单的说从库出现system lock 应该视为正在干活，而不是名称看到的“lock”，这是由于slave端不存在语句（row格式）的执行，都是Event的直接apply，状态没有切换的机会，也可以认为是slave端状态划分不严谨，其实做一个pstack就能完全看出问题。下面是产生的必要条件：

由于大量的小事物，比如如UPDATE/DELETE table where处理一行数据，这会出现只包含一行数据库的DML event的语句，如果table是一张大表，则会加剧这种可能。
这个表上没有主键或者唯一键，问题加剧。
由于类似Innodb lock堵塞，也就是slave从库修改了数据同时和sql_thread也在修改同样的数据，问题加剧。
确实I/O扛不住了，可以尝试修改参数。

如果是大量的表没有主键或者唯一键可以考虑修改参数slave_rows_search_algorithms 试试。关于slave_rows_search_algorithms 在我的系列中有一章详细讨论，这里不做熬述。

六、system lock 延迟的问题分析

我们知道所有的state都是MySQL上层的一种状态，如果要发生状态的改变必须要调用THD::enter_stage来改变，而system lock则是调用mysql_lock_tables进入的状态，同时从库SQL_THREAD中还有另外一种状态重要的状态reading event from the relay log。

这里是rpl_slave.cc handle_slave_sql函数中的很小的一部分主要用来证明我的分析。

/* Read queries from the IO/THREAD until this thread is killed */
    
while(!sql_slave_killed(thd,rli)) //大循环
{
     THD_STAGE_INFO(thd, stage_reading_event_from_the_relay_log); //这里进入reading event from the relay log状态
if(exec_relay_log_event(thd,rli)) //这里会先调入next_event函数读取一条event，然后调用lock_tables但是如果不是第一次调用lock_tables则不需要调用MySQL_lock_tables
//逻辑在lock_tables调用mySQL_lock_tables则会将状态置为system lock，然后进入Innodb层进行数据的查找和修改
    
}

这里还特地请教了阿里的印风兄验证了一下mysql_lock_tables是myisam实现表锁的函数Innodb会设置为共享锁。

这里我们先抛开query event/map event等。只考虑DML event，下面就是system lock出现的流程：

如果一个小事物只有一条DML event的场景下逻辑如下：

->进入reading eventfrom the relay log状态
 ->读取一条event(参考next_event函数)
  ->进入system lock状态
   ->Innodb层进行查找和修改数据

如果是一个大事物则包含了多条DML event的场景逻辑如下:

->进入reading eventfrom the relay log状态
 ->读取一条event(参考next_event函数)
  ->进入system lock状态
   ->Innodb层进行查找和修改数据
->进入reading eventfrom the relay log状态
 ->读取一条event(参考next_event函数)
  ->Innodb层进行查找和修改数据
->进入reading eventfrom the relay log状态
 ->读取一条event(参考next_event函数)
  ->Innodb层进行查找和修改数据
....直到本事物event执行完成

因此我们看到对于一个小事物我们的sql_thread会在加system lock的情况下进行对数据进行查找和修改。

因此得出了我的结论，同时如果是Innodb层锁造成的sqlthread堵塞也会在持有system lock的状态下。但是对于一个大事物则不一样，虽然出现同样的问题，但是其状态是reading event from the relay log。

所以如果出现system lock一般就是考虑前文给出的结论。

七、分析中用到的断点

mysql_lock_tables 本函数更改状态为system lockgdb打印:p tables[0]->s->table_name
THD::enter_stage 本函数改变状态gdb打印:p new_stage->m_name
ha_innobase::index_read innodb查找数据接口gdb打印:p index->table_name
ha_innobase::delete_row innodb删除数据接口
exec_relay_log_event 获取event并且应用gdb 打印:ev->get_type_code()

原文链接：https://www.jianshu.com/p/839e1fa81edb
扫码加个好友，还有更多文章分享呀
MySQL：从库出现system lock的原因 - 文章图片

点赞
收藏
分享
- 文章举报

Evelyn_Lv 发布了10 篇原创文章 · 获赞 0 · 访问量 177 私信关注

内容总结

以上是互联网集市为您收集整理的MySQL：从库出现system lock的原因全部内容，希望文章能够帮你解决MySQL：从库出现system lock的原因所遇到的程序开发问题。如果觉得互联网集市技术教程内容还不错，欢迎将互联网集市网站推荐给程序员好友。

内容备注

版权声明：本文内容由互联网用户自发贡献，该文观点与技术仅代表作者本人。本站仅提供信息存储空间服务，不拥有所有权，不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容，请发送邮件至 gblab@vip.qq.com 举报，一经查实，本站将立刻删除。

内容手机端

扫描二维码推送至手机访问。

本文链接：https://qyyshop.com/info/878042.html

来源：【匿名】

首页 / MYSQL / MySQL：从库出现system lock的原因

MySQL：从库出现system lock的原因

内容导读

内容图文

内容总结

内容备注

内容手机端

SYSTEM - 相关标签

MYSQL - 相关标签

MYSQL - 技术教程分类

MYSQL - 最新教程

MYSQL - 最热教程