www-apache-bugdb mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ted Keller <kel...@bfg.com>
Subject Re: general/3301: Severe performance problems under heavy load - not noticed in apache-1.3.1
Date Wed, 28 Oct 1998 01:33:33 GMT
Marc,

I think I am seeing something different here.  Although I don't have truss
on my SGI - I ran a par against the base 1.3.3 server engine.  Attached
are the results.  My configuration does have cache enabled.  Garbage
collection is being performed.  Each of the active processes is consuming
between 3-4% of the cpu time.  This seems consistent between the two
releases.

Response times for low usage appear quite acceptable - and no noticable
differences appear between apache 1.3.1 and apache 1.3.3.  Differences
appear with loads increase.  In this case, the loading per proxy copy
stays at 3-4% cpu loads.  However, processor time doesn't increase above
50% (except for occational spikes).  With the 1.3.1 server, loading
increased above the 50% range - and spiking was continous.  This appears
different from eric cooks description where processor load continued to
increase due to the garbage collection calls.

par output....

from child server....

root@d8544-cs 63: par -s -P 22478 -l -SS
OVERFLOW: total so far 183
OVERFLOW: total so far 387

-- snip --


OVERFLOW: total so far 25859
OVERFLOW: total so far 26490
OVERFLOW: total so far 27202
14470mS[ 3]     httpd(22478): END-read() = 751
14473mS[ 3]     httpd(22478): read(4, 0x10030718, 4096) = 0
14473mS[ 3]     httpd(22478): close(4) OK
14474mS[ 3]     httpd(22478): getpid() = 22478 ppid=8515
14474mS[ 3]     httpd(22478): time() = 909536426
14474mS[ 3]     httpd(22478): getdomainname((null), 256) OK
14474mS[ 3]     httpd(22478): socket(PF_INET, SOCK_DGRAM, 0) = 4
14475mS[ 3]     httpd(22478): connect(4, <00 02 00 35 aa 7e 9b 08 00 00 00
00 00
 00 00 00>, 16) OK
14476mS[ 3]     httpd(22478): send(4, <00 05 01 00 00 01 00 00 00 00 00 00
07 63
 6f 75>..., 46, 0) = 46
14477mS[ 3]     httpd(22478): select(5, IN:set=4 OUT:set=4, 0, 0, sec=5
usec=0) 
= 1
14480mS[ 3]     httpd(22478): recv(4, <00 05 85 83 00 01 00 00 00 01 00 00
07 63
 6f 75>..., 1024, 0) = 105
14481mS[ 3]     httpd(22478): close(4) OK
14482mS[ 3]     httpd(22478): socket(PF_INET, SOCK_DGRAM, 0) = 4
14483mS[ 3]     httpd(22478): connect(4, <00 02 00 35 aa 7e 9b 08 00 00 00
00 00
 00 00 00>, 16) OK
14483mS[ 3]     httpd(22478): send(4, <00 06 01 00 00 01 00 00 00 00 00 00
07 63
 6f 75>..., 38, 0) = 38
14484mS[ 3]     httpd(22478): select(5, IN:set=4 OUT:set=4, 0, 0, sec=5
usec=0) 
= 1
14489mS[ 0]     httpd(22478): recv(4, <00 06 81 80 00 01 00 01 00 02 00 02
07 63
 6f 75>..., 1024, 0) = 147
14489mS[ 0]     httpd(22478): close(4) OK
14489mS[ 0]     httpd(22478): socket(PF_INET, SOCK_STREAM, 6) = 4
14493mS[ 0]     httpd(22478): open(/etc/hosts, O_RDONLY, 0666) = 5
14494mS[ 0]     httpd(22478): fstat(5, 0x7fff8898) OK
14494mS[ 0]     httpd(22478): ioctl(5, TCGETA, 0x7fff8840) errno = 25 (Not
a typ
ewriter)
14494mS[ 0]     httpd(22478): read(5, "#\n# If the NIS is running, thi",
4096) =
 751
14497mS[ 0]     httpd(22478): read(5, 0x10030718, 4096) = 0
14497mS[ 0]     httpd(22478): close(5) OK
14498mS[ 0]     httpd(22478): getpid() = 22478 ppid=8515
14498mS[ 0]     httpd(22478): time() = 909536426
14498mS[ 0]     httpd(22478): getdomainname((null), 256) OK
14499mS[ 0]     httpd(22478): socket(PF_INET, SOCK_DGRAM, 0) = 5
14499mS[ 0]     httpd(22478): connect(5, <00 02 00 35 aa 7e 9b 08 00 00 00
00 00
 00 00 00>, 16) OK
14499mS[ 0]     httpd(22478): send(5, <00 07 01 00 00 01 00 00 00 00 00 00
03 31
 30 30>..., 45, 0) = 45
14500mS[ 0]     httpd(22478): select(6, IN:set=5 OUT:set=5, 0, 0, sec=5
usec=0) 
= 1
14504mS[ 3]     httpd(22478): recv(5, <00 07 81 80 00 01 00 03 00 01 00 01
03 31
 30 30>..., 1024, 0) = 196
14505mS[ 3]     httpd(22478): close(5) OK
14512mS[ 3]     httpd(22478): open(/etc/socks.conf, O_RDONLY, 0666) = 5
14513mS[ 3]     httpd(22478): fstat(5, 0x7fff88a8) OK
14513mS[ 3]     httpd(22478): ioctl(5, TCGETA, 0x7fff8850) errno = 25 (Not
a typ
ewriter)
14513mS[ 3]     httpd(22478): read(5, "direct\t192.73.67.0\t\t255.255.25",
4096)
 = 206
14515mS[ 3]     httpd(22478): read(5, 0x10030718, 4096) = 0
14515mS[ 3]     httpd(22478): close(5) OK
14517mS[ 3]     httpd(22478): socket(PF_INET, SOCK_STREAM, 0) = 5
14518mS[ 3]     httpd(22478): connect(5, <00 02 04 38 aa 7e 9b 08 00 00 00
00 00
 00 00 00>, 16) OK
14523mS[ 1]     httpd(22478): ulimit(4, 0) = 200
14523mS[ 1]     httpd(22478): fcntl(5, F_GETFL) = 0x2
14523mS[ 1]     httpd(22478): close(4) OK
14525mS[ 1]     httpd(22478): fcntl(5, F_DUPFD, 4) = 4
14525mS[ 1]     httpd(22478): close(5) OK
14525mS[ 1]     httpd(22478): select(5, 0, IN:set=4 OUT:set=4, 0, sec=15
usec=0)
 = 1
14525mS[ 1]     httpd(22478): write(4, <04 01 00 50 d1 43 77 64>, 8) = 8
14526mS[ 1]     httpd(22478): select(5, 0, IN:set=4 OUT:set=4, 0, sec=15
usec=0)
 = 1
14526mS[ 1]     httpd(22478): write(4, "root\0", 5) = 5
OVERFLOW: total so far 27932
14527mS[ 1]     httpd(22478): select(5, set=4, 0, 0, sec=15 usec=0)
14779mS[ 2]     httpd(22478): END-read() = 457
14781mS[ 2]     httpd(22478):
unlink(/scratch/internet/apache/l/a/m/QpOb4w5ewuKT
F_JvVhQ) errno = 2 (No such file or directory)
14784mS[ 2]     httpd(22478): read(4, 0x7fff6b5b, 8013) = 0
14797mS[ 2]     httpd(22478): write(3, "HTTP/1.0 302 Moved\r\nDate: Wed,",
457) 
= 457
14799mS[ 2]     httpd(22478): close(4) OK
14799mS[ 2]     httpd(22478): fork() = 22565
14809mS[ 3]     httpd(22478): waitsys(P_PID, 22565, 0x7fff89e0,
WTRAPPED|WEXITED
, 0)
14826mS[ 1]     httpd(22478): was sent signal SIGCLD
14827mS[ 1]     httpd(22478): END-waitsys(P_PID, 22565, sig=SIGCLD errno=0
code=
CLD_EXITED pid=22565, status=0, WTRAPPED|WEXITED, 0) = 0
14829mS[ 1]     httpd(22478): close(3) OK
14830mS[ 1]     httpd(22478): sigaction(SIGUSR1, flags=0 handler=0x4289cc
mask=<
NO_SIGNALS>, flags=0 handler=SIG_IGN mask=<NO_SIGNALS>, 0xfad592c) OK
14830mS[ 1]     httpd(22478): close(4) errno = 9 (Bad file number)
14833mS[ 1]     httpd(22478): sigaction(SIGHUP, flags=0 handler=SIG_IGN
mask=<NO
_SIGNALS>, flags=0 handler=0x428954 mask=<NO_SIGNALS>, 0xfad592c) OK
14833mS[ 1]     httpd(22478): sigaction(SIGUSR1, flags=0 handler=SIG_IGN
mask=<N
O_SIGNALS>, flags=0 handler=0x4289cc mask=<NO_SIGNALS>, 0xfad592c) OK
14834mS[ 1]     httpd(22478): prctl(PR_GETNSHARE) = 0
14836mS[ 1]     httpd(22478): exit(0)
OVERFLOW: total so far 28640






>From root process .....



root@d8544-cs 67: par -s -P 8515 -SS -l
OVERFLOW: total so far 279
OVERFLOW: total so far 829
OVERFLOW: total so far 1494
OVERFLOW: total so far 2172
OVERFLOW: total so far 2712
OVERFLOW: total so far 3229
OVERFLOW: total so far 3743
OVERFLOW: total so far 4227
 2491mS[ 0]   UNKNOWN( 8515): END-select() = 0
 2491mS[ 0]   UNKNOWN( 8515): time() = 909536916
 2491mS[ 0]   UNKNOWN( 8515): waitsys(P_ALL, 0, NO PID,
WNOHANG|WTRAPPED|WEXITED
, 0) = 0
OVERFLOW: total so far 4715
OVERFLOW: total so far 5221
OVERFLOW: total so far 5743
OVERFLOW: total so far 6235
 2491mS[ 0]   UNKNOWN( 8515): select(0, 0, 0, 0, sec=1 usec=0) = 0
 3502mS[ 3]   UNKNOWN( 8515): time() = 909536917
 3502mS[ 3]   UNKNOWN( 8515): waitsys(P_ALL, 0, NO PID,
WNOHANG|WTRAPPED|WEXITED
, 0) = 0
OVERFLOW: total so far 6775
OVERFLOW: total so far 7271
OVERFLOW: total so far 7772
 3502mS[ 3]   UNKNOWN( 8515): select(0, 0, 0, 0, sec=1 usec=0)
OVERFLOW: total so far 8260
OVERFLOW: total so far 8786
OVERFLOW: total so far 9290
OVERFLOW: total so far 9781
OVERFLOW: total so far 10222
OVERFLOW: total so far 10684
OVERFLOW: total so far 11139
OVERFLOW: total so far 11614
OVERFLOW: total so far 12134
OVERFLOW: total so far 12611
OVERFLOW: total so far 13084
OVERFLOW: total so far 13596
OVERFLOW: total so far 14070
OVERFLOW: total so far 14554
OVERFLOW: total so far 15054
OVERFLOW: total so far 15577
OVERFLOW: total so far 16117
OVERFLOW: total so far 16638
 9238mS[ 3]   UNKNOWN( 8515): END-select() = 0
 9238mS[ 3]   UNKNOWN( 8515): time() = 909536923
 9239mS[ 3]   UNKNOWN( 8515): waitsys(P_ALL, 0, NO PID,
WNOHANG|WTRAPPED|WEXITED
, 0) = 0
OVERFLOW: total so far 17172
 9239mS[ 3]   UNKNOWN( 8515): select(0, 0, 0, 0, sec=1 usec=0)
OVERFLOW: total so far 17754
OVERFLOW: total so far 18314
OVERFLOW: total so far 18884
OVERFLOW: total so far 19456
OVERFLOW: total so far 20083
OVERFLOW: total so far 20712
11203mS[ 1]   UNKNOWN( 8515): END-select() = 0
11203mS[ 1]   UNKNOWN( 8515): time() = 909536925
11204mS[ 1]   UNKNOWN( 8515): waitsys(P_ALL, 0, NO PID,
WNOHANG|WTRAPPED|WEXITED
, 0) = 0
OVERFLOW: total so far 21372
11204mS[ 1]   UNKNOWN( 8515): select(0, 0, 0, 0, sec=1 usec=0)
OVERFLOW: total so far 22074
OVERFLOW: total so far 22771
OVERFLOW: total so far 23388
OVERFLOW: total so far 24036
OVERFLOW: total so far 24622
OVERFLOW: total so far 25168
13188mS[ 1]   UNKNOWN( 8515): END-select() = 0
13188mS[ 1]   UNKNOWN( 8515): time() = 909536927
13189mS[ 1]   UNKNOWN( 8515): waitsys(P_ALL, 0, NO PID,
WNOHANG|WTRAPPED|WEXITED
, 0) = 0
OVERFLOW: total so far 25688
13189mS[ 1]   UNKNOWN( 8515): select(0, 0, 0, 0, sec=1 usec=0)
OVERFLOW: total so far 26212
root@d8544-cs 68: Broken pipe


ted keller





On 27 Oct 1998 marc@apache.org wrote:

> [In order for any reply to be added to the PR database, ]
> [you need to include <apbugs@Apache.Org> in the Cc line ]
> [and leave the subject line UNCHANGED.  This is not done]
> [automatically because of the potential for mail loops. ]
> [If you do not include this Cc, your reply may be ig-   ]
> [nored unless you are responding to an explicit request ]
> [from a developer.                                      ]
> [Reply only with text; DO NOT SEND ATTACHMENTS!         ]
> 
> 
> Synopsis: Severe performance problems under heavy load - not noticed in apache-1.3.1
> 
> State-Changed-From-To: open-feedback
> State-Changed-By: marc
> State-Changed-When: Tue Oct 27 10:33:34 PST 1998
> State-Changed-Why:
> Why do you say you don't think it is related to the proxy?
> 
> Does PR#3202 (http://bugs.apache.org/index/full/3202)
> sound like it could be the same thing you are seeing?
> 


Mime
View raw message