ISUCON4の予選問題をやってみる。(その1) #isucon

巷ではISUCON5の予選が終わり本戦に向けて盛り上がっている最中、第4回のISUCON4をやってみるという時期外れのエントリー

前々からやってみたかったというのと、じゃあISUCON5やってみようかと思ったらGCEだったからなんか面倒そうだったので一つ前のISUCON4をということ。

ISUCON4

こちらに問題とか指定のAMIとかが掲載されている

ISUCOM まとめ
http://isucon.net/archives/41252218.html
ISUCON4 予選問題の解説と講評＆ AMIの公開
http://isucon.net/archives/40724693.html

環境構築

AMI
ami-e3577fe2

Instance Type: m3.xlarge
EBS Optimization: なし
Root Volume: 8GB, Magnetic (NOT SSD)

上記のAMIで EC2 を立ち上げる. 80もアクセス可能にしとく
ステータスチェックが完了したらsshでアクセス可能になる. この辺はEC2のことなので省略

$ ssh -i .ssh/hiyuzawa_dev.pem ec2-user@xxx.xxx.xxx.xx

HTTPアクセスすると試験問題環境にアクセスできる。デフォルトはRubyで動いているらしい。とりあえずperlに変える。

$ sudo /etc/init.d/supervisord stop
$ sudo vim /etc/supervisord.conf #rubyのautostartをfalse perlのをtrueに変更
$ sudo /etc/init.d/supervisord start

startの時にperl版が起動しなくて少しハマったけどRubyプロセスが起動しっぱなしだったのでKillしてstartしたら立ち上がった.
困ったら下記のログあたりを参照

$ tail -f /tmp/isucon.perl.log

plack で startmanが起動してる
├─supervisord(3084)───starman master (3086)─┬─starman worker (3087) │ ├─starman worker (3088) │ ├─starman worker (3089) │ ├─starman worker (3090) │ └─starman worker (3091)

80番Portでブラウザからアクセスしてみると仮の銀行のログイン画面が表示される。今回の問題用のダミーサイト。

とりあえずbenchmarkしてみる

手順書通りにやってみる

$ sudo su - isucon
$ ./benchmarker bench
 13:11:17 type:score     success:6880    fail:0  score:1487

ドキュメントではperl版の初期スコアは3000点ぐらいと書いてあるけど1487点しかいかない... まあいいか。

最適化してみる

敵を知る準備

まずは敵を知るという意味でアクセスログを眺める。nginx側は

$ tail -f /var/log/nginx/access.log

で確認できるけど ReverseProxy側のログも見たいので　app.psgi に以下を追記

builder {
  enable "AccessLog",
    format => "combined";

これで

$ tail -f /tmp/isucon.perl.log

にReverseProxy側のログも流れてきた。(もう一度Benchmarkするとスコアも変化しないのでこのログ排出での性能劣化は軽微)

静的ファイルをnginx側で処理

基本ですね。とりあえずやる。

# sudo vim /etc/nginx/nginx.conf
http {
  ...
  server {
    location ~* \.(css|png)$ {
      root /home/isucon/webapp/perl/public;
      break;
    }
    ...
  }
}

nginxの再起動

$ /etc/init.d/nginx restart

まあ、大してスコアは変わらない

$ ./benchmarker bench
13:39:46 type:score     success:7400    fail:0  score:1599

少し負荷をかけて見る

$ ./benchmarker bench --workload 5
13:45:03 type:score     success:15470   fail:0  score:3345

topでみると MySQLが、CPU食いまくってブン回っている

MySQLをちょっとプログラムソースから調べてみる。

みるからにMySQL負荷をかけているSQLは以下

'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)',

'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)',

login_logというテーブルの定義は以下、

mysql> show create table login_log\G
*************************** 1. row ***************************
       Table: login_log
Create Table: CREATE TABLE `login_log` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `created_at` datetime NOT NULL,
  `user_id` int(11) DEFAULT NULL,
  `login` varchar(255) NOT NULL,
  `ip` varchar(255) NOT NULL,
  `succeeded` tinyint(4) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=71548 DEFAULT CHARSET=utf8

user_idとipにindex作れば負荷は下がるはずなので追加

# sql/schema.sql
CREATE INDEX idx_user_id on login_log(user_id);
CREATE INDEX idx_ip on login_log(ip);

またまたベンチマーク

14:15:45 type:score     success:80686   fail:9811       score:17756

これだけで17756。でもfailが出てきたのでログを見ると

14:19:44 type:fail      reason:Get http://localhost/: dial tcp 127.0.0.1:80: cannot assign requested address    method:GET      uri:/

なにやら怪しげなログ。cannot assign address とかある。TIME_WAIT増殖問題っぽい。もう一度ベンチマーク起動しつつ実行中に

$ netstat | grep TIME_WAIT | wc -l

するとぐんぐん数値が増えてくる。

sysctlの調整(TIME_WAIT回避)

$ sudo sysctl -n net.ipv4.tcp_tw_recycle
0
$ sudo sysctl -w net.ipv4.tcp_tw_recycle=1
net.ipv4.tcp_tw_recycle = 1
$ sudo sysctl -n net.ipv4.tcp_tw_recycle
1
$ sudo sysctl -w net.ipv4.tcp_tw_reuse=1
$ sudo sysctl -n net.ipv4.tcp_fin_timeout=15

これでベンチマーク再度実行

$ ./benchmarker bench --workload 5
14:25:18 type:score     success:98890   fail:0  score:21362
$ ./benchmarker bench --workload 10
14:27:11 type:score     success:112110  fail:0  score:24222

やみくもに最後に並列度を10にしたら24222まで上がった。

まだまだ遥か予選落ちレベルですね。
http://isucon.net/archives/40576269.html

これからKVSなどメモリに乗せたりして、プログラムも変更していろいろやってスコアを上げていくんでしょうね。
いろいろ頭の中ではあれしたらいいとかチューニングはあるので、それをやると実際どこまで上がるのか興味あるのでまた今度続きやります。
実際にやると楽しいですね。。。

次回やってみた