ウェブアプリケーションのパフォーマンスチューニング
•
2 likes•2,483 views
ウェブアプリケーショのパフォーマンスチューニング - Devel::KYTProf 使って！
![レスポンスタイム計測
Apacheの場合
LogFormat %D でアクセスログに レスポンスタイム(マイクロ秒)を
表示できる
LogFormat "%h %t "%r" %D"
123.123.123.123 [20/Nov/2010:01:02:03 +0900]
"GET /path/to/hoge HTTP/1.1" 1021](https://image.slidesharecdn.com/2-101120012713-phpapp02/85/-11-320.jpg)
![レスポンスタイム計測 - HTTPヘッダ
LogFormat "%h %t "%r" "%{X-Ridge-Dispatch}o" %D"
123.123.123.123 [20/Nov/2010:01:02:03 +0900] "GET / HTTP/1.1"
"Hatena::Monolith::Engine::Index#default" 1021
%{レスポンスヘッダ名}o で reverse proxy のログにディスパッチ
結果をレスポンスタイムと共に記録](https://image.slidesharecdn.com/2-101120012713-phpapp02/85/-13-320.jpg)
![Devel::NYTProf - 実例
sub sanitize {
my $str = shift;
$str =~ s/&(?![#a-zA-Z0-9_]{2,6};)/&/g;
$str =~ s/</</g;
$str =~ s/>/>/g;
$str =~ s/"/"/g;
$str =~ s/'/'/g;
$str =~ s//\/g;
return $str;
}](https://image.slidesharecdn.com/2-101120012713-phpapp02/85/-21-320.jpg)
![Devel::NYTProf - 実例
sub sanitize {
my $str = shift;
$str =~ /[&<>"']/ or return $str;
$str =~ s/&(?![#a-zA-Z0-9_]{2,6};)/&/g;
$str =~ s/</</g;
$str =~ s/>/>/g;
$str =~ s/"/"/g;
$str =~ s/'/'/g;
$str =~ s//\/g;
return $str;
}](https://image.slidesharecdn.com/2-101120012713-phpapp02/85/-23-320.jpg)
![Devel::KYTProf - add_prof(s)
use Devel::KYTProf;
Devel::KYTProf->add_prof(
'Foo::Bar',
'baz',
sub { },
);
# Foo::Bar クラスの baz メソッドを計測対象に
Devel::KYTProf->add_profs(
'Foo::Bar',
[qw/baz piyo/]
);](https://image.slidesharecdn.com/2-101120012713-phpapp02/85/-27-320.jpg)
ウェブアプリケーションのパフォーマンスチューニング
- 3. 自己紹介 - 最近つくったもの はてなキーワード リダイレクト機能 Devel::KYTProf https://github.com/onishi/perl5-devel-kytprof 仮面ライダーオーズのお面
- 4. 最近つくったもの
- 5. 最近つくったもの
- 6. 最近つくったもの
- 10. パフォーマンスチューニングフロー 大きなところから粒度を細かくして掘り下げていく 1. 自分のサイトは遅いのか 2. どのページがどんな条件で遅いのか 3. 遅い原因はどこにあるのか アプリケーション? ネットワーク? 外部原因? (APIなど) 4. 原因を取り除く / キャッシュを行う ボトルネックをみつけるまでが大変＞＜
- 11. レスポンスタイム計測 Apacheの場合 LogFormat %D でアクセスログに レスポンスタイム(マイクロ秒)を 表示できる LogFormat "%h %t "%r" %D" 123.123.123.123 [20/Nov/2010:01:02:03 +0900] "GET /path/to/hoge HTTP/1.1" 1021
- 12. レスポンスタイム計測 - HTTPヘッダ ウェブアプリケーションから情報を出力する（はてなではWAFに実 装） アプリケーションの処理速度 ディスパッチ結果 $ curl -I 'http://mono.hatena.ne.jp/' | grep 'X-' X-Framework: Ridge/0.1 Plack/0.9937 X-Runtime: 423ms X-Ridge-Dispatch: Hatena::Monolith::Engine::Index#default
- 13. レスポンスタイム計測 - HTTPヘッダ LogFormat "%h %t "%r" "%{X-Ridge-Dispatch}o" %D" 123.123.123.123 [20/Nov/2010:01:02:03 +0900] "GET / HTTP/1.1" "Hatena::Monolith::Engine::Index#default" 1021 %{レスポンスヘッダ名}o で reverse proxy のログにディスパッチ 結果をレスポンスタイムと共に記録
- 14. レスポンスタイム計測 - グラフ化#1 レスポンスタイム 分布
- 15. レスポンスタイム計測 - グラフ化#2 レスポンスタイム 推移 (日)
- 16. レスポンスタイム計測 - グラフ化#3 レスポンスタイム 推移 (時間)
- 17. グラフから読み取ること サービスの応答速度 応答速度の変化 (劣化) 条件による応答速度の違い URL / ディスパッチ先 リクエストメソッド 時間帯
- 18. 遅い原因を調査する - run.pl $ perl server.pl -p 3000 # Webサーバーとして動作する $ perl run.pl http://d.hatena.ne.jp/onishi/ # 1リクエストだけ処理する プロファイリングしやすい -d オプションを入れてプロファイラを実行 cron で定時実行して継続プロファイル
- 19. Devel::NYTProf http://search.cpan.org/dist/Devel-NYTProf/ $ perl -d:NYTProf run.pl http://d.hatena.ne.jp/onishi/ # nytprof.out というファイルができる $ nytprofhtml # nytprof というディレクトリができる DEMO
- 20. Devel::NYTProf よくある重い原因 正規表現 動的に生成しない。コンパイルオプション $` $' を使わない オブジェクト生成コスト (DateTime ...) 利用頻度の高いUtility関数 速い段階で抜けられないか
- 21. Devel::NYTProf - 実例 sub sanitize { my $str = shift; $str =~ s/&(?![#a-zA-Z0-9_]{2,6};)/&/g; $str =~ s/</</g; $str =~ s/>/>/g; $str =~ s/"/"/g; $str =~ s/'/'/g; $str =~ s//\/g; return $str; }
- 23. Devel::NYTProf - 実例 sub sanitize { my $str = shift; $str =~ /[&<>"']/ or return $str; $str =~ s/&(?![#a-zA-Z0-9_]{2,6};)/&/g; $str =~ s/</</g; $str =~ s/>/>/g; $str =~ s/"/"/g; $str =~ s/'/'/g; $str =~ s//\/g; return $str; }
- 25. Devel::NYTProf - tips DB::disable_profile() # モジュールのロード DB::enable_profile() # 計測したい処理 run.pl でのプロファイルは mod_perl などの永続環境でないため、 モジュールのロード(コンパイル, import) 処理が計測されてしまうの でそれを抑制する
- 26. Devel::KYTProf https://github.com/onishi/perl5-devel-kytprof $ perl -d:KYTProf run.pl http://d.hatena.ne.jp/onishi/ ボトルネックの大半はネットワークIO！！ use するだけでネットワークIOの発生するメソッドの実行時間と呼 び出し元をwarnする DBI LWP Cache::Memcached::Fast … DEMO
- 27. Devel::KYTProf - add_prof(s) use Devel::KYTProf; Devel::KYTProf->add_prof( 'Foo::Bar', 'baz', sub { }, ); # Foo::Bar クラスの baz メソッドを計測対象に Devel::KYTProf->add_profs( 'Foo::Bar', [qw/baz piyo/] );
- 28. Devel::KYTProf - options Devel::KYTProf->namespace_regex('Hatena::Diary'); # caller を指定名前空間まで遡る Devel::KYTProf->threshold(100); # (ms) # n ms 以上かかった処理だけを出力する Devel::KYTProf->logger(Some::Logger->new); Devel::KYTProf->mute('DBI', 'connect'); Devel::KYTProf->unmute('DBI', 'connect');
- 31. 継続プロファイリング 0 * * * * perl -d:KYTProf run.pl http://d.hatena.ne. jp/onishi/ >> /var/log/profile.log 2>&1 毎時実行して記録を残す 日々のパフォーマンスの状況を残す 一時的な問題があった時に後から何があったか眺めたり パフォーマンス改善の効果を確かめたり
- 34. ご清聴ありがとうございました