Fwd: OOM Kernel messages

"Kirk Bauer" <[email protected]>
Newsgroups gmane.comp.log.logwatch.devel
Message-ID <[email protected]>
---------- Forwarded message ----------
From: Orion Poplawski <[email protected]>
Date: Feb 4, 2008 1:44 PM
Subject: OOM Kernel messages
To: [email protected]


The attached patch handles out of memory killer kernel messages.

oom-killer messages are like:



Feb  3 11:50:07 coop00 kernel: automount invoked oom-killer:
gfp_mask=0x201d2, order=0, oo
mkilladj=0
Feb  3 11:50:07 coop00 kernel:
Feb  3 11:50:07 coop00 kernel: Call Trace:
Feb  3 11:50:07 coop00 kernel:  [<ffffffff800ba4fe>]
out_of_memory+0x53/0x267
Feb  3 11:50:07 coop00 kernel:  [<ffffffff8009b728>]
autoremove_wake_function+0x0/0x2e
Feb  3 11:50:07 coop00 kernel:  [<ffffffff8000f012>]
__alloc_pages+0x229/0x2b2
Feb  3 11:50:07 coop00 kernel:  [<ffffffff80012685>]
__do_page_cache_readahead+0x95/0x1d9
Feb  3 11:50:07 coop00 kernel:  [<ffffffff8003d0c1>]
lock_timer_base+0x1b/0x3c
Feb  3 11:50:07 coop00 kernel:  [<ffffffff80048de8>]
try_to_del_timer_sync+0x51/0x5a
Feb  3 11:50:07 coop00 kernel:  [<ffffffff80013000>]
filemap_nopage+0x148/0x322
Feb  3 11:50:07 coop00 kernel:  [<ffffffff800087e0>]
__handle_mm_fault+0x1f8/0xdf2
Feb  3 11:50:07 coop00 kernel:  [<ffffffff80064617>]
do_page_fault+0x4b8/0x81d
Feb  3 11:50:07 coop00 kernel:  [<ffffffff8005bea5>] error_exit+0x0/0x84
Feb  3 11:50:07 coop00 kernel:
Feb  3 11:50:07 coop00 kernel: Mem-info:
Feb  3 11:50:07 coop00 kernel: Node 0 DMA per-cpu:
Feb  3 11:50:07 coop00 kernel: cpu 0 hot: high 0, batch 1 used:0
Feb  3 11:50:07 coop00 kernel: cpu 0 cold: high 0, batch 1 used:0
Feb  3 11:50:07 coop00 kernel: cpu 1 hot: high 0, batch 1 used:0
Feb  3 11:50:07 coop00 kernel: cpu 1 cold: high 0, batch 1 used:0
Feb  3 11:50:07 coop00 kernel: Node 0 DMA32 per-cpu:
Feb  3 11:50:07 coop00 kernel: cpu 0 hot: high 186, batch 31 used:35
Feb  3 11:50:07 coop00 kernel: cpu 0 cold: high 62, batch 15 used:49
Feb  3 11:50:07 coop00 kernel: cpu 1 hot: high 186, batch 31 used:0
Feb  3 11:50:07 coop00 kernel: cpu 1 cold: high 62, batch 15 used:0
Feb  3 11:50:07 coop00 kernel: Node 0 Normal per-cpu:
Feb  3 11:50:07 coop00 kernel: cpu 0 hot: high 186, batch 31 used:41
Feb  3 11:50:07 coop00 kernel: cpu 0 cold: high 62, batch 15 used:51
Feb  3 11:50:07 coop00 kernel: cpu 1 hot: high 186, batch 31 used:0
Feb  3 11:50:07 coop00 kernel: cpu 1 cold: high 62, batch 15 used:0
Feb  3 11:50:07 coop00 kernel: Node 0 HighMem per-cpu: empty
Feb  3 11:50:07 coop00 kernel: Node 1 DMA per-cpu: empty
Feb  3 11:50:07 coop00 kernel: Node 1 DMA32 per-cpu: empty
Feb  3 11:50:07 coop00 kernel: Node 1 Normal per-cpu:
Feb  3 11:50:07 coop00 kernel: cpu 0 hot: high 186, batch 31 used:0
Feb  3 11:50:07 coop00 kernel: cpu 0 cold: high 62, batch 15 used:0
Feb  3 11:50:07 coop00 kernel: cpu 1 hot: high 186, batch 31 used:123
Feb  3 11:50:07 coop00 kernel: cpu 1 cold: high 62, batch 15 used:14
Feb  3 11:50:07 coop00 kernel: Node 1 HighMem per-cpu: empty
Feb  3 11:50:07 coop00 kernel: Free pages:       32016kB (0kB HighMem)
Feb  3 11:50:07 coop00 kernel: Active:1240425 inactive:1240057 dirty:0
writeback:0 unstabl
e:0 free:8004 slab:5410 mapped:647 pagetables:11714
Feb  3 11:50:07 coop00 kernel: Node 0 DMA free:11288kB min:12kB low:12kB
high:16kB active:
0kB inactive:0kB present:10900kB pages_scanned:0 all_unreclaimable? yes
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 3960 5980 5980
Feb  3 11:50:07 coop00 kernel: Node 0 DMA32 free:13056kB min:5056kB
low:6320kB high:7584kB
  active:1887908kB inactive:1887004kB present:4055200kB
pages_scanned:7715349 all_unreclaim
able? yes
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 2020 2020
Feb  3 11:50:07 coop00 kernel: Node 0 Normal free:2556kB min:2580kB
low:3224kB high:3868kB
  active:1026576kB inactive:1023136kB present:2068480kB
pages_scanned:3924125 all_unreclaim
able? yes
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 0 0
Feb  3 11:50:07 coop00 kernel: Node 0 HighMem free:0kB min:128kB
low:128kB high:128kB acti
ve:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 0 0
Feb  3 11:50:07 coop00 kernel: Node 1 DMA free:0kB min:0kB low:0kB
high:0kB active:0kB ina
ctive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 4040 4040
Feb  3 11:50:07 coop00 kernel: Node 1 DMA32 free:0kB min:0kB low:0kB
high:0kB active:0kB i
nactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 4040 4040
Feb  3 11:50:07 coop00 kernel: Node 1 Normal free:5116kB min:5160kB
low:6448kB high:7740kB
  active:2047216kB inactive:2050088kB present:4136960kB
pages_scanned:8554171 all_unreclaim
able? yes
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 0 0
Feb  3 11:50:07 coop00 kernel: Node 1 HighMem free:0kB min:128kB
low:128kB high:128kB acti
ve:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 0 0
Feb  3 11:50:07 coop00 kernel: Node 0 DMA: 4*4kB 5*8kB 4*16kB 5*32kB
4*64kB 2*128kB 3*256k
B 1*512kB 1*1024kB 0*2048kB 2*4096kB = 11288kB
Feb  3 11:50:07 coop00 kernel: Node 0 DMA32: 4*4kB 0*8kB 1*16kB 1*32kB
1*64kB 1*128kB 0*25
6kB 1*512kB 0*1024kB 0*2048kB 3*4096kB = 13056kB
Feb  3 11:50:07 coop00 kernel: Node 0 Normal: 19*4kB 2*8kB 0*16kB 1*32kB
0*64kB 1*128kB 3*
256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 2556kB
Feb  3 11:50:07 coop00 kernel: Node 0 HighMem: empty
Feb  3 11:50:07 coop00 kernel: Node 1 DMA: empty
Feb  3 11:50:07 coop00 kernel: Node 1 DMA32: empty
Feb  3 11:50:07 coop00 kernel: Node 1 Normal: 1*4kB 1*8kB 1*16kB 1*32kB
1*64kB 1*128kB 5*2
56kB 1*512kB 1*1024kB 1*2048kB 0*4096kB = 5116kB
Feb  3 11:50:07 coop00 kernel: Node 1 HighMem: empty
Feb  3 11:50:07 coop00 kernel: Swap cache: add 16681225, delete
16681005, find 3167567/369
1900, race 1+3
Feb  3 11:50:07 coop00 kernel: Free swap  = 0kB
Feb  3 11:50:07 coop00 kernel: Total swap = 10482404kB
Feb  3 11:50:07 coop00 kernel: Free swap:            0kB
Feb  3 11:50:07 coop00 kernel: 2621440 pages of RAM
Feb  3 11:50:07 coop00 kernel: 108973 reserved pages
Feb  3 11:50:07 coop00 kernel: 7048 pages shared
Feb  3 11:50:07 coop00 kernel: 220 pages swap cached
Feb  3 11:50:07 coop00 kernel: Out of memory: Killed process 10056
(wrf.exe).
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 4040 4040
Feb  3 11:50:07 coop00 kernel: Node 1 Normal free:5116kB min:5160kB
low:6448kB high:7740kB
  active:2059500kB inactive:2037812kB present:4136960kB
pages_scanned:9326724 all_unreclaim
able? yes
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 0 0
Feb  3 11:50:07 coop00 kernel: Node 1 HighMem free:0kB min:128kB
low:128kB high:128kB acti
ve:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  3 11:50:07 coop00 kernel: lowmem_reserve[]: 0 0 0 0
Feb  3 11:50:07 coop00 kernel: Node 0 DMA: 4*4kB 5*8kB 4*16kB 5*32kB
4*64kB 2*128kB 3*256k
B 1*512kB 1*1024kB 0*2048kB 2*4096kB = 11288kB
Feb  3 11:50:07 coop00 kernel: Node 0 DMA32: 4*4kB 0*8kB 1*16kB 1*32kB
1*64kB 1*128kB 0*25
6kB 1*512kB 0*1024kB 0*2048kB 3*4096kB = 13056kB
Feb  3 11:50:07 coop00 kernel: Node 0 Normal: 19*4kB 2*8kB 0*16kB 1*32kB
0*64kB 1*128kB 3*
256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 2556kB
Feb  3 11:50:07 coop00 kernel: Node 0 HighMem: empty
Feb  3 11:50:07 coop00 kernel: Node 1 DMA: empty
Feb  3 11:50:07 coop00 kernel: Node 1 DMA32: empty
Feb  3 11:50:07 coop00 kernel: Node 1 Normal: 1*4kB 1*8kB 1*16kB 1*32kB
1*64kB 1*128kB 5*2
56kB 1*512kB 1*1024kB 1*2048kB 0*4096kB = 5116kB
Feb  3 11:50:07 coop00 kernel: Node 1 HighMem: empty
Feb  3 11:50:07 coop00 kernel: Swap cache: add 16681225, delete
16681005, find 3167567/369
1900, race 1+3
Feb  3 11:50:07 coop00 kernel: Free swap  = 0kB
Feb  3 11:50:07 coop00 kernel: Total swap = 10482404kB
Feb  3 11:50:07 coop00 kernel: Free swap:            0kB
Feb  3 11:50:07 coop00 kernel: 2621440 pages of RAM
Feb  3 11:50:07 coop00 kernel: 108973 reserved pages
Feb  3 11:50:07 coop00 kernel: 7155 pages shared
Feb  3 11:50:07 coop00 kernel: 220 pages swap cached


I think the most cogent piece of information though is what processes is
killed.  The attached patch will generate the following ouput:

--------------------- Kernel Begin ------------------------


  WARNING:  Out of memory killer killed these executables
     wrf.exe :  2 Time(s)

  ---------------------- Kernel End -------------------------






--
Orion Poplawski
Technical Manager                     303-415-9701 x222
NWRA/CoRA Division                    FAX: 303-415-9702
3380 Mitchell Lane                  [email protected]
Boulder, CO 80301              http://www.cora.nwra.com



-- 
Kirk Bauer <[email protected]>
http://linux.kaybee.org | www.logwatch.org
Author, Automating UNIX & Linux Administration

_______________________________________________
Logwatch-Devel mailing list
[email protected]
http://www2.list.logwatch.org:81/mailman/listinfo/logwatch-devel
kernel.patch (text/x-patch, 1.5 KB)
--- scripts/services/kernel	2008-02-04 12:36:52.000000000 -0700
+++ /usr/share/logwatch/scripts/services/kernel	2008-02-04 13:05:02.000000000 -0700
@@ -37,6 +37,7 @@
 my %GPFaults = ();
 my %UnalignedErrors = ();
 my %FPAssists = ();
+my %OOM = ();
 my %Errors = ();
 my %Kernel = ();
 
@@ -66,12 +68,16 @@
       $UnalignedErrors{$1}++;
    } elsif ($ThisLine =~ /([^(]*)\(\d+\): floating-point assist fault at ip/) {
       $FPAssists{$1}++;
+   } elsif ($ThisLine =~ /Out of memory: Killed process \d+ \((.*)\)/) {
+      $OOM{$1}++;
    } elsif ( ( my $errormsg ) = ( $ThisLine =~ /(.*?[Ee]rror.{0,17})/ ) ) {
       # filter out smb open/read errors cased by insufficient permissions
       my $SkipError = 0;
       $SkipError = 1 if $ThisLine =~ /smb_readpage_sync: .*open failed, error=-13/;
       $SkipError = 1 if $ThisLine =~ /smb_open: .* open failed, result=-13/;
       $SkipError = 1 if $ThisLine =~ /smb_open: .* open failed, error=-13/;
+      # filter out error_exit in stack traces caused by OOM conditions
+      $SkipError = 1 if $ThisLine =~ /\[<[\da-f]+>\] error_exit\+0x/;
       $Errors{$errormsg}++ if ( (! $SkipError) || ($Detail > 8));
    }
    # OTHER  
@@ -133,6 +139,13 @@
    }
 }
 
+if (keys %OOM) {
+   print "\nWARNING:  Out of memory killer killed these executables\n";
+   foreach my $Thisone ( sort {$a cmp $b} keys %OOM ) {
+      print "   $Thisone :  $OOM{$Thisone} Time(s)\n";
+   }
+}
+
 if (keys %Errors) {
    print "\nWARNING:  Kernel Errors Present\n";
    foreach my $Thisone ( sort {$a cmp $b} keys %Errors ) {
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.