Анализировал
перконовский отчет по слоу логу и наткнулся на странную вещь — простой на первый взгляд запрос, а выполняется безумно долго
# Query 2: 0.11 QPS, 0.37x concurrency, ID 0x4CA3394E8B549060 at byte 9272
# This item is included in the report because it matches --limit.
# Scores: Apdex = 0.70 [1.0], V/M = 11.65
# Query_time sparkline: | ^^_|
# Time range: 2012-10-24 19:01:23 to 19:59:56
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 8 390
# Exec time 15 1307s 502ms 22s 3s 20s 6s 992ms
# Lock time 28 16s 74us 50ms 41ms 48ms 18ms 48ms
# Rows sent 2 390 1 1 1 1 0 1
# Rows examine 0 390 1 1 1 1 0 1
# Rows affecte 0 0 0 0 0 0 0 0
# Rows read 2 390 1 1 1 1 0 1
# Bytes sent 33 782.48k 1.96k 2.08k 2.01k 1.96k 8.76 1.96k
# Merge passes 0 0 0 0 0 0 0 0
# Tmp tables 0 0 0 0 0 0 0 0
# Tmp disk tbl 0 0 0 0 0 0 0 0
# Tmp tbl size 0 0 0 0 0 0 0 0
# Query size 37 480.54k 1.23k 1.23k 1.23k 1.20k 0 1.20k
# InnoDB:
# IO r bytes 0 0 0 0 0 0 0 0
# IO r ops 0 0 0 0 0 0 0 0
# IO r wait 0 0 0 0 0 0 0 0
# pages distin 0 850 0 4 2.18 2.90 0.99 2.90
# queue wait 34 1272s 0 21s 3s 20s 6s 900ms
# rec lock wai 0 0 0 0 0 0 0 0
# String:
# Databases teamplate
# Hosts
# InnoDB trxID 574517216 (1/0%), 574517222 (1/0%)... 388 more
# Last errno 0
# Users template
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms ################################################################
# 1s ####################################################
# 10s+ ###############
# Tables
# SHOW TABLE STATUS FROM `template` LIKE 'user'\G
# SHOW CREATE TABLE `template`.`user`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `user` `u` WHERE `u`.`id` = '1313095'\G
если зайти в исходный файл медленных запросов, то увидим следующее
# User@Host: template[template] @ [192.168.2.84]
# Thread_id: 85137536 Schema: template Last_errno: 0 Killed: 0
# Query_time: 21.562995 Lock_time: 0.050135 Rows_sent: 1 Rows_examined: 1 Rows_affected: 0 Rows_read: 1
# Bytes_sent: 2027 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# InnoDB_trx_id: 574517216
# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0
# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000
# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 21.462465
# InnoDB_pages_distinct: 3
SET timestamp=1351090883;
SELECT * FROM `user` `u` WHERE `u`.`id` = '1313095';
не стоит говорить что индекс на id кластерный.
по эксплейну все красиво — используется именно праймари с колвом строк один.
и вот это смущает
InnoDB_queue_wait: 21.462465
гуглить и яндексить по этому не очень просто, толкового не много.
куда копать дальше? посоветуйте.
