nginx/wordpressの応答速度を監視 (munin+nginx_request_time)
このサイトは現在 wordpress を nginx + php7-fpm の上で動かしている。 nginx の動作確認には munin + nginx_request_time プラグインが便利。
ただ、nginx_request_time は、ある程度規模の大きなサイトを念頭に置いて作られているようで、本サイトのような弱小サイトでは少々工夫が必要だ。
以下に意図したデータを拾うためのノウハウをメモしておきます。
- サーバが遅いらしいので、nginxのレスポンスタイムを計測するmunin pluginを書いた – なんかかきたい
- Nginxのレスポンスタイムをパーセンタイル値で計測するMunin plugin
- munin: nginx_request_timeプラグインでキャッシュ応答等を除外(proxy_pass時のみ集計) – Qiita
nginx_request_timeは何を計算しているのか?
オリジナル版は、muninから起動された時点のログを新しい方から1000行分読み込み、パーセンタイル値で表示します。
多くのサイトではこの動作でも問題はないと思いますが、アクセス数が少ないサイトだと以下の問題が発生します。
- muninの起動間隔(5分)で生成されるログが1000行以下の場合、昔のデータを引きずって表示してしまいます。
- (逆に1000行以上作成される場合は最新の1000行しか計算されません)
- キャッシュ応答や、管理者によるアクセスも計算対象になります
1000行で切ってしまうと夜間などアクセス数が少ない時刻の表示が不正確になるので、過去5分間(一定時間)のアクセスだけを対象にした方が良い。
(plugin開発者はアクセス数の多いサイト向けに、敢えてこのような仕様にしたのだと思いますが、うちのサイトの計測には合わないです)
管理者によるアクセスも、アクセス数の多いサイトなら通常アクセスに埋もれて問題にならないと思うのですが、アクセス数が少ないサイトで誤差が増えてしまいます。
diff書いてみました
/wp-admin/ 以下や wp-cron を除外し、過去10分を計算するようにしています。
計測したいサイトによって、何を除外するか・どれだけのログを計算するかが変わると思います。
--- nginx_request_time 2017-05-25 00:21:36.666509561 +0900 +++ nginx_request_time.new 2017-05-25 00:22:01.185509680 +0900 @@ -61,6 +61,7 @@ use Statistics::Lite qw(max min mean median); use Statistics::Descriptive; use Text::LTSV; +use Time::Piece; my $line_counter = exists $ENV{'loglimit'} ? $ENV{'loglimit'} : 1000; my $LOG = exists $ENV{'logfile'} ? $ENV{'logfile'} @@ -77,10 +78,11 @@ my $mode = $0; $mode =~ s/.*/nginx_request_time//; +my $title = ($mode eq '_nocache')? " without cache": ""; if (exists $ARGV[0] and $ARGV[0] eq "config") { - print <<'EOS'; -graph_title NGINX response time + print <<"EOS"; +graph_title NGINX response time$title graph_args -l 0 --base 1000 graph_category nginx graph_vlabel millseconds @@ -90,6 +92,9 @@ max.label max max.draw LINE2 max.min 0 +percentile99.label 99th percentile +percentile99.draw LINE2 +percentile99.min 0 EOS } else { print <<'EOS'; @@ -112,15 +117,24 @@ my @request_time_array = (); my $log_handle = File::ReadBackwards->new($LOG) or die "$!"; +my $start = (((localtime->epoch)/(5*60))-2)*5*60; # 2*5min for (my $i = 0; $i < $line_counter; $i++) { my $log_line = $log_handle->readline; if (defined($log_line)) { my $p = Text::LTSV->new; my $hash = $p->parse_line($log_line); + my $time_n = Time::Piece->strptime($hash->{time},"%d/%b/%Y:%H:%M:%S %z")->epoch; + if ($time_n<$start) { next; }; my $time_s = $hash->{reqtime}; if (!defined($time_s)) { next; } + if (($mode eq '_nocache') && ($hash->{apptime} eq '-')) { next; }; + if ($hash->{req} =~ m!/wp-admin/!) { next; }; + if ($hash->{req} =~ m!/wp-cron?!) { next; }; push @request_time_array, $time_s * 1000; } else { last; } @@ -131,6 +145,7 @@ $stat->add_data(@request_time_array); my $percentile90 = $stat->percentile(90); my $percentile95 = $stat->percentile(95); +my $percentile99 = $stat->percentile(99); my $min = min @request_time_array; my $max = max @request_time_array; @@ -141,3 +156,5 @@ print "median.value $mediann"; print "percentile90.value $percentile90n"; print "percentile95.value $percentile95n"; +print "percentile99.value $percentile99n";
ディスカッション
コメント一覧
まだ、コメントがありません