目の前に僕らの道がある

勉強会とか、技術的にはまったことのメモ

#isucon 予選でdstatを叩くだけの簡単なお仕事をしてきました

なんか公開するタイミングを逃したから、もう非公開でいいかなと思ったのですが、一応。

いや。まじで。それくらい何もしてなかったです。

一応、予選は12位で通過出来た模様です。

ISUCONの予選は土曜日にid:karupaneruraさんとid:kfly8さんとチーム坂パスタとして参加しました。
こちらのエントリの方が参考になるかと。

あっ。坂パスタってのは市ヶ谷にあるパスタ屋の俗称で、Unって店です。kfly8の人が足繁く通っているお店です。
市ヶ谷近辺の人は行ってみたらいかがでしょうか?

  • [gnavi:55893:detail]

役割とか

最初に決めた役割はこんな感じで、その後の流れもだいたい同じような役割を組んだまま進んでいきました。

  • 自分: アーキテクチャの把握、ログの場所や、負荷状況の把握
  • karupanerura: デプロイツールや細々した基盤の整備
  • kfly: アプリの仕様把握

午前中から昼過ぎにかけて

f:id:masasuz:20131007133656j:plain

アプリ回りは二人が見てくれると思って、自分はまずアーキテクチャ回りを見てました。
ふんふんperlは5.18ね。mysqlは5.6使ってるのかー。memcached plugin使ってるのかー(<=この時点で気づけたはず)。おっとApacheが動いているな。
Amazon Linuxとか触ったことないな。RedHat系かー。いつも使ってるDebian系が良かったなー。
とか、psとかtop叩きつつ独り言を言っていた気がします。

いちいちlogをそれぞれの場所に見に行くのがめんどいので、~/logs/ 以下にsymlinkを張るとかもこのあたりでしていた気がします。

とりあえず、mpstatとdstatが無いと捗らないのでyumで入れました。

ひとまず、素の状態でベンチを回して、どこに負荷がかかってそうかをtopで見ていました。
mysqlがやたらCPU使っているのをみて、あー、これは良くないクエリがあるな。と見て、mysql回りをいじることにしました。

mysqldumpslowとかを使うのが、定石なんでしょうけど、いつも使い慣れているpercona-toolkitのpt-query-digestを使うことに。
このときは、こんなことで時間を無駄にするとは思いも寄りませんでした。

  • tarを落として来て実行。モジュールが足りない。
    • cpanmで入れる => テストがこける => --forceでいれる => 実行時にmysql.soが無いと言われる
  • 仕方ないのでrpmを落として来てインストール。
    • シェバンが#/usr/bin/env perlなので、localのperlを使おうとする => モジュールが無い => シェバンをsystem perlの方に向ける
    • => yumで必要なperlモジュールをいれる => 実行するとDBD::mysqlmysql.soが無いと怒られる。 => 全部yumでいれたのになんで????
  • 仕方ないので、explainオプションを外す
    • これで、mysqlに接続する必要が無くなるので、ひとまず動く。
  • 結果が出力されない?
    • tcpdumpでeth0のmysqlパケットをキャプチャしていた => なんで??? => アプリはlocalhostに接続しているので、TCP/IPで無くUNIXドメインで接続してる
    • => パケットがキャプチャできないので、long_query_timeを0.1にして計測 => やっとクエリ解析できるようになる

細かいところを省いたのですが、慣れない環境と時間が無いと言うことで焦っていろいろ混乱していました。
一つ一つはもう少し落ち着けばいろいろ見えたはずなのに。という思いです。


f:id:masasuz:20131001125905j:plain

この間、かるぱねるら先生がstarmanをstarletに変えたり、kfly8先生がアプリの仕様をまとめたりとちゃんとお仕事をしてくれてました。
ホント、何やってんだ。自分。

昼下がり

このあたりからやっとチューニングを始められた気がします。my.cnfを適当に変えたりしてました。

パフォーマンスに直接関係ありそうなのはこの辺ですかね。正直buffer poolはこんなにいらなかったはず。
ちゃんと計測していなかったのが見て取れますね!!

innodb_buffer_pool_size=9G
innodb_flush_log_at_trx_commit=2
innodb_file_per_table
innodb_flush_method=O_DIRECT
innodb_file_format = Barracuda
innodb_support_xa=OFF

で、そういえばmysql5.6だったら、shutdown時にbuffer poolがダンプできるんだった使える!
と思いこんな設定をいれたんですが、ベンチの初期処理でデータを初期化しているので、全く意味なかったですね。
ベンチマークスクリプトの挙動を理解していなかったのが見て取れますね!!

innodb_buffer_pool_dump_at_shutdown=1
innodb_buffer_pool_load_at_startup=1

最終的なmy.cnfはこんな感じでした。

で、もうひとつDB回りでやった無駄なことは、ベンチマークスクリプトの初期化処理で、こんなのを走らせるようにしてました。
やっていることとしては元のテーブルと同じ構造のblackholeテーブルを作って全データを流し込んでます。
こうすることにより全データがbuffer poolに乗るのですが、が、が、初期化時にinsertしている時点で、buffer poolに乗るはずなので、敢えてそんなコトしなくても良かったというオチです。

DROP TABLE IF EXISTS bh;
CREATE TABLE bh LIKE memos;
ALTER TABLE bh ENGINE=Blackhole;
INSERT INTO bh SELECT * FROM memos;
DROP TABLE bh;

CREATE TABLE bh LIKE users;
ALTER TABLE bh ENGINE=Blackhole;
INSERT INTO bh SELECT * FROM users;
DROP TABLE bh;

myql回りの細々したことをやりつつ、並行してベンチ毎にpt-query-digestで出たいけてないクエリをkfly8先生に直してと言うだけの簡単なお仕事もしていました。

f:id:masasuz:20130513132219j:plain

この間、かるぱね先生がapacheをnginxに変えたり、kfly先生ががりがりアプリを書き換えていた気がします。

ラストスパート

自分はベンチを実行して負荷をみつつ、ログを見つつ、遅いクエリを報告するだけの簡単なお仕事をしている裏でkfly4先生やかるぱ先生がガリガリチューニングしてくれたので、スコアも10800くらいに届き途中までは5位以内に入ってました。

残り30分になったところで、再起動してもちゃんと動くかどうか確認するために、再起動したところ、nginxが自動起動していないという小さいトラブルとスコアが8000ぐらいに落ちているというでかいトラブルに見舞われました。
前者はchkconfig onしてなかっただけなので、問題なく。
後者は、予選が終わってから原因が分かったのですが、supervisordでstarletでなくstarmanが立ち上がっていたことが原因でした。コレに関しては、ベンチがうまく動かなくなったときに、starletをsupervisord管理で立ち上げるように直したので、提出したAMIでは直っているはず。
そんなこんなで、ラスト30分は混乱の中最高スコアに戻ることなく終わりました。
かるぱ氏が触れてますが、提出AMIでベンチし直したら、最高スコアを記録してました。おしい。

反省とか

  • プロファイリングしてなかった
    • 結局何がボトルネックになっていたのかを最後まで把握できていなかった。だめだめですね
  • 落ち着きが足りない
    • 冷静に考えていればすぐに分かることで時間を無駄にしていた。特に午前
  • ログや計測結果の見える化をもう少ししたかった
    • エラーログやアクセスログ、pt-query-digestのレポート、dstat、mpstat、ベンチマークの結果などをでかいディスプレイに表示して皆が見えるようにしておけば、もう少しはかどったかなと思います
  • 結局dstatを見るだけの簡単なお仕事しかしてない
    • ふりかえるとホントに何もしてないな
    • すみません。本戦ではちゃんと働きます


予選を通過できたのは、かる先生、kfly8先生のお二人のお陰です。本戦までにはちゃんと準備してきます。

f:id:masasuz:20130403133539j:plain

余談

kfly8の人は坂パスタが好きなんですが、自分は通称地下パスタという店の方が好きです。
会社ビルの真向かいにあって近くて、一時期週3で通っていた時期もありました。
市ヶ谷近辺の方は行ってみたらいかがでしょうか?
ちなみに最初の1枚以外は全部地下パスタの写真です。

R plus
〒102-8468 東京都千代田区六番町4-11 朝日六番町マンションB1
4,500円(平均)1,000円(ランチ平均)