Mysql 5.5 High I/O Wait

[Tim Nelson]

Mysql 5.5 same transaction mix hour by hour, same number of records in a table. VM running RHEL 5.8 spikes with wait I/O of > 50% and 100k breads/s. nothing obvious from show process list as the same queries are being run when things are fast. slow log reports queries that are work fast other times. mysqld is taking up 90% often of CPU as well. memory seems ok, never swapping.

Then out of the blue, everything goes back to normal. No other processes other than mysqld are clock time, just httpd calling mod_perl scripts to insert or query (essentially) a single table database with at most 500k records.

Literally, this VM can run for serval days without a peep, and then all of a sudden things go to hell in a hand basket. This system is closed in that the clients that do inserts are automated and run on intervals, and the clients that do the selects are also automated and run even less frequently.


Tuning scripts don't seem to be unhappy either.

Any ideas of what to look at?

------------------------- CUT HERE ----------------------------

When things are going bad:

12:49:52 PM tps rtps wtps bread/s bwrtn/s
12:49:53 PM 3959.18 3915.31 43.88 62579.59 351.02
12:49:54 PM 4900.00 4873.00 27.00 77920.00 680.00
12:49:55 PM 4448.00 4035.00 413.00 64512.00 17448.00
12:49:56 PM 3800.00 3621.00 179.00 58032.00 26224.00
12:49:57 PM 4557.14 4300.00 257.14 69142.86 5795.92
12:49:58 PM 3819.19 3806.06 13.13 60832.32 1810.10
12:49:59 PM 4275.00 4193.00 82.00 66864.00 2000.00
12:50:00 PM 4493.20 4414.56 78.64 70524.27 3984.47
12:50:01 PM 4165.66 4144.44 21.21 66311.11 169.70
12:50:02 PM 3985.87 3921.74 64.13 62565.22 634.78

When things are good:

01:08:00 PM 122.00 0.00 122.00 0.00 2064.00
01:08:01 PM 732.29 0.00 732.29 0.00 36758.33
01:08:02 PM 308.25 6.19 302.06 74.23 6696.91
01:08:03 PM 103.03 0.00 103.03 0.00 1793.94
01:08:04 PM 227.55 0.00 227.55 0.00 3159.18
01:08:05 PM 45.54 0.00 45.54 0.00 538.61
01:08:06 PM 146.94 0.00 146.94 0.00 2334.69
01:08:07 PM 205.00 0.00 205.00 0.00 2856.00
01:08:08 PM 88.78 0.00 88.78 0.00 1836.73
01:08:09 PM 105.05 9.09 95.96 145.45 1478.79

And you can see Wait I/O just goes nuts:
08:00:01 AM CPU %user %nice %system %iowait %steal %idle
11:30:01 AM all 37.57 0.00 3.30 0.91 0.00 58.23
11:40:02 AM all 36.71 0.00 3.29 1.58 0.00 58.42
11:50:01 AM all 40.07 0.00 3.71 1.77 0.00 54.45
12:00:01 PM all 34.23 0.00 3.22 1.73 0.00 60.83
12:10:01 PM all 39.47 0.35 3.55 1.34 0.00 55.28
12:20:01 PM all 41.73 0.00 4.99 19.08 0.00 34.20
12:30:01 PM all 45.22 0.00 7.35 46.68 0.00 0.74
12:40:01 PM all 44.32 0.00 7.69 47.80 0.00 0.19
12:50:01 PM all 43.33 0.00 7.11 49.32 0.00 0.24

my.cnf:

[mysql]

# CLIENT #
port = 3306
socket = /var/lib/mysql/mysql.sock

[mysqld]

# GENERAL #
user = mysql
default-storage-engine = InnoDB
socket = /var/lib/mysql/mysql.sock
pid-file = /var/lib/mysql/mysql.pid

# MyISAM #
key-buffer-size = 32M
myisam-recover = FORCE,BACKUP

# SAFETY #
max-allowed-packet = 64M
max-connect-errors = 1000000

# DATA STORAGE #
datadir = /var/lib/mysql/

# BINARY LOGGING #
#log-bin = /var/lib/mysql/mysql-bin
#expire-logs-days = 14
#sync-binlog = 1

# CACHES AND LIMITS #
tmp-table-size = 32M
max-heap-table-size = 32M
query-cache-type = 0
query-cache-size = 0
max-connections = 500
thread-cache-size = 50
open-files-limit = 65535
table-definition-cache = 1024
table-open-cache = 2048

# INNODB #
innodb-flush-method = O_DIRECT
innodb-log-files-in-group = 2
innodb-log-file-size = 128M
innodb-flush-log-at-trx-commit = 1
innodb-file-per-table = 1
innodb_file_format = Barracuda
innodb-buffer-pool-size = 1G
#innodb-buffer-pool-size = 2G
innodb_lock_wait_timeout = 180

# LOGGING #
log-error = /var/lib/mysql/mysql-error.log
log-queries-not-using-indexes = 1
slow-query-log = 1
slow-query-log-file = /var/lib/mysql/mysql-slow.log