ブログに投稿するまでが ISUCON なので書き記します。
チーム名: パジャマ飯 最終スコア: 15000 前後
当日の流れ
時刻 | 行動 | 詳細 | スコア |
---|---|---|---|
9:00 | 起床 | - | - |
9:30 | 朝ごはん | - | - |
10:00 | スタート | - | - |
10:15 | VM を起動し SSH でログインできるようになる | - | - |
10:25 | ベンチマーク実行 | Perl | 300 前後 |
10:30 | BitBucket での管理 | - | - |
10:35 | アプリ構成を確認 | Nginx:80 -> Isuda:5000, Isutar:50001 -> MySQL | - |
10:40 | 計測コードを追加 | - | - |
11:00 | 処理が重い箇所をピックアップ | GET /, htmlify, POST /stars | - |
11:30 | ベンチが走りきらないので対処を開始 | POST /login, GET /keyword がタイムアウトしている | - |
12:00 | POST /login の対処 | random_string を都度生成するのをやめる | 3000 |
12:30 | POST /keyword の対処 | keyword と description をつなげて is_spam_contents へのリクエストを2回から1回にする | 3366 |
13:00 | POST /keyword の対処 | keyword_length を追加(これは後で Revert) | 3000 前後 |
13:30 | POST /keyword の対処(Revert) | そもそもベンチが走りきっていない事に疑問を抱く | 3000 前後 |
14:00 | top コマンドでプロセスの挙動を調べる | perl の worker 数が少ない事に気づく | - |
14:30 | Isuda の Woker数を増やす | 5 -> 15 | 9488 前後 |
15:00 | htmlify の対処 | keyword だけを selectするように修正 | 14834 |
15:15 | GET / の対処 | entry の updated_at にインデックスをつける | 15869 |
15:30 | POST '/stars' の対処 | keyword の有無だけを確認する API を追加 | 16685 |
15:45 | set_name の対処 | user テーブルを Redis 化 | 18044 |
16:30 | htmlify の対処(2) | sha1 使わずに keyword.id にしようとする | - |
17:50 | アクセスログを出力しないようにする | MySQL と Nginx の conf を修正。なぜかスコアが落ちる? | 15000前後 |
18:00 | 終了 | - | - |
使用した言語: Perl
私は業務で使用してきた言語が経歴が長い順に Perl, Node.js, Python となっているのと前日に ISUCON5 予選の練習をした時に Perl で練習したので今回は Perl を選択しています。
あと今回負荷を計測する方法として Perl の DESTROY 関数を使いたかったというの理由の一つです。Prefork しておいたプロセスが一定期間で役目を終えて kill されるので、そのタイミングまで経過時間をプロセス内に保存しておき kill されるタイミングで DESTROY にエラー出力に経過時間を吐き出す関数を用意し臨みました。
/var/log/syslog
を tail -f
していると時々その情報が出てくるのでそれを眺めながら予選に臨みました。
10:00 -> 15:00(スタート地点に立つまで)
事前に何度か練習していたため portal.azure.com
での作業は割と順調で無事 SSH でログインして作業開始までスムーズに行えました。
最初に MySQL の databases に isuda
と isutar
が存在しているのを確認し、nginx.conf を見ておそらくこのような構成だろうなという予測をしました。
nginx -> / :5000 isuda.psgi -> MySQL -> /star :5001 isutar.psgi -> MySQL
実際には後 localhost:5050
がいたのですがこの時点ではまだ気づいていませんでした。
ベンチマークを実行すると POST /login
, POST /keyword
, GET /stars
がタイムアウトしているとのメッセージが表示されます。
また、前述の計測ツールから GET /
, htmlify
, POST /stars
の処理に時間がかかっているようです。なんですがこれはあくまでベンチが走りきっていないので参考になっているか分かっていませんでした。
まずはベンチが走りきらないといけないのですが、ベンチマークがタイムアウトしている箇所を順番にソースコードの改修を行いました。これは大幅にタイムロスしました。
ソースコードを改修してもなかなかベンチマークツールが走りきらないので他に原因があるのではないかと思い top -c
コマンドをよくよく見てみると Perl の worker 数が少ない気がしました。
isuda の worker 数を 5 -> 10 にすると点数が跳ね上がりベンチマークツールが完走しました。さらに 15, 20 と試して最終的に 15 に設定して数値が 9488 をマークしました。
真っ先に worker 数を増やしておけばベンチマークツールが完走するので負荷の高い場所を重点的に修正できたのですが、ベンチマークツールを完走させるために is_spam_contents でのリクエストを keyword, content を結合して2回のリクエストを1回にするなど、序盤は比較的負荷の少ない部分の改修(そうだと知りつつもベンチマークが回りきらないと話にならないので)を頑張っていました。
というわけで開始5時間経過してやっと ISUCON6 のスタート地点に立つ事ができました。
15:00 -> 16:00(順風満帆)
というわけで後は以下の通り順調に作業が進みました。
時刻 | 行動 | 詳細 | スコア |
---|---|---|---|
15:00 | htmlify の対処 | keyword だけを select するように修正 | 14834 |
15:15 | GET / の対処 | entry の updated_at にインデックスをつける | 15869 |
15:30 | POST '/stars' の対処 | keyword の有無だけを確認する API を追加 | 16685 |
15:45 | set_name の対処 | user テーブルを Redis 化 | 18044 |
本当はまだまだ改修したいポイントはあったんですが、いかんせん手がたりない。
当初の予定では16:00以降は MySQL, Nginx の設定を修正したり VM 再起動した後にちゃんと動くかどうかの確認をしてコードをいじらない予定でした。
なんですが 16:00 ぐらいまでリーダーズボードに少しだけ登場したりしていたのでなんとなく欲がでてきました。そして後際立って重い処理である htmlify が残っていました。こちらの改修ポイントは以下の2点
A: 1プロセスがここの処理を 2 秒前後時間かかっている keyword を取得する処理と
my $keywords = $self->dbh->select_all(qq[ SELECT keyword FROM entry ORDER BY CHARACTER_LENGTH(keyword) DESC ]);
B: 1プロセスがここの処理を 10 秒以上時間かかっているここの処理
$content =~ s{($re)}{ my $kw = $1; $kw2sha{$kw} = "isuda_" . sha1_hex(encode_utf8($kw)); }eg;
せっかくのチャレンジだったので、残り時間は B のために全部使いました。うまくいけば大幅なスコアアップが望めるかも...
で、残念ながら結果が出ませんでした。sha1_hex しないで id そのまま使えばいいんじゃないかと思ったんですがあんまり速くならず。
感想
今回の目標は負荷の高い処理を計測して、そこにちゃんと対処する。という事がちゃんとできるかどうかを自分に課していました。
とりあえず幾つかはボトルネックを発見して修正する事ができました。なんですが序盤でソースコードばかり見すぎていて OS のリソースがどれぐらい利用されているかなどなどを全く見ていなかったのは反省点です。
あと終盤で htmlfiy で経過する時間が大きいからその関数自体を速くしようとしてしましましたが、そもそもその関数を呼び出している箇所がどこで、何度もそこを呼ぶ必要が本当にあるのか?という点を考慮しませんでした。視野が狭くなっていたのが反省点です。もういいおっさんなので目先の事よりももっと遠く、広く見渡せるようにならないとなあ。
とはいえ今回も楽しめて、いっぱい知識的なお土産を手に入れる事ができました。このような機会を今年も提供していただいた運営者と出題者の皆さまありがとうございました。あとはベンチマークツールが公開されたらしっかり復習したいと思います。