第２回模擬ISUCONやりました
こんにちは。
今回は、一昨日行った第２回模擬ISUCONの模様をお届けします。
題材はISUCON5予選問題。
マニュアルがこちら。
そして会場は、沖縄で一番インターネットに近い場所、ぼくらのお師匠さんであるさぼさんの城、ギークハウス沖縄。
前置きはこれぐらいにして、早速内容の方に。
1.Azure童貞卒業
はい、卒業しました。
今回はAWSではなく、さぼさんの提案でMicrosoftのAzureを使いました。
ってことでAWSと同じく、サーバーにSSHでログインできるユーザーとしてマサとディックス君を追加します。
.ssh下にあるauthorized_keysに、２人の公開鍵を登録します。
これでおっけー。
2.ログファイルの設定
前回のハッカーズチャンプルーで行ったpixivさんの第１回模擬ISUCON同様、ログファイルの設定を行なっていく。
過去記事にて割愛。
Nginxのログファイルは前回よりスムーズにできた。
「}（閉じ括弧）」忘れによるエラーが出たこともあったけどww
mysqlは、myprofilerを使ってのスロークエリの監視が最後までできなかった。
原因は、ディックス君がインストールしたものが古いバージョンだったためww
バージョンって大事ね。
3.ボトルネックはどこだ!?
とりあえずnginxのログとtopコマンドで怪しそうなところを探った。
まずはnginxのaccess.log。
alpで整形したらこんな感じ。
下のほうを見ていくと、
ん、何か重そうなのがある!?
/initializeとはなんぞや。
get '/initialize' do
db.query("DELETE FROM relations WHERE id > 500000")
db.query("DELETE FROM footprints WHERE id > 500000")
db.query("DELETE FROM entries WHERE id > 500000")
db.query("DELETE FROM comments WHERE id > 1500000")
end
初期化を行なってるみたい。
でもなんだろう、なんかイケてない感じがするのはぼくだけだろうか。
とりあえずもうちょっとログ見てみることに。
お、"/"がなんか大変だぞ。
ってことでソースコードに。
get '/' do
authenticated!
profile = db.xquery('SELECT * FROM profiles WHERE user_id = ?', current_user[:id]).first
entries_query = 'SELECT * FROM entries WHERE user_id = ? ORDER BY created_at LIMIT 5'
entries = db.xquery(entries_query, current_user[:id])
.map{ |entry| entry[:is_private] = (entry[:private] == 1); entry[:title], entry[:content] = entry[:body].split(/\n/, 2); entry }
comments_for_me_query = <<SQL
SELECT c.id AS id, c.entry_id AS entry_id, c.user_id AS user_id, c.comment AS comment, c.created_at AS created_at
FROM comments c
JOIN entries e ON c.entry_id = e.id
WHERE e.user_id = ?
ORDER BY c.created_at DESC
LIMIT 10
SQL
comments_for_me = db.xquery(comments_for_me_query, current_user[:id])
entries_of_friends = []
db.query('SELECT * FROM entries ORDER BY created_at DESC LIMIT 1000').each do |entry|
next unless is_friend?(entry[:user_id])
entry[:title] = entry[:body].split(/\n/).first
entries_of_friends << entry
break if entries_of_friends.size >= 10
end
comments_of_friends = []
db.query('SELECT * FROM comments ORDER BY created_at DESC LIMIT 1000').each do |comment|
next unless is_friend?(comment[:user_id])
entry = db.xquery('SELECT * FROM entries WHERE id = ?', comment[:entry_id]).first
entry[:is_private] = (entry[:private] == 1)
next if entry[:is_private] && !permitted?(entry[:user_id])
comments_of_friends << comment
break if comments_of_friends.size >= 10
end
friends_query = 'SELECT * FROM relations WHERE one = ? OR another = ? ORDER BY created_at DESC'
friends_map = {}
db.xquery(friends_query, current_user[:id], current_user[:id]).each do |rel|
key = (rel[:one] == current_user[:id] ? :another : :one)
friends_map[rel[key]] ||= rel[:created_at]
end
friends = friends_map.map{|user_id, created_at| [user_id, created_at]}
query = <<SQL
SELECT user_id, owner_id, DATE(created_at) AS date, MAX(created_at) AS updated
FROM footprints
WHERE user_id = ?
GROUP BY user_id, owner_id, DATE(created_at)
ORDER BY updated DESC
LIMIT 10
SQL
footprints = db.xquery(query, current_user[:id])
locals = {
profile: profile || {},
entries: entries,
comments_for_me: comments_for_me,
entries_of_friends: entries_of_friends,
comments_of_friends: comments_of_friends,
friends: friends,
footprints: footprints
}
erb :index, locals: locals
end
"/"のモリモリ感がすごい。
ここでとりあえずベンチマークを走らせるのだが、同じようなクエリがめっちゃ走ってることに気づく。(キャプチャするの忘れてました。)
この時思ったのが、「N+1問題」。
確信はなかったが、DBのボトルネックになりがちなのがどうやらこの「N+1問題」らしい。
ここも臭いと思いつつももうちょい探る。
"/"に戻るけど、このブロック内で使われてるメソッドを見てみる。
やはり臭そうなところがあった。
def get_user(user_id)
user = db.xquery('SELECT * FROM users WHERE id = ?', user_id).first
raise Isucon5::ContentNotFound unless user
user
end
topコマンドからもわかるように、mysqlがまず最初のボトルネックだったみたい。
第１回模擬ISUCONで学んだのは、
「DBから取ってくる情報は必要なやつだけ」
この get_userメソッドではユーザー情報を全部取ってきてるのがイケてない。
よって、"/"がモリモリになっちゃうって予測。
とりあえずキャッシュさせてみるが変わらず。（試しにやってみただけww）
次にやろうとしたのがsql文の書き換え。
さっきの「N+1問題」の記事に書いてあるが、テーブル同士をJOINさせようというもの。
なんですが、ここで終了間際wwwww
「ベンチ行ってらっしゃぁぁぁぁい！！！」
19.8点wwwwwwwwwwwwwwww
しかもタマキって誰や。勝手に出てくんなよ。
最後にもう一回ベンチ走らせるが、最悪の0点.....。
キャプチャはあえて憚らさせていただきます....。
............................終了。
4.反省
最初のサーバー立ち上げはスムーズにできたのでよかったかなと。
ユーザー追加も難なくできたので、前回のAWS触った経験が活きててよかった。
あとはもっと早くできるようになること。
実際のチューニング作業に移るまでに相当の時間がかかった。
それもログファイルの設定。
バージョン違いによる動作不良は、本番では勘弁したい。
よってここの設定をいかに早くできるかが重要。
そもそもボトルネックはまずぼくらにあった感じwww
第２回模擬ISUCONのソースコードは初見。（本番環境とほぼ同じ）
じっくりソースコードを読んでる時間はないので、やはりログ解析をしっかり行えることが先決かな。ログは嘘つかないので。
個人的に、今回はエディタを使わずにvimを使ってイジイジしてた。
こうでもしないと慣れないのでwww
結果的にまぁまぁ使えるようになったのでよかったかな。
あとは、分業できるところは分業させて効率化を図りたいところ。
なんだけど、やはり初歩的なミスがまだ多いので、お互いフォロー・チェックし合いながらの方がよさそう。
とまぁ、こんな感じです。
スコア０はさすがに面喰らったwww
