ISUCON3遊び (5)
おさらい
前回時点のもので、MySQLからの戻りをそのまま利用してエラーが出ていたので対処
--- a/ruby/app.rb +++ b/ruby/app.rb @@ -175,7 +175,9 @@ class Isucon3App < Sinatra::Base end older = nil newer = nil + + memos = memos.to_a # Arrayに変換 + 0.upto(memos.count - 1).each do |i| if memos[i]["id"] == memo["id"]
とりあえずエラー解消。ベンチマークで 750-800 あたり
何をするか
workload 1でこれだけ出てるのでスケールアウトさせる手もあるがもう少し粘る。
- MySQLでのスロークエリ (1sec以上) があるか #=> ない
とりあえず遅いリクエストを探すことに
goaccessでリクエストの統計を確認
GoAccess - Visual Web Log Analyzer を使い、アクセスを見る
2 - Top requests (URLs) Total: 366/494 Top requests sorted by hits - [avg. time served | protocol | method] 301 1 7.23% 4.17 MiB 845.43 ms GET HTTP/1.1 / 119 1 2.86% 158.63 KiB 123.84 ms GET HTTP/1.1 /signin 119 1 2.86% 0.0 B 122.84 ms POST HTTP/1.1 /signin 119 1 2.86% 1.66 MiB 547.89 ms GET HTTP/1.1 /mypage 119 1 2.86% 0.0 B 156.86 ms POST HTTP/1.1 /memo 119 1 2.86% 0.0 B 248.86 ms POST HTTP/1.1 /signout 33 1 0.79% 0.0 B 106.00 us OPTIONS HTTP/1.0 *
見方詳しく分からないが、おそらく平均的にトップページが遅い様子なので対処することに。
トップページが遅い問題への対処
クエリは以前改良したので、それ以外の部分を見る。
MySQLのパラメータを見ると、クエリキャッシュが効いてなかった...
=>対処
$ cat /etc/my.cnf [mysqld] innodb_additional_mem_pool_size = 20MB innodb_log_buffer_size = 64MB sort_buffer_size = 4MB query_cache_limit = 8MB query_cache_size = 256MB query_cache_type=1 # 追加
=>これで 850くらいに
クエリキャッシュヒット率を確認
$ mysqladmin -u isucon -p extended-status | grep Qcache Enter password: | Qcache_free_blocks | 2 | | Qcache_free_memory | 266090520 | | Qcache_hits | 57587 | | Qcache_inserts | 3211 | | Qcache_lowmem_prunes | 0 | | Qcache_not_cached | 105 | | Qcache_queries_in_cache | 61 | | Qcache_total_blocks | 134 | [isucon@ip-172-30-2-22 ruby]$ irb irb(main):001:0> 57587.0 / (57587 + 3211 + 105) * 100 => 94.5552764231647
トップページが遅い問題への対処結果
2 - Top requests (URLs) Total: 350/350 Top requests sorted by hits - [avg. time served | protocol | method] 129 1 4.76% 1.77 MiB 398.49 ms GET HTTP/1.1 / 54 1 1.99% 71.98 KiB 10.28 ms GET HTTP/1.1 /signin 54 1 1.99% 0.0 B 43.95 ms POST HTTP/1.1 /signin 54 1 1.99% 0.0 B 44.92 ms POST HTTP/1.1 /memo 54 1 1.99% 759.94 KiB 359.51 ms GET HTTP/1.1 /mypage 54 1 1.99% 0.0 B 28.26 ms POST HTTP/1.1 /signout 10 1 0.37% 0.0 B 99.00 us OPTIONS HTTP/1.0
=>レスポンスタイムが半分くらいに減少
しかし、レスポンスサイズが落ちてるのは何かおかしい気がする。
トップページアクセス処理の改良
調子に乗ってトップページ、memos取得SQLの変更部分
を変更する。
=>ループしてユーザ名を取得するのを止めて、INNER JOINして取得するように変更
- memos = $mysql.query("SELECT * FROM memos WHERE is_private=0 ORDER BY created_at DESC, id DESC LIMIT 100") - memos.each do |row| - row["username"] = $mysql.xquery("SELECT username FROM users WHERE id=?", row["user"]).first["username"] - end + memos = $mysql.query("SELECT m.id, m.content, m.created_at, u.username FROM memos m inner join users u on m.user = u.id WHERE m.is_private=0 ORDER BY m.created_at DESC, m.id desc limit 100") erb :index, :layout => :base, :locals => { :memos => memos,
ここでベンチマーク実行時のTimeout数が20近くになりFAIL判定になるように。 どこか (Apache/Passenger/Unicorn/MySQL)でリクエストを捌ききれていないので要調査。
初めてオフラインで集まってやったけど、なかなか楽しい。