> > Web servers itself starts spinning on 100% CPU once this happens. > > > > Log has this entry: > > > > [Thu Jan 06 18:52:18 2005] [error] APR::Socket::recv: > > (11) Resource temporarily unavailable at > > /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_block.pm > > line 41 > > I suppose that's t/protocol/echo_block.t (and not t/protocol/echo_filter), > right?
No - the test output at this stage looks like this: t/protocol/echo_block...................# Failed test 3 in t/protocol/echo_block.t at line 22 fail #2 FAILED test 3 Failed 1/3 tests, 66.67% okay t/protocol/echo_filter.................. (there no no newline on that last line.) > Wow, irix. It's a first time I see anybody trying modperl on it. Really? I've had it running v1.25 on Apache1.3.x for years. > Can you identify where the process spins? e.g. try the technique explained > in: 21.7.4.1. Using the Perl trace > http://modperlbook.org/html/ch21_07.html or some tracing tool. > > any difference if you put an eval {} block around that line? Well, I doubt it will make much difference given that it was reported for a different script. It all seems to be pointing to issues around (non-)blocking sockets? The echo_block and echo_filter tests both refer to fixes on Apache2.0.52 for Open/NetBSD here. Anyway - here's what you requested (after adding t/conf/modperl_extra.pl): I removed all of the dirs (expect lib) from t which preceded protocol then ran "make test". This is the resulting log (I've wrapped some bits, but the longer lines may still wrap...). ===================================================================================== [Mon Jan 10 17:52:05 2005] [info] Init: Initializing OpenSSL library [Mon Jan 10 17:52:05 2005] [info] Init: Seeding PRNG with 0 bytes of entropy [Mon Jan 10 17:52:05 2005] [info] Init: Generating temporary RSA private keys (512/1024 bits) [Mon Jan 10 17:52:06 2005] [info] Init: Generating temporary DH parameters (512/1024 bits) [Mon Jan 10 17:52:06 2005] [warn] Init: Session Cache is not configured [hint: SSLSessionCache] [Mon Jan 10 17:52:06 2005] [info] Init: Initializing (virtual) servers for SSL [Mon Jan 10 17:52:06 2005] [info] Server: Apache/2.0.52, Interface: mod_ssl/2.0.52, Library: OpenSSL/0.9.7d [Mon Jan 10 17:52:06 2005] [info] Init: Initializing OpenSSL library [Mon Jan 10 17:52:06 2005] [info] Init: Seeding PRNG with 0 bytes of entropy [Mon Jan 10 17:52:06 2005] [info] Init: Generating temporary RSA private keys (512/1024 bits) [Mon Jan 10 17:52:07 2005] [info] Init: Generating temporary DH parameters (512/1024 bits) [Mon Jan 10 17:52:07 2005] [info] Init: Initializing (virtual) servers for SSL [Mon Jan 10 17:52:07 2005] [info] Server: Apache/2.0.52, Interface: mod_ssl/2.0.52, Library: OpenSSL/0.9.7d [Mon Jan 10 17:52:07 2005] [notice] Digest: generating secret for digest authentication ... [Mon Jan 10 17:52:07 2005] [notice] Digest: done [Mon Jan 10 17:52:07 2005] [notice] Apache/2.0.52 (Unix) DAV/2 mod_ssl/2.0.52 OpenSSL/0.9.7d mod_perl/1.999.20 Perl/v5.8.5 configured -- resuming normal operations [Mon Jan 10 17:52:07 2005] [info] Server built: Jan 6 2005 14:00:24 [Mon Jan 10 17:52:07 2005] [debug] prefork.c(955): AcceptMutex: sysvsem (default: sysvsem) [Mon Jan 10 17:52:16 2005] [error] recv() has returned untainted data: at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_block.pm line 38.\n [Mon Jan 10 17:52:41 2005] [error] Caught SIGUSR2! at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/conf/modperl_extra.pl line 6 Book::Startup::__ANON__('USR2') called at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_filter.pm line 22 eval {...} called at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_filter.pm line 22 TestProtocol::echo_filter::uc_filter('Apache::Filter=SCALAR(0x102b00d0)', 'APR::Brigade=SCALAR(0x102b0100)') called at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_filter.pm line 50 eval {...} called at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_filter.pm line 50 TestProtocol::echo_filter::handler('Apache::Connection=SCALAR(0x101ab0c8)') called at -e line 0 eval {...} called at -e line 0 [Mon Jan 10 17:52:41 2005] [error] Apache::Filter::fflush: (500) Block not fully transferred at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/echo_filter.pm line 50 [Mon Jan 10 17:52:50 2005] [error] APR::Socket::recv: (11) Resource temporarily unavailable at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/pseudo_http.pm line 118 [Mon Jan 10 17:52:50 2005] [error] APR::Socket::recv: (11) Resource temporarily unavailable at /local/GML/Apache2/mod_perl-2.0.0-RC3/t/protocol/TestProtocol/pseudo_http.pm line 118 *** The following error entry is expected and harmless *** [Mon Jan 10 17:52:50 2005] [info] removed PID file /local/GML/Apache2/mod_perl-2.0.0-RC3/t/logs/httpd.pid (pid=328342) [Mon Jan 10 17:52:50 2005] [notice] caught SIGTERM, shutting down