High load but low cpu usage

performancetop

top shows extreme high load, but cpu usage is relatively low. High load is consequence of many (~30) processes, started with niceness level of 15, so system is responsive.

top - 18:51:04 up 28 days, 16:30,  5 users,  load average: 254.30, 267.54, 265.42
Tasks: 421 total,  15 running, 406 sleeping,   0 stopped,   0 zombie
%Cpu(s): 14.4 us,  7.6 sy, 76.7 ni,  1.0 id,  0.0 wa,  0.0 hi,  0.3 si,  0.0 st
KiB Mem:  98940592 total, 98165984 used,   774616 free,  1577264 buffers
KiB Swap: 10059673+total,   659128 used, 99937600 free. 56868984 cached Mem

PID   USER  PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                              
49138 root  20   0  0.226t 0.025t 0.012t S 152.4 26.9   9192:51 java                                                                                 
15617 root  35  15 3821500 2.122g  16820 R  96.5  2.2 476:47.21 run_proc                                                                             
30440 root  35  15 5654432 200788  22960 S  82.6  0.2  18:49.65 run_proc                                                                  
37970 root  35  15 4706700 173912  18268 R  82.0  0.2   2241:08 run_proc                                                                  
45289 root  35  15 3723844 187600   8880 R  80.3  0.2   2142:22 run_proc                                                                  
11930 root  35  15  986632 150748  15836 R  52.2  0.2  31:06.74 run_proc                                                                         
 9921 root  35  15 2020804 105872   4812 S  24.8  0.1   2369:07 app                                                                              
30500 root  35  15 1455168 109312   7172 S  21.8  0.1 619:19.67 app                                                                              
 9963 root  35  15 3011908 144264  16804 S  21.2  0.1 282:59.01 run_proc                                                                  
24406 root  35  15 1989336  41164   3800 S  18.5  0.0 447:19.64 app                                                                              
46617 root  35  15 4159848 144072  17428 S  17.5  0.1 277:42.93 run_proc                                                                  
11280 root  35  15 4160060 148816  17484 S  16.9  0.2 283:00.52 run_proc                                                                  
24409 root  35  15 4889308 154020  17816 S  15.9  0.2 295:25.44 run_proc                                                                  
45562 root  35  15 3011940 148496  16860 S  15.9  0.2 286:21.70 run_proc                                                                  
22428 root  35  15 4422012 144080  17440 S  14.5  0.1 280:29.95 run_proc                                                                  
41371 root  35  15 1532440 206976  14208 S  13.6  0.2 291:10.54 app                                                                              
44285 root  35  15 5157436 162172  17904 R  13.6  0.2 298:19.36 run_proc                                                                  
 3793 root  35  15 4421984 150392  17432 S  12.6  0.2 293:43.98 run_proc                                                                  
41325 root  35  15 4553164 149596  17460 S  12.6  0.2 292:41.16 run_proc                                                                  
 2571 root  35  15 3011924 144388  16804 S  12.2  0.1 286:04.91 run_proc                                                                  
 4707 root  35  15 3011924 142384  16832 S  12.2  0.1 283:09.38 run_proc                                                                  
33573 root  35  15 4159992 144296  17432 R  12.2  0.1 282:51.66 run_proc                                                                  
42805 root  35  15 3011900 146272  16800 S  12.2  0.1 275:29.13 run_proc                                                                  
47365 root  35  15 4889804 154008  17740 R  12.2  0.2 286:58.69 run_proc                                                                  
33670 root  35  15 4159452 147980  17464 S  10.9  0.1 284:35.61 run_proc                                                                  
 1316 root  35  15 2100388 187292  12700 S  10.6  0.2 403:51.63 app                                                                              
35410 root  35  15 4295312 153696  18072 R  10.6  0.2 288:10.70 run_proc                                                                  
39749 root  35  15 4356064 152000  17436 R  10.6  0.2 284:17.87 run_proc                                                                  
12727 root  35  15 3011940 150384  16832 S   9.6  0.2 276:58.67 run_proc                                                                  
  484 root  35  15 4421584 149924  17432 S   9.3  0.2 275:11.69 run_proc                                                                  
10099 root  35  15 5085108 158916  17784 S   9.3  0.2 296:36.48 run_proc                                                                  
17062 root  35  15 4356448 144248  17432 S   8.9  0.1 281:26.88 run_proc                                                                  
20880 root  35  15 4291720 144784  17432 S   8.6  0.1 282:45.64 run_proc

“`

What I don't really understand is why is cpu usage so low? I mean, if there are so many processes in run queue, why cpus are not execute them instead of being idle? What I expect here is cpu usage of 1200% (system has 12 cpu cores). As you can notice, there is no heavy I/O utilization here.

root@~# iostat -d -x
Linux 3.13.0-119-generic (server)   11/20/17    _x86_64_    (12 CPU)

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.16    40.12   28.82   75.55  1176.18  2775.77    75.73     0.49    4.72    5.41    4.46   0.38   3.97

It's also worth mentioning that each of those run_proc processes creates ~30 threads, most of them in S state:

root@d:~# top -H -p 46660

  PID USER  PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
48563 root  35  15 3011912 138636  13156 R  3.7  0.1 339:33.64 run_proc
48309 root  35  15 3011912 138636  13156 R  0.7  0.1   1:35.97 run_proc
48281 root  35  15 3011912 138636  13156 S  0.3  0.1   1:35.50 run_proc
48294 root  35  15 3011912 138636  13156 R  0.3  0.1   1:35.70 run_proc
46660 root  35  15 3011912 138636  13156 R  0.0  0.1   0:40.41 run_proc
46959 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46960 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46961 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46962 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46963 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46964 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46965 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
46966 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
47717 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
48254 root  35  15 3011912 138636  13156 R  0.0  0.1   1:36.84 run_proc
48270 root  35  15 3011912 138636  13156 R  0.0  0.1   1:35.32 run_proc
48271 root  35  15 3011912 138636  13156 R  0.0  0.1   1:35.54 run_proc
48272 root  35  15 3011912 138636  13156 S  0.0  0.1   1:38.97 run_proc
48278 root  35  15 3011912 138636  13156 S  0.0  0.1   1:35.45 run_proc
48279 root  35  15 3011912 138636  13156 R  0.0  0.1   1:36.43 run_proc
48286 root  35  15 3011912 138636  13156 R  0.0  0.1   1:37.92 run_proc
48296 root  35  15 3011912 138636  13156 R  0.0  0.1   1:37.09 run_proc
48297 root  35  15 3011912 138636  13156 S  0.0  0.1   1:35.84 run_proc
48298 root  35  15 3011912 138636  13156 S  0.0  0.1   1:38.47 run_proc
48312 root  35  15 3011912 138636  13156 S  0.0  0.1   1:37.07 run_proc
48317 root  35  15 3011912 138636  13156 R  0.0  0.1   1:36.06 run_proc
48323 root  35  15 3011912 138636  13156 S  0.0  0.1   1:37.90 run_proc
48360 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
48362 root  35  15 3011912 138636  13156 S  0.0  0.1   0:09.49 run_proc
48445 root  35  15 3011912 138636  13156 S  0.0  0.1   0:40.89 run_proc
48447 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
48448 root  35  15 3011912 138636  13156 S  0.0  0.1   0:00.00 run_proc
48559 root  35  15 3011912 138636  13156 S  0.0  0.1   0:22.75 run_proc
48560 root  35  15 3011912 138636  13156 S  0.0  0.1   0:05.26 run_proc
48561 root  35  15 3011912 138636  13156 S  0.0  0.1   0:22.78 run_proc
48562 root  35  15 3011912 138636  13156 S  0.0  0.1   0:23.02 run_proc

Best Answer

As noted in the comments, in this particular case the catch was: the CPU utilization is reported as several numbers - 14.4 us, 7.6 sy, 76.7 ni. Quoting from "What does 'nice' mean on CPU utilization graphs?" -

  • %user: Percentage of CPU utilization that occurred while executing at the user level (application).
  • %nice: Percentage of CPU utilization that occurred while executing at the user level with nice priority.
  • %system: Percentage of CPU utilization that occurred while executing at the system level (kernel).

The "nice priority" usage, which was high in this particular case, indicates "the % of CPU time occupied by user level processes with a positive nice value (lower scheduling priority -- see man nice for details)".


If you encounter high load with low total CPU utilization, remember that "load average" on Linux includes any tasks in the uninterruptible state (there are many reasons for a task to be in that state, such as waiting for I/O) - see this serverfault Q&A for a few short explanations or, if you want to take a deep dive, read through "Linux Load Averages: Solving the Mystery" by Brendan Gregg.

Also relevant: High Load Average with modest CPU Utilization and almost no IO on serverfault.

Related Question