pprotein でボトルネックを探して ISUCON で優勝する
スニダンを開発しているSODA inc.の Advent Calendar 6日目の記事です!!!/
\昨日は @decoch718 さんによる「エンジニアブログを開設して1年で取り組んだことを公開」でした!
組織としてのアウトプットがドンドン増えていてすごい!
明日は @KosukeSaigusa さんによる「Dart のドキュメンテーションについて」の予定です!
お楽しみに!
はじめに
推測するな、計測せよ
Rule 1. You can't tell where a program is going to spend its time. Bottlenecks occur in surprising places, so don't try to second guess and put in a speed hack until you've proven that's where the bottleneck is.
Rule 2. Measure. Don't tune for speed until you've measured, and even then don't unless one part of the code overwhelms the rest.Rob Pike, "Notes on Programming in C" (1989), https://www.lysator.liu.se/c/pikestyle.html
Rob Pike氏が最初にそれらしいことを言った原典をカッコつけて持ってきました。
皆さん、パフォーマンス改善をするときは推測せずに計測していきましょう。
ISUCONでは特に、「計測→改善→計測→…」のサイクルをどれだけ高速に回せるかがとっても重要です。
pproteinで計測せよ
3大計測ポイント(?)であるプロファイル、スロークエリログ、アクセスログをまとめて計測して可視化してくれる神ツールです。
pproteinがないと、ログのローテートをしたり、ログを手元に持ってきてalpなどで分析したり、 go tool pprof
で毎回計測を走らせたり、それらの計測結果をチームメンバーに共有したり、と色々なことをしないといけなくて大変です。
ISUCON13終了直後の現在は、優勝チームのメンバーの1人である とーふとふさん が自チームで使っていたpproteinを公開してくれています。
これを見ればどんなツールかのイメージは簡単につくでしょう。
そしてこのツールは同じチームのメンバーである sekaiさん が作ったツールです。ありがたや。
pproteinの使い方をご紹介します
本記事ではpproteinの使い方をご紹介します。
リポジトリにREADMEが置かれておらず、インターネット上にも使い方をまとめたページなどが見当たらず、初めて使うときは少し大変でした。
Goで書かれてて読みやすかったこともあり、pproteinのコードを全部読んで理解しました()
計測対象の準備
まずは計測ができるよう各サーバで準備していきましょう。
Goアプリケーションのpprof
これは echov4.EnableDebugHandler(e)
を main
関数に置くだけで簡単です。
pprof を単体で使う場合は net/http/pprof
をBlank importしたり、6060番ポートを自分で開放したり、が必要ですが、そのあたりに相当することはいい感じに内部でやってくれています。
gin
など他のWebフレームワークにも対応していて便利です。
フレームワークの種類は気にせずに standalone.Integrate(":19000")
のように19000番ポートで公開するのもよいでしょう。
MySQLのスロークエリログ
スロークエリログが出力されるように設定します。
Ansible でいい感じに適用できるようにしておくと便利です。
ログの読み込みがPermission Deniedになる場合は chmod
しちゃいましょう。
sudo chmod +rx /var/log/mysql/
sudo chmod +r /var/log/mysql/mysql-slow.log
MySQLを別サーバに分離しても大丈夫
だって pprotein-agent
があるのだから。
途中でMySQLを別サーバに逃がして複数台構成にすると、当たり前ですがGoアプリケーションがスロークエリログを直接取得できなくなってしまいます。
その場合は pprotein-agent
というプロセスをMySQLが起動しているサーバで稼働させることでpproteinがログを取得できるようにします。
詳細は後述の「pprotein-agentのserviceを起動」にて。
Nginxのアクセスログ
アクセスログがltsv形式で出力されるように設定します。
こちらも Ansible でいい感じに適用できるようにしておくと便利です。
ログの読み込みがPermission Deniedになる場合は chmod
しちゃいましょう(これもAnsibleでやると便利です)。
sudo chmod +r /var/log/nginx/access.log
Nginxを別サーバに分離しても大丈夫
だって pprotein-agent
があるのだから。
MySQLと同じくNginxを別サーバに逃がす場合もGoアプリケーションからアクセスログを直接取得できなくなってしまいます。
この場合も pprotein-agent
をNginxサーバで稼働させることで解決します。
pproteinの準備
ここからpprotein本体の準備に入ります(ワクワク)。
CloudFormationでサーバ起動
CloudFormationを利用して、計測対象サーバと同じVPC、同じSubnetにpprotein用のサーバを起動します。
ISUCON13では一応競技用サーバと同じAMIでEC2を起動しましたが、別のAMIでも問題ないでしょう。
CloudFormationのParametersでVPCとSubnetを指定できるように用意しておくと便利です。
また、競技用サーバのSecurity Groupは変更してしまうと失格になるのですが、pprotein用のサーバは変更して問題ないので、9000番ポートを開放しておきます。
周辺ツールのインストール
次に、pproteinを動かすのに必要なツール群をバンバン入れていきましょう。
pprofのグラフ描画に使うgraphviz
sudo apt install -y graphviz gv
スロークエリログの分析に使うslp
wget https://github.com/tkuchiki/slp/releases/download/v0.2.1/slp_linux_amd64.tar.gz
tar -xvf slp_linux_amd64.tar.gz
sudo mv slp /usr/local/bin/slp
アクセスログの分析に使うalp
wget https://github.com/tkuchiki/alp/releases/download/v1.0.21/alp_linux_amd64.tar.gz
tar -xvf alp_linux_amd64.tar.gz
sudo mv alp /usr/local/bin/alp
pprotein本体
wget https://github.com/kaz/pprotein/releases/download/v1.2.4/pprotein_1.2.4_linux_amd64.tar.gz
tar -xvf pprotein_1.2.4_linux_amd64.tar.gz
pproteinのserviceを起動
pprotein用サーバで /etc/systemd/system/pprotein.service
を作って起動しましょう。
起動に成功すると http://{pprotein用サーバのPublic IP}:9000
でpproteinのWeb UIにアクセスできるようになっているはずです。
[Unit]
Description=pprotein service
[Service]
ExecStart=/home/isucon/pprotein
WorkingDirectory=/home/isucon
Environment=PATH=$PATH:/usr/local/bin
Restart=always
User=root
[Install]
WantedBy=multi-user.target
sudo systemctl start pprotein
pprotein-agentのserviceを起動
MySQLが別サーバの場合は、そのサーバで /etc/systemd/system/pprotein-agent.service
を作って起動しましょう。
起動に成功すると19000番ポートでスロークエリログが取得できるエンドポイントが公開されているはずです。
/var/log/mysql/mysql-slow.log
などログファイルのPermissionにご注意を。
wget https://github.com/kaz/pprotein/releases/download/v1.2.4/pprotein_1.2.4_linux_amd64.tar.gz
tar -xvf pprotein_1.2.4_linux_amd64.tar.gz
[Unit]
Description=pprotein-agent service
[Service]
ExecStart=/home/isucon/pprotein-agent
WorkingDirectory=/home/isucon
Environment=PATH=$PATH:/usr/local/bin
Restart=always
User=root
[Install]
WantedBy=multi-user.target
sudo systemctl start pprotein-agent
group/targets
の設定
pproteinのWeb UI上にある setting
からログ収集に関するを設定を変更します。
group/targets
は基本的には計測対象サーバのPrivate IPとログを取得できるエンドポイントが公開されているポートを設定していくだけでOKです。
ここで standalone.Integrate
を使っているとすべてのポートを19000番にできるので脳内メモリを節約することができますね。
ちなみに、ここでの設定内容はpprotein用サーバ上の /home/isucon/data/targets.json
に保存されます。
[
{
"Type": "pprof",
"Label": "webapp",
"URL": "http://192.168.0.11:8080/debug/pprof/profile",
"Duration": 60
},
{
"Type": "httplog",
"Label": "nginx",
"URL": "http://192.168.0.11:8080/debug/log/httplog",
"Duration": 60
},
{
"Type": "slowlog",
"Label": "mysql",
"URL": "http://192.168.0.12:19000/debug/log/slowlog",
"Duration": 60
}
]
httplog/config
の設定
httplog/config
はPath Parameterを受け取るエンドポイントを正規表現でいい感じにまとめる設定を書きます。
ちなみに、ここでの設定内容はpprotein用サーバ上の /home/isucon/data/alp.yml
に保存されます。
matching_groups:
- ^/api/user/[0-9a-zA-Z_-]+/theme$
- ^/api/user/[0-9a-zA-Z_-]+/livestream$
- ^/api/livestream/[0-9a-f_-]+$
- ^/api/livestream/[0-9a-f_-]+/livecomment$
- ^/api/livestream/[0-9a-f_-]+/reaction$
- ^/api/livestream/[0-9a-f_-]+/report$
- ^/api/livestream/[0-9a-f_-]+/ngwords$
- ^/api/livestream/[0-9a-f_-]+/livecomment/[0-9a-f_-]+/report$
- ^/api/livestream/[0-9a-f_-]+/moderate$
- ^/api/livestream/[0-9a-f_-]+/enter$
- ^/api/livestream/[0-9a-f_-]+/exit$
- ^/api/user/[0-9a-zA-Z_-]+$
- ^/api/user/[0-9a-zA-Z_-]+/statistics$
- ^/api/user/[0-9a-zA-Z_-]+/icon$
- ^/api/livestream/[0-9a-f_-]+/statistics$
いざ計測
ISUCONのベンチマーカーはまず最初にinitialize処理をして初期データ作ったりしています。
そのinitialize処理の最後にpproteinでの計測を自動でスタートするようにすると便利です。
メモ機能もあるので、ベンチのログやスコアを計測結果に紐づけて残しておくと便利でしょう(と、優勝チームのpproteinを見て思いました(小並感))。
おわりに
優勝できませんでした!!!
が、初出場でも頑張れたのはpproteinのおかげです!!!
株式会社SODAの開発組織がお届けするZenn Publicationです。 是非Entrance Bookもご覧ください! → recruit.soda-inc.jp/engineer
Discussion