Req In Process Versus Req / sec

[Tris]

Hi Guys

For the last day or so the Requests in Processing has been much higher than the Req / Second.

Requests in programming between 500 and 1500 and the Req/Sec is only around 200.

I have increased everything I could think of that would try and remidy this (PHP connections etc etc etc) but nothing seems to be working. This is causing the site to be really slow loading. There is a delay of about... 5 seconds before it starts loading.

Just wondering if any of you have any experience with this or anything like that

[auser]

there was a similar case before when bottleneck is at MySQL.

a tip to check MySQL performance:
#mysqladmin processlist

[Tris]

Already did :-P MySQL is on a dedicated server. I have confirmed at tested that there is no issue with the MySQL

[EDIT] or the connection, which is via private network

[auser]

then please check:

IOWait (can simply check it by top)

memory limit for php process

[Tris]

iowait is fine. Soft Memory limit is 450M and hard is 500M

[auser]

can you post the output of "top" here?

[Tris]

top - 16:20:45 up 32 days, 8:49, 2 users, load average: 7.69, 7.09, 7.56
Tasks: 467 total, 7 running, 435 sleeping, 0 stopped, 25 zombie
Cpu(s): 31.7%us, 1.0%sy, 0.0%ni, 66.5%id, 0.0%wa, 0.1%hi, 0.7%si, 0.0%st
Mem: 49457604k total, 24374084k used, 25083520k free, 8156932k buffers
Swap: 4192956k total, 0k used, 4192956k free, 13440892k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
25487 theybf 15 0 45928 28m 1872 S 24.2 0.1 0:06.13 lsphp5
25348 theybf 15 0 47536 29m 1872 S 21.9 0.1 0:15.70 lsphp5
25442 theybf 15 0 47516 29m 1872 S 19.9 0.1 0:11.45 lsphp5
25480 theybf 15 0 46080 28m 1872 S 18.6 0.1 0:06.01 lsphp5
25280 theybf 15 0 51732 33m 1876 S 18.2 0.1 0:30.23 lsphp5
25345 theybf 15 0 46284 28m 1872 S 17.9 0.1 0:17.59 lsphp5
25444 theybf 15 0 46068 28m 1872 S 17.9 0.1 0:11.79 lsphp5
25449 theybf 16 0 46032 28m 1880 R 17.6 0.1 0:06.83 lsphp5
25450 theybf 15 0 46296 28m 1872 R 17.2 0.1 0:09.27 lsphp5
25478 theybf 15 0 46508 28m 1872 S 16.9 0.1 0:06.19 lsphp5
25486 theybf 15 0 45772 27m 1880 S 16.9 0.1 0:06.04 lsphp5
25476 theybf 15 0 46104 28m 1872 S 16.6 0.1 0:06.51 lsphp5
25479 theybf 16 0 46024 28m 1872 S 16.6 0.1 0:06.39 lsphp5
25439 theybf 15 0 46372 28m 1872 S 16.2 0.1 0:12.16 lsphp5
25484 theybf 15 0 46344 28m 1872 S 16.2 0.1 0:06.26 lsphp5
25490 theybf 15 0 45812 28m 1872 R 16.2 0.1 0:06.48 lsphp5
25493 theybf 15 0 46468 28m 1880 S 16.2 0.1 0:06.35 lsphp5


This was from around the time it was at its worst

[auser]

when it's worse again, strace the busiest lsphp5 process.
in the above top output, it's the one pid=25487

then
#strace -c -p 25487

(until it quits automatically)

paste the output here, let's see if we can get any clue from it.

[Tris]

[root@server1 ~]# strace -c -p 16283
Process 16283 attached - interrupt to quit
Process 16283 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
81.22 0.073741 1 142837 1006 read
6.87 0.006242 88 71 connect
3.10 0.002812 937 3 brk
2.78 0.002524 0 46388 71 lstat
1.10 0.000999 10 103 select
1.03 0.000934 0 2912 840 access
0.97 0.000884 0 5951 71 open
0.75 0.000685 1 1148 write
0.45 0.000409 0 5956 close
0.44 0.000403 0 6022 getcwd
0.44 0.000400 0 6960 150 stat
0.38 0.000348 1 371 4 writev
0.18 0.000167 0 11618 lseek
0.11 0.000098 0 11618 fstat
0.06 0.000058 0 143 chdir
0.05 0.000046 1 71 socket
0.03 0.000028 0 213 setsockopt
0.02 0.000016 0 2087 fcntl
0.00 0.000000 0 286 rt_sigaction
0.00 0.000000 0 142 rt_sigprocmask
0.00 0.000000 0 214 setitimer
0.00 0.000000 0 4 accept
0.00 0.000000 0 72 shutdown
0.00 0.000000 0 71 readlink
0.00 0.000000 0 27 getppid
------ ----------- ----------- --------- --------- ----------------
100.00 0.090794 245288 2142 total

[auser]

[root@server1 ~]# strace -c -p 16283
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
81.22 0.073741 1 142837 1006 read


so most of the time(81.22%) is trying to read something, maybe infinite loop in php script?

can further trace what the lsphp5 process is trying to read:
#strace -e read -p xxx -o info.txt

check info.txt, see if something unusual.

[Tris]

Take a look here: http://tinyurl.com/oo76d5

[mistwang]

most read system calls are for MySQL, I think. Have you upgrade your site lately? New plugin?

[Tris]

Nope nothing like that. Its got a dedicated database server over private network. So there should be no issues with speed there unless you guys have any suggestions.

[NiteWave]

is your problem equal to:

http://theybf.com/?wpmp_switcher=desktop

too slow?

that's because the page size is too big(~6M).
this can explain why "Req In Process >> Req / sec". the web server have to take much time to read 6M from disk to serve a single request to homepage(and subsequent requests, img/js/css etc). So it keeps reading.

[Tris]

@NiteWave: All images are external. I understand a lot needs to be done code wise to help increase the speed. Thats not really the issue.

The other day (although it has stopped now) it seemed to be a minute or so before the page started loading. There were no network issues and no load issues on the server. It seemed to just be how many people could be served at one time

[NiteWave]

please further trace what files are opened:

#strace -e open,read,close -p xxx

for the question lsphp5 process