Say you've just installed a new
script, and when you try it out you see the grey screen of death
saying "Internal Server Error"
(Figure 21-1). Or even worse,
you've had a script running on a production server
for a long time without problems, when the same grey screen starts to
show up occasionally for no apparent reason.

Figure 21-1. Internal Server Error

How can you find out what the problem is, before you actually attempt
to solve it?

The first problem is determining the location of the error message.

You have been coding in Perl for years, and whenever an error
occurred in the past it was displayed in the same terminal window
from which you started the script. But when you work with a web
server, the errors do not show up in a terminal. In many cases, the
server has no terminal to which to send the error messages.

Actually, the error messages don't disappear; they
end up in the
error_log file.
Its location is specified by the
ErrorLog
directive in httpd.conf. The default setting is:

ErrorLog logs/error_log

where logs/error_log is appended to the value of
the ServerRoot directive.

If you've followed the convention
we've used in this book and your
ServerRoot is:

ServerRoot /home/httpd/httpd_perl

the full path to the file will be
/home/httpd/httpd_perl/logs/error_log.

Whenever you see "Internal Server
Error" in a browser it's time to
look at this file.

There are cases when errors don't go to the
error_log file. This can happen when the server
is starting and hasn't gotten as far as opening the
error_log file for writing before it needs to
write an error message. In that case, Apache writes the messages to
STDERR. If you have entered a
nonexistent directory path in your ErrorLog
directive in httpd.conf, the error message will
be printed to STDERR. If the error happens when
the server executes a PerlRequire,
PerlModule, or other startup-time directive you
might also see output sent to STDERR. If you
haven't redirected Apache's
STDERR, then the messages are printed to the
console (tty, terminal) from which you started the server.

Note that when you're running the server in
single-process mode (httpd
-X), the usual startup message:

Apache/1.3.24 (Unix) mod_perl/1.26 configured

won't appear in the error_log
file. Also, any startup warnings will be printed to the console,
since in this mode the server redirects its STDERR stream to the
error_log file only at a later stage.

The first problem is solved: we know where the error messages are.

The second problem is,
how useful is
the error message?

The usefulness of the error message depends to some extent on the
programmer's coding style. An uninformative message
might not help you spot and fix the error.

For example, let's take a function that opens a file
passed to it as a parameter for reading. It does nothing else with
the file. Here's the first version of the code:

Let's assume that /tmp/test.txt
doesn't exist, so the open( )
call will fail to open the file. When we call this script from our
browser, the browser returns an "Internal Server
Error" message and we see the following error
appended to error_log:

Died at /home/httpd/perl/test.pl line 9.

We can use the hint Perl kindly gave to us to find where in the code
die( ) was called. However, we still
won't necessarily know what filename was passed to
this subroutine to cause the program termination.

If we have only one function call, as in the example above, the task
of finding the problematic filename is trivial. Now
let's add one more open_file( )
function call and assume that of the two, only the file
/tmp/test.txt exists:

open_file("/tmp/test.txt");
open_file("/tmp/test2.txt");

When you execute the above call, you will see:

Died at /home/httpd/perl/test.pl line 9.

Based on this error message, can you tell what file your program
failed to open? Probably not. Let's improve it by
showing the name of the file that failed:

which obviously makes a big difference, since now we know what file
we failed to open.

By the way, if you append a newline to the end of the message you
pass to die( ), Perl won't report
the line number at which the error has happened. If you write:

open FILE, $filename or die "failed to open $filename\n";

the error message will be:

failed to open /tmp/test2.txt

which gives you very little to go on. It's very hard
to debug with such uninformative error messages.

The warn( ) function outputs an error message in the
same way as die( ), but whereas die(
) causes program termination, execution continues normally
after a warn( ). Just like with die(
), if you add a newline to the end of the message, the
filename and the line number from which warn( )
was called won't be logged.

You might want to use warn( ) instead of
die( ) if the failure isn't
critical. Consider the following code:

if (open FILE, $filename) {
# do something with the file
close FILE;
}
else {
warn "failed to open $filename";
}
# more code here...

However, unless you have a really good reason to do otherwise, you
should generally die( ) when your code encounters
any problem whatsoever. It can be very hard to catch a problem that
manifests itself only several hundred lines after the problem was
caused.

A different approach for producing useful warnings and error messages
is to print the function call stack
backtrace. The Carp
module comes to our aid with its cluck(
) function. Consider the script in Example 21-1.

Carp::cluck( ) is assigned as a warnings signal
handler. Whenever a warning is triggered, this function will be
called. When we execute the script, we see:

My value is Perl
Use of uninitialized value at ./warnings.pl line 15.
main::print_value( ) called at ./warnings.pl line 11
main::incorrect( ) called at ./warnings.pl line 8
My value is

Take a moment to understand the stack trace in the warning. The
deepest calls are printed first. So the second line tells us that the
warning was triggered in print_value( ) and the
third line tells us that print_value( ) was called
by the subroutine incorrect( ):

script -> incorrect( ) -> print_value( )

When we look at the source code for the function incorrect(
), we see that we forgot to pass the variable to the
print_value( ) function. Of course, when you write
a subroutine like print_value( ),
it's a good idea to check the passed arguments
before starting execution. We omitted that step to contrive an easily
debuggable example.

You can also call Carp::cluck( ) directly in your
code, and it will produce the call-stack backtrace for you. This is
usually very useful during the code development phase.

Carp::confess( ) is like Carp::cluck(
), but it acts as a die( ) function
(i.e., terminates the program) and prints the call-stack backtrace.
The functions Carp::carp(
)
and Carp::croak( ) are two other equivalents of
warn( ) and die( ),
respectivily, but they report about the caller of the function in
which they are used, rather the function itself.

In some cases the built-in caller(
) function can be useful as well, but it
can be a bit cumbersome to use when you need to peek several levels
up the call stack.

When using the warn( ) and die(
) functions, be aware of the following pitfall. Here the
message passed to die( ) is printed with no
problems, assuming the file /does_not_exist
actually doesn't exist:

So the die( ) part has effectively disappeared.
Make sure you always use the low-precendence logical OR operator
or in this situation. Alternatively, you can use
parentheses, but this is less visually appealing:

Only the first pair of parentheses is really needed here, but to be
consistent we use them through the whole statement.

Now let's return to improving the warning and error
messages. The failing code reports the names of the problematic
files, but we still don't know the real reason for
the failure. Let's try to improve the warn(
) example. The -r operator tests whether
the file is readable:

Now if we cannot read the file we do not even try to open it. But we
still see a warning in error_log:

Couldn't open /tmp/test.txt - doesn't exist or is not readable
at /home/httpd/perl/test.pl line 9.

The warning tells us the reason for the failure, so we
don't have to go to the code and check what it was
trying to do with the file.

It could be quite a coding overhead to explain all the possible
failure reasons that way, but why reinvent the wheel? We already have
the reason for the failure stored in the $!
variable. Let's go back to the open_file(
) function:

failed to open /tmp/test.txt: No such file or directory
at /home/httpd/perl/test.pl line 9.

Now we have all the information we need to debug these problems: we
know what line of code triggered die( ), we know
what file we were trying to open, and we also know the reason,
provided by Perl's $! variable.

Note that there's a big difference between the
following two commonly seen bits of Perl code:

open FILE, $filename or die "Can't open $filename: $!";
open FILE, $filename or die "Can't open $filename!";

The first bit is helpful; the second is just rude. Please do your
part to ease human suffering, and use the first version, not the
second.

To show our useful error messages in action, let's
cause an error. We'll create the file
/tmp/test.txt as a different user and make sure
that it isn't readable by Apache processes:

failed to open /tmp/test.txt: Permission denied
at /home/httpd/perl/test.pl line 9.

Here we see a different reason: we created a file that
doesn't belong to the user the server runs as
(usually nobody). It does not have permission to
read the file.

Now you can see that it's much easier to debug your
code if you validate the return values of the system calls and
properly code arguments to die( ) and
warn( ) calls. The open( )
function is just one of the many system calls Perl provides.

Second problem solved: we now have useful error messages.

So now you can code and see error messages from mod_perl scripts and
modules as easily as if they were plain Perl scripts that you
execute from a shell.