You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Matt Juszczak <ma...@atopia.net> on 2009/07/15 01:21:58 UTC
[users@httpd] Spiraling Apache Server, Multiple /tmp in lsof
Hi all,
Working on debugging an apache server that continually keeps CPU pegged at
100%, and load average well above 30.00.
To debug, I've set maxclients lower, and maxrequestsperchild to 0 (so that
a tracing process doesn't continuously re-spawn).
I notice a few inefficiencies in the trace (mostly .htaccess file
searching, which we're working on phasing out, and DNS lookups because we
were using hostnames instead of IP's to connect to DB servers, but we're
phasing that out as well).
But then I get to sections like this that coninuously repeat themselves,
which is why I assume I also see processes in top hang in a "lockf" state:
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
50943 httpd RET fcntl 0
When I look up 0xd in lsof, I get:
httpd 50943 www 9u PIPE 0xffffff008ab9c8b8 16384 ->0xffffff008ab9ca10
httpd 50943 www 10u PIPE 0xffffff008ab9ca10 0 ->0xffffff008ab9c8b8
httpd 50943 www 11w VREG 0,92 0 353317 /var (/dev/amrd0s1d)
httpd 50943 www 12u VREG 0,93 0 38 /tmp/aprY4bEZy
httpd 50943 www 13u VREG 0,93 0 39 /tmp (/dev/amrd0s1e)
httpd 50943 www 14u VREG 0,93 0 40 /tmp (/dev/amrd0s1e)
httpd 50943 www 15u VREG 0,93 0 32 /tmp (/dev/amrd0s1e)
httpd 50943 www 16u VREG 0,93 0 41 /tmp (/dev/amrd0s1e)
httpd 50943 www 17u VREG 0,93 0 34 /tmp (/dev/amrd0s1e)
httpd 50943 www 18u VREG 0,93 0 35 /tmp (/dev/amrd0s1e)
httpd 50943 www 19u VREG 0,93 0 43 /tmp (/dev/amrd0s1e)
httpd 50943 www 20u VREG 0,93 0 42 /tmp (/dev/amrd0s1e)
httpd 50943 www 21u VREG 0,93 0 45 /tmp (/dev/amrd0s1e)
httpd 50943 www 22u VREG 0,93 0 44 /tmp (/dev/amrd0s1e)
httpd 50943 www 23u VREG 0,93 0 47 /tmp (/dev/amrd0s1e)
httpd 50943 www 24u VREG 0,93 0 48 /tmp/aprGXHCAa
httpd 50943 www 25w VREG 0,92 0 353299 /var/log/accept.lock.43707
httpd 50943 www 26w VREG 0,92 0 353299 /var/log/accept.lock.43707
httpd 50943 www 27w VREG 0,93 0 48 /tmp/aprGXHCAa
I interpret 0xd to be 13, which would be /tmp. Why are there so many
/tmp's (is this something in the code?). Perhaps this isn't part of the
issue with the high load, but I know that the apache processes are timing
out connections (and in fact, I'm getting these errors almost consistently
right before this apache thread accepts a new connection):
50943 httpd CALL
setsockopt(0x26,SOL_SOCKET,SO_RCVTIMEO,0x7fffffff70d0,0x10)
50943 httpd RET setsockopt -1 errno 33 Numerical argument out of
domain
50943 httpd CALL
setsockopt(0x26,SOL_SOCKET,SO_SNDTIMEO,0x7fffffff70d0,0x10)
50943 httpd RET setsockopt -1 errno 33 Numerical argument out of
domain
and seeing a lot of:
50943 httpd CALL fcntl(0x14,F_SETLK,0xffffffffffffb210)
50943 httpd RET fcntl -1 errno 35 Resource temporarily unavailable
Also, with MaxRequestsPerChild set to 0, I assumed the threads would never
re-spawn, but I monitor with ktrace and after a few minutes, it begins
with:
50943 httpd RET gettimeofday 0
50943 httpd CALL read(0x1f,0x809655048,0x1f40)
50943 httpd GIO fd 31 read 123 bytes
"OPTIONS * HTTP/1.0\r
User-Agent: Apache/2.2.11 (FreeBSD) mod_ssl/2.2.11 OpenSSL/0.9.8e
DAV/2 (internal dummy connection)\r
\r
"
50943 httpd RET read 123/0x7b
50943 httpd CALL gettimeofday(0x7fffffffe830,0)
And then eventually dies out:
50943 httpd CALL sigprocmask(SIG_SETMASK,0x80067fed0,0)
50943 httpd RET sigprocmask 0
50943 httpd CALL sigprocmask(SIG_BLOCK,0x80067fec0,0x7fffffffe830)
50943 httpd RET sigprocmask 0
50943 httpd CALL sigprocmask(SIG_SETMASK,0x80067fed0,0)
50943 httpd RET sigprocmask 0
50943 httpd CALL exit(0)
Thanks for any advice someone can give!
---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] Spiraling Apache Server, Multiple /tmp in lsof
Posted by Matt Juszczak <ma...@atopia.net>.
Hi all,
Just wanted to ping one more time to see if anyone had any ideas,
especially related to all the /tmp entries in lsof for each apache thread
which I haven't seen before.
On Tue, 14 Jul 2009, Matt Juszczak wrote:
> Hi all,
>
> Working on debugging an apache server that continually keeps CPU pegged at
> 100%, and load average well above 30.00.
>
> To debug, I've set maxclients lower, and maxrequestsperchild to 0 (so that a
> tracing process doesn't continuously re-spawn).
>
> I notice a few inefficiencies in the trace (mostly .htaccess file searching,
> which we're working on phasing out, and DNS lookups because we were using
> hostnames instead of IP's to connect to DB servers, but we're phasing that
> out as well).
>
> But then I get to sections like this that coninuously repeat themselves,
> which is why I assume I also see processes in top hang in a "lockf" state:
>
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
> 50943 httpd CALL fcntl(0xd,F_SETLKW,0xffffffffffffc0d0)
> 50943 httpd RET fcntl 0
>
> When I look up 0xd in lsof, I get:
>
> httpd 50943 www 9u PIPE 0xffffff008ab9c8b8 16384
> ->0xffffff008ab9ca10
> httpd 50943 www 10u PIPE 0xffffff008ab9ca10 0
> ->0xffffff008ab9c8b8
> httpd 50943 www 11w VREG 0,92 0
> 353317 /var (/dev/amrd0s1d)
> httpd 50943 www 12u VREG 0,93 0
> 38 /tmp/aprY4bEZy
> httpd 50943 www 13u VREG 0,93 0
> 39 /tmp (/dev/amrd0s1e)
> httpd 50943 www 14u VREG 0,93 0
> 40 /tmp (/dev/amrd0s1e)
> httpd 50943 www 15u VREG 0,93 0
> 32 /tmp (/dev/amrd0s1e)
> httpd 50943 www 16u VREG 0,93 0
> 41 /tmp (/dev/amrd0s1e)
> httpd 50943 www 17u VREG 0,93 0
> 34 /tmp (/dev/amrd0s1e)
> httpd 50943 www 18u VREG 0,93 0
> 35 /tmp (/dev/amrd0s1e)
> httpd 50943 www 19u VREG 0,93 0
> 43 /tmp (/dev/amrd0s1e)
> httpd 50943 www 20u VREG 0,93 0
> 42 /tmp (/dev/amrd0s1e)
> httpd 50943 www 21u VREG 0,93 0
> 45 /tmp (/dev/amrd0s1e)
> httpd 50943 www 22u VREG 0,93 0
> 44 /tmp (/dev/amrd0s1e)
> httpd 50943 www 23u VREG 0,93 0
> 47 /tmp (/dev/amrd0s1e)
> httpd 50943 www 24u VREG 0,93 0
> 48 /tmp/aprGXHCAa
> httpd 50943 www 25w VREG 0,92 0
> 353299 /var/log/accept.lock.43707
> httpd 50943 www 26w VREG 0,92 0
> 353299 /var/log/accept.lock.43707
> httpd 50943 www 27w VREG 0,93 0
> 48 /tmp/aprGXHCAa
>
> I interpret 0xd to be 13, which would be /tmp. Why are there so many /tmp's
> (is this something in the code?). Perhaps this isn't part of the issue with
> the high load, but I know that the apache processes are timing out
> connections (and in fact, I'm getting these errors almost consistently right
> before this apache thread accepts a new connection):
>
> 50943 httpd CALL
> setsockopt(0x26,SOL_SOCKET,SO_RCVTIMEO,0x7fffffff70d0,0x10)
> 50943 httpd RET setsockopt -1 errno 33 Numerical argument out of domain
> 50943 httpd CALL
> setsockopt(0x26,SOL_SOCKET,SO_SNDTIMEO,0x7fffffff70d0,0x10)
> 50943 httpd RET setsockopt -1 errno 33 Numerical argument out of domain
>
>
> and seeing a lot of:
>
> 50943 httpd CALL fcntl(0x14,F_SETLK,0xffffffffffffb210)
> 50943 httpd RET fcntl -1 errno 35 Resource temporarily unavailable
>
>
> Also, with MaxRequestsPerChild set to 0, I assumed the threads would never
> re-spawn, but I monitor with ktrace and after a few minutes, it begins with:
>
> 50943 httpd RET gettimeofday 0
> 50943 httpd CALL read(0x1f,0x809655048,0x1f40)
> 50943 httpd GIO fd 31 read 123 bytes
> "OPTIONS * HTTP/1.0\r
> User-Agent: Apache/2.2.11 (FreeBSD) mod_ssl/2.2.11 OpenSSL/0.9.8e
> DAV/2 (internal dummy connection)\r
> \r
> "
> 50943 httpd RET read 123/0x7b
> 50943 httpd CALL gettimeofday(0x7fffffffe830,0)
>
>
> And then eventually dies out:
>
> 50943 httpd CALL sigprocmask(SIG_SETMASK,0x80067fed0,0)
> 50943 httpd RET sigprocmask 0
> 50943 httpd CALL sigprocmask(SIG_BLOCK,0x80067fec0,0x7fffffffe830)
> 50943 httpd RET sigprocmask 0
> 50943 httpd CALL sigprocmask(SIG_SETMASK,0x80067fed0,0)
> 50943 httpd RET sigprocmask 0
> 50943 httpd CALL exit(0)
>
>
> Thanks for any advice someone can give!
>
>
> ---------------------------------------------------------------------
> The official User-To-User support forum of the Apache HTTP Server Project.
> See <URL:http://httpd.apache.org/userslist.html> for more info.
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> " from the digest: users-digest-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
>
---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org