まどろみの思考空間スマートフォン用の表示で見るスターをつけました引用をストックしましたストック一覧を見る閉じる引用するにはまずログインしてくださいログイン閉じる引用をストックできませんでした。再度お試しください閉じる限定公開記事のため引用できません。読者です読者をやめる読者になる読者になるまどろみの思考空間2014-09-28ISUCON4予選に参加しましたということで昨日09/28にサークルの人(わたし、りょい君、kakira君)でチーム「☆(ゝω・)vキャピ」として参加しました。当日まで2回ほど勉強会を開きました。一回目は肝になりそうな部分をそれぞれがまとめて発表し勉強するという形式。具体的には負荷とはそもそもなにか?(わたし),MySQLまわり(kakira君),memcachedまわり(りょい君)って感じにしました。これはわたし担当分は普段さわっているから、kakira君は競技プログラマなのでこのあたりデータ構造とかアルゴリズムとか関連付けて理解できそう、りょい君がこのメンバの中で一番Perlかけるので実装の際にしっているとつよいって感じで割り当てました。AMIからの起動とか軽い動作確認などもこの日にしました。予選の方針として「推測するな計測せよ」というのを徹底していこうということ、またそれとあわせ最初一時間はチューニングを始めずに統計をとる、ソースコードを読むなどして構造を理解最初のボトルネックを探す、そして最後の1時間は再起動したらうまくいかなくなり失格なんてことののないようチューニングをやめ確認をしているというふうにすることに。選択した言語はのこり二人が読み書きできるということでPerlにすることに。(個人的にはPythonがよかった...)二回目の勉強会ではISUCON3の過去問を解くという形。始まる前にチャットサーバとか、ディスプレイの設定(デュアルディスプレイにした)とかそういうことをしておきました。チャットサーバにはDevHubというものを使わせていただきました。これを採用した理由は普通にチャットできる部分とメモとしてマークダウンで書いておいておける場所がある点。チャットはURL貼るという用途にしか使いませんでしたが(普通の会話は口頭でしていた)、メモは色々わかったことなどを各々が書き込んで結構使いました。↓予選後のスクリーンショット予選開始とりあえずAMIを立ち上げベンチマークを走らせます。(10:11)最初に決めたようにわたしはサーバ周り、りょい君、kakira君にはアプリケーションのソースコードを読んだり、サイト構造を把握してもらったりをお願いしました。psやnetstatからサーバで動いているプロセスリッスンしているポートを把握。前回までと大きく構成変わっているのはwebサーバデフォルトでhttpdではなくnginxであること、memcachedが動いていないことでしょうか?そしてわたしは各種計測ツール導入。入れたものとしてはdstat,percona-toolkitなんかをいれました。nginxでアクセスログの先頭に処理時間を表示するように設定。ついでに設定を見るとワーカーが1だったので(一時間はチューニングしないという話でしたが単純な変更で済むので)ワーカを4にして再起動。MySQLについてもスロークエリを出力するように設定して再起動。今回はsupervisordがRuby実装ということで使うPerl実装に切り替えました。ほんとはSSHもisuconユーザでログインできるように設定するはずだったのですが、なんか焦ってしまいできない...こんなところで時間潰すのももったいないので他の人には不便をしいますが(ほんと申し訳ない...)、とりあえず一旦やめ再度ベンチマークを走らせます。(10:44)最初走らせた手応え、前回までの感じで大体workload8あたりがベストなのでこの時点でその程度の値にして実行。2014となりました。やったね!暫定一位!このままいければよかったんだけど...dstat,topの結果をみているとロードが最大3〜4前後であること、IOというよりCPUがネックになっていそうなこと、時々ポンとIOが来ること、やっぱりMySQLのCPU使用率が高いことがw狩りました。ログ出力の関係からか常にディスクアクセス(書き込み)が発生しています。メモリは全然使い切れていないようなのでメモリにのせる実装が良さそうですねとか考えました。スロークエリの結果からはなんかlogin処理であるクエリが殆どをしめているっぽいです。login_logというテーブルを参照しているのでログインまわりかなとか考えつつ。ページごとのアクセス数の偏り、なんかをみてみても静的ファイルを除いてログインまわりに結構アクセスが来ています。/tmUnblock.cgiソースコード解析しているkakira君からも該当クエリがめっちゃ効率わるいという話だったので、とりあえずここをチューニングしようという話に。ソースコードが単純であることからmemcachedに全部のっければいいのでは?という話に。これはメモリ上にのせるというよりも検索コストをさげるのとSQLでCPU使ってるのでKVSとしてO(1)でアクセスするという意味合いがつよいです。いうことでソースコード書き換え開始とその前にisuconユーザのホームディレクトリ配下をgit管理するようにしました。kakira君がSQLソースコードをよみ大まかな設計をし、りょい君が実装していきます。わたしはそれにアルゴリズムまわりにちょっと口を出す程度。わたしはnginxで静的ファイルを返すように変更したり、MySQLのパラメータを変えたりと細かなチューニングをしていきます。IPでの遮断の方を書き換えベンチを走らせると6000超えました。この調子でいけるか?ということでユーザロックのほうも実装開始。これはいけるか?って思いましたがここからが...お昼も食べつつ13:30ぐらいに再度ベンチを走らせるものの/mypageがfailしまたreportとの付きあわせがうまく行かないらしく、スコアが送信されない状態...送られれば100000越えてたのに...って感じでデバッグが開始されます。バグの原因がわからない。mypageにアクセスできないはずのユーザがログインできているだろうと推測はできたのですが、手動でしらべるのは手間がかかる、またエラーログとしてページが予想されたものとことなりますだけでは情報がすくない...さらにPerlのデータ構造まわりの参照なのかスカラなのかハッシュあのかよくわからないというあれが発生し、さらに泥沼に...改善したと思ったら今度はユーザロックをし続けているっぽい...15:30頃一旦差し戻そうというはなしになり、スコアが3000に逆戻り...ソースコードをあらためて綺麗な心で書き換えはじめます。うまくいかない...って感じですでに16:30。無理そうなので一旦諦めチューニングして別のところをチューニングし始めます。ところでおなじBANなのになんでIPのほうはfailしてないのって話になりどうやらIPで遮断されたものは一回もないようなので、とりあえずそこのコードを単純にreturnするようにしました。これで6000程度に戻る。あとはユーザのテーブルにインデックスをはったりして6500前後まで行きました。実装力低い...これが大きかったです...とくにわたしがPerl読み書きできないので...また、コンテストの性質上コードを読んでいる時間が長くなるのですぐに実装できるより読みやすい言語のほうが良さそうです。次回参加する際はわたしもプログラミングまわりで力になれるようにしておきたいです。*ダブルチェックをする実は途中でわたしがsupervisordを再起動しとうとおもって、bashの履歴機能つかって再起動していたら実は複数回memcachedを再起動していてperlのエラーログがうまく出されないという事象がありまして、これは実サービスでやったらプロセスによってはとんでもないことになり非常に反省しております。今回でも余計に時間をかけさせてしまったというので申し訳ない。再起動など影響のある作業するときはきちんとコマンドがあっているかチェックをする。声掛けだけではなく、ダブルチェックするなどを怠らないようにしないといけませんね。*ダメそうだったら途中ですぐに諦めるloginまわりでかなり時間をとっていしまいました。これは途中で方針変更できるはずなのに強行突破しとうとしたのは間違いでした。MySQLのテーブル設計をきちんとする(一回でも成功しているかしていないかの判定があったのでそこのテーブルをわけるなど)、その上でクエリの改善をするなどで十分高速化できたはずで、その場合加点が0というわけではなく多少は加点があり、さらに別のポイントのチューニングにも時間をまわせました。今年が初参加でしたが、とてもおもしろかったです。技術者として自分に足りない部分を再度確認できるよい機会でもありました。問題自体は去年とはことなり、複数問題点が含まれているというより大きな問題がありそれを解決するって感じだったのかなって感じてます(もしかしたらたくさんある問題点をわたしたちがみつけられなかっただけなのかもしれませんが...)やっぱり計測大事ですね。来年はもっとスコア伸ばしていきたいです。学生枠5位になんとか入り本戦出場できることになりました。わたしは研究の関係で参加できないので残り二人に頑張ってもらいます。Blog|ブログを報告する。