munin: nginx_request_timeプラグインでキャッシュ応答等を除外（proxy_pass時のみ集計）

diff

1行足すだけじゃ！

$ diff -u /usr/share/munin/plugins/nginx_request_time /usr/share/munin/plugins/nginx_request_time_withoutcache
--- /usr/share/munin/plugins/nginx_request_time 2016-11-29 01:20:15.063783808 +0900
+++ /usr/share/munin/plugins/nginx_request_time_withoutcache    2016-12-07 23:27:05.093202230 +0900
@@ -123,6 +123,7 @@
         my $hash = $p->parse_line($log_line);
         my $time_s = $hash->{reqtime};
         if (!defined($time_s)) { next; }
+        if ($hash->{apptime} eq "-") { next; }
         push @request_time_array, $time_s * 1000;
     } else {
         last;

補足: nginxのログ設定

log_format  ltsv  "time:$time_local"
                  "\thost:$remote_addr"
                  "\tforwardedfor:$http_x_forwarded_for"
                  "\treq:$request"
                  "\tstatus:$status"
                  "\tsize:$body_bytes_sent"
                  "\treferer:$http_referer"
                  "\tua:$http_user_agent"
                  "\treqtime:$request_time"
                  "\tapptime:$upstream_response_time"
                  "\tvhost:$host";

$upstream_response_timeの値

公式資料が見当たらないのですが、少なくとも下記の場合に $upstream_response_time の値は - となります。

• nginxのみでレスポンスを返却したとき
• proxy_cacheでキャッシュ応答したとき

そこを引っ掛けて除外させることで、proxy_passでリバースプロキシした時の応答時間だけを集計できます。

アプリの本来の処理時間はいかほど…

趣味で作っているサービスのAPIサーバを例に。
キャッシュ応答も含めて集計すると、最混雑時には90パーセンタイル値も0msになります。正しいといえば正しいのですが。

キャッシュ応答を除外させると…　中央値300ms強。99パーセンタイル値に不安がありますが、まあまあかな。