Mysql – High average load due to the High thesql cpu usage

innodbloadmonitoringMySQL

i've got 2 warnings about my average load being high in the past week and apparently it has to do something with the mysql

my daily visit has been increased about 10-20 thousand (total of 180-150 thousand pre day ) also i've started to use triggers since last month

my tables are not that big , big ones are about 100,000 rows .

so here is the warning :

 This is an automated message notifying you that the 5 minute load average on your system is 10.93.
This has exceeded the 10 threshold.

One Minute      - 40.6
Five Minutes    - 10.93
Fifteen Minutes - 4.78

top - 20:33:02 up 22 days, 22:38,  0 users,  load average: 40.60, 10.93, 4.78
Tasks: 667 total,  83 running, 580 sleeping,   0 stopped,   4 zombie
Cpu(s): 18.5%us,  0.4%sy,  0.0%ni, 80.7%id,  0.1%wa,  0.0%hi,  0.3%si,  0.0%st
Mem:  32840004k total, 32478112k used,   361892k free,   364564k buffers
Swap:  1050616k total,   532240k used,   518376k free, 22111016k cached

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
7577 mysql     20   0 6680m 1.4g 5680 S 243.8  4.6  13448:23 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/lib/mysql/ns4008353.ip-198-27-68.net.err --open-files-limit=7296 --pid-file=/var/lib/mysql/ns4008353.ip-198-27-68.net.pid                                                                                                                                                                                                                                                                             
1296 apache    20   0  262m  72m 7076 R  7.0  0.2   3:55.66 /usr/sbin/httpd -k start -DSSL                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     

another one :

One Minute      - 73.75
Five Minutes    - 18.41
Fifteen Minutes - 6.96

top - 11:09:03 up 14 days, 13:14,  0 users,  load average: 73.75, 18.41, 6.96
Tasks: 483 total, 111 running, 369 sleeping,   0 stopped,   3 zombie
Cpu(s): 18.2%us,  0.4%sy,  0.0%ni, 81.1%id,  0.1%wa,  0.0%hi,  0.3%si,  0.0%st
Mem:  32840004k total, 32671524k used,   168480k free,   378116k buffers
Swap:  1050616k total,   428900k used,   621716k free, 22453492k cached

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
7577 mysql     20   0 7391m 2.2g 5644 S 355.7  6.9   8113:40 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/lib/mysql/ns4008353.ip-198-27-68.net.err --open-files-limit=7296 --pid-file=/var/lib/mysql/ns4008353.ip-198-27-68.net.pid                                                                                                                                                                                                                                                                             
3480 apache    20   0  211m  19m 3708 R  5.0  0.1   0:00.30 /usr/sbin/httpd -k start -DSSL                                                                                                                                                                                                                                

obviously there is something wrong with mysql

when i do top in the ssh , occasionally i see mysql cpu usage goes up to 90%-110% (1 core out of 8 of curse) even when there is not much traffic on the site .

so i did a SHOW FULL PROCESSLIST and here is the result

Id      User                Host        db         Command  Time    State                   Info
387971  sitedb_main     localhost   sitedb_main     Sleep   72      NULL
388070  sitedb_main     localhost   sitedb_main     Query   0      Copying to tmp table     SELECT * FROM `images` WHERE `confirm` = 1   AND `...
388071  sitedb_main     localhost   NULL            Query   0       NULL                    SHOW FULL PROCESSLIST

another one :

Id      User                Host        db         Command  Time    State           Info
209521  sitedb_main     localhost   sitedb_main     Sleep   108                     NULL
209752  sitedb_main     localhost   sitedb_main     Sleep   0                       NULL
209756  sitedb_main     localhost   sitedb_main     Query   0     Sorting result    SELECT *    FROM (`images`)    WHERE `confirm` =  1
209757  sitedb_main     localhost   NULL            Query   0     NULL              SHOW FULL PROCESSLIST

there is one particulars process which has sleep under the Command column , it starts at 0 for time and goes up to 100 or 200 sometimes 300 and then fades away .

it seems that mysql load peaks when couple of these sleep process (5-6) are running simultaneously

i've no idea what are these sleeping processes (nothing under the info column )

my databes is indexed and my queries are fairly optimaized
so any suggestion ?

btw i've enabled the slow query log (i hope ) and am in the process of installing mytop :

problem installing mytop , need a up to date tools for monitoring mysql

Processor Name  Intel(R) Xeon(R) CPU E3-1245 V2 @ 3.40GHz
Total Memory    32840004 kB
Free Memory 10416752 kB
Total Swap Memory   1050616 kB
Free Swap Memory    1050616 kB
MySQL 5.5.31    Running

this is all the lines with innodb ! from my.cnf :

innodb_file_per_table=1
innodb_buffer_pool_size=1G
#innodb_log_file_size=256M
#innodb_log_buffer_size=4M

my.cnf :

bind-address=127.0.0.1
innodb_file_per_table=1
innodb_buffer_pool_size=1G
default-storage-engine=MYISAM
#innodb_log_file_size=256M
#innodb_log_buffer_size=4M
#datadir=/var/lib/mysql
#socket=/var/lib/mysql/mysql.sock
skip-external-locking
wait_timeout=1200
query_prealloc_size=16384
query_cache_type=1
sort_buffer_size=2M
key_buffer=128M
key_buffer_size=512M
max_connect_errors=10
query_cache_size=128M
read_buffer_size=8M
join_buffer_size=64M
table_cache=1500
max_connections=450
query_cache_limit=4M
max_allowed_packet=128M
tmp_table_size=128M
max_heap_table_size=128M
connect_timeout=10
myisam_sort_buffer_size=64M
thread_cache_size=64
query_alloc_block_size=16384
local-infile=0

open_files_limit=7296
slow-query-log = 1
slow-query-log-file = /var/log/mysql/log-slow-queries.log
long_query_time = 1

Best Answer

Looking at this my.cnf, InnoDB for MySQL 5.5 has more firepower you can configure.

I would add the following settings:

innodb_read_io_threads=64
innodb_write_io_threads=64
innodb_fast_shutdown=0
innodb_log_buffer_size=256M
innodb_log_file_size=512M
innodb_flush_method=O_DIRECT
query_cache_size=0

What are these for?

  • innodb_read_io_threads and innodb_write_io_threads (both since MySQL 5.1.38) allocate the specified number of threads for reads and writes. Default is 4 and maximum is 64.
  • innodb_fast_shutdown set to 0 completely purges transactional changes to disk. This also makes for a faster startup.
  • innodb_log_file_size is 5MB by default in MySQL 5.5. I am merely suggesting they be much bigger. The documentation says : The size in bytes of each log file in a log group. The combined size of log files cannot exceed 3.99999999068677 GB which is equal to the 4294967295 range limit. A pair of 2047 MB log files, for example, would allow you to approach the range limit but not exceed it. The default value is 5MB. Sensible values range from 1MB to 1/N-th of the size of the buffer pool, where N is the number of log files in the group. The larger the value, the less checkpoint flush activity is needed in the buffer pool, saving disk I/O. But larger log files also mean that recovery is slower in case of a crash.
  • innodb_flush_method tells InnoDB to bypass caching anything in the OS. All needed caching is done internally (within the InnoDB Architecture)
  • query_cache_size is set to 128M. It shoudl be 0 because InnoDB checks the query cache very frequently. In fact, it's preferred that this be disabled for InnoDB (See my earlier post from Sep 05, 2012 : Is the overhead of frequent query cache invalidation ever worth it?)
  • innodb_log_buffer_size set higher decreases Disk I/O.

You are probably running with default log files, so I would do this:

STEP 01 : Log in to mysql and run this:

mysql> SET GLOBAL innodb_fast_shutdown = 0;

STEP 02 : Shutdown MySQL

service mysql stop

STEP 03 : Rename InnoDB Log Files

cd /var/lib/mysql
mv ib_logfile0 ib_logfile0.bak
mv ib_logfile1 ib_logfile1.bak

STEP 04 : Startup MySQL

service mysql start

Extra time is needed to recreate the new ib_logfile0 and new ib_logfile1

This should increase InnoDB's overall performance in terms of CPU and Disk Usage

Give it a Try !!!

As a side point, here is what InnoDB looks like under the hood:

InnoDB Architecture

InnoDB Architecture