I recently got a new server for our website, and installed RH7.2 on
it and shipped it off to the colo. Since then, I've been getting
lots of 404 server errors, so I added debugging code to the stacked
content handler (a modified version of Apache::NavBar). What
showed up in the error_log is unbelieveable.
- variables randomly get corrupted
- statements either fail, or are skipped
(hence the Alzheimers reference)
I've tried both the apache and mod_perl that come with RH7.2 as well
as on the latest versions of both that I compiled by hand, and there's
no change in behavior between them.
Here's the relevant sections of code from the module (I can also send a
copy of the module if people think having the whole thing would help).
##The PRINT method for the Apache::OutputChain handler
sub PRINT {
my $self = shift;
my $r = $self->[0];
my $bar = load_nav($r);
my $plate = load_plate($r);
local $_ = join '', @_;
my ($header, $content);
($header,$content) = m#<HEAD>(.+)</HEAD>.*<BODY.*?>(.+)</BODY>#si;
my $thash = {
'left_nav_java' => $bar->java,
'header' => $header,
'navigation_table' => $bar->table,
'content' => $content
};
warn join ':', $$, $r->filename, ref($plate), "\n";
if (ref($plate) ne 'Text::Template') {
warn join '', "NavGraphics($$) PRINT: >", $plate, "<\n";
}
my $result = $plate->fill_in(HASH => $thash);
if (defined $result) {
$self->Apache::OutputChain::PRINT($result);
}
else {
warn "ERROR: $Text::Template::ERROR\n";
}
return OK;
}
##The template object caching subroutine
##Note the warn statements and their order
sub load_plate {
my ($r) = @_;
my $conf_file = $r->server_root_relative($r->dir_config('MyTemplate'));
my $mod_time;
if (-e $conf_file) {
$mod_time = (stat _)[9];
}
else {
$conf_file = '';
$mod_time = 0;
}
warn "NavGraphics($$): conf_file = >$conf_file<\n";
warn "NavGraphics($$) time=$mod_time\n";
warn join '', "NavGraphics($$): exists ", exists $TB{$conf_file}, "\n";
return $TB{$conf_file}->template()
if exists($TB{$conf_file})
&& ($TB{$conf_file}->modified() >= $mod_time)
&& (ref($TB{$conf_file}->template()) eq 'Text::Template');
warn "NavGraphics($$): plate not cached\n";
warn "NavGraphics($$): plate $TB{$conf_file}\n";
warn "NavGraphics($$): before new $TB{$conf_file}\n";
$TB{$conf_file} = Apache::NavGraphics::NavTemplate->new($conf_file);
warn "NavGraphics($$): after new $TB{$conf_file}\n";
warn join '', "NavGraphics plate($$): ", ref($TB{$conf_file}->template()), "\n";
return $TB{$conf_file}->template();
}
##The new method for Apache::NavGraphics::NavTemplate
package Apache::NavGraphics::NavTemplate;
sub new {
my ($class, $templateFile) = @_;
warn "NavPlate($$): new <$templateFile>\n";
unless ($templateFile) {
warn "NavPlate($$) Empty templateFile sent\n";
return bless { 'template' => '',
'modified' => 0 }, $class;
}
my $fh = Apache::File->new($templateFile) || return;
warn "NavPlate($$): after fh\n";
my $template = Text::Template->new(
TYPE => 'FILEHANDLE',
SOURCE => $fh,
DELIMITERS => ['{{', '}}']
)
or warn "($$)Problem with template: $Text::Template::ERROR\n";
warn join '', "NavPlate($$) ref: ", ref($template), "\n";
return bless({ 'template' => $template,
'modified' => (stat $templateFile)[9] }, $class);
}
And here's some error_log output:
NavGraphics(30166): conf_file = >/etc/httpd/etc/Sunset6.template<
NavGraphics(30166) time=1025358762
NavGraphics(30166): exists 1
NavGraphics(30166): plate not cached
NavGraphics(30166): plate Apache::NavGraphics::NavTemplate=HASH(0x8268adc)
NavGraphics(30166): before new Apache::NavGraphics::NavTemplate=HASH(0x8268adc)
NavGraphics(30166): after new Apache::NavGraphics::NavTemplate=HASH(0x82688a8)
NavGraphics plate(30166):
30166:/home/httpd/html/Web/WebPolicy.html::
Please note the flow. This page has been accessed several times, but
now the caching code says that it isn't cached, which means that the
cached Text::Template object isn't there anymore, even though the hash
entry exists. Without worrying why that happens, look at the rest of
this section. There should be additional debugging output between
these lines:
NavGraphics(30166): before new Apache::NavGraphics::NavTemplate=HASH(0x8268adc)
NavGraphics(30166): after new Apache::NavGraphics::NavTemplate=HASH(0x82688a8)
from this call to create a new object:
$TB{$conf_file} = Apache::NavGraphics::NavTemplate->new($conf_file);
There isn't, but the hash has changed, as shown by the change in
address! What's more, the last two lines show that whatever is
returned by load_plate isn't an object. It turns out that it's the
template itself (the file).
Sometimes, the debugging code will look like this:
Graphics(30166): conf_file = >/etc/httpd/etc/Sunset6.template<
NavGraphics(30166) time=1025358762
NavGraphics(30166): exists
NavGraphics(30166): plate not cached
NavGraphics(30166): plate
NavGraphics(30166): before new
NavGraphics(30166): after new Apache::NavGraphics::NavTemplate=HASH(0x82689a4)
NavGraphics plate(30166):
30166:/home/httpd/html/Ministries/index.html::
In this case, the debugging output shows that the whole hash key/value
pair has been lost, and similar to before, no debugging output from the
call to new.
And another snippet, where the thing actually worked:
NavGraphics(30165): conf_file = >/etc/httpd/etc/Sunset6.template<
NavGraphics(30165) time=1025358762
NavGraphics(30165): exists
NavGraphics(30165): plate not cached
NavGraphics(30165): plate
NavGraphics(30165): before new
NavPlate(30165): new </etc/httpd/etc/Sunset6.template>
NavPlate(30165): after fh
NavPlate(30165) ref: Text::Template
NavGraphics(30165): after new Apache::NavGraphics::NavTemplate=HASH(0x8270b7c)
NavGraphics plate(30165): Text::Template
30165:/home/httpd/html/index.html:Text::Template:
The frequency of this all happening is very low, and interestingly
enough, almost never happens during stress testing of the machine.
Several nights ago, I pushed about 16000 hits onto the machine over 3
hours with no errors, only to have errors in the log show up a few
hours later.
At this point, I feel like I'm in way over my head. I'd appreciate any
help or suggestions for additional debugging tests to run.
Thanks,
Colin
httpd.conf snippet:
NameVirtualHost 199.108.225.3
PerlModule Apache::OutputChain
PerlModule Apache::NavGraphics
PerlModule Apache::SendFile
##Main site, www
<VirtualHost 199.108.225.3>
ServerName www.sunsetpres.org
DocumentRoot /home/httpd/html
<Directory "/">
SetHandler perl-script
PerlHandler Apache::OutputChain Apache::NavGraphics Apache::SendFile
PerlSetVar MyTemplate etc/Sunset6.template
PerlSetVar NavGraphicsDir /navgraphics
</Directory>
</VirtualHost>
perl -V:
Summary of my perl5 (revision 5.0 version 6 subversion 1) configuration:
Platform:
osname=linux, osvers=2.4.17-0.13smp, archname=i386-linux
uname='linux daffy.perf.redhat.com 2.4.17-0.13smp #1 smp fri feb 1 10:30:48 est
2002 i686 unknown '
config_args='-des -Doptimize=-O2 -march=i386 -mcpu=i686 -Dcc=gcc -Dcf_by=Red Hat,
Inc. -Dcccdlflags=-fPIC -Dinstallprefix=/usr -Dprefix=/usr -Darchname=i386-linux
-Uusethreads -Uuseithreads -Uuselargefiles -Dd_dosuid -Dd_semctl_semun -Di_db -Di_ndbm
-Di_gdbm -Di_shadow -Di_syslog -Dman3ext=3pm -Dlocincpth='
hint=recommended, useposix=true, d_sigaction=define
usethreads=undef use5005threads=undef useithreads=undef usemultiplicity=undef
useperlio=undef d_sfio=undef uselargefiles=undef usesocks=undef
use64bitint=undef use64bitall=undef uselongdouble=undef
Compiler:
cc='gcc', ccflags ='-fno-strict-aliasing -I/usr/local/include',
optimize='-O2 -march=i386 -mcpu=i686',
cppflags='-fno-strict-aliasing -I/usr/local/include'
ccversion='', gccversion='2.96 20000731 (Red Hat Linux 7.1 2.96-98)',
gccosandvers=''
intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=4
alignbytes=4, usemymalloc=n, prototype=define
Linker and Libraries:
ld='gcc', ldflags =' -L/usr/local/lib'
libpth=/usr/local/lib /lib /usr/lib
libs=-lnsl -ldl -lm -lc -lcrypt -lutil
perllibs=-lnsl -ldl -lm -lc -lcrypt -lutil
libc=/lib/libc-2.2.4.so, so=so, useshrplib=false, libperl=libperl.a
Dynamic Linking:
dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-rdynamic'
cccdlflags='-fPIC', lddlflags='-shared -L/usr/local/lib'
Characteristics of this binary (from libperl):
Compile-time options:
Built under linux
Compiled at Feb 20 2002 15:01:16
@INC:
/usr/lib/perl5/5.6.1/i386-linux
/usr/lib/perl5/5.6.1
/usr/lib/perl5/site_perl/5.6.1/i386-linux
/usr/lib/perl5/site_perl/5.6.1
/usr/lib/perl5/site_perl/5.6.0/i386-linux
/usr/lib/perl5/site_perl/5.6.0
/usr/lib/perl5/site_perl
.
Apache versions:
apache-1.3.22-6 (from RH7.2)
apache_1.3.26
mod_perl:
mod_perl-1.26-2 (from RH7.2)
mod_perl-1.27
