2007-02-28 15:12:10

Catalyst::Engineでバグ?

[Catalyst]

CGIにて使用。
<form action="" method="post">
<textarea name="comment" rows="4" cols="40"></textarea>
</form>

以下のようなエラーが出てしまう。
[error] Caught exception in engine "Wrong Content-Length value: 4387 at /usr/lib/perl5/site_perl/5.8.8/Catalyst.pm line 1584"

メーリングリストにも同様の事柄が載っているが、行番号が違う。バージョンが違うのだろうか?
入力データ量を減らすと問題が発生しない。
Catalystのバージョンは5.7006。
時間が有れば原因究明したいところ。


2007.05.07追記
5.7007でも
[error] Caught exception in engine "Wrong Content-Length value: 5908 at /usr/lib/perl5/site_perl/5.8.8/Catalyst.pm line 1611"
と出た。
Catalyst.pm 1611行目 $c->engine->prepare_body( $c, @_ ); としている部分。
つまり
Catalyst::Engine 313行目からのprepare_bodyメソッドで止まっている。

sub prepare_body {
    my ( $self, $c ) = @_; 
    my $length = $c->request->header('Content-Length') || 0;
    $self->read_length( $length );
    if ( $length > 0 ) {
        (略)
        while ( my $buffer = $self->read($c) ) {
            $c->prepare_body_chunk($buffer);
        }
        # paranoia against wrong Content-Length header
        my $remaining = $length - $self->read_position;
        if ( $remaining > 0 ) {
            $self->finalize_read($c);
            Catalyst::Exception->throw(
                "Wrong Content-Length value: $length" );
        }
    }
    (略)
}

データ量が多くなると、$length と $self->read_position の数が合わなくなる。
ログに書き出すと、$length=7687 $self->read_position=4096。
4096とはキリが良過ぎる・・・。
Catalystのテストサーバでは発生しないのに、CGI環境で発生する・・・。

$self->read_position を追う。
Catalyst::Engine 内で最初に0がセットされ、read メソッドで読み込んだサイズ分加算される。

Catalyst::Engine に以下の説明がある
=head2 $self->read_chunk($c, $buffer, $length)
Each engine inplements read_chunk as its preferred way of reading a chunk
of data.
=cut

Catalyst::Engine::CGI に
sub read_chunk { shift; shift; *STDIN->sysread(@_); }
がある。

Catalyst::Engineの readメソッド を以下のように書き換えてdump

sub read {
    my ( $self, $c, $maxlength ) = @_;
    unless ( $self->{_prepared_read} ) {
        $self->prepare_read($c);
        $self->{_prepared_read} = 1;
    }
    my $remaining = $self->read_length - $self->read_position;
    $maxlength ||= $CHUNKSIZE;
    # Are we done reading?
    if ( $remaining <= 0 ) {
        $self->finalize_read($c);
        return;
    }
    my $readlen = ( $remaining > $maxlength ) ? $maxlength : $remaining;
    my $rc = $self->read_chunk( $c, my $buffer, $readlen );
    if ( defined $rc ) {
        $self->read_position( $self->read_position + $rc );
$c->log->dumper( $maxlength );
$c->log->dumper( $remaining );
$c->log->dumper( $self->read_position );
$c->log->dumper( $rc );
$c->log->dumper( $buffer );
        return $buffer;
    }
    else {
        Catalyst::Exception->throw(
            message => "Unknown error reading input: $!" );
    }
}

readメソッドは、Catalyst::Engine の prepare_body メソッドでwhileで廻されている。
今回は二回呼ばれた。
$maxlengthは ①65536 ②65536
$remainingは ①6809 ②2713
$self->read_positionは ①4096 ②4096
$rcは ①4096 ②0
$bufferは ①4096byteURLエンコード済文字列 ②0byte

readが間に合わない??
同一環境の別アプリケーションでは再現しない。

package Test::Controller::Root;
use strict;
use warnings;
use base 'Catalyst::Controller';
__PACKAGE__->config->{namespace} = '';
sub default : Private {
    my ( $self, $c ) = @_;
    $c->stash->{str} = $c->req->param('str') || '';
    $c->stash->{template} = 'temp.tt2';
}
sub end : ActionClass('RenderView') {}
1;

$maxlengthは ①65536 ②65536
$remainingは ①6809 ②2713
$self->read_positionは ①4096 ②6809
$rcは ①4096 ②2713

普通だ・・・デバッグ断念。

悩んだ末、フォームでenctype="multipart/form-data"を指定した。
<form method="post" action="" enctype="multipart/form-data">
エラーは発生しなくなった。嫌な解決。