5

Just now I was forced to remotely reboot my CentOS 6.3 system due to a ultra high load (75!) that paralyzed the system. This is a web/mail server that serves a wordpress blog (mySQL + PHP).

Is there any log I can analyze and try to discover what cause that?

This is the email I have received now from the system about the event yesterday:

This is an automated message notifying you that the 5 minute load average on your system is 75.91.
This has exceeded the 10 threshold.

One Minute      - 83.24
Five Minutes    - 75.91
Fifteen Minutes - 39.35

top - 22:25:30 up 122 days,  7:28,  0 users,  load average: 99.14, 80.70, 42.31
Tasks: 298 total,   1 running, 297 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.2%us,  0.5%sy,  0.0%ni, 98.1%id,  0.3%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   1020176k total,   956828k used,    63348k free,     2788k buffers
Swap:  4194296k total,  1391900k used,  2802396k free,    25164k cached

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
   1 root      20   0 19352  448  444 S  0.0  0.0   0:08.27 /sbin/init                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
   2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [kthreadd]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
   3 root      RT   0     0    0    0 S  0.0  0.0   0:09.43 [migration/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   4 root      20   0     0    0    0 S  0.0  0.0   1884:48 [ksoftirqd/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   5 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 [migration/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   6 root      RT   0     0    0    0 S  0.0  0.0   0:06.06 [watchdog/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
   7 root      RT   0     0    0    0 S  0.0  0.0   0:07.81 [migration/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   8 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 [migration/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   9 root      20   0     0    0    0 S  0.0  0.0   7:25.62 [ksoftirqd/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
  10 root      RT   0     0    0    0 S  0.0  0.0   0:04.58 [watchdog/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
  11 root      20   0     0    0    0 S  0.0  0.0   4:48.95 [events/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
  12 root      20   0     0    0    0 S  0.0  0.0   9:13.85 [events/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
  13 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [cgroup]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           
  14 root      20   0     0    0    0 S  0.0  0.0   0:08.21 [khelper]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                          
  15 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [netns]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
  16 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [async/mgr]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
  17 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [pm]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
  18 root      20   0     0    0    0 S  0.0  0.0   0:21.72 [sync_supers]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
  19 root      20   0     0    0    0 S  0.0  0.0   0:20.65 [bdi-default]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
  20 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [kintegrityd/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
  21 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [kintegrityd/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
  22 root      20   0     0    0    0 S  0.0  0.0   5:26.09 [kblockd/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
  23 root      20   0     0    0    0 S  0.0  0.0   0:22.90 [kblockd/1] 

I am not sure if this can help.

Everything appears to be using 0% of CPU...

this is another email...

This is an automated message notifying you that the 5 minute load average on your system is 70.53.
This has exceeded the 10 threshold.

One Minute      - 94.79
Five Minutes    - 70.53
Fifteen Minutes - 32.68

top - 22:23:34 up 122 days,  7:26,  0 users,  load average: 96.88, 74.74, 35.91
Tasks: 283 total,   2 running, 281 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.2%us,  0.5%sy,  0.0%ni, 98.1%id,  0.3%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   1020176k total,   970440k used,    49736k free,     3196k buffers
Swap:  4194296k total,  1249404k used,  2944892k free,    29836k cached

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
6715 apache    20   0  217m 7804 3252 D  1.9  0.8   0:00.28 /usr/sbin/httpd -k start -DSSL                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
6770 apache    20   0  218m 8772 3368 D  1.9  0.9   0:00.28 /usr/sbin/httpd -k start -DSSL                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
6799 apache    20   0  301m 8088 3184 D  1.9  0.8   0:00.14 /usr/sbin/httpd -k start -DSSL                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
7265 root      20   0 15160 1220  808 R  1.9  0.1   0:00.02 /usr/bin/top -c -b -n 1                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
7266 root      20   0 15160 1220  808 R  1.9  0.1   0:00.02 /usr/bin/top -c -b -n 1                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
   1 root      20   0 19352  448  444 S  0.0  0.0   0:08.27 /sbin/init                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
   2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [kthreadd]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
   3 root      RT   0     0    0    0 S  0.0  0.0   0:09.43 [migration/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   4 root      20   0     0    0    0 S  0.0  0.0   1884:48 [ksoftirqd/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   5 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 [migration/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   6 root      RT   0     0    0    0 S  0.0  0.0   0:06.06 [watchdog/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
   7 root      RT   0     0    0    0 S  0.0  0.0   0:07.81 [migration/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   8 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 [migration/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
   9 root      20   0     0    0    0 S  0.0  0.0   7:22.58 [ksoftirqd/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
  10 root      RT   0     0    0    0 S  0.0  0.0   0:04.58 [watchdog/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
  11 root      20   0     0    0    0 S  0.0  0.0   4:48.95 [events/0]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
  12 root      20   0     0    0    0 S  0.0  0.0   9:13.85 [events/1]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
  13 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [cgroup]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           
  14 root      20   0     0    0    0 S  0.0  0.0   0:08.21 [khelper]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                          
  15 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [netns]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
  16 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [async/mgr]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
  17 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [pm]                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
  18 root      20   0     0    0    0 S  0.0  0.0   0:21.72 [sync_supers]                       

Yes, I am using Apache. 75 is the load average saw on top for the last 5 minutes.

  • 1
    Look into /var/log, that's where the logs tend to be. You might get more specific answers if you explain more. For example, 75 what? I'm guessing CPU%? That's not a high load. What server are you using? apache error logs are usually in /var/log/apache2/error.log. – terdon Oct 22 '13 at 23:17
  • 1
    @terdon I assume he meant 75 load average. – jordanm Oct 23 '13 at 2:49
  • 1
    @terdon I strongly doubt this is about cpu%. load is a Unix well known metric. Although with some variations depending on the OS, system load represent the average number of processes competing for CPUs during the last 1, 5 and 15 minutes. – jlliagre Oct 23 '13 at 2:56
  • @jlliagre that's the one reported at the top of top right? I knew it was the last 1,5 and 15 minutes but I thought it was a measure of CPU usage, not the number of processes. Thank you both for clarifying. – terdon Oct 23 '13 at 3:48
  • @terdon, that's indeed the one reported by top, uptime, w and also cat /proc/loadavg on Linux. – jlliagre Oct 23 '13 at 3:51
3

The amount of swap used suggests that swapping might be to blame. The output of vmstat would show this better during the problem scenario.

vmstat 1 30

However, neither top or vmstat are well suited for diagnosing issues after the fact.

My general advice would be to install the sysstat package. This will enable system metrics to be saved periodically and the information can then be retrieved later by sar. Sysstat may be configured for substantial detail, but the default configuration will give you an initial overview over CPU usage, system load, paging and swapping.

yum install sysstat

sar 
sar -q
sar -B
sar -W

If this reveals little of use, you may need to look deeper, however. Something may be going on that is not immediately visible through the common performance metrics, other than the process queue (load average). One possibility is that the CPU is preoccupied with excessive interrupt requests, causing processes to queue up for what little processing time remains available to the system.

If that is the case, you may be able to find some clues in /proc/interrupts

cat /proc/interrupts

Perhaps network adapters or the local timer show an unusually high number of interrupts?

It may come down to familiarizing yourself with perf and waiting for the next occurrence of the problem. Start recording once the trouble starts, or automate the process with a script that triggers on high load average.

perf record -a

perf report

Perf provides an incredibly detailed view of operations on the system, but also collects a lot of data and causes significant overhead, making it impractical to have it running continuously.

In the case of CentOS 6.3 there is a chance that mysterious high load averages will go away with an upgrade to CentOS 6.4, which resolves a bug in the kernel source that relates to the local timer. However, your problem could just as well be caused by any given driver that may have been provided by your hardware vendor.

1

Unless you have some system monitoring in place with logging, it is hard to tell what explains a high system load afterwards.

A common cause of performance drop is thrashing due to RAM exhaution.

On most Unix systems, thrashing doesn't lead to a high load but Linux does account processes waiting for I/O in this metric so that might be the case here.

0

To figure out which processes are a problem:

Run top -H (the -H enables showing threads)

The keyboard shortcuts vary by version.

With older top (before 3.3?):

Press Shift+o to bring up the sort options.
Then w to sort by process status.
Then Enter to go back to the main page.
Then Shift + R to reverse the sorting.

With newer top (3.3? and after):

Press f to bring up the field options.
Use the arrow keys to go to S = Process Status and press s.
Press q to go back to the main page.
Press Shift + R to reverse the sorting.

Then in the S column, look for processes which have D or R (they should now be at the top). These will be processes contributing to system load.

If the process shows a D, that means "uninterruptable sleep". Usually this is caused when the process is waiting on I/O (disk, network, etc).
If the process shows a R, that means it's just doing normal computation.


To find more about what those processes are doing:

With older top:

Press f then y to enable the WCHAN field.

With newer top:

Press f to bring up the field options.
Use the arrow keys to go to WCHAN = Sleeping in Function and press d to enable it.
Then q to get back to the main page.

If your system has the necessary kernel options, and the wchan file is present on your system (I forget where it is and what it's called), the WCHAN field should show you what kernel function the process is currently running (if the field just shows a - or a ? on everything, you don't have support).
A bit of google here and you should be on your way.

If you don't have wchan support, you can always try an strace on the processes to find out what they're doing, but that's the difficult way.

  • 1
    The question looks to be about investigating a load issue afterwards from logs, not while it happens with monitoring commands. – jlliagre Oct 23 '13 at 5:57

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.