adegtyarev
10-04-2012, 08:01 PM
Hello!
Analyzing slow query log and found that amazing stuff:
# Profile
# Rank Query ID Response time Calls R/Call Apdx V/M Item
# ==== ================== ================ ===== ======= ==== ===== ======
# 1 0xB74299AAD34DEA0A 19830.1255 79.0% 15594 1.2717 0.53 0.15 SELECT thread forum user avatar customavatar post attachment
[...]
# Query 1: 0.26 QPS, 0.33x concurrency, ID 0xB74299AAD34DEA0A at byte 20627
# This item is included in the report because it matches --limit.
# Scores: Apdex = 0.53 [1.0], V/M = 0.15
# Query_time sparkline: | ^_|
# Time range: 2012-10-04 07:00:20 to 23:44:42
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 91 15594
# Exec time 78 19830s 1s 16s 1s 2s 437ms 1s
# Lock time 16 55s 70us 12s 3ms 224us 179ms 138us
# Rows sent 5 228.43k 15 15 15 15 0 15
# Rows examine 92 3.24G 972 220.18k 217.75k 211.82k 5.48k 211.82k
# Query size 96 23.36M 1.53k 1.54k 1.53k 1.53k 0 1.53k
# String:
# Databases u31385_bmw
# Hosts
# Users u31385_bmw
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################################## ##############
# 10s+ #
SELECT thread.threadid, thread.postuserid, thread.title, thread.dateline, thread.forumid,
post.pagetext AS preview, forum.title AS forum_title, forum.description_clean AS
forum_description_clean, post.userid AS userid, attachment_thumbnail.attachmentid AS
thumbnail_attachmentid, attachment_thumbnail.dateline AS thumbnail_dateline,
avatar.avatarid, user.avatarrevision ,avatar.avatarpath, NOT ISNULL(customavatar.userid)
AS hascustomavatar, customavatar.dateline AS avatardateline,customavatar.width_thumb
AS avwidth,customavatar.height_thumb AS avheight
FROM thread AS thread
LEFT JOIN forum AS forum ON (forum.forumid = thread.forumid)
LEFT JOIN user AS user ON (user.userid = thread.postuserid)
LEFT JOIN avatar AS avatar ON(avatar.avatarid = user.avatarid)
LEFT JOIN customavatar AS customavatar ON(customavatar.userid = user.userid)
LEFT JOIN post AS post ON(post.postid = thread.firstpostid)
LEFT JOIN attachment AS attachment_thumbnail
ON((attachment_thumbnail.postid = thread.firstpostid)
AND (attachment_thumbnail.extension = 'jpg'
OR attachment_thumbnail.extension = 'gif'
OR attachment_thumbnail.extension = 'png'))
WHERE thread.forumid = '94'
GROUP BY thread.threadid
ORDER BY thread.dateline DESC
LIMIT 15\G
The query brought by ProvB Index mod which we bought years ago. Explain on this query shows that is using temporary table to perform ORDERing by thread.dateline:
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: thread
type: index
possible_keys: forumid,m_select2
key: dateline
key_len: 4
ref: NULL
rows: 197
Extra: Using where; Using temporary
*************************** 2. row ***************************
id: 1
select_type: SIMPLE
table: forum
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 2
ref: u31385_bmw.thread.forumid
rows: 1
Extra:
*************************** 3. row ***************************
id: 1
select_type: SIMPLE
table: user
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: u31385_bmw.thread.postuserid
rows: 1
Extra:
*************************** 4. row *************************** [22/1810]
id: 1
select_type: SIMPLE
table: avatar
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 2
ref: u31385_bmw.user.avatarid
rows: 1
Extra:
*************************** 5. row ***************************
id: 1
select_type: SIMPLE
table: customavatar
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: u31385_bmw.user.userid
rows: 1
Extra:
*************************** 6. row ***************************
id: 1
select_type: SIMPLE
table: post
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: u31385_bmw.thread.firstpostid
rows: 1
Extra:
*************************** 7. row ***************************
id: 1
select_type: SIMPLE
table: attachment_thumbnail
type: ref
possible_keys: postid,extension,post_extension,m_select1
key: postid
key_len: 4
ref: u31385_bmw.thread.firstpostid
rows: 3
Extra:
7 rows in set (0.00 sec)
Having 632140 entries in table thread, that ordering take a lot of time. This obviously shown in profile on this particular query:
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000052 |
| checking query cache for query | 0.000111 |
| Opening tables | 0.000035 |
| System lock | 0.000021 |
| Table lock | 0.000065 |
| init | 0.000077 |
| optimizing | 0.000031 |
| statistics | 0.000605 |
| preparing | 0.000039 |
| Creating tmp table | 0.001370 |
| Sorting for group | 0.000021 |
| executing | 0.000015 |
| Copying to tmp table | 1.271814 | <------ (1)
| Sorting result | 0.045776 | <------ (2)
| Sending data | 0.000431 |
| end | 0.000019 |
| removing tmp table | 0.038664 | <------ (3)
| end | 0.000030 |
| query end | 0.000014 |
| freeing items | 0.000064 |
| logging slow query | 0.000018 |
| logging slow query | 0.000034 |
| cleaning up | 0.000018 |
+--------------------------------+----------+
23 rows in set (0.00 sec)
Tried without luck to get a bit of support from the upstream. Posting questions on the ProvB forum is a black hole.
The query couldn't be cached by MySQL query cache for unknown reason - I see it in slow log almost every second. Probably this is because of tables involed in query are changed rapidly.
Removing ORDER BY clause makes query much faster (0.00 sec), because it runs without using temporary tables. But can't remove that ordering on production as selected rows are news on site index page and must be ordered by date. Any suggestions on how this query could be optimized?
vBulletin version 3.8.6
Posts: 17 millions, Users: 207 thousands
Intel(R) Xeon(R) CPU X5675 x 24 CPUs
RAM: 24576MB
MySQL 5.1.57, Queries per second ~ 500.
Analyzing slow query log and found that amazing stuff:
# Profile
# Rank Query ID Response time Calls R/Call Apdx V/M Item
# ==== ================== ================ ===== ======= ==== ===== ======
# 1 0xB74299AAD34DEA0A 19830.1255 79.0% 15594 1.2717 0.53 0.15 SELECT thread forum user avatar customavatar post attachment
[...]
# Query 1: 0.26 QPS, 0.33x concurrency, ID 0xB74299AAD34DEA0A at byte 20627
# This item is included in the report because it matches --limit.
# Scores: Apdex = 0.53 [1.0], V/M = 0.15
# Query_time sparkline: | ^_|
# Time range: 2012-10-04 07:00:20 to 23:44:42
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 91 15594
# Exec time 78 19830s 1s 16s 1s 2s 437ms 1s
# Lock time 16 55s 70us 12s 3ms 224us 179ms 138us
# Rows sent 5 228.43k 15 15 15 15 0 15
# Rows examine 92 3.24G 972 220.18k 217.75k 211.82k 5.48k 211.82k
# Query size 96 23.36M 1.53k 1.54k 1.53k 1.53k 0 1.53k
# String:
# Databases u31385_bmw
# Hosts
# Users u31385_bmw
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################################## ##############
# 10s+ #
SELECT thread.threadid, thread.postuserid, thread.title, thread.dateline, thread.forumid,
post.pagetext AS preview, forum.title AS forum_title, forum.description_clean AS
forum_description_clean, post.userid AS userid, attachment_thumbnail.attachmentid AS
thumbnail_attachmentid, attachment_thumbnail.dateline AS thumbnail_dateline,
avatar.avatarid, user.avatarrevision ,avatar.avatarpath, NOT ISNULL(customavatar.userid)
AS hascustomavatar, customavatar.dateline AS avatardateline,customavatar.width_thumb
AS avwidth,customavatar.height_thumb AS avheight
FROM thread AS thread
LEFT JOIN forum AS forum ON (forum.forumid = thread.forumid)
LEFT JOIN user AS user ON (user.userid = thread.postuserid)
LEFT JOIN avatar AS avatar ON(avatar.avatarid = user.avatarid)
LEFT JOIN customavatar AS customavatar ON(customavatar.userid = user.userid)
LEFT JOIN post AS post ON(post.postid = thread.firstpostid)
LEFT JOIN attachment AS attachment_thumbnail
ON((attachment_thumbnail.postid = thread.firstpostid)
AND (attachment_thumbnail.extension = 'jpg'
OR attachment_thumbnail.extension = 'gif'
OR attachment_thumbnail.extension = 'png'))
WHERE thread.forumid = '94'
GROUP BY thread.threadid
ORDER BY thread.dateline DESC
LIMIT 15\G
The query brought by ProvB Index mod which we bought years ago. Explain on this query shows that is using temporary table to perform ORDERing by thread.dateline:
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: thread
type: index
possible_keys: forumid,m_select2
key: dateline
key_len: 4
ref: NULL
rows: 197
Extra: Using where; Using temporary
*************************** 2. row ***************************
id: 1
select_type: SIMPLE
table: forum
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 2
ref: u31385_bmw.thread.forumid
rows: 1
Extra:
*************************** 3. row ***************************
id: 1
select_type: SIMPLE
table: user
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: u31385_bmw.thread.postuserid
rows: 1
Extra:
*************************** 4. row *************************** [22/1810]
id: 1
select_type: SIMPLE
table: avatar
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 2
ref: u31385_bmw.user.avatarid
rows: 1
Extra:
*************************** 5. row ***************************
id: 1
select_type: SIMPLE
table: customavatar
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: u31385_bmw.user.userid
rows: 1
Extra:
*************************** 6. row ***************************
id: 1
select_type: SIMPLE
table: post
type: eq_ref
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: u31385_bmw.thread.firstpostid
rows: 1
Extra:
*************************** 7. row ***************************
id: 1
select_type: SIMPLE
table: attachment_thumbnail
type: ref
possible_keys: postid,extension,post_extension,m_select1
key: postid
key_len: 4
ref: u31385_bmw.thread.firstpostid
rows: 3
Extra:
7 rows in set (0.00 sec)
Having 632140 entries in table thread, that ordering take a lot of time. This obviously shown in profile on this particular query:
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000052 |
| checking query cache for query | 0.000111 |
| Opening tables | 0.000035 |
| System lock | 0.000021 |
| Table lock | 0.000065 |
| init | 0.000077 |
| optimizing | 0.000031 |
| statistics | 0.000605 |
| preparing | 0.000039 |
| Creating tmp table | 0.001370 |
| Sorting for group | 0.000021 |
| executing | 0.000015 |
| Copying to tmp table | 1.271814 | <------ (1)
| Sorting result | 0.045776 | <------ (2)
| Sending data | 0.000431 |
| end | 0.000019 |
| removing tmp table | 0.038664 | <------ (3)
| end | 0.000030 |
| query end | 0.000014 |
| freeing items | 0.000064 |
| logging slow query | 0.000018 |
| logging slow query | 0.000034 |
| cleaning up | 0.000018 |
+--------------------------------+----------+
23 rows in set (0.00 sec)
Tried without luck to get a bit of support from the upstream. Posting questions on the ProvB forum is a black hole.
The query couldn't be cached by MySQL query cache for unknown reason - I see it in slow log almost every second. Probably this is because of tables involed in query are changed rapidly.
Removing ORDER BY clause makes query much faster (0.00 sec), because it runs without using temporary tables. But can't remove that ordering on production as selected rows are news on site index page and must be ordered by date. Any suggestions on how this query could be optimized?
vBulletin version 3.8.6
Posts: 17 millions, Users: 207 thousands
Intel(R) Xeon(R) CPU X5675 x 24 CPUs
RAM: 24576MB
MySQL 5.1.57, Queries per second ~ 500.