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
