perl-modperl mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Colin Kuskie <>
Subject mod_perl/Apache has Alzheimers?
Date Fri, 02 Aug 2002 18:45:37 GMT
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) {
  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): 

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):

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

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.


httpd.conf snippet:


PerlModule Apache::OutputChain
PerlModule Apache::NavGraphics
PerlModule Apache::SendFile

##Main site, www
DocumentRoot /home/httpd/html

<Directory "/">
  SetHandler perl-script
  PerlHandler Apache::OutputChain Apache::NavGraphics Apache::SendFile
  PerlSetVar MyTemplate etc/Sunset6.template
  PerlSetVar NavGraphicsDir /navgraphics


perl -V:

Summary of my perl5 (revision 5.0 version 6 subversion 1) configuration:
    osname=linux, osvers=2.4.17-0.13smp, archname=i386-linux
    uname='linux 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
    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/, 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

Apache versions:

apache-1.3.22-6 (from RH7.2)


mod_perl-1.26-2 (from RH7.2)

View raw message