httpd-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Arkadi Shishlov" <ark...@mebius.lv>
Subject Re: piped log bug?
Date Sun, 27 Feb 2005 20:42:51 GMT
On Sun, Feb 27, 2005 at 10:51:12AM -0500, Jeff Trawick wrote:
> On Sun, 27 Feb 2005 12:52:53 +0200, Arkadi Shishlov <arkadi@mebius.lv> wrote:
> > On my medium busy FreeBSD and Linux servers I noticed that sometimes
> > apache leaves previous instance children in non-working state after
> > restart. Examination with ps/strace/truss shows that all of them
> > are writing to piped (cronolog backed) access log, but by that time
> > all cronolog processes are already gone.
> > 
> > I quickly examined the source, both 1.3 and 2.0, and seems that the
> > reading side of logging pipe is not closed in Apache process. I think
> > the server must close reading fd in child process, or else all children
> > are stuck in pipewr when there are no one to read the log.
> 
> I can see the perhaps-unexpected fd handling with a simple test of
> 1.3.  I think the issue is that Apache wants* to keep using the same
> pipe if the piped logger crashes and has to be restarted, so it has to
> keep both handles open so that the new piped logger instance can use
> the same pipe.

Yes, but reading side must be kept in parent/master process only. All
children must close it after fork.

> If Apache didn't keep that side of the pipe open in the parent, then
> after a piped logger crashes and has to be restarted, a different pipe
> would have to be created, and none of the current httpd child
> processes would be able to have their messages logged since the new
> piped logger would be using a different pipe.
> 
> The key question seems to be: If all the other Apache installations in
> the world work like this, then why are you having problems?  Has that

Probably
- many installations doesn't used piped logs
- many webservers are not busy
- many just restarts unconditionaly
- many didn't bother to investigate

> other side of the pipe handle been incorrectly inherited by some other
> process, and *that* is what is causing a write to the pipe to hang? 

I believe the reading part of the pipe is inherited by every child.

> lsof should be able to check for other processes which have a read
> handle to the same pipe.

'which have a read handle to the same pipe' - Hmm.. not sure how to do
this with lsof.
Here is the master:

httpd   40282 root    2u  PIPE 0xe2d61cc0    16384         ->0xe48ada00
httpd   40282 root    3u  VREG  13,131076        0  808500 /usr/local/apache-1.3.33/logs/httpd.mm.40276.sem
httpd   40282 root    4u  PIPE 0xe2d630c0    16384         ->0xe365b0e0
httpd   40282 root    5u  VREG  13,131072        0   19127 / (/dev/da0s1a)
httpd   40282 root    6u  PIPE 0xe2d61cc0    16384         ->0xe48ada00
httpd   40282 root    7u  PIPE 0xe365b0e0    16384         ->0xe2d630c0
httpd   40282 root    8u  PIPE 0xe48addc0    16384         ->0xe4211ea0
httpd   40282 root    9u  PIPE 0xe4211ea0    16384         ->0xe48addc0

Here is one of the children:

httpd   76090 apache    2u  PIPE 0xe2d61cc0    16384         ->0xe48ada00
httpd   76090 apache    3u  VREG  13,131076        0  808500 /usr/local/apache-1.3.33/logs/httpd.mm.40276.sem
httpd   76090 apache    4u  PIPE 0xe2d630c0    16384         ->0xe365b0e0
httpd   76090 apache    5u  VREG  13,131072        0   19127 / (/dev/da0s1a)
httpd   76090 apache    6u  PIPE 0xe2d61cc0    16384         ->0xe48ada00
httpd   76090 apache    7u  PIPE 0xe365b0e0    16384         ->0xe2d630c0
httpd   76090 apache    8u  PIPE 0xe48addc0    16384         ->0xe4211ea0
httpd   76090 apache    9u  PIPE 0xe4211ea0    16384         ->0xe48addc0
httpd   76090 apache   11u  unix 0xe053c7c0      0t0         ->0xe0547e00

These the only PIPEs they have.
I use three instances of piped log - access, error, ssl. The PIPE count is
identical == 6 in both master and worker, which confirms the theory..?


arkadi.

Mime
View raw message