You are viewing a plain text version of this content. The canonical link for it is here.
Posted to modperl@perl.apache.org by Andrew Merton <am...@gmail.com> on 2011/12/14 22:44:05 UTC
Problem with long http request generation time - process restarting
Hi --
I am getting the following message recurring in my log:
Parent: child process exited with status 255 -- Restarting.
followed by the process restart sequence.
I have tracked it down to a call to $r->content which doesn't seem to
return properly.
It would appear that
1. The POST request has Encoding-type: chunked (message total length is
~5kb);
2. The client sends the HTTP headers, then pauses 3-4 seconds while it
generates the body of the message (confirmed with WireShark);
3. So when I call $r-content, when it succeeds I see a 3-4 second pause
before it completes;
4. If another request arrives during the call to $r->content, the process
aborts and restarts - I assume it is interfering with the read() call in
$r->content.
Since the pause is so long, it is very likely to be interrupted even though
I only have 5 clients currently :(
Given the the chunked implemenation in mod_perl 2.0 is apparently
incomplete, have I struck one area where this affects the result?
Can anyone make suggestions as to how I can work around this problem? I
wondered about maybe moving my handler to the log phase (currently it's a
Response handler), by which time I assume the entire message must be
available, but it seems like a major kludge and presumably would lead to
other issues anyway.
Or is there some multi-threading thing I should have done - currently I
have not really done anything specific...
I am using Apache2.2 on Win7 (no flames please :)), with ActiveState Perl
"(v5.12.2) built for MSWin32-x86-multi-thread".
Andrew
Re: Problem with long http request generation time - process restarting
Posted by Issac Goldstand <ma...@beamartyr.net>.
That stinks of a segfault. The admission to using Windows at the end
makes me suspect it even more, as Windows has an unfortunate habit, due
to the MPM implementation, of a thread segfault taking the whole server
down with it, causing a several second delay while it cleans up the old
process and replaces it with a new one (with mod_perl doing all its init
stuff again)
I used to hate having to deal with that :)
Having said that, I don't think it's a chunking issue, as httpd core
handles that, not mod_perl. Can you supply more info? Not sure what,
but my gut says there's a missing piece here.
Issac
On 14/12/2011 23:44, Andrew Merton wrote:
> Hi --
>
> I am getting the following message recurring in my log:
>
> Parent: child process exited with status 255 -- Restarting.
>
> followed by the process restart sequence.
>
> I have tracked it down to a call to $r->content which doesn't seem to
> return properly.
>
> It would appear that
>
> 1. The POST request has Encoding-type: chunked (message total length
> is ~5kb);
>
> 2. The client sends the HTTP headers, then pauses 3-4 seconds while it
> generates the body of the message (confirmed with WireShark);
>
> 3. So when I call $r-content, when it succeeds I see a 3-4 second
> pause before it completes;
>
> 4. If another request arrives during the call to $r->content, the
> process aborts and restarts - I assume it is interfering with the
> read() call in $r->content.
>
> Since the pause is so long, it is very likely to be interrupted even
> though I only have 5 clients currently :(
>
> Given the the chunked implemenation in mod_perl 2.0 is apparently
> incomplete, have I struck one area where this affects the result?
>
> Can anyone make suggestions as to how I can work around this problem?
> I wondered about maybe moving my handler to the log phase (currently
> it's a Response handler), by which time I assume the entire message
> must be available, but it seems like a major kludge and presumably
> would lead to other issues anyway.
>
> Or is there some multi-threading thing I should have done - currently
> I have not really done anything specific...
>
> I am using Apache2.2 on Win7 (no flames please :)), with ActiveState
> Perl "(v5.12.2) built for MSWin32-x86-multi-thread".
>
> Andrew
>
>
Re: Problem with long http request generation time - process restarting
Posted by Andrew Merton <am...@gmail.com>.
> I was getting exception code 0xC00000FD (Stack overflow) in Classify.dll
(Params::Classify?)
Well. This goes to show that desperation is the mother of invention :)
I went so far as to look at the code for Params::Classify, and noticed that
there is a pure Perl version if the XS load fails, so I renamed the
Perl/site/lib/auto/Params/Classify directory to ClassifyXXX and restarted
the server.
Now it hasn't failed at all, even when I use my previously
guaranteed-to-fail test case (triggering 5 simultaneous connections).
So according to this "solution" there must be non-thread-safe code in
Classify.dll which is sometimes turning all infinitely-recursive on me...
Hope I'm not suffering from premature solution declaration (i.e. it'll
crash again as soon as I post this), but it looks like for me it is fixed,
although there may be something that needs to be looked at in the .dll?
Cheers,
Andrew Merton
Re: Problem with long http request generation time - process restarting
Posted by Perrin Harkins <pe...@elem.com>.
On Fri, Dec 16, 2011 at 1:20 PM, Randolf Richardson <ra...@modperl.pl> wrote:
> I've been using DBI in threaded Perl environments for many years,
> and it works just fine for me. I used Oracle 8i in the past on
> NetWare (with ModPerl 1 in a threaded environment because the NetWare
> OS is a thread-based architecture and Apache HTTPd and ModPerl were
> both compiled accordingly), but I switched to PostgreSQL many years
> ago so I'm not up-to-date with the more recent Oracle DBD issues...
I can't really suggest anything for the main question on this thread,
but I wanted to mention that mod_perl 1 only supported a single
thread, i.e. running on Windows means running one thread that all
requests had to line up for. By contrast, mod_perl 2 runs multiple
threads so it may bring threading issues in CPAN libraries to light
where they didn't show up in mod_perl 1.
- Perrin
Re: Problem with long http request generation time - process restarting
Posted by Andrew Merton <am...@gmail.com>.
Thanks Hans - that fits with what I'm seeing (including no connection with
Oracle).
I had previously discovered that including DateTime in a handler made it
crash at start-up (actually using DateTime wasn't actually necessary) , but
didn't make the connection between that and Params::Classify partly because
this crash only occurs under certain circumstances. When I later
reintroduced DateTime it didn't seem to crash any more, so I never thought
it would be causing this one. Oh well, live and learn...
Thanks for the response...
Andrew
On Sun, Jan 29, 2012 at 11:52 AM, Hans Scharler <hs...@gmail.com> wrote:
> The Classify.dll issue gave me much trouble to figure out. In my instance,
> the issue has nothing to do with the database or Oracle.
>
> Here's what I found:
>
> Updating DateTime to version 0.72 includes Params::Classify as a
> dependency.
>
> http://search.cpan.org/~drolsky/DateTime-0.72/
>
> Also, DateTime-TimeZone version 1.40 also includes Params::Classify.
>
> When Classify.dll gets onto a Windows installation of mod_perl, Apache
> will crash/restart often. Regular Perl is fine.
>
> The latest DateTime and DateTime-TimeZone modules that work with mod_perl
> are DateTime 0.70 and DateTime-TimeZone 1.34.
>
> I spend a few days troubleshooting Classify.dll and the only way I could
> get it to work was to remove it and use older versions of DateTime.
>
> I hope this helps you out.
>
> Cheers,
> Hans
>
>
>
> On Fri, Jan 27, 2012 at 5:44 PM, Perrin Harkins <pe...@elem.com> wrote:
>
>> Sorry, just a clumsy cell phone touch.
>>
>> - Perrin
>> On Jan 27, 2012 5:42 PM, "Perrin Harkins" <pe...@elem.com> wrote:
>>
>>> - Perrin
>>> On Jan 13, 2012 6:47 PM, "Andrew Merton (subscriptions)" <
>>> amerton.signup@gmail.com> wrote:
>>>
>>>> On 17/12/2011 7:20 a.m., Randolf Richardson wrote:
>>>>
>>>> Thanks for the responses :)
>>>>
>>>> However - I just read another thread somewhere that made me think of
>>>> looking in the Event log.
>>>>
>>>> It appears that the culprit is Oracle - there are errors
>>>> naming OraOCIEI11.dll as the "Faulting Module name".
>>>>
>>>> That's very interesting. Windows Event Viewer is a good place to
>>>> look (I keep forgetting about it as I'm used to /var/log/messages in
>>>> Unix/Linux and similar environments).
>>>>
>>>> Well. It turns out that in this case the event log was actually a red
>>>> herring. By creating another Apache instance (to avoid breaking the
>>>> "production" server :)) and stripping out all references to Oracle, DBI,
>>>> DBD etc from both httpd.conf and the Perl, I have determined that the
>>>> problem has nothing to do with Oracle.
>>>>
>>>> After doing that, I was getting exception code 0xC00000FD (Stack
>>>> overflow) in Classify.dll (Params::Classify?) so I tried setting the
>>>> ThreadStackSize to 2MB, and now I get 0xC0000005 and the module is unknown
>>>> according to the Event log.
>>>>
>>>> I think I'm going mad.
>>>>
>>>> Is there a way to make Apache/mod_perl (on Windows 7) give me a stack
>>>> dump when the child process exits? Al I get in the log is the "Parent:
>>>> child process exited ..." message, which is not very helpful. I have
>>>> downloaded the -symbols.zip files from ActiveState and installed them in
>>>> the proper directories (alongside their .dlls), but then realised that I'm
>>>> not getting the equivalent of a core dump file to analyze. The Event log
>>>> points to a directory containing only a text file (*.wer) which doesn't
>>>> have anything useful AFAICS...
>>>>
>>>> Andrew
>>>>
>>>
>
Re: Problem with long http request generation time - process restarting
Posted by Hans Scharler <hs...@gmail.com>.
The Classify.dll issue gave me much trouble to figure out. In my instance,
the issue has nothing to do with the database or Oracle.
Here's what I found:
Updating DateTime to version 0.72 includes Params::Classify as a dependency.
http://search.cpan.org/~drolsky/DateTime-0.72/
Also, DateTime-TimeZone version 1.40 also includes Params::Classify.
When Classify.dll gets onto a Windows installation of mod_perl, Apache will
crash/restart often. Regular Perl is fine.
The latest DateTime and DateTime-TimeZone modules that work with mod_perl
are DateTime 0.70 and DateTime-TimeZone 1.34.
I spend a few days troubleshooting Classify.dll and the only way I could
get it to work was to remove it and use older versions of DateTime.
I hope this helps you out.
Cheers,
Hans
On Fri, Jan 27, 2012 at 5:44 PM, Perrin Harkins <pe...@elem.com> wrote:
> Sorry, just a clumsy cell phone touch.
>
> - Perrin
> On Jan 27, 2012 5:42 PM, "Perrin Harkins" <pe...@elem.com> wrote:
>
>> - Perrin
>> On Jan 13, 2012 6:47 PM, "Andrew Merton (subscriptions)" <
>> amerton.signup@gmail.com> wrote:
>>
>>> On 17/12/2011 7:20 a.m., Randolf Richardson wrote:
>>>
>>> Thanks for the responses :)
>>>
>>> However - I just read another thread somewhere that made me think of
>>> looking in the Event log.
>>>
>>> It appears that the culprit is Oracle - there are errors
>>> naming OraOCIEI11.dll as the "Faulting Module name".
>>>
>>> That's very interesting. Windows Event Viewer is a good place to
>>> look (I keep forgetting about it as I'm used to /var/log/messages in
>>> Unix/Linux and similar environments).
>>>
>>> Well. It turns out that in this case the event log was actually a red
>>> herring. By creating another Apache instance (to avoid breaking the
>>> "production" server :)) and stripping out all references to Oracle, DBI,
>>> DBD etc from both httpd.conf and the Perl, I have determined that the
>>> problem has nothing to do with Oracle.
>>>
>>> After doing that, I was getting exception code 0xC00000FD (Stack
>>> overflow) in Classify.dll (Params::Classify?) so I tried setting the
>>> ThreadStackSize to 2MB, and now I get 0xC0000005 and the module is unknown
>>> according to the Event log.
>>>
>>> I think I'm going mad.
>>>
>>> Is there a way to make Apache/mod_perl (on Windows 7) give me a stack
>>> dump when the child process exits? Al I get in the log is the "Parent:
>>> child process exited ..." message, which is not very helpful. I have
>>> downloaded the -symbols.zip files from ActiveState and installed them in
>>> the proper directories (alongside their .dlls), but then realised that I'm
>>> not getting the equivalent of a core dump file to analyze. The Event log
>>> points to a directory containing only a text file (*.wer) which doesn't
>>> have anything useful AFAICS...
>>>
>>> Andrew
>>>
>>
Re: Problem with long http request generation time - process restarting
Posted by Perrin Harkins <pe...@elem.com>.
Sorry, just a clumsy cell phone touch.
- Perrin
On Jan 27, 2012 5:42 PM, "Perrin Harkins" <pe...@elem.com> wrote:
> - Perrin
> On Jan 13, 2012 6:47 PM, "Andrew Merton (subscriptions)" <
> amerton.signup@gmail.com> wrote:
>
>> On 17/12/2011 7:20 a.m., Randolf Richardson wrote:
>>
>> Thanks for the responses :)
>>
>> However - I just read another thread somewhere that made me think of
>> looking in the Event log.
>>
>> It appears that the culprit is Oracle - there are errors
>> naming OraOCIEI11.dll as the "Faulting Module name".
>>
>>
>> That's very interesting. Windows Event Viewer is a good place to
>> look (I keep forgetting about it as I'm used to /var/log/messages in
>> Unix/Linux and similar environments).
>>
>> Well. It turns out that in this case the event log was actually a red
>> herring. By creating another Apache instance (to avoid breaking the
>> "production" server :)) and stripping out all references to Oracle, DBI,
>> DBD etc from both httpd.conf and the Perl, I have determined that the
>> problem has nothing to do with Oracle.
>>
>> After doing that, I was getting exception code 0xC00000FD (Stack
>> overflow) in Classify.dll (Params::Classify?) so I tried setting the
>> ThreadStackSize to 2MB, and now I get 0xC0000005 and the module is unknown
>> according to the Event log.
>>
>> I think I'm going mad.
>>
>> Is there a way to make Apache/mod_perl (on Windows 7) give me a stack
>> dump when the child process exits? Al I get in the log is the "Parent:
>> child process exited ..." message, which is not very helpful. I have
>> downloaded the -symbols.zip files from ActiveState and installed them in
>> the proper directories (alongside their .dlls), but then realised that I'm
>> not getting the equivalent of a core dump file to analyze. The Event log
>> points to a directory containing only a text file (*.wer) which doesn't
>> have anything useful AFAICS...
>>
>> Andrew
>>
>
Re: Problem with long http request generation time - process restarting
Posted by Perrin Harkins <pe...@elem.com>.
- Perrin
On Jan 13, 2012 6:47 PM, "Andrew Merton (subscriptions)" <
amerton.signup@gmail.com> wrote:
> On 17/12/2011 7:20 a.m., Randolf Richardson wrote:
>
> Thanks for the responses :)
>
> However - I just read another thread somewhere that made me think of
> looking in the Event log.
>
> It appears that the culprit is Oracle - there are errors
> naming OraOCIEI11.dll as the "Faulting Module name".
>
>
> That's very interesting. Windows Event Viewer is a good place to
> look (I keep forgetting about it as I'm used to /var/log/messages in
> Unix/Linux and similar environments).
>
> Well. It turns out that in this case the event log was actually a red
> herring. By creating another Apache instance (to avoid breaking the
> "production" server :)) and stripping out all references to Oracle, DBI,
> DBD etc from both httpd.conf and the Perl, I have determined that the
> problem has nothing to do with Oracle.
>
> After doing that, I was getting exception code 0xC00000FD (Stack overflow)
> in Classify.dll (Params::Classify?) so I tried setting the ThreadStackSize
> to 2MB, and now I get 0xC0000005 and the module is unknown according to the
> Event log.
>
> I think I'm going mad.
>
> Is there a way to make Apache/mod_perl (on Windows 7) give me a stack dump
> when the child process exits? Al I get in the log is the "Parent: child
> process exited ..." message, which is not very helpful. I have downloaded
> the -symbols.zip files from ActiveState and installed them in the proper
> directories (alongside their .dlls), but then realised that I'm not getting
> the equivalent of a core dump file to analyze. The Event log points to a
> directory containing only a text file (*.wer) which doesn't have anything
> useful AFAICS...
>
> Andrew
>
Re: Problem with long http request generation time - process restarting
Posted by "Andrew Merton (subscriptions)" <am...@gmail.com>.
On 17/12/2011 7:20 a.m., Randolf Richardson wrote:
>> Thanks for the responses :)
>>
>> However - I just read another thread somewhere that made me think of
>> looking in the Event log.
>>
>> It appears that the culprit is Oracle - there are errors
>> naming OraOCIEI11.dll as the "Faulting Module name".
> That's very interesting. Windows Event Viewer is a good place to
> look (I keep forgetting about it as I'm used to /var/log/messages in
> Unix/Linux and similar environments).
Well. It turns out that in this case the event log was actually a red
herring. By creating another Apache instance (to avoid breaking the
"production" server :)) and stripping out all references to Oracle, DBI,
DBD etc from both httpd.conf and the Perl, I have determined that the
problem has nothing to do with Oracle.
After doing that, I was getting exception code 0xC00000FD (Stack
overflow) in Classify.dll (Params::Classify?) so I tried setting the
ThreadStackSize to 2MB, and now I get 0xC0000005 and the module is
unknown according to the Event log.
I think I'm going mad.
Is there a way to make Apache/mod_perl (on Windows 7) give me a stack
dump when the child process exits? Al I get in the log is the "Parent:
child process exited ..." message, which is not very helpful. I have
downloaded the -symbols.zip files from ActiveState and installed them in
the proper directories (alongside their .dlls), but then realised that
I'm not getting the equivalent of a core dump file to analyze. The
Event log points to a directory containing only a text file (*.wer)
which doesn't have anything useful AFAICS...
Andrew
Re: Problem with long http request generation time - process restarting
Posted by Randolf Richardson <ra...@modperl.pl>.
> Thanks for the responses :)
>
> However - I just read another thread somewhere that made me think of
> looking in the Event log.
>
> It appears that the culprit is Oracle - there are errors
> naming OraOCIEI11.dll as the "Faulting Module name".
That's very interesting. Windows Event Viewer is a good place to
look (I keep forgetting about it as I'm used to /var/log/messages in
Unix/Linux and similar environments).
> Apparently one is not supposed to use DBI in a threaded Perl environment.
I've been using DBI in threaded Perl environments for many years,
and it works just fine for me. I used Oracle 8i in the past on
NetWare (with ModPerl 1 in a threaded environment because the NetWare
OS is a thread-based architecture and Apache HTTPd and ModPerl were
both compiled accordingly), but I switched to PostgreSQL many years
ago so I'm not up-to-date with the more recent Oracle DBD issues...
For those experiencing problems with DBI in threaded environments,
my guess is that it's more likely due to problems with the way the
environment was set up (possibly even related to compilation?) or,
more likely, that a developer doesn't really understand threads
(unfortunately this seems to be fairly common).
Also, with DBI there are some wonderful features such as
"connect_cached" and "prepare_cached" that are a huge benefit in
persistent environments such as ModPerl 2 that also seem to work
without issues in threaded environments. These features appear to be
well-suited for use in persistent multi-threaded environments, but
it's important to note that one can just use the regular "connect"
and "prepare" functions too (and that they'll work as expected).
One way people seem to mess up with programming in a threaded
environment is that they rely on global variables inappropriately,
and then have multiple threads using the same variable without
ensuring atomic operations (e.g., using the same database or
statement handles simultaneously across separate threads does lead to
problems). There are other issues too, but I suspect this type of
mistake is more common.
> Someone in a PHP system created the Oracle environment and connection using
> a THREADED_MUTEXED option which worked for them.
>
> Investigation continues...
Thanks, and please keep us updated (at modperl@perl.apache.org
instead of via a private reply). If Oracle's DBD is doing something
unexpected, and especially if you do manage to find a solution, that
could be useful to people who use Oracle.
Randolf Richardson - randolf@inter-corporate.com
Inter-Corporate Computer & Network Services, Inc.
Beautiful British Columbia, Canada
http://www.inter-corporate.com/
Re: Problem with long http request generation time - process restarting
Posted by Randolf Richardson <ra...@modperl.pl>.
> Hi --
>
> I am getting the following message recurring in my log:
>
> Parent: child process exited with status 255 -- Restarting.
>
> followed by the process restart sequence.
>
> I have tracked it down to a call to $r->content which doesn't seem to
> return properly.
>
> It would appear that
>
> 1. The POST request has Encoding-type: chunked (message total length is
> ~5kb);
>
> 2. The client sends the HTTP headers, then pauses 3-4 seconds while it
> generates the body of the message (confirmed with WireShark);
>
> 3. So when I call $r-content, when it succeeds I see a 3-4 second pause
> before it completes;
>
> 4. If another request arrives during the call to $r->content, the process
> aborts and restarts - I assume it is interfering with the read() call in
> $r->content.
>
> Since the pause is so long, it is very likely to be interrupted even though
> I only have 5 clients currently :(
>
> Given the the chunked implemenation in mod_perl 2.0 is apparently
> incomplete, have I struck one area where this affects the result?
>
> Can anyone make suggestions as to how I can work around this problem? I
> wondered about maybe moving my handler to the log phase (currently it's a
> Response handler), by which time I assume the entire message must be
> available, but it seems like a major kludge and presumably would lead to
> other issues anyway.
I find it curious that you observe this behaviour within just under
5 seconds. The KeepAliveTimeout setting, which defaults to 5
seconds, might be of interest to you -- I would certainly try setting
it to 20 seconds temporarily in the hopes of at least ruling it out
as a possible cause:
http://httpd.apache.org/docs/2.2/mod/core.html#keepalivetimeout
> Or is there some multi-threading thing I should have done - currently I
> have not really done anything specific...
>
> I am using Apache2.2 on Win7 (no flames please :)), with ActiveState Perl
> "(v5.12.2) built for MSWin32-x86-multi-thread".
I have noticed that socket I/O under Windows behaves strangely at
times. I eventually moved off to running Apache HTTPd 2.2 with
ModPerl 2 on NetBSD under VirtualBox, which basically seemed to cure
all the unpredictable problems I encountered (not just with ModPerl 2
but with other technologies, such as ImageMagick's PerlMagick
libraries, even without ModPerl 2 in the mix, issues with compiling
code downloaded from CPAN, etc.) as well as yielded better
performance with faster response times.
I found ActiveState Perl to be a great implementation, but one of
the problems I had was that it sometimes didn't have a pre-compiled
module that I needed, and moving to Unix was a lot easier.
I mention those points in the hopes that it will be helpful to you
(switching to Unix was helpful to a few of my friends who love PHP,
and one who does a lot of xBase {Clipper} programming), and I hope
you don't view this as a flame.
Randolf Richardson - randolf@inter-corporate.com
Inter-Corporate Computer & Network Services, Inc.
Beautiful British Columbia, Canada
http://www.inter-corporate.com/