数据库优化经典案例

TCP重传会对数据库产生什么影响
• 大量SQL被kill
在执行 kill query thread_id 时，MySQL 做了两件事： 1. 把对应的session的运行状态值(killed )改成THD::KILL_QUERY 2. 给对应的session的执行线程发一个信号。 被kill的线程需要在埋点的地方/可唤醒的等待判断线程状态
• 当通过二级索引扫描记录时，如果选择性好，符合条件的记录少，SQL速度快。 相反的，如果符合条件的记录多且大部分被标记为删除的时候，SQL速度慢。
• 只针对RR有效，RC不存在该问题
一次奇怪的SQL慢查的分析
慢查解剖
mysql > select * from t1 where b='1234567890A' limit 1; Empty set (8.23 sec)
TCP重传会对数据库产生什么影响
• 大量SQL被kill
• 每个实例部署了sql killer 当实例中存在执行时间超过1秒的SQL，立即执行kill query thread_id。
• 收到大量SQL被kill的告警
TCP重传会对数据库产生什么影响
• 大量SQL被kill
• 日志里面的thread id都是同一个 • 执行时间超过killer的阈值，以1秒递增
如果事务中发生了网络异常
事务什么时候会退出？
开始抓包 # tcpdump host 192.168.56.102 -s 0 -w /tmp/tcp_timeout.pcap
如果事务中发生了网络异常
事务什么时候会退出？
3. 主动kill 异常会话 mysql > kill thread_id;
TCP重ATA_TRX_ID(1000) DATA_ROLL_PTR
aaa
2
DATA_TRX_ID(1001) DATA_ROLL_PTR
bbb
3
DATA_TRX_ID(1002) DATA_ROLL_PTR
ccc
4
DATA_TRX_ID(1003) DATA_ROLL_PTR
ddd
5
DATA_TRX_ID(1004) DATA_ROLL_PTR
deleted:1 deleted:1 deleted:1
1
DATA_TRX_ID(1000) DATA_ROLL_PTR
aaa
2
DATA_TRX_ID(1001) DATA_ROLL_PTR
bbb
3
DATA_TRX_ID(1002) DATA_ROLL_PTR
ccc
1. 通过主键，扫描到ID=1的记录，根据MVCC比对DATA_TRX_ID，记录可见 2. 由于ID=1已经被标记为DELETED，删除记录可见 3. 由于表数据还没有全部扫描完成，未满足limit 1，继续扫描下一条记录 4. 扫描到ID=2的记录，根据MVCC比对DATA_TRX_ID，记录可见 5. 由于ID=2已经被标记为DELETED，删除记录可见 6. 由于表数据还没有全部扫描完成，未满足limit 1，继续扫描下一条记录 7. 重复4-6步骤，直到满足找到一条记录，或者全表扫描完成
TCP重传会对数据库产生什么影响
• 数据库大量慢查
TCP重传会对数据库产生什么影响
• 数据库大量慢查
在网络发生重传的时候，SQL的执行结果发送给客户端的时 候需要通过TCP重传来完成，SQL的执行state表现为 Sending to client。
如果一个block在net_write_timeout时间内都没有完成发送， SQL执行将会中断，抛出1161错误(Got timeout writing communication packets)
些收尾工作完成后，SQL语句才会退出。
大量删除导致的SQL慢查
现象描述
1. 执行sbtest1表的部分查询非常慢，状态为 Sending data 2. 执行除sbtest1表外的其他表查询都非常快
大量删除导致的SQL慢查
分析问题
1. 数据库的隔离级别为RR 2. 查询监控慢查的量是大量删除操作之后开始的 3. 询问业务方，得知该表会经常执行删除旧数据的操作 4. History list length 非常大，达到几万，并且一直在增长 5. 查询innodb_trx 表发现有一个事务，很久没有提交
事务什么时候会退出？
1. MySQL参数 wait_timeout（默认8小时） 表示的是MySQ L的一个连接空闲超过8小时， M y S Q L 自动断开该连接
如果事务中发生了网络异常
事务什么时候会退出？
2. 等待TCP超时
TCP 超时参数 /proc/sys/net/ipv4/tcp_keepalive_time = 7200（等待空闲时间秒） /proc/sys/net/ipv4/tcp_keepalive_intvl = 75（探测间隔秒） /proc/sys/net/ipv4/tcp_keepalive_probes = 9（探测次数）
2. Innodb 拿到第/下一条数据后，返回Server层。 3. Server层判断发现b 的值不是‘1234567890X’，继续请求下一条 4. 循环执行步骤2和步骤3，直到扫描完全部1234567890的记录 5. 返回空
Rows_examined太多了，全表扫描了吧
表结构
一次奇怪的SQL慢查的分析
b 列上面有索引，没走索引么，隐式转化了么？
一次奇怪的SQL慢查的分析
查看执行计划
走索引的呀，为啥rows那么大，实际匹配为0呢？
一次奇怪的SQL慢查的分析
不会碰到BUG了吧？
• 从业务方确认SQL的作用 • 业务上一直重复插入，如果记录存在就不插入 • 确认了下业务方最近插入的记录
表示在读取以及处理行数据以及发送数据到客户端，由于数据只有一 行，且当时网络正常，那么时间就是耗费在读取和处理select的数据
大量删除导致的SQL慢查
主键记录
deleted:1 deleted:1 deleted:1 deleted:1 deleted:1 deleted:1 deleted:1 deleted:1 deleted:0 deleted:0 deleted:0
如果事务中发生了网络异常
事务什么时候会退出？
2. 等待TCP超时
修改TCP超时 # echo 60 > /proc/sys/net/ipv4/tcp_keepalive_time # echo 7 > /proc/sys/net/ipv4/tcp_keepalive_intvl # echo 5 > /proc/sys/net/ipv4/tcp_keepalive_probes
t3
select * from sbtest1 limit 1(ౌ )
select * from sysbench.sbtest1 order by id desc limit 1 ; ҁ ள ҂
t4
select * from sbtest2 limit 1(ள)
select * from sysbench.sbtest1 where id=21134001 limit 1;( ள҂
大量删除导致的SQL慢查
总结
• 大量删除是由ID从小到大进行，由于存在活跃事务，因此ID头部存在大量标 记为删除还没被purge的行，在主键中依然存在
• 当通过主键正序全表扫描取limit 1的时候，根据当前的事务ID去判断该行是否 可见，发现不可见之后，继续往下扫描，直到找到第一行
• 当通过主键逆序全表扫描取limit 1的时候，由于逆序这边ID没有进行删除操作， 只需要取一条判断可见即可返回
select * from sysbench.sbtest1 where k=25990706 limit 1 ; ҁ ள ҂
大量删除导致的SQL慢查
• 执行sbtest1主键扫描很慢 • 执行sbtest2 主键扫描很快
大量删除导致的SQL慢查
通过profile，发现大部分时间耗费在sending data
power off
Server 192.168.56.101
断电
如果事务中发生了网络异常
MySQL Server事务信息
如果事务中发生了网络异常
MySQL Server 主机TCP连接信息
如果事务中发生了网络异常
启动一个新的client，对t1表进行加锁需要等待
如果事务中发生了网络异常
服务端为什么没有退出这个事务呢？
eee
….
…
…
…
…
…
…
…
….
…
…
…
20000000
DATA_TRX_ID(20)
DATA_ROLL_PTR
abc
20000001
DATA_TRX_ID(20)
DATA_ROLL_PTR
edf
20000002
DATA_TRX_ID(20)
DATA_ROLL_PTR
ghi
大量删除导致的SQL慢查
select * from sbtest1 limit 1 扫描记录的过程
TCP重传会对数据库产生什么影响
• 大量SQL被kill
为啥执行kill query thread_id无效
• 线程没有执行到判断线程状态的逻辑。读写 IO 的函数一直无法返
回，线程一直在等待进入innodb等，会导致不能及时判断线程的状 态。
• 终止逻辑耗时较长。例如大事务回滚，临时文件删除等。需要等这
大量删除导致的SQL慢查
搭建模拟测试环境，利用sysbench创建一张48730893行的sbtest1表
Sess1
Sess2
Sess3
t1 begin;select * from sbtest1 limit 1;
delete from sbtest1 order by id limit
t2
1 0 0 0 ; ( ஗ሾ ӷ ӡ ེ )
以下案例均在事务开始之后
• 假如强制关闭应用 • 假如client机器突然崩溃宕机/断电 • 假如网络发生抖动/网卡发生故障
如果事务中发生了网络异常
模拟client突然宕机
10:00:00 10:00:10
Client 192.168.56.102
begin; select * from zandb.t1 for update;
TCP 新建连接需要三次握手 TCP 关闭连接需要四次挥手
如果事务中发生了网络异常
如果事务中发生了网络异常
网络异常的时候，TCP连接的状态还是 ESTABLISHED，说明了任何一方都没有发送FIN 包，服务端还在等待CLIENT发送数据，此时的 MySQL事务无法直接退出。
如果事务中发生了网络异常
大量删除导致的SQL慢查
Sending data
The thread is reading and processing rows for a SELECT statement, and sending data to the client. Because operations occurring during this state tend to perform large amounts of disk access (reads), it is often the longest-running state over the lifetime of a given query.
数据库优化经典案例
技术创新 变革未来
案例列表
• 如果事务过程中发生了网络异常 • TCP重传会对数据库产生什么影响 • 大量删除导致的SQL慢查 • 一次奇怪的SQL慢查的分析 • 一次SQL RT增加的问题排查 • 利用strace利器解决性能问题 • 如何去定位MySQL性能问题的根源
如果事务中发生了网络异常
一次奇怪的SQL慢查的分析
好像突然发现了什么
插入的数据被截断了
一次奇怪的SQL慢查的分析
一共有20万的脏数据
一次奇怪的SQL慢查的分析
为什么会慢呢
1. MySQL Server 在传给Innodb执行的时候，由于Innodb 定义t1表的b 字段为varchar(10)，截取了前 10 个字符‘1234567890’，给Innodb。
• 超时重传
TCP每发送一个报文段，就对这个报文段设置一次计时器。 当计时器超时而没有收到确认时，就重传该报文。
• 快重传
在发送端一连收到4个ack报文，其中3个重复报文时，就 立即重传相应的报文而不等到定时器超时。
TCP重传会对数据库产生什么影响
• 数据库大量慢查
模拟40%的重传 $sudo tc qdisc add dev eth0 root netem loss 40%
1datatrxid1002datarollptrcccselectfromsbtest1limit由于表数据还没有全部扫描完成未满足limit1继续扫描下一条记录由于表数据还没有全部扫描完成未满足limit1继续扫描下一条记录重复46步骤直到满足找到一条记录或者全表扫描完成大量删除导致的sql慢查总结大量删除是由id从小到大进行由于存在活跃事务因此id头部存在大量标记为删除还没被purge的行在主键中依然存在当通过主键正序全表扫描取limit1的时候根据当前的事务id去判断该行是否可见发现不可见之后继续往下扫描直到找到第一行当通过主键逆序全表扫描取limit1的时候由于逆序这边id没有进行删除操作只需要取一条判断可见即可返回当通过二级索引扫描记录时如果选择性好符合条件的记录少sql速度快