So my database has been running great for a while, and all of a sudden I’m seeing a lot of long running queries (that have been optimized and have been running fine) and my servers io wait starts growing to ~30%. My database is 22 GB, and all but one of my tables are InnoDB. The DB is doing around 1,000 qps.
My DB traffic stays pretty consistent so increased traffic doesn’t seem to cause the high io wait times. The only thing I can think of that has changed is the number of rows in my tables. I’ve got 2 tables that are around 30 million rows.
I’m not a dba. I have done quite a bit of reading on Mysql performance, though, and have tried to tune the Mysql as best I can. I assume our problems are coming from something being configured incorrectly.
Any help would be greatly appreciated.
Server Info
- CPU 4 x Dual Core AMD Opteron™ Processor 270
- RAM 15 GB
Linux
- Version 2.6.16.33-xenU (gcc version 4.1.1 20070105 (Red Hat 4.1.1-52)) #2 SMP
- Ubuntu 7.10 gutsy
Mysql
-
Version 5.0.45-Debian_1ubuntu3-log
-
SHOW GLOBAL VARIABLES;
| auto_increment_increment | 1 |
| auto_increment_offset | 1 |
| automatic_sp_privileges | ON |
| back_log | 50 |
| basedir | /usr/ |
| binlog_cache_size | 32768 |
| bulk_insert_buffer_size | 8388608 |
| character_set_client | latin1 |
| character_set_connection | latin1 |
| character_set_database | latin1 |
| character_set_filesystem | binary |
| character_set_results | latin1 |
| character_set_server | latin1 |
| character_set_system | utf8 |
| character_sets_dir | /usr/share/mysql/charsets/ |
| collation_connection | latin1_swedish_ci |
| collation_database | latin1_swedish_ci |
| collation_server | latin1_swedish_ci |
| completion_type | 0 |
| concurrent_insert | 1 |
| connect_timeout | 5 |
| datadir | /mnt/mysql_data/ |
| date_format | %Y-%m-%d |
| datetime_format | %Y-%m-%d %H:%i:%s |
| default_week_format | 0 |
| delay_key_write | ON |
| delayed_insert_limit | 100 |
| delayed_insert_timeout | 300 |
| delayed_queue_size | 1000 |
| div_precision_increment | 4 |
| engine_condition_pushdown | OFF |
| expire_logs_days | 10 |
| flush | OFF |
| flush_time | 0 |
| ft_boolean_syntax | + -><()~*:“”&| |
| ft_max_word_len | 84 |
| ft_min_word_len | 4 |
| ft_query_expansion_limit | 20 |
| ft_stopword_file | (built-in) |
| group_concat_max_len | 1024 |
| have_archive | YES |
| have_bdb | NO |
| have_blackhole_engine | YES |
| have_compress | YES |
| have_crypt | YES |
| have_csv | YES |
| have_dynamic_loading | YES |
| have_example_engine | NO |
| have_federated_engine | YES |
| have_geometry | YES |
| have_innodb | YES |
| have_isam | NO |
| have_merge_engine | YES |
| have_ndbcluster | DISABLED |
| have_openssl | DISABLED |
| have_ssl | DISABLED |
| have_query_cache | YES |
| have_raid | NO |
| have_rtree_keys | YES |
| have_symlink | YES |
| init_connect | |
| init_file | |
| init_slave | |
| innodb_additional_mem_pool_size | 20971520 |
| innodb_autoextend_increment | 8 |
| innodb_buffer_pool_awe_mem_mb | 0 |
| innodb_buffer_pool_size | 8589934592 |
| innodb_checksums | ON |
| innodb_commit_concurrency | 0 |
| innodb_concurrency_tickets | 500 |
| innodb_data_file_path | ibdata1:100M:autoextend |
| innodb_data_home_dir | |
| innodb_doublewrite | ON |
| innodb_fast_shutdown | 1 |
| innodb_file_io_threads | 4 |
| innodb_file_per_table | OFF |
| innodb_flush_log_at_trx_commit | 2 |
| innodb_flush_method | |
| innodb_force_recovery | 0 |
| innodb_lock_wait_timeout | 20 |
| innodb_locks_unsafe_for_binlog | OFF |
| innodb_log_arch_dir | |
| innodb_log_archive | OFF |
| innodb_log_buffer_size | 8388608 |
| innodb_log_file_size | 335544320 |
| innodb_log_files_in_group | 2 |
| innodb_log_group_home_dir | ./ |
| innodb_max_dirty_pages_pct | 90 |
| innodb_max_purge_lag | 0 |
| innodb_mirrored_log_groups | 1 |
| innodb_open_files | 300 |
| innodb_rollback_on_timeout | OFF |
| innodb_support_xa | ON |
| innodb_sync_spin_loops | 20 |
| innodb_table_locks | ON |
| innodb_thread_concurrency | 8 |
| innodb_thread_sleep_delay | 10000 |
| interactive_timeout | 28800 |
| join_buffer_size | 131072 |
| key_buffer_size | 33554432 |
| key_cache_age_threshold | 300 |
| key_cache_block_size | 1024 |
| key_cache_division_limit | 100 |
| language | /usr/share/mysql/english/ |
| large_files_support | ON |
| large_page_size | 0 |
| large_pages | OFF |
| lc_time_names | en_US |
| license | GPL |
| local_infile | ON |
| locked_in_memory | OFF |
| log | OFF |
| log_bin | ON |
| log_bin_trust_function_creators | OFF |
| log_error | |
| log_queries_not_using_indexes | OFF |
| log_slave_updates | OFF |
| log_slow_queries | ON |
| log_warnings | 1 |
| long_query_time | 1 |
| low_priority_updates | OFF |
| lower_case_file_system | OFF |
| lower_case_table_names | 0 |
| max_allowed_packet | 16776192 |
| max_binlog_cache_size | 18446744073709551615 |
| max_binlog_size | 104857600 |
| max_connect_errors | 10 |
| max_connections | 500 |
| max_delayed_threads | 20 |
| max_error_count | 64 |
| max_heap_table_size | 16777216 |
| max_insert_delayed_threads | 20 |
| max_join_size | 18446744073709551615 |
| max_length_for_sort_data | 1024 |
| max_prepared_stmt_count | 16382 |
| max_relay_log_size | 0 |
| max_seeks_for_key | 18446744073709551615 |
| max_sort_length | 1024 |
| max_sp_recursion_depth | 0 |
| max_tmp_tables | 32 |
| max_user_connections | 0 |
| max_write_lock_count | 18446744073709551615 |
| multi_range_count | 256 |
| myisam_data_pointer_size | 6 |
| myisam_max_sort_file_size | 9223372036854775807 |
| myisam_recover_options | OFF |
| myisam_repair_threads | 1 |
| myisam_sort_buffer_size | 8388608 |
| myisam_stats_method | nulls_unequal |
| ndb_autoincrement_prefetch_sz | 32 |
| ndb_force_send | ON |
| ndb_use_exact_count | ON |
| ndb_use_transactions | ON |
| ndb_cache_check_time | 0 |
| ndb_connectstring | |
| net_buffer_length | 16384 |
| net_read_timeout | 30 |
| net_retry_count | 10 |
| net_write_timeout | 60 |
| new | OFF |
| old_passwords | OFF |
| open_files_limit | 3582 |
| optimizer_prune_level | 1 |
| optimizer_search_depth | 62 |
| pid_file | /var/run/mysqld/mysqld.pid |
| port | 3306 |
| preload_buffer_size | 32768 |
| profiling | OFF |
| profiling_history_size | 15 |
| protocol_version | 10 |
| query_alloc_block_size | 8192 |
| query_cache_limit | 1048576 |
| query_cache_min_res_unit | 4096 |
| query_cache_size | 0 |
| query_cache_type | OFF |
| query_cache_wlock_invalidate | OFF |
| query_prealloc_size | 8192 |
| range_alloc_block_size | 2048 |
| read_buffer_size | 131072 |
| read_only | OFF |
| read_rnd_buffer_size | 262144 |
| relay_log_purge | ON |
| relay_log_space_limit | 0 |
| rpl_recovery_rank | 0 |
| secure_auth | OFF |
| secure_file_priv | |
| server_id | 2 |
| skip_external_locking | ON |
| skip_networking | OFF |
| skip_show_database | OFF |
| slave_compressed_protocol | OFF |
| slave_load_tmpdir | /mnt/mysql_data/tmp/ |
| slave_net_timeout | 3600 |
| slave_skip_errors | OFF |
| slave_transaction_retries | 10 |
| slow_launch_time | 2 |
| socket | /var/run/mysqld/mysqld.sock |
| sort_buffer_size | 2097144 |
| sql_big_selects | ON |
| sql_mode | |
| sql_notes | ON |
| sql_warnings | OFF |
| ssl_ca | |
| ssl_capath | |
| ssl_cert | |
| ssl_cipher | |
| ssl_key | |
| storage_engine | InnoDB |
| sync_binlog | 0 |
| sync_frm | ON |
| system_time_zone | UTC |
| table_cache | 1536 |
| table_lock_wait_timeout | 50 |
| table_type | InnoDB |
| thread_cache_size | 32 |
| thread_stack | 131072 |
| time_format | %H:%i:%s |
| time_zone | SYSTEM |
| timed_mutexes | OFF |
| tmp_table_size | 1024 |
| tmpdir | /mnt/mysql_data/tmp |
| transaction_alloc_block_size | 8192 |
| transaction_prealloc_size | 4096 |
| tx_isolation | REPEATABLE-READ |
| updatable_views_with_limit | YES |
| version | 5.0.45-Debian_1ubuntu3-log |
| version_comment | Debian etch distribution |
| version_compile_machine | x86_64 |
| version_compile_os | pc-linux-gnu |
| wait_timeout | 600 -
SHOW GLOBAL STATUS;
| Aborted_clients | 2 |
| Aborted_connects | 0 |
| Binlog_cache_disk_use | 0 |
| Binlog_cache_use | 3058177 |
| Bytes_received | 18816243950 |
| Bytes_sent | 182503223657 |
| Com_admin_commands | 1 |
| Com_alter_db | 0 |
| Com_alter_table | 0 |
| Com_analyze | 0 |
| Com_backup_table | 0 |
| Com_begin | 3062707 |
| Com_call_procedure | 0 |
| Com_change_db | 0 |
| Com_change_master | 0 |
| Com_check | 0 |
| Com_checksum | 0 |
| Com_commit | 3057864 |
| Com_create_db | 0 |
| Com_create_function | 0 |
| Com_create_index | 0 |
| Com_create_table | 0 |
| Com_create_user | 0 |
| Com_dealloc_sql | 0 |
| Com_delete | 6583 |
| Com_delete_multi | 0 |
| Com_do | 0 |
| Com_drop_db | 0 |
| Com_drop_function | 0 |
| Com_drop_index | 0 |
| Com_drop_table | 0 |
| Com_drop_user | 0 |
| Com_execute_sql | 0 |
| Com_flush | 0 |
| Com_grant | 0 |
| Com_ha_close | 0 |
| Com_ha_open | 0 |
| Com_ha_read | 0 |
| Com_help | 0 |
| Com_insert | 913342 |
| Com_insert_select | 0 |
| Com_kill | 0 |
| Com_load | 0 |
| Com_load_master_data | 0 |
| Com_load_master_table | 0 |
| Com_lock_tables | 0 |
| Com_optimize | 0 |
| Com_preload_keys | 0 |
| Com_prepare_sql | 0 |
| Com_purge | 0 |
| Com_purge_before_date | 0 |
| Com_rename_table | 0 |
| Com_repair | 0 |
| Com_replace | 0 |
| Com_replace_select | 0 |
| Com_reset | 0 |
| Com_restore_table | 0 |
| Com_revoke | 0 |
| Com_revoke_all | 0 |
| Com_rollback | 4821 |
| Com_savepoint | 0 |
| Com_select | 34569207 |
| Com_set_option | 11383 |
| Com_show_binlog_events | 0 |
| Com_show_binlogs | 0 |
| Com_show_charsets | 0 |
| Com_show_collations | 0 |
| Com_show_column_types | 0 |
| Com_show_create_db | 0 |
| Com_show_create_table | 0 |
| Com_show_databases | 0 |
| Com_show_errors | 0 |
| Com_show_fields | 36910 |
| Com_show_grants | 0 |
| Com_show_innodb_status | 0 |
| Com_show_keys | 0 |
| Com_show_logs | 0 |
| Com_show_master_status | 0 |
| Com_show_ndb_status | 0 |
| Com_show_new_master | 0 |
| Com_show_open_tables | 0 |
| Com_show_privileges | 0 |
| Com_show_processlist | 0 |
| Com_show_slave_hosts | 1 |
| Com_show_slave_status | 0 |
| Com_show_status | 7743104 |
| Com_show_storage_engines | 0 |
| Com_show_tables | 10952 |
| Com_show_triggers | 0 |
| Com_show_variables | 202 |
| Com_show_warnings | 0 |
| Com_slave_start | 0 |
| Com_slave_stop | 0 |
| Com_stmt_close | 0 |
| Com_stmt_execute | 0 |
| Com_stmt_fetch | 0 |
| Com_stmt_prepare | 0 |
| Com_stmt_reset | 0 |
| Com_stmt_send_long_data | 0 |
| Com_truncate | 0 |
| Com_unlock_tables | 0 |
| Com_update | 3213818 |
| Com_update_multi | 0 |
| Com_xa_commit | 0 |
| Com_xa_end | 0 |
| Com_xa_prepare | 0 |
| Com_xa_recover | 0 |
| Com_xa_rollback | 0 |
| Com_xa_start | 0 |
| Compression | OFF |
| Connections | 6872 |
| Created_tmp_disk_tables | 187729 |
| Created_tmp_files | 211 |
| Created_tmp_tables | 376632 |
| Delayed_errors | 0 |
| Delayed_insert_threads | 0 |
| Delayed_writes | 0 |
| Flush_commands | 1 |
| Handler_commit | 10249469 |
| Handler_delete | 0 |
| Handler_discover | 0 |
| Handler_prepare | 6115724 |
| Handler_read_first | 192304 |
| Handler_read_key | 392210003 |
| Handler_read_next | 9155741769 |
| Handler_read_prev | 0 |
| Handler_read_rnd | 3134865 |
| Handler_read_rnd_next | 32034534 |
| Handler_rollback | 5138 |
| Handler_savepoint | 0 |
| Handler_savepoint_rollback | 0 |
| Handler_update | 0 |
| Handler_write | 30488911 |
| Innodb_buffer_pool_pages_data | 483900 |
| Innodb_buffer_pool_pages_dirty | 63756 |
| Innodb_buffer_pool_pages_flushed | 708235 |
| Innodb_buffer_pool_pages_free | 1 |
| Innodb_buffer_pool_pages_latched | 8 |
| Innodb_buffer_pool_pages_misc | 40387 |
| Innodb_buffer_pool_pages_total | 524288 |
| Innodb_buffer_pool_read_ahead_rnd | 1359 |
| Innodb_buffer_pool_read_ahead_seq | 6970 |
| Innodb_buffer_pool_read_requests | 27856201125 |
| Innodb_buffer_pool_reads | 698690 |
| Innodb_buffer_pool_wait_free | 0 |
| Innodb_buffer_pool_write_requests | 40718811 |
| Innodb_data_fsyncs | 94825 |
| Innodb_data_pending_fsyncs | 0 |
| Innodb_data_pending_reads | 0 |
| Innodb_data_pending_writes | 0 |
| Innodb_data_read | 18081370112 |
| Innodb_data_reads | 893070 |
| Innodb_data_writes | 6570956 |
| Innodb_data_written | 29564379648 |
| Innodb_dblwr_pages_written | 708235 |
| Innodb_dblwr_writes | 12758 |
| Innodb_log_waits | 0 |
| Innodb_log_write_requests | 7043610 |
| Innodb_log_writes | 6103194 |
| Innodb_os_log_fsyncs | 69265 |
| Innodb_os_log_pending_fsyncs | 0 |
| Innodb_os_log_pending_writes | 0 |
| Innodb_os_log_written | 6354055168 |
| Innodb_page_size | 16384 |
| Innodb_pages_created | 15931 |
| Innodb_pages_read | 1074474 |
| Innodb_pages_written | 708235 |
| Innodb_row_lock_current_waits | 0 |
| Innodb_row_lock_time | 2015890 |
| Innodb_row_lock_time_avg | 143 |
| Innodb_row_lock_time_max | 21384 |
| Innodb_row_lock_waits | 14088 |
| Innodb_rows_deleted | 6589 |
| Innodb_rows_inserted | 913341 |
| Innodb_rows_read | 9435790975 |
| Innodb_rows_updated | 3177083 |
| Key_blocks_not_flushed | 0 |
| Key_blocks_unused | 26792 |
| Key_blocks_used | 14 |
| Key_read_requests | 8113318 |
| Key_reads | 81332 |
| Key_write_requests | 1394173 |
| Key_writes | 0 |
| Last_query_cost | 0.000000 |
| Max_used_connections | 279 |
| Ndb_cluster_node_id | 0 |
| Ndb_config_from_host | |
| Ndb_config_from_port | 0 |
| Ndb_number_of_data_nodes | 0 |
| Not_flushed_delayed_rows | 0 |
| Open_files | 18 |
| Open_streams | 0 |
| Open_tables | 919 |
| Opened_tables | 925 |
| Prepared_stmt_count | 0 |
| Qcache_free_blocks | 0 |
| Qcache_free_memory | 0 |
| Qcache_hits | 0 |
| Qcache_inserts | 0 |
| Qcache_lowmem_prunes | 0 |
| Qcache_not_cached | 0 |
| Qcache_queries_in_cache | 0 |
| Qcache_total_blocks | 0 |
| Questions | 44894895 |
| Rpl_status | NULL |
| Select_full_join | 0 |
| Select_full_range_join | 0 |
| Select_range | 243349 |
| Select_range_check | 0 |
| Select_scan | 241007 |
| Slave_open_temp_tables | 0 |
| Slave_retried_transactions | 0 |
| Slave_running | OFF |
| Slow_launch_threads | 0 |
| Slow_queries | 38471 |
| Sort_merge_passes | 103 |
| Sort_range | 247677 |
| Sort_rows | 29168476 |
| Sort_scan | 405301 |
| Ssl_accept_renegotiates | 0 |
| Ssl_accepts | 0 |
| Ssl_callback_cache_hits | 0 |
| Ssl_cipher | |
| Ssl_cipher_list | |
| Ssl_client_connects | 0 |
| Ssl_connect_renegotiates | 0 |
| Ssl_ctx_verify_depth | 0 |
| Ssl_ctx_verify_mode | 0 |
| Ssl_default_timeout | 0 |
| Ssl_finished_accepts | 0 |
| Ssl_finished_connects | 0 |
| Ssl_session_cache_hits | 0 |
| Ssl_session_cache_misses | 0 |
| Ssl_session_cache_mode | NONE |
| Ssl_session_cache_overflows | 0 |
| Ssl_session_cache_size | 0 |
| Ssl_session_cache_timeouts | 0 |
| Ssl_sessions_reused | 0 |
| Ssl_used_session_cache_entries | 0 |
| Ssl_verify_depth | 0 |
| Ssl_verify_mode | 0 |
| Ssl_version | |
| Table_locks_immediate | 46497124 |
| Table_locks_waited | 0 |
| Tc_log_max_pages_used | 0 |
| Tc_log_page_size | 0 |
| Tc_log_page_waits | 1 |
| Threads_cached | 2 |
| Threads_connected | 275 |
| Threads_created | 858 |
| Threads_running | 74 |
| Uptime | 59291 |
| Uptime_since_flush_status | 59291 -
mysqlreport
MySQL 5.0.45-Debian_1ub uptime 0 16:29:5 Wed May 14 17:24:55 2008
__ Key ____________________________________________________________ _____
Buffer used 14.00k of 32.00M %Used: 0.04
Current 5.84M %Usage: 18.24
Write hit 100.00%
Read hit 99.00%
__ Questions ___________________________________________________________
Total 44.96M 757.7/s
DMS 38.76M 653.2/s %Total: 86.21
Com_ 13.95M 235.0/s 31.02
-Unknown 7.75M 130.7/s 17.24
COM_QUIT 6.87k 0.1/s 0.02
Slow (1) 38.47k 0.6/s 0.09 %DMS: 0.10 Log: ON
DMS 38.76M 653.2/s 86.21
SELECT 34.62M 583.4/s 77.00 89.32
UPDATE 3.22M 54.2/s 7.16 8.30
INSERT 914.94k 15.4/s 2.03 2.36
DELETE 6.59k 0.1/s 0.01 0.02
REPLACE 0 0/s 0.00 0.00
Com_ 13.95M 235.0/s 31.02
show_status 7.75M 130.7/s 17.24
begin 3.07M 51.7/s 6.82
commit 3.06M 51.6/s 6.81
__ SELECT and Sort _____________________________________________________
Scan 241.29k 4.1/s %SELECT: 0.70
Range 243.76k 4.1/s 0.70
Full join 0 0/s 0.00
Range check 0 0/s 0.00
Full rng join 0 0/s 0.00
Sort scan 405.92k 6.8/s
Sort range 248.06k 4.2/s
Sort mrg pass 103 0.0/s
__ Table Locks _________________________________________________________
Waited 0 0/s %Total: 0.00
Immediate 46.57M 784.7/s
__ Tables ____________________________________________________________ __
Open 919 of 1536 %Cache: 59.83
Opened 925 0.0/s
__ Connections _________________________________________________________
Max used 279 of 500 %Max: 55.80
Total 6.88k 0.1/s
__ Created Temp ________________________________________________________
Disk table 188.00k 3.2/s
Table 377.19k 6.4/s Size: 1.0k
File 211 0.0/s
__ Threads ____________________________________________________________ _
Running 73 of 275
Cached 2 of 32 %Hit: 87.52
Created 858 0.0/s
Slow 0 0/s
__ Aborted ____________________________________________________________ _
Clients 2 0.0/s
Connects 0 0/s
__ Bytes ____________________________________________________________ ___
Sent 182.78G 3.1M/s
Received 18.84G 317.5k/s
__ InnoDB Buffer Pool __________________________________________________
Usage 8.00G of 8.00G %Used: 100.00
Read hit 100.00%
Pages
Free 0 %Total: 0.00
Data 483.90k 92.30 %Drty: 13.26
Misc 40384 7.70
Latched 3 0.00
Reads 27.90G 470.1k/s
From file 699.26k 11.8/s 0.00
Ahead Rnd 1363 0.0/s
Ahead Sql 6976 0.1/s
Writes 40.79M 687.3/s
Flushes 708.89k 11.9/s
Wait Free 0 0/s
__ InnoDB Lock _________________________________________________________
Waits 14118 0.2/s
Current 0
Time acquiring
Total 2016944 ms
Average 142 ms
Max 21384 ms
__ InnoDB Data, Pages, Rows ____________________________________________
Data
Reads 893.81k 15.1/s
Writes 6.58M 110.9/s
fsync 94.91k 1.6/s
Pending
Reads 0
Writes 0
fsync 0
Pages
Created 15.96k 0.3/s
Read 1.08M 18.1/s
Written 708.89k 11.9/s
Rows
Deleted 6.60k 0.1/s
Inserted 914.94k 15.4/s
Read 9.45G 159.2k/s
Updated 3.18M 53.6/s