MySQL performance issue – intermittently slow queries

MySQLmysql-5.5performancequery-performance

I manage an intranet application used by around 50 staff in a few locations. The application is hosted on a Windows Server 2008 VM with 8GB RAM and MySQL (5.5) is running on the same server as IIS.

I have slow query logging enabled and noticed that certain queries are intermittently slow. For example, some queries are logging as taking 13 seconds but then when I try the same query in the MySQL client on my machine (or on the server), they are fast (~0.1 second).

A few weeks ago I ran mysqlcheck --auto-repair --optimize --all-databases and it seemed to help things – the query log was not nearly as densely populated. However, this week things have returned to how they were before with various queries taking a long time intermittently.

I have one query which the slow query log has recorded as taking 8.3 seconds this morning. I ran it 5 or 6 times from the CLI and twice it was ~2 seconds and the rest were less than 0.2 seconds.

All of the slow queries are SELECT though I have seen a very small number of INSERT taking just over one second.

All tables are InnoDB. Here are the InnoDB variables as shown by show variables:


+---------------------------------+------------------------+
| Variable_name | Value |
+---------------------------------+------------------------+
| have_innodb | YES |
| ignore_builtin_innodb | OFF |
| innodb_adaptive_flushing | ON |
| innodb_adaptive_hash_index | ON |
| innodb_additional_mem_pool_size | 27262976 |
| innodb_autoextend_increment | 8 |
| innodb_autoinc_lock_mode | 1 |
| innodb_buffer_pool_instances | 1 |
| innodb_buffer_pool_size | 2097152000 |
| innodb_change_buffering | all |
| innodb_checksums | ON |
| innodb_commit_concurrency | 0 |
| innodb_concurrency_tickets | 500 |
| innodb_data_file_path | ibdata1:10M:autoextend |
| innodb_data_home_dir | |
| innodb_doublewrite | ON |
| innodb_fast_shutdown | 1 |
| innodb_file_format | Antelope |
| innodb_file_format_check | ON |
| innodb_file_format_max | Antelope |
| innodb_file_per_table | OFF |
| innodb_flush_log_at_trx_commit | 1 |
| innodb_flush_method | |
| innodb_force_load_corrupted | OFF |
| innodb_force_recovery | 0 |
| innodb_io_capacity | 2000 |
| innodb_large_prefix | OFF |
| innodb_lock_wait_timeout | 50 |
| innodb_locks_unsafe_for_binlog | OFF |
| innodb_log_buffer_size | 13631488 |
| innodb_log_file_size | 652214272 |
| innodb_log_files_in_group | 2 |
| innodb_log_group_home_dir | .\ |
| innodb_max_dirty_pages_pct | 75 |
| innodb_max_purge_lag | 0 |
| innodb_mirrored_log_groups | 1 |
| innodb_old_blocks_pct | 37 |
| innodb_old_blocks_time | 0 |
| innodb_open_files | 300 |
| innodb_purge_batch_size | 20 |
| innodb_purge_threads | 0 |
| innodb_random_read_ahead | OFF |
| innodb_read_ahead_threshold | 56 |
| innodb_read_io_threads | 64 |
| innodb_replication_delay | 0 |
| innodb_rollback_on_timeout | OFF |
| innodb_rollback_segments | 128 |
| innodb_spin_wait_delay | 6 |
| innodb_stats_method | nulls_equal |
| innodb_stats_on_metadata | ON |
| innodb_stats_sample_pages | 8 |
| innodb_strict_mode | OFF |
| innodb_support_xa | ON |
| innodb_sync_spin_loops | 30 |
| innodb_table_locks | ON |
| innodb_thread_concurrency | 0 |
| innodb_thread_sleep_delay | 10000 |
| innodb_use_native_aio | ON |
| innodb_use_sys_malloc | ON |
| innodb_version | 1.1.8 |
| innodb_write_io_threads | 64 |
+---------------------------------+------------------------+

What things should I be looking at or monitoring at this point? I am looking into the possibility of getting a dedicated database server in case there are memory or disk I/O resource issues vs IIS, but this may not be feasible.

I am reluctant to share specific queries here for commercial confidentiality reasons and appreciate that may not be helpful!

Additional info

I ran MySQL Tuner for Windows and got the following findings:

– Assuming 8000 MB of physical memory
– Assuming 12286 MB of swap space
– Currently running supported MySQL version 5.5.24-log
– InnoDB Engine Installed
– Data in InnoDB tables: 575M (Tables: 194)
– Total fragmented tables: 194
– All database users have passwords assigned
– Up for: 1d 7h 44m 38s (982K q [8.000 qps], 41K conn, TX: 15G, RX: 839M)
– Reads / Writes: 98% / 2%
– Total buffers: 2.6G global + 960.0K per thread (400 max threads)
– Maximum possible memory usage: 3.0G (38% of installed RAM)
– Slow queries: 1% (476/982K)
– Highest usage of available connections: 2% (7/400)
– Key buffer size / total MyISAM indexes: 641.0M/263.0K
– Key buffer hit rate: 99% (2M cached / 7 reads)
– Query cache is disabled
– Sorts requiring temporary tables: 6% (5K temp sorts / 102K sorts)
– Joins performed without indexes: 7320
– Temporary tables created on disk: 38% (31K on disk / 84K total)
– Thread cache hit rate: 99% (7 created / 41K connections)
– Table cache hit rate: 1% (155 open / 9K opened)
– Open file limit used: 0% (3/4K)
– Table locks acquired immediately: 100% (1M immediate / 1M locks)
– InnoDB data size / buffer pool: 575.2M/2.0G
– Run OPTIMIZE TABLE to defragment tables for better performance
– Adjust your join queries to always utilize indexes
– When making adjustments, make tmp_table_size/max_heap_table_size equal
– Reduce your SELECT DISTINCT queries without LIMIT clauses
– Increase table_cache gradually to avoid file descriptor limits
– query_cache_size (>= 8M)
– join_buffer_size (> 128.0K, or always use indexes with joins)
– tmp_table_size (> 64M)
– max_heap_table_size (> 16M)
– table_cache (> 256)

Update 23OCT2015

On Monday evening I tweaked a few config variables – join_buffer_size, sort_buffer_size and table_open_cache. On Tuesday I spent an hour going through the whole database and adding indexes to almost all columns used in joins (I may have missed a few). I then made a few in-app changes which have resulted in a) some better queries and b) fewer queries on (relatively) high-traffic pages.

Pre-changes, Monday's slow query log had 474 queries >1 second. Post-indexing Tuesday had 220 queries >1 second; by Thursday, with app changes, it was down to 110 queries >1 second. I'm expecting another drop today after I made an app update this morning. I do still have some queries which are intermittently slow, with decent EXPLAIN profiles. Updated tuner output is below, and I will provide some sample queries with EXPLAIN and SHOW CREATE TABLE after I have a collected a good size sample from the latest app.

Updated tuner output. I restarted MySQL this morning so there isn't quite as much data as in my original post. For some reason it is not outputting the number of joins performed without indexes anymore…

  • Assuming 8000 MB of physical memory
  • Assuming 12286 MB of swap space
  • Currently running supported MySQL version 5.5.24-log
  • Archive Engine Installed
  • Berkeley DB Engine Not Installed
  • Federated Engine Not Installed
  • InnoDB Engine Installed
  • ISAM Engine Not Installed
  • NDBCLUSTER Engine Not Installed
  • Data in InnoDB tables: 576M (Tables: 192)
  • Data in MyISAM tables: 1M (Tables: 19)
  • Total fragmented tables: 192
  • All database users have passwords assigned
  • Up for: 6h 37m 51s (216K q [9.000 qps], 10K conn, TX: 2G, RX: 174M)
  • Reads / Writes: 87% / 13%
  • Total buffers: 2.6G global + 4.6M per thread (400 max threads)
  • Maximum possible memory usage: 4.4G (56% of installed RAM)
  • Slow queries: 1% (53/216K) (0.02%, previously 0.04%)
  • Highest usage of available connections: 2% (8/400)
  • Key buffer size / total MyISAM indexes: 641.0M/255.0K
  • Key buffer hit rate: 99% (772K cached / 12 reads)
  • Query cache is disabled
  • Sorts requiring temporary tables: 1% (167 temp sorts / 24K sorts) Down from 6%
  • Temporary tables created on disk: 36% (5K on disk / 15K total) Down from 38%
  • Thread cache hit rate: 99% (8 created / 10K connections)
  • Table cache hit rate: 9% (211 open / 2K opened) Up from 1%
  • Open file limit used: 0% (1/4K)
  • Table locks acquired immediately: 100% (359K immediate / 359K locks)
  • InnoDB data size / buffer pool: 576.6M/2.0G
  • Run OPTIMIZE TABLE to defragment tables for better performance
  • MySQL started within last 24 hours – recommendations may be inaccurate
  • When making adjustments, make tmp_table_size/max_heap_table_size equal
  • Reduce your SELECT DISTINCT queries without LIMIT clauses
  • Increase table_cache gradually to avoid file descriptor limits
  • query_cache_size (>= 8M)
  • tmp_table_size (> 64M)
  • max_heap_table_size (> 16M)
  • table_cache (> 512)

Example query

This one ran this morning at 8:47am and took 7.08 seconds. Rows sent: 10, rows examined: 40.

Running the same query in MySQL client takes 0.06 seconds.

SELECT  ProjectFile.id, ProjectFile.project_id, ProjectFile.document_type,
        ProjectFile.name, ProjectFile.project_file_type_id, ProjectFile.created,
        ProjectFileType.id, ProjectFileType.name, ProjectFileType.is_archived
    FROM  db.project_files AS ProjectFile
    LEFT JOIN  db.project_file_types AS ProjectFileType
        ON (ProjectFile.project_file_type_id = ProjectFileType.id)
    WHERE  ProjectFile.project_id = 19319
    ORDER BY  ProjectFileType.name ASC, ProjectFile.name ASC;

EXPLAIN output:

*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: ProjectFile
type: ref
possible_keys: project_id
key: project_id
key_len: 5
ref: const
rows: 10
Extra: Using where; Using temporary; Using filesort
*************************** 2. row ***************************
id: 1
select_type: SIMPLE
table: ProjectFileType
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: db.ProjectFile.project_file_type_id
rows: 1
Extra:

Best Answer

Comments about that Tuner output:

Data in InnoDB tables: 575M (Tables: 194)
Total fragmented tables: 194
Run OPTIMIZE TABLE to defragment tables for better performance

Notice how all InnoDB tables are fragmented? That is the nature of how it is implemented. Do not bother running OPTIMIZE; it will almost never provide substantive benefit.

Joins performed without indexes: 7320

Irrelevant if the tables are tiny. The important ones will show up in the slowlog even without log_queries_not_using_indexes. (Leave that setting off; it only clutters the slowlog.)

Temporary tables created on disk: 38% (31K on disk / 84K total)
Slow queries: 1% (476/982K)

Let's see the worst ones. Please provide EXPLAIN and SHOW CREATE TABLE. I recommend long_query_time of 2 or lower.

Don't increase any of the last 5 items from Tuner.

The rest of Tuner's comments are reasonable.

Next step

Get the output from pt-query-digest and let's see the first couple, plus EXPLAIN and SHOW CREATE TABLE.