binlog_group_commit_sync_delay 参数对并发的影响
一、现象
某天,开发人员找到了我,说是某条 UPDATE 语句执行需要 零点几秒,这个速度他们不能接受。不管怎样,首先看一下 SQL 是怎样的:
update t set name='a' where id = 1
数据量 100万,id 是 主键
二、问题排查
2.1 首先排除下执行计划问题
理论上来说走的是主键扫描。那么,首先怀疑一下是不是执行计划出错,走了全表扫。虽然可能性很低,但还是先排除掉这个原因
explain update t set name = 'a' where id = 1 +----+-------------+------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | 1 | UPDATE | t | NULL | range | PRIMARY | PRIMARY | 8 | const | 1 | 100.00 | Using where | +----+-------------+------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
执行计划看来并没有问题。就算索引高度为4,最多也就是4次IO,这对于SSD磁盘 是完成没有压力的,所以,磁盘是否有问题
2.2 排除下磁盘问题
%util 并不高,甚至 50% 都没有达到。暂时先排除磁盘的原因。所以,问题还是回到数据库层,看一下update一条语句,是在哪个环节慢了
2.3 show profiles 看一下各个环节消耗的情况
--打开profiling
set profiling = 1
--执行SQL
update t set name where id = 1
--查看Profiles
SELECT STATE, SUM(DURATION) as total_R, ROUND(100 * SUM(DURATION) / (SELECT SUM(DURATION) FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = 1), 2) as pct_r, count(*) as calls, sum(DURATION) / count(*) as "R/Call" FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = 1 GROUP BY STATE ORDER BY Total_R DESC; +--------------------------------+----------+----------+-------+--------------+ | STATE | total_R | pct_r | calls | R/Call | +--------------------------------+----------+----------+-------+--------------+ | query end | 1.003655 | 35641.16 | 2 | 0.5018275000 | | updating | 0.001037 | 36.83 | 1 | 0.0010370000 | | starting | 0.000100 | 3.55 | 1 | 0.0001000000 | | freeing items | 0.000084 | 2.98 | 1 | 0.0000840000 | | Opening tables | 0.000078 | 2.77 | 1 | 0.0000780000 | | System lock | 0.000068 | 2.41 | 1 | 0.0000680000 | | init | 0.000042 | 1.49 | 1 | 0.0000420000 | | Waiting for semi-sync ACK from | 0.000042 | 1.49 | 1 | 0.0000420000 | | end | 0.000041 | 1.46 | 1 | 0.0000410000 | | cleaning up | 0.000035 | 1.24 | 1 | 0.0000350000 | | closing tables | 0.000027 | 0.96 | 1 | 0.0000270000 | | checking permissions | 0.000020 | 0.71 | 1 | 0.0000200000 | +--------------------------------+----------+----------+-------+--------------+
可以看到主要消耗在 query end 上面。
query end是什么状态? Google 查询了下面这篇博客
http://inetkiller.github.io/2014/05/20/mysql%E8%AF%AD%E5%8F%A5%E6%80%A7%E8%83%BD%E5%88%86%E6%9E%90%E4%B8%8E%E4%BC%98%E5%8C%96/
里面提到了,他修改了 innodb_flush_log_at_trx_commit = 0 解决了性能问题。但是我并没有去改 innodb_flush_log_at_trx_commit。 因为这篇博客给了我一个启发,从日志上面入手
2.4 怀疑 binlog_group_commit_sync_delay 设置的问题
因为要提高slave的复制性能,我把这个参数 binlog_group_commit_sync_delay 调整到了 1s,跟 update 的执行时间很接近。
binlog_group_commit_sync_delay 参数解释:等待多少时间后才进行组提交
带着疑问我把 binlog_group_commit_sync_delay 设置为 0,再次执行
update t set name='a' where id = 1
这一次很快,0.03秒 执行完成。问题似乎已经找到了,但我为了更加确认,我在测试库上执行了又复现了一遍。
三、解决办法
问题分析到这里,很明显就是 binlog_group_commit_sync_delay 参数设置的太大的问题,所以把 binlog_group_commit_sync_delay 设置为 0,就解决了。似乎写到这里就应该结束了,呵呵。天真,还没完呢,请看后续
四、binlog_group_commit_sync_delay 带来的其他副作用
开发在这之前告诉我,说最近的 锁 比较频繁。让我帮忙看一下数据库的问题。我上去数据库查了下,发现基本上都是 RECORD LOCK。被阻塞 SQL 也是下面那条语句
update t set name='a' where id = 1
只是 ID 不一样而已。那么,在生产上我是不敢拿 update 再来执行一遍的,所以我改成了 SELECT * FROM t where id =1,嗯,结果很快,0.01 秒就出来了。然后就可以跟开发说,我这SQL执行很快啊,数据库没有问题的。
看到这里是不是发现了什么?
没错,binlog_group_commit_sync_delay 会影响你的 commit 时间,所以,其他 修改同一行的数据也会 被阻塞。具体看以下实验
会话1:
update t set name = 'aaa' where id = 1; Query OK, 1 row affected (1.01 sec)
会话2:
update t set name = 'aa' where id = 1; Query OK, 1 row affected (1.65 sec)
会话3:
---TRANSACTION 2396, ACTIVE 0 sec starting index read mysql tables in use 1, locked 1 LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s) MySQL thread id 17, OS thread handle 139756413503232, query id 232 localhost root updating update t set name = 'aa' where id = 1 ------- TRX HAS BEEN WAITING 0 SEC FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 27 page no 3 n bits 88 index PRIMARY of table `vcyber`.`t` trx id 2396 lock_mode X locks rec but not gap waiting Record lock, heap no 18 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 0: len 4; hex 80000001; asc ;; 1: len 6; hex 00000000095b; asc [;; 2: len 7; hex 3b0000002a0447; asc ; * G;; 3: len 1; hex 61; asc a;;
看到没有,RECORD LOCK。
binlog_group_commit_sync_delay 对并发的影响就是这么大。各位客官,奉劝一句:binlog_group_commit_sync_delay 这个参数 慎用,用的好了你就是大神,用不好了就跟我一样背锅