OK I looked in my slow query log and the three slow queries around the times of my timing-out-posts seem to have nothing to do with what I'm doing. They are all looking at the "General Parakeet Chat" area (forum 5) - which I'm not in. And two of them are ordering by username, which is confusing. If someone was looking at the forum area in general it would list items by date. What query lists by user name, for a given forum area?
So I'm not getting any sense, from the slow forum query log, what is slowing down my posts. I'll note the post *does* get in even though it times out. So it's something hanging it after the post goes in. Any ideas how to troubleshoot? Maybe something is simply locking up after the post is done?
Here are the three queries going on during my testing time.
# Time: 121217 1:28:32
# User@Host: root[root] @ localhost [127.0.0.1]
# Query_time: 15.328125 Lock_time: 0.000000 Rows_sent: 11 Rows_examined: 93778
SET timestamp=1355725712;
select t1.TOPIC_ID,t1.POST_ID,t2.USER_DISPLAY_NAME,t1.TOPIC_CREATED_TIME,t1.TOPIC_LAST_REPLY_TIME,t1.TOPIC_SUBJECT,
t1.TOPIC_STATUS,t1.TOPIC_IS_APPROVED,t1.TOPIC_ICON,t1.TOPIC_VIEWS,t1.TOPIC_REPLIES,t1.TOPIC_TOTAL_RATES,
t1.TOPIC_RATING,t3.USER_NAME_COLOR,t2.USER_MEMBERSHIP_LEVEL,t1.USER_ID,t1.TOPIC_IS_STICKY,t1.TOPIC_LAST_POSTER_ID,
t1.TOPIC_LAST_POSTER_NAME,t1.TOPIC_LAST_POST_ID,t1.TOPIC_IS_EVENT,t1.TOPIC_HAS_FILE,t1.TOPIC_HAS_POLL,t1.TOPIC_POSTER_NAME,t1.TOPIC_THUMBNAIL,t4.POST_BODY,t3.USER_GROUP_IMAGES
from ubbt_TOPICS as t1
left join ubbt_USERS as t2 on t1.USER_ID = t2.USER_ID
left join ubbt_USER_PROFILE as t3 on t1.USER_ID = t3.USER_ID
left join ubbt_POSTS as t4 on t1.POST_ID = t4.POST_ID
where t1.FORUM_ID = 5
and t1.TOPIC_IS_STICKY = '0'
AND t1.TOPIC_IS_APPROVED = '1'
ORDER BY t2.USER_DISPLAY_NAME asc
LIMIT 9860, 11;
# Time: 121217 1:40:56
# User@Host: root[root] @ localhost [127.0.0.1]
# Query_time: 10.859375 Lock_time: 0.000000 Rows_sent: 11 Rows_examined: 53307
SET timestamp=1355726456;
select t1.TOPIC_ID,t1.POST_ID,t2.USER_DISPLAY_NAME,t1.TOPIC_CREATED_TIME,t1.TOPIC_LAST_REPLY_TIME,t1.TOPIC_SUBJECT,
t1.TOPIC_STATUS,t1.TOPIC_IS_APPROVED,t1.TOPIC_ICON,t1.TOPIC_VIEWS,t1.TOPIC_REPLIES,t1.TOPIC_TOTAL_RATES,
t1.TOPIC_RATING,t3.USER_NAME_COLOR,t2.USER_MEMBERSHIP_LEVEL,t1.USER_ID,t1.TOPIC_IS_STICKY,t1.TOPIC_LAST_POSTER_ID,
t1.TOPIC_LAST_POSTER_NAME,t1.TOPIC_LAST_POST_ID,t1.TOPIC_IS_EVENT,t1.TOPIC_HAS_FILE,t1.TOPIC_HAS_POLL,t1.TOPIC_POSTER_NAME,t1.TOPIC_THUMBNAIL,t4.POST_BODY,t3.USER_GROUP_IMAGES
from ubbt_TOPICS as t1
left join ubbt_USERS as t2 on t1.USER_ID = t2.USER_ID
left join ubbt_USER_PROFILE as t3 on t1.USER_ID = t3.USER_ID
left join ubbt_POSTS as t4 on t1.POST_ID = t4.POST_ID
where t1.FORUM_ID = 5
and t1.TOPIC_IS_STICKY = '0'
AND t1.TOPIC_IS_APPROVED = '1'
ORDER BY t1.TOPIC_SUBJECT asc
LIMIT 9120, 11;
# Time: 121217 1:41:06
# User@Host: root[root] @ localhost [127.0.0.1]
# Query_time: 14.562500 Lock_time: 0.000000 Rows_sent: 11 Rows_examined: 93058
SET timestamp=1355726466;
select t1.TOPIC_ID,t1.POST_ID,t2.USER_DISPLAY_NAME,t1.TOPIC_CREATED_TIME,t1.TOPIC_LAST_REPLY_TIME,t1.TOPIC_SUBJECT,
t1.TOPIC_STATUS,t1.TOPIC_IS_APPROVED,t1.TOPIC_ICON,t1.TOPIC_VIEWS,t1.TOPIC_REPLIES,t1.TOPIC_TOTAL_RATES,
t1.TOPIC_RATING,t3.USER_NAME_COLOR,t2.USER_MEMBERSHIP_LEVEL,t1.USER_ID,t1.TOPIC_IS_STICKY,t1.TOPIC_LAST_POSTER_ID,
t1.TOPIC_LAST_POSTER_NAME,t1.TOPIC_LAST_POST_ID,t1.TOPIC_IS_EVENT,t1.TOPIC_HAS_FILE,t1.TOPIC_HAS_POLL,t1.TOPIC_POSTER_NAME,t1.TOPIC_THUMBNAIL,t4.POST_BODY,t3.USER_GROUP_IMAGES
from ubbt_TOPICS as t1
left join ubbt_USERS as t2 on t1.USER_ID = t2.USER_ID
left join ubbt_USER_PROFILE as t3 on t1.USER_ID = t3.USER_ID
left join ubbt_POSTS as t4 on t1.POST_ID = t4.POST_ID
where t1.FORUM_ID = 5
and t1.TOPIC_IS_STICKY = '0'
AND t1.TOPIC_IS_APPROVED = '1'
ORDER BY t2.USER_DISPLAY_NAME desc
LIMIT 9140, 11;
