C10K対応Prefork型高速PSGI/Plackサーバの Monoceros をHTTP/1.1に対応させました。

https://metacpan.org/release/Monoceros
https://github.com/kazeburo/Monoceros

MonocerosではHTTPのKeepAliveに対応して、大量の接続を捌く事ができますが、リリース時点ではHTTP/1.0 KeepAliveにしか対応していませんでした。しかし、nginxのupsream などでは、keepaliveを有効にしてHTTPセッションを使い回したい場合にHTTP/1.1が求められます。

monoceros-keepalive.png

以前このあたりの事をしらべてblog書いています

nginx-1.1.x で httpなupstreamにもkeepaliveができるようになったので検証してみた
http://blog.nomadscafe.jp/2012/02/nginx-11x-httpupstreamkeepalive.html

これではMonocerosが活かせないということで既に1.1に対応しているStarmanを参考にしつつ、HTTP/1.1対応しました。対応したのは次の機能

  • KeepAlive
  • Transfer-Encoding: chunked (Request & Response)
  • HTTP Pipelining
  • Expect

これらに対応しつつ、今までのHTTP/1.0のKeepAliveも使えるようになっています。

ほとんど使われない機能ですが、HTTP Pipeliningにも対応していて

my $body = 'OK 'x10;
sub {
    [200, ['Content-Type'=>'text/plain'],[$body]]
}

こんなpsgiを書いてMonocerosを起動してncを使って2つのリクエストを続けて投げてみると、

$ cat reqs.txt 
GET /1 HTTP/1.1
Host: foo

GET /2 HTTP/1.1
Host: foo
Connection: close

$ cat reqs.txt | nc 10.xx.xx.xx 5000
HTTP/1.1 200 OK
Date: Fri, 17 May 2013 06:08:35 GMT
Server: Plack::Handler::Monoceros
Content-Type: text/plain
Transfer-Encoding: chunked

1e
OK OK OK OK OK OK OK OK OK OK 
0

HTTP/1.1 200 OK
Date: Fri, 17 May 2013 06:08:35 GMT
Server: Plack::Handler::Monoceros
Content-Type: text/plain
Transfer-Encoding: chunked
Connection: close

1e
OK OK OK OK OK OK OK OK OK OK 
0

と、レスポンスも2つ得られました。Transfer-Encodingがchunkedにもなってますね。

Monocerosをnginx のバックエンドに設置してのベンチマーク

HTTP/1.1対応できたので、早速nginxのバックエンドにしてベンチマークしてみました。

monoceros-keepalive-bench.png

Upstream KeepAliveを有効にすると、大体倍の性能になるようですね。ベンチマークに使ったのはab、参考としてabもkeepalive on/off切り替えてデータを取得しました。なお、直接 Monocerosにアクセスすると、2万強のreq/secがでます。この差がReverse Proxyする分のオーバーヘッドですね

ベンチマークに使った環境は前回と同じ、Xeon L5630 2.13GHz 4コア/8スレッド を2つ積んだサーバです。nginxとMonocerosを同じサーバに導入し、abは別のサーバから実行しました。

ベンチマークに使ったアプリケーション

my $body = 'OK 'x10;
sub {
    [200, ['Content-Type'=>'text/plain','Content-Length'=>length($body)],[$body]]
}

残念ながら ab が Transfer-Encoding: chunked による KeepAliveに対応していないので、Content-Lengthを付けています。

Monocerosの起動は、

$ carton exec -- plackup -E production --port 5000 --max-workers=10 -s Monoceros --max-reqs-per-child=50000 -a app.psgi

nginx.confは主なところを抜き出すと以下。

worker_processes 1;
events {
    use epoll;
    worker_connections  10000;
}
http {
    keepalive_timeout      5 3;
    keepalive_requests     50000;
    upstream backend {
        server 127.0.0.1:5000;
        keepalive 100;
    }
    server {
        listen       8080;
        server_name  localhost;
        location / {
            proxy_http_version 1.1;
            proxy_set_header Connection "";
            proxy_pass http://backend;
        }
    }
}

ab は -c 100 で実行しました。

$ ab -k -c 100 -n 50000 'http://10.xx.xx.xx:8080/

リクエストの数や接続数次第ではnginxのworker_processes/keepaliveなどの設定を変更する必要がありそうです。

Monoceros というPSGI/Plackサーバ書きました

https://metacpan.org/release/Monoceros
https://github.com/kazeburo/Monoceros

StarmanやStarletのようなPreforkなアプリケーションサーバでは、コネクションの維持イコールプロセスの占有なので、HTTPのKeepAliveは無効にするのが一般的ですが、負荷の高いサービスではTIME_WAIT状態のソケットが溜まったり、SYN-ACKの再送問題などあり、KeepAliveを使いたいという欲求があったりなかったりします。

Monoceros はリクエストを処理するworkerの他に、イベントドリブンで動くコネクション管理プロセスを立てて、クライアントからの接続ソケットをunix domain socketを使いプロセス間でやりとりします。待機中の接続をPreforkなworkerではなくイベントドリブンのプロセスで管理することで、プロセスを占有することなく大量のコネクションを捌く事ができます。適切に設定すれば10000接続もいけると思います。

monoceros1.png

コネクション管理プロセスではAnyEventを使って接続をイベントドリブンで処理して、クライアントからの接続ののち最初のリクエストが読み取れる段階になったらIO::FDPassを使ってWorkerにソケットを受け渡します。Workerは受け取ったソケットからリクエストを読み取ってクライアントにレスポンスを直接返します。KeepAliveが有効であれば、その接続を維持して再度読み込み待ちにするようにコネクション管理プロセスに情報を送信し、Workerは次のリクエストに備えます。

実際にはDEFER_ACCEPTの処理やmax_keepalive_requestに達した際の処理があるのでもう少し複雑です。興味のある方はソースコードを参考にしてもらえたらと思います。

Workerは、高速で安定しているStarletを継承してほぼそのまま利用しています。なので現状HTTP/1.0のKeepAliveだけをサポートしています。

ベンチマーク

さっそくベンチマークです。MonocerosとStarman/Starletを比べてみます。

今回ベンチマークに使った各ソフトウェアのバージョンは以下になります

Plack (1.0023)
EV (4.15)
Guard (1.022)
Starlet (0.18)
HTTP::Parser::XS (0.16)
Monoceros (0.08)
Starman (0.3011)

サーバは Xeon L5630 2.13GHz 4コア/8スレッド を2つ積んだサーバです

それぞれ以下のオプションで起動します。MonocerosとStarmanは1接続あたりのKeepAliveリクエスト数の上限設定がありません。

$ carton exec -- plackup -E production --port 5000 --max-workers=15 -s Starlet --max-keepalive-reqs=50000 --max-reqs-per-child=50000 -a app.psgi
$ carton exec -- plackup -E production --port 5000 --max-workers=15 -s Monoceros --max-reqs-per-child=50000 -a app.psgi
$ carton exec -- starman --preload-app --workers=15 --max-requests=50000 -a app.psgi

app.psgiの中身は

use Plack::Builder;
my $length = 12;
my $body = 'x'x$length;
builder {
    enable 'AccessLog', logger => sub { };
    sub {
        #select undef,undef,undef,0.01;
        my $env = shift;
        my $req = Plack::Request->new($env);
        my @params = $req->param('foo');   
        [200, ['Content-Type'=>'text/plain','Content-Length'=>length($body)],[$body]]
    }
};

になっています。

ベンチマークに使った ab のオプションは

KeepAlive無効時 $ ab -c 100 -n 50110 http://../foo?foo=bar&bar=baz&baz=hoge&hoge=foo
KeepAlive有効時 $ ab -k -c 100 -n 50110 http://../foo?foo=bar&bar=baz&baz=hoge&hoge=foo

ベンチマーク結果

monoceros2.png

まず、MonocerosはKeepAlive無効時にStarletとほぼ同等の性能がでます。内部の動作でもselect(2)が一回多いだけでほぼ同じ動きをしています。

そしてKeepAliveを有効にした場合、StarmanとStarletが大きく数値を伸ばしているのに対して、Monocerosは少し増えただけのように思えます。

これにはいくつか理由があります。まずabは接続できたコネクションを優先して使ってリクエストを行います。-c 100と同時接続数を100に指定しても実際には100回の接続を均等に使いません。最初に接続できたコネクションを中心にリクエストを行ってしまいます。Starman/Starletでは —workers/—max-workers に指定された値、ここでは15接続に偏ってアクセスします。

Starman/Starletでは1つの接続が1つのプロセスを占有して処理されるのでKeepAlive有効時に高速になりますが、逆にMonocerosではAnyEventのプロセスとworker間のソケットのやりとりをして多くの接続を受け付け、接続とプロセスを分離して扱えるように設計されているので、その分多少のオーバーヘッドがあります。それでもKeepAlive有効時に高速になるようにkazuho氏のアドバイスの参考に様々な工夫をしています。

Monoceros雑感
http://d.hatena.ne.jp/kazuhooku/20130425/1366851011

kazuho++

KeepAlive Timeoutを考慮したベンチマーク

ApacheBenchの動作は上で説明した通りなのですが、実際のブラウザ/Proxyとの通信では状況が異なります。KeepAliveを使って何回かのリクエストを行った後もまたその接続を使い回す可能性あるので、ブラウザ側かサーバ側でコネクションを切断するまで何もしない状態で接続が維持されます。Starman/Starletではそういった接続でも1つのプロセスを占有してしまうので、次のリクエストを受け付けることができなくなります。

Starman/Starletにある —keepalive-timeout というオプションはKeepAliveの次のアクセスを待つまでの時間で、通信のない接続にプロセスがいつまでも占有されてしまうのを防ぎます。ApacheではKeepAliveTimeoutですね。

以下のブログも参考になります。

keep-aliveでHTTPコネクションを放置するベンチマーク(abパッチ)
http://mtl.recruit.co.jp/blog/2008/09/keepalivehttpab.html

上記のブログと同じようなベンチマークをperlのCoroとFurlを使って書いてみました。FurlはデフォルトでKeepAliveになります。

use strict;
use warnings;
use 5.10.0;
use AnyEvent;
use Coro;
use FurlX::Coro::HTTP;
use Time::HiRes;
use Statistics::Basic qw(:all);
use List::Util qw/max min/;

my $reqs_per_thread = $ARGV[0];
my $threads = $ARGV[1];
my $url = $ARGV[2];

my $cv = AE::cv;
my @coros;
my @statistics;
my $errors = 0;
my %ua;
for my $id (1..$threads) {
    $cv->begin;
    push @coros, async {

        warn "[$id] start";
        $ua{$id}  = FurlX::Coro::HTTP->new(
            timeout => 5,
        );
        for (1..$reqs_per_thread) {
            my @t = Time::HiRes::gettimeofday;
            my @res = $ua{$id}->get($url);
            my $ela = Time::HiRes::tv_interval ( \@t );
            push @statistics, $ela;
            $errors++ if $res[1] != 200;
        }
        warn "[$id] end";
        $cv->end;
    };
}

my @t = Time::HiRes::gettimeofday;
$_->join for @coros;
$cv->recv;
my $total =  Time::HiRes::tv_interval ( \@t );

say sprintf 'finished in %s sec. concurrency: %s reqs_per_thread: %s', $total, $threads, $reqs_per_thread;
say sprintf 'requests: failed %s', $errors;
say '= per-reqs statistics =';
say sprintf 'minimum: %s sec', min(@statistics);
say sprintf 'maximum: %s sec', max(@statistics);
say sprintf 'average: %s sec', average(@statistics);
say sprintf 'median: %s sec', median(@statistics);

1接続に付き250リクエストを接続数100と1000でStarletとMonocerosに対して実行してみます

まずStarlet。

■接続数100

finished in 15.043832 sec. concurrency: 100 reqs_per_thread: 250
requests: failed 80
= per-reqs statistics =
minimum: 0.000444 sec
maximum: 5.991323 sec 
average: 0.03 sec
median: 0 sec

■接続数1000

finished in 177.534857 sec. concurrency: 1000 reqs_per_thread: 250
requests: failed 14765
= per-reqs statistics =
minimum: 0.00041 sec
maximum: 6.146582 sec
average: 0.37 sec
median: 0 sec

5秒以上リクエスト(接続)に時間が掛かかることもあり、何度もリクエストに失敗しています。

次にMonoceros。

■接続数100

finished in 4.0479 sec. concurrency: 100 reqs_per_thread: 250
requests: failed 0
= per-reqs statistics =
minimum: 0.000625 sec
maximum: 0.045615 sec
average: 0.02 sec
median: 0.02 sec

■接続数1000

finished in 43.784275 sec. concurrency: 1000 reqs_per_thread: 250
requests: failed 0
= per-reqs statistics =
minimum: 0.001168 sec
maximum: 0.402207 sec
average: 0.17 sec
median: 0.17 sec

全体の掛かる時間が短くなりました。リクエスト単位でも最大で0.4秒でレスポンスが得られ、リクエストが失敗するとはありません。Starletに比べて最短のレスポンス時間とレスポンス時間の中央値が悪くなっていますが、このあたりがMonocerosのオーバーヘッドなのでしょう。

結論

アプリケーションサーバでKeepAliveを有効にして大量の接続を維持し隊!ということがあればMonocerosは十分に使えると思われます。ぜひお試しください

dannさんが以前Catalystでやってたのを参考に、Plack/PSGIアプリケーションのメモリリークを Devel::Leak::Object で調べる方法

plackup を -MDevel::Leak::Object 付けて起動

$ plackup -MDevel::Leak::Object=GLOBAL_bless -e '$Devel::Leak::Object::TRACKSOURCELINES = 1' -s Starlet --max-workers=1 app.psgi

-e ‘$Devel::Leak::Object::TRACKSOURCELINES = 1’ を付けると行数まで出力してくれる

app.psgiはこんなの

sub {
   my $env = shift;
   my $ref;$ref = bless \$ref, 'XXX';
   [200,['Content-Type'=>'text/html'],["OK"]];
};

Starletの —max-reqs-per-child のデフォルトは 100 なので、ab使って100回アクセス。

$ ab -n 100 http://localhost:5000/

すると、plackupを起動したコンソールの最後に、

...
127.0.0.1 - - [18/Apr/2013:17:21:17 +0900] "GET / HTTP/1.0" 200 2 "-" "ApacheBench/2.3"
127.0.0.1 - - [18/Apr/2013:17:21:17 +0900] "GET / HTTP/1.0" 200 2 "-" "ApacheBench/2.3"
127.0.0.1 - - [18/Apr/2013:17:21:17 +0900] "GET / HTTP/1.0" 200 2 "-" "ApacheBench/2.3"
Tracked objects by class:
    Config                                   1
    Errno                                    1
    POSIX::SigRt                             1
    XXX                                      100

Sources of leaks:
Config
     1 from /path/to/perl5/perlbrew/perls/perl-5.16/lib/5.16.3/darwin-2level/Config.pm line: 73
Errno
     1 from /path/to/perl5/perlbrew/perls/perl-5.16/lib/5.16.3/darwin-2level/Errno.pm line: 167
POSIX::SigRt
     1 from /path/to/perl5/perlbrew/perls/perl-5.16/lib/5.16.3/Tie/Hash.pm line: 246
XXX
   100 from /path/to/Desktop/app.psgi line: 3

とでます。これで XXX があやちいことがわかりましたね

Plack-1.0023 から Plack::Middleware::AccessLog が Apache::LogFormat::Compiler を使うようになって、アクセスログの出力が速くなりました。

これまでの PM::AccessLog はリクエストの度に ログフォーマットの文字列を正規表現でパース、必要なメソッドを呼び出してアクセスログを生成していましたが、ALFCは初期化フェーズで ログフォーマットの文字列を1つのperlのコードに変換してしまうので、低コストでログを生成することができます。

以下ベンチマーク結果。アクセスログを有効にしただけのHello Worldだと、1.5倍くらい早くなる模様。memcachedに数回リクエストを送るだけのアプリケーションならプロダクション環境でも効果があるんじゃないでしょうか。ちなみにサーバを介さないベンチマークだと6倍ぐらい高速になってました

Benchmarks

HelloWorld.psgi

use Plack::Builder;
builder {
    enable 'AccessLog', logger => sub { };
    sub { [200, ['Content-Type'=>'text/plain','Content-Length'=>11],['Hello World']] }
};

Setup

Plack-1.0022

$ cat cpanfile
requires 'Plack', '== 1.0022';
requires 'Starlet';
requires 'HTTP::Parser::XS';
$ carton install
$ carton exec -- -- plackup -s Starlet -E production --max-workers=10 --max-reqs-per-child=10000 -a HelloWorld.psgi

Plack-1.0023

$ cat cpanfile
requires 'Plack', '== 1.0023';
requires 'Starlet';
requires 'HTTP::Parser::XS';
$ carton install
$ carton exec -- -- plackup -s Starlet -E production --max-workers=10 --max-reqs-per-child=10000 -a HelloWorld.psgi

ApacheBench Options

$ ab -c 8 -n 50000 http://localhost:5000/

Result

Plack-1.0022

Concurrency Level:      8
Time taken for tests:   4.201 seconds
Complete requests:      50000
Failed requests:        0
Write errors:           0
Total transferred:      7300146 bytes
HTML transferred:       550011 bytes
Requests per second:    11900.85 [#/sec] (mean)
Time per request:       0.672 [ms] (mean)
Time per request:       0.084 [ms] (mean, across all concurrent requests)
Transfer rate:          1696.84 [Kbytes/sec] received

Plack-1.0023

Concurrency Level:      8
Time taken for tests:   2.864 seconds
Complete requests:      50000
Failed requests:        0
Write errors:           0
Total transferred:      7300146 bytes
HTML transferred:       550011 bytes
Requests per second:    17460.12 [#/sec] (mean)
Time per request:       0.458 [ms] (mean)
Time per request:       0.057 [ms] (mean, across all concurrent requests)
Transfer rate:          2489.48 [Kbytes/sec] received

これが出た事でAxsLogに「高速」というアドバンテージがなくなった。PODを書き直さないと!

Apache::LogFormat::Compiler のバージョン0.05で、ログフォーマットの %D とか %{..}i の文字を追加できるようになりました。

https://metacpan.org/release/KAZEBURO/Apache-LogFormat-Compiler-0.05/

こちらのticketを実装しました
https://github.com/kazeburo/Apache-LogFormat-Compiler/issues/1

使い方

my $log_handler = Apache::LogFormat::Compiler->new(
    '%z %{HTTP_X_FORWARDED_FOR|REMOTE_ADDR}Z',
    char_handlers => +{
        'z' => sub {
            my ($env,$req) = @_;
            return $env->{HTTP_X_FORWARDED_FOR};
        }
    },
    block_handlers => +{
        'Z' => sub {
            my ($block,$env,$req) = @_;
            # block eq 'HTTP_X_FORWARDED_FOR|REMOTE_ADDR'
            my ($main, $alt) = split('\|', $args);
            return exists $env->{$main} ? $env->{$main} : $env->{$alt};
        }
    },
);

他にもPlackへの依存がなくなったり、いくつか修正が入ってます。

監視をテーマに参加者全員がゆるふわに好き放題しゃべる Monitoring Casual Talk に参加してきました

Zussar: http://www.zusaar.com/event/521056

発表した内容はこちら。監視の話なのかどうかは謎

MHA for MySQLの基本構成と弊社で使っているMHA管理ツールの紹介です。masterha_managerの設定とプロセス管理、そしてオンラインでのマスター切り替えをWebUIから行えるの非常に便利なツールです。オープンソースになってないのに喋りました。すみません。

今回感じたのが、モニカジ参加者かいわいでの監視ツールが zabbix か munin + nagios に固まってきている点。zabbix勢はツールの使いこなしに悩んでいて、nagios勢は設定ファイルの自動生成あたりがホットな話題という感じでした。

弊社は cloudforecast + データセンターの監視サービス + 一部nagios の環境。サーバ管理ツールとの連携とかあまりしていないので、監視漏れは気をつけていないとでてくるし、そろそろツールの改良,自動化などを考えたいと思っているところ。

ちなみに nagiosの設定ファイルは Data::Section::SimpleXslateで生成してる。

#!/usr/bin/env perl

use strict;
use warnings;
use Text::Xslate;
use Data::Section::Simple qw(get_data_section);
use Log::Minimal;
$Log::Minimal::AUTODUMP=1;

my @nodes;
for my $l ( split /\n/, get_data_section('data') ) {
    chomp($l);
    my ($ip, $host, $notify) = split /\s+/, $l;
    push @nodes, {
        ipaddr => $ip,
        hostname => $host,
        is_master => ( $host =~ m!^dbm! ) ? 1 : 0,
        notify => $notify ? 1 : 0,
    };
}

my $tx = Text::Xslate->new();
print $tx->render_string(get_data_section('tmpl'), { nodes => \@nodes });

__DATA__
@@ data
10.xx.xx.74 dbm101.service
10.xx.xx.74 dbs101.service

@@ tmpl
: for $nodes -> $node {
define host{
  use                     generic-host
  max_check_attempts      3
  host_name               <: $node.hostname :>
  alias                   <: $node.hostname :>
  address                 <: $node.ipaddr :>
  contact_groups          ldnsg
}

define service{
  use                             generic-service
  host_name                       <: $node.hostname :>
  service_description             Disk Usage
  max_check_attempts              3
  normal_check_interval           15
  retry_check_interval            15
  notification_options            u,c,r
  notifications_enabled           1
  check_command                   check_mysql5_disk
}
..
:}

define hostgroup{
  hostgroup_name  mysql5
  alias           mysql5
  members         <: $nodes.map(-> $a { $a.hostname }).join(", ") :>
}

サーバが増えても1行足すだけなので、お気楽ですね。

日本語でも書く

Plack::Middleware::AxsLog バージョン 0.10 をリリースしました。

cpan: https://metacpan.org/release/Plack-Middleware-AxsLog

今までのバージョンでは、combined、common、ltsvの3つのログフォーマットしか使えなかったんだけど、新しいバージョンで任意のフォーマットが使えるようになりました。

AxsLogがPM::AccessLogに比べて速いのは、ログ文字列の生成を正規表現ではなく、単純な文字列連結でやっていたためで、その代わりにフォーマットを自由に変更できない制限がありました。

けど、このバージョンから Apache::LogFormat::Compiler を使っているので、速度を犠牲にすることなくフォーマットの変更が可能となりましたぞよ。

使い方

use Plack::Builder;

builder {
    enable 'AxsLog',
        format => '%h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-agent}i" %D',
        response_time => 1,
        error_only => 1,
    $app
};

ちなみにマイクロベンチマークの結果。AccessLogよりも5倍程度高速

Benchmark: running axslog, axslog_format, error_only_axslog, log, nolog for at least 3 CPU seconds...
    axslog:  3 wallclock secs ( 3.15 usr +  0.01 sys =  3.16 CPU) @ 15955.70/s (n=50420)
axslog_format:  3 wallclock secs ( 3.19 usr +  0.01 sys =  3.20 CPU) @ 16036.25/s (n=51316)
error_only_axslog:  4 wallclock secs ( 3.14 usr +  0.01 sys =  3.15 CPU) @ 42440.32/s (n=133687)
       log:  3 wallclock secs ( 3.18 usr +  0.01 sys =  3.19 CPU) @ 3216.61/s (n=10261)
     nolog:  4 wallclock secs ( 3.13 usr +  0.00 sys =  3.13 CPU) @ 432826.20/s (n=1354746)
                      Rate    log axslog axslog_format error_only_axslog   nolog
log                 3217/s     --   -80%          -80%              -92%    -99%
axslog             15956/s   396%     --           -1%              -62%    -96%
axslog_format      16036/s   399%     1%            --              -62%    -96%
error_only_axslog  42440/s  1219%   166%          165%                --    -90%
nolog             432826/s 13356%  2613%         2599%              920%      --

scriptはこれ https://github.com/kazeburo/Plack-Middleware-AxsLog/blob/master/logbench.pl

I released Plack::Middleware::AxsLog version 0.10 at last week.

cpan: https://metacpan.org/release/Plack-Middleware-AxsLog

Plack-Middleware-AxsLog < 0.10 supports only combined, common, ltsv log format. And cannot specify the log format freely.

PM::AxsLog simply joined strings to generate logline. So it’s faster than PM::AccessLog. But does’t have ability to modify the log format.

By using Apache::LogFormat::Compiler, PM::AxsLog version 0.10 can modify log format without performance loss.

usage

use Plack::Builder;

builder {
    enable 'AxsLog',
        format => '%h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-agent}i" %D',
        response_time => 1,
        error_only => 1,
    $app
};

result of micro-benchmarking

Benchmark: running axslog, axslog_format, error_only_axslog, log, nolog for at least 3 CPU seconds...
    axslog:  3 wallclock secs ( 3.15 usr +  0.01 sys =  3.16 CPU) @ 15955.70/s (n=50420)
axslog_format:  3 wallclock secs ( 3.19 usr +  0.01 sys =  3.20 CPU) @ 16036.25/s (n=51316)
error_only_axslog:  4 wallclock secs ( 3.14 usr +  0.01 sys =  3.15 CPU) @ 42440.32/s (n=133687)
       log:  3 wallclock secs ( 3.18 usr +  0.01 sys =  3.19 CPU) @ 3216.61/s (n=10261)
     nolog:  4 wallclock secs ( 3.13 usr +  0.00 sys =  3.13 CPU) @ 432826.20/s (n=1354746)
                      Rate    log axslog axslog_format error_only_axslog   nolog
log                 3217/s     --   -80%          -80%              -92%    -99%
axslog             15956/s   396%     --           -1%              -62%    -96%
axslog_format      16036/s   399%     1%            --              -62%    -96%
error_only_axslog  42440/s  1219%   166%          165%                --    -90%
nolog             432826/s 13356%  2613%         2599%              920%      --

benchmark script is here: https://github.com/kazeburo/Plack-Middleware-AxsLog/blob/master/logbench.pl

I uploaded Apache::LogFormat::Compiler to CPAN.

cpan: https://metacpan.org/release/Apache-LogFormat-Compiler
github: https://github.com/kazeburo/Apache-LogFormat-Compiler

Apache::LogFormat::Compiler compiles log_format line ‘combined’, ‘common’ or ‘%h %l %u %t “%r” %>s %b’ to perl-code.

It’s faster than Plack::Middleware::AccessLog’s way that parses log_format by regexp each request.

my $log_handler = Apache::LogFormat::Compiler->new();
my $compile_log_app = builder {
    enable sub {
        my $app = shift;
        sub {
            my $env = shift;
            my $res = $app->();
            $env->{psgi.errors}->print($log_handler->log_line($env,$res,6,0));
        }
    };
    sub{ [ 200, [], [ "Hello "] ] };
};

This sample psgiapp is 8 times faster than the app that uses PM::AcccessLog.

I have plan to use Apache::LogFormat::Compiler in Plack::Middleware::AxsLog for customize any log_format.

generated sample perl-code.

% perl -Ilib -ML -E 'say Apache::LogFormat::Compiler->new()->{log_handler_code} '
sub {
        my ($env,$res,$length,$time) = @_;
        my @lt = localtime;
        my $t = sprintf '%02d/%s/%04d:%02d:%02d:%02d %s', $lt[3], $abbr[$lt[4]], $lt[5]+1900, 
          $lt[2], $lt[1], $lt[0], $tz;
        q!! . ($env->{REMOTE_ADDR} || '-')
      . q! ! . '-'
      . q! ! . ($env->{REMOTE_USER} || '-')
      . q! ! . "[" . $t . "]"
      . q! "! . _safe($env->{REQUEST_METHOD}) . " " . _safe($env->{REQUEST_URI}) .
                       " " . $env->{SERVER_PROTOCOL}
      . q!" ! . $res->[0]
      . q! ! . (defined $length ? $length : '-')
      . q! "! . _string($env->{"HTTP_" . uc('Referer')})
      . q!" "! . _string($env->{"HTTP_" . uc('User_agent')})
      . q!"!
    }

I just released Module::Build::Pluggable::CPANfile to CPAN.

Module::Build::Pluggable::CPANfile is plugin for Module::Build::Pluggable to include dependencies from cpanfile.

cpan: https://metacpan.org/release/Module-Build-Pluggable-CPANfile
github: https://github.com/kazeburo/Module-Build-Pluggable-CPANfile

This is Module::Install::CPANfile for Module:Build.

Here is short sample cpanfile and Build.PL.

# cpanfile
requires 'Plack', 0.9;
on test => sub {
    requires 'Test::Warn';
};

# Build.PL
use Module::Build::Pluggable (
    'CPANfile'
);

my $builder = Module::Build::Pluggable->new(
    license              => 'perl',
    dynamic_config       => 0,
    no_index    => { 'directory' => [ 'inc' ] },
    name        => 'Foo-Bar',
    module_name => 'Foo::Bar',        
    test_files => (-d '.git' || $ENV{RELEASE_TESTING}) ? 't/ xt/' : 't/',
    recursive_test_files => 1,
    create_readme  => 1,
    create_license => 1,
);
$builder->create_build_script();

Prereqs will be dumped into (MY)?META.(yml|json)

Try it!

最近のコンテンツはインデックスページで見られます。過去に書かれたものはアーカイブのページで見られます。

アイテム

  • monoceros-keepalive-bench.png
  • monoceros-keepalive.png
  • monoceros2.png
  • monoceros1.png
  • derived2gf.png
  • hr_total.png
  • hr_top.png
  • reverseproxy2.png
  • isucon_kazeburo.png
  • mycnf.png

ウェブページ

OpenID対応しています OpenIDについて
Powered by Movable Type 4.27-ja