2

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:

  • Check if the queries are slow to execute or only waiting on some locks in these cases (there should be a lock_time written in the slow log). Use pt-query-digest to better analyze the slow queries. – jkavalik Oct 16 '15 at 13:24
  • lock_time is showing as 0.0000 in all cases. I'll check out pt-query-digest now. Thanks! – gazareth Oct 16 '15 at 13:47
  • Do you have any monitoring tools on the server (zabbix/nagios etc.)? So you could check the time when the slow query "happened" and see if there was some unusual spike on CPU/IO/Memory. – jkavalik Oct 16 '15 at 21:12
  • 1
    jonathanlevin.co.uk/2012/01/query-digest-on-windows.html but you can upload the log to any linux with perl if you have some accessible and just do it there (even virtual will do). – jkavalik Oct 19 '15 at 11:13
  • 1
    What is strange is that the times are inconsistent - to me that points to the disk being the bottleneck. That might explain why it's fine at times (say you are the only person querying the database at that time), but then if 20 people are requesting data from the same time, that might be causing the bottleneck. The 7320 joins without indexes would also be a cause for concern for me - if you are having to do full table reads, particularly on large tables, that's not going to be helping either. Unfortunately Windows isn't really my bag, and without seeing the queries, hard to make suggestions! – Liam Wiltshire Oct 19 '15 at 14:24
1

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.

  • Thank you for your answer. Please see updated info in OP. To date, I have been unable to get pt-query-digest to work on Windows (have tried cygwin and Strawberry perl). – gazareth Oct 23 '15 at 14:15
  • See if mysqldumpslow -s t will work on Windows. dev.mysql.com/doc/refman/5.5/en/mysqldumpslow.html . – Rick James Oct 23 '15 at 22:25
  • Note that the 23OCT changes mostly involved indexes and app changes, not tuning. So, continue to focus on the 'worst' queries. Sometimes that will lead to changing a tunable, but rarely. – Rick James Oct 23 '15 at 22:28
  • Sample query & EXPLAIN added to OP. – gazareth Oct 27 '15 at 11:51
  • "took 7.08 seconds. Rows sent: 10, rows examined: 40" -- What else was going on at the same time? Even with a slow disk and a very cold cache, that should have taken more than 1 second. – Rick James Oct 30 '15 at 13:58

Your Answer

By clicking "Post Your Answer", you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.