Andy McCurdy wrote:
I've been seeing some weirdness w/ MySQL and InnoDB over the past few days. I have a database that's entirely using InnoDB. The database is roughly 4.5G (one datafile) and contains a little over 50 tables. The web applications that hit this database do about 85-90% reads and 10-15% writes. Whenever a write comes in, it seems that subsequent reads get blocked to the _ENTIRE DATABASE_. What really confuses me is that reads even to other tables that aren't any way involved with the table that's being written to are waiting until the write completes. I do not use any foreign key relationships which could block a parent row.
Whenever I run "show processlist", everything looks fine until a write comes in. Reads are answered < 1 sec, and generally don't even appear on the processlist. However, as soon as a write hits, all of the reads are in a state of "NULL" until the write completes. This problem is compounded when several different writes happen from different connections at the same time. It leads to the MySQL server blocking long enough that the number of reads in the queue exceed the number of max connections. Once the writes happen, all of the read queries in the queue get answered and the normal processing continues.
I've included two samples from the "show processlist" command. They were taken approx. 1 second apart and show the growing amount of reads when writes are in the queue. I've removed the User and Host columns as they don't seem to be relevant as well as trimmed the state column down. I've also included the my.cnf config file and an output of "show status".
Additionally, I'm running Redhat 7.3 - kernel ver. 2.4.20-28.7bigmem #1 SMP
Any help on eliminating this bottleneck would be greatly appreciated! Thanks. -andy
================================= process list 1 =================================
+----------+------+-------------+--------+---------+------------------------------------
| Id | db | Command | Time | State | Info
+----------+------+-------------+--------+---------+------------------------------------
| 2972920 | NULL | Binlog Dump | 463909 | Has sen | NULL
| 2972930 | NULL | Binlog Dump | 463909 | Has sen | NULL
| 10954259 | NULL | Query | 0 | NULL | show processlist
| 10962986 | gne | Sleep | 4 | | NULL
| 10962987 | gne | Sleep | 4 | | NULL
| 10962997 | gne | Query | 3 | NULL | SELECT r.*, ui.username FROM review
| 10963003 | gne | Query | 2 | NULL | SELECT * FROM clan WHERE id='142'
| 10963018 | gne | Query | 3 | NULL | SELECT * FROM clan WHERE id='274'
| 10963019 | gne | Query | 3 | update | INSERT INTO rating (ref_type_id, re
| 10963020 | gne | Query | 2 | NULL | SELECT * FROM clan WHERE id='55'
| 10963021 | gne | Query | 3 | NULL | SELECT urs_id FROM user_info_new WH
| 10963022 | gne | Query | 3 | NULL | SELECT r.*, ui.username FROM review
| 10963023 | gne | Query | 3 | NULL | SELECT r.*, ui.username FROM review
| 10963024 | gne | Query | 2 | NULL | SELECT count(*) AS count FROM pm_me
| 10963025 | gne | Query | 2 | NULL | SELECT * FROM contact WHERE user_id
| 10963026 | gne | Query | 2 | NULL | SELECT * FROM clan WHERE id='729'
| 10963027 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963028 | gne | Query | 2 | NULL | select r.review_id from review r wh
| 10963029 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963030 | gne | Query | 2 | update | INSERT INTO pm_message SET id=NULL,
| 10963031 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963032 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963033 | gne | Query | 2 | NULL | select r.review_id from review r wh
| 10963034 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963035 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963036 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963037 | gne | Query | 2 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963038 | gne | Query | 2 | NULL | SELECT * FROM pm_message WHERE id =
| 10963039 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963041 | gne | Query | 2 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963042 | gne | Query | 1 | NULL | select r.review_id from review r wh
| 10963043 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963045 | gne | Query | 1 | NULL | SELECT count(*) AS count FROM pm_me
| 10963046 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963047 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963048 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963049 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963050 | gne | Query | 1 | NULL | select r.review_id from review r wh
| 10963051 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963052 | gne | Query | 1 | NULL | SELECT * FROM clan WHERE id='331'
| 10963053 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963054 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963055 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963056 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963057 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963058 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963059 | gne | Query | 1 | NULL | SELECT c.* FROM clan_pid cp, clan c
+----------+------+-------------+--------+---------+------------------------------------
================================= process list 2 =================================
+----------+------+-------------+--------+--------+------------------------------------
| Id | db | Command | Time | State | Info
+----------+------+-------------+--------+--------+------------------------------------
| 2972920 | NULL | Binlog Dump | 463909 | Has sen| NULL
| 2972930 | NULL | Binlog Dump | 463909 | Has sen| NULL
| 10954259 | NULL | Query | 0 | NULL | show processlist
| 10962986 | gne | Sleep | 4 | | NULL
| 10962987 | gne | Sleep | 4 | | NULL
| 10962997 | gne | Query | 3 | NULL | SELECT r.*, ui.username FROM review
| 10963003 | gne | Query | 2 | NULL | SELECT * FROM clan WHERE id='142'
| 10963018 | gne | Query | 3 | NULL | SELECT * FROM clan WHERE id='274'
| 10963019 | gne | Query | 3 | update | INSERT INTO rating (ref_type_id, re
| 10963020 | gne | Query | 2 | NULL | SELECT * FROM clan WHERE id='55'
| 10963021 | gne | Query | 3 | NULL | SELECT urs_id FROM user_info_new WH
| 10963022 | gne | Query | 3 | NULL | SELECT r.*, ui.username FROM review
| 10963023 | gne | Query | 3 | NULL | SELECT r.*, ui.username FROM review
| 10963024 | gne | Query | 2 | NULL | SELECT count(*) AS count FROM pm_me
| 10963025 | gne | Query | 2 | NULL | SELECT * FROM contact WHERE user_id
| 10963026 | gne | Query | 2 | NULL | SELECT * FROM clan WHERE id='729'
| 10963027 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963028 | gne | Query | 2 | NULL | select r.review_id from review r wh
| 10963029 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963030 | gne | Query | 2 | update | INSERT INTO pm_message SET id=NULL,
| 10963031 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963032 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963033 | gne | Query | 2 | NULL | select r.review_id from review r wh
| 10963034 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963035 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963036 | gne | Query | 2 | NULL | SELECT urs_id FROM user_info_new WH
| 10963037 | gne | Query | 2 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963038 | gne | Query | 2 | NULL | SELECT * FROM pm_message WHERE id =
| 10963039 | gne | Query | 2 | NULL | SELECT r.*, ui.username FROM review
| 10963041 | gne | Query | 2 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963042 | gne | Query | 1 | NULL | select r.review_id from review r wh
| 10963043 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963045 | gne | Query | 1 | NULL | SELECT count(*) AS count FROM pm_me
| 10963046 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963047 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963048 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963049 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963050 | gne | Query | 1 | NULL | select r.review_id from review r wh
| 10963051 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963052 | gne | Query | 1 | NULL | SELECT * FROM clan WHERE id='331'
| 10963053 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963054 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963055 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963056 | gne | Query | 1 | NULL | SELECT urs_id FROM user_info_new WH
| 10963057 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963058 | gne | Query | 1 | NULL | SELECT r.*, ui.username FROM review
| 10963059 | gne | Query | 1 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963061 | gne | Query | 0 | NULL | SELECT urs_id FROM user_info_new WH
| 10963062 | gne | Query | 0 | NULL | SELECT r.*, ui.username FROM review
| 10963063 | gne | Query | 0 | NULL | SELECT r.*, ui.username FROM review
| 10963064 | gne | Query | 0 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963065 | gne | Query | 0 | NULL | SELECT * FROM clan_member where uni
| 10963066 | gne | Query | 0 | NULL | SELECT r.*, ui.username FROM review
| 10963067 | gne | Query | 0 | NULL | SELECT * FROM clan c, clan_member c
| 10963068 | gne | Query | 0 | NULL | SELECT c.* FROM clan_pid cp, clan c
| 10963069 | gne | Query | 0 | NULL | SELECT count(*) AS count FROM pm_me
+----------+------+-------------+--------+--------+------------------------------------
====================== my.cnf ====================== [mysqld] log-error = /var/opt/mysql/error.log log-bin server-id = 600
set-variable = slave_net_timeout=3600 set-variable = net_read_timeout=3600 set-variable = query_cache_size=512M set-variable = wait_timeout=10 set-variable = key_buffer_size=128M set-variable = max_allowed_packet=1024000000 set-variable = table_cache=512 set-variable = sort_buffer=2M set-variable = record_buffer=4M set-variable = thread_cache=8 set-variable = tmp_table_size=64M set-variable = thread_concurrency=4 set-variable = myisam_sort_buffer_size=256M set-variable = max_binlog_size=1024000000 set-variable = ft_min_word_len=3 set-variable = ft_stopword_file='' set-variable = long_query_time=1 set-variable = max_connections=400 set-variable = innodb_buffer_pool_size=512M set-variable = max_connect_errors=999999999
==================================== server status values (show status) ==================================== +--------------------------+------------+ | Aborted_clients | 335329 | | Aborted_connects | 373166 | | Bytes_received | 1943964913 | | Bytes_sent | 1037459639 | | Com_admin_commands | 61 | | Com_alter_table | 1 | | Com_analyze | 0 | | Com_backup_table | 0 | | Com_begin | 0 | | Com_change_db | 11518911 | | Com_change_master | 0 | | Com_check | 0 | | Com_commit | 0 | | Com_create_db | 0 | | Com_create_function | 0 | | Com_create_index | 0 | | Com_create_table | 8 | | Com_delete | 19952 | | Com_delete_multi | 0 | | Com_drop_db | 0 | | Com_drop_function | 0 | | Com_drop_index | 0 | | Com_drop_table | 2 | | Com_flush | 1 | | Com_grant | 2 | | Com_ha_close | 0 | | Com_ha_open | 0 | | Com_ha_read | 0 | | Com_insert | 237294 | | Com_insert_select | 2400 | | Com_kill | 758 | | Com_load | 0 | | Com_load_master_data | 0 | | Com_load_master_table | 0 | | Com_lock_tables | 0 | | Com_optimize | 0 | | Com_purge | 0 | | Com_rename_table | 0 | | Com_repair | 0 | | Com_replace | 31107 | | Com_replace_select | 0 | | Com_reset | 0 | | Com_restore_table | 0 | | Com_revoke | 0 | | Com_rollback | 0 | | Com_savepoint | 0 | | Com_select | 22301021 | | Com_set_option | 49 | | Com_show_binlog_events | 0 | | Com_show_binlogs | 0 | | Com_show_create | 2 | | Com_show_databases | 31 | | Com_show_fields | 1129 | | Com_show_grants | 0 | | Com_show_keys | 13 | | Com_show_logs | 0 | | Com_show_master_status | 0 | | Com_show_new_master | 0 | | Com_show_open_tables | 0 | | Com_show_processlist | 34450 | | Com_show_slave_hosts | 6 | | Com_show_slave_status | 0 | | Com_show_status | 47 | | Com_show_innodb_status | 4 | | Com_show_tables | 51 | | Com_show_variables | 12 | | Com_slave_start | 0 | | Com_slave_stop | 0 | | Com_truncate | 18 | | Com_unlock_tables | 0 | | Com_update | 253907 | | Connections | 11927865 | | Created_tmp_disk_tables | 6751 | | Created_tmp_tables | 6753 | | Created_tmp_files | 358 | | Delayed_insert_threads | 0 | | Delayed_writes | 0 | | Delayed_errors | 0 | | Flush_commands | 1 | | Handler_commit | 2 | | Handler_delete | 17202 | | Handler_read_first | 991 | | Handler_read_key | 541415295 | | Handler_read_next | 340543222 | | Handler_read_prev | 0 | | Handler_read_rnd | 25605878 | | Handler_read_rnd_next | 1794754881 | | Handler_rollback | 3868360 | | Handler_update | 9501 | | Handler_write | 3358752 | | Key_blocks_used | 124690 | | Key_read_requests | 1091453021 | | Key_reads | 174764 | | Key_write_requests | 176791 | | Key_writes | 166926 | | Max_used_connections | 400 | | Not_flushed_key_blocks | 0 | | Not_flushed_delayed_rows | 0 | | Open_tables | 512 | | Open_files | 208 | | Open_streams | 0 | | Opened_tables | 56254 | | Questions | 77415469 | | Qcache_queries_in_cache | 207102 | | Qcache_inserts | 19047398 | | Qcache_hits | 31627612 | | Qcache_lowmem_prunes | 2766958 | | Qcache_not_cached | 3253542 | | Qcache_free_memory | 317973448 | | Qcache_free_blocks | 94546 | | Qcache_total_blocks | 508910 | | Rpl_status | NULL | | Select_full_join | 0 | | Select_full_range_join | 0 | | Select_range | 1026865 | | Select_range_check | 0 | | Select_scan | 11300 | | Slave_open_temp_tables | 0 | | Slave_running | OFF | | Slow_launch_threads | 3 | | Slow_queries | 305224 | | Sort_merge_passes | 0 | | Sort_range | 1291192 | | Sort_rows | 26291581 | | Sort_scan | 7175 | | Table_locks_immediate | 38768307 | | Table_locks_waited | 45913 | | Threads_cached | 0 | | Threads_created | 1190079 | | Threads_connected | 53 | | Threads_running | 43 | | Uptime | 692494 | +--------------------------+------------+
Andy, mysql> show innodb status;
output and the mysql version number might help figure this out better.
walt
-- MySQL General Mailing List For list archives: http://lists.mysql.com/mysql To unsubscribe: http://lists.mysql.com/[EMAIL PROTECTED]
