2012年2月アーカイブ

GrowthForecastというグラフ表示ツールで捗る話」で紹介したGrowthForecastですが、モリス氏のfluent meetupでの発表やriywo氏の発表で少し紹介されていたりするわけですが、社内でも少しずつメトリクスが増えて活用されています。

データが既に入っているので大きな変更はできないのですが、少し機能追加をしています。

ソースコード
https://github.com/kazeburo/GrowthForecast

1分更新グラフ

GrowthForecast はWebアプリケーションとWorkerの2つから構成されています。APIに対してPOSTされたデータは、一旦SQLiteのDBに格納され、Workerがそれを取得、RRDファイルを更新します。これまでは5分毎に動くworkerがいるだけでしたが、そこに1分毎動くworkerを追加しました。

growthforecast_two_workers.png

上の図のようにworkerが2つ動くようになりました。すぐに結果が知りたいとき、5分よりも高い解像度でデータがみたいときに利用できます。

画面では、とりあえず感が強いけどボタンが追加されています。

growthforecast-1min.png

デフォルトでこの機能が有効になっていますが、以下のように起動することで、これまでと同じ5分更新だけにできます

$ perl growthforecast.pl --disable-1min-metrics

JSONフォーマットでの出力機能追加

これまでGrowthForecastはデータを溜め込んでグラフとして表示するだけでしたが、これだけではせっかく貯めたデータの再利用ができず捗りません。そこでRRDファイルに保存されているデータをJSONにて出力できるAPIを作りました。

APIは2種類。1つ目はグラフの凡例にでているサマリー取得API

$ curl http://example.com/summary/path/to/graph
{"graph":["0.00000000","0.09241971","5.91815168","0.00000000"]}

レスポンスのデータは指定期間中の「現在」「平均」「最大」「最小」となります。

もう一つのAPIは、グラフデータのエクスポート。

$ curl http://gf.ops.dev.livedoor.net/xport/path/to/graph?t=d&gmode=subtract
{"column_names":["graph"],"step":600,"columns":1,"end_timestamp":1329790200,"start_timestamp":1329671400,"rows":[[0.499581818333333],[0],[0],[0],[0],[0],[0],[0],[0],...,[null]]}

このようにグラフを描く際に使う値が取得できます。2つのAPIは複合グラフでも利用可能です。

これらのAPIを使って、以下のような監視をすることを妄想中です。

fluent-growthforecast-monitoring.png

アクセスログからステータスコードごとにまとめて件数をGrowthForecastになげて、エラーの割合が一定を超えたらアラートを出すとか、ツールを連携させることで実現できそうですね

合わせて読みたい

fluent-plugin-flowcounter および fluent-plugin-growthforecast released! #fluentd - tagomorisのメモ置き場

slowloris対策として、Apacheの2.1.15から入ったモジュールにmod_reqtimeoutというのがあります。

RequestReadTimeout header=10 body=30

このように設定することで、headerの受信が10秒以内、bodyの受信が30秒以内に完了しない場合、「408」エラーとできます。簡単で便利そうですね

公式ドキュメント http://httpd.apache.org/docs/2.2/en/mod/mod_reqtimeout.html


ただし、

Apacheをreverse proxyとして使用している場合はTimeoutにならず、リクエストの一部がproxy先に送られるという問題があるので注意が必要というか、はまったのでその話。

ちなみに、すでにBugzillaには上がっているけど、2.2系ではまだ対応完了してない https://issues.apache.org/bugzilla/show_bug.cgi?id=51103




以下再現方法。

まず、reverse proxy側で RequestReadTimeout と ProxyPass を設定します

RequestReadTimeout header=10 body=5
ProxyPass /backend http://127.0.0.1:5000

そして、backendとなるStarletには以下のpatchをあてます。

diff --git a/lib/Starlet/Server.pm b/lib/Starlet/Server.pm
index ea5a34a..f99f360 100644
--- a/lib/Starlet/Server.pm
+++ b/lib/Starlet/Server.pm
@@ -17,6 +17,8 @@ use Socket qw(IPPROTO_TCP TCP_NODELAY);
 use Try::Tiny;
 use Time::HiRes qw(time);

+use Log::Minimal;
+
 use constant MAX_REQUEST_SIZE => 131072;
 use constant MSWin32          => $^O eq 'MSWin32';

@@ -155,6 +157,10 @@ sub handle_connection {
         undef $can_exit;
         my $reqlen = parse_http_request($buf, $env);
         if ($reqlen >= 0) {
+            {
+                local $Log::Minimal::AUTODUMP=1;
+                warnf $env;
+            }
             # handle request
             if ($use_keepalive) {
                 if (my $c = $env->{HTTP_CONNECTION}) {
@@ -177,6 +183,7 @@ sub handle_connection {
                             $conn, \$chunk, $cl, 0, $self->{timeout})
                             or return;
                     }
+warnf "chunk size: %d", length($chunk);
                     $buffer->print($chunk);
                     $cl -= length $chunk;
                 }

関係ないけどStarletはシンプルなのでこういう検証に便利ですね

そしてtest用のpsgiアプリケーションを書いて

use Plack::Request;

sub {
    my $env = shift;
    my $req = Plack::Request->new($env);
    my $content = $req->content();
    my $length = length($content);
    [200,['Content-Type'=>'text/plain','Content-Length'=>length($length)+1],["$length\n"]];
};

起動、

$ plackup -s Starlet test.psgi

今度は、Bodyを送るのに5秒以上掛かるように細工したクライアントを書きます

#!/usr/bin/perl

use strict;
use warnings;
use IO::Socket::INET;

my $sock = IO::Socket::INET->new(
    PeerAddr => '127.0.0.1',
    PeerPort => '8080',
);

my $header = <<EOF;
POST /backend/foo HTTP/1.1
Host: example.com
User-Agent: slowpost
Content-Length: 32768
EOF

$header =~ s/\n/\r\n/g;

$sock->syswrite("$header\r\n");

for (1..8) {
    $sock->syswrite("1"x4096);
    sleep 1;
}

my $res;
$sock->sysread( $res, 8192 );

print $res;

これを使って、Apacheに向けてリクエストを送ってみると、、

$ perl slowpost.pl
HTTP/1.1 400 Bad Request
Date: Thu, 16 Feb 2012 02:28:51 GMT
Content-Length: 226
Connection: close
Content-Type: text/html; charset=iso-8859-1

<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>400 Bad Request</title>
</head><body>
<h1>Bad Request</h1>
<p>Your browser sent a request that this server could not understand.<br />
</p>
</body></html>

Bodyの送信に5秒以上掛かっているので、期待としては「408」が返って来そうですが「400」となりました。

Apacheのエラーログには

[Thu Feb 16 11:28:56 2012] [error] proxy: pass request body failed to 127.0.0.1:5000 (127.0.0.1) from 127.0.0.1 ()

このように記録されています。

ふむふむ、bodyのproxyに失敗しただけかと思うのですが、実際にはbodyも一部だけがproxyされ途中で切れています。

以下がplackupを起動したターミナルの出力

2012-02-16T11:28:54 [WARN] {'psgi.multiprocess' => 1,'SCRIPT_NAME' => '','SERVER_NAME' => 0,'HTTP_CONNECTION' => 'close','HTTP_X_FORWARDED_SERVER' => 'kazeburomba.local','PATH_INFO' => '/foo','CONTENT_LENGTH' => '32768','REQUEST_METHOD' => 'POST','psgi.multithread' => '','HTTP_USER_AGENT' => 'slowpost','QUERY_STRING' => '','REMOTE_PORT' => 55700,'SERVER_PORT' => 5000,'psgix.input.buffered' => 1,'REMOTE_ADDR' => '127.0.0.1','HTTP_X_FORWARDED_HOST' => 'example.com','SERVER_PROTOCOL' => 'HTTP/1.1','HTTP_X_FORWARDED_FOR' => '127.0.0.1','psgi.streaming' => 1,'psgi.errors' => *::STDERR,'REQUEST_URI' => '/foo','psgi.version' => [1,1],'psgi.nonblocking' => '','psgix.io' => bless( \*Symbol::GEN1, 'IO::Socket::INET' ),'psgi.url_scheme' => 'http','psgi.run_once' => '','HTTP_HOST' => '127.0.0.1:5000'} at /Users/hoge/perl5/perlbrew/perls/perl-5.12.2/lib/site_perl/5.12.2/Starlet/Server.pm line 162
2012-02-16T11:28:54 [WARN] chunk size:16384 at /Users/hoge/perl5/perlbrew/perls/perl-5.12.2/lib/site_perl/5.12.2/Starlet/Server.pm line 184

ヘッダも送られてきて、Bodyも16384byte読み込んでいます。

実際、StarletではBody部分がContent-Lengthの長さにならなければリクエストの処理に移らないので、問題とはならないのですが、Content-Lengthと異なっていても正常に処理をしてしまった場合(libapreqを使うmod_perlがそうだった気がする)問題となる可能性があります。

こわいこわい

おそらく原因としては、mod_reqtimeoutもmod_proxyもfilterで動いていて、reqtimeoutがエラーと判断した時にはすでにmod_proxyがbackendにコンテンツを送ってしまっていて、mod_proxyでリクエストのBofyの続きが読めなくなって「400」エラーって事なんだろうなぁと思ってます。

対策としては、RequestReadTimeout を使わない、もしくは使う場所を限定する(アップロードなど通信時間長くなるところには使わない)、Content-LengthやChunked-Transferを正しく扱うサーバを使ってのが考えられます。

そういえば昔、同じような問題に、LimitRequestBodyでもあたったことがあって、ApacheのFilter機構は難しいなぁと思った次第。

画像配信など大量にアクセスを捌く際にちょっと気になっていたhttpなupstreamとkeepaliveできない件が、nginx-1.1系でできるようになったので試してみた

nginx11keepalive.png

今回keepaliveできるようになったのは↑のbackendと通信するところ。

本家のドキュメントはこちら
http://nginx.org/en/docs/http/ngxhttpupstream_module.html#keepalive

keepalive機能を使うには、以下のように設定します

http {
    upstream backend {
        server 127.0.0.1:5000;
        keepalive 16;
    }
    server {
        listen       8080;
        server_name  localhost;
        location / {
            proxy_http_version 1.1;
            proxy_set_header Connection ";
            proxy_pass http://backend;
        }
    }
}

upstreamブロックにkeepaliveで、保持するコネクション数を指定し、proxy_http_version で「1.1」を(1.0については後述)、proxy_set_headerでConnectionヘッダを削除します。削除しなければならないのは、nginxがデフォルトで「close」を設定するからです。これで http://127.0.0.1:5000/ への通信がkeepalive可能になるはずです。

確認には、HTTP/1.1をサポートしたStarmanに、以下のpatchをあてて利用します

diff --git a/lib/Starman/Server.pm b/lib/Starman/Server.pm
index 67d1528..137972a 100644
--- a/lib/Starman/Server.pm
+++ b/lib/Starman/Server.pm
@@ -175,6 +175,7 @@ sub process_request {

         my $env = {
             REMOTE_ADDR     => $self->{server}->{peeraddr},
+            REMOTE_PORT     => $self->{server}->{peerport},
             REMOTE_HOST     => $self->{server}->{peerhost} || $self->{server}->{peeraddr},
             SERVER_NAME     => $self->{server}->{sockaddr}, # XXX: needs to be resolved?
             SERVER_PORT     => $self->{server}->{sockport},

そして用意したPSGIアプリケーションが以下。

sub {
    my $env = shift;
    my $port = $env->{REMOTE_PORT};
    [200,['Content-Type'=>'text/plain','Content-Length'=>length($port)+1],["$port\n"]];
};

keepaliveが有効であれば、backend側でのREMOTE_PORTは変わらないはずです。試しにstarmanを起動し、直接アクセスします。

$ starman --preload-app test.psgi
$ curl http://localhost:5000/{1..5}
55075
55075
55075
55075
55075

curlもHTTP/1.1 keepaliveをサポートするので、全て同じポート番号が戻ります。

次に nginx を起動して試してみます

$ ./sbin/nginx
$ curl http://localhost:8080/{1..5}
55099
55099
55099
55099
55099

おぉ。同じ番号になってます。keepaliveできてそう。

確認のために、nginx側でkeepaliveに関する設定を削除してみると、

$ curl http://localhost:8080/{1..5}
55233
55234
55235
55236
55237

このようにポート番号が次々に変わって行きます。keepaliveが有効になっているのがわかりますね!

ここまで検証してサービスで使えそう!と思ったのですが、今回使う事を考えていた画像配信で使っているSquidは残念なことに、HTTP/1.1 keepaliveをサポートしていません。Connectionヘッダにkeep-aliveを入れてリクエストをするHTTP/1.0が必要となります。

そこで、nginxの設定を

server {
    listen       8080;
    server_name  localhost;
    location / {
        proxy_set_header Connection "keep-alive";
        proxy_pass http://backend;
    }
}

このように変更し試してみましたが、keepaliveされませんでした。そこでnginxのソースコードを追って行くと、HTTP/1.1でない場合はコネクションを必ずcloseしてしまうようになってたので、レスポンスのConnectionヘッダに「keep-alive」が入っていた場合に、切断しないようにする以下のpatchをあてました。

--- nginx-1.1.14.orig/src/http/ngx_http_upstream.c      2012-01-19 00:07:43.000000000 +0900
+++ nginx-1.1.14/src/http/ngx_http_upstream.c   2012-02-09 17:11:02.000000000 +0900
@@ -3426,6 +3426,13 @@
         r->upstream->headers_in.connection_close = 1;
     }

+    if (ngx_strlcasestrn(h->value.data, h->value.data + h->value.len,
+                         (u_char *) "keep-alive", 10 - 1)
+        != NULL)
+    {
+        r->upstream->headers_in.connection_close = 0;
+    }
+
     return NGX_OK;
 }

これでHTTP/1.0でもkeepaliveできるはずなので、今度はHTTP/1.1をサポートしないStarletを使って検証します。Starmanと同じくREMOTE_PORTが取れるようpatchをあてます

diff --git a/lib/Starlet/Server.pm b/lib/Starlet/Server.pm
index ea5a34a..63b54f2 100644
--- a/lib/Starlet/Server.pm
+++ b/lib/Starlet/Server.pm
@@ -106,6 +106,7 @@ sub accept_loop {
                     SERVER_NAME => $self->{host},
                     SCRIPT_NAME => '',
                     REMOTE_ADDR => $conn->peerhost,
+                    REMOTE_ADDR => $conn->peerport,
                     'psgi.version' => [ 1, 1 ],
                     'psgi.errors'  => *STDERR,
                     'psgi.url_scheme' => 'http',

これで、plackup使いStarletサーバを起動し検証します。

$ plackup -s Starlet --max-keepalive-reqs=1000 test.psgi
$ curl http://localhost:8080/{1..5}
55961
55961
55961
55961
55961

同じポート番号がならんだので、keepaliveできてそう!やった!!1

最後に、参考程度にMacBookAir上でApacheBenchを使ってベンチマークとって見ました

$ ab -k -c 10 -n 5000 http://localhost:8080/

# keepaliveなし
Requests per second:    1910.71 [#/sec] (mean)
# keepaliveあり
Requests per second:    2935.73 [#/sec] (mean)

通常のアプリケーションサーバでは接続数が問題となるので、使わないと思いますが、後ろの接続数が問題とならない特定の用途では使えます。
ということで、既に画像配信の本番サーバにもpatchあてたnginx-1.1系が投入されています。多少CPU使用率が減った気がします。