猿に文明を与えるな

個人的な勝手なまとめ。

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)でリクエストを捌ききれていないので要調査。


初めてオフラインで集まってやったけど、なかなか楽しい。