You are viewing a plain text version of this content. The canonical link for it is here.
Posted to modperl@perl.apache.org by Vince Veselosky <vi...@control-escape.com> on 2003/03/29 00:25:42 UTC
[Question] Handler executing twice!?!
I'm hoping someone can explain this one to me. I have a virtual host set
up like so:
<<VHOST
# This declares Apache::Webquills::InitSession::handler
PerlRequire /var/www/html/webquills/offline/wq_startup.pl
<VirtualHost *>
ServerName www.example.com
ServerAlias example.com
ServerPath /test
DocumentRoot /var/www/html/test
PerlHeaderParserHandler Apache::Webquills::InitSession
<Directory /var/www/html/test>
AllowOverride All
Options Indexes FollowSymLinks MultiViews ExecCGI
Order allow,deny
Allow from all
SetHandler perl-script
PerlHandler Apache::Registry
</Directory>
</VirtualHost>
VHOST
Now here is the thing. The PerlHeaderParserHandler executes TWICE for
every request. The second time through is apparently a different Apache
object from the first, as when I write to $r->notes, only the values
from the second execution are visible to the content handler.
Now, if I comment out the PerlHeaderParserHandler line in the conf file,
the handler never executes at all (which is expected), so it isn't
getting pushed onto handlers from somewhere else.
The handler code looks something like this:
<<CODE
use vars qw( $stupid );
my $DEBUG =1;
sub handler
{
# Always call 'instance' so as not to clobber params.
my ($r) = Apache::Request->instance(shift);
# Insane bug I cannot track causes this handler to execute twice
# for each request. It's driving me nuts.
if ( $stupid++ ) {
$r->log_error($r->current_callback . " executed twice! Argh!");
$r->notes(HAND2 => "HAND2");
$r->pnotes(HAND2 => "HAND2");
} else {
$r->log_error($r->current_callback . " executed once.");
$r->notes(HAND1 => "HAND1");
$r->pnotes(HAND1 => "HAND1");
return DECLINED;
}#END if
## SNIP -- Some standard Apache::Session stuff happens here.
## This "Log Handler" actually unties and closes the session.
## It executes just fine.
$r->push_handlers('PerlLogHandler', \&closer);
if ( $DEBUG ) {
$r->log_error("$$: ". $r->current_callback);
$r->log_error("$$: ". $r->is_main ? "is main" : "not main");
$r->log_error("$$: ". $r->is_initial_req ? "is initial" : "not initial");
}#END if
return OK;
}
CODE
The log messages get me this:
<<LOG
[Fri Mar 28 17:27:06 2003] [error] PerlHeaderParserHandler executed once.
[Fri Mar 28 17:27:06 2003] [error] PerlHeaderParserHandler executed
twice! Argh!
[Fri Mar 28 17:27:06 2003] [error] 19914: PerlHeaderParserHandler
[Fri Mar 28 17:27:06 2003] [error] is main
[Fri Mar 28 17:27:06 2003] [error] is initial
LOG
And the content handler sees values for HAND2 but not for HAND1.
Why is this thing running twice, and how can I make it stop??? I hope
someone can hit me over the head with a clue-stick, because this thing
is driving me completely bananas!
All help is greatly appreciated,
Vince Veselosky
http://ice.control-escape.com
Re: [Question] Handler executing twice!?!
Posted by Stas Bekman <st...@stason.org>.
Vince Veselosky wrote:
[...]
> Now here is the thing. The PerlHeaderParserHandler executes TWICE for
> every request. The second time through is apparently a different Apache
Could it be that something in your code pushes the handler on the stack again?
I'd suggest debugging with Apache::ShowRequest?
http://search.cpan.org/author/DOUGM/Apache-Module-0.11/lib/Apache/ShowRequest.pm
Do tracing:
http://perl.apache.org/docs/1.0/guide/debug.html#Debug_Tracing
Use the 'h' setting
PerlSetEnv MOD_PERL_TRACE h
Try to use $r->get_handlers() and see what you get.
Finally, if nothing helps, go with gdb.
Also what happens if you don't use Apache::Request?
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
Re: [Question] Handler executing twice!?!
Posted by Vince Veselosky <vi...@control-escape.com>.
AHA! That's the culprit! mod_dir implements this at the fix-up stage to
allow the directive in .htaccess files, hence my confusion. Thank you
Stas! It all makes sense now.
-Vince
Stas Bekman wrote:
> Vince Veselosky wrote:
> [...]
>
>> The thing that triggered it was the fact that the url was an
>> "index.pl" file. When called as "example.com/index.pl", everything
>> worked as expected, but when called as "example.com/", apache (or
>> something) generated a subrequest for index.pl.
>>
>> NOW my question is, why does apache generate the subrequest *after*
>> the HeaderParser phase, causing it to execute twice? This seems like
>> a pure URI translation issue, and I would expect it to happen in the
>> URI translation phase, *before* the HeaderParser executes at all. I'm
>> wondering if this happens in all requests, or if it is related to
>> Apache::Registry in the content handler. I didn't take the time to
>> track down exactly where the subrequest originates, so I'm not sure
>> if it is a mod_perl issue or just an apache issue. I might one day
>> build some test cases and figure it out, but not soon. Anyone have
>> some insight to add?
>
>
> Do you have mod_dir (DirectoryIndex) configured? It performs a
> rewrite/sub_request-redirect in the fixup stage.
> http://httpd.apache.org/docs/mod/mod_dir.html
> __________________________________________________________________
> Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
> http://stason.org/ mod_perl Guide ---> http://perl.apache.org
> mailto:stas@stason.org http://use.perl.org http://apacheweek.com
> http://modperlbook.org http://apache.org http://ticketmaster.com
Re: [Question] Handler executing twice!?!
Posted by Stas Bekman <st...@stason.org>.
Vince Veselosky wrote:
[...]
> The thing that triggered it was the fact that the url was an "index.pl"
> file. When called as "example.com/index.pl", everything worked as
> expected, but when called as "example.com/", apache (or something)
> generated a subrequest for index.pl.
>
> NOW my question is, why does apache generate the subrequest *after* the
> HeaderParser phase, causing it to execute twice? This seems like a pure
> URI translation issue, and I would expect it to happen in the URI
> translation phase, *before* the HeaderParser executes at all. I'm
> wondering if this happens in all requests, or if it is related to
> Apache::Registry in the content handler. I didn't take the time to track
> down exactly where the subrequest originates, so I'm not sure if it is a
> mod_perl issue or just an apache issue. I might one day build some test
> cases and figure it out, but not soon. Anyone have some insight to add?
Do you have mod_dir (DirectoryIndex) configured? It performs a
rewrite/sub_request-redirect in the fixup stage.
http://httpd.apache.org/docs/mod/mod_dir.html
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
Re: [Question] Handler executing twice!?!
Posted by Vince Veselosky <vi...@control-escape.com>.
Whew, okay, I have an answer, but I also still have a question. The
short explanation:
The "bug" in my code was the fact that I forgot that a request might
also be a subrequest, so now I check if the request is_initial_req and
short circuit if not. (And a tiny bug in my trace code caused my debug
log to report is_initial_req as true all the time. Stupid operator
precedence bugs!) That solves my immediate problem and gives me
something to watch for in future.
The thing that triggered it was the fact that the url was an "index.pl"
file. When called as "example.com/index.pl", everything worked as
expected, but when called as "example.com/", apache (or something)
generated a subrequest for index.pl.
NOW my question is, why does apache generate the subrequest *after* the
HeaderParser phase, causing it to execute twice? This seems like a pure
URI translation issue, and I would expect it to happen in the URI
translation phase, *before* the HeaderParser executes at all. I'm
wondering if this happens in all requests, or if it is related to
Apache::Registry in the content handler. I didn't take the time to track
down exactly where the subrequest originates, so I'm not sure if it is a
mod_perl issue or just an apache issue. I might one day build some test
cases and figure it out, but not soon. Anyone have some insight to add?
Thanks to everyone who sent help and suggestions!
-Vince Veselosky
http://ice.control-escape.com
Vince Veselosky wrote:
>
> Now here is the thing. The PerlHeaderParserHandler executes TWICE for
> every request. The second time through is apparently a different
> Apache object from the first, as when I write to $r->notes, only the
> values from the second execution are visible to the content handler.
>
> Now, if I comment out the PerlHeaderParserHandler line in the conf
> file, the handler never executes at all (which is expected), so it
> isn't getting pushed onto handlers from somewhere else.
>
> Why is this thing running twice, and how can I make it stop??? I hope
> someone can hit me over the head with a clue-stick, because this thing
> is driving me completely bananas!
>
> All help is greatly appreciated,
> Vince Veselosky
> http://ice.control-escape.com
>
>
>
>
>