Description:
Time after time mysql seems to hang for a bit and don't process any of queries. Thing "hang" period can last from 2-3 secs till 30-60 seconds, and even simplest queries are not processed, e.g.
select unix_timestamp();
Here is a processlist output, I just catched it. Few processes are in sending data status, but these queries are normally don't consume so much of time.
Example:
| 193093 | gcc | 62.250.11.174:22786 | gccdb | Query | 5 | Sending data | select updated from product_xmlproduct_feature_cache where product_feature_id=13186084 |
but normally:
mysql> select updated from product_xmlproduct_feature_cache where product_feature_id=13186084;
+------------+
| updated |
+------------+
| 1170892173 |
+------------+
1 row in set (0.01 sec)
mysql> explain select updated from product_xmlproduct_feature_cache where product_feature_id=13186084;
+----+-------------+----------------------------------+-------+--------------------+--------------------+---------+-------+------+-------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+----------------------------------+-------+--------------------+--------------------+---------+-------+------+-------+
| 1 | SIMPLE | product_xmlproduct_feature_cache | const | product_feature_id | product_feature_id | 5 | const | 1 | |
+----+-------------+----------------------------------+-------+--------------------+--------------------+---------+-------+------+-------+
And show processlist output:
mysql> show processlist;
+--------+------+---------------------+-------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+--------+------+---------------------+-------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
| 1650 | gcc | 62.250.11.174:11739 | gccdb | Query | 7 | NULL | select count(id) from process_queue where process_status_id > 1 and process_status_id < 30 and proce |
| 158269 | gcc | 62.250.11.174:5768 | gccdb | Query | 7 | Sending data | select id from process_queue where process_status_id <> 30 and command = '/home/gcc/bin/update_produ |
| 165935 | gcc | 62.250.11.174:16900 | gccdb | Query | 7 | NULL | select restricted_values, type from feature where feature_id = '2200' |
| 187885 | gcc | 62.250.11.174:2651 | gccdb | Sleep | 310 | | NULL |
| 188042 | gcc | 62.250.11.174:2988 | gccdb | Query | 6 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 188043 | gcc | 62.250.11.174:2989 | gccdb | Query | 6 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 188044 | gcc | 62.250.11.174:2991 | gccdb | Query | 3 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 188335 | root | localhost | gccdb | Query | 0 | NULL | show processlist |
| 188727 | gcc | 62.250.11.174:4221 | gccdb | Query | 6 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 188786 | gcc | 62.250.11.174:4316 | gccdb | Query | 4 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189288 | gcc | 62.250.11.174:5166 | gccdb | Query | 4 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189400 | gcc | 62.250.11.174:9356 | gccdb | Query | 7 | NULL | select v.value, v.record_id, v.langid from
product_family as pf, vocabulary as v, product as p wher |
| 189401 | gcc | 62.250.11.174:9357 | gccdb | Query | 7 | Sending data | select name from product_name where product_id = 124890 and langid = 2 |
| 189402 | gcc | 62.250.11.174:9358 | gccdb | Query | 7 | NULL | select updated from product_xmlproduct_feature_cache where product_feature_id=9426826 |
| 189409 | gcc | 62.250.11.174:9367 | gccdb | Query | 7 | Sending data | select product_feature_local_id, cf.feature_id,
pfl.value, f.measure_id, m.sign, (cf.searchable |
| 189410 | gcc | 62.250.11.174:9368 | gccdb | Query | 7 | end | UPDATE process_queue SET finished_date = unix_timestamp(), process_status_id = 30 WHERE id = '71507 |
| 189413 | gcc | 62.250.11.174:9376 | gccdb | Query | 7 | NULL | select product_feature_id, cf.feature_id,
pf.value, f.measure_id, m.sign, (cf.searchable *
|
| 189414 | gcc | 62.250.11.174:9377 | gccdb | Query | 7 | end | UPDATE product_xmlproduct_feature_cache SET updated = unix_timestamp(), xmlproduct_feature_chunk = ' |
| 189421 | gcc | 62.250.11.174:9393 | gccdb | Query | 6 | NULL | SELECT password, length(password) FROM users WHERE login='xxx' AND subscription_level=4 and |
| 189422 | gcc | 62.250.11.174:9396 | gccdb | Query | 5 | NULL | SELECT password, length(password) FROM users WHERE login='xxx' AND subscription_level=4 and |
| 189423 | gcc | 62.250.11.174:9398 | gccdb | Query | 4 | NULL | SELECT password, length(password) FROM users WHERE login='xxx' AND subscription_level=4 and |
| 189424 | gcc | 62.250.11.174:9405 | gccdb | Query | 2 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189425 | gcc | 62.250.11.174:9407 | gccdb | Query | 2 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189426 | gcc | 62.250.11.174:9408 | gccdb | Query | 2 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189427 | gcc | 62.250.11.174:9411 | gccdb | Query | 2 | NULL | select unix_timestamp() |
| 189428 | gcc | 62.250.11.174:9412 | gccdb | Query | 1 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189429 | gcc | 62.250.11.174:9414 | gccdb | Query | 0 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
| 189430 | gcc | 62.250.11.174:9416 | gccdb | Query | 0 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user |
+--------+------+---------------------+-------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
Storage engine used is MyISAM.
How to repeat:
Sorry, no idea :-(
Suggested fix:
No workaround known.
Description: Time after time mysql seems to hang for a bit and don't process any of queries. Thing "hang" period can last from 2-3 secs till 30-60 seconds, and even simplest queries are not processed, e.g. select unix_timestamp(); Here is a processlist output, I just catched it. Few processes are in sending data status, but these queries are normally don't consume so much of time. Example: | 193093 | gcc | 62.250.11.174:22786 | gccdb | Query | 5 | Sending data | select updated from product_xmlproduct_feature_cache where product_feature_id=13186084 | but normally: mysql> select updated from product_xmlproduct_feature_cache where product_feature_id=13186084; +------------+ | updated | +------------+ | 1170892173 | +------------+ 1 row in set (0.01 sec) mysql> explain select updated from product_xmlproduct_feature_cache where product_feature_id=13186084; +----+-------------+----------------------------------+-------+--------------------+--------------------+---------+-------+------+-------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+----------------------------------+-------+--------------------+--------------------+---------+-------+------+-------+ | 1 | SIMPLE | product_xmlproduct_feature_cache | const | product_feature_id | product_feature_id | 5 | const | 1 | | +----+-------------+----------------------------------+-------+--------------------+--------------------+---------+-------+------+-------+ And show processlist output: mysql> show processlist; +--------+------+---------------------+-------+---------+------+--------------+------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +--------+------+---------------------+-------+---------+------+--------------+------------------------------------------------------------------------------------------------------+ | 1650 | gcc | 62.250.11.174:11739 | gccdb | Query | 7 | NULL | select count(id) from process_queue where process_status_id > 1 and process_status_id < 30 and proce | | 158269 | gcc | 62.250.11.174:5768 | gccdb | Query | 7 | Sending data | select id from process_queue where process_status_id <> 30 and command = '/home/gcc/bin/update_produ | | 165935 | gcc | 62.250.11.174:16900 | gccdb | Query | 7 | NULL | select restricted_values, type from feature where feature_id = '2200' | | 187885 | gcc | 62.250.11.174:2651 | gccdb | Sleep | 310 | | NULL | | 188042 | gcc | 62.250.11.174:2988 | gccdb | Query | 6 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 188043 | gcc | 62.250.11.174:2989 | gccdb | Query | 6 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 188044 | gcc | 62.250.11.174:2991 | gccdb | Query | 3 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 188335 | root | localhost | gccdb | Query | 0 | NULL | show processlist | | 188727 | gcc | 62.250.11.174:4221 | gccdb | Query | 6 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 188786 | gcc | 62.250.11.174:4316 | gccdb | Query | 4 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189288 | gcc | 62.250.11.174:5166 | gccdb | Query | 4 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189400 | gcc | 62.250.11.174:9356 | gccdb | Query | 7 | NULL | select v.value, v.record_id, v.langid from product_family as pf, vocabulary as v, product as p wher | | 189401 | gcc | 62.250.11.174:9357 | gccdb | Query | 7 | Sending data | select name from product_name where product_id = 124890 and langid = 2 | | 189402 | gcc | 62.250.11.174:9358 | gccdb | Query | 7 | NULL | select updated from product_xmlproduct_feature_cache where product_feature_id=9426826 | | 189409 | gcc | 62.250.11.174:9367 | gccdb | Query | 7 | Sending data | select product_feature_local_id, cf.feature_id, pfl.value, f.measure_id, m.sign, (cf.searchable | | 189410 | gcc | 62.250.11.174:9368 | gccdb | Query | 7 | end | UPDATE process_queue SET finished_date = unix_timestamp(), process_status_id = 30 WHERE id = '71507 | | 189413 | gcc | 62.250.11.174:9376 | gccdb | Query | 7 | NULL | select product_feature_id, cf.feature_id, pf.value, f.measure_id, m.sign, (cf.searchable * | | 189414 | gcc | 62.250.11.174:9377 | gccdb | Query | 7 | end | UPDATE product_xmlproduct_feature_cache SET updated = unix_timestamp(), xmlproduct_feature_chunk = ' | | 189421 | gcc | 62.250.11.174:9393 | gccdb | Query | 6 | NULL | SELECT password, length(password) FROM users WHERE login='xxx' AND subscription_level=4 and | | 189422 | gcc | 62.250.11.174:9396 | gccdb | Query | 5 | NULL | SELECT password, length(password) FROM users WHERE login='xxx' AND subscription_level=4 and | | 189423 | gcc | 62.250.11.174:9398 | gccdb | Query | 4 | NULL | SELECT password, length(password) FROM users WHERE login='xxx' AND subscription_level=4 and | | 189424 | gcc | 62.250.11.174:9405 | gccdb | Query | 2 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189425 | gcc | 62.250.11.174:9407 | gccdb | Query | 2 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189426 | gcc | 62.250.11.174:9408 | gccdb | Query | 2 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189427 | gcc | 62.250.11.174:9411 | gccdb | Query | 2 | NULL | select unix_timestamp() | | 189428 | gcc | 62.250.11.174:9412 | gccdb | Query | 1 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189429 | gcc | 62.250.11.174:9414 | gccdb | Query | 0 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | | 189430 | gcc | 62.250.11.174:9416 | gccdb | Query | 0 | NULL | select user_id, user_group, access_restriction, access_restriction_ip, subscription_level from user | +--------+------+---------------------+-------+---------+------+--------------+------------------------------------------------------------------------------------------------------+ Storage engine used is MyISAM. How to repeat: Sorry, no idea :-( Suggested fix: No workaround known.