Gマイナー志向

とくに意味はありません

ISUCON3予選でチーム└('-'└)として参加した&やったこと

ISUCON3の予選にチーム└('-'└)として参加してきました。スコアは10784.5で暫定15位、問題がなければ本戦に進める予定です。
以下、やったことをつらつらと。

チーム編成

今回は職場の同僚であるyamasakiさんとfujiwaraさんと私の3人で参戦しました。自分以外は初参加だったため、本戦を見越してOJTで進めました。残念ながらSELinuxはdisabledです。
ちなみに弊社からは学生枠暫定2位のチーム( (0) / (0)) ☆祝☆も参戦しています。

事前準備

前日の夕方、Amazon Management Consoleで、AMIの選択からログインするところまでシミュレーションをしておきました。
ちなみにその際にAmazon IAMで自分以外のアカウントも作り、3人のうち誰でもログインできるようにしておきました。もしAMIの作成も時間内に行う必要があるのであれば、作業分担ができるようにするためです。

当日序盤

前日にシミュレーションしておいたこともあって、AMI-idの公開から実際にインスタンスを起動するところまでスムーズに実行することができました。
開始から10分で最初のベンチマーク実行、この時点で暫定一位。

まず状況を確認、ApacheMySQL、supervisord経由で起動されたStarmanなどを確認、自分はPerlが慣れているのでPerlのまま進めることにしました。

負荷の確認はdstatとtopで

負荷の状況はdstatとtopで確認してました。topからmysqldの負荷が高いこと、dstatからI/Oが多いことを確認していました。
ちなみに、dstatのオプションは-tlampが好きです。

dstat -tlamp

/etc/my.cnfがなかったけど気にしない

MySQLのチューニングをするためにmy.cnfを探してみたものの簡単には見つからなかったのですが、そんなことはあまり気にせず、MySQLの設定を/usr/share/doc/MySQL-server-5.6.14/からもってきて、そこに一般的なチューニングパラメータを追加していきました。

cp /usr/share/doc/MySQL-server-5.6.14/my-default.cnf /etc/my.cnf

適当な設定を投入後、mysqldのrestartで設定が反映されていることを確認。

また、環境に合わせたパラメータチューニングは何度かベンチマークを回したあとに
MySQLTuner-perlを使いました。これ仕事でも愛用してます。

wget -O mysqltuner.pl mysqltuner.pl
perl mysqltuner.pl

Apacheからnginx変更

Apacheからnginxに変更して/css,/js,/img,favicon.icoのリソースはnginxから返すようにしました。

        location / {
                proxy_pass http://localhost:5000;
                proxy_set_header Host $host;
        }
        root /home/isucon/webapp/public;
        location /css {
          access_log off;
        }
        location /js {
          access_log off;
        }
        location /img {
          access_log off;
        }
        location /favicon.ico {
          access_log off;
        }

またその際にアクセスログに$request_timeを追加して、どのリクエストの応答時間が遅いのかを出力するようにしました。

    log_format  main  '$request_time $remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';

あとで集計しやすいように頭に追加。
上記のtop、dstatと合わせてリクエストの応答時間もチューニングの指標にしています。

MySQLのテーブルにインデックスを張る

PerlのプログラムからSELECTのクエリをgrepして、必要なテーブルにインデックスを追加しました。

grep SELECT /home/isucon/webapp/perl/lib/Isucon3/Web.pm
ALTER TABLE memos ADD INDEX (is_private, created_at);
ALTER TABLE memos ADD INDEX (user, created_at);
ALTER TABLE memos ADD INDEX (user, is_private, created_at);

ただ、手動でインデックスを追加してもベンチマークを回すたびにインデックスがなくなり、/home/isucon/webapp/config/schema.sqlのCREATE TABLE文に追記しても反映されなかったため、インデックスを追加するシェルスクリプトを作成し、ベンチマーク実行時の--initオプションでスクリプトを実行するようにしました。

/home/isucon/init.sh

(
  echo 'ALTER TABLE memos ADD INDEX (is_private, created_at);'
  echo 'ALTER TABLE memos ADD INDEX (user, created_at);'
  echo 'ALTER TABLE memos ADD INDEX (user, is_private, created_at);'
) | mysql -u root -proot isucon 2>/dev/null
isucon3 benchmark --init=/home/isucon/init.sh

プログラムからの応答を1秒間キャッシュして返すようにしてみるがチェックに引っかかるので諦めた

1秒程度の短い時間ならキャッシュしても問題ないんじゃないかと考え、isucon_sessionのクッキー所有者ごとにキャッシュする実装に変えてみました。

    proxy_cache_path /dev/shm/nginx_cache levels=1:2 keys_zone=default:512m inactive=1m max_size=512m;
    proxy_temp_path /dev/shm/tmp;
(中略)
        set $do_not_cache 0;
(中略)
        proxy_no_cache $do_not_cache;
        proxy_cache_bypass $do_not_cache;
        proxy_cache default;
        proxy_cache_methods GET HEAD;
        proxy_cache_key "$scheme$proxy_host$request_uri$cookie_isucon_session";
        proxy_cache_valid 200 1s;

がしかし、どうやってもベンチマークプログラムのチェックがエラーになり解決できそうにないため、ここにこだわるのはやめてキャッシュすることを諦めています。

MySQLでクエリーキャッシュを部分的に有効にした

memosは何度も更新されるからクエリーキャッシュを効かせても逆効果と考えて、SQL_CACHE構文で特定のクエリに対してのみキャッシュを行うようにSQLを書き換えました。

my.cnf

query_cache_size = 128M
query_cache_limit = 64M
query_cache_type = 2

Web.pm変更例

-'SELECT * FROM users WHERE id=?',
+'SELECT SQL_CACHE * FROM users WHERE id=?',

-'SELECT username FROM users WHERE id=?',
+'SELECT SQL_CACHE username FROM users WHERE id=?',

-'SELECT id, username, password, salt FROM users WHERE username=?',
+'SELECT SQL_CACHE id, username, password, salt FROM users WHERE username=?',

トップページや/recent/:pageなどで毎回ユーザ情報を取得していた部分をキャッシュするようにした

このあたりからプログラムのソースを本格的に見始めました。応答時間が遅いリクエストが/recent/:pageだったのでそのあたりを中心に確認したところ、無駄にSELECTしている部分があったのでPerlでキャッシュするようにしました。

変更前

    for my $memo (@$memos) {
        $memo->{username} = $self->dbh->select_one(
            'SELECT SQL_CACHE username FROM users WHERE id=?',
            $memo->{user},
        );
    }
||
変更後
>|perl|
    my $cache = {};
    for my $memo (@$memos) {
        my $user = $memo->{user};
        unless (exists $cache->{$user}) {
          $cache->{$user} = $self->dbh->select_one(
              'SELECT SQL_CACHE username FROM users WHERE id=?',
              $user,
          );
        }
        $memo->{username} = $cache->{$user};
    }

この部分ではJOINでの実装も試してみたのですが、圧倒的に遅くなったので元に戻して上のようなキャッシュ実装に変更しています。最終的にmy $cache = {};は一番外側に追い出してグローバル変数のように扱いました。

Plack::Middleware::Profiler::NYTProfでプロファイリングしてみたがよくわからなかった

こちらの記事を参考にしながらPlack::Middleware::Profiler::NYTProfを導入してみたのですが、うまく使いこなせませんでした。NYTProfを入れた状態でbenchmarkを走らせたために沢山プロファイル結果が生成されてしまい、どれを見ればいいのかわからなくなったんですね。今思えばブラウザなどでアクセスしてみて確認すればよかったんや…。

NYTProfの結果からuri_for()の処理に時間がかかっていた

NYTProfをうまく使いこなせなかったものの、確認すると$c.req.uri_for()の処理に時間がかかっていたことから、$c.req.uri_for()の部分は絶対URLを直書きにしてみました。
しかし絶対URL直書きだとなぜかベンチマークのチェックに引っかかってしまうため直書きを諦めて、以下のように毎回呼ばないようにしました。

変更前

: for $memos -> $memo {
<li>
  <a href="<: $c.req.uri_for('/memo/') :><: $memo.id :>"><: $memo.content.split('\r?\n').first() :></a> by <: $memo.username :> (<: $memo.created_at :>)
</li>
: }

変更後

: my $memourl = $c.req.uri_for('/memo/') 
: for $memos -> $memo {
<li>
  <a href="<: $memourl :><: $memo.id :>"><: $memo.content.split('\r?\n').first() :></a> by <: $memo.username :> (<: $memo.created_at :>)
</li>
: }

innodb_log_fileを/dev/shm/に移した

途中ディスクフルになる事態が発生したため容量の削減を図っていたのですが、その時にふとinnodb_log_fileをtmpfsに載せればいいんじゃないかと気づき、innodb_log_group_home_dirを/dev/shm/に移してみました。

innodb_log_file_size = 1G
innodb_log_files_in_group = 4
innodb_log_group_home_dir = /dev/shm/

innodb_log_fileは起動時に存在しなくても作成されること、レギュレーション的にも問題ないことから移したのですが、その結果ディスクI/Oがほとんどなくなりました。これ結構効いたかも。

/memo/:idのolder,newerが無駄だったのでなんとかした

/memo/:idも応答時間が遅いリクエストだったため、以下のように書き換えています。うおおお俺のSQL力が試されている!

変更前

    my $memos = $self->dbh->select_all(
        "SELECT * FROM memos WHERE user=? $cond ORDER BY created_at",
        $memo->{user},
    );
    my ($newer, $older);
    for my $i ( 0 .. scalar @$memos - 1 ) {
        if ( $memos->[$i]->{id} eq $memo->{id} ) {
            $older = $memos->[ $i - 1 ] if $i > 0;
            $newer = $memos->[ $i + 1 ] if $i < @$memos;
        }
    }

変更後

    my $newer = $self->dbh->select_row("SELECT SQL_CACHE id FROM memos WHERE user=? AND id > ? $cond ORDER BY id ASC LIMIT 1", $memo->{user}, $memo->{id});
    my $older = $self->dbh->select_row("SELECT SQL_CACHE id FROM memos WHERE user=? AND id < ? $cond ORDER BY id DESC LIMIT 1", $memo->{user}, $memo->{id});

もっと効率のいいSQLがあったかもしれませんが、まぁこんな感じに。

外部プログラムのmarkdownを呼び出しているところをText::Markdownに書き換えた

プログラム内でMarkdown書式をhtmlに展開するためにmarkdownコマンドを呼び出している部分に気づいたため、ググって最初にでてきたText::Markdownに置き換えました。Text::Markdownに置き換えてもベンチマーク上は問題がなかったことから、それ以上は深く追求はしてません。

いらないカラムを取っ払ったりとか不要な書き換えUPDATEを削除とか

SELECT * FROM ...としている部分は、実際に使われているカラムを調べてカラムを直指定にしたり、usersテーブルのlast_accessカラムの更新はどこからも参照されてないので取っ払ったり、saltの生成に使用しているsha256_hex()を外したりしました。

StarmanをStarletに変えてみた

このあたりでMySQLだけでなくPerlプログラムの負荷が増えてきたのでStarmanからStarletに切り替えました。

禁断のtcp_rw_reuseを有効にした

副作用が大きいため普段仕事では使わないnet.ipv4.tcp_tw_reuseを1に設定しました。ベンチマークと対象サーバが同一で閉じたネットワークのためです。/etc/sysctl.confに追記したのはとりあえず以下の通り。

net.ipv4.tcp_tw_reuse = 1
net.ipv4.tcp_fin_timeout = 30
net.ipv4.tcp_tw_recycle = 1
net.ipv4.ip_local_port_range = 16384 65535

ベンチマークプログラムの--workerを1ずつ増やしていった

このあたりはもう終盤ですが、isucon3 benchmarkの--workerをデフォルトの1から2に変更したところスコアが上がったので、徐々に数字を増やしていき一番スコアが高くなるところを探りました。
だいたい7か8あたりがピークで一番いいスコアになり、それ以上はTimeoutが頻発する状況となりました。

全力で/etc/motdを作りこんだが失敗に終わった

終盤、運営の皆様へ愛のメッセージを伝えようと/etc/motdを作りこんだのですが、サーバが再起動すると/etc/motdがAmazon Linux側で上書きされてしまうらしく、我々のメッセージは残念ながら届けられませんでした。残念。

まとめ

本戦ではmotdをしっかりとキメたい。
運営の皆様ありがとうございます。お疲れ様でしたあああああ!