#isucon 4予選参戦記 - 2日目暫定3位でした

ISUCON4予選2日目に.datというチームで参加してきました。普段はCookpadRailsAndroid書いてます。

.datは@kani_b (前職の同僚で現職の同僚)と@y_matsuwitter (前職の同僚)と僕というメンバー構成で、 前職の同僚でチームを作りました。
久々のメンバーと共に1つの課題に全力で取り組むことができてすごく楽しかったです!!!!!!!!!

運営のみなさんありがとうございました!&お疲れ様でした!

予選ではgolang参考実装を元に改善し、計測最終スコアは51,045で2日目暫定3位となりました。
AMIの検査に問題がなければ本戦に出場できる見込みです。やったー!

どのように当日までに準備をし、本番を迎えたのかをつらつらと記録しようと思います。

改善施策の詳しい内容は @kani_b, @y_matsuwitterが書いてくれるはず!(書かれたらリンク貼っておきます

3行でまとめ

  • fluentdを用いた分析環境の構築など事前準備を念入りにした
  • メンバーの役割分担がうまく効いた
  • たのしかった!!!!!!!!!!!!

準備

1ヶ月前

チームメンバーで集まり、

  • 役割分担
  • 当日のワークフロー
  • 宿題

を話し合いました。

役割分担

@kani_bはインフラを専門とした実務経験が豊富なためOpsに専念し、@y_matsuwittergolangへの造詣が深いためDevに専念することにしました。 僕はgolangの実務経験が全くないこともあり、チーム全体のファシリテーションと分析、小さい変更を担当としました。

当日のワークフロー

ワークフローと書きましたが厳密に取り決めをしたわけではなく、セットアップ -> コードリーディング&分析-> 改善開始にどれだけ労力を掛けるのかを決めたのみです。

  • 初期セットアップに掛ける時間は15分
  • コードリーディングと分析に掛ける時間は30分
  • ソースコードgithubのprivate repoを使い、変更点はPullRequest&即マージする。 (変更を戻しやすくする
  • インスタンスは各自1台ずつ持ち、@y_matuwitterのインスタンスを本番計測用とする
  • その他の事項は都度取り決めを行う

時間制限が8時間と短いため、改善作業以外の時間を短くしています。
セットアップに掛ける時間をどれだけ短くし問題点を正確に洗い出す環境を整えるかが重要になると考え、事前にスクリプトと分析環境を用意しています。

宿題

いくつか本番までにこなしておく宿題を決めました

@y_matsuwitter
  • ライブラリの事前調査
@kani_b
@TakatoshiMaeda

宿題を決めた後には本番前日までは一切集まらず、githubのprivate repo上でやること&やったことをissueに記録していきコミュニケーションを取っていました。

ぼくのしゅくだいきろく

宿題1.分析環境の整備

どうやって柔軟に素早く分析出来る環境を作ろうか考えた結果、

全サーバーのアクセスログとプロファイルログを事前に用意したDBに保存し、クエリで分析できるようにする

方針としました。

想定されたユースケースとして

等、様々な視点での情報が必要になると考えたため、メンバー全員が好きなタイミングで調査出来る環境を考えた結果です。

具体的にはnginxのアクセスログgolangのプロファイルログをltsvで出力し、事前にDigitalOceanで作成したサーバーにfluentdで転送/集約しました。

結果、このような分析環境となりました

f:id:takatoshi-maeda:20140929231143p:plain

3台のサーバーそれぞれでベンチマークを実行した結果を

  • nginx access log -> access_logs_[メンバー名]
  • golang profile log -> profile_logs_[メンバー名]

というテーブルに集約しています。 これで、各メンバーが任意のタイミングで様々な切り口から分析が出来る環境が整いました。

サーバーにfluentdをインストールする作業自体も後述するセットアップスクリプトで自動化しています。

golangのプロファイリングツール

nginxはltsvでアクセスログを吐き出すだけなのでいいのですが、golangのプロファイルログをDBに保存するためには仕組みを考える必要がありました。
golangのプロファイリングツールを探したのですが、どれもしっくりと来ずpprofもよくわからなかった *1 為、小さいパッケージを作って使うことにしました。

TakatoshiMaeda/lightup · GitHub

計測したい処理を囲うことで囲った箇所の

  • 呼び出し開始箇所
  • 実行時間
  • 実行終了時間
  • 任意のパラメータ

をltsvログに出力します。

import(
  l "github.com/TakatoshiMaeda/lightup"
)

l.SetFileOutput("/tmp/profile.log", 0666)

track := l.Start(map[string]string{ "param": "value" })
for i := 0; i < 100; i++ {
  time.Sleep(1)
}
track <- time.Now()

実行結果をDBにストアした結果はこのようになります

f:id:takatoshi-maeda:20140929231317p:plain

このツールを使うことで、詳細なアプリケーションの実行時間をSQLで分析できるようになりました。 実装がこれでいいのかは未だに自信がありませんが、まぁ本番で使えたのでよしとします...

この分析環境を用いた戦略

結果として、この分析結果を用いた戦略の決定はしませんでした。(コードリーディングの時点で早期に全員が納得できる方針が立ったため)
しかし、確実に処理時間が短くなってるのかの確認には有効でしたし、計測出来る環境を整えておくことが重要だと思ったので悔いはないです。
データの入出力がもっと複雑な問題であればもっとアグレッシブに使用していたかもしれません。

宿題2.作業環境のセットアップスクリプトの準備

capistranoを使い、様々な作業を自動化したisuコマンドを作成して使用しました。 結果として、競技開始からBenchmarkerのアクセスログが集約サーバーに保持されるまで15分程で完了させることが出来ました。

$ isu -T
isu setup                  # setup!!!
isu user:setup             # setup users
isu user:deploy_keys       # deploy ssh keys
isu connect:admin          # check connection for admin user
isu connect:isucon         # check connection for isucon user
isu default_package:setup  # setup default install require packages
isu fluentd:setup          # setup fluentd
isu fluentd:install        # install fluentd
isu fluentd:register       # register dat-agent service
isu fluentd:config:update  # update fluentd config file
isu fluentd:config:check   # check config fluentd.conf
isu fluentd:status         # fluentd status
isu fluentd:start          # start fluentd
isu fluentd:restart        # restart fluentd
isu fluentd:reload         # reload fluentd
isu fluentd:stop           # stop fluentd
isu fluentd:test           # test post fluentd
isu ssh                    # connection ssh
isu ssh:kanny              # connection ssh for kanny server
isu ssh:prod               # connection ssh for production server
isu ssh:tmaeda             # connection ssh for tmaeda server
isu ssh:y_matsu            # connection ssh for y_matsu server
isu bench                  # runninng test benchmark
isu bench:all              # running all test benchmark
isu bench:prod             # runninng production benchmark

これらは2013AMIを対象環境として作成したのですが、本番環境がAmazonLinuxでよかった.......

以下各コマンドの解説です

setup

諸々のセットアップを自動で全実行するコマンドです。 本番では怖くて使わなかった...

user:setup/user:deploy_keys

各メンバーのgithubに登録されてる公開鍵をisuconユーザーに配布する為のタスクです。 また、予選コードのrepositoryにpush権限を持つ秘密鍵も配布しています。 user:setupは結局user:deploy_keysのaliasになった

connect:admin/connect:admin

ec2-userへの接続確認と、isuconユーザーへの接続確認を行うタスクです。

default_package:setup

開発や調査に必要なパッケージをインストールするタスクです

fluentd:setup

fluentd:install -> fluentd:register -> fluentd:config:update -> fluentd:restartの順に実行するタスクです

fluentd:install

td-agentをインストールするタスクです

fluentd:register
isu fluentd:register       # register dat-agent service

ん?dat-agent...?ここでちょっとだけ工夫しました。
fluentdのセットアップ自動化を行う際に、予選インスタンスで既にtd-agentがインストールされている or system rubyが1.8.xであるケースが怖かったのです。
既にデフォルトでインストールされているfluentdに変更を加えるとデフォルトの挙動を壊すことになりますし、インストールされていない場合、system rubyが1.8.x系だとfluentdが動くrubyをインストールする必要があるなど手間取る未来が見えました。
少しでもセットアップ時間を短縮したいため、このタスクではfluentdやtd-agentの動作に干渉しないように事前に書いておいたrcスクリプト/etc/init.d/dat-agentとして配布しています。
/etc/init.d/dat-agent内部ではtd-agentが持つfluentdを別系統のdeamonとして起動するようにしています。
こうすることで、既にtd-agentがインストールされているケースでも独立して利用することができ、system rubyが古かった場合でもtd-agentのインストールをすることで素早く利用できます。

fluentd:config:update

fluentdの設定を全てのサーバーに配布するタスクです

fluentd:config:check

全てのサーバーのfluentdのconfigを表示するタスクです

fluentd:status/fluentd:start/fluentd:stop/fluentd:restart/fluentd:reload

/etc/init.d/dat-agentを操作するタスクです

fluentd:test

fluentdのhttpエンドポイントにリクエストを投げ、ログサーバーとの疎通を確認するタスクです。 setup後、発行して疎通を確認しました。

isu ssh:/isu bench:

名前のままです

1箇所、ユーザーディレクトリのパーミッションの関係(?)でうまくいかない箇所がありましたが、それ以外は概ね期待通りに動いてくれたお陰でセットアップの短縮につながりました。

宿題3.golangの勉強

golangはちょっと触った程度の経験しかなかったため、2013予選の問題を1から書きなおしてみました。 結果的にある程度の勘所はわかったので良かったのでは無いかと思います。lightupはその流れで作った副産物です。

僕が当日に行った変更としては

  • ユーザー情報のオンメモリ化
  • パスワードの平文化

  • nginx <-> goappをUnixDomainSocket化

結果的にこの3つの改善しかできませんでした... 分析や細々タスクをやりながらだったとはいえ、あまりにもダメなのでもっとちゃんとやらないとなーと思った次第です

まとめ

僕のISUCONで取り組んだ内容は以上となります。 まだ本戦に進むことが確定したわけではありませんが、出場出来た際には全力で取り組みたいと思います。

*1:僕のgo力が低いせいだと思う...