转载

关于热点数据导出与加载的影响，多的是你不知道的事

导读

想必数据库的同行们都知道，热点数据导出导入的动作，使得数据库重启之后，不需要再耗费大量的时间来预热，使得因为热点数据的原因导致数据库性能波动的时间大大减少，那么执行热点数据的导出与导入操作时究竟对数据库的性能有没有影响呢？如果你的服务器拥有超大内存，而且设置了一个对应内存一定比例的超大buffer pool，是否在纠结需不需要设置热点数据在重启时自动导出导入呢？下面一起看演示过程，答案就在其中。

背景

sysbench造数200个500W数据量的表，占用磁盘空间275G
服务器配置
CPU：72 vcpus
内存：256G
磁盘：1.5T SSD RAID10
数据库版本：5.6.34
数据库参数：innodb_buffer_pool_size=160G
测试目的：测试在innodb_buffer_pool_size设置的buffer poo size占满时，导出导入ib_buffer_pool文件需要多长时间

手动执行导出ib_buffer_pool

sysbench 32线程oltp持续加压
先查看一下buffer pool中当前有多少的数据量，是否达到或接近160G buffer大小，如果数据量已接近160G,则继续往下（注：Innodb_buffer_pool_pages_data为当前buffer pool中包含数据的页数）

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:11:51]>show status like '%Innodb_buffer_pool_pages_data%';

+-------------------------------+----------+

| Variable_name | Value |

+-------------------------------+----------+

| Innodb_buffer_pool_pages_data | 10319938 |

+-------------------------------+----------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:12:02]>select 10319938*16/1024/1024;

+-----------------------+

| 10319938*16/1024/1024 |

+-----------------------+

| 157.46975708 |

+-----------------------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:12:17]>

为了对比后续有热点数据和没有热点数据导入导出的差别，先执行一次不导出导入热点数据的数据库重启，并记录关闭和启动mysqld的时间，先在innodb_buffer_pool_dump_at_shutdown=off的情况下，关闭MySQL，看看关闭时间需要多久。

# 设置 innodb_buffer_pool_dump_at_shutdown=off;

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 15:37:26]>set global innodb_buffer_pool_dump_at_shutdown=off;

Query OK, 0 rows affected (0.00 sec)

# 执行关闭mysqld，并记录time命令打印的执行时间

$time mysqladmin --defaults-file=/home/mysql/conf/my1.cnf -uroot -p'password' -hlocalhost -P3306 shutdown

170428 18:34:16 mysqld_safe mysqld from pid file /home/mysql/data/mysqldata1/sock/mysql.pid ended

[1]+ Done

......

real 1m4.020s

user 43m35.121s

sys 11m36.453s

# 执行启动mysqld，启动mysqld之前，先在my.cnf中配置参数innodb_buffer_pool_load_at_startup=OFF，再启动，看看需要多长时间，由于是挂后台，无法使用time命令查看，可以通过错误日志中的输出来大致判断启动时间需要多长

$time mysqld_safe --defaults-file=/home/mysql/conf/my1.cnf --user=mysql &

$cat /data2/mysqldata1/log/error.log

......

170428 17:18:09 mysqld_safe Starting mysqld daemon with databases from /home/mysql/data/mysqldata1/mydata

2017-04-28 17:18:09 0 [Warning] Using unique option prefix collation instead of collation-server is deprecated and will be removed in a future release. Please use the full name instead.

......

2017-04-28 17:18:28 16701 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000228' at position 58975338, /

relay log '/home/mysql/data/mysqldata1/relaylog/mysql-relay-bin.000462' position: 4

2017-04-28 17:18:28 16701 [Note] Event Scheduler: Loaded 0 events

2017-04-28 17:18:28 16701 [Note] /usr/local/mysql/bin/mysqld: ready for connections.

Version: '5.6.34-log' socket: '/home/mysql/data/mysqldata1/sock/mysql.sock' port: 3306 MySQL Community Server (GPL)

从以上错误日志的输出信息中可以看到，Starting mysqld 到打印socket地址时间的日志时间判断，在没有加载ib_buffer_pool时的启动时间为20S，且memlock参数未使用的情况下
现在，重新使用sysbench持续32线程oltp加压，以使得热点数据尽量占满buffer pool
然后登录数据库执行set global innodb_buffer_pool_dump_now=on;语句(注意：在执行这个步骤之前，你需要确保Innodb_buffer_pool_pages_data参数中的页数接近占用全部的buffer pool size，否则后续的测试没有意义)

# 设置innodb_buffer_pool_dump_now=on，表示立即导出热点数据页到ib_buffer_pool文件中

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 16:58:00]>set global innodb_buffer_pool_dump_now=on;

Query OK, 0 rows affected (0.00 sec)

# 使用Innodb_buffer_pool_dump_status状态变量查看一下dump完成时间（如果没有显示dump completed 则需要继续等待并持续查看这个变量，直到显示dump completed 为止）

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:00:15]>show status like 'Innodb_buffer_pool_dump_status';

+--------------------------------+--------------------------------------------------+

| Variable_name | Value |

+--------------------------------+--------------------------------------------------+

| Innodb_buffer_pool_dump_status | Buffer pool(s) dump completed at 170428 16:58:42 |

+--------------------------------+--------------------------------------------------+

1 row in set (0.00 sec)

现在，查看与MySQL ibdata1文件相同目录下的ib_buffer_pool文件。

$ ls -lh /data2/mysqldata1/innodb_ts/

total 2.1G

-rw-rw---- 1 mysql mysql 95M Apr 28 16:58 ib_buffer_pool

-rw-rw---- 1 mysql mysql 2.0G Apr 28 16:58 ibdata1

# 使用stat命令查看这个文件的秒级别access和Modify时间，在这个场景下，我们可以认为access代表了文件创建时间（文件句柄打开时间），Modify代表了文件最后变更的时间（数据写入完成时间）

#stat /data2/mysqldata1/innodb_ts/ib_buffer_pool

......

Access: 2017-04-28 16:58:39.078935848 +0800

Modify: 2017-04-28 16:58:42.568889476 +0800

Change: 2017-04-28 16:58:42.568889476 +0800

计算前面几个步骤获取的时间：通过数据库中的show status like 'Innodb_buffer_pool_dump_status';查询结果，完成时间是16:58:42，通过stat命令查询到这个文件最后修改时间是16:58:42，时间一致，文件access时间与Modify时间相差3秒，表示ib_buffer_pool文件在文件系统层3秒就完成了dump操作（从数据库层到文件系统层的写入），而对于数据库层，执行set global innodb_buffer_pool_dump_now=on;时是立即返回，说明该语句对于数据库语句执行来说，没有阻塞操作。

自动执行导出ib_buffer_pool

sysbench 32线程oltp持续加压
登录MySQL数据库中使用修改变量：set global innodb_buffer_pool_dump_at_shutdown=on; 修改innodb_buffer_pool_dump_at_shutdown=on之后，mysqld在关闭时会自动导出热点数据页到ib_buffer_pool文件中

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:12:17]>set global innodb_buffer_pool_dump_at_shutdown=on;

Query OK, 0 rows affected (0.00 sec)

注意：innodb_fast_shutdown的值不能为2，否则将无法执行导出（经源码分析，在该参数设置为2时，不会进入dump函数执行ib_buffer_pool的导出），如果为2请先修改为1即可：set global innodb_fast_shutdown=1;

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:14:20]>show variables like 'innodb_fast_shutdown';

+----------------------+-------+

| Variable_name | Value |

+----------------------+-------+

| innodb_fast_shutdown | 2 |

+----------------------+-------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:14:31]>set global innodb_fast_shutdown=1;

Query OK, 0 rows affected (0.00 sec)

在shell命令行中停止MySQL，留意停止时间需要多长。

$time mysqladmin --defaults-file=/home/mysql/conf/my1.cnf -uroot -p'password' -hlocalhost -P3306 shutdown

......

real 1m18.036s

user 0m0.005s

sys 0m0.004s

查看错误日志，可以发现Dump ib_buffer_pool文件中的相关日志输出，开始时间到结束时间对比，耗时为4S。

2017-04-28 17:16:21 7ed606745700 InnoDB: Dumping buffer pool(s) to /home/mysql/data/mysqldata1/innodb_ts/ib_buffer_pool

2017-04-28 17:16:25 7ed606745700 InnoDB: Buffer pool(s) dump completed at 170428 17:16:25

使用stat命令查看ib_buffer_pool文件的创建，修改时间，这里也可以看到，access和modify时间相差是4S，说明buffer pool在4S内完成了dump。

#ls -lh /data2/mysqldata1/innodb_ts/ib_buffer_pool

-rw-rw---- 1 mysql mysql 95M Apr 28 17:16 /data2/mysqldata1/innodb_ts/ib_buffer_pool

[root@master /root]

#stat /data2/mysqldata1/innodb_ts/ib_buffer_pool

......

Access: 2017-04-28 17:16:21.938770942 +0800

Modify: 2017-04-28 17:16:25.291726062 +0800

Change: 2017-04-28 17:16:25.291726062 +0800

手动执行导入ib_buffer_pool

在shell命令行中启动MySQL（注意这里配置文件中配置参数innodb_buffer_pool_load_at_startup设置为OFF，让mysqld启动时并不自动加载ib_buffer_pool文件）

170428 17:18:09 mysqld_safe Starting mysqld daemon with databases from /home/mysql/data/mysqldata1/mydata

2017-04-28 17:18:09 0 [Warning] Using unique option prefix collation instead of collation-server is deprecated and will be removed in a future release. Please use the full name instead.

......

2017-04-28 17:18:28 16701 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended./

Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.

2017-04-28 17:18:28 16701 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000228' at position 58975338,/

relay log '/home/mysql/data/mysqldata1/relaylog/mysql-relay-bin.000462' position: 4

2017-04-28 17:18:28 16701 [Note] Event Scheduler: Loaded 0 events

2017-04-28 17:18:28 16701 [Note] /usr/local/mysql/bin/mysqld: ready for connections.

Version: '5.6.34-log' socket: '/home/mysql/data/mysqldata1/sock/mysql.sock' port: 3306 MySQL Community Server (GPL)

从上面的错误日志信息中可以看到，从Starting mysqld 到打印socket地址时间的日志时间判断，在没有加载ib_buffer_pool时的启动时间为20S，且memlock参数未使用的情况下。现在，登录数据库手动load ib_buffer_pool文件。

# 执行load ib_buffer_pool文件

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 17:24:53]>set global innodb_buffer_pool_load_now=ON;

Query OK, 0 rows affected (0.00 sec)

# 查看load 完成时间，如果没有查看到load completed，则持续查看Innodb_buffer_pool_load_status状态变量

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:14:21]>show status like '%Innodb_buffer_pool_load_status';

+--------------------------------+--------------------------------------------------+

| Variable_name | Value |

+--------------------------------+--------------------------------------------------+

| Innodb_buffer_pool_load_status | Buffer pool(s) load completed at 170428 18:10:32 |

+--------------------------------+--------------------------------------------------+

1 row in set (0.00 sec)

# load ib_buffer_pool期间加载期间，可以使用iostat命令查看data磁盘载情况，如下

avg-cpu: %user %nice %system %iowait %steal %idle

0.06 0.00 0.15 1.15 0.00 98.64

Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util

sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

sdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

sdc 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

sdd 0.00 0.00 4410.00 0.00 141120.00 0.00 32.00 0.86 0.19 0.19 85.70

dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

dm-1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

dm-2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

dm-3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

md127 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

sde 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

sdf 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

查看错误日志中的Dump开始时间
2017-04-28 17:29:42 7fd07fff9700 InnoDB: Loading buffer pool(s) from /home/mysql/data/mysqldata1/innodb_ts/ib_buffer_pool
从上面一系列结果来看，日志中开始执行load的时间为17:29:42，而show status查看到的load ib_buffer_pool文件完成时间是18:10:32，耗时近40分钟，load期间磁盘读负载较高。但并不会阻塞对数据库的读写操作

自动执行导入ib_buffer_pool

本节中由于使用相同环境，"手动执行导入ib_buffer_pool"的演示步骤中已经执行过手动load ib_buffer_pool文件，这里需要先关闭mysqld并使用关闭时自动导入热点数据页参数innodb_buffer_pool_dump_at_shutdown=on，以及innodb_fast_shutdown=1
先设置set global innodb_buffer_pool_dump_at_shutdown=on;设置set global innodb_fast_shutdown=1;

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:46:50]>set global innodb_buffer_pool_dump_at_shutdown=on;

Query OK, 0 rows affected (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:46:58]>set global innodb_fast_shutdown=1;

Query OK, 0 rows affected (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:47:03]>

然后停止MySQL

$ mysqladmin --defaults-file=/home/mysql/conf/my1.cnf -uroot -p'password' -hlocalhost -P3306 shutdown

把innodb_buffer_pool_load_at_startup=ON参数加到配置文件中

cat /home/mysql/conf/my1.cnf

......

innodb_buffer_pool_load_at_startup=ON

启动MySQL

$ mysqld_safe --defaults-file=/home/mysql/conf/my1.cnf --user=mysql &

查看错误日志中，开始Load的日志输出如下（并没有看到Load ib_buffer_pool完成的日志）

2017-04-28 18:49:55 7fa0dfb83700 InnoDB: Loading buffer pool(s) from /home/mysql/data/mysqldata1/innodb_ts/ib_buffer_pool

登录数据库中查询Load状态（可以看到总共10319883个页，才导入119681个页，才1%……），没有发现 load completed 字符串。

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 18:50:22]>show status like '%Innodb_buffer_pool_load_status';

+--------------------------------+------------------------------+

| Variable_name | Value |

+--------------------------------+------------------------------+

| Innodb_buffer_pool_load_status | Loaded 119681/10319883 pages |

+--------------------------------+------------------------------+

1 row in set (0.00 sec)

在ib_buffer_pool文件执行载入过程中，可以尝试着访问一下数据库（可以正常访问，说明在Load ib_buffer_pool时并不会阻塞数据库访问，Load操作是在后台执行的）

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:51:52]>select * from sbtest1 order by id desc limit 1;

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| id | k | c | pad |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| 9999999 | 2507960 | 25744810828-37032637642-87919764377-76779868555-49415634722-86176448317-10050757951-88422706101-49861857465-53325889077 | 55855883347-94289537806-43993911203-91112041707-01357150366 |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

1 row in set (0.00 sec)

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:52:02]>update sbtest1 set k=k+1 where id=9999999;

Query OK, 1 row affected (0.00 sec)

Rows matched: 1 Changed: 1 Warnings: 0

[root@master:/root 5.6.34-log_Instance1 root@localhost:sbtest 18:54:05]>select * from sbtest1 order by id desc limit 1;

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| id | k | c | pad |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

| 9999999 | 2507961 | 25744810828-37032637642-87919764377-76779868555-49415634722-86176448317-10050757951-88422706101-49861857465-53325889077 | 55855883347-94289537806-43993911203-91112041707-01357150366 |

+---------+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+

1 row in set (0.00 sec)

这个时候，要做的就是继续等待，直到错误日志中打印Load完成的日志，或者Innodb_buffer_pool_load_status状态变量查看到 load completed 字符串。

# 查看错误日志

$ cat /data2/mysqldata1/log/error.log

......

2017-04-28 19:30:32 7fa0dfb83700 InnoDB: Buffer pool(s) load completed at 170428 19:30:32

# 数据库中的状态查询到Load完成

[root@master:/root 5.6.34-log_Instance1 root@localhost:test 19:46:10]>show status like '%Innodb_buffer_pool_load_status';

+--------------------------------+--------------------------------------------------+

| Variable_name | Value |

+--------------------------------+--------------------------------------------------+

| Innodb_buffer_pool_load_status | Buffer pool(s) load completed at 170428 19:30:32 |

+--------------------------------+--------------------------------------------------+

1 row in set (0.00 sec)

从上面的结果中可以看到，Load开始时间是18:49:55，结束时间是19:30:32，耗时近40分钟，与手动Load ib_buffer_pool文件耗时相当。

总结

从以上测试结果可以看到，ib_buffer_pool的Dump时间160G左右的数据量，1000W左右的数据页，只需要几秒时间，在Load的时候，需要大约40分钟，但是在Load ib_buffer_pool文件的时候并不会阻塞对数据库的访问，所以理论上在MySQL的起停中开启ib_buffer_pool的自动Dump和Load对数据库前台的操作影响极小，建议在配置文件中设置如下参数以实现该功能。

innodb_buffer_pool_dump_at_shutdown=ON

innodb_buffer_pool_load_at_startup=ON

innodb_fast_shutdown=1

补充

在MySQL 5.6.x版本中innodb_buffer_pool_dump_at_shutdown和innodb_buffer_pool_load_at_startup参数默认关闭，从MySQL 5.7.7及其之后的版本默认开启，在MySQL起停的时候自动Dump 和Load ib_buffer_pool文件，但需要注意innodb_fast_shutdown参数不能设置为2，否则就算参数innodb_buffer_pool_dump_at_shutdown开启，在关闭MySQL时也不会自动Dump ib_buffer_pool文件，可能导致在MySQL启动时报ib_buffer_pool文件不存在的错误（如果你手工执行了set global innodb_buffer_pool_dump_now=ON就会立即Dump出ib_buffer_pool文件）。
虽然在Load ib_buffer_pool文件时不会阻塞前台的操作，而是在后台执行，但是从测试结果中可以看到，Load操作会占用大量磁盘的读IO，所以对于MySQL的起停操作，需要避开业务高峰期进行。

正文到此结束