Hello all,

I've been running a Debian Lenny LAMP server since last Sept and have been very happy with it. Linux has always been a hobby for me and most times I run up against something new, I can figure it out with a bit of googling. Something has me stumped though and I'm hoping you guys can shed a little light on the situation.

Around May 5th I accidentally deleted something important from my server. In order to get it back, I restored my server from the most recent nightly backup. Ever since then, in about 95% of my daily logwatch reports, I have loooooong list of kernel messages. Logwatch doesn't call them errors, but they very well could be. I never had stuff like this in my reports before the restore, but now it's almost every day.

Here is an example of the output:

Kernel
2 Time(s): 0 pages HighMem
1 Time(s): 103012 pages non-shared
1 Time(s): 103812 pages non-shared
2 Time(s): 133104 pages RAM
1 Time(s): 33970 pages shared
1 Time(s): 36819 pages shared
1 Time(s): 51273 total pagecache pages
1 Time(s): 54141 total pagecache pages
2 Time(s): 5637 pages reserved
1 Time(s): 9198 pages in swap cache
1 Time(s): 9331 pages in swap cache
2 Time(s): <IRQ>  [<c0137fe5>] ? irq_exit+0x65/0x70
2 Time(s): CPU    0: hi:    0, btch:   1 usd:   0
1 Time(s): CPU    0: hi:  186, btch:  31 usd:  25
1 Time(s): CPU    0: hi:  186, btch:  31 usd:  91
2 Time(s): CPU   1: hi:    0, btch:   1 usd:   0
1 Time(s): CPU    1: hi:  186, btch:  31 usd: 110
1 Time(s): CPU    1: hi:  186, btch:  31 usd: 179
2 Time(s): CPU    2: hi:    0, btch:   1 usd:   0
1 Time(s): CPU    2: hi:  186, btch:  31 usd:  40
1 Time(s): CPU    2: hi:  186, btch:  31 usd:  59
2 Time(s): CPU    3: hi:    0, btch:   1 usd:   0
1 Time(s): CPU    3: hi:  186, btch:  31 usd:  50
1 Time(s): CPU    3: hi:  186, btch:  31 usd:  56
2 Time(s): Call Trace:
1 Time(s): DMA free:2060kB min:84kB low:104kB high:124kB active_anon:196kB inactive_anon:2328kB active_file:1508kB inactive_file:980kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15808kB mlocked:0kB dirty:0kB writeback:0kB mapped:704kB shmem:0kB slab_reclaimable:24kB slab_unreclaimable:36kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
1 Time(s): DMA free:2096kB min:84kB low:104kB high:124kB active_anon:100kB inactive_anon:2328kB active_file:1584kB inactive_file:996kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15808kB mlocked:0kB dirty:0kB writeback:0kB mapped:704kB shmem:0kB slab_reclaimable:24kB slab_unreclaimable:4kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
2 Time(s): DMA per-cpu:
1 Time(s): DMA: 181*4kB 101*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2060kB
1 Time(s): DMA: 184*4kB 100*8kB 1*16kB 1*32kB 2*64kB 1*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2096kB
1 Time(s): Free swap  = 188888kB
1 Time(s): Free swap  = 190336kB
2 Time(s): Mem-Info:
1 Time(s): Normal free:13620kB min:2816kB low:3520kB high:4224kB active_anon:142404kB inactive_anon:152700kB active_file:98448kB inactive_file:67208kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:512064kB mlocked:0kB dirty:0kB writeback:0kB mapped:17476kB shmem:8kB slab_reclaimable:7512kB slab_unreclaimable:6084kB kernel_stack:1104kB pagetables:2504kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
1 Time(s): Normal free:6952kB min:2816kB low:3520kB high:4224kB active_anon:174856kB inactive_anon:116056kB active_file:130808kB inactive_file:45852kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:512064kB mlocked:0kB dirty:24kB writeback:0kB mapped:18772kB shmem:8kB slab_reclaimable:7608kB slab_unreclaimable:6068kB kernel_stack:1120kB pagetables:2760kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
2 Time(s): Normal per-cpu:
1 Time(s): Normal: 1541*4kB 628*8kB 149*16kB 1*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 13604kB
1 Time(s): Normal: 240*4kB 399*8kB 141*16kB 17*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 6952kB
1 Time(s): Pid: 0, comm: swapper Not tainted 2.6.38.3-linode32 #1
1 Time(s): Pid: 269, comm: kswapd0 Not tainted 2.6.38.3-linode32 #1
1 Time(s): Swap cache stats: add 1054305, delete 1044974, find 5701264/5891884
1 Time(s): Swap cache stats: add 1055406, delete 1046208, find 5703305/5894027
2 Time(s): Total swap = 262140kB
1 Time(s): [<c0101227>] ? hypercall_page+0x227/0x1010
1 Time(s): [<c01013a7>] ? hypercall_page+0x3a7/0x1010
6 Time(s): [<c0105b37>] ? xen_force_evtchn_callback+0x17/0x30
1 Time(s): [<c0105b8f>] ? xen_safe_halt+0xf/0x20
1 Time(s): [<c01062d3>] ? xen_irq_enable_direct_end+0x0/0x1
2 Time(s): [<c010630b>] ? xen_restore_fl_direct_end+0x0/0x1
1 Time(s): [<c0106314>] ? check_events+0x8/0xc
1 Time(s): [<c0107ed2>] ? cpu_idle+0x42/0x70
1 Time(s): [<c0109436>] ? kernel_thread_helper+0x6/0x10
2 Time(s): [<c0109487>] ? xen_do_upcall+0x7/0xc
1 Time(s): [<c010f66f>] ? default_idle+0x2f/0x60
1 Time(s): [<c012fb87>] ? finish_task_switch+0x47/0xb0
2 Time(s): [<c0138070>] ? __do_softirq+0x0/0x130
2 Time(s): [<c01380ec>] ? __do_softirq+0x7c/0x130
2 Time(s): [<c01382a6>] ? local_bh_enable+0x16/0x80
1 Time(s): [<c013deda>] ? try_to_del_timer_sync+0x4a/0x80
1 Time(s): [<c014a410>] ? kthread+0x0/0x80
1 Time(s): [<c014a484>] ? kthread+0x74/0x80
1 Time(s): [<c014a800>] ? autoremove_wake_function+0x0/0x40
1 Time(s): [<c018275f>] ? zone_watermark_ok_safe+0x8f/0xa0
2 Time(s): [<c0184720>] ? __alloc_pages_nodemask+0x4f0/0x670
1 Time(s): [<c018a490>] ? kswapd+0x0/0x7b0
1 Time(s): [<c018ac1e>] ? kswapd+0x78e/0x7b0
1 Time(s): [<c018f9a7>] ? set_pgdat_percpu_threshold+0x87/0xa0
2 Time(s): [<c01a9746>] ? kmem_cache_free+0x46/0x120
2 Time(s): [<c01aa339>] ? cache_alloc_refill+0x2f9/0x520
2 Time(s): [<c01aa614>] ? __kmalloc+0xb4/0xe0
2 Time(s): [<c043a03d>] ? xen_evtchn_do_upcall+0x1d/0x30
2 Time(s): [<c04a0015>] ? xennet_poll+0x7f5/0xc20
2 Time(s): [<c04f44fe>] ? pskb_expand_head+0x12e/0x200
2 Time(s): [<c04f4a4d>] ? __pskb_pull_tail+0x4d/0x2b0
2 Time(s): [<c04fae3d>] ? __netif_receive_skb+0x32d/0x510
2 Time(s): [<c04fbcf7>] ? netif_receive_skb+0x67/0x70
2 Time(s): [<c04fc43a>] ? net_rx_action+0x9a/0x130
2 Time(s): [<c04fcbba>] ? dev_hard_start_xmit+0x26a/0x520
2 Time(s): [<c04fcf91>] ? dev_queue_xmit+0x121/0x550
1 Time(s): [<c0504fe5>] ? neigh_resolve_output+0xf5/0x310
1 Time(s): [<c050f6f0>] ? eth_header+0x0/0xc0
1 Time(s): [<c050f700>] ? eth_header+0x10/0xc0
2 Time(s): [<c0510912>] ? sch_direct_xmit+0xb2/0x170
2 Time(s): [<c0534e44>] ? nf_iterate+0x74/0xa0
2 Time(s): [<c0554926>] ? ip_rcv_finish+0xf6/0x3c0
2 Time(s): [<c0554f20>] ? ip_local_deliver_finish+0x0/0x220
2 Time(s): [<c0554fb7>] ? ip_local_deliver_finish+0x97/0x220
2 Time(s): [<c05590e8>] ? ip_local_out+0x18/0x20
2 Time(s): [<c05597e7>] ? ip_queue_xmit+0x137/0x3a0
4 Time(s): [<c0559e20>] ? ip_finish_output+0x0/0x300
2 Time(s): [<c0559f54>] ? ip_finish_output+0x134/0x300
2 Time(s): [<c055a1ca>] ? ip_output+0xaa/0xe0
2 Time(s): [<c056a9c4>] ? tcp_rcv_established+0x594/0x840
2 Time(s): [<c056c7d2>] ? tcp_transmit_skb+0x372/0x7e0
2 Time(s): [<c056ed98>] ? tcp_write_xmit+0x198/0x980
2 Time(s): [<c056f5e4>] ? __tcp_push_pending_frames+0x24/0x90
2 Time(s): [<c0571fc6>] ? tcp_v4_do_rcv+0xd6/0x230
2 Time(s): [<c05727ec>] ? tcp_v4_rcv+0x6cc/0x7b0
2 Time(s): [<c05ee32d>] ? packet_rcv_spkt+0xfd/0x140
1 Time(s): [<c063d6b9>] ? schedule+0x219/0x8b0
1 Time(s): [<c07ca410>] ? unknown_bootoption+0x0/0x190
1 Time(s): [<c07ca8ac>] ? start_kernel+0x2da/0x2df
1 Time(s): [<c07cdaa5>] ? xen_start_kernel+0x530/0x538
1 Time(s): active_anon:35650 inactive_anon:38757 isolated_anon:0
1 Time(s): active_anon:43739 inactive_anon:29596 isolated_anon:0
1 Time(s): active_file:24989 inactive_file:17047 isolated_file:0
1 Time(s): active_file:33098 inactive_file:11712 isolated_file:0
1 Time(s): free:2262 slab_reclaimable:1908 slab_unreclaimable:1518
1 Time(s): free:3920 slab_reclaimable:1884 slab_unreclaimable:1530
3 Time(s): imklog 3.18.6, log source = /proc/kmsg started.
1 Time(s): kswapd0: page allocation failure. order:3, mode:0x20
2 Time(s): lowmem_reserve[]: 0 0 0 0
2 Time(s): lowmem_reserve[]: 0 500 500 500
1 Time(s): mapped:4545 shmem:2 pagetables:626 bounce:0
1 Time(s): mapped:4869 shmem:2 pagetables:690 bounce:0
1 Time(s): swapper: page allocation failure. order:4, mode:0x20
1 Time(s): unevictable:0 dirty:0 writeback:0 unstable:0
1 Time(s): unevictable:0 dirty:6 writeback:0 unstable:0

I had to add all those line breaks by hand, so hopefully I found them all.

Anybody know if this is something to be worried about? How to make it stop? Why a restoration would cause this?

Your thoughts are greatly appreciated.

Thanks in advance.

It wouldn't. Please reboot into the latest kernel and this will likely alleviate the problem for you.

Hope that helps!
-Chris

Hi, and thanks for the reply.

Can you please elaborate on "reboot into the latest kernel"?

How would I go about that?

Thanks again.

Log in, Linodes tab, dashboard, make sure the configuration profile is set to "Latest 2.6 Paravirt", reboot. That's it!

-Chris

Thanks, I had just found the Boot Settings-->Kernel section of Configuration Profile and was wondering what kernel it should be set to. When I looked there, it was already set to "Latest 2.6 Paravirt (2.6.39.1-linode34", however, when I checked my kernel version on the server it was "2.6.38.3-linode32".

A reboot, as you suggested, has updated it, so hopefully that'll clear up the log reports.

Thanks!