Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

This system is running Centos 5.8 final using 2.6.18-308.4.1.el5 as a virtual machine on VMware ESXi 5. Standard LAMP install, running three instances of Wordpress.

Server has been running for a couple of years and never had any issues, then today httpd crashed twice with out of memory messages and hoses pretty much everything else in the process with the VM becoming unresponsive.

Here's the top output while the system is still running OK sorted by memory usage:

top - 19:54:19 up  8:05,  1 user,  load average: 0.00, 0.01, 0.03
Tasks:  88 total,   2 running,  86 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   2058780k total,  1037964k used,  1020816k free,    21324k buffers
Swap:  2064376k total,    94756k used,  1969620k free,   633840k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND            
15737 daemon    15   0  244m  35m 4464 S  0.0  1.8   0:03.46 httpd              
16139 daemon    15   0  240m  32m 4044 S  0.0  1.6   0:01.43 httpd              
16182 daemon    15   0  240m  32m 4052 S  0.0  1.6   0:01.13 httpd              
 2517 root      11 -10 38932  32m 1732 S  0.0  1.6   0:00.03 iscsiuio           
16129 daemon    15   0  241m  32m 4444 S  0.0  1.6   0:01.62 httpd              
15926 daemon    15   0  241m  31m 4460 S  0.0  1.6   0:03.28 httpd              
15934 daemon    15   0  240m  31m 4456 S  0.0  1.6   0:02.26 httpd              
16138 daemon    15   0  239m  30m 4456 S  0.0  1.5   0:01.64 httpd              
16194 daemon    15   0  238m  30m 4052 S  0.0  1.5   0:01.14 httpd              
16012 daemon    15   0  239m  30m 4448 S  0.0  1.5   0:01.73 httpd              
16234 daemon    15   0  239m  30m 4516 S  0.0  1.5   0:00.59 httpd              
 3289 mysql     15   0  246m  11m 3160 S  0.0  0.6   0:42.62 mysqld             
 3007 ntp       15   0 23408 5040 3912 S  0.0  0.2   0:00.02 ntpd               
 3066 root      18   0  215m 4584 2736 S  0.0  0.2   0:03.83 httpd              
 3295 root      34  19  253m 3500 1600 S  0.0  0.2   0:00.09 yum-updatesd       
16154 root      15   0 90176 3376 2640 R  0.0  0.2   0:00.10 sshd               
 2524 root       5 -10  5092 3040 1896 S  0.0  0.1   0:00.01 iscsid             
 3068 daemon    19   0  158m 2020  716 S  0.0  0.1   0:00.00 httpd              
 2371 root      15   0  135m 1712 1388 S  0.0  0.1   0:02.25 vmtoolsd           
16156 root      16   0 66092 1608 1204 S  0.0  0.1   0:00.02 bash               
 3122 haldaemo  15   0 31352 1496  992 S  0.0  0.1   0:00.70 hald               
 3029 root      15   0 66964 1160  736 S  0.0  0.1   0:00.05 sendmail           
16246 root      15   0 12744 1088  840 R  0.4  0.1   0:00.21 top                
 2902 dbus      15   0 31516 1024  820 S  0.0  0.0   0:00.01 dbus-daemon        
 3303 root      34  19 12932  956  804 S  0.0  0.0   0:00.08 gam_server         
 2964 root      20   0 54424  816  692 S  0.0  0.0   0:00.02 automount          
 2988 root      15   0 62676  780  580 S  0.0  0.0   0:00.12 sshd               
 3136 haldaemo  22   0 12340  712  712 S  0.0  0.0   0:00.00 hald-addon-keyb

Here's some additional data, output from the error_log, previous apache had an unclean shutdown cause I had to hard reset the server to get it back:

[Tue May 22 08:50:31 2012] [error] cgid daemon process died, restarting
[Tue May 22 08:57:28 2012] [warn] Init: Session Cache is not configured [hint: SSLSessionCache]
[Tue May 22 08:57:28 2012] [notice] suEXEC mechanism enabled (wrapper: /usr/local/apache2/bin/suexec)
[Tue May 22 08:57:28 2012] [notice] Digest: generating secret for digest authentication ...
[Tue May 22 08:57:28 2012] [notice] Digest: done
[Tue May 22 08:57:29 2012] [warn] pid file /usr/local/apache2/logs/httpd.pid overwritten -- Unclean shutdown of previous Apache run?
[Tue May 22 08:57:29 2012] [notice] Apache/2.2.17 (Unix) mod_ssl/2.2.15 OpenSSL/0.9.8e-fips-rhel5 DAV/2 PHP/5.3.6 proxy_html/3.1.2 configured -- resuming normal operations
[Tue May 22 11:11:28 2012] [warn] Init: Session Cache is not configured [hint: SSLSessionCache]
[Tue May 22 11:11:28 2012] [notice] suEXEC mechanism enabled (wrapper: /usr/local/apache2/bin/suexec)
[Tue May 22 11:11:28 2012] [notice] Digest: generating secret for digest authentication ...
[Tue May 22 11:11:28 2012] [notice] Digest: done
[Tue May 22 11:11:29 2012] [warn] pid file /usr/local/apache2/logs/httpd.pid overwritten -- Unclean shutdown of previous Apache run?
[Tue May 22 11:11:29 2012] [notice] Apache/2.2.17 (Unix) mod_ssl/2.2.15 OpenSSL/0.9.8e-fips-rhel5 DAV/2 PHP/5.3.6 proxy_html/3.1.2 configured -- resuming normal operations

The message log output shows some more information but it's not quite clear to me what exactly is causing the out of memory issue:

May 22 08:07:34 web kernel: INFO: task sendmail:2993 blocked for more than 120 seconds.
May 22 08:07:34 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 08:07:34 web kernel: sendmail      D ffff81003fe85cb0     0  2993      1          3002  2971 (NOTLB)
May 22 08:07:34 web kernel:  ffff810036ec5c58 0000000000000082 ffff81002d2111c0 ffff810036ec5c38
May 22 08:07:34 web kernel:  0000000010801040 0000000000000009 ffff81003cdb7080 ffff81003d260820
May 22 08:07:34 web kernel:  0000831e520cfa2f 000000000001562a ffff81003cdb7268 0000000000000009
May 22 08:07:34 web kernel: Call Trace:
May 22 08:07:35 web kernel:  [<ffffffff80130006>] avc_has_perm+0x46/0x58
May 22 08:07:35 web kernel:  [<ffffffff80063c63>] __mutex_lock_slowpath+0x60/0x9b
May 22 08:07:35 web kernel:  [<ffffffff80063cad>] .text.lock.mutex+0xf/0x14
May 22 08:07:35 web kernel:  [<ffffffff8000d047>] do_lookup+0xd1/0x227
May 22 08:07:35 web kernel:  [<ffffffff8000a295>] __link_path_walk+0x9e6/0xf25
May 22 08:07:35 web kernel:  [<ffffffff8000eb23>] link_path_walk+0x45/0xb8
May 22 08:07:43 web kernel:  [<ffffffff8000cdf6>] do_path_lookup+0x294/0x310
May 22 08:07:43 web kernel:  [<ffffffff80130da6>] selinux_file_alloc_security+0x2a/0x54
May 22 08:07:43 web kernel:  [<ffffffff8002380c>] __path_lookup_intent_open+0x56/0x97
May 22 08:07:43 web kernel:  [<ffffffff8001b0e7>] open_namei+0x73/0x6ba
May 22 08:07:43 web kernel:  [<ffffffff800275c8>] do_filp_open+0x1c/0x38
May 22 08:07:43 web kernel:  [<ffffffff80019f9a>] do_sys_open+0x44/0xbe
May 22 08:07:43 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 08:07:43 web kernel: 
May 22 08:09:22 web kernel: INFO: task sendmail:2993 blocked for more than 120 seconds.
May 22 08:09:22 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 08:09:22 web kernel: sendmail      D ffff81003fe85cb0     0  2993      1          3002  2971 (NOTLB)
May 22 08:09:22 web kernel:  ffff810036ec5c58 0000000000000082 ffff81002d2111c0 ffff810036ec5c38
May 22 08:09:22 web kernel:  0000000010801040 0000000000000009 ffff81003cdb7080 ffff81003d260820
May 22 08:09:22 web kernel:  0000831e520cfa2f 000000000001562a ffff81003cdb7268 0000000000000009
May 22 08:09:22 web kernel: Call Trace:
May 22 08:09:22 web kernel:  [<ffffffff80130006>] avc_has_perm+0x46/0x58
May 22 08:09:22 web kernel:  [<ffffffff80063c63>] __mutex_lock_slowpath+0x60/0x9b
May 22 08:09:22 web kernel:  [<ffffffff80063cad>] .text.lock.mutex+0xf/0x14
May 22 08:09:22 web kernel:  [<ffffffff8000d047>] do_lookup+0xd1/0x227
May 22 08:09:22 web kernel:  [<ffffffff8000a295>] __link_path_walk+0x9e6/0xf25
May 22 08:09:22 web kernel:  [<ffffffff8000eb23>] link_path_walk+0x45/0xb8
May 22 08:18:00 web kernel:  [<ffffffff8000cdf6>] do_path_lookup+0x294/0x310
May 22 08:18:38 web kernel:  [<ffffffff80130da6>] selinux_file_alloc_security+0x2a/0x54
May 22 08:18:49 web kernel:  [<ffffffff8002380c>] __path_lookup_intent_open+0x56/0x97
May 22 08:18:53 web kernel:  [<ffffffff8001b0e7>] open_namei+0x73/0x6ba
May 22 08:18:55 web kernel:  [<ffffffff800275c8>] do_filp_open+0x1c/0x38
May 22 08:18:56 web kernel:  [<ffffffff80019f9a>] do_sys_open+0x44/0xbe
May 22 08:18:57 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 08:18:57 web kernel: 
May 22 08:18:58 web kernel: hald-addon-stor invoked oom-killer: gfp_mask=0x201d2, order=0, oomkilladj=0
May 22 08:18:59 web kernel: 
May 22 08:19:01 web kernel: Call Trace:
May 22 08:19:01 web kernel:  [<ffffffff800ca89a>] out_of_memory+0x8e/0x2f3
May 22 08:19:03 web kernel:  [<ffffffff8000f612>] __alloc_pages+0x27f/0x308
May 22 08:19:05 web kernel:  [<ffffffff80012fef>] __do_page_cache_readahead+0x96/0x17b
May 22 08:19:08 web kernel:  [<ffffffff8001392c>] filemap_nopage+0x14c/0x360
May 22 08:19:11 web kernel:  [<ffffffff80008972>] __handle_mm_fault+0x1fd/0x103b
May 22 08:19:14 web kernel:  [<ffffffff80067202>] do_page_fault+0x499/0x842
May 22 08:19:17 web kernel:  [<ffffffff8005a12c>] hrtimer_cancel+0xc/0x16
May 22 08:19:20 web kernel:  [<ffffffff80063cf9>] do_nanosleep+0x47/0x70
May 22 08:19:22 web kernel:  [<ffffffff8005a019>] hrtimer_nanosleep+0x58/0x118
May 22 08:19:26 web kernel:  [<ffffffff8000d543>] dput+0x2c/0x114
May 22 08:19:35 web kernel:  [<ffffffff8005dde9>] error_exit+0x0/0x84
May 22 08:19:39 web kernel: 
May 22 08:19:40 web kernel: Mem-info:
May 22 08:19:43 web kernel: Node 0 DMA per-cpu:
May 22 08:19:45 web kernel: cpu 0 hot: high 0, batch 1 used:0
May 22 08:19:49 web kernel: cpu 0 cold: high 0, batch 1 used:0
May 22 08:19:58 web kernel: Node 0 DMA32 per-cpu:
May 22 08:20:15 web kernel: cpu 0 hot: high 186, batch 31 used:18
May 22 08:20:55 web kernel: cpu 0 cold: high 62, batch 15 used:43
May 22 08:21:01 web kernel: Node 0 Normal per-cpu: empty
May 22 08:25:46 web kernel: Node 0 HighMem per-cpu: empty
May 22 08:42:51 web kernel: Free pages:        6936kB (0kB HighMem)
May 22 08:45:07 web kernel: Active:118447 inactive:107813 dirty:0 writeback:0 unstable:0 free:1734 slab:7139 mapped-file:1180 mapped-anon:227504 pagetables:12490
May 22 08:50:31 web kernel: Node 0 DMA free:2964kB min:36kB low:44kB high:52kB active:0kB inactive:0kB present:9700kB pages_scanned:0 all_unreclaimable? yes
May 22 08:50:32 web kernel: lowmem_reserve[]: 0 994 994 994
May 22 08:50:33 web kernel: Node 0 DMA32 free:3972kB min:4012kB low:5012kB high:6016kB active:473788kB inactive:431252kB present:1018016kB pages_scanned:1721253 all_unreclaimable? yes
May 22 08:50:36 web kernel: lowmem_reserve[]: 0 0 0 0
May 22 08:50:40 web kernel: Node 0 Normal free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
May 22 08:50:42 web kernel: lowmem_reserve[]: 0 0 0 0
May 22 08:50:48 web kernel: Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
May 22 08:57:20 ine syslogd 1.4.1: restart.


May 22 09:47:32 web kernel: INFO: task httpd:4525 blocked for more than 120 seconds.
May 22 09:47:32 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:47:32 web kernel: httpd         D ffff8100355254c0     0  4525   3047          4529  4518 (NOTLB)
May 22 09:47:32 web kernel:  ffff810007d49c78 0000000000000082 0000000000033e8c ffff810007d49c58
May 22 09:47:32 web kernel:  0000000000033e8c 0000000000000009 ffff81001d84f040 ffff81003bc2a7a0
May 22 09:47:32 web kernel:  0000022ec44dacb7 0000000000057fb5 ffff81001d84f228 0000000000000020
May 22 09:47:32 web kernel: Call Trace:
May 22 09:47:32 web kernel:  [<ffffffff80130006>] avc_has_perm+0x46/0x58
May 22 09:47:32 web kernel:  [<ffffffff80063c63>] __mutex_lock_slowpath+0x60/0x9b
May 22 09:47:32 web kernel:  [<ffffffff80063cad>] .text.lock.mutex+0xf/0x14
May 22 09:47:32 web kernel:  [<ffffffff8000d047>] do_lookup+0xd1/0x227
May 22 09:47:32 web kernel:  [<ffffffff8000a295>] __link_path_walk+0x9e6/0xf25
May 22 09:47:32 web kernel:  [<ffffffff8000eb23>] link_path_walk+0x45/0xb8
May 22 09:47:36 web kernel:  [<ffffffff8000cdf6>] do_path_lookup+0x294/0x310
May 22 09:47:37 web kernel:  [<ffffffff80012955>] getname+0x15b/0x1c2
May 22 09:47:37 web kernel:  [<ffffffff800239f8>] __user_walk_fd+0x37/0x4c
May 22 09:47:37 web kernel:  [<ffffffff8003ef35>] vfs_lstat_fd+0x18/0x47
May 22 09:47:38 web kernel:  [<ffffffff8000f5ba>] __alloc_pages+0x227/0x308
May 22 09:47:38 web kernel:  [<ffffffff8002ac36>] sys_newlstat+0x19/0x31
May 22 09:47:38 web kernel:  [<ffffffff80047025>] sys_getcwd+0x1e1/0x1f3
May 22 09:47:38 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 09:47:39 web kernel: 
May 22 09:57:33 web kernel: INFO: task kjournald:523 blocked for more than 120 seconds.
May 22 09:57:33 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:57:33 web kernel: kjournald     D ffff810030977cc0     0   523     14           553   512 (L-TLB)
May 22 09:57:33 web kernel:  ffff81003e45bdd0 0000000000000046 ffff81003795acd0 ffff81003795a190
May 22 09:57:33 web kernel:  0000000000000000 000000000000000a ffff810037ee7080 ffff81001f366040
May 22 09:57:33 web kernel:  000002ac4f6926b0 0000000000000bc7 ffff810037ee7268 000000008008e66d
May 22 09:57:33 web kernel: Call Trace:
May 22 09:57:33 web kernel:  [<ffffffff88033661>] :jbd:journal_commit_transaction+0x173/0x10c2
May 22 09:57:33 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:57:33 web kernel:  [<ffffffff8004ad59>] try_to_del_timer_sync+0x7f/0x88
May 22 09:57:33 web kernel:  [<ffffffff880376a3>] :jbd:kjournald+0xc1/0x213
May 22 09:57:33 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:57:33 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 09:59:34 web kernel:  [<ffffffff880375e2>] :jbd:kjournald+0x0/0x213
May 22 09:59:34 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 09:59:34 web kernel:  [<ffffffff80032632>] kthread+0xfe/0x132
May 22 09:59:34 web kernel:  [<ffffffff8005dfb1>] child_rip+0xa/0x11
May 22 09:59:36 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 09:59:36 web kernel:  [<ffffffff80032534>] kthread+0x0/0x132
May 22 09:59:36 web kernel:  [<ffffffff8005dfa7>] child_rip+0x0/0x11
May 22 09:59:36 web kernel: 
May 22 09:59:36 web kernel: INFO: task crond:3060 blocked for more than 120 seconds.
May 22 09:59:36 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:59:37 web kernel: crond         D ffff81003e5e3200     0  3060      1  4837    3073  3047 (NOTLB)
May 22 09:59:38 web kernel:  ffff810035889de8 0000000000000086 ffff810037b69ff8 0000000000000002
May 22 09:59:38 web kernel:  0000000035889e48 0000000000000009 ffff81003daf5100 ffff8100099b0860
May 22 09:59:38 web kernel:  000002b63c1e3c33 000000000000d704 ffff81003daf52e8 00000000880537b3
May 22 09:59:38 web kernel: Call Trace:
May 22 09:59:38 web kernel:  [<ffffffff80025966>] filldir+0x6a/0xb7
May 22 09:59:38 web kernel:  [<ffffffff88032008>] :jbd:start_this_handle+0x2e9/0x370
May 22 09:59:38 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:38 web kernel:  [<ffffffff8803215a>] :jbd:journal_start+0xcb/0x102
May 22 09:59:38 web kernel:  [<ffffffff88050cfe>] :ext3:ext3_dirty_inode+0x28/0x7b
May 22 09:59:38 web kernel:  [<ffffffff80013d53>] __mark_inode_dirty+0x29/0x16e
May 22 09:59:38 web kernel:  [<ffffffff800258fc>] filldir+0x0/0xb7
May 22 09:59:38 web kernel:  [<ffffffff80035089>] vfs_readdir+0x8c/0xa9
May 22 09:59:38 web kernel:  [<ffffffff80038930>] sys_getdents+0x75/0xbd
May 22 09:59:38 web kernel:  [<ffffffff8002e1f8>] sys_fcntl+0x2d0/0x2dc
May 22 09:59:38 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 09:59:38 web kernel: 
May 22 09:59:38 web kernel: INFO: task mysqld:4602 blocked for more than 120 seconds.
May 22 09:59:38 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:59:38 web kernel: mysqld        D ffff81003e5e3200     0  4602   3148          4603  4601 (NOTLB)
May 22 09:59:38 web kernel:  ffff81003973db88 0000000000000082 ffff81001cd457e0 ffff81003f6c4040
May 22 09:59:38 web kernel:  ffff81001cd457e0 0000000000000007 ffff81001cd457e0 ffff8100356527a0
May 22 09:59:38 web kernel:  000002b9cc62d5f7 0000000000003df9 ffff81001cd459c8 0000000080063002
May 22 09:59:38 web kernel: Call Trace:
May 22 09:59:39 web kernel:  [<ffffffff8006ecd9>] do_gettimeofday+0x40/0x90
May 22 09:59:39 web kernel:  [<ffffffff88032008>] :jbd:start_this_handle+0x2e9/0x370
May 22 09:59:39 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:39 web kernel:  [<ffffffff8803215a>] :jbd:journal_start+0xcb/0x102
May 22 09:59:39 web kernel:  [<ffffffff88050cfe>] :ext3:ext3_dirty_inode+0x28/0x7b
May 22 09:59:39 web kernel:  [<ffffffff80013d53>] __mark_inode_dirty+0x29/0x16e
May 22 09:59:39 web kernel:  [<ffffffff8000c58d>] do_generic_mapping_read+0x347/0x359
May 22 09:59:39 web kernel:  [<ffffffff8000d251>] file_read_actor+0x0/0x159
May 22 09:59:39 web kernel:  [<ffffffff8000c6eb>] __generic_file_aio_read+0x14c/0x198
May 22 09:59:39 web kernel:  [<ffffffff80016eb7>] generic_file_aio_read+0x36/0x3b
May 22 09:59:39 web kernel:  [<ffffffff8000cf39>] do_sync_read+0xc7/0x104
May 22 09:59:39 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:39 web kernel:  [<ffffffff8000b721>] vfs_read+0xcb/0x171
May 22 09:59:39 web kernel:  [<ffffffff800136e6>] sys_pread64+0x50/0x70
May 22 09:59:39 web kernel:  [<ffffffff8005dde9>] error_exit+0x0/0x84
May 22 09:59:39 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 09:59:39 web kernel: 
May 22 09:59:39 web kernel: INFO: task kjournald:523 blocked for more than 120 seconds.
May 22 09:59:39 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:59:39 web kernel: kjournald     D ffff810030977cc0     0   523     14           553   512 (L-TLB)
May 22 09:59:39 web kernel:  ffff81003e45bdd0 0000000000000046 ffff81003795acd0 ffff81003795a190
May 22 09:59:39 web kernel:  0000000000000000 000000000000000a ffff810037ee7080 ffff81001f366040
May 22 09:59:39 web kernel:  000002ac4f6926b0 0000000000000bc7 ffff810037ee7268 000000008008e66d
May 22 09:59:39 web kernel: Call Trace:
May 22 09:59:39 web kernel:  [<ffffffff88033661>] :jbd:journal_commit_transaction+0x173/0x10c2
May 22 09:59:39 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:39 web kernel:  [<ffffffff8004ad59>] try_to_del_timer_sync+0x7f/0x88
May 22 09:59:39 web kernel:  [<ffffffff880376a3>] :jbd:kjournald+0xc1/0x213
May 22 09:59:39 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:39 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 09:59:39 web kernel:  [<ffffffff880375e2>] :jbd:kjournald+0x0/0x213
May 22 09:59:39 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 09:59:39 web kernel:  [<ffffffff80032632>] kthread+0xfe/0x132
May 22 09:59:39 web kernel:  [<ffffffff8005dfb1>] child_rip+0xa/0x11
May 22 09:59:39 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 09:59:39 web kernel:  [<ffffffff80032534>] kthread+0x0/0x132
May 22 09:59:39 web kernel:  [<ffffffff8005dfa7>] child_rip+0x0/0x11
May 22 09:59:39 web kernel: 
May 22 09:59:39 web kernel: INFO: task crond:3060 blocked for more than 120 seconds.
May 22 09:59:39 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:59:39 web kernel: crond         D ffff81003e5e3200     0  3060      1  4837    3073  3047 (NOTLB)
May 22 09:59:39 web kernel:  ffff810035889de8 0000000000000086 ffff810037b69ff8 0000000000000002
May 22 09:59:39 web kernel:  0000000035889e48 0000000000000009 ffff81003daf5100 ffff8100099b0860
May 22 09:59:39 web kernel:  000002b63c1e3c33 000000000000d704 ffff81003daf52e8 00000000880537b3
May 22 09:59:39 web kernel: Call Trace:
May 22 09:59:39 web kernel:  [<ffffffff80025966>] filldir+0x6a/0xb7
May 22 09:59:39 web kernel:  [<ffffffff88032008>] :jbd:start_this_handle+0x2e9/0x370
May 22 09:59:39 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:39 web kernel:  [<ffffffff8803215a>] :jbd:journal_start+0xcb/0x102
May 22 09:59:39 web kernel:  [<ffffffff88050cfe>] :ext3:ext3_dirty_inode+0x28/0x7b
May 22 09:59:39 web kernel:  [<ffffffff80013d53>] __mark_inode_dirty+0x29/0x16e
May 22 09:59:39 web kernel:  [<ffffffff800258fc>] filldir+0x0/0xb7
May 22 09:59:39 web kernel:  [<ffffffff80035089>] vfs_readdir+0x8c/0xa9
May 22 09:59:39 web kernel:  [<ffffffff80038930>] sys_getdents+0x75/0xbd
May 22 09:59:39 web kernel:  [<ffffffff8002e1f8>] sys_fcntl+0x2d0/0x2dc
May 22 09:59:39 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 09:59:40 web kernel: 
May 22 09:59:40 web kernel: INFO: task mysqld:4602 blocked for more than 120 seconds.
May 22 09:59:40 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:59:40 web kernel: mysqld        D ffff81003e5e3200     0  4602   3148          4603  4601 (NOTLB)
May 22 09:59:40 web kernel:  ffff81003973db88 0000000000000082 ffff81001cd457e0 ffff81003f6c4040
May 22 09:59:40 web kernel:  ffff81001cd457e0 0000000000000007 ffff81001cd457e0 ffff8100356527a0
May 22 09:59:40 web kernel:  000002b9cc62d5f7 0000000000003df9 ffff81001cd459c8 0000000080063002
May 22 09:59:40 web kernel: Call Trace:
May 22 09:59:40 web kernel:  [<ffffffff8006ecd9>] do_gettimeofday+0x40/0x90
May 22 09:59:40 web kernel:  [<ffffffff88032008>] :jbd:start_this_handle+0x2e9/0x370
May 22 09:59:40 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:40 web kernel:  [<ffffffff8803215a>] :jbd:journal_start+0xcb/0x102
May 22 09:59:40 web kernel:  [<ffffffff88050cfe>] :ext3:ext3_dirty_inode+0x28/0x7b
May 22 09:59:40 web kernel:  [<ffffffff80013d53>] __mark_inode_dirty+0x29/0x16e
May 22 09:59:42 web kernel:  [<ffffffff8000c58d>] do_generic_mapping_read+0x347/0x359
May 22 09:59:42 web kernel:  [<ffffffff8000d251>] file_read_actor+0x0/0x159
May 22 09:59:42 web kernel:  [<ffffffff8000c6eb>] __generic_file_aio_read+0x14c/0x198
May 22 09:59:42 web kernel:  [<ffffffff80016eb7>] generic_file_aio_read+0x36/0x3b
May 22 09:59:42 web kernel:  [<ffffffff8000cf39>] do_sync_read+0xc7/0x104
May 22 09:59:42 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:42 web kernel:  [<ffffffff8000b721>] vfs_read+0xcb/0x171
May 22 09:59:42 web kernel:  [<ffffffff800136e6>] sys_pread64+0x50/0x70
May 22 09:59:42 web kernel:  [<ffffffff8005dde9>] error_exit+0x0/0x84
May 22 09:59:42 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 09:59:42 web kernel: 
May 22 09:59:42 web kernel: INFO: task mysqld:4745 blocked for more than 120 seconds.
May 22 09:59:42 web kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 22 09:59:42 web kernel: mysqld        D ffff81003e5e3200     0  4745   3148          4752  4744 (NOTLB)
May 22 09:59:42 web kernel:  ffff810020e9bb88 0000000000000082 ffff81001524e860 ffff81003f6c4040
May 22 09:59:42 web kernel:  ffff81001524e860 0000000000000009 ffff81001524e860 ffff81001eed40c0
May 22 09:59:42 web kernel:  000002be52c090ef 00000000000061bd ffff81001524ea48 0000000080063002
May 22 09:59:42 web kernel: Call Trace:
May 22 09:59:42 web kernel:  [<ffffffff8006ecd9>] do_gettimeofday+0x40/0x90
May 22 09:59:42 web kernel:  [<ffffffff88032008>] :jbd:start_this_handle+0x2e9/0x370
May 22 09:59:42 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:42 web kernel:  [<ffffffff8803215a>] :jbd:journal_start+0xcb/0x102
May 22 09:59:42 web kernel:  [<ffffffff88050cfe>] :ext3:ext3_dirty_inode+0x28/0x7b
May 22 09:59:42 web kernel:  [<ffffffff80013d53>] __mark_inode_dirty+0x29/0x16e
May 22 09:59:42 web kernel:  [<ffffffff8000c58d>] do_generic_mapping_read+0x347/0x359
May 22 09:59:42 web kernel:  [<ffffffff8000d251>] file_read_actor+0x0/0x159
May 22 09:59:42 web kernel:  [<ffffffff8000c6eb>] __generic_file_aio_read+0x14c/0x198
May 22 09:59:42 web kernel:  [<ffffffff80016eb7>] generic_file_aio_read+0x36/0x3b
May 22 09:59:42 web kernel:  [<ffffffff8000cf39>] do_sync_read+0xc7/0x104
May 22 09:59:42 web kernel:  [<ffffffff800a34a7>] autoremove_wake_function+0x0/0x2e
May 22 09:59:42 web kernel:  [<ffffffff8000b721>] vfs_read+0xcb/0x171
May 22 09:59:42 web kernel:  [<ffffffff80011d15>] sys_read+0x45/0x6e
May 22 09:59:42 web kernel:  [<ffffffff8005d116>] system_call+0x7e/0x83
May 22 09:59:42 web kernel: 
May 22 10:07:56 web kernel: kthread invoked oom-killer: gfp_mask=0xd0, order=1, oomkilladj=0
May 22 10:07:56 web kernel: 
May 22 10:07:56 web kernel: Call Trace:
May 22 10:07:56 web kernel:  [<ffffffff800ca89a>] out_of_memory+0x8e/0x2f3
May 22 10:07:56 web kernel:  [<ffffffff8000f612>] __alloc_pages+0x27f/0x308
May 22 10:07:56 web kernel:  [<ffffffff80130006>] avc_has_perm+0x46/0x58
May 22 10:07:56 web kernel:  [<ffffffff8002377f>] alloc_page_interleave+0x3f/0x76
May 22 10:07:56 web kernel:  [<ffffffff8003c427>] __get_free_pages+0xe/0x71
May 22 10:07:56 web kernel:  [<ffffffff8001f14f>] copy_process+0xc6/0x15db
May 22 10:07:56 web kernel:  [<ffffffff800a11c3>] alloc_pid+0x228/0x2c4
May 22 10:07:56 web kernel:  [<ffffffff80030f52>] do_fork+0x69/0x1c1
May 22 10:07:56 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 10:32:59 web kernel:  [<ffffffff8005df3d>] kernel_thread+0x81/0xeb
May 22 10:34:45 web kernel:  [<ffffffff800a328f>] keventd_create_kthread+0x0/0xc4
May 22 10:34:45 web kernel:  [<ffffffff80032534>] kthread+0x0/0x132
May 22 10:34:45 web kernel:  [<ffffffff8005dfa7>] child_rip+0x0/0x11
May 22 10:34:45 web kernel:  [<ffffffff800a32ac>] keventd_create_kthread+0x1d/0xc4
May 22 10:34:45 web kernel:  [<ffffffff8004d2d2>] run_workqueue+0x9e/0xfb
May 22 10:34:45 web kernel:  [<ffffffff80049ac2>] worker_thread+0x0/0x122
May 22 10:34:45 web kernel:  [<ffffffff80049bb2>] worker_thread+0xf0/0x122
May 22 10:34:45 web kernel:  [<ffffffff8008ee74>] default_wake_function+0x0/0xe
May 22 10:34:45 web kernel:  [<ffffffff80032632>] kthread+0xfe/0x132
May 22 10:34:45 web kernel:  [<ffffffff8005dfb1>] child_rip+0xa/0x11
May 22 10:34:45May 22 11:11:20 ine syslogd 1.4.1: restart.

Here are some screenshots from the performance logs to show what was happening with the CPU/RAM/IO values. Disk IO is likely due to the swap file filling up and increasing IO load.

VM CPU VM DISK IO VM RAM

If anyone could point me into the right direction on how to fix this it would be much appreciated. Thanks in advance.

share|improve this question
    
Is your system fully patched ? –  drcelus May 23 '12 at 5:41
    
@drcelus last patches were applied via yum-update on Sunday, May 20. Nothing since. –  Reality Extractor May 23 '12 at 6:17
    
Sounds like a denial of service to me. What is on your apache access logs ? –  drcelus May 23 '12 at 8:41
    
@drcelus access logs don't show any unusual activity, also the load of 50k hits, 2k visitors for 5/22 is consistent with most other days –  Reality Extractor May 23 '12 at 18:32
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Browse other questions tagged or ask your own question.