[MySQL FAQ]系列 — MySQL无法启动例一

MySQL FAQ
插图来自网络并作简单加工,如果觉得不当还请及时告知 :)

【场景】某个打算用于slave新搭建的实例启动报错,启动过程中报告InnoDB数据页发生损坏。错误日志像下面这样:

150330 15:37:44 mysqld_safe Starting mysqld daemon with databases from /data/mysql/mytest_3306
2015-03-30 15:37:45 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use –explicit_defaults_for_timestamp server option (see documentation for more details).
2015-03-30 15:37:45 5884 [Warning] Using unique option prefix myisam_recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
2015-03-30 15:37:45 5884 [Note] Plugin ‘FEDERATED’ is disabled.
2015-03-30 15:37:45 5884 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-03-30 15:37:45 5884 [Note] InnoDB: The InnoDB memory heap is disabled
2015-03-30 15:37:45 5884 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-03-30 15:37:45 5884 [Note] InnoDB: Memory barrier is not used
2015-03-30 15:37:45 5884 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-03-30 15:37:45 5884 [Note] InnoDB: Using Linux native AIO
2015-03-30 15:37:45 5884 [Note] InnoDB: Using CPU crc32 instructions
2015-03-30 15:37:45 5884 [Note] InnoDB: Initializing buffer pool, size = 2.0G
2015-03-30 15:37:46 5884 [Note] InnoDB: Completed initialization of buffer pool
2015-03-30 15:37:47 5884 [Note] InnoDB: Highest supported file format is Barr.
2015-03-30 15:37:48 5884 [Warning] InnoDB: Resizing redo log from 3*32768 to 2*16384 pages, LSN=2740249189
2015-03-30 15:37:48 5884 [Warning] InnoDB: Starting to delete and rewrite log files.
2015-03-30 15:37:48 5884 [Note] InnoDB: Setting log file ./ib_logfile101 size to 256 MB
InnoDB: Progress in MB: 100 200
2015-03-30 15:37:49 5884 [Note] InnoDB: Setting log file ./ib_logfile1 size to 256 MB
InnoDB: Progress in MB: 100 200
2015-03-30 15:37:50 5884 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2015-03-30 15:37:50 5884 [Warning] InnoDB: New log files created, LSN=2740249612
2015-03-30 15:37:50 5884 [Note] InnoDB: 128 rollback segment(s) are active.
2015-03-30 15:37:50 5884 [Note] InnoDB: Waiting for purge to start
2015-03-30 15:37:50 5884 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.21-rel69.0 started; log sequence number 2740249189
2015-03-30 15:37:50 5884 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: ab27d3e4-d6af-11e4-8020-c81f66eeffa6.
150330 15:36:33 mysqld_safe Starting mysqld daemon with databases from /data/mysql/mytest_3306
2015-03-30 15:37:50 5884 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: ab27d3e4-d6af-11e4-8020-c81f66eeffa6.
2015-03-30 15:37:50 5884 [Note] RSA private key file not found: /data/mysql/mytest_3306//private_key.pem. Some authentication plugins will not work.
2015-03-30 15:37:50 5884 [Note] RSA public key file not found: /data/mysql/mytest_3306//public_key.pem. Some authentication plugins will not work.
2015-03-30 15:37:50 5884 [Note] Server hostname (bind-address): ’10.x.x.x’; port: 3306
2015-03-30 15:37:50 5884 [Note] – ’10.x.x.x’ resolves to ’10.x.x.x’;
2015-03-30 15:37:50 5884 [Note] Server socket created on IP: ’10.x.x.x’.
2015-03-30 15:37:50 7f4ce4d68700 InnoDB: Error: page 32769 log sequence number 2740254202
InnoDB: is in the future! Current system log sequence number 2740249622.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2015-03-30 15:37:50 5884 [Note] Event Scheduler: Loaded 0 events
2015-03-30 15:37:50 5884 [Note] /opt/Percona-Server-5.6.21-rel69.0-675.Linux.x86_64/bin/mysqld: ready for connections.
Version: ‘5.6.21-69.0-log’ socket: ‘/data/mysql/mytest_3306/mysql.sock’ port: 3306 Percona Server (GPL), Release 69.0, Revision 675
2015-03-30 15:37:58 7f4ce4d68700 InnoDB: Error: page 6327 log sequence number 2740254445
InnoDB: is in the future! Current system log sequence number 2740251356.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.

【分析】正常情况下,新部署的实例是不太可能出现InnoDB数据页损坏的。经了解,这个实例是采用xtrabackup工具从master备份过来做恢复的。

细心的同学,通过观察上面的日志,应该能从中发现一些蛛丝马迹。有几个地方需要引起注意:

1、版本是Percona Server 5.6.21;
2、刚启动就把InnoDB的redo log给resize了;
3、刚启动就发现InnoDB的page LSN和redo log中的不匹配;

之所以提醒大家注意上面的三点,并且把版本信息放在了第一条,是因为从5.6版本开始,InnoDB如如果发现当前的redo log文件大小和预设配置的redo log大小不一致的话,就会自动将其删除重建

写到这里,相信聪明的你应该已经想到什么了吧,没错,导致这个启动报错的原因是:从master上xtrabackup备份出来的innodb redo log大小和本地配置参数不一致,被删除重建,结果事务恢复失败,提示数据也损坏错误信息

【解决】修改slave本地配置文件,把下面几个InnoDB配置选项都修改成和在master上的一样,再次执行恢复启动即可。

innodb_data_file_path
innodb_log_file_size
innodb_log_files_in_group
innodb_file_per_table

[MySQL FAQ]系列 — pt-table-checksum工具使用报错一例

Percona Tollkit
图片来自Percona官网

今天同事在用 percona toolkit 工具中的 pt-table-checksum 对主从数据库进行校验,提交命令后,一直提示下面的信息:

Pausing because Threads_running=0

看字面意思是在提示当前活跃线程数为0,但为什么不继续执行呢。这个提示信息有点含糊其辞,该工具是用Perl写的,因此直接打开看脚本跟踪一下,大概就明白怎么回事了,原来是这个工具有负载保护机制,避免运行时对线上数据库产生影响。

和这个机制相关的参数名是: –max-load,其类型是:Array,用法是一个或多个 variables = value 组成的判断条件,然后根据这个规则判断某些条件是否超标。例如,设定 –max-load=”Threads_running=25″,意思是当前活跃线程数如果超过25,就暂停 checksum 工作,直到活跃线程数低于 25。

因此,在我们这个案例中,想要强制让 table-checksum 继续工作的话,可以设定 –max-load 的值,例如:

pt-table-checksum --max-load="Threads_running=25" ...其他选项...

或者

pt-table-checksum --max-load="Threads_connected=25" ...其他选项...

 

前面的选项意思是判断活跃线程数不要超过25个,后面的选项意思是当前打开的线程数不要超过25个。

下面是 pt-table-checksum 帮助手册里的一段话:

–max-load
type: Array; default: Threads_running=25; group: Throttle

Examine SHOW GLOBAL STATUS after every chunk, and pause if any status variables are higher than the threshold. The option accepts a comma-sep-
arated list of MySQL status variables to check for a threshold. An optional “=MAX_VALUE” (or “:MAX_VALUE”) can follow each variable. If not
given, the tool determines a threshold by examining the current value and increasing it by 20%.

For example, if you want the tool to pause when Threads_connected gets too high, you can specify “Threads_connected”, and the tool will check
the current value when it starts working and add 20% to that value. If the current value is 100, then the tool will pause when Threads_con-
nected exceeds 120, and resume working when it is below 120 again. If you want to specify an explicit threshold, such as 110, you can use
either “Threads_connected:110” or “Threads_connected=110”.

The purpose of this option is to prevent the tool from adding too much load to the server. If the checksum queries are intrusive, or if they
cause lock waits, then other queries on the server will tend to block and queue. This will typically cause Threads_running to increase, and the
tool can detect that by running SHOW GLOBAL STATUS immediately after each checksum query finishes. If you specify a threshold for this vari-
able, then you can instruct the tool to wait until queries are running normally again. This will not prevent queueing, however; it will only
give the server a chance to recover from the queueing. If you notice queueing, it is best to decrease the chunk time.

[MySQL优化案例]系列 — slave延迟很大优化方法

mysql replication
备注:插图来自网络搜索,如果觉得不当还请及时告知 :)

一般而言,slave相对master延迟较大,其根本原因就是slave上的复制线程没办法真正做到并发。简单说,在master上是并发模式(以InnoDB引擎为主)完成事务提交的,而在slave上,复制线程只有一个sql thread用于binlog的apply,所以难怪slave在高并发时会远落后master。

ORACLE MySQL 5.6版本开始支持多线程复制,配置选项 slave_parallel_workers 即可实现在slave上多线程并发复制。不过,它只能支持一个实例下多个 database 间的并发复制,并不能真正做到多表并发复制。因此在较大并发负载时,slave还是没有办法及时追上master,需要想办法进行优化。

另一个重要原因是,传统的MySQL复制是异步(asynchronous)的,也就是说在master提交完后,才在slave上再应用一遍,并不是真正意义上的同步。哪怕是后来的Semi-sync Repication(半同步复制),也不是真同步,因为它只保证事务传送到slave,但没要求等到确认事务提交成功。既然是异步,那肯定多少会有延迟。因此,严格意义上讲,MySQL复制不能叫做MySQL同步(处女座的面试官有可能会在面试时把说成MySQL同步的一律刷掉哦)。

另外,不少人的观念里,slave相对没那么重要,因此就不会提供和master相同配置级别的服务器。有的甚至不但使用更差的服务器,而且还在上面跑多实例。

综合这两个主要原因,slave想要尽可能及时跟上master的进度,可以尝试采用以下几种方法:

  1. 采用MariaDB发行版,它实现了相对真正意义上的并行复制,其效果远比ORACLE MySQL好的很多。在我的场景中,采用MariaDB作为slave的实例,几乎总是能及时跟上master。如果不想用这个版本的话,那就老实等待官方5.7大版本发布吧;
    关于MariaDB的Parallel Replication具体请参考:Replication and Binary Log Server System Variables#slave_parallel_threads – MariaDB Knowledge Base
  2. 每个表都要显式指定主键,如果没有指定主键的话,会导致在row模式下,每次修改都要全表扫描,尤其是大表就非常可怕了,延迟会更严重,甚至导致整个slave库都被挂起,可参考案例:mysql主键的缺少导致备库hang
  3. 应用程序端多做些事,让MySQL端少做事,尤其是和IO相关的活动,例如:前端通过内存CACHE或者本地写队列等,合并多次读写为一次,甚至消除一些写请求;
  4. 进行合适的分库、分表策略,减小单库单表复制压力,避免由于单库单表的的压力导致整个实例的复制延迟;
  5. 其他提高IOPS性能的几种方法,根据效果优劣,我做了个简单排序:
    • 更换成SSD,或者PCIe SSD等IO设备,其IOPS能力的提升是普通15K SAS盘的数以百倍、万倍,甚至几十万倍计;
    • 加大物理内存,相应提高InnoDB Buffer Pool大小,让更多热数据放在内存中,降低发生物理IO的频率;
    • 调整文件系统为 XFS 或 ReiserFS,相比ext3可以极大程度提高IOPS能力。在高IOPS压力下,相比ext4有更稳健的IOPS表现(有人认为 XFS 在特别的场景下会有很大的问题,但我们除了剩余磁盘空间少于10%时引发丢数据外,其他的尚未遇到);
    • 调整RAID级别为raid 1+0,它相比raid1、raid5等更能提高IOPS性能。如果已经全部是SSD设备了,可以2块盘做成RAID 1,或者多快盘做成RAID 5(并且可以设置全局热备盘,提高阵列容错性),甚至有些土豪用户直接将多块SSD盘组成RAID 50;
    • 调整RAID的写cache策略为WB或FORCE WB,详情请参考:常用PC服务器阵列卡、硬盘健康监控 以及 PC服务器阵列卡管理简易手册
    • 调整内核的io scheduler,优先使用deadline,如果是SSD,则可以使用noop策略,相比默认的cfq,个别情况下对IOPS的性能提升至少是数倍的。

其他更多方法,欢迎大家帮忙补充 :)

[MySQL优化案例]系列 — discuz!热帖翻页优化

discuz-logo
备注:插图来自discuz!官方LOGO,如果觉得不当还请及时告知 :)

写在前面:discuz!作为首屈一指的社区系统,为广大站长提供了一站式网站解决方案,而且是开源的(虽然部分代码是加密的),它为这个垂直领域的行业发展作出了巨大贡献。尽管如此,discuz!系统源码中,还是或多或少有些坑。其中最著名的就是默认采用MyISAM引擎,以及基于MyISAM引擎的抢楼功能session表采用memory引擎等,可以参考后面几篇历史文章。本次我们要说说discuz!在应对热们帖子翻页逻辑功能中的另一个问题。

在我们的环境中,使用的是 MySQL-5.6.6 版本。

在查看帖子并翻页过程中,会产生类似下面这样的SQL:

mysql> desc SELECT * FROM pre_forum_post WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline DESC LIMIT 15\G
 *************************** 1. row ***************************
 id: 1
 select_type: SIMPLE
 table: pre_forum_post
 type: ref
 possible_keys: tid,displayorder,first
 key: displayorder
 key_len: 3
 ref: const
 rows: 593371
 Extra: Using index condition; Using where; Using filesort

这个SQL执行的代价是:

-- 根据索引访问行记录次数,总体而言算是比较好的状态
| Handler_read_key           | 16     |

-- 根据索引顺序访问下一行记录的次数,通常是因为根据索引的范围扫描,或者全索引扫描,总体而言也算是比较好的状态
| Handler_read_next          | 329881 |

-- 按照一定顺序读取行记录的总次数。如果需要对结果进行排序,该值通常会比较大。当发生全表扫描或者多表join无法使用索引时,该值也会比较大
| Handler_read_rnd           | 15     |

而当遇到热帖需要往后翻很多页时,例如:

mysql> desc SELECT * FROM pre_forum_post WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline  LIMIT 129860, 15\G
 *************************** 1. row ***************************
 id: 1
 select_type: SIMPLE
 table: pre_forum_post
 type: ref
 possible_keys: displayorder
 key: displayorder
 key_len: 3
 ref: const
 rows: 593371
 Extra: Using where; Using filesort

这个SQL执行的代价则变成了(可以看到Handler_read_key、Handler_read_rnd大了很多):

| Handler_read_key           | 129876 | -- 因为前面需要跳过很多行记录
| Handler_read_next          | 329881 | -- 同上
| Handler_read_rnd           | 129875 | -- 因为需要先对很大一个结果集进行排序

可见,遇到热帖时,这个SQL的代价会非常高。如果该热帖被大量的访问历史回复,或者被搜素引擎一直反复请求并且历史回复页时,很容易把数据库服务器直接压垮。

小结:这个SQL不能利用 `displayorder` 索引排序的原因是,索引的第二个列 `invisible` 采用范围查询(RANGE),导致没办法继续利用联合索引完成对 `dateline` 字段的排序需求(而如果是 WHERE tid =? AND invisible IN(?, ?) AND dateline =? 这种情况下是完全可以用到整个联合索引的,注意下二者的区别)。

知道了这个原因,相应的优化解决办法也就清晰了:
创建一个新的索引 idx_tid_dateline,它只包括 tid、dateline 两个列即可(根据其他索引的统计信息,item_type 和 item_id 的基数太低,所以没包含在联合索引中。当然了,也可以考虑一并加上)。

我们再来看下采用新的索引后的执行计划:

mysql> desc SELECT * FROM pre_forum_post WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline  LIMIT 15\G
 *************************** 1. row ***************************
 id: 1
 select_type: SIMPLE
 table: pre_forum_post
 type: ref
 possible_keys: tid,displayorder,first,idx_tid_dateline
 key: idx_tid_dateline
 key_len: 3
 ref: const
 rows: 703892
 Extra: Using where

可以看到,之前存在的 Using filesort 消失了,可以通过索引直接完成排序了。

不过,如果该热帖翻到较旧的历史回复时,相应的SQL还是不能使用新的索引:

mysql> desc SELECT * FROM pre_forum_post WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline LIMIT 129860,15\G
 *************************** 1. row ***************************
 id: 1
 select_type: SIMPLE
 table: pre_forum_post
 type: ref
 possible_keys: tid,displayorder,first,idx_tid_dateline
 key: displayorder
 key_len: 3
 ref: const
 rows: 593371
 Extra: Using where; Using filesort

对比下如果建议优化器使用新索引的话,其执行计划是怎样的:

mysql> desc SELECT * FROM pre_forum_post use index(idx_tid_dateline) WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline  LIMIT 129860,15\G
 *************************** 1. row ***************************
 id: 1
 select_type: SIMPLE
 table: pre_forum_post
 type: ref
 possible_keys: idx_tid_dateline
 key: idx_tid_dateline
 key_len: 3
 ref: const
 rows: 703892
 Extra: Using where

可以看到,因为查询优化器认为后者需要扫描的行数远比前者多了11万多,因此认为前者效率更高。

事实上,在这个例子里,排序的代价更高,因此我们要优先消除排序,所以应该强制使用新的索引,也就是采用后面的执行计划,在相应的程序中指定索引。

最后,我们来看下热帖翻到很老的历史回复时,两个执行计划分别的profiling统计信息对比:

1、采用旧索引(displayorder):

mysql> SELECT * FROM pre_forum_post WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline LIMIT 129860,15;

​#查看profiling结果
 | starting             | 0.020203 |
 | checking permissions | 0.000026 |
 | Opening tables       | 0.000036 |
 | init                 | 0.000099 |
 | System lock          | 0.000092 |
 | optimizing           | 0.000038 |
 | statistics           | 0.000123 |
 | preparing            | 0.000043 |
 | Sorting result       | 0.000025 |
 | executing            | 0.000023 |
 | Sending data         | 0.000045 |
 | Creating sort index  | 0.941434 |
 | end                  | 0.000077 |
 | query end            | 0.000044 |
 | closing tables       | 0.000038 |
 | freeing items        | 0.000056 |
 | cleaning up          | 0.000040 |

2、如果是采用新索引(idx_tid_dateline):

mysql> SELECT * FROM pre_forum_post use index(idx_tid_dateline) WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY dateline LIMIT 129860,15;

​#对比查看profiling结果
 | starting             | 0.000151 |
 | checking permissions | 0.000033 |
 | Opening tables       | 0.000040 |
 | init                 | 0.000105 |
 | System lock          | 0.000044 |
 | optimizing           | 0.000038 |
 | statistics           | 0.000188 |
 | preparing            | 0.000044 |
 | Sorting result       | 0.000024 |
 | executing            | 0.000023 |
 | Sending data         | 0.917035 |
 | end                  | 0.000074 |
 | query end            | 0.000030 |
 | closing tables       | 0.000036 |
 | freeing items        | 0.000049 |
 | cleaning up          | 0.000032 |

可以看到,效率有了一定提高,不过不是很明显,因为确实需要扫描的数据量更大,所以 Sending data 阶段耗时更多。

这时候,我们可以再参考之前的一个优化方案:[MySQL优化案例]系列 — 分页优化

然后可以将这个SQL改写成下面这样:

mysql> EXPLAIN SELECT * FROM pre_forum_post t1 INNER JOIN (
 SELECT id FROM pre_forum_post use index(idx_tid_dateline) WHERE
 tid=8201301 AND `invisible` IN('0','-2') ORDER BY
 dateline  LIMIT 129860,15) t2
 USING (id)\G
 *************************** 1. row ***************************
 id: 1
 select_type: PRIMARY
 table: 
 type: ALL
 possible_keys: NULL
 key: NULL
 key_len: NULL
 ref: NULL
 rows: 129875
 Extra: NULL
 *************************** 2. row ***************************
 id: 1
 select_type: PRIMARY
 table: t1
 type: eq_ref
 possible_keys: PRIMARY
 key: PRIMARY
 key_len: 4
 ref: t2.id
 rows: 1
 Extra: NULL
 *************************** 3. row ***************************
 id: 2
 select_type: DERIVED
 table: pre_forum_post
 type: ref
 possible_keys: idx_tid_dateline
 key: idx_tid_dateline
 key_len: 3
 ref: const
 rows: 703892
 Extra: Using where

再看下这个SQL的 profiling 统计信息:

| starting             | 0.000209 |
| checking permissions | 0.000026 |
| checking permissions | 0.000026 |
| Opening tables       | 0.000101 |
| init                 | 0.000062 |
| System lock          | 0.000049 |
| optimizing           | 0.000025 |
| optimizing           | 0.000037 |
| statistics           | 0.000106 |
| preparing            | 0.000059 |
| Sorting result       | 0.000039 |
| statistics           | 0.000048 |
| preparing            | 0.000032 |
| executing            | 0.000036 |
| Sending data         | 0.000045 |
| executing            | 0.000023 |
| Sending data         | 0.225356 |
| end                  | 0.000067 |
| query end            | 0.000028 |
| closing tables       | 0.000023 |
| removing tmp table   | 0.000029 |
| closing tables       | 0.000044 |
| freeing items        | 0.000048 |
| cleaning up          | 0.000037 |

可以看到,效率提升了1倍以上,还是挺不错的。

最后说明下,这个问题只会在热帖翻页时才会出现,一般只有1,2页回复的帖子如果还采用原来的执行计划,也没什么问题。

因此,建议discuz!官方修改或增加下新索引,并且在代码中判断是否热帖翻页,是的话,就强制使用新的索引,以避免性能问题。

扩展阅读:

1、MySQL优化 之 Discuz论坛优化
2、MySQL优化 之 Discuz论坛优化 — 续
3、MySQL优化 之 Discuz论坛MySQL通用优化

最后稍微吐槽一下:最近几天遇到了几起关于MySQL查询优化器的BUG,挺让人摸不着头脑的 :(