%Time ExclSec CumulS #Calls sec/call Csec/c Name
86.2 0.950 13.359 10002 0.0001 0.0013 Catalyst::Engine::prepare
25.3 0.450 3.930 10002 0.0000 0.0004 Catalyst::Engine::CGI::Base::prepare_path
18.9 0.290 2.930 10002 0.0000 0.0003 Catalyst::Engine::FastCGI::prepare_request
14.8 0.040 2.300 10002 0.0000 0.0002 Catalyst::Engine::CGI::prepare_request
14.5 0.950 2.250 10002 0.0001 0.0002 Catalyst::Engine::CGI::Base::prepare_headers
13.359秒のうち，遅いのはprepare_path, prepare_request（FastCGIとCGIの２箇所）, prepare_headersの３つ。この３つで9秒ほどかかっている，と。まずはC::E::CGI::Base::prepare_pathから。
sub prepare_path {
my $c = shift;
my $base;
{
my $scheme = $c->request->secure ? 'https' : 'http';
my $host = $ENV{HTTP_HOST} || $ENV{SERVER_NAME};
my $port = $ENV{SERVER_PORT} || 80;
my $path = $ENV{SCRIPT_NAME} || '/';
unless ( $path =~ /\/$/ ) {
$path .= '/';
}
$base = URI->new;
$base->scheme($scheme);
$base->host($host);
$base->port($port);
$base->path($path);
$base = $base->canonical->as_string;
}
my $location = $ENV{SCRIPT_NAME} || '/';
my $path = $ENV{PATH_INFO} || '/';
$path =~ s/^($location)?\///;
$path =~ s/%([0-9A-Fa-f]{2})/chr(hex($1))/eg;
$path =~ s/^\///;
$c->req->base($base);
$c->req->path($path);
}
prepare_pathはExclSecが0.45秒，CumulSが3.930秒かかっている。ExclSecは後半の正規表現連打がもったいない気がする。CumulSはURI::schemeなどが積もり積もって，だろう。new, scheme, host, port, pathと呼んでcanonicalしている。URI::*を抜き出してみると，
%Time ExclSec CumulS #Calls sec/call Csec/c Name
5.49 0.110 0.850 10002 0.0000 0.0001 URI::http::canonical
5.23 0.300 0.810 20004 0.0000 0.0000 URI::_server::host
5.17 0.620 0.800 70014 0.0000 0.0000 URI::_generic::authority
4.26 0.420 0.660 20004 0.0000 0.0000 URI::_scheme
4.07 0.230 0.630 10002 0.0000 0.0001 URI::_server::canonical
3.94 0.020 0.610 10002 0.0000 0.0001 URI::scheme
3.42 0.240 0.530 20004 0.0000 0.0000 URI::new
3.23 0.240 0.500 20004 0.0000 0.0000 URI::_server::_port
3.04 0.060 0.470 10002 0.0000 0.0000 URI::_server::port
1.81 0.220 0.280 20004 0.0000 0.0000 URI::_generic::path
となっている。それぞれの詳細にまでたどるのは面倒くさいのであまり考えない。要するに環境変数から$c->req->baseと$c->req->pathを作っているだけなんだが，そこにURI::*を使うのはコストが高いんじゃないだろうか。
しかも，FastCGIなら，そもそも環境変数にセットして渡されるんじゃなく，FastCGIプロトコルで渡ってきたFCGI_PARAMSをFCGI.xsのpopulate_envでハッシュにコピーした結果だもんなぁ（コピー先のデフォルトが%ENVになっている）。
ところでlighttpdだとSERVER_NAMEにもHTTP_HOSTにもポート番号入っているな。環境変数取得した結果を見ると。いや，wgetか？ まあいいや。
# wget -q -O - http://localhost:8080/fcgi/ctest.fcgi/hoge//fuga?foo=bar
DOCUMENT_ROOT:/var/www/localhost/htdocs
FCGI_ROLE:RESPONDER
GATEWAY_INTERFACE:CGI/1.1
HTTP_ACCEPT:*/*
HTTP_CONNECTION:Keep-Alive
HTTP_HOST:localhost:8080
HTTP_USER_AGENT:Wget/1.10.2
PATH_INFO:/hoge/fuga
PATH_TRANSLATED:/var/www/localhost/htdocs/hoge/fuga
QUERY_STRING:foo=bar
REDIRECT_STATUS:200
REMOTE_ADDR:127.0.0.1
REMOTE_PORT:41597
REQUEST_METHOD:GET
REQUEST_URI:/fcgi/ctest.fcgi/hoge//fuga?foo=bar
SCRIPT_FILENAME:/var/www/localhost/htdocs/fcgi/ctest.fcgi
SCRIPT_NAME:/fcgi/ctest.fcgi
SERVER_ADDR:127.0.0.1
SERVER_NAME:localhost:8080
SERVER_PORT:8080
SERVER_PROTOCOL:HTTP/1.0
SERVER_SOFTWARE:lighttpd/1.4.7
さて，この3.9秒が省略できたとしたら，10000 / (43.469302 - 3.9) = 252.7req/sになるはず。試しにprepare_pathを
sub prepare_path {
my $c = shift;
$c->req->base('http://localhost/fcgi/ctest.fcgi/');
$c->req->path( $ENV{PATH_INFO} || '/' );
}
としたC::E::FastCGI2.pmを作ってみよう。
・・・と，その前にab2をDProf無しで試しておこう。
Server Software: lighttpd/1.4.7
Server Hostname: localhost
Server Port: 8080
Document Path: /fcgi/ctest.fcgi
Document Length: 48 bytes
Concurrency Level: 1
Time taken for tests: 21.617732 seconds
Complete requests: 10000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 9412
Total transferred: 1717060 bytes
HTML transferred: 480000 bytes
Requests per second: 462.58 [#/sec] (mean)
Time per request: 2.162 [ms] (mean)
Time per request: 2.162 [ms] (mean, across all concurrent requests)
Transfer rate: 77.53 [Kbytes/sec] received
あ，結構速いか。まあ試してみよう。
Concurrency Level: 1
Time taken for tests: 17.791063 seconds
Complete requests: 10000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 9412
Total transferred: 1717060 bytes
HTML transferred: 480000 bytes
Requests per second: 562.08 [#/sec] (mean)
Time per request: 1.779 [ms] (mean)
Time per request: 1.779 [ms] (mean, across all concurrent requests)
Transfer rate: 94.20 [Kbytes/sec] received
うん。100req/sのスピードアップ。
続いてprepare_headers。
sub prepare_headers {
my $c = shift;
while ( my ( $header, $value ) = each %ENV ) {
next unless $header =~ /^(HTTP|CONTENT)/i;
( my $field = $header ) =~ s/^HTTPS?_//;
$c->req->headers->header( $field => $value );
}
$c->req->method( $ENV{REQUEST_METHOD} || 'GET' );
}
prepare_pathと同じく，FCGI_PARAMS→%ENV→$c->req->headersとコピーの無駄があるのと，正規表現のボトルネック。substrとeqで良いんじゃないだろうか。中で約1秒の消費。残り1秒は$c->req->headers->headerと辿るとこかな・・・とりあえずヘッダは大文字前提，CONTならCONTENTと仮定した決め打ちでやってみよう。
sub prepare_headers {
my $c = shift;
while ( my ( $header, $value ) = each %ENV ) {
my $h4 = substr($header,0,4);
if( $h4 eq 'HTTP' ){
if( substr($header,4,1) eq 'S' ){
$c->req->headers->header(substr($header,6) => $value);
}else{
$c->req->headers->header(substr($header,5) => $value);
}
}elsif( $h4 eq 'CONT' ){
$c->req->headers->header($header => $value);
}
}
$c->req->method( $ENV{REQUEST_METHOD} || 'GET' );
}
Concurrency Level: 1
Time taken for tests: 17.787568 seconds
Complete requests: 10000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 9412
Total transferred: 1717060 bytes
HTML transferred: 480000 bytes
Requests per second: 562.19 [#/sec] (mean)
Time per request: 1.779 [ms] (mean)
Time per request: 1.779 [ms] (mean, across all concurrent requests)
Transfer rate: 94.22 [Kbytes/sec] received
うーん。変わらん。ずるしまくってみよう。
sub prepare_headers {
my $c = shift;
my $hdrs = $c->req->headers;
while ( my ( $header, $value ) = each %ENV ) {
my $h = substr($header,0,1);
if( $h eq 'H' ){
if( substr($header,4,1) eq 'S' ){
$hdrs->{substr($header,6)} = $value;
}else{
$hdrs->{substr($header,5)} = $value;
}
}elsif( $h eq 'C' ){
$hdrs->{$header} = $value;
}
}
$c->req->method( $ENV{REQUEST_METHOD} || 'GET' );
}
ここまでやって
Concurrency Level: 1
Time taken for tests: 16.736236 seconds
Complete requests: 10000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 9412
Total transferred: 1717060 bytes
HTML transferred: 480000 bytes
Requests per second: 597.51 [#/sec] (mean)
Time per request: 1.674 [ms] (mean)
Time per request: 1.674 [ms] (mean, across all concurrent requests)
Transfer rate: 100.14 [Kbytes/sec] received
こんなもん。まぁ，prepare_headers側でいじるより，FCGI.pmを使わないで直接準備する方が正解ではなかろうか。
続いてC::E::FastCGI::prepare_request。CGI::_reset_globals()してC::E::FastCGI::Base::prepare_requestしてC::E::CGI::prepare_requestしている。C::E::FastCGI::Baseでは$c->fastcgiに$requestを入れている。
sub prepare_request {
my ( $c, $request, @arguments ) = @_;
CGI::_reset_globals();
$c->SUPER::prepare_request($request);
$c->Catalyst::Engine::CGI::prepare_request(@arguments);
}
C::E::CGI::prepare_request。
sub prepare_request {
my ( $c, $object ) = @_;
my $cgi;
if ( defined($object) && ref($object) ) {
if ( $object->isa('Apache') ) { # MP 1.3
$cgi = CGI->new($object);
}
elsif ( $object->isa('Apache::RequestRec') ) { # MP 1.99
$cgi = CGI->new($object);
}
elsif ( $object->isa('Apache2::RequestRec') ) { # MP 2.00
$cgi = CGI->new($object);
}
elsif ( $object->isa('CGI') ) {
$cgi = $object;
}
else {
my $class = ref($object);
Catalyst::Exception->throw(
message => qq/Unknown object '$object'/
);
}
}
$c->cgi( $cgi || CGI->new );
}
むむ。どうなっているのだろう・・・C::E::FastCGI::prepare_requestで\@argumentsをdumperしてみよう。
・・・空だった。つまり最後の$c->cgi(CGI->new)されているだけ。しかもそれが重い。
ってか，Engineの実装によるんだったらEngine側で入れておけよな，って感じ。えーい，どうせCatalyst::*では使っていないから$c->cgiを外しちまえ。そうすりゃ_reset_globalsもしなくていいじゃん。
Concurrency Level: 1
Time taken for tests: 9.104013 seconds
Complete requests: 10000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 9412
Total transferred: 1227060 bytes
HTML transferred: 0 bytes
Requests per second: 1098.42 [#/sec] (mean)
Time per request: 0.910 [ms] (mean)
Time per request: 0.910 [ms] (mean, across all concurrent requests)
Transfer rate: 131.59 [Kbytes/sec] received
ほら。倍速くなった。・・・あれ？ 速すぎだろ？何か別の（メモリ管理とか）要素が働いたのかな。
さて，cgiを外して問題あるかと見れば・・・ありゃ。
sub prepare_body {
my $c = shift;
# XXX this is undocumented in CGI.pm. If Content-Type is not
# application/x-www-form-urlencoded or multipart/form-data
# CGI.pm will read STDIN into a param, POSTDATA.
$c->request->body( $c->cgi->param('POSTDATA') );
}
sub prepare_parameters {
my $c = shift;
my ( @params );
if ( $c->request->method eq 'POST' ) {
for my $param ( $c->cgi->url_param ) {
for my $value ( $c->cgi->url_param($param) ) {
push ( @params, $param, $value );
}
}
}
for my $param ( $c->cgi->param ) {
for my $value ( $c->cgi->param($param) ) {
push ( @params, $param, $value );
}
}
$c->request->param(@params);
}
C::E::CGIのこんなところに。C::E::FastCGIはこっちを呼んでるなぁ。しかし，GETリクエストの時には不要だろう。
--2005/11/08 04:34追記 間違い。その後prepare_parameters呼んでいてエラー出していることが発覚。
とりあえず手抜きで，prepare_parameters, prepare_bodyで何もしないようにする（つまりPOSTを受け取ったりできな）と
Concurrency Level: 1
Time taken for tests: 13.821929 seconds
Complete requests: 10000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 9412
Total transferred: 1717060 bytes
HTML transferred: 480000 bytes
Requests per second: 723.49 [#/sec] (mean)
Time per request: 1.382 [ms] (mean)
Time per request: 1.382 [ms] (mean, across all concurrent requests)
Transfer rate: 121.26 [Kbytes/sec] received
こんなもんだった。723.49 req/sと高速化はしているけど，倍は嘘でした。
これはprepare_parameters, prepare_bodyをさぼっているのでC::E::FastCGIで（CGI.pmを使わずに）用意してやる必要がある。
Trackback URL for this post:
http://old.typemiss.net/trackback/3
続いてCatalyst::Dispatcher::dispatchのオーバーヘッドについて。
dispatchではCatalystの面白さでもあり，複雑さにもつながるURL⇔クラス・メソッドのマッピングを処理しているので，それなりのオー
