High "Load Average"

I am using nginx + php-fpm (quad-core PC) + MySQL (on another PC) and
facing an interesting issue:
after some time nginx is running, system “load average” goes up
(sometimes up to 30 and even more points) while CPU usage is still less
then 30% With such a high load system becomes very slow and
unresponsive. Restarting nginx helps, but only for a little while. Any
ideas on the matter?

Thanks,
Sessna

Posted at Nginx Forum:

On Fri, 2010-03-12 at 12:34 -0500, Sessna wrote:

I am using nginx + php-fpm (quad-core PC) + MySQL (on another PC) and
facing an interesting issue:
after some time nginx is running, system “load average” goes up
(sometimes up to 30 and even more points) while CPU usage is still
less then 30% With such a high load system becomes very slow and
unresponsive. Restarting nginx helps, but only for a little while. Any
ideas on the matter?

You fail to mention what sort of disk subsystem you are using. High
load is often indicative of I/O bottlenecks. You also don’t mention
what OS you are using, but if it’s Linux you should install iotop and
take a look at what process is driving the load (it might be Nginx, but
more likely MySQL - restarting Nginx simply cancels whatever pending
requests MySQL had is my guess).

Cliff

Cliff W. Wrote:

You fail to mention what sort of disk subsystem you are using.
One SCSI disk

High load is often indicative of I/O bottlenecks.
You also don’t mention what OS you are using,
CentOS release 5.4

you should install iotop and take a look at what process is driving the load
Here is the snippet from iotop output
Total DISK READ: 3.33 K/s | Total DISK WRITE: 3.27 M/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
20264 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp
21604 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp
21605 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp
20054 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp
20902 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp
20275 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp
20828 be/4 nobody 0.00 B/s 0.00 B/s 0.00 % 99.99 % php-cgi
–fpm --fpm-config /etc/php-fp

Looks like php-cgi makes 99.99% IO, but not really sure what this means

(it might be Nginx, but more likely MySQL - restarting Nginx simply cancels whatever pending
requests MySQL had is my guess).
MySQL is running on another PC, so php makes network connections to DB.
It may take a while, of course, but should not php being blocked and
sleeping while network system is processing request?

Thanks,
Sessna

Posted at Nginx Forum:

On Sat, 2010-03-13 at 02:29 -0500, Sessna wrote:

Here is the snippet from iotop output
Looks like php-cgi makes 99.99% IO, but not really sure what this means
This means that php-cgi is spending 99.99% of its time in I/O, not that
it’s creating 99.99% of your I/O. It means php-cgi is waiting almost
all the time.

(it might be Nginx, but more likely MySQL - restarting Nginx simply
cancels whatever pending
requests MySQL had is my guess).
MySQL is running on another PC, so php makes network connections to
DB. It may take a while, of course, but should not php being blocked
and sleeping while network system is processing request?

Yes, and this is certainly what is happening. You have to remember
that “load” is an indication of how many processes are waiting to be
scheduled, and this includes processes that are waiting on I/O. In this
case it looks like PHP isn’t generating a lot of I/O, rather it is
waiting, creating a high load, and at the same time, you are running
out of PHP processes to handle new requests, which is why the box slows
down.

I’d follow these steps:

  1. check the state of the MySQL server. See if this machine is
    overloaded.

  2. check MySQL itself. Turn on query logging and see if you have some
    query that’s taking a long time to complete.

  3. take a look at your network to make sure that there isn’t an issue
    there (saturation, packet loss, etc).

Regards,
Cliff

Cliff W. Wrote:

This means that php-cgi is spending 99.99% of its time in I/O, not that
it’s creating 99.99% of your I/O. It means php-cgi is waiting almost
all the time.

This is reasonable and fully corresponds to the PHP script action
pattern: gather data for quering MySQL, issue prepared query and wait
for results
Taking into account that MySQL is running on another box, PHP is waiting
almost all the time for results.

Yes, and this is certainly what is happening.
You have to remember that “load” is an indication of how many processes are waiting to be
scheduled, and this includes processes that are waiting on I/O.
In this case it looks like PHP isn’t generating a lot of I/O, rather it is
waiting, creating a high load,

Agreed, “load” indicates average number of processes that are running,
runnable or in uninterruptible sleep.
PHP waiting for netwrok responce must be in uninterruptible sleep state,
than (it is must not be running and doubtly runnable).
So, waiting PHP processes can make “load average” very high.

and at the same time, you are running out of PHP processes to handle new requests,

Correct me if I am wrong, but when nginx lacks ready PHP process “11:
Resource temporarily unavailable while connecting to upstream” message
is put into error.log
Have seen plenty of these during initial system setup, but after adding
php-fpm children all goes well: no such messages in logs and no “5xx
error” pages reported by users for a long time.
I am monitoring logs carefully. So I suppose that all is OK with PHP
processes number.

which is why the box slows down.
not sure yet

I’d follow these steps:

  1. check the state of the MySQL server. See if this machine is overloaded.

MySQL box is fine and running, no excessively high load or any type of
slowing down

  1. check MySQL itself. Turn on query logging and see if you have some
    query that’s taking a long time to complete.

There are several queries that can take up to several seconds to
complete, looking into optimizations

  1. take a look at your network to make sure that there isn’t an issue
    there (saturation, packet loss, etc).

Can you give an advice on how to check saturation of the link between
these two boxes?
Boxes are standing close to each other and network transmission looks
like fine as well.

May be I am missing something, but I see the general overview of the
task as following:
Machine A hosts N processes waiting for network reply. (Blocked on
recv(), I assume)
Machine B is a “Black Box”, running something which produces results for
machine A. At the moment it doesn’t matter what it is and how long it
takes to produce a result. Let’s assume time T.
Increasing number of waiting processes on machine A slows it down.
Sounds strange, though. Thought that sleeping process consumes memory
only and doesn’t impact performance. May be it is something related to
task scheduling? Is big number of sleeping process impacts performance
and/or slows down scheduler?

Thanks,
Sessna

Posted at Nginx Forum:

On 12:34 Fri 12 Mar , Sessna wrote:

I am using nginx + php-fpm (quad-core PC) + MySQL (on another PC) and facing an interesting issue:
after some time nginx is running, system “load average” goes up (sometimes up to 30 and even more points) while CPU usage is still less then 30% With such a high load system becomes very slow and unresponsive. Restarting nginx helps, but only for a little while. Any ideas on the matter?

You should check CPU%, Disk IO% and probable look for
operations on the wait queue. sysrec does this on Solaris,
Im working to port the recorder on Linux, FreeBSD.
You should somehow count for yourself:

CPU # usr + sys time across all CPUs

Memory # free RAM. freemem from availrmem

Disk # %busy. r+w times across all Disks

Network # throughput. r+w bytes across all NICs

Saturation,

CPU # threads on the run queue

Memory # scan rate of the page scanner

Disk # operations on the wait queue

Network # errors due to buffer saturation

Load average is a metric which might not really tell you a very useful
image
unless you really know what is means and how to interpret that. Check it
out:

The Pith of Performance: How Long Should My Queue Be?

I would start with:

  • Disk IO, CPU% and look for signs of saturation.
  • cpuplayer (is your machine spending more time in SYS/USER ?)
  • useful to collect longer trends in order to see whats going on

Hope it helps,
Stefan


References:

sysrec:
http://systemdatarecorder.org/recording/recorders.html

cpuplayer:
http://systemdatarecorder.org/cpuplayer/

as already indicated your php-cgi processes are waiting IO completion
from other sources: database backend, other backends if you use. This
might indicate why you have a high percentage of iowait. You gotta
drill down and find whats going on:

  1. webserver - database connection:
    check network link, speed, full duplex
    check TCP/sec: connection ESTABLISHED to understand whats your load
    check TCP/IP settings on Linux, both machines: web and db servers

    Give a try to netstat:
    http://blogs.sun.com/timc/entry/nicstat_the_solaris_and_linux
    it really gives you a picture about your network utilisation.

  2. vmstat: would as well give you an overall picture of cpu/mem
    what does it say on your box: vmstat 1 10 ? Run this as well
    on your DB server.
    check free column
    check si, so

stefan

Stefan P. Wrote:

You should check CPU%, Disk IO% and probable look for
operations on the wait queue. sysrec does this on Solaris,
Im working to port the recorder on Linux, FreeBSD.
You should somehow count for yourself:

I am using sar tool at the moment and unfortunately not that experienced
to migrate SDR from Solaris myself

Here is snippet from sar output for typical situation when the system
slows down:

CPU %user %nice %system %iowait %steal %idle
all 7.92 0.00 7.75 46.93 0.00 37.40
all 8.43 0.00 8.31 48.12 0.00 35.14
all 8.03 0.00 8.01 45.84 0.00 38.12
all 8.39 0.00 8.43 46.48 0.00 36.69
all 9.89 0.11 7.32 54.83 0.00 27.85
all 9.09 0.00 8.87 49.75 0.00 32.30
all 8.96 0.00 9.09 48.89 0.00 33.06
all 10.02 0.00 9.60 51.23 0.00 29.15

  • Disk IO, CPU% and look for signs of saturation.
  • cpuplayer (is your machine spending more time in SYS/USER ?)
  • useful to collect longer trends in order to see whats going on

From this table we can tell that CPU is not completely used, there is about 30% idle, user and system CPU consumptions are almost equal (is it good or bad? what usage ratio is expected?) %iowait looks like high (relatively to other metrics) but I am not quite sure what does it mean.
Does anybody see something leading to slowness in these metrics?

Thanks,
Sessna

Posted at Nginx Forum:

Give a try to netstat:

thanks for advice, looks like very good tool

I meant nicstat. Works on Linux, Solaris.
Probable worth of considering porting this to FreeBSD too.

0 23 1165724 541884 97260 261432 0 0 0 4212 11362 8626 11 8 25 55 0
0 14 1165724 541740 97268 261436 0 0 0 3968 6058 4598 4 4 41 51 0
0 2 1165724 540876 97276 261324 0 0 0 5792 6281 4923 4 5 53 38 0
1 9 1165716 540732 97296 261260 32 0 32 3780 14479 11158 13 9 53 25 0
1 9 1165716 541632 97296 261316 0 0 0 4248 6083 3842 1 3 71 24 0
3 33 1165716 541016 97296 261372 0 0 4 3696 7933 5780 6 9 37 49 0
2 29 1165716 541864 97300 261488 0 0 4 4128 6081 4607 6 5 40 50 0
1 45 1165716 538448 97308 261520 0 0 0 3648 12608 10577 11 7 27 56 0
5 15 1165716 541024 97308 261124 0 0 0 3844 12440 9727 10 9 34 47 0

we have nginx -> php + fastcgi -> db … others
vmstat tells us that there are some processes waiting for IO
, b column, and most likely these are the connections mapped to
the fastcgi process. So nginx passed the requests to the
fcgi process (php-cgi etc…) and then fcgi will have do to
its work.

Could this be a problem of the php/fcgi process(es) running on that
box ? I mean the php-cgi which has nothing to do with the nginx
server. Configuration, settings of the FCGI/PHP module ?

We have about 540Mb free memory and small si activity (there is only one 32K page reading presented in snipped, but actually I’ve seen several more 32K reads). As expected plenty of processes in “uninterraptible sleep” state. Looks like enough free resourses (mem, CPU), but system is very slow. I am beginning to think that processes in “uninterruptible sleep” state are driving system to have scheduling lag. Looks for me like they do not consume CPU, but slows down task scheduler. Can it be an issue?

Good is to have latest patches applied etc. To me this is a good
candidate for
DTrace (Solaris) or SystemTap (linux). Probable check php/cgi settings,
nginx
settings for fcgi, linux kernel patches, if any. As well try to
experiment with
a much smaller application first. See if you observe same thing (good to
have a
test env where you could reproduce these sort of things)

stefan

Stefan P. Wrote:

Give a try to netstat:

thanks for advice, looks like very good tool

  1. vmstat: would as well give you an overall picture of cpu/mem
    what does it say on your box: vmstat 1 10 ?
    Run this as well
    on your DB server.
    check free column
    check si, so

Here is output from vmstat run on both servers:

DB server

procs -----------memory---------- —swap-- -----io---- --system–
-----cpu------
r b swpd free buff cache si so bi bo in cs us sy
id wa st
1 0 12488 581340 401492 176548 0 0 0 52 10550 9003 23 6
66 5 0
4 0 12488 581768 401492 176548 0 0 0 0 10519 8365 18 6
76 0 0
0 2 12488 581520 401492 176552 0 0 0 1716 4211 4028 13 6
62 20 0
0 1 12488 581196 401492 176564 0 0 0 800 1763 1531 0 0
67 33 0
12 0 12488 579464 401504 176612 0 0 44 252 10519 17321 35
12 45 7 0
0 0 12488 583124 401504 176548 0 0 144 0 10094 18755 22
9 65 4 0
7 0 12488 581612 401504 176460 0 0 0 0 10777 8417 9 6
85 0 0
5 0 12488 581712 401504 176460 0 0 0 308 10426 8411 10 5
85 0 0
8 0 12488 584316 401504 176464 0 0 0 0 10515 8168 10 4
86 0 0
0 6 12488 584180 401504 176464 0 0 0 1660 5757 5053 5 4
49 42 0
0 5 12488 584008 401504 176464 0 0 0 1240 1429 1286 0 1
28 72 0
10 1 12488 582048 401504 176464 0 0 8 1512 4903 4918 7 3
43 47 0
4 1 12488 582696 401504 176476 0 0 0 1128 9823 8041 19 8
53 20 0

Plenty of free memory and no swap activity at all

and Web server exactly at the same. Load is very high, system
significantly slowed down.
Load average: 48.14, 63.45, 78.10

procs -----------memory---------- —swap-- -----io---- --system–
-----cpu------
r b swpd free buff cache si so bi bo in cs us sy
id wa st
5 21 1165724 542180 97228 261580 0 0 0 3812 12690 10142 11
9 38 41 0
17 2 1165724 543352 97244 261508 0 0 0 5020 7574 5605 4 5
52 38 0
3 8 1165724 542296 97248 261332 0 0 0 3492 10717 7997 6
7 65 23 0
1 9 1165724 545036 97248 261160 0 0 0 3908 6850 4321 3 5
61 30 0
0 14 1165724 544320 97248 260940 0 0 0 3236 6474 4485 5 5
28 62 0
0 23 1165724 541884 97260 261432 0 0 0 4212 11362 8626 11
8 25 55 0
0 14 1165724 541740 97268 261436 0 0 0 3968 6058 4598 4 4
41 51 0
0 2 1165724 540876 97276 261324 0 0 0 5792 6281 4923 4 5
53 38 0
1 9 1165716 540732 97296 261260 32 0 32 3780 14479 11158 13
9 53 25 0
1 9 1165716 541632 97296 261316 0 0 0 4248 6083 3842 1 3
71 24 0
3 33 1165716 541016 97296 261372 0 0 4 3696 7933 5780 6 9
37 49 0
2 29 1165716 541864 97300 261488 0 0 4 4128 6081 4607 6 5
40 50 0
1 45 1165716 538448 97308 261520 0 0 0 3648 12608 10577 11
7 27 56 0
5 15 1165716 541024 97308 261124 0 0 0 3844 12440 9727 10
9 34 47 0

We have about 540Mb free memory and small si activity (there is only one
32K page reading presented in snipped, but actually I’ve seen several
more 32K reads). As expected plenty of processes in “uninterraptible
sleep” state. Looks like enough free resourses (mem, CPU), but system is
very slow. I am beginning to think that processes in “uninterruptible
sleep” state are driving system to have scheduling lag. Looks for me
like they do not consume CPU, but slows down task scheduler. Can it be
an issue?

Thanks,
Sessna

Posted at Nginx Forum:

On Sun, 2010-03-14 at 05:15 -0400, Sessna wrote:

Cliff W. Wrote:

This means that php-cgi is spending 99.99% of its time in I/O, not that
it’s creating 99.99% of your I/O. It means php-cgi is waiting almost
all the time.

This is reasonable and fully corresponds to the PHP script action pattern: gather data for quering MySQL, issue prepared query and wait for results
Taking into account that MySQL is running on another box, PHP is waiting almost all the time for results.

Well, all it means is that the bottleneck lies outside PHP. I wouldn’t
read too much else into it. It just means that 99% of your slowness is
elsewhere.

and at the same time, you are running out of PHP processes to handle new requests,

Correct me if I am wrong, but when nginx lacks ready PHP process “11: Resource temporarily unavailable while connecting to upstream” message is put into error.log
Have seen plenty of these during initial system setup, but after adding php-fpm children all goes well: no such messages in logs and no “5xx error” pages reported by users for a long time.
I am monitoring logs carefully. So I suppose that all is OK with PHP processes number.

Maybe. Or maybe you’ve simply disguised the problem by throwing more
processes at it. How many PHP processes are you running? Can you
provide your php-fpm parameters? Also, what’s an approximation of your
requests per second during these peak times?

which is why the box slows down.
not sure yet

I’d follow these steps:

  1. check the state of the MySQL server. See if this machine is overloaded.

MySQL box is fine and running, no excessively high load or any type of slowing down

Again, load isn’t always indicative of “speed”. How are you sure it’s
responding quickly? Have you compared the times of queries during
periods of load vs idle times?

  1. check MySQL itself. Turn on query logging and see if you have some
    query that’s taking a long time to complete.

There are several queries that can take up to several seconds to complete, looking into optimizations

Going out on a limb: would it be possible to temporarily replace these
slow queries with something faster? That is, drop the query results
into a table and use that in place of the actual query?

I’d be curious to see the output of iotop on your MySQL server as well.

Machine B is a “Black Box”, running something which produces results
for machine A. At the moment it doesn’t matter what it is and how long
it takes to produce a result. Let’s assume time T.

I cannot possibly fathom how the length of T doesn’t matter. To me
that is probably the single most important data point to investigate.
The entire response time directly depends on T and you say it “doesn’t
matter”?

Increasing number of waiting processes on machine A slows it down.

Why do you think machine A is slow? Machine A waits for machine B and
you blame machine A. I don’t see how you arrive at this conclusion.
To me it seems it could be either machine (or the connection between the
machines) and more testing needs to be done to arrive at such a
conclusion.

I’d be more interested in how T varies as number of sleeping processes
increases.

Sounds strange, though. Thought that sleeping process consumes memory
only and doesn’t impact performance. May be it is something related to
task scheduling? Is big number of sleeping process impacts performance
and/or slows down scheduler?

Not since kernel 2.6, AFAIK. How many processes are we talking about
here?

As an aside, one thing that you mentioned earlier that I was wondering
about: what is writing to the local disk at 3.27MB/s (from iotop
output)?

Cliff

Stefan P. Wrote:

I meant nicstat. Works on Linux, Solaris.
Probable worth of considering porting this to FreeBSD too.

here are latest results from netstat and nicstat tools

netstat -ant | grep ESTABLISHED | egrep ‘:80>’ | wc -l
1157

We can say 1157 HTTP sessions are established (and may be kept alive)

nicstat

Time      Int   rKB/s   wKB/s   rPk/s   wPk/s    rAvs    wAvs %Util 

Sat
10:24:02 lo 0.33 0.33 290.8 290.8 1.16 1.16 0.00
0.00
10:24:02 eth0 0.29 0.79 1183.8 1448.1 0.25 0.56 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:03 lo 153.7 153.7 338.6 338.6 464.7 464.7 0.00
0.00
10:24:03 eth0 1070.9 768.7 3599.4 3987.9 304.7 197.4 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:04 lo 65.22 65.22 191.9 191.9 348.1 348.1 0.00
0.00
10:24:04 eth0 932.5 691.3 3250.8 3437.7 293.7 205.9 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:05 lo 522.5 522.5 687.5 687.5 778.2 778.2 0.00
0.00
10:24:05 eth0 1075.6 988.8 3758.0 4308.4 293.1 235.0 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:06 lo 235.0 235.0 551.9 551.9 436.0 436.0 0.00
0.00
10:24:06 eth0 855.4 857.6 3476.3 3761.2 252.0 233.5 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:07 lo 135.3 135.3 351.9 351.9 393.6 393.6 0.00
0.00
10:24:07 eth0 1021.0 1025.4 3970.6 4591.4 263.3 228.7 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:08 lo 168.1 168.1 492.3 492.3 349.6 349.6 0.00
0.00
10:24:08 eth0 793.6 864.8 3340.2 3875.5 243.3 228.5 0.00
0.00
Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util
Sat
10:24:09 lo 32.88 32.88 78.97 78.97 426.4 426.4 0.00
0.00
10:24:09 eth0 551.1 462.1 2416.2 2461.1 233.6 192.3 0.00
0.00

Good is to have latest patches applied etc. To me
this is a good candidate for DTrace (Solaris) or SystemTap (linux).
getting acquainted with SystemTap, looks like not “5 minutes to learn”
system

Cliff W. Wrote:

I’ve arranged answers regarding to questions grouped by “theme”

Well, all it means is that the bottleneck lies outside PHP.
I wouldn’t read too much else into it.
It just means that 99% of your slowness is elsewhere.

I cannot possibly fathom how the length of T doesn’t matter.
To me that is probably the single most important data point to investigate.
The entire response time directly depends on T and you say it “doesn’t matter”?

Why do you think machine A is slow?
Machine A waits for machine B and you blame machine A.
I don’t see how you arrive at this conclusion.
To me it seems it could be either machine (or the connection between the machines)
and more testing needs to be done to arrive at such a conclusion.

Combined answer on all these questions. Looks like we are talking about
not the same thing in here. You are talking about response time for
network request issued by user. It really consists of several stages of
processing in here. Like

  1. HTTP request handled by nginx
  2. data processing by PHP (provided via CGI interface with php-fpm in my
    case)
  3. external DB request processing (aka T in our discussion)
  4. response to user
    and in this case I totally agree with you - time T does matter and
    directly influences response time.

What I am talking about is a little bit different. In peak hours
response time degrades significantly, but is still more or less
acceptable, but what is unacceptable is that machine A slows down and
replies for external actions (like SSH login, VPN connection) very
slowly. For example, I sometimes even can’t establish VPN connection to
it due to timeouts. (there is openvpn server running on it). That’s why
I am talking about “slow machine A” and blame it. That’s why I am
worried about “uninterruptible sleep” processes and thinking about
scheduling lag

I’d be curious to see the output of iotop on your
MySQL server as well.

here it is:

Total DISK READ: 0.00 B/s | Total DISK WRITE: 0.00 B/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
23144 be/4 mysql 0.00 B/s 19.10 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
880 be/4 mysql 0.00 B/s 11.46 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
1247 be/4 mysql 0.00 B/s 11.46 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
1287 be/4 mysql 0.00 B/s 53.49 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
1305 be/4 mysql 0.00 B/s 22.92 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
7929 be/4 mysql 0.00 B/s 15.28 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
30493 be/4 mysql 0.00 B/s 15.28 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
10222 be/4 mysql 0.00 B/s 7.64 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
1 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % init [3]
2 be/3 root 0.00 B/s 0.00 B/s 0.00 % 0.00 %
3 rt/3 root 0.00 B/s 0.00 B/s 0.00 % 0.00 %

and another sample

Total DISK READ: 0.00 B/s | Total DISK WRITE: 107.53 K/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
709 be/3 root 0.00 B/s 55.62 K/s 0.00 % 45.85 %
4129 be/4 mysql 0.00 B/s 3.71 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
4147 be/4 mysql 0.00 B/s 3.71 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
4233 be/4 mysql 0.00 B/s 7.42 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
4273 be/4 mysql 0.00 B/s 7.42 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
6587 be/4 mysql 0.00 B/s 14.83 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
15008 be/4 mysql 0.00 B/s 3.71 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock
7449 be/4 mysql 0.00 B/s 11.12 K/s 0.00 % 0.00 % mysqld
–basedir=/usr~/lib/mysql/mysql.sock

looks like nothing special for me. MySQL is running, not much I/O

May be it is something related to task scheduling? Is big number of sleeping process impacts performance and/or slows down scheduler?

Not since kernel 2.6, AFAIK. How many processes are we talking about here?
nginx worker_processes 4
php-pfm max_children 1000 total

and system processes of course, but nothing much

Maybe. Or maybe you’ve simply disguised the
problem by throwing more processes at it. How many PHP processes are you
running? Can you provide your php-fpm parameters? Also, what’s an
approximation of your requests per second during these peak times?

2 pools with 500 php-fpm children each and something like 1000-2000
concurrent HTTP sessions

As an aside, one thing that you mentioned earlier that I was wondering
about: what is writing to the local disk at 3.27MB/s (from iotop output)?

Total DISK READ: 0.00 B/s | Total DISK WRITE: 3.56 M/s
TID PRIO USER DISK READ DISK WRITE> SWAPIN IO COMMAND
32722 be/4 nginx 0.00 B/s 207.89 K/s 0.00 % 0.00 % nginx:
worker process
22705 be/4 nobody 0.00 B/s 107.30 K/s 0.00 % 0.00 % php-cgi
–fpm --fpm-config /etc/php-fp
22235 be/4 nobody 0.00 B/s 83.83 K/s 0.00 % 0.00 % php-cgi
–fpm --fpm-config /etc/php-fp
21203 be/4 nobody 0.00 B/s 57.00 K/s 0.00 % 0.00 % php-cgi
–fpm --fpm-config /etc/php-fp
32719 be/4 nginx 0.00 B/s 50.30 K/s 0.00 % 55.19 % nginx:
worker process
32718 be/4 nginx 0.00 B/s 10.06 K/s 0.00 % 0.00 % nginx:
worker process
21195 be/4 nobody 0.00 B/s 3.35 K/s 0.00 % 0.00 % php-cgi
–fpm --fpm-config /etc/php-fp
21327 be/4 nobody 0.00 B/s 3.35 K/s 0.00 % 0.00 % php-cgi
–fpm --fpm-config /etc/php-fp
22189 be/4 nobody 0.00 B/s 3.35 K/s 0.00 % 0.00 % php-cgi
–fpm --fpm-config /etc/php-fp

php-cgi and nginx are writing. php is writing some processed data and
logs. Anyway, is 3.5 M/s is not a big deal for SCSI disk, isn’t it?

By the way here:

is couple of words about slowing down systems with active network IO.

Best regards,
Sessna

Posted at Nginx Forum:

On Tue, 2010-03-16 at 11:53 -0400, Sessna wrote:

What I am talking about is a little bit different. In peak hours
response time degrades significantly, but is still more or less
acceptable, but what is unacceptable is that machine A slows down and
replies for external actions (like SSH login, VPN connection) very
slowly. For example, I sometimes even can’t establish VPN connection
to it due to timeouts. (there is openvpn server running on it). That’s
why I am talking about “slow machine A” and blame it. That’s why I am
worried about “uninterruptible sleep” processes and thinking about
scheduling lag

Ah, I did not gather this from your previous explanations. Yes, this
is much different than what I was attempting to solve.

Have you done any tuning of your system to handle high loads or is this
a default CentOS install?

Cliff

Stefan P. Wrote:

You are talking about a system slowdown caused by your current
workload. This might be caused by a series of things some related
to the kernel. But most likely analysing with SystemTap whats going
on here might help. Thats why I keep telling people DTrace is like a gold mine
or a step in the future. Since you are not on Solaris you need to
start looking into SystemTap. If possible, have a box with Solaris
or FreeBSD next running this workload and check with DTraceToolkit.

I am started paying with SystemTap and FreeBSD is coming next in line.
thanks for advice.

Cliff W. Wrote:

Have you done any tuning of your system to handle
high loads or is this a default CentOS install?

no any patches and only small tuning for FS and Network options

Soft & Hard limits

  •   soft    nofile  1024
    
  •   hard    nofile  65535
    

file descriptor limit
echo 65535 > /proc/sys/fs/file-max
ulimit -n 8192

somaxconn and backlog adjustments
echo 8192 > /proc/sys/net/core/netdev_max_backlog
echo 8192 > /proc/sys/net/core/somaxconn

Best regards,
Sessna

Posted at Nginx Forum:

Time      Int   rKB/s   wKB/s   rPk/s   wPk/s    rAvs    wAvs %Util    Sat

10:24:02 lo 0.33 0.33 290.8 290.8 1.16 1.16 0.00 0.00
10:24:02 eth0 0.29 0.79 1183.8 1448.1 0.25 0.56 0.00 0.00

make sure you run enicstat since Util, Sat are always 0 on Linux if you
dont do that:

"
Added a script, enicstat, which uses ethtool to get speeds and duplex
modes for all interfaces, then calls nicstat with an appropriate -S
value."

http://blogs.sun.com/timc/entry/nicstat_the_solaris_and_linux

What I am talking about is a little bit different. In peak hours response time degrades significantly, but is still more or less acceptable, but what is unacceptable is that machine A slows down and replies for external actions (like SSH login, VPN connection) very slowly. For example, I sometimes even can’t establish VPN connection to it due to timeouts. (there is openvpn server running on it). That’s why I am talking about “slow machine A” and blame it. That’s why I am worried about “uninterruptible sleep” processes and thinking about scheduling lag

You are talking about a system slowdown caused by your current
workload. This might be caused by a series of things some related
to the kernel. But most likely analysing with SystemTap whats going
on here might help. Thats why I keep telling people DTrace is like a
gold mine
or a step in the future. Since you are not on Solaris you need to
start looking into SystemTap. If possible, have a box with Solaris
or FreeBSD next running this workload and check with DTraceToolkit.

Good luck,
stefan

Sessna wrote:

I am using nginx + php-fpm (quad-core PC) + MySQL (on another PC) and
facing an interesting issue:
after some time nginx is running, system “load average” goes up
(sometimes up to 30 and even more points) while CPU usage is still less
then 30% With such a high load system becomes very slow and
unresponsive. Restarting nginx helps, but only for a little while. Any
ideas on the matter?

Thanks,
Sessna

Posted at Nginx Forum:
high "Load Average"

php-fpm has a slow log feature. You can configure it in php-fpm.conf,
and check the php-fpm slow log later. In the slow log, php-fpm will tell
us where are the slow parts of php scripts.

If we see mysql_query(), then it means that sql is slow. We should check
the mysql slow log. May be we can use mysql slow analyse tool to figure
out the slow queries.

If we see file_get_contents(), then it means there is something wrong
with the file system, maybe you are reading files from net file systems
like NFS.

Hope this will help you.

30 0
1 9 1165716 541632 97296 261316 0 0 0 4248 6083 3842 1 3 71
24 0
3 33 1165716 541016 97296 261372 0 0 4 3696 7933 5780 6 9 37
49 0
2 29 1165716 541864 97300 261488 0 0 4 4128 6081 4607 6 5 40
50 0
1 45 1165716 538448 97308 261520 0 0 0 3648 12608 10577 11 7
27 56 0
5 15 1165716 541024 97308 261124 0 0 0 3844 12440 9727 10 9
34 47 0

I don’t think there’s any network problems, it looks much more like your
system is running out of disk IO bandwidth. There’s a continuous stream
of
data being sent to disk (bo). The actual rate (~4000 blocks/s) isn’t
that
high if it’s purely linear write, but my guess is you’re getting quite
a
bit of random IO going on. That’s causing lots of processes to block.

What’s probably also happening is that your sshd and vpn server are
being
swapped out (swapped = 1.1G, free = 540M), so when you try and connect,
they
have to be swapped back in. Because of all the IO being pushed to disk,
the
reads are starved, and swapping them in takes a while, causing your
connections to time out.

Basically the question to answer, why and what are your php processing
writing so much to local disk continuously for?

One thing that can help.

echo 1 > /proc/sys/vm/block_dump; sleep 10; echo 0 >
/proc/sys/vm/block_dump

Then look at:

dmesg | less

And scroll down till you see stuff like:

[20394434.668776] pdflush(320): WRITE block 15744 on sda5
[20394434.668783] pdflush(320): WRITE block 15752 on sda5
[20394434.689927] pdflush(320): WRITE block 15760 on sda5
[20394434.699997] pdflush(320): WRITE block 173474328 on sda5
[20394434.772645] cleanup(32657): dirtied inode 4909405 (55FD14AE95D) on
sda5
[20394434.772674] cleanup(32657): dirtied inode 4909405 (55FD14AE95D) on
sda5
[20394435.567579] nginx(14952): dirtied inode 3215421100 (0000623907) on
tmpfs
[20394435.603644] kjournald(2281): WRITE block 901856 on sda1
[20394435.603687] kjournald(2281): WRITE block 901864 on sda1
[20394435.603696] kjournald(2281): WRITE block 901872 on sda1

And see if you can find out what files the php processes are writing to.

Rob