[MySQL FAQ]系列 — 不同的binlog_format会导致哪些SQL不会被记录

我们都知道binlog_format有三种可选配置:STATEMENT、ROW、MIXED,相应地,基于这三种模式的Replication分别称为SBR(STATEMENT BASED Replication)、RBR、MBR。 同时,我们也知道,MySQL Replication可以支持比较灵活的binlog规则,可以设置某些库、某些表记录或者忽略不记录。

通常地,我们强烈建议不要设置这些规则,默认都记录就好,在Slave上也是如此,默认所有库都进行Replicate,不要设置DO、IGNORE、REWRITE规则。 如果非要设置这些规则的话,可能会导致某些场景下或者某些特定的SQL无法被记录,就需要特别注意了。

我经过比较简单的测试,不同的binlog_format可能会导致某些SQL不被记录的情况总结如下:

mysql-faq-how-binlog-format-affect-replication
上面的测试区分了两种模式,一种是连接时指定了其他数据库,一种是连接时未指定任何数据库,相当于下面的两种方式:
#假设do/ignore规则中的DB名字叫DoDB/IgnoreDB/RewriteDB的话,OtherDB是规则之外的其他DB

#一种是:连接时指定了do/ignore/rewrite规则之外的其他DB
mysql -h host -u user -p passwd -p port -A OtherDB

#还有一种是:连接时不指定任何DB
mysql -h host -u user -p passwd -p port -A

#tips,加上 -A 是--no-auto-rehash的缩写,其作用是连接后不读取数据库、表、字段信息。与其相反的选项是 --auto-rehash,也就是连接后会读取数据库、表、字段信息,以便自动补齐。
更多情况请读者自行进行测试吧 :)

[MySQL FAQ]系列 — MySQL复制中slave延迟监控

在MySQL复制环境中,我们通常只根据 Seconds_Behind_Master 的值来判断SLAVE的延迟。这么做大部分情况下尚可接受,但并不够准确,而应该考虑更多因素。

首先,我们先看下SLAVE的状态:

yejr@imysql.com [(none)]> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
***
Master_Log_File: mysql-bin.000327
Read_Master_Log_Pos: 668711237
Relay_Log_File: mysql-relay-bin.002999
Relay_Log_Pos: 214736858
Relay_Master_Log_File: mysql-bin.000327
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
***
Skip_Counter: 0
Exec_Master_Log_Pos: 654409041
Relay_Log_Space: 229039311
***
Seconds_Behind_Master: 3296
***

可以看到 Seconds_Behind_Master 的值是 3296,也就是SLAVE至少延迟了 3296 秒。

我们再来看下SLAVE上的2个REPLICATION进程状态:

yejr@imysql.com [(none)]> show full processlist\G
*************************** 1. row ***************************
Id: 6
User: system user
Host:
db: NULL
Command: Connect
Time: 22005006
State: Waiting for master to send event
Info: NULL
*************************** 2. row ***************************
Id: 7
User: system user
Host:
db: NULL
Command: Connect
Time: 3293
State: Updating
Info: UPDATE ** SET ** WHERE **

可以看到SQL线程一直在执行UPDATE操作,注意到 Time 的值是 3293,看起来像是这个UPDATE操作执行了3293秒,一个普通的SQL而已,肯定不至于需要这么久。
实际上,在REPLICATION进程中,Time 这列的值可能有几种情况:
1、SQL线程当前执行的binlog(实际上是relay log)中的timestamp和IO线程最新的timestamp的差值,这就是通常大家认为的 Seconds_Behind_Master 值,并不是某个SQL的实际执行耗时;
2、SQL线程当前如果没有活跃SQL在执行的话,Time值就是SQL线程的idle time;

而IO线程的Time值则是该线程自从启动以来的总时长(多少秒),如果系统时间在IO线程启动后发生修改的话,可能会导致该Time值异常,比如变成负数,或者非常大。

来看下面几个状态:

#设置pager,只查看关注的几个status值
yejr@imysql.com [(none)]> pager cat | egrep -i 'system user|Exec_Master_Log_Pos|Seconds_Behind_Master|Read_Master_Log_Pos'

#这是没有活跃SQL的情况,Time值是idle time,并且 Seconds_Behind_Master 为 0
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004245 | Waiting for master to send event | NULL |
| 7 | system user | | NULL | Connect | 13 | Has read all relay log;**
Read_Master_Log_Pos: 445167889
Exec_Master_Log_Pos: 445167889
Seconds_Behind_Master: 0

#和上面一样
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004248 | Waiting for master to send event | NULL |
| 7 | system user | | NULL | Connect | 16 | Has read all relay log;**
Read_Master_Log_Pos: 445167889
Exec_Master_Log_Pos: 445167889
Seconds_Behind_Master: 0

#这时有活跃SQL了,Time值是和 Seconds_Behind_Master 一样,即SQL线程比IO线程“慢”了1秒
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004252 | Waiting for master to send event | NULL |
| 7 | system user | | floweradmin | Connect | 1 | Updating | update **
Read_Master_Log_Pos: 445182239
Exec_Master_Log_Pos: 445175263
Seconds_Behind_Master: 1

#和上面一样
yejr@imysql.com [(none)]> show processlist; show slave status\G
| 6 | system user | | NULL | Connect | 22004254 | Waiting for master to send event | NULL |
| 7 | system user | | floweradmin | Connect | 1 | Updating | update **
Read_Master_Log_Pos: 445207174
Exec_Master_Log_Pos: 445196837
Seconds_Behind_Master: 1

好了,最后我们说下如何正确判断SLAVE的延迟情况:
1、首先看 Relay_Master_Log_FileMaster_Log_File 是否有差异;
2、如果Relay_Master_Log_FileMaster_Log_File 是一样的话,再来看Exec_Master_Log_PosRead_Master_Log_Pos 的差异,对比SQL线程比IO线程慢了多少个binlog事件;
3、如果Relay_Master_Log_FileMaster_Log_File 不一样,那说明延迟可能较大,需要从MASTER上取得binlog status,判断当前的binlog和MASTER上的差距;

因此,相对更加严谨的做法是:
在第三方监控节点上,对MASTER和SLAVE同时发起SHOW BINARY LOGSSHOW SLAVE STATUS\G的请求,最后判断二者binlog的差异,以及 Exec_Master_Log_PosRead_Master_Log_Pos 的差异。

例如:
在MASTER上执行SHOW BINARY LOGS 的结果是:

+------------------+--------------+
| Log_name | File_size |
+------------------+--------------+
| mysql-bin.000009 | 1073742063 |
| mysql-bin.000010 | 107374193 |
+------------------+--------------+

而在SLAVE上执行SHOW SLAVE STATUS\G 的结果是:

Master_Log_File: mysql-bin.000009
 Read_Master_Log_Pos: 668711237
Relay_Master_Log_File: mysql-bin.000009
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
***
Exec_Master_Log_Pos: 654409041

***
Seconds_Behind_Master: 3296
***

这时候,SLAVE实际的延迟应该是:
mysql-bin.000009 这个binlog中的binlog position 1073742063 和 SLAVE上读取到的binlog position之间的差异延迟,即:

1073742063 - 654409041 = 419333022 个binlog event

并且还要加上 mysql-bin.000010这个binlog已经产生的107374193个binlog event,共

107374193 + 419333022 = 526707215 个binlog event

后记更新:

1、可以在MASTER上维护一个监控表,它只有一个字段,存储这最新最新时间戳(高版本可以采用event_scheduler来更新,低版本可以用cron结合自动循环脚本来更新),在SLAVE上读取该字段的时间,只要MASTER和SLAVE的系统时间一致,即可快速知道SLAVE和MASTER延迟差了多少。不过,在高并发的系统下,这个时间戳可以细化到毫秒,否则哪怕时间一致,也是有可能会延迟数千个binlog event的。
2、网友(李大玉,QQ:407361231)细心支出上面的计算延迟有误,应该是mysql-bin.000009的最大事件数减去已经被执行完的事件数,即1073742063 – 654409041= 419333022个binlog event,再加上mysql-bin.000010这个binlog已经产生的107374193个binlog event,共526707215 个binlog event。

[MySQL FAQ]系列 — 你所不知的table is full那些事

当我们要写入新数据而发生“The table is full”告警错误时,先不要着急,按照下面的思路来逐步分析即可:
1、查看操作系统以及MySQL的错误日志文件
确认操作系统的文件系统没有报错,并且MySQL的错误日志文件中是否有一些最直观的可见的错误提示。
有可能是数据库文件超过操作系统层的文件大小限制,比如fat/fat32以及低版本的Linux,文件最大不可以大于2G(最大扩展到4G),这就需要转换fat32为NTFS,或升级Linux版本。

2、确认磁盘空间没有满
执行 df -h 查看剩余磁盘空间,如果发现磁盘空间确实已经用完,则尽快删除不需要的文件。

如果通过 du 计算各个目录的总和却发现根本不会用完磁盘空间时,就需要注意了,可能是某个被删除的文件还没完全释放,导致 df 看起来已经用完,但 du 却又统计不到。
这时候可以执行 lsof | grep -i deleted 找到被删除的大文件,将其对应的进程杀掉,释放该文件描述符。

如果该进程不能被杀掉,例如是 mysqld 进程在占用的话,可以在 MySQL 里找到是哪个内部线程在用,停止该线程即可。

曾经发生过这样一个例子:
用vim打开MySQL的slow query log,退出时选择了 “wq” 指令,也就是保存退出,结果悲剧发生了。
因为在其打开的那段时间内,slow query log有新日志产生,会持续写入,但他退出时采用保存退出的方式,变成了一个“新”文件(或者说新文件句柄 file handler),这个“新”文件无法被mysqld进程识别,
mysqld进程依旧将slow query log写入到原来它打开的那个文件(或者说文件句柄)里,该日志文件在持续增长,但手工保存退出的文件却再也不增长了,直接查看文件看不出任何异常。
这时候只能用 lsof -p `pidof mysqld` 才能看到该文件。
解决方法很简单,将原来的文件备份一下,执行下面的指令:

FLUSH SLOW LOGS;

备注:MySQL 5.5开始才支持 BINARY/ENGINE/ERROR/GENERAL/RELAY/SLOW 等关键字,之前的版本只能刷新全部日志。

3、确认数据表状态

  • 如果是MyISAM引擎

默认配置下,MyISAM引擎最大可支持256TB(myisam_data_pointer_size = 6,256^6 = 256TB),除非操作系统层有限制。
在MySQL5.0中,MyISAM引擎行记录默认是动态长度,单表最大可达256TB,MyISAM行指针(myisam_data_pointer_size)长度为6字节。
在这之前,MyISAM行指针默认长度为4字节,只支持4GB的数据。改行指针最大值可设为8字节。
在行指针设置较小不够用的时候,为提高MyISAM表最大容量,可以修改表定义设定MAX_ROWS的值:

ALTER TABLE `xx` ENGINE=MyISAM MAX_ROWS=nn

备注:表定义中,AVG_ROW_LENGTH 属性定义的是 BLOB/TEXT 字段类型的最大长度。

  • 如果是InnoDB引擎

ibdata*共享表空间最后一个文件没有设置成自增长,或者超过32位系统的单文件大小限制。
解决方法:
1、ibdata*的最后一个文件(非最后一个文件无法设置为自动增长)设置成自动增长;
2、检查操作系统,迁移到64位操作系统下;
3、转成独立表空间;
4、删除历史数据,重整表空间;

  • 如果是MEMORY引擎

1、适当提高max_heap_table_size设置(注意该值是会话级别,不要设置过大,例如1GB,一般不建议超过256MB);
2、执行ALTER TABLE t_mem ENGINE=MEMORY; 重整表空间,否则无法写入新数据
3、删除部分历史数据或者直接清空,重整表空间;
4、设置 big_tables = 1,将所有临时表存储在磁盘,而非内存中,缺点是如果某个SQL执行时需要用到临时表,则性能会差很多;

顺便说下,如果数据表有一列自增INT做主键,但是该ID值达到了INT最大值的话,MyISAM、MEMORY、InnoDB三种引擎的告警信息是不一样的。
InnoDB引擎的告警信息类似这样:
ERROR 1467 (HY000): Failed to read auto-increment value from storage engine

而MyISAM和MEMORY引擎则都是这样:
ERROR 1062 (23000): Duplicate entry ‘4294967295’ for key ‘PRIMARY’

参考

MySQL手册:B.5.2.12 The table is full

[MySQL FAQ]系列 — 如何安全地关闭MySQL实例

本文分析了mysqld进程关闭的过程,以及如何安全、缓和地关闭MySQL实例,对这个过程不甚清楚的同学可以参考下。

关闭过程:

  • 1、发起shutdown,发出  SIGTERM信号
  • 2、有必要的话,新建一个关闭线程(shutdown thread)

如果是客户端发起的关闭,则会新建一个专用的关闭线程

如果是直接收到 SIGTERM 信号进行关闭的话,专门负责信号处理的线程就会负责关闭工作,或者新建一个独立的线程负责这个事

当无法创建独立的关闭线程时(例如内存不足),MySQL Server会发出类似下面的告警信息:

Error: Can’t create thread to kill server

  • 3、MySQL Server不再响应新的连接请求

关闭TCP/IP网络监听,关闭Unix Socket等渠道

  • 4、逐渐关闭当前的连接、事务

空闲连接,将立刻被终止;

当前还有事务、SQL活动的连接,会将其标识为 killed,并定期检查其状态,以便下次检查时将其关闭;(参考 KILL 语法)

当前有活跃事务的,该事物会被回滚,如果该事务中还修改了非事务表,则已经修改的数据无法回滚,可能只会完成部分变更;

如果是Master/Slave复制场景里的Master,则对复制线程的处理过程和普通线程也是一样的;

如果是Master/Slave复制场景里的Slave,则会依次关闭IO、SQL线程,如果这2个线程当前是活跃的,则也会加上 killed 标识,然后再关闭;

Slave服务器上,SQL线程是允许直接停止当前的SQL操作的(为了避免复制问题),然后再关闭该线程;

在MySQl 5.0.80及以前的版本里,如果SQL线程当时正好执行一个事务到中间,该事务会回滚;从5.0.81开始,则会等待所有的操作结束,除非用户发起KILL操作。

当Slave的SQL线程对非事务表执行操作时被强制 KILL了,可能会导致Master、Slave数据不一致;

  • 5、MySQL Server进程关闭所有线程,关闭所有存储引擎;

刷新所有表cache,关闭所有打开的表;

每个存储引擎各自负责相关的关闭操作,例如MyISAM会刷新所有等待写入的操作;InnoDB会将buffer pool刷新到磁盘中(从MySQL 5.0.5开始,如果innodb_fast_shutdown不设置为 2 的话),把当前的LSN记录到表空间中,然后关闭所有的内部线程。

  • 6、MySQL Server进程退出

关于KILL指令

从5.0开始,KILL 支持指定  CONNECTION | QUERY两种可选项:

  • KILL CONNECTION和原来的一样,停止回滚事务,关闭该线程连接,释放相关资源;
  • KILL QUERY则只停止线程当前提交执行的操作,其他的保持不变;

提交KILL操作后,该线程上会设置一个特殊的 kill标记位。通常需要一段时间后才能真正关闭线程,因为kill标记位只在特定的情况下才检查:

  • 1、执行SELECT查询时,在ORDER BY或GROUP BY循环中,每次读完一些行记录块后会检查 kill标记位,如果发现存在,该语句会终止;
  • 2、执行ALTER TABLE时,在从原始表中每读取一些行记录块后会检查 kill 标记位,如果发现存在,该语句会终止,删除临时表;
  • 3、执行UPDATE和DELETE时,每读取一些行记录块并且更新或删除后会检查 kill 标记位,如果发现存在,该语句会终止,回滚事务,若是在非事务表上的操作,则已发生变更的数据不会回滚;
  • 4、GET_LOCK() 函数返回NULL;
  • 5、INSERT DELAY线程会迅速内存中的新增记录,然后终止;
  • 6、如果当前线程持有表级锁,则会释放,并终止;
  • 7、如果线程的写操作调用在等待释放磁盘空间,则会直接抛出“磁盘空间满”错误,然后终止;
  • 8、当MyISAM表在执行REPAIR TABLE 或 OPTIMIZE TABLE 时被 KILL的话,会导致该表损坏不可用,指导再次修复完成。

安全关闭MySQL几点建议

想要安全关闭 mysqld 服务进程,建议按照下面的步骤来进行:

  • 0、用具有SUPER、ALL等最高权限的账号连接MySQL,最好是用 unix socket 方式连接;
  • 1、在5.0及以上版本,设置innodb_fast_shutdown = 1,允许快速关闭InnoDB(不进行full purge、insert buffer merge),如果是为了升级或者降级MySQL版本,则不要设置;
  • 2、设置innodb_max_dirty_pages_pct = 0,让InnoDB把所有脏页都刷新到磁盘中去;
  • 3、设置max_connections和max_user_connections为1,也就最后除了自己当前的连接外,不允许再有新的连接创建;
  • 4、关闭所有不活跃的线程,也就是状态为Sleep  且 Time 大于 1 的线程ID;
  • 5、执行 SHOW PROCESSLIST  确认是否还有活跃的线程,尤其是会产生表锁的线程,例如有大数据集的SELECT,或者大范围的UPDATE,或者执行DDL,都是要特别谨慎的;
  • 6、执行 SHOW ENGINE INNODB STATUS 确认History list length的值较低(一般要低于500),也就是未PURGE的事务很少,并且确认Log sequence number、Log flushed up to、Last checkpoint at三个状态的值一样,也就是所有的LSN都已经做过检查点了;
  • 7、然后执行FLUSH LOCKAL TABLES 操作,刷新所有 table cache,关闭已打开的表(LOCAL的作用是该操作不记录BINLOG);
  • 8、如果是SLAVE服务器,最好是先关闭 IO_THREAD,等待所有RELAY LOG都应用完后,再关闭 SQL_THREAD,避免 SQL_THREAD 在执行大事务被终止,耐心待其全部应用完毕,如果非要强制关闭的话,最好也等待大事务结束后再关闭SQL_THREAD;
  • 9、最后再执行 mysqladmin shutdown。
  • 10、紧急情况下,可以设置innodb_fast_shutdown = 1,然后直接执行 mysqladmin shutdown 即可,甚至直接在操作系统层调用 kill 或者 kill -9 杀掉 mysqld 进程(在innodb_flush_log_at_trx_commit = 0 的时候可能会丢失部分事务),不过mysqld进程再次启动时,会进行CRASH RECOVERY工作,需要有所权衡。

啰嗦那么多,其实正常情况下执行 mysqladmin shutdown 就够了,如果发生阻塞,再参考上面的内容进行分析和解决吧,哈哈:)

MySQL 5.6 查询优化器新特性的“BUG”

最近碰到一个慢SQL问题,解决过程有点小曲折,和大家分享下。 SQL本身不复杂,表结构、索引也比较简单,不过个别字段存在于多个索引中。

CREATE TABLE `pre_forum_post` (
  `pid` int(10) unsigned NOT NULL,
  `fid` mediumint(8) unsigned NOT NULL DEFAULT '0',
  `tid` mediumint(8) unsigned NOT NULL DEFAULT '0',
  `first` tinyint(1) NOT NULL DEFAULT '0',
  `author` varchar(40) NOT NULL DEFAULT '',
  `authorid` int(10) unsigned NOT NULL DEFAULT '0',
  `subject` varchar(80) NOT NULL DEFAULT '',
  `dateline` int(10) unsigned NOT NULL DEFAULT '0',
  `message` mediumtext NOT NULL,
  `useip` varchar(15) NOT NULL DEFAULT '',
  `invisible` tinyint(1) NOT NULL DEFAULT '0',
  `anonymous` tinyint(1) NOT NULL DEFAULT '0',
  `usesig` tinyint(1) NOT NULL DEFAULT '0',
  `htmlon` tinyint(1) NOT NULL DEFAULT '0',
  `bbcodeoff` tinyint(1) NOT NULL DEFAULT '0',
  `smileyoff` tinyint(1) NOT NULL DEFAULT '0',
  `parseurloff` tinyint(1) NOT NULL DEFAULT '0',
  `attachment` tinyint(1) NOT NULL DEFAULT '0',
  `rate` smallint(6) NOT NULL DEFAULT '0',
  `ratetimes` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `status` int(10) NOT NULL DEFAULT '0',
  `tags` varchar(255) NOT NULL DEFAULT '0',
  `comment` tinyint(1) NOT NULL DEFAULT '0',
  `replycredit` int(10) NOT NULL DEFAULT '0',
  `position` int(8) unsigned NOT NULL AUTO_INCREMENT,
  PRIMARY KEY (`tid`,`position`),
  UNIQUE KEY `pid` (`pid`),
  KEY `fid` (`fid`),
  KEY `displayorder` (`tid`,`invisible`,`dateline`),
  KEY `first` (`tid`,`first`),
  KEY `new_auth` (`authorid`,`invisible`,`tid`),
  KEY `idx_dt` (`dateline`)
) ENGINE=MyISAM DEFAULT CHARSET=utf8;


"root@localhost Fri Aug  1 11:59:56 2014 11:59:56 [test]>show table status like 'pre_forum_post'\G
*************************** 1. row ***************************
           Name: pre_forum_post
         Engine: MyISAM
        Version: 10
     Row_format: Dynamic
           Rows: 23483977
 Avg_row_length: 203
    Data_length: 4782024708
Max_data_length: 281474976710655
   Index_length: 2466093056
      Data_free: 0
 Auto_increment: 1
    Create_time: 2014-08-01 11:00:56
    Update_time: 2014-08-01 11:08:49
     Check_time: 2014-08-01 11:12:23
      Collation: utf8_general_ci
       Checksum: NULL
 Create_options: 
        Comment: 


mysql> show index from pre_forum_post;
+----------------+------------+--------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| Table          | Non_unique | Key_name     | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
+----------------+------------+--------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| pre_forum_post |          0 | PRIMARY      |            1 | tid         | A         |      838713 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          0 | PRIMARY      |            2 | position    | A         |    23483977 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          0 | pid          |            1 | pid         | A         |    23483977 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | fid          |            1 | fid         | A         |        1470 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | displayorder |            1 | tid         | A         |      838713 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | displayorder |            2 | invisible   | A         |      869776 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | displayorder |            3 | dateline    | A         |    23483977 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | first        |            1 | tid         | A         |      838713 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | first        |            2 | first       | A         |     1174198 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | new_auth     |            1 | authorid    | A         |     1806459 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | new_auth     |            2 | invisible   | A         |     1956998 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | new_auth     |            3 | tid         | A         |    11741988 |     NULL | NULL   |      | BTREE      |         |               |
| pre_forum_post |          1 | idx_dt       |            1 | dateline    | A         |    23483977 |     NULL | NULL   |      | BTREE      |         |               |
+----------------+------------+--------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+

我们来看下这个SQL的执行计划:

mysql> explain select * from pre_forum_post where tid=7932612 and `invisible` in('0','-2') order by dateline  limit 15\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: pre_forum_post
         type: index
possible_keys: PRIMARY,displayorder,first
          key: idx_dt
      key_len: 4
          ref: NULL
         rows: 14042
        Extra: Using where

可以看到执行计划比较奇怪,从几个可选的索引中,最终选择了 idx_dt,结果悲剧了,这个SQL执行耗时很长:

mysql> select * from pre_forum_post where tid=7932612 and `invisible` in('0','-2') order by dateline  limit 15;
15 rows in set (26.78 sec)

看下MySQL的会话状态值:Handler_read_next

| Handler_read_next          | 17274153 |

1700多万数据中选取15条记录,结果可想而知,非常慢。 我们强制指定比较靠谱的索引再看下:

mysql> explain select * from pre_forum_post force index(displayorder) where tid=7932612 and `invisible` in('0','-2') order by dateline  limit 15\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: pre_forum_post
         type: range
possible_keys: displayorder
          key: displayorder
      key_len: 4
          ref: NULL
         rows: 46131
        Extra: Using index condition; Using filesort

看下实际执行的耗时:

mysql> select * from pre_forum_post force index(displayorder) where tid=7932612 and `invisible` in('0','-2') order by dateline  limit 15;
15 rows in set (0.08 sec)

尼玛,怎么可以这么快,查询优化器未免太坑爹了吧。 再看下MySQL的会话状态值:Handler_read_next

| Handler_read_next          | 31188 |

和不强制索引的情况相比,差了553倍! 所幸,5.6以上除了EXPLAIN外,还支持OPTIMIZER_TRACE,我们来观察下两种执行计划的区别,发现不强制指定索引时的执行计划有诈,会在最后判断到 ORDER BY 子句时,修改执行计划:

          {\
            "reconsidering_access_paths_for_index_ordering": {\
              "clause": "ORDER BY",\
              "index_order_summary": {\
                "table": "`pre_forum_post`",\
                "index_provides_order": true,\
                "order_direction": "asc",\
                "index": "idx_dt",\
                "plan_changed": true,\
                "access_type": "index_scan"\
              } /* index_order_summary */\
            } /* reconsidering_access_paths_for_index_ordering */\

而在前面analyzing_range_alternativesconsidered_execution_plans阶段,都认为其他几个索引也是可选择的,直到这里才给强X了,你Y 看起来像是MySQL 5.6查询优化器的bug了,GOOGLE了一下,还真发有人已经反馈过类似的问题: MySQL bug 70245: incorrect costing for range scan causes optimizer to choose incorrect index

看完才发现,其实不是神马BUG,而是原来从5.6开始,增加了一个选项叫eq_range_index_dive_limit 的高级货,这货大概的用途是: 在较多等值查询(例如多值的IN查询)情景中,预估可能会扫描的记录数,从而选择相对更合适的索引,避免所谓的index dive问题。

当面临下面两种选择时:

1、索引代价较高,但结果较为精确;
2、索引代价较低,但结果可能不够精确;

简单说,选项 eq_range_index_dive_limit 的值设定了 IN列表中的条件个数上线,超过设定值时,会将执行计划分支从 1 变成 2

该值默认为10,但社区众多人反馈较低了,因此在5.7版本后,将默认值调整为200了。

不过,今天我们这里的案例却是想反的,因为优化器选择了看似代价低但精确的索引,实际却选择了更低效的索引。 因此,我们需要将其阈值调低,尝试设置 eq_range_index_dive_limit = 2 后(上面的例子中,IN条件里有2个值),再看下新的查询计划:

mysql> set eq_range_index_dive_limit = 2;

mysql> explain select * from pre_forum_post where tid=7932612 and `invisible` in('0','-2') order by dateline  limit 15\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: pre_forum_post
         type: range
possible_keys: PRIMARY,displayorder,first
          key: displayorder
      key_len: 4
          ref: NULL
         rows: 54
        Extra: Using index condition; Using filesort

卧槽,预估扫描记录数又降了557倍,相比最开始降了接近32万倍! 在这个案例中,虽然通过修改选项 eq_range_index_dive_limit 的阈值可以达到优化效果,但事实上更靠谱的做法是:直接删除 idx_dt 索引。 是的,没错,删除这个垃圾重复索引,因为实际上这个索引的用处不大,够坑爹吧~~

参考资料:
http://blog.163.com/li_hx/blog/static/18399141320147521735442/
http://mysqlserverteam.com/you-asked-for-it-new-default-for-eq_range_index_dive_limit/ https://www.facebook.com/note.php?note_id=10151533648715933
http://bugs.mysql.com/bug.php?id=70586
http://bugs.mysql.com/bug.php?id=67980
http://bugs.mysql.com/bug.php?id=70331