MySQL database uses too much CPU

...even surpassing it's theorically maximum possible allocation.

[OK] Maximum possible memory usage: 7.3G (46% of installed RAM)

There is not actually a way to calculate maximum possible memory usage for MySQL, because there is no cap on the memory it can request from the system.

The calculation done by mysqltuner.pl is only an estimate, based on a formula that doesn't take into account all possible variables, because if all possible variables were taken into account, the answer would always be "infinite." It's unfortunate that it's labeled this way.

Here is my theory on what's contributing to your excessive memory usage:

thread_cache_size       = 128

Given that your max_connections is set to 200, the value of 128 for thread_cache_size seems far too high. Here's what makes me think this might be contributing to your problem:

When a thread is no longer needed, the memory allocated to it is released and returned to the system unless the thread goes back into the thread cache. In that case, the memory remains allocated.

^{http://dev.mysql.com/doc/refman/5.6/en/memory-use.html}

If your workload causes even an occasional client thread to require a large amount of memory, those threads may be holding onto that memory, then going back to the pool and sitting around, continuing to hold on to memory they don't technically "need" any more, on the premise that holding on to the memory is less costly than releasing it if you're likely to need it again.

I think it's worth a try to do the following, after first making a note of how much memory MySQL is using at the moment.

Note how many threads are currently cached:

mysql> show status like 'Threads_cached';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| Threads_cached | 9     |
+----------------+-------+
1 row in set (0.00 sec)

Next, disable the thread cache.

mysql> SET GLOBAL thread_cache_size = 0;

This disables the thread cache, but the cached threads will stay in the pool until they're used one more time. Disconnect from the server, then reconnect and repeat.

mysql> show status like 'Threads_cached';

Continue disconnecting, reconnecting, and checking until the counter reaches 0.

Then, see how much memory MySQL is holding.

You may see a decrease, possibly significant, and then again you may not. I tested this on one of my systems, which had 9 threads in the cache. Once those threads had all been cleared out of the cache, the total memory held by MySQL did decrease... not by much, but it does illustrate that threads in the cache do release at least some memory when they are destroyed.

If you see a significant decrease, you may have found your problem. If you don't, then there's one more thing that needs to happen, and how quickly it can happen depends on your environment.

If the theory holds that the other threads -- the ones currently servicing active client connections -- have significant memory allocated to them, either because of recent work in their current client session or because of work requiring a lot of memory that was done by another connection prior to them languishing in the pool, then you won't see all of the potential reduction in memory consumption until those threads are allowed to die and be destroyed. Presumably your application doesn't hold them forever, but how long it will take to know for sure whether there's a difference will depend on whether you have the option of cycling your application (dropping and reconnecting the client threads) or if you'll have to just wait for them to be dropped and reconnected over time on their own.

But... it seems like a worthwhile test. You should not see a substantial performance penalty by setting thread_cache_size to 0. Fortunately, thread_cache_size is a dynamic variable, so you can freely change it with the server running.

I'm going to explain how I solved the performance problem that I was fighting with for weeks. Feel free to criticize, the result can only be better for people in need.

First I read the book "High Performance MySQL". It is a great book because they expose the ways of profiling right from the start. Basically when you are done reading the first 2-3 chapters, you have enough tools to start digging. I wasn't aware of most of the profiling methods and I learned a lot.

I decided to start digging from the query_log by setting query_log_time=0. Then i picked the query that was causing trouble. In fact there was only one choice possible since all the queries were indexed, but this particular one was working on a large table. Went through everything here.

The target table was:

+------------+---------------+------+-----+-------------------+----------------+
| Field      | Type          | Null | Key | Default           | Extra          |
+------------+---------------+------+-----+-------------------+----------------+
| id         | int(11)       | NO   | PRI | NULL              | auto_increment |
| domain_id  | int(11)       | NO   | MUL | NULL              |                |
| url        | varchar(250)  | NO   | UNI | 0                 |                |
| visited    | enum('Y','N') | NO   |     | N                 |                |
| updated    | timestamp     | NO   |     | CURRENT_TIMESTAMP |                |
| hits       | smallint(6)   | NO   |     | 0                 |                |
| stop_visit | enum('Y','N') | NO   |     | N                 |                |
+------------+---------------+------+-----+-------------------+----------------+

The suspicious query was:

SELECT id FROM tracker WHERE updated<=NOW() and domain_id=2 and stop_visit='N' LIMIT 1;

There was a BTREE index on (updated,domain_id,stop_visit) so the explain plan gave nothing out. Then I tried querying the profiling like this:

 SET profiling=1;
 SHOW profiles;
 SET @query_id=1
 SELECT STATE, SUM(DURATION) AS Total_R,
 ROUND(
 100 * SUM(DURATION) /
 (SELECT SUM(DURATION)
 FROM INFORMATION_SCHEMA.PROFILING
 WHERE QUERY_ID = @query_id
 ), 2) AS Pct_R,
 COUNT(*) AS Calls,
 SUM(DURATION) / COUNT(*) AS "R/Call"
 FROM INFORMATION_SCHEMA.PROFILING
 WHERE QUERY_ID = @query_id
 GROUP BY STATE
 ORDER BY Total_R DESC;

Nothing wrong was observed and the query was executing with timings under 0.001. No temporary tables, indexes are used... Everything looks OK but obviously there is a underlying problem that I knew it was there.

SHOW STATUS and FLUSH STATUS showed something really weird:

 FLUSH status;
 SELECT id FROM tracker WHERE updated<=NOW() and domain_id=2 and stop_visit='N' LIMIT 1;
 show status where variable_name like 'Created%' or variable_name like 'Handler%';

+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Created_tmp_disk_tables    | 0     |
| Created_tmp_files          | 6     |
| Created_tmp_tables         | 0     |
| Handler_commit             | 0     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 0     |
| Handler_read_last          | 0     |
| Handler_read_next          | 44687 |
| Handler_read_prev          | 0     |
| Handler_read_rnd           | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+

Now I thought why is Handler_read_next so high when the index was tailored to be selective (or i thought so). Well it wasn't. And more importantly I still don't have an answer to this question. After a bunch of random tries I found out that the ENUM column (stop_visit) was causing this very high Handler_read_next value. Changing the datatype to tinyint [0,1] or char(1) ['Y','N'] rewarded me with nothing.

At this point, I decided to break everything and re-start from scratch with the knowledge acquired. This resulted in the following changes to the initial table:

+-----------+---------------------+------+-----+-------------------+----------------+
| Field     | Type                | Null | Key | Default           | Extra          |
+-----------+---------------------+------+-----+-------------------+----------------+
| id        | bigint(20) unsigned | NO   | PRI | NULL              | auto_increment |
| url_crc   | int(10) unsigned    | NO   | MUL | NULL              |                |
| updated   | timestamp           | NO   | MUL | CURRENT_TIMESTAMP |                |
| domain_id | tinyint(3) unsigned | NO   |     | NULL              |                |
| owner     | int(10) unsigned    | NO   | MUL | 0                 |                |
| url       | varchar(255)        | NO   |     | NULL              |                |
| hits      | tinyint(3) unsigned | NO   |     | 0                 |                |
+-----------+---------------------+------+-----+-------------------+----------------+

The previous multi-column index became a single column index ALTER table tracker add index idx_updated (updated).

The result was a query that did not do any Handler_read_next operations. Instead it was gracefully incrementing Handler_read_key and Handler_read_first by 1.

Another obscure problem was solved by using a method described in this book used to access VARCHAR datatypes. I had this UNIQUE index on the url column previously, and I used to INSERT IGNORE on this big table thinking that trusting the UNIQUE constraint was the way to go. So I thought, if Mysql has to go through all the rows to INSERT this new url it is gonna be painful. Reason is approximate 40 INSERT IGNORE every 0.001 (as soon as the first query finished) with average 50 concurrent clients.

So I changed this behavior by using a crc32 integer index. And then just doing a read like so:

  SELECT * from tracker WHERE url_crc=crc32('http://google.com') and url='http://google.com'

There is still 40 SELECT like those every 0.001 but at least I can easily profile them. So I decided to stick with this for the moment.

After all those changes were made, the time to validate all the work came.

Again from this great book 3 simple methods:

> while true; do sleep 1; mysql -e 'SHOW PROCESSLIST\G' | grep State: | sort | uniq -c | sort -rn; done

> mysqladmin ext -i1 | awk 'BEGIN{printf "%5s %5s %5s %5s %5s %5s %5s\n","QPS","Thcon","Thrun","Opentb","tmp_tbl","FreePages","Bytessent"}/Queries/{q=$4-qp;qp=$4}/Threads_connected/{tc=$4}/Created_tmp_disk_tables/{tmp=$4}/Opened_tables/{ot=$4}/Innodb_buffer_pool_pages_free/{pf=$4}/Bytes_sent/{bs=$4}/Threads_running/{printf "%5d %5d %5d %5d %5d %10d %10d\n",q,tc,$4,ot,tmp,pf,bs}'

> awk '/^# Time:/{print $3, $4, c;c=0}/^# User/{c++}' mysql-slow.log

The first command will help to spot those states that are not normal. It will be also the start of more advanced profiling, but I won't cover those aspects here. That command helped me to find out that the query cache was doing more harm than good.

The second command is made to check the STATUS of the server and see how it is evolving. A problem can be quickly spotted just by looking in the output:

QPS    Th_con Th_run Opened_files tmp_disk free_pages bytes_sent
466    22     7   276    54     120658   30110619
401    22     6   276    54     120657   30145343
405    22     9   276    54     120657   30179509
=>85    22     5   276    54     120658   30196291

The sudden drop of the QPS to 85 is an alert that something is going wrong. In my case, the query_log revealed a huge quantity of updates. That was caused by a caching table that wasn't flushing in a cool way for MySQL.

With all those improvements I managed to DoS my router kernel: [539677.201824] nf_conntrack: table full, dropping packet.. That was a first :p

So I think that is all, time to thank the authors of the great book 'High Performance MySQL' and the community here for all the relevant posts.