1、日志产生的性能影响:
由于日志的记录带来的直接性能损耗就是数据库系统中最为昂贵的IO资源。MySQL的日志包括错误日志(ErrorLog),更新日志(UpdateLog),二进制日志(Binlog),查询日志(QueryLog),慢查询日志(SlowQueryLog)等。当然,更新日志是老版本的MySQL才有的,目前已经被二进制日志替代。
在默认情况下,系统仅仅打开错误日志,关闭了其他所有日志,以达到尽可能减少IO损耗提高系统性能的目的。但是在一般稍微重要一点的实际应用场景中,都至少需要打开二进制日志,因为这是MySQL很多存储引擎进行增量备份的基础,也是MySQL实现复制的基本条件。有时候为了进一步的性能优化,定位执行较慢的SQL语句,很多系统也会打开慢查询日志来记录执行时间超过特定数值(由我们自行设置)的SQL语句。
一般情况下,在生产系统中很少有系统会打开查询日志。因为查询日志打开之后会将MySQL中执行的每一条Query都记录到日志中,会该系统带来比较大的IO负担,而带来的实际效益却并不是非常大。一般只有在开发测试环境中,为了定位某些功能具体使用了哪些SQL语句的时候,才会在短时间段内打开该日志来做相应的分析。所以,在MySQL系统中,会对性能产生影响的MySQL日志(不包括各存储引擎自己的日志)主要就是Binlog了。
测试环境:
Red Hat Enterprise Linux Server release 6.3 (Santiago)
Server version: 5.6.22-log MySQL Community Server (GPL)
我搭建了1主3从的环境,准备测试MHA架构,过程中发现,测试并发插入的时候,从库1可以跟上,从库2,3跟不上
如何判断是io thread慢还是 sql thread慢呢,有个方法,观察show slave status\G ,
判断3个参数(参数后面的值是默认空闲时候的正常值):
Slave_IO_State: Waiting for master to send event
Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
Seconds_Behind_Master: 0
1.sql thread慢的表现:
Seconds_Behind_Master越来越大
Slave_SQL_Running_State: Reading event from the relay log
2.io thread慢的表现:
Seconds_Behind_Master为0
Slave_SQL_Running_State: 显示正常值
Slave_IO_State:显示忙碌状态
而我观察到的值是
Slave_IO_State: Waiting for master to send event
Seconds_Behind_Master: 313
Slave_SQL_Running_State: Reading event from the relay log
因此推断是sql thread慢
为啥只有slave2,3慢,而slave1可以跟上呢,开始怀疑是参数配置的差异,比对/etc/my.cnf后发现,配置无差异
因此排除这个原因,后来用dstat观察,发现繁忙时候,slave的IO写速度上不去
slave1:
$ dstat
—-total-cpu-usage—- -dsk/total- -net/total- —paging– —system–
usr sys idl wai hiq siq| read writ| recv send| in out | int csw
0 0 100 0 0 0|9308B 11k| 0 0 | 3B 3B| 63 63
3 4 54 40 0 0| 88k 10M| 45k 9438B| 0 0 |1857 2579
3 3 59 35 0 1| 80k 7552k| 40k 8486B| 0 0 |1675 2307
3 3 56 38 0 0| 72k 7824k| 42k 8816B| 0 0 |1727 2348
3 4 52 41 0 1| 96k 9688k| 49k 10k| 0 0 |2029 2874
3 4 54 39 0 0| 96k 8880k| 45k 9410B| 0 0 |1905 2674
3 3 53 40 0 1| 96k 9776k| 58k 10k| 0 0 |1935 2671
3 3 58 36 0 0| 64k 7848k| 40k 8420B| 0 0 |1724 2357
3 5 52 40 0 1| 96k 8936k| 49k 10k| 0 0 |1948 2680
3 4 51 42 0 1| 96k 9400k| 49k 10k| 0 0 |1988 2760
3 4 52 41 0 0| 88k 9752k| 49k 10k| 0 0 |2058 2868
4 4 51 41 0 1| 96k 9680k| 49k 9938B| 0 0 |1990 2750
3 3 59 35 0 0| 80k 7632k| 39k 8288B| 0 0 |1668 2275
3 4 52 42 0 1| 80k 8504k| 46k 9146B| 0 0 |1860 2523
3 4 51 42 0 0| 80k 8496k| 43k 8684B| 0 0 |1882 2516
2 3 65 30 0 0| 64k 5976k| 30k 6440B| 0 0 |1326 1802
3 4 53 40 0 1| 72k 8360k| 59k 10k| 0 0 |1859 2538
3 4 51 42 0 1| 96k 8840k| 53k 10k| 0 0 |1958 2648
2 4 51 43 0 0| 72k 7352k| 40k 7760B| 0 0 |1633 2219
3 4 51 42 0 1| 88k 7920k| 31k 6770B| 0 0 |1767 2373
3 3 54 40 0 0| 80k 8528k| 40k 8750B| 0 0 |1859 2549
slave2:
—-total-cpu-usage—- -dsk/total- -net/total- —paging– —system–
usr sys idl wai hiq siq| read writ| recv send| in out | int csw
2 1 50 47 0 1|8192B 1168k| 55k 10k| 0 0 | 533 771
1 1 51 48 0 0|8192B 1048k| 33k 7046B| 0 0 | 427 622
1 1 51 48 0 0|8192B 1080k| 58k 9806B| 0 0 | 500 709
1 1 50 48 0 0| 0 1864k| 51k 8486B| 0 0 | 502 669
1 2 51 47 0 0|8192B 1120k| 42k 8156B| 0 0 | 496 674
1 1 51 47 0 0|8192B 1160k| 32k 6350B| 0 0 | 467 655
1 2 51 47 0 0| 0 1288k| 50k 10k| 0 0 | 563 797
1 1 51 47 0 0|8192B 1200k| 43k 8486B| 0 0 | 493 728
2 1 50 47 0 0|8192B 1024k| 45k 8816B| 0 0 | 481 659
1 1 50 48 0 0|8192B 1248k| 49k 9450B| 0 0 | 517 772
1 1 50 48 0 0| 0 1264k| 47k 9146B| 0 0 | 516 756
1 2 50 47 0 1|8192B 1144k| 50k 10k| 0 0 | 520 765
1 1 51 48 0 0|8192B 1200k| 51k 8156B| 0 0 | 484 716
1 2 50 48 0 0|8192B 968k| 50k 9278B| 0 0 | 470 684
1 1 50 48 0 0|8192B 1128k| 39k 7892B| 0 0 | 476 679
1 1 51 47 0 0| 0 1248k| 45k 9476B| 0 0 | 523 760
1 2 50 48 0 0|8192B 1448k| 41k 7826B| 0 0 | 552 805
1 1 50 48 0 0|8192B 1120k| 44k 8090B| 0 0 | 470 692
slave3:
—-total-cpu-usage—- -dsk/total- -net/total- —paging– —system–
usr sys idl wai hiq siq| read writ| recv send| in out | int csw
1 1 50 49 0 0|8192B 1328k|1167B 170B| 0 0 | 385 515
1 1 51 48 0 0|8192B 1128k| 754B 170B| 0 0 | 325 449
1 1 50 49 0 0| 0 920k| 474B 314B| 0 0 | 279 381
0 1 50 49 0 0|8192B 664k|1633B 170B| 0 0 | 226 291
1 1 50 49 0 0|8192B 1200k|1250B 170B| 0 0 | 353 475
1 1 50 48 0 0| 0 1432k|1632B 170B| 0 0 | 402 551
1 1 51 48 0 0| 16k 1752k|1045B 170B| 0 0 | 487 664
1 1 50 48 0 0|8192B 1648k| 12k 170B| 0 0 | 461 636
1 1 51 48 0 0| 0 1272k| 886B 170B| 0 0 | 380 501
1 1 50 49 0 0|8192B 1000k|1023B 170B| 0 0 | 300 400
1 1 50 48 0 0|8192B 1096k| 747B 170B| 0 0 | 332 442
1 1 50 48 0 0|8192B 1448k|1003B 170B| 0 0 | 416 557
1 1 50 48 0 0| 0 1592k|1174B 170B| 0 0 | 450 614
1 1 51 48 0 0|8192B 1416k|1028B 170B| 0 0 | 404 552
0 1 50 49 0 0|8192B 1128k|1031B 170B| 0 0 | 331 447
1 1 51 48 0 0|8192B 1160k|1185B 170B| 0 0 | 340 458
1 1 50 49 0 0| 0 1120k| 633B 170B| 0 0 | 326 453
1 0 50 49 0 0|8192B 656k|8886B 170B| 0 0 | 221 288
1 1 50 49 0 0|8192B 1128k|1619B 170B| 0 0 | 335 451
slave1可以达到每秒9M的写入IO,而slave2,3只能达到每秒1M多,IO性能差很多,后来分析了下存储,发现是有很大差异的,也印证了我的推测
那么问题来了,要如何优化IO性能比较差的slave呢,其实很简单,修改两个参数
mysql>SHOW VARIABLES like ‘%innodb_fl%’;
mysql>SHOW VARIABLES like ‘sync_binlog’;
mysql> set global sync_binlog=20 ;
Query OK, 0 rows affected (0.00 sec)
mysql> set global innodb_flush_log_at_trx_commit=2;Query OK, 0 rows affected (0.00 sec)
innodb_flush_log_at_trx_commit和sync_binlog是MySQL innodb引擎的两个重要的参数,其中innodb_flush_log_at_trx_commit是将事务日志从innodb log buffer写入到redo log中,sync_binlog是将二进制日志文件刷新到磁盘上。
innodb事务日志redo,binlog逻辑过程如下:
1.事务写入redo log buffer中;
2.将log buffer刷新到redo log中,不过会先写一个TX PREPARE标记;
3.写binlog
4.在redo log中写入TX COMMIT标记;
5.将写binlog成功的标记写入redo log。
参数解析如下:
innodb_flush_log_at_trx_commit = N:
N=0 每隔一秒,把事务日志缓存区的数据写到日志文件中,以及把日志文件的数据刷新到磁盘上;
log buffer 会 每秒写入到日志文件并刷写(flush)到磁盘。但每次事务提交不会有任何影响,也就是 log buffer 的刷写操作和事务提交操作没有关系。在这种情况下,MySQL性能最好,但如果 mysqld 进程崩溃,通常会导致最后 1s 的日志丢失。
N=1 每个事务提交时候,把事务日志从缓存区写到日志文件中,并且刷新日志文件的数据到磁盘上;
当取值为 1 时,每次事务提交时,log buffer 会被写入到日志文件并刷写到磁盘。这也是默认值。这是最安全的配置,但由于每次事务都需要进行磁盘I/O,所以也最慢。
N=2 每事务提交的时候,把事务日志数据从缓存区写到日志文件中;每隔一秒,刷新一次日志文件,但不一定刷新到磁盘上,而是取决于操作系统的调度;
当取值为 2 时,每次事务提交会写入日志文件,但并不会立即刷写到磁盘,日志文件会每秒刷写一次到磁盘。这时如果 mysqld 进程崩溃,由于日志已经写入到系统缓存,所以并不会丢失数据;在操作系统崩溃的情况下,通常会导致最后 1s 的日志丢失。
上面说到的「最后 1s」并不是绝对的,有的时候会丢失 更多数据。有时候由于调度的问题,每秒刷写(once-per-second flushing)并不能保证 100% 执行。对于一些数据一致性和完整性要求不高的应用,配置为 2 就足够了;如果为了最高性能,可以设置为 0。有些应用,如支付服务,对一致性和完整性要求很高,所以即使最慢,也最好设置为 1.
当我们设置为2 的时候,Log Thread 会在我们每次事务结束的时候将数据写入事务日志,但是这里的写入仅仅是调用了文件系统的文件写入操作。而我们的文件系统都是有缓存机制的,所以Log Thread 的这个写入并不能保证内容真的已经写入到物理磁盘上面完成持久化的动作。文件系统什么时候会将缓存中的这个数据同步到物理磁盘文件Log Thread 就完全不知道了。所以,当设置为2 的时候,MySQL Crash 并不会造成数据的丢失,但是OS Crash 或者是主机断电后可能丢失的数据量就完全控制在文件系统上了。各种文件系统对于自己缓存的刷新机制各不一样,大家可以自行参阅相关的手册。
sync_binlog = N:
N>0 每向二进制日志文件写入N条SQL或N个事务后,则把二进制日志文件的数据刷新到磁盘上;
N=0 不主动刷新二进制日志文件的数据到磁盘上,而是由操作系统决定;
推荐配置组合:
N=1,1 — 适合数据安全性要求非常高,而且磁盘IO写能力足够支持业务,比如充值消费系统;
N=1,0 — 适合数据安全性要求高,磁盘IO写能力支持业务不富余,允许备库落后或无复制;
N=2,0或2,m(0<m<100) — 适合数据安全性有要求,允许丢失一点事务日志,复制架构的延迟也能接受;
N=0,0 — 磁盘IO写能力有限,无复制或允许复制延迟稍微长点能接受,例如:日志性登记业务;
当两个参数设置为双1的时候,写入性能最差,sync_binlog=N (N>1 ) innodb_flush_log_at_trx_commit=2 时,(在当前模式下)MySQL的写操作才能达到最高性能。
数据安全性
当innodb_flush_log_at_trx_commit和sync_binlog 都为1时是最安全的,在mysqld 服务崩溃或者服务器主机crash的情况下,binary log 只有可能丢失最多一个语句或者一个事务。但是鱼与熊掌不可兼得,都为1会导致频繁的IO操作,因此该模式也是最慢的一种方式。
当innodb_flush_log_at_trx_commit设置为0,mysqld进程的崩溃会导致上一秒钟所有事务数据的丢失。
当innodb_flush_log_at_trx_commit设置为2,只有在操作系统崩溃或者系统掉电的情况下,上一秒钟所有事务数据才可能丢失。
双1适合数据安全性要求非常高,而且磁盘IO写能力足够支持业务,比如订单,交易,充值,支付消费系统。双1模式下,当磁盘IO无法满足业务需求时,推荐的做法是innodb_flush_log_at_trx_commit=2 ,sync_binlog=N (N为500 或1000) 且使用带蓄电池后备电源的缓存cache,防止系统断电异常。
———————
注意:
如果启用了autocommit,那么每一个语句statement就会有一次写操作;否则每个事务对应一个写操作。
而且mysql服务默认是autocommit打开的
修改参数后,slave2,3也一样可以跟上slave1的速度了
slave2,3:
—-total-cpu-usage—- -dsk/total- -net/total- —paging– —system–
usr sys idl wai hiq siq| read writ| recv send| in out | int csw
3 2 94 2 0 0| 32k 80k| 49k 10k| 0 0 |1042 658
3 2 94 1 0 1| 32k 72k| 49k 10k| 0 0 |1258 964
2 2 95 2 0 0| 32k 72k| 44k 9146B| 0 0 |1126 882
2 1 95 2 0 0| 32k 72k| 41k 8486B| 0 0 | 959 659
2 2 96 1 0 0| 32k 72k| 47k 9476B| 0 0 |1153 841
2 2 95 2 0 0| 24k 72k| 39k 8090B| 0 0 | 866 504
2 2 96 1 0 0| 24k 72k| 42k 7562B| 0 0 | 908 663
2 1 95 2 0 0| 40k 72k| 52k 10k| 0 0 |1084 685
3 1 94 2 0 1| 40k 80k| 54k 11k| 0 0 |1204 873
2 2 96 1 0 0| 16k 32k| 30k 6044B| 0 0 | 846 802
2 1 97 1 0 0| 24k 32k| 35k 7760B| 0 0 |1059 888
2 1 95 3 0 0| 32k 856k| 44k 9278B| 0 0 | 943 551
2 1 94 3 0 0| 32k 104k| 42k 8618B| 0 0 | 986 704
2 1 96 1 0 0| 24k 72k| 34k 7034B| 0 0 | 863 682
2 2 95 2 0 0| 32k 64k| 45k 8684B| 0 0 |1052 750
2 2 90 7 0 0| 24k 416k| 38k 7166B| 0 0 | 906 722
3 2 93 2 0 1| 32k 80k| 57k 10k| 0 0 |1069 829
3 2 94 1 0 0| 32k 72k| 42k 8486B| 0 0 |1076 942
2 1 96 1 0 0| 24k 72k| 37k 7496B| 0 0 | 859 575
2 2 94 2 0 1| 32k 64k| 43k 8684B| 0 0 |1138 1011
3 2 94 1 0 0| 32k 72k| 42k 9014B| 0 0 |1099 782
2 3 94 2 0 0| 32k 72k| 50k 10k| 0 0 |1332 1359
2 2 95 2 0 0| 24k 72k| 34k 6902B| 0 0 | 921 799
2 2 94 2 0 0| 40k 72k| 55k 11k| 0 0 |1318 1016
1 2 96 2 0 0| 32k 80k| 41k 8882B| 0 0 |1020 719
而且我观察到slave2,3的写入数量减少了两个数量级,从1M多下降到70k