Mysql – Is our MySQL poor performance related to excessive daily query cache prunes

cacheMySQLmysql-5.6performance

We are experiencing a high number of query cache prunes per day, currently 80851746. MySQL really struggles even under a reasonable load of say 50+ concurrent connections.

The host is a Physical Server with SSDs configured as RAID 5, 24 cores and 128GB RAM. It is a dedicated MySQL 5.6 server and is accessed by various PHP clients.

The instance consists of 3 databases with a total size of 1TB, all tables are InnoDB and compressed.

I've included as much information as possible below, any advice would be much appreciated. I can provide more information if needed. Thanks.

OS Information

# lsb_release -a
Distributor ID: Ubuntu
Description:    Ubuntu 14.04.5 LTS
Release:    14.04
Codename:   trusty

# uname -a
Linux xxxxxxxxxx 3.13.0-32-generic #57-Ubuntu SMP Tue Jul 15 03:51:08 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

Memory Information

# free -m
             total       used       free     shared    buffers     cached
Mem:        128915     128335        580          0        396      78764
-/+ buffers/cache:      49174      79740
Swap:        30517        192      30325

CPU Information

# cat /proc/cpuinfo
processor   : 0
vendor_id   : GenuineIntel
cpu family  : 6
model       : 45
model name  : Intel(R) Xeon(R) CPU E5-2640 0 @ 2.50GHz
stepping    : 7
microcode   : 0x704
cpu MHz     : 1200.000
cache size  : 15360 KB
physical id : 0
siblings    : 12
core id     : 0
cpu cores   : 6
apicid      : 0
initial apicid  : 0
fpu     : yes
fpu_exception   : yes
cpuid level : 13
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 s
s ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eag
erfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadli
ne_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dtherm tpr_shadow vnmi flexpriority ept vpid
bogomips    : 4999.98
clflush size    : 64
cache_alignment : 64
address sizes   : 46 bits physical, 48 bits virtual
power management:

# top
top - 10:48:41 up 94 days, 18:37,  5 users,  load average: 8.69, 9.65, 9.85
Tasks: 385 total,   1 running, 383 sleeping,   0 stopped,   1 zombie
%Cpu0  : 19.7 us,  5.0 sy,  0.0 ni, 71.3 id,  1.0 wa,  3.0 hi,  0.0 si,  0.0 st
%Cpu1  : 15.3 us,  3.3 sy,  0.0 ni, 81.0 id,  0.0 wa,  0.3 hi,  0.0 si,  0.0 st
%Cpu2  : 24.1 us,  5.7 sy,  0.0 ni, 66.6 id,  1.0 wa,  2.7 hi,  0.0 si,  0.0 st
%Cpu3  : 12.7 us,  3.3 sy,  0.0 ni, 83.7 id,  0.3 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu4  :  4.0 us,  2.0 sy,  0.0 ni, 93.4 id,  0.3 wa,  0.3 hi,  0.0 si,  0.0 st
%Cpu5  : 14.7 us,  4.0 sy,  0.0 ni, 80.0 id,  0.7 wa,  0.7 hi,  0.0 si,  0.0 st
%Cpu6  : 17.1 us,  3.7 sy,  0.0 ni, 76.9 id,  1.7 wa,  0.7 hi,  0.0 si,  0.0 st
%Cpu7  : 42.5 us,  7.0 sy,  0.0 ni, 49.5 id,  0.7 wa,  0.3 hi,  0.0 si,  0.0 st
%Cpu8  : 37.3 us,  2.7 sy,  0.0 ni, 58.7 id,  0.7 wa,  0.7 hi,  0.0 si,  0.0 st
%Cpu9  : 33.3 us,  4.3 sy,  0.0 ni, 60.3 id,  0.3 wa,  1.7 hi,  0.0 si,  0.0 st
%Cpu10 : 17.3 us,  5.0 sy,  0.0 ni, 75.0 id,  0.7 wa,  2.0 hi,  0.0 si,  0.0 st
%Cpu11 : 17.7 us,  4.0 sy,  0.0 ni, 76.7 id,  1.3 wa,  0.3 hi,  0.0 si,  0.0 st
%Cpu12 :  0.3 us,  0.3 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu13 : 17.8 us,  4.4 sy,  0.0 ni, 75.8 id,  0.0 wa,  2.0 hi,  0.0 si,  0.0 st
%Cpu14 :  1.0 us,  0.3 sy,  0.0 ni, 98.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu15 :  0.3 us,  0.3 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu16 : 25.3 us,  4.3 sy,  0.0 ni, 68.0 id,  0.3 wa,  2.0 hi,  0.0 si,  0.0 st
%Cpu17 :  0.0 us,  0.3 sy,  0.0 ni, 99.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu18 : 27.0 us,  1.0 sy,  0.0 ni, 71.3 id,  0.7 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu19 :  1.3 us,  0.7 sy,  0.0 ni, 98.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu20 : 25.9 us,  0.3 sy,  0.0 ni, 73.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu21 :  5.7 us,  2.3 sy,  0.0 ni, 92.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu22 : 51.3 us,  4.7 sy,  0.0 ni, 41.0 id,  0.7 wa,  2.3 hi,  0.0 si,  0.0 st
%Cpu23 : 35.3 us,  9.7 sy,  0.0 ni, 51.7 id,  1.0 wa,  2.3 hi,  0.0 si,  0.0 st
KiB Mem:  13200956+total, 13146136+used,   548208 free,   406712 buffers
KiB Swap: 31250428 total,   198052 used, 31052376 free. 80715696 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                  
13928 mysql     20   0 56.424g 0.044t  10028 S 517.3 35.4   9937:02 mysqld                                                   
  540 root      20   0       0      0      0 S   6.0  0.0   2392:26 jbd2/sdb1-8

Storage Information

# dmesg
[    6.615531] megasas: 0x1000:0x005b:0x1000:0x9266: bus 4:slot 0:func 0
[    6.742104] megasas: FW now in Ready state
[    6.784030] megaraid_sas 0000:04:00.0: irq 94 for MSI/MSI-X
[    6.784042] megaraid_sas 0000:04:00.0: irq 95 for MSI/MSI-X
[    6.784051] megaraid_sas 0000:04:00.0: irq 96 for MSI/MSI-X
[    6.784058] megaraid_sas 0000:04:00.0: irq 97 for MSI/MSI-X
[    6.784065] megaraid_sas 0000:04:00.0: irq 98 for MSI/MSI-X
[    6.784072] megaraid_sas 0000:04:00.0: irq 99 for MSI/MSI-X
[    6.784093] megaraid_sas 0000:04:00.0: irq 100 for MSI/MSI-X
[    6.784100] megaraid_sas 0000:04:00.0: irq 101 for MSI/MSI-X
[    6.784106] megaraid_sas 0000:04:00.0: irq 102 for MSI/MSI-X
[    6.784112] megaraid_sas 0000:04:00.0: irq 103 for MSI/MSI-X
[    6.784119] megaraid_sas 0000:04:00.0: irq 104 for MSI/MSI-X
[    6.784125] megaraid_sas 0000:04:00.0: irq 105 for MSI/MSI-X
[    6.784131] megaraid_sas 0000:04:00.0: irq 106 for MSI/MSI-X
[    6.784137] megaraid_sas 0000:04:00.0: irq 107 for MSI/MSI-X
[    6.784155] megaraid_sas 0000:04:00.0: irq 108 for MSI/MSI-X
[    6.784162] megaraid_sas 0000:04:00.0: irq 109 for MSI/MSI-X
[    6.784204] megaraid_sas 0000:04:00.0: [scsi0]: FW supports<16> MSIX vector,Online CPUs: <24>,Current MSIX <16>
[    6.869100] md: multipath personality registered for level -4
[    6.893842] megasas:IOC Init cmd success
[    6.917873] megasas: INIT adapter done
[    6.989936] megaraid_sas 0000:04:00.0: Controller type: MR,Memory size is: 1024MB
[    6.990092] scsi0 : LSI SAS based MegaRAID driver
[    6.990290] scsi 0:0:0:0: Direct-Access     LSI      MR9266-8i        3.16 PQ: 0 ANSI: 5
[    6.990374] scsi 0:0:1:0: Direct-Access     LSI      MR9266-8i        3.16 PQ: 0 ANSI: 5
[    6.991442] scsi 0:0:17:0: Enclosure         LSI CORP SAS2X28          0717 PQ: 0 ANSI: 5
[    7.002766] scsi 0:2:0:0: Direct-Access     LSI      MR9266-8i        3.16 PQ: 0 ANSI: 5
[    7.002869] scsi 0:2:1:0: Direct-Access     LSI      MR9266-8i        3.16 PQ: 0 ANSI: 5
[    7.008930] scsi 0:0:17:0: Attached scsi generic sg0 type 13
[    7.009066] sd 0:2:0:0: Attached scsi generic sg1 type 0
[    7.009080] sd 0:2:0:0: [sda] 2342125568 512-byte logical blocks: (1.19 TB/1.08 TiB)
[    7.009145] sd 0:2:0:0: [sda] Write Protect is off
[    7.009146] sd 0:2:0:0: [sda] Mode Sense: 1f 00 00 08
[    7.009188] sd 0:2:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    7.009212] sd 0:2:1:0: Attached scsi generic sg2 type 0
[    7.009230] sd 0:2:1:0: [sdb] 8197439488 512-byte logical blocks: (4.19 TB/3.81 TiB)
[    7.009289] sd 0:2:1:0: [sdb] Write Protect is off
[    7.009290] sd 0:2:1:0: [sdb] Mode Sense: 1f 00 00 08
[    7.009343] sd 0:2:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    7.017925]  sda: sda1 sda2 sda3 sda4
[    7.018501] sd 0:2:0:0: [sda] Attached SCSI disk
[    7.028790]  sdb: sdb1
[    7.029058] sd 0:2:1:0: [sdb] Attached SCSI disk

# df -h
Filesystem      Size  Used Avail Use% Mounted on
udev             63G   12K   63G   1% /dev
tmpfs            13G  1.1M   13G   1% /run
/dev/sda1        19G  5.3G   13G  31% /
none            4.0K     0  4.0K   0% /sys/fs/cgroup
none            5.0M     0  5.0M   0% /run/lock
none             63G   12K   63G   1% /run/shm
none            100M     0  100M   0% /run/user
/dev/sda3       9.1G  2.7G  6.0G  31% /var
/dev/sdb1       3.8T  1.5T  2.1T  42% /data
tmpfs            48G   96K   48G   1% /mysql_tmp

MySQL Information

# service mysql status
 * /usr/bin/mysqladmin  Ver 8.42 Distrib 5.6.36-82.1, for debian-linux-gnu on x86_64
Copyright (c) 2009-2017 Percona LLC and/or its affiliates
Copyright (c) 2000, 2017, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Server version      5.6.36-82.1-log
Protocol version    10
Connection      Localhost via UNIX socket
UNIX socket     /var/run/mysqld/mysqld.sock
Uptime:         1 day 1 hour 56 min 7 sec

Threads: 640  Questions: 730887058  Slow queries: 3189910  Opens: 3837  Flush tables: 1  Open tables: 2006  Queries per second avg: 7828.109

MySQL my.cnf

[mysqld]
character-set-server            = utf8
collation-server                = utf8_unicode_ci
server-id                       = 20
user                            = mysql
pid-file                        = /run/mysqld/mysqld.pid
socket                          = /run/mysqld/mysqld.sock
bind-address                    = 0.0.0.0
skip-name-resolve
tmpdir                          = /mysql_tmp
datadir                         = /data/mysql/
default-storage-engine          = InnoDB
myisam-recover-options          = FORCE,BACKUP

binlog_format                   = mixed
log_bin                         = /data/mysql/binlog/mysql-bin
expire-logs-days                = 4
sync_binlog                     = 1
slave-net-timeout               = 60

max-connections                 = 2000
interactive_timeout             = 14400
wait_timeout                    = 14400

tmp-table-size                  = 1024M
max-heap-table-size             = 1024M
query-cache-type                = 1
query-cache-size                = 33554432
thread-cache-size               = 100
open-files-limit                = 65535
table-definition-cache          = 4096
table-open-cache                = 4096
key-buffer-size                 = 32M
max-allowed-packet              = 16M
max-connect-errors              = 1000000

innodb-flush-method             = O_DIRECT
innodb-log-files-in-group       = 2
innodb-log-file-size            = 4G
innodb-buffer-pool-size         = 40G
innodb-file-per-table           = 1
innodb_file-format              = Barracuda
innodb-flush-log-at-trx-commit  = 1
innodb_support_xa               = 1

log-error                       = /var/log/mysql/mysql-error.log
log-warnings                    = 2
slow-query-log                  = 1
slow-query-log-file             = /var/log/mysql/mysql-slow.log

mysqltune Output

# mysqltuner 

 >>  MySQLTuner 1.1.1 - Major Hayden <major@mhtx.net>

-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.6.36-82.1-log
[OK] Operating on 64-bit architecture

-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB -Federated +InnoDB -ISAM -NDBCluster 
[--] Data in InnoDB tables: 778G (Tables: 399)
[--] Data in PERFORMANCE_SCHEMA tables: 0B (Tables: 52)
[!!] Total fragmented tables: 80

-------- Security Recommendations  -------------------------------------------
[OK] All database users have passwords assigned

-------- Performance Metrics -------------------------------------------------
[--] Up for: 1d 2h 22m 29s (728M q [7K qps], 19M conn, TX: 1773B, RX: 95B)
[--] Reads / Writes: 80% / 20%
[--] Total buffers: 41.1G global + 1.1M per thread (2000 max threads)
[OK] Maximum possible memory usage: 43.3G (34% of installed RAM)
[OK] Slow queries: 0% (3M/728M)
[OK] Highest usage of available connections: 51% (1029/2000)
[OK] Key buffer size / total MyISAM indexes: 32.0M/109.0K
[OK] Key buffer hit rate: 100.0% (1B cached / 15 reads)
[OK] Query cache efficiency: 52.9% (301M cached / 569M selects)
[!!] Query cache prunes per day: 80851746
[OK] Sorts requiring temporary tables: 1% (208K temp sorts / 13M sorts)
[!!] Joins performed without indexes: 60354
[!!] Temporary tables created on disk: 49% (49M on disk / 98M total)
[OK] Thread cache hit rate: 99% (9K created / 19M connections)
[OK] Table cache hit rate: 52% (2K open / 3K opened)
[OK] Open file limit used: 0% (81/65K)
[OK] Table locks acquired immediately: 100% (349M immediate / 349M locks)
[!!] InnoDB data size / buffer pool: 778.6G/40.0G

-------- Recommendations -----------------------------------------------------
General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
    Adjust your join queries to always utilize indexes
    Temporary table size is already large - reduce result set size
    Reduce your SELECT DISTINCT queries without LIMIT clauses
Variables to adjust:
    query_cache_size (> 32M)
    join_buffer_size (> 256.0K, or always use indexes with joins)
    innodb_buffer_pool_size (>= 778G)

Best Answer

I would yes for one reason: InnoDB and the Query Cache are not good neighbors. Why ?

On Jun 07, 2014, I answered the question Why query_cache_type is disabled by default start from MySQL 5.6?. In that post, I poetically described how InnoDB man-handles the Query Cache. I originally got that information from Pages 209-215 of High Performance MySQL (2nd Edition).

I have recommended people disable their query cache before:

Sep 25, 2013 : invalidating query cache entries(key)
Sep 26, 2013 : query cache hit value is not changing in my database
Dec 23, 2013 : MySQL with high CPU and memory usage

RECOMMENDATIONS

Disable your query cache by setting query_cache_size and query_cache_type to 0. If things improve, all, well and good. If it does not improve, you must do three(3) things

Set query_cache_type back to 1
query_cache_size
- You have it set right now at 32M (33554432)
- Please increase it
query_cache_limit
- You do not have it set. The default is 1M.
- With a query_cache_size of 32M, you can only hold, at the very least, 32 results that are 1M each. If you have smaller results sets going into the query cache, this might crowd the query cache and would cause lots of prunes because there is no elbow room for new incoming results sets.

HEADS UP !!!

If you are using MySQL 5.7.19 or prior, please read the MySQL Documentation on Query Cache Configuration for more authoritative advice.

For all those using MySQL 5.7.20 and beyond, the query cache is deprecated and will go away.

Related Solutions

MySQL Tables crashing randomly

Generally, tables will become corrupt only when a write operation is interrupted. MySQL uses a write() system call, so even if the server crashes, as long as the OS is still operative the data will be safe.

If many different tables are getting repeatedly corrupted, I would suspect hardware problems first. Have the system taken down and RAM and the hard drives tested. Bad RAM cells or disk sectors can lead to this type of table corruption.

After the above hardware checks, before you start up mysqld, I would make sure you are starting with a clean slate by running myisamchk --silent --force */*.MYI first. Then start mysqld. If corruption occurs again, check the error log for a corresponding system crash. If you find corruption even in the absence of a mysqld crash, you may have found a bug: Try to isolate a particular query that occurs just before (you'll need to have the general query log enabled). If you can kill the server with a specific query repeatedly, you have found a bug and should submit it.

If you are running multiple instances of mysqld, or running myisamchk while mysqld is running, it might be that the lock manager for your system is not working properly. If you are NOT running multiple instances, try using the --skip-external-locking option to remove the lock manager from the mix of possibilities.

Some versions come with testing tools. They are in a directory call mysql-test and/or mysql-bench or similar. Try those out. Also try to emulate your application on a different system to see if you can replicate the crashes/corruption.

Mysql – How to debug a db memory-leak causing thesql to go before it’s own limits

...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.