猿に文明を与えるな

個人的な勝手なまとめ。

ISUCON4 予選遊び (2)

思い出す

newrelicをセットしたが、データが表示されない・・・ と思ってたら10minくらいしたら表示された。

初期測定

$ ./benchmarker bench 
#=> 12:59:08 type:score     success:5610    fail:0  score:1212

MySQL

遅いクエリを探す

# my.cnf
slow_query_log = ON
slow_query_log_file = /tmp/mysql-slow.log
long_query_time = 0.5

初期のデータロードだけがひっかかった。無視。

INSERT INTO `users` (`id`, `login`, `password_hash`, `salt`) VALUES

測定

workloadを増やしていき、どこで詰まるか確認

workload 3 #=> 13:06:18 type:score     success:10750   fail:0  score:2323
workload 5 #=> 13:09:07 type:score     success:11490   fail:0  score:2483
workload 7 #=> 13:10:59 type:score     success:11170   fail:0  score:2416 

5を限界と考える。

MySQL

パラメータを確認

query_cache_size: 0
thread_cache_size: 0

0は無いだろうと考え、次のように変更

# /etc/my.cnf
query_cache_size = 160M
thread_cache = 100
測定

大して変わらず

13:26:04 type:score     success:11965   fail:1  score:2588

アプリ

遅いリクエストを検出

/etc/nginx/nginx.confを変更

http {
  upstream app {
    server 127.0.0.1:8080;

  }

  # add this two directives
  log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                    '$status $body_bytes_sent "$http_referer" '
                    '"$http_user_agent" "$http_x_forwarded_for" $request_time';
  access_log  /var/log/nginx/access.log  main;

  server {
    location / {
      proxy_pass http://app;
    }
  }
}

だいたい2-5ミリ秒で変わらん・・・

遅そうなロジック探す

attempt_loginメソッドの中で呼ばれている次のメソッドが気になった。

  • ip_banned?
  • user_locked?

ひとまずキャッシュを入れる。

     helpers do
+      def dc
+        @dc ||= Dalli::Client.new('localhost:11211', {
+          :namespace => "isucon",
+          :compress => true
+        })
+      end
+
(中略)
       def user_locked?(user)
         return nil unless user
+        return true if dc.get("#{user['id']}-locked")
         log = db.xquery("SELECT COUNT(1) AS failures FROM login_log WHERE user_id = ? AND id > IFNULL((select id from login_log where user_id = ? AND succeeded = 1 ORDER BY id DESC LIMIT 1), 0);", user['id'], user['id']).first
 
-        config[:user_lock_threshold] <= log['failures']
+        ret = (config[:user_lock_threshold] <= log['failures'])
+        dc.set("#{user['id']}-locked", ret)
+        ret
       end
 
       def ip_banned?
+        return true if dc.get("#{request.ip}-banned")
         log = db.xquery("SELECT COUNT(1) AS failures FROM login_log WHERE ip = ? AND id > IFNULL((select id from login_log where ip = ? AND succeeded = 1 ORDER BY id DESC LIMIT 1), 0);", request.ip, request.ip).first
 
-        config[:ip_ban_threshold] <= log['failures']
+        ret = (config[:ip_ban_threshold] <= log['failures'])
+        dc.set("#{request.ip}-banned", ret)
+        ret
       end

スコアは大して変わらず: 14:43:18 type:score success:12330 fail:0 score:2666


メモリ全然使ってないので大きく何かを載せることで改善しそうな気がする。