How to Fix Slow InnoDB INSERT/UPDATE/DELETE in MySQL

innodbMySQL

Background

A couple of weeks ago all of my INSERT's/UPDATE's/DELETE's became overall slow (not SELECT's). Before that, everything was normal (mysql statements executed in <0,01 seconds). Now a simple INSERT takes about 0,1 seconds. It's the same for all tables in the database and even for the simpliest query in a table with no data and only one index, it's not related to any advanced or complex queries.

Example:

mysql> INSERT INTO test (name) VALUES ('Andy');
Query OK, 1 row affected (0.09 sec)

The table looks like this:

mysql> SHOW CREATE TABLE test;
+-----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table     | Create Table                                                                                                                                                                                |
+-----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| test | CREATE TABLE `test` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `name` varchar(50) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=791 DEFAULT CHARSET=latin1 |
+-----------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

After server reboot

The first thing I tested was to reboot the server. After that everything was good and back to normal! But after a couple of days the slow queries was back.

As mysql has been much faster before and even after a reboot, for a
couple of days, I think that there must be some sort of problem or
should I accept that a mysql query takes about 0,1 seconds to execute?

my.cnf

[mysql]
# CLIENT #
port                           = 3306
socket                         = /var/run/mysqld/mysqld.sock
[mysqld]
# GENERAL #
user                           = mysql
default_storage_engine         = InnoDB
socket                         = /var/run/mysqld/mysqld.sock
pid_file                       = /var/run/mysqld/mysql.pid
# MyISAM #
key_buffer_size                = 32M
myisam_recover                 = FORCE,BACKUP
# SAFETY #
max_allowed_packet             = 1G
max_connect_errors             = 1000000
innodb                         = FORCE
# DATA STORAGE #
datadir                        = /var/lib/mysql/
# BASIC SETTINGS #
basedir                = /usr
tmpdir                 = /tmp
# BINARY LOGGING #
log_bin                        = /var/log/mysql/mysql-bin
expire_logs_days               = 4
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         = 4096
table_open_cache               = 1024
# INNODB #
innodb_flush_method            = O_DIRECT
innodb_log_files_in_group      = 2
innodb_log_file_size           = 256M
innodb_flush_log_at_trx_commit = 1
innodb_file_per_table          = 1
innodb_buffer_pool_size        = 12G
# LOGGING #
log_error                      = /var/log/mysql/error.log
log_queries_not_using_indexes  = 0
long_query_time                = 5
slow_query_log                 = 1
slow_query_log_file            = /var/log/mysql/mysql-slow.log
# REPLICATION RELATED #
server-id              = 1
log-slave-updates
auto_increment_increment       = 10
auto_increment_offset          = 1
relay_log              = /var/log/mysql/mysql-relay
sync_binlog            = 1
innodb_support_xa          = 1
sync_master_info           = 1
sync_relay_log             = 1
sync_relay_log_info        = 1
#replicate-ignore-db           = mysql
binlog-format              = ROW
[mysqldump]
quick
quote-names
max_allowed_packet  = 16M

top

top - 14:34:24 up 28 days, 13:16,  2 users,  load average: 0.21, 0.46, 0.48
Tasks: 104 total,   1 running, 103 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.1%us,  0.0%sy,  0.0%ni, 99.9%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  16419976k total, 12208664k used,  4211312k free,   209064k buffers
Swap:  8376316k total,        0k used,  8376316k free,  9348992k cached

Notes

Server RAM: 16GB

Server HD: 3 x 146 GB SAS (RAID 5)

Version: Percona MySQL 5.5.30-30.2-log

Replication: Yes, the server is the master in a repliation setup

Database size: ~2GB


Update 1, jan 7 (Test 1)

Changed the innodb_flush_log_at_trx_commit to 0. Now the queries run a little bit faster, but setting innodb_flush_log_at_trx_commit to 0 is from what I have heard not a good solution. Here is a query profile.

mysql> INSERT INTO test (name) VALUES ('Andy');
Query OK, 1 row affected (0.02 sec)

mysql> SHOW PROFILE;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000036 |
| checking permissions | 0.000006 |
| Opening tables       | 0.000048 |
| System lock          | 0.000006 |
| init                 | 0.000012 |
| update               | 0.000069 |
| end                  | 0.000002 |
| query end            | 0.021729 |
| closing tables       | 0.000015 |
| freeing items        | 0.000019 |
| logging slow query   | 0.000002 |
| cleaning up          | 0.000002 |
+----------------------+----------+
12 rows in set (0.00 sec)

Update 2, jan 14

The problem seems to be intermittent, i.e. the problems disapears for a while and then comes back. Not only after reboot of server. A couple of days ago the problem disappeared but came back yesterday. Heres the query profile of the same query as above:

mysql> INSERT INTO test (name) VALUES ('Andy');
Query OK, 1 row affected (0.08 sec)

mysql> SHOW PROFILE;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000025 |
| checking permissions | 0.000004 |
| Opening tables       | 0.000014 |
| System lock          | 0.000004 |
| init                 | 0.000007 |
| update               | 0.000036 |
| end                  | 0.000003 |
| query end            | 0.082652 |
| closing tables       | 0.000012 |
| freeing items        | 0.000016 |
| logging slow query   | 0.000002 |
| cleaning up          | 0.000001 |
+----------------------+----------+
12 rows in set (0.00 sec)

The comments to this post, says quite clearly that MySQL/InnoDB should not be run on RAID 5. Is there anything else I can test before I go with the conclusion that RAID 5 is the problem? Is the intermittent slow INSERT/UPDATE/DELETE a sign of that the problem is RAID 5?

Best Answer

Problem found. It has nothing to do with MySQL/InnoDB. The problem was in the RAID controller battery that were going throuh "relearning" cycle and then the write-Back policy is disabled and Write-Through is enabled and as a result writes become very slow. If you have a Dell server and similar symtoms, take a look at the syslog and the battery.

Jan 13 17:34:21 Server Administrator: Storage Service EventID: 2188  The controller write policy has been changed to Write Through.:  Battery 0 Controller 0

For more information: http://agiletesting.blogspot.se/2011/09/slow-database-check-raid-battery.html

Maybe this question should be renamed and moved to Server Fault.