Kernel 3.0.6-44

This morning while reading /var/log/messages/ i found some interesting lines:


Oct 14 08:33:44 creation kernel:   104.107424] BUG: Bad page state in process khugepaged  pfn:3fa00
Oct 14 08:33:44 creation kernel:   104.107432] page:ffffea0000deb000 count:810317 mapcount:0 mapping:          (null) index:0x0
Oct 14 08:33:44 creation kernel:   104.107436] page flags: 0x147257(locked|error|referenced|dirty|active|arch_1|private_2|writeback|head|reclaim|unevictable)
Oct 14 08:33:44 creation kernel:   104.107454] Pid: 33, comm: khugepaged Tainted: P            3.0.6-44-desktop #1
Oct 14 08:33:44 creation kernel:   104.107458] Call Trace:
Oct 14 08:33:44 creation kernel:   104.107478]  <ffffffff81004562>] dump_trace+0x82/0x370
Oct 14 08:33:44 creation kernel:   104.107488]  <ffffffff8158aad3>] dump_stack+0x69/0x6f
Oct 14 08:33:44 creation kernel:   104.107497]  <ffffffff81105fc4>] bad_page+0xb4/0x100
Oct 14 08:33:44 creation kernel:   104.107507]  <ffffffff81106e1e>] free_pcppages_bulk+0x47e/0x490
Oct 14 08:33:44 creation kernel:   104.107516]  <ffffffff81107c1c>] free_hot_cold_page+0x17c/0x460
Oct 14 08:33:44 creation kernel:   104.107525]  <ffffffff81107f53>] __pagevec_free+0x53/0xd0
Oct 14 08:33:44 creation kernel:   104.107532]  <ffffffff8110b81a>] release_pages+0x25a/0x290
Oct 14 08:33:44 creation kernel:   104.107541]  <ffffffff8110b94e>] pagevec_lru_move_fn+0xfe/0x120
Oct 14 08:33:44 creation kernel:   104.107548]  <ffffffff8110bad0>] __lru_cache_add+0x80/0xa0
Oct 14 08:33:44 creation kernel:   104.107555]  <ffffffff81111759>] putback_lru_page+0x69/0xe0
Oct 14 08:33:44 creation kernel:   104.107563]  <ffffffff8114e7cb>] __collapse_huge_page_copy+0x19b/0x240
Oct 14 08:33:44 creation kernel:   104.107571]  <ffffffff8114eda8>] collapse_huge_page+0x308/0x540
Oct 14 08:33:44 creation kernel:   104.107578]  <ffffffff8114f29c>] khugepaged_scan_pmd+0x2bc/0x2d0
Oct 14 08:33:44 creation kernel:   104.107586]  <ffffffff8114f417>] khugepaged_scan_mm_slot+0x167/0x260
Oct 14 08:33:44 creation kernel:   104.107593]  <ffffffff8114f6e0>] khugepaged_loop+0x1d0/0x340
Oct 14 08:33:44 creation kernel:   104.107601]  <ffffffff8114f89a>] khugepaged+0x4a/0xc0
Oct 14 08:33:44 creation kernel:   104.107608]  <ffffffff8107c876>] kthread+0x96/0xa0
Oct 14 08:33:44 creation kernel:   104.107617]  <ffffffff81596144>] kernel_thread_helper+0x4/0x10
Oct 14 08:33:49 creation kernel:   109.053562] BUG: Bad page state in process sh  pfn:3fa01
Oct 14 08:33:49 creation kernel:   109.053569] page:ffffea0000deb038 count:0 mapcount:0 mapping:          (null) index:0x0
Oct 14 08:33:49 creation kernel:   109.053573] page flags: 0x1f9(locked|uptodate|dirty|lru|active|slab|owner_priv_1)
Oct 14 08:33:49 creation kernel:   109.053586] Pid: 3513, comm: sh Tainted: P    B       3.0.6-44-desktop #1
Oct 14 08:33:49 creation kernel:   109.053590] Call Trace:
Oct 14 08:33:49 creation kernel:   109.053610]  <ffffffff81004562>] dump_trace+0x82/0x370
Oct 14 08:33:49 creation kernel:   109.053620]  <ffffffff8158aad3>] dump_stack+0x69/0x6f
Oct 14 08:33:49 creation kernel:   109.053630]  <ffffffff81105fc4>] bad_page+0xb4/0x100
Oct 14 08:33:49 creation kernel:   109.053639]  <ffffffff811062c7>] prep_new_page+0x187/0x1a0
Oct 14 08:33:49 creation kernel:   109.053651]  <ffffffff8110652b>] get_page_from_freelist+0x24b/0x6c0
Oct 14 08:33:49 creation kernel:   109.053659]  <ffffffff81107244>] __alloc_pages_nodemask+0x114/0x870
Oct 14 08:33:49 creation kernel:   109.053668]  <ffffffff8114183d>] alloc_pages_vma+0x9d/0x160
Oct 14 08:33:49 creation kernel:   109.053676]  <ffffffff81122257>] __do_fault+0x347/0x550
Oct 14 08:33:49 creation kernel:   109.053686]  <ffffffff8112578e>] handle_pte_fault+0x8e/0x220
Oct 14 08:33:49 creation kernel:   109.053693]  <ffffffff81591131>] do_page_fault+0x1a1/0x540
Oct 14 08:33:49 creation kernel:   109.053702]  <ffffffff8158e495>] page_fault+0x25/0x30
Oct 14 08:33:49 creation kernel:   109.053733]  <00007f046e396bb7>] 0x7f046e396bb6

Can someone check and post back if they see the same “bug” lines as mine stated above?
What can be the cause of this ?

Cannot confirm the bug reported,

the output on this machine is,

<2011Oct14><12:41></var/log>  less messages |grep 'Oct 14' |grep kernel
Oct 14 11:10:38 linux-qz4c kernel: imklog 5.6.5, log source = /proc/kmsg started.
Oct 14 11:10:38 linux-qz4c kernel:     8.487553] type=1400 audit(1318583435.284:2): apparmor="STATUS" operation="profile_load" name="/bin/ping" pid=900 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     8.528223] type=1400 audit(1318583435.325:3): apparmor="STATUS" operation="profile_load" name="/sbin/klogd" pid=905 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     8.619235] type=1400 audit(1318583435.416:4): apparmor="STATUS" operation="profile_load" name="/sbin/syslog-ng" pid=909 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     8.707286] type=1400 audit(1318583435.504:5): apparmor="STATUS" operation="profile_load" name="/sbin/syslogd" pid=913 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     9.082814] type=1400 audit(1318583435.879:6): apparmor="STATUS" operation="profile_load" name="/usr/lib/apache2/mpm-prefork/apache2" pid=918 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     9.082874] type=1400 audit(1318583435.879:7): apparmor="STATUS" operation="profile_load" name="/usr/lib/apache2/mpm-prefork/apache2//DEFAULT_URI" pid=918 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     9.082915] type=1400 audit(1318583435.879:8): apparmor="STATUS" operation="profile_load" name="/usr/lib/apache2/mpm-prefork/apache2//HANDLING_UNTRUSTED_INPUT" pid=918 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     9.082987] type=1400 audit(1318583435.879:9): apparmor="STATUS" operation="profile_load" name="/usr/lib/apache2/mpm-prefork/apache2//phpsysinfo" pid=918 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     9.173801] type=1400 audit(1318583435.970:10): apparmor="STATUS" operation="profile_load" name="/usr/lib/dovecot/deliver" pid=922 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:     9.267725] type=1400 audit(1318583436.064:11): apparmor="STATUS" operation="profile_load" name="/usr/lib/dovecot/dovecot-auth" pid=926 comm="apparmor_parser"
Oct 14 11:10:38 linux-qz4c kernel:    10.897146] powernow-k8: Found 1 AMD Phenom(tm) II X4 940 Processor (4 cpu cores) (version 2.20.00)
Oct 14 11:10:38 linux-qz4c kernel:    10.897200] powernow-k8:    0 : pstate 0 (3000 MHz)
Oct 14 11:10:38 linux-qz4c kernel:    10.897201] powernow-k8:    1 : pstate 1 (2300 MHz)
Oct 14 11:10:38 linux-qz4c kernel:    10.897202] powernow-k8:    2 : pstate 2 (1800 MHz)
Oct 14 11:10:38 linux-qz4c kernel:    10.897203] powernow-k8:    3 : pstate 3 (800 MHz)
Oct 14 11:10:38 linux-qz4c kernel:    11.389909] microcode: CPU0: patch_level=0x01000086
Oct 14 11:10:38 linux-qz4c kernel:    11.486528] microcode: CPU1: patch_level=0x01000086
Oct 14 11:10:38 linux-qz4c kernel:    11.490089] microcode: CPU2: patch_level=0x01000086
Oct 14 11:10:38 linux-qz4c kernel:    11.493518] microcode: CPU3: patch_level=0x01000086
Oct 14 11:10:38 linux-qz4c kernel:    11.496818] microcode: Microcode Update Driver: v2.00 <tigran@aivazian.fsnet.co.uk>, Peter Oruba
Oct 14 11:10:38 linux-qz4c kernel:    11.870493] ip6_tables: (C) 2000-2006 Netfilter Core Team
Oct 14 11:10:38 linux-qz4c kernel:    11.970701] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
Oct 14 11:10:38 linux-qz4c kernel:    11.987866] ip_tables: (C) 2000-2006 Netfilter Core Team
Oct 14 11:10:39 linux-qz4c kernel: Kernel logging (proc) stopped.
Oct 14 11:10:39 linux-qz4c kernel: imklog 5.6.5, log source = /proc/kmsg started.
Oct 14 11:10:44 linux-qz4c kernel:    17.633884] [fglrx] GART Table is not in FRAME_BUFFER range 
Oct 14 11:10:44 linux-qz4c kernel:    17.634152] [fglrx] Could not enable MSI; System prevented initialization
Oct 14 11:10:44 linux-qz4c kernel:    17.634659] [fglrx] Firegl kernel thread PID: 1402
Oct 14 11:10:44 linux-qz4c kernel:    17.634721] [fglrx] Firegl kernel thread PID: 1403
Oct 14 11:10:44 linux-qz4c kernel:    17.634779] [fglrx] Firegl kernel thread PID: 1404
Oct 14 11:10:44 linux-qz4c kernel:    17.635040] [fglrx] IRQ 18 Enabled
Oct 14 11:10:44 linux-qz4c kernel:    18.142749] [fglrx] Gart USWC size:1160 M.
Oct 14 11:10:44 linux-qz4c kernel:    18.142752] [fglrx] Gart cacheable size:459 M.
Oct 14 11:10:44 linux-qz4c kernel:    18.142756] [fglrx] Reserved FB block: Shared offset:0, size:1000000 
Oct 14 11:10:44 linux-qz4c kernel:    18.142758] [fglrx] Reserved FB block: Unshared offset:fffc000, size:4000 
Oct 14 11:34:54 linux-qz4c kernel:  1467.898793] EXT4-fs (sda2): re-mounted. Opts: acl,user_xattr,commit=0
Oct 14 11:34:54 linux-qz4c kernel:  1468.118355] EXT4-fs (sda3): re-mounted. Opts: acl,user_xattr,commit=0
Oct 14 11:37:47 linux-qz4c kernel:  1640.498454] EXT4-fs (sdb1): warning: maximal mount count reached, running e2fsck is recommended
Oct 14 11:37:47 linux-qz4c kernel:  1640.499646] EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: (null)
Oct 14 11:38:04 linux-qz4c kernel:  1658.150593] fuse init (API version 7.16)
Oct 14 11:46:08 linux-qz4c kernel:  2142.014384] sdb: detected capacity change from 8036285952 to 0
Oct 14 11:46:11 linux-qz4c kernel:  2144.686497] usb 1-6: USB disconnect, device number 3
Oct 14 12:23:05 linux-qz4c kernel:  4358.978150] r8169 0000:02:00.0: eth0: link down
Oct 14 12:23:05 linux-qz4c kernel:  4358.978702] ADDRCONF(NETDEV_UP): eth0: link is not ready
Oct 14 12:23:30 linux-qz4c kernel:  4383.308051] r8169 0000:02:00.0: eth0: link up
Oct 14 12:23:30 linux-qz4c kernel:  4383.309440] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Oct 14 12:23:30 linux-qz4c kernel:  4383.477798] NET: Registered protocol family 17
Oct 14 12:23:32 linux-qz4c kernel:  4385.521131] martian source 255.255.255.255 from 192.168.178.1, on dev eth0
Oct 14 12:23:32 linux-qz4c kernel:  4385.521140] ll header: ff:ff:ff:ff:ff:ff:00:04:0e:76:29:c6:08:00
Oct 14 12:23:40 linux-qz4c kernel:  4393.506274] eth0: no IPv6 routers present
<2011Oct14><12:42></var/log>

Can an application cause this output? Or is it hardware related?

Sorry cannot help. Suggest you have a look at the following page,

‘http://answers.softpicks.net/answers/topic/khugepaged-eating-100-CPU-1793490-1.htm’

No problem. Using 3.0.7 kernel, checked /var/log/messages/ a few days in a row and the error did not appear anymore.