Causes of high runq-sz and cswch/s output from sar

Hi folks,

I'm running RHEL4 (2.6.9 - 64 bit) on a 4 CPU Dual Core Xeon. This server is running DB2 database. I've been getting the following readings from sar over the past week:

09:35:01 AM   cswch/s
09:40:01 AM   4774.95
09:45:01 AM  27342.76
09:50:02 AM 196015.02
09:55:01 AM 337021.92
10:00:01 AM 347007.79
10:05:01 AM 309210.99
10:10:01 AM 308174.09
10:15:01 AM 350074.07
10:20:01 AM 350716.36
10:25:01 AM 329279.95
10:30:02 AM 319551.01
10:35:01 AM 312952.02
10:40:01 AM 130142.16
10:45:01 AM   6056.06
10:50:01 AM   5131.25
09:35:01 AM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15
09:40:01 AM         5      1156      7.31      6.63      6.69
09:45:01 AM        29      1190     29.53     15.30      9.89
09:50:02 AM        45      1298     58.97     39.22     21.26
09:55:01 AM       117      1323     85.29     67.64     38.24
10:00:01 AM        71      1332     70.71     76.38     50.85
10:05:01 AM        96      1286     58.03     65.37     53.27
10:10:01 AM       105      1316     77.59     70.25     58.42
10:15:01 AM       136      1334     97.88     82.74     66.72
10:20:01 AM        70      1308     80.77     84.55     72.34
10:25:01 AM        86      1308     77.55     81.79     74.77
10:30:02 AM       177      1327    121.49    100.03     83.81
10:35:01 AM        95      1334    135.49    118.93     95.86
10:40:01 AM        10      1212     14.40     71.86     84.11

The context switching and run queue length values stick out like a sore thumb. However, the CPU load at that time is normal although slightly alleviated:

09:40:01 AM       all     58.65      0.00      1.81      0.16     39.38
09:45:01 AM       all     72.99      0.00      2.44      0.27     24.30
09:50:02 AM       all     53.78      0.00      6.21      1.19     38.82
09:55:01 AM       all     45.99      0.00      9.12      0.75     44.14
10:00:01 AM       all     46.96      0.00      9.25      0.76     43.02
10:05:01 AM       all     42.43      0.00      9.36      2.05     46.16
10:10:01 AM       all     47.45      0.00      8.60      0.38     43.56
10:15:01 AM       all     45.64      0.00      9.17      0.34     44.84
10:20:01 AM       all     44.27      0.00      8.69      0.62     46.43
10:25:01 AM       all     45.23      0.00      9.04      0.73     45.00
10:30:02 AM       all     57.97      0.00      9.27      0.08     32.68
10:35:01 AM       all     61.81      0.00      9.62      0.09     28.48
10:40:01 AM       all     66.45      0.00      6.24      0.21     27.11
10:45:01 AM       all     45.15      0.00      2.41      0.28     52.16
10:50:01 AM       all     33.64      0.00      2.05      0.23     64.08
10:55:01 AM       all     39.24      0.00      3.27      0.27     57.22
11:00:01 AM       all     49.34      0.00      4.09      0.22     46.35
11:05:01 AM       all     42.20      0.00      2.45      0.32     55.02
11:10:01 AM       all     35.33      0.00      2.14      0.20     62.33
11:15:01 AM       all     33.07      0.00      2.31      0.24     64.38
11:20:01 AM       all     35.54      0.00      4.20      0.21     60.05
11:25:01 AM       all     34.20      0.00      2.02      0.16     63.61
11:30:01 AM       all     31.26      0.00      1.79      0.17     66.78
11:35:01 AM       all     36.21      0.00      2.88      0.14     60.76

I've checked on any long running queries, but there seems to be none. My question is how can I find the cause of the high system usage? Is it possible to pinpoint the process(es) which is causing the issue?

Thanks!

It's probally IO related.

does "ps aux" give processes in de "D" state?

Don't know about processes in "D" state. Will have to run top in batch mode to find out when it happens again. Does context switching relate to IO functions?

I/O may cause a process to lose current context. ie. switch context.

What I/O scheduler are you using: AS, CFQ?

If your %iowait is high try increasing quantum.

It is possible to see 100% iowait. What iowait really measures is the percent of time at least one process is in an iowait state. I would bet your system shows a high values during the context switch rush.

cfq is able to dedicate a time slice to each process that uses a block device. You can adjust the time slice. Consider looking into that.

Since you are not incurring a cpu hit, all you are doing is increasing wasted cpu time in context switches. Rather than something more useful. IMO.

How do I find out which I/O scheduler in Linux?

Edit: Scratch that. Just Googled it... Thankx.

as, cfq, deadline, and noop are the four choices, AFIAK right now

/sys/block/$devicename/queue/scheduler for each device has one of those values. Supposedly you can place another value into the "file"

echo  "noop" > /sys/block/$devicename/queue/scheduler

and thereby change the behavior of a running kernel. ..... where $devicename is the name of a block device like /dev/sda1

"elevator" is the kernel parameter used to control this at boot time.

I HAVE NEVER done this; be careful.

That sounds risky as I've never tweak this setting before in any of the servers as well :slight_smile: Will I be able to determine which process is causing the high context switching by using top in batch mode when the switching occurs?

What do you get for memory and swap utilisation? The very high run queue suggests you are short of cpu capacity or that the system is busy doing something else.
Please post:
sar -r

Here's the output of sar -r from the same time:

09:35:01 AM kbmemfree kbmemused  %memused kbbuffers  kbcached kbswpfree kbswpused  %swpused  kbswpcad
09:40:01 AM  15046056  17858708     54.27    137752  15462864   2005980     25628      1.26       196
09:45:01 AM  14860936  18043828     54.84    138352  15470012   2005980     25628      1.26       196
09:50:02 AM  14353048  18551716     56.38    139012  15489608   2005992     25616      1.26       196
09:55:01 AM  14272048  18632716     56.63    139600  15501472   2006020     25588      1.26       320
10:00:01 AM  14387000  18517764     56.28    140240  15504280   2006024     25584      1.26       320
10:05:01 AM  14653488  18251276     55.47    140984  15517036   2006024     25584      1.26       320
10:10:01 AM  14488416  18416348     55.97    141656  15526200   2006024     25584      1.26       320
10:15:01 AM  14264888  18639876     56.65    142316  15544148   2006024     25584      1.26       320
10:20:01 AM  14396136  18508628     56.25    142848  15553436   2006028     25580      1.26       320
10:25:01 AM  14420704  18484060     56.17    143532  15561912   2006036     25572      1.26       312
10:30:02 AM  14178392  18726372     56.91    144132  15570408   2006036     25572      1.26       312
10:35:01 AM  13993760  18911004     57.47    144772  15587536   2006036     25572      1.26       312
10:40:01 AM  14934640  17970124     54.61    145440  15578360   2006036     25572      1.26       312
10:45:01 AM  15290560  17614204     53.53    146004  15577968   2006040     25568      1.26       312
10:50:01 AM  15269904  17634860     53.59    146548  15569016   2006044     25564      1.26       312
10:55:01 AM  15448048  17456716     53.05    147112  15356484   2006044     25564      1.26       312
11:00:01 AM  15422928  17481836     53.13    147708  15347760   2006044     25564      1.26       312
11:05:01 AM  15387928  17516836     53.23    148312  15355560   2006048     25560      1.26       312
11:10:01 AM  15151440  17753324     53.95    149036  15575784   2006048     25560      1.26       312
11:15:01 AM  15128528  17776236     54.02    149564  15582804   2006048     25560      1.26       312
11:20:01 AM  15117632  17787132     54.06    150096  15581448   2006048     25560      1.26       312
11:25:01 AM  15101384  17803380     54.11    150624  15588716   2006048     25560      1.26       312
11:30:01 AM  15078216  17826548     54.18    151084  15593972   2006052     25556      1.26       312