gistfile1.txt

[09:56am] mage2k: Bino__: hi
[09:56am] Bino__: hi
[09:57am] mage2k: looks like about an hour ago the load kicked up a bit
[10:01am] You left the chat by being disconnected from the server.
[10:02am] You reconnected to the server.
[10:04am] Bino: yeah, we're heading into peak time
[10:07am] mage2k: do you want to do a quick db restart an re-increase the RAM?
[10:08am] Bino: let me take a look
[10:08am] mage2k: there's actually over 250M of RAM free, so I'd think we'd also want to re-increase the innodb buffers
[10:09am] mage2k: I'm checking to see if it was due to any obvious queries now
[10:09am] Bino: ok, thanks
[10:11am] mage2k: here's one:
[10:11am] mage2k: SELECT COUNT(*) FROM (SELECT posts.url, posts.title, posts.id, posts.permalink, posts.city_id, posts.country_id, posts.user_id, posts.category_id, posts.created_at, posts.type, posts.price, posts.views_count, posts.premium, posts.body_html, posts.max_photos, posts.expires_at, posts.should_float, posts.popularity FROM posts inner join(
[10:11am] mage2k:       SELECT posts.id FROM posts
[10:11am] mage2k:       WHERE posts.active = 1 AND posts.type in ("DiscussionPost","HousingPost","SalePost","ServicePost","JobPost","EventPost") AND posts.country_city_merge in (0,1) AND expires_at > NOW()
[10:12am] mage2k:       ORDER BY should_float desc, created_at desc  ) as internal
[10:12am] mage2k:       WHERE internal.id = posts.id) AS count_table;
[10:13am] mage2k: this has the explain: https://gist.github.com/efbc2043cffb0ee2881c
[10:17am] Bino: ok, so you think we need to re-increase?
[10:18am] mage2k: in fact, a lot of those ran just before 9am PDT which coincides with the load increase
[10:18am] mage2k: those were then followed by a lot fo 2-3 second sphinx queries that processed a lot of data
[10:19am] mage2k: then a lot of huge tags queries
[10:20am] mage2k: wow, just a huge number of sphinx queries and the first query I pasted above
[10:21am] mage2k: with each sphinx query examining 70K - 100K rows
[10:23am] mage2k: so, the load's come back down to around 2 now but I'm thinking this may happen again the next time all of your sphinx updaters run
[10:24am] Bino: hmm, yeah
[10:24am] Bino: so what can we do about the sphinx updaters?
[10:25am] Bino: to reduce load from them
[10:25am] mage2k: one thing would be to stagger them so that they're only running from one slice at a time
[10:25am] Bino: right, lets do that, that's what I thought we needed to do
[10:26am] mage2k: this is since 8:50am PDT:
[10:26am] mage2k: Count: 493  Time=3.23s (1593s)  Lock=0.00s (0s)  Rows=1944.3 (958528), rede[rede]@6hosts
[10:26am] mage2k: SELECT (posts.id * N + N) AS id, posts.active AS active, posts.body AS body, posts.category_id AS category_id, posts.city_id AS city_id, 'S' AS class, N AS class_id, posts.country_id AS country_id, UNIX_TIMESTAMP(posts.created_at) AS created_at, posts.max_photos AS max_photos, posts.popularity AS popularity, posts.premium AS premium, posts.preview AS preview, posts.price AS price, CAST(GROUP_CONCAT(DISTINCT tags.name SEPARAT
[10:26am] mage2k: OR 'S') AS CHAR) AS tags, posts.title AS title, posts.type AS type, posts.user_id AS user_id FROM posts left join taggings on taggings.post_id = posts.id left join tags on tags.id = taggings.tag_id WHERE posts.id >= N AND posts.id <= N AND (active = N and expires_at > NOW()) GROUP BY posts.id
[10:26am] mage2k: 493 sphinx queries totally 1593 seconds of run time in the slow query log
[10:26am] mage2k: here's the second:
[10:26am] mage2k: Count: 25  Time=42.56s (1063s)  Lock=0.00s (0s)  Rows=1.0 (25), rede[rede]@5hosts
[10:26am] mage2k: SELECT * FROM `posts`    WHERE (`posts`.`repost_token` = 'S')  LIMIT N
[10:27am] Bino: those are the top two time consumers?
[10:27am] mage2k: right
[10:27am] mage2k: here's 3-5:
[10:27am] mage2k: Count: 78  Time=9.31s (726s)  Lock=0.00s (0s)  Rows=1.0 (78), rede[rede]@6hosts
[10:27am] mage2k: SELECT count(posts.id) AS count_posts_id FROM `posts`    WHERE (posts.active = N AND posts.type = "S" AND posts.country_city_merge in (N,N))  ORDER BY should_float desc, created_at desc
[10:27am] mage2k: Count: 108  Time=5.65s (610s)  Lock=0.00s (0s)  Rows=1.0 (108), rede[rede]@6hosts
[10:27am] mage2k: SELECT COUNT(*) FROM (SELECT posts.url, posts.title, posts.id, posts.permalink, posts.city_id, posts.country_id, posts.user_id, posts.category_id, posts.created_at, posts.type, posts.price, posts.views_count, posts.premium, posts.body_html, posts.max_photos, posts.expires_at, posts.should_float, posts.popularity FROM posts inner join(
[10:27am] mage2k: SELECT posts.id FROM posts
[10:27am] mage2k: WHERE posts.active = N AND posts.type = "S" AND posts.country_city_merge in (N,N)
[10:27am] mage2k: ORDER BY should_float desc, created_at desc  ) as internal
[10:27am] mage2k: WHERE internal.id = posts.id) AS count_table
[10:27am] mage2k: Count: 78  Time=7.03s (548s)  Lock=0.00s (0s)  Rows=25.0 (1950), rede[rede]@5hosts
[10:27am] mage2k: SELECT posts.url, posts.title, posts.id, posts.permalink, posts.city_id, posts.country_id, posts.user_id, posts.category_id, posts.created_at, posts.type, posts.price, posts.views_count, posts.premium, posts.body_html, posts.max_photos, posts.expires_at, posts.should_float, posts.popularity FROM posts inner join(
[10:28am] mage2k: SELECT posts.id FROM posts
[10:28am] mage2k: WHERE posts.active = N AND posts.type = "S" AND posts.country_city_merge in (N,N)
[10:28am] mage2k: ORDER BY should_float desc, created_at desc  ) as internal
[10:28am] mage2k: WHERE internal.id = posts.id LIMIT N, N
[10:28am] mage2k: note that 4 and 5 are basically the same query with the first being the count version
[10:28am] mage2k: Bino: ok, I have a scheduled maintenance for another client that's supposed to start right now
[10:28am] Bino: my gut feeling is, if we can just get through those, the rest is fine right? So if we can optimize those queries, stagger the sphinx updates, then we should be ok without increasing ram
[10:28am] Bino: ok, go ahead
[10:28am] Bino: and I'll go over this with sylvestre
[10:28am] mage2k: cool, I'll ping you in a bit when I'm free again to see how things are going
[10:28am] Bino: thanks!
[10:28am] mage2k: np