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_TRACE environment variable which can contain any combination of the following options.
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:
PerlModule Apache::Reload PerlInitHandler Apache::Reload PerlSetVar ReloadAll Off PerlSetVar ReloadModules "Apache::* Book::*"
do:
panic% setenv MOD_PERL_TRACE d panic% ./httpd -X PerlModule: arg='Apache::Reload' loading perl module 'Apache::Reload'...ok loading perl module 'Apache'...ok loading perl module 'Tie::IxHash'...not ok init `PerlInitHandler' stack perl_cmd_push_handlers: @PerlInitHandler, 'Apache::Reload' pushing `Apache::Reload' into `PerlInitHandler' handlers perl_cmd_var: 'ReloadAll' = 'Off' perl_cmd_var: 'ReloadModules' = 'Apache::* Book::*'
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:
PerlInitHandler Apache::Reload PerlPostReadRequestHandler Book::ProxyRemoteAddr PerlFixupHandler Apache::GTopLimit
And you can see that they were all called:
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.
Copyright © 2003 O'Reilly & Associates. All rights reserved.