MySQL5.5数据库innodb_change_buffering怪异问题分析

　　最近我们接手一个第三方开发的游戏运维，所有的安装文档和软件包及配置参数都是第三方提供的，其中数据库部分使用的MySQL官方开源版本5.5.20,配置文件也是第三方提供的，我们在部署第一个区服后，按自己使用MySQL5.1版本数据库的经验来初步优化MySQL数据库的配置文件my.cnf,其中主要是启用了innodb_file_per_table,并且修改innodb_flush_log_at_trx_commit的2改为0,然后将主机和MySQL纳入到Cacti的监控中,在运行第四天的时候，我们发现Cacti的监控上有一些差异，然后开始寻找原因…

　　1)硬件配置和相关参数设置

　　CPU：2*5630(16 core)

　　MEM：16GB

　　HDD:2*15k 300GB sas RAID1 (IO太差了…)

　　innodb_change_buffering=all

　　innodb_buffer_pool_size=2G

　　应用环境：python 短连接

　　2)数据库物理文件大小和mysqldump逻辑备份集大小

　　2.1)第一台主机(innodb_file_per_table=OFF,innodb_flush_log_at_trx_commit=2)

　　[mysql@ZS29 mysql]$ ll -h

　　-rw-rw—- 1 mysql mysql 970M Mar 27 17:24 ibdata1

　　ZS29_20120327.sql.bz2 52.9M

　　2.1)第二台主机(innodb_file_per_table=ON,innodb_flush_log_at_trx_commit=0)

　　[mysql@ZSAS mysql]$ du -sSh 19216819010/

　　1.2G 19216819010/

　　ZSAS_20120327.sql.bz2 46.9M

　　由上面数据我们可以看到共享表空间比独立表空间的存储效率高

　　3)转到正题说innodb_change_buffering这个参数

　　官方文档解释连接如下：http://dev.mysql.com/doc/refman/5.5/en/innodb-parameters.html#sysvar_innodb_change_buffering

　　更详细的信息在这里：http://dev.mysql.com/doc/refman/5.5/en/innodb-performance-change_buffering.html

　　4)看我Cacti的监控图

　　4.1)第一台主机

　　4.1)第二台主机

　　22日启用该数据库

　　26日的凌晨4点做mysqldump –single-transaction全备，发现ibuf cell count从2增加到94

　　27日凌晨4点全备时候ibuf cell count从94增加到218

　　但是ibuf used cell最大使用是1(Y?),对ibuf cell count统计原理不清楚

　　innodb buffer pool的监控上看到,第一台主机970MB的物理文件使用了1GB的BP，第二台主机上1.2GB的物理文件将2GB的BP都使用完

　　innodb_insert buffer usage的监控图上看到。第一台主机的ibuf使用为0，第二台主机使用ibuf信息如图上方蓝色斜体字所示

　　5)下面是两台主机的show engine innodb statusG的输出

　　5.1)第一台主机

　　mysql> show engine innodb statusG

　　*************************** 1. row ***************************

　　Type: InnoDB

　　Name:

　　Status:

　　=====================================

　　120326 14:21:50 INNODB MONITOR OUTPUT

　　=====================================

　　Per second averages calculated from the last 46 seconds

　　—————–

　　BACKGROUND THREAD

　　—————–

　　srv_master_thread loops: 666042 1_second, 666037 sleeps, 65599 10_second, 10428 background, 10428 flush

　　srv_master_thread log flush and writes: 669932

　　———-

　　SEMAPHORES

　　———-

　　OS WAIT ARRAY INFO: reservation count 364363, signal count 1993532

　　Mutex spin waits 22249903, rounds 64715401, OS waits 253896

　　RW-shared spins 312039, rounds 2368779, OS waits 70939

　　RW-excl spins 598499, rounds 3373436, OS waits 27594

　　Spin rounds per wait: 2.91 mutex, 7.59 RW-shared, 5.64 RW-excl

　　————

　　TRANSACTIONS

　　————

　　Trx id counter 130D68CA

　　Purge done for trx’s n:o < 130D5319 undo n:o < 0

　　History list length 2313

　　LIST OF TRANSACTIONS FOR EACH SESSION:

　　—TRANSACTION 130738AE, not started

　　MySQL thread id 267042058, OS thread handle 0×43147940, query id 1126874980 localhost root

　　show engine innodb status

　　——–

　　FILE I/O

　　——–

　　I/O thread 0 state: waiting for i/o request (insert buffer thread)

　　I/O thread 1 state: waiting for i/o request (log thread)

　　I/O thread 2 state: waiting for i/o request (read thread)

　　I/O thread 3 state: waiting for i/o request (read thread)

　　I/O thread 4 state: waiting for i/o request (read thread)

　　I/O thread 5 state: waiting for i/o request (read thread)

　　I/O thread 6 state: waiting for i/o request (read thread)

　　I/O thread 7 state: waiting for i/o request (read thread)

　　I/O thread 8 state: waiting for i/o request (read thread)

　　I/O thread 9 state: waiting for i/o request (read thread)

　　I/O thread 10 state: waiting for i/o request (write thread)

　　I/O thread 11 state: waiting for i/o request (write thread)

　　I/O thread 12 state: waiting for i/o request (write thread)

　　I/O thread 13 state: waiting for i/o request (write thread)

　　I/O thread 14 state: waiting for i/o request (write thread)

　　I/O thread 15 state: waiting for i/o request (write thread)

　　I/O thread 16 state: waiting for i/o request (write thread)

　　I/O thread 17 state: waiting for i/o request (write thread)

　　Pending normal aio reads: 0 [0, 0, 0, 0, 0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0, 0, 0, 0, 0] ,

　　ibuf aio reads: 0, log i/o’s: 0, sync i/o’s: 0

　　Pending flushes (fsync) log: 0; buffer pool: 0

　　1391 OS file reads, 116655932 OS file writes, 1258228 OS fsyncs

　　0.00 reads/s, 0 avg bytes/read, 209.39 writes/s, 2.52 fsyncs/s

　　————————————-

　　INSERT BUFFER AND ADAPTIVE HASH INDEX

　　————————————-

　　Ibuf: size 1, free list len 0, seg size 2, 0 merges

　　merged operations:

　　insert 0, delete mark 0, delete 0

　　discarded operations:

　　insert 0, delete mark 0, delete 0

　　Hash table size 4425293, node heap has 3501 buffer(s)

　　1420.25 hash searches/s, 498.34 non-hash searches/s

　　—

　　LOG

　　—

　　Log sequence number 41254406127

　　Log flushed up to 41254372111

　　Last checkpoint at 40870741452

　　0 pending log writes, 0 pending chkp writes

　　115271637 log i/o’s done, 206.80 log i/o’s/second

　　———————-

　　BUFFER POOL AND MEMORY

　　———————-

　　Total memory allocated 2197815296; in additional pool allocated 0

　　Dictionary memory allocated 467977

　　Buffer pool size 131072

　　Free buffers 70823

　　Database pages 56748

　　Old database pages 20927

　　Modified db pages 9187

　　Pending reads 0

　　Pending writes: LRU 0, flush list 0, single page 0

　　Pages made young 3278, not young 0

　　0.00 youngs/s, 0.00 non-youngs/s

　　Pages read 0, created 56748, written 2032679

　　0.00 reads/s, 0.02 creates/s, 2.85 writes/s

　　Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

　　Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

　　LRU len: 56748, unzip_LRU len: 0

　　I/O sum[0]:cur[0], unzip sum[0]:cur[0]

　　————–

　　ROW OPERATIONS

　　————–

　　0 queries inside InnoDB, 0 queries in queue

　　1 read views open inside InnoDB

　　Main thread process no. 20434, id 1102543168, state: sleeping

　　Number of rows inserted 23525784, updated 52408224, deleted 19612589, read 10413217446

　　7.39 inserts/s, 95.72 updates/s, 0.61 deletes/s, 12916.57 reads/s

　　—————————-

　　END OF INNODB MONITOR OUTPUT

　　============================

　　5.1)第二台主机

　　mysql> show engine innodb statusG

　　*************************** 1. row ***************************

　　Type: InnoDB

　　Name:

　　Status:

　　=====================================

　　120326 14:21:43 INNODB MONITOR OUTPUT

　　=====================================

　　Per second averages calculated from the last 32 seconds

　　—————–

　　BACKGROUND THREAD

　　—————–

　　srv_master_thread loops: 453194 1_second, 453193 sleeps, 45105 10_second, 2270 background, 2270 flush

　　srv_master_thread log flush and writes: 477705

　　———-

　　SEMAPHORES

　　———-

　　OS WAIT ARRAY INFO: reservation count 251972, signal count 608458

　　Mutex spin waits 15744080, rounds 41341479, OS waits 135480

　　RW-shared spins 126894, rounds 2003575, OS waits 61480

　　RW-excl spins 202240, rounds 2643686, OS waits 52335

　　Spin rounds per wait: 2.63 mutex, 15.79 RW-shared, 13.07 RW-excl

　　————

　　TRANSACTIONS

　　————

　　Trx id counter 10133D76

　　Purge done for trx’s n:o < 10133C95 undo n:o < 0

　　History list length 436

　　LIST OF TRANSACTIONS FOR EACH SESSION:

　　—TRANSACTION 100C5EF4, not started

　　MySQL thread id 227845139, OS thread handle 0x431d9940, query id 961453164 localhost root