When we are interested in mod_perl-level
events, it's quite hard to use system-level tracing,
both because of the system trace's verbosity and
because it's hard to find the boundary between
events. Therefore, we need to do mod_perl-level tracing.
To enable mod_perl debug tracing, configure mod_perl with the
PERL_TRACE option:
panic% perl Makefile.PL PERL_TRACE=1 ...
The trace levels can then be enabled via the
MOD_PERL_TRACEenvironment
variable which can contain any combination of the following options.
For startup processing:
c
Trace directive handling during Apache (non-mod_perl)
configuration-directive handling
d
Trace directive handling during mod_perl directive processing during
configuration read
s
Trace processing of <Perl>sections
For runtime processing:
h
Trace Perl handler callbacks during the processing of incoming
requests and during startup (PerlChildInitHandler)
g
Trace global variable handling, interpreter construction,
END blocks, etc.
Alternatively, setting the environment variable to
all will include all the options listed above.
One way of setting this variable is by adding this directive to
httpd.conf:
PerlSetEnv MOD_PERL_TRACE all
For example, if you want to see a trace of the
PerlRequire and PerlModule
directives as they are executed, use:
PerlSetEnv MOD_PERL_TRACE d
You can also use the command-line environment, setting:
panic% setenv MOD_PERL_TRACE all
panic% ./httpd -X
If running under a Bourne-style shell, you can set the environment
variable for only the duration of a single command:
panic% MOD_PERL_TRACE=all ./httpd -X
If using a different shell, you should try using the
env utility, which has a similar effect:
panic% env MOD_PERL_TRACE=all ./httpd -X
For example, if you want to trace the processing of the
Apache::Reloadsetting during startup and you want
to see what happens when the following directives are processed:
We have removed the rest of the trace and separated the output trace
into four groups, each equivalent to the appropriate setting from our
configuration example. So we can see that:
PerlModule Apache::Reload
loads the Apache::Reload and
Apache modules but fails to load
Tie::IxHash, since we don't have
it installed (which is not a fatal error in the case of
Apache::Reload).
The following initializes the PerlInitHandler
stack, as it wasn't yet used, and pushes
Apache::Reload there:
PerlInitHandler Apache::Reload
The last two directives call perl_cmd_var( ) to
set the Perl variables that can be retrieved in the code with
dir_config( ), as explained in Chapter 4:
PerlSetVar ReloadAll Off
PerlSetVar ReloadModules "Apache::* Book::*"
Now let's look at the trace of the handlers called
during the execution of this code:
use strict;
my $r = shift;
$r->send_http_header("text/plain");
$r->print("Hello");
We set MOD_PERL_TRACE to trace handler calls with
h:
panic% setenv MOD_PERL_TRACE h
panic% ./httpd -X &
panic% tail -f /home/httpd/httpd_perl/logs/error_log
running 1 server configured stacked handlers for /perl/test.pl...
calling &{PerlInitHandler->[0]} (1 total)
&{PerlInitHandler->[0]} returned status=0
`PerlInitHandler' push_handlers( ) stack is empty
PerlInitHandler handlers returned 0
running 1 server configured stacked handlers for /perl/test.pl...
calling &{PerlPostReadRequestHandler->[0]} (1 total)
&{PerlPostReadRequestHandler->[0]} returned status=0
`PerlPostReadRequestHandler' push_handlers( ) stack is empty
PerlPostReadRequestHandler handlers returned 0
`PerlTransHandler' push_handlers( ) stack is empty
PerlTransHandler handlers returned -1
`PerlInitHandler' push_handlers( ) stack is empty
PerlInitHandler handlers returned -1
`PerlHeaderParserHandler' push_handlers( ) stack is empty
`PerlAccessHandler' push_handlers( ) stack is empty
PerlAccessHandler handlers returned -1
`PerlTypeHandler' push_handlers( ) stack is empty
PerlTypeHandler handlers returned -1
running 1 server configured stacked handlers for /perl/test.pl...
calling &{PerlFixupHandler->[0]} (1 total)
registering PerlCleanupHandler
&{PerlFixupHandler->[0]} returned status=-1
`PerlFixupHandler' push_handlers( ) stack is empty
PerlFixupHandler handlers returned -1
running 1 server configured stacked handlers for /perl/test.pl...
calling &{PerlHandler->[0]} (1 total)
&{PerlHandler->[0]} returned status=0
`PerlHandler' push_handlers( ) stack is empty
PerlHandler handlers returned 0
`PerlLogHandler' push_handlers( ) stack is empty
PerlLogHandler handlers returned -1
running registered cleanup handlers...
perl_call: handler is a cached CV
`PerlCleanupHandler' push_handlers( ) stack is empty
PerlCleanupHandler handlers returned -1
You can see what handlers were registered to be executed during the
processing of this simple script. In our configuration we had these
relevant directives:
calling &{PerlInitHandler->[0]} (1 total)
&{PerlInitHandler->[0]} returned status=0
calling &{PerlPostReadRequestHandler->[0]} (1 total)
&{PerlPostReadRequestHandler->[0]} returned status=0
calling &{PerlFixupHandler->[0]} (1 total)
registering PerlCleanupHandler
&{PerlFixupHandler->[0]} returned status=-1
In addition, when Apache::GTopLimit was running,
it registered a PerlCleanupHandler, which was
executed at the end:
running registered cleanup handlers...
perl_call: handler is a cached CV
Since we were executing an Apache::Registry
script, the PerlHandler was executed as well:
running 1 server configured stacked handlers for /perl/test.pl...
calling &{PerlHandler->[0]} (1 total)
&{PerlHandler->[0]} returned status=0
`PerlHandler' push_handlers( ) stack is empty
PerlHandler handlers returned 0
So if you debug your handlers, you can see what handlers were called,
whether they have registered some new handlers on the fly, and what
the return status from the executed handler was.
