You are viewing a plain text version of this content. The canonical link for it is here.
Posted to modperl@perl.apache.org by Bjoern Hoehrmann <de...@gmx.net> on 2005/08/13 20:47:02 UTC
[mp2] strange behavior of script under heavy load
Hi,
I'm using mod_perl 2.0.1 on Apache/2.0.54 on Windows Server 2003
using standard configuration. I am trying to run the code for the
http://dev.w3.org/cvsweb/validator/httpd/cgi-bin/check W3C Markup
Validator, changed to use SGML::Parser::OpenSP to interface with the
OpenSP library instead of using IPC::Open3 and a command line tool.
Output is generated using HTML::Template 2.7, there is a line "print
$T->output;" that does this.
Things work fine under minimal load, with the print line above it
would generate proper output and if the line is commented out no
output is generated. Using Apache `ab` with e.g. `ab -c 60 -n 600`
(60 concurrent requests, 600 requests total) the script starts
failing (that is, it generates unexpected output) after some number
of requests.
Unexpected output is for example that the script generates output
even though the line above is commented out and so no output should
be generated. Such output could be
http://lists.w3.org/Archives/Public/www-archive/2005Aug/att-0006/truncated-result.txt
This is what HTML::Template would generate for the request if no
parameters are set. Parameters should be set though and this is
the output even if the corresponding print() is commented out, so
this output is a bit strange and unexpected. Again, this happens
only under heavy load, it does not happen for e.g. `ab -c 1 -n 600`
or at least rarely.
In the Apache logs it goes like this (with the print commented out)
[13/Aug/2005:20:22:48 +0200] "GET /check... HTTP/1.0" 200 -
[13/Aug/2005:20:22:49 +0200] "GET /check... HTTP/1.0" 200 -
[... the same with different timestamps about 50 times ...]
[13/Aug/2005:20:22:54 +0200] "GET /check... HTTP/1.0" 200 -
[13/Aug/2005:20:22:54 +0200] "GET /check... HTTP/1.0" 200 -
[13/Aug/2005:20:22:54 +0200] "GET /check... HTTP/1.0" 200 2697
[13/Aug/2005:20:22:54 +0200] "GET /check... HTTP/1.0" 200 -
[13/Aug/2005:20:22:54 +0200] "GET /check... HTTP/1.0" 200 2697
[13/Aug/2005:20:22:54 +0200] "GET /check... HTTP/1.0" 200 -
[13/Aug/2005:20:22:57 +0200] "GET /check... HTTP/1.0" 200 2697
[13/Aug/2005:20:22:57 +0200] "GET /check... HTTP/1.0" 200 2697
(the 2697 bytes results are the truncated-result.txt above).
The test input I'm using should yield in 102 reported errors.
Under normal load, only 94 errors are reported (the last 8 errors
are missing), under heavy load, sometimes, 102 erors are reported.
For a different test case using the same script the script will
die after some number of concurrent requests because the script
attempts to call a method on an undefined variable. Under normal
load the variable would be defined and things work as expected.
I'm not sure where or how to look for what might be causing this,
any suggestions?
TIA,
--
Björn Höhrmann · mailto:bjoern@hoehrmann.de · http://bjoern.hoehrmann.de
Weinh. Str. 22 · Telefon: +49(0)621/4309674 · http://www.bjoernsworld.de
68309 Mannheim · PGP Pub. KeyID: 0xA4357E78 · http://www.websitedev.de/
Re: [mp2] strange behavior of script under heavy load
Posted by Tom Schindl <to...@gmx.at>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
[...]
> This was apparently caused by code like this
>
> use File::Temp qw();
> my $fh = File::Temp->new();
> File::Temp::unlink0($fh, $fh->filename);
> print "Content-Type:text/plain\n\n";
>
> On Win32 this would delay unlinking the temp files until File::Temp is
> unloaded. For some reason, File::Temp stops creating new temp files
> after about 180 files. Using it with stand-alone Perl it should allow
> for > 2000 temp files. I'm not sure why File::Temp does not croak here
> then or why this causes the strange behavior, but fixing the incorrect
> code above solves the problem.
>
If I'm not completly mistaken this thread about win32 and temp-files on
p5p may explain it.
http://www.gossamer-threads.com/lists/perl/porters/195601
[...]
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.0 (GNU/Linux)
Comment: Using GnuPG with Mandriva - http://enigmail.mozdev.org
iD8DBQFDAI3VkVPeOFLgZFIRAnw7AKCnCpdJf8uiPEHI0/nYxLDzo1tAZACeMAPj
f8jushxhaY4Z1sGgSnc20D8=
=NhId
-----END PGP SIGNATURE-----
Re: [mp2] strange behavior of script under heavy load
Posted by Bjoern Hoehrmann <de...@gmx.net>.
* Bjoern Hoehrmann wrote:
>>The test input I'm using should yield in 102 reported errors.
>>Under normal load, only 94 errors are reported (the last 8 errors
>>are missing), under heavy load, sometimes, 102 erors are reported.
>
>I could track this down to input like
>
> <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN" >
> <nobr>...</nobr>
>
>This should result in an error 'element "NOBR" undefined' from OpenSP.
>When running it under mod_perl and the winnt mpm however it gives this
>message sometimes and 'document type does not allow element "NOBR"
>here' on other times. At some point I got different errors for every
>other request though it's not that stable anymore. It's not possible
>to reproduce this when using debug builds of OpenSP...
This is the result of an unitialized variable in OpenSP. I've fixed it
in the openjade cvs. Hopefully there aren't more gotchas of this kind.
--
Björn Höhrmann · mailto:bjoern@hoehrmann.de · http://bjoern.hoehrmann.de
Weinh. Str. 22 · Telefon: +49(0)621/4309674 · http://www.bjoernsworld.de
68309 Mannheim · PGP Pub. KeyID: 0xA4357E78 · http://www.websitedev.de/
Re: [mp2] strange behavior of script under heavy load
Posted by Bjoern Hoehrmann <de...@gmx.net>.
* Bjoern Hoehrmann wrote:
>This is what HTML::Template would generate for the request if no
>parameters are set. Parameters should be set though and this is
>the output even if the corresponding print() is commented out, so
>this output is a bit strange and unexpected. Again, this happens
>only under heavy load, it does not happen for e.g. `ab -c 1 -n 600`
>or at least rarely.
This was apparently caused by code like this
use File::Temp qw();
my $fh = File::Temp->new();
File::Temp::unlink0($fh, $fh->filename);
print "Content-Type:text/plain\n\n";
On Win32 this would delay unlinking the temp files until File::Temp is
unloaded. For some reason, File::Temp stops creating new temp files
after about 180 files. Using it with stand-alone Perl it should allow
for > 2000 temp files. I'm not sure why File::Temp does not croak here
then or why this causes the strange behavior, but fixing the incorrect
code above solves the problem.
>The test input I'm using should yield in 102 reported errors.
>Under normal load, only 94 errors are reported (the last 8 errors
>are missing), under heavy load, sometimes, 102 erors are reported.
I could track this down to input like
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN" >
<nobr>...</nobr>
This should result in an error 'element "NOBR" undefined' from OpenSP.
When running it under mod_perl and the winnt mpm however it gives this
message sometimes and 'document type does not allow element "NOBR"
here' on other times. At some point I got different errors for every
other request though it's not that stable anymore. It's not possible
to reproduce this when using debug builds of OpenSP...
--
Björn Höhrmann · mailto:bjoern@hoehrmann.de · http://bjoern.hoehrmann.de
Weinh. Str. 22 · Telefon: +49(0)621/4309674 · http://www.bjoernsworld.de
68309 Mannheim · PGP Pub. KeyID: 0xA4357E78 · http://www.websitedev.de/