KMEMCHECK: linux-next: kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!

KMEMCHECK: linux-next: kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!

[Tetsuo Handa]

Hello.

I encountered this.

[    0.004000] ------------[ cut here ]------------
[    0.004000] kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!
[    0.004000] invalid opcode: 0000 [#1] SMP 
[    0.004000] last sysfs file: 
[    0.004000] Modules linked in:
[    0.004000] 
[    0.004000] Pid: 0, comm: swapper Not tainted (2.6.29-rc7-next-20090310 #1) VMware Virtual Platform
[    0.004000] EIP: 0060:[<c0122e01>] EFLAGS: 00010202 CPU: 0
[    0.004000] EIP is at kmemcheck_hide_pages+0x51/0x80
[    0.004000] EAX: c06d6f70 EBX: f7000000 ECX: 370001e3 EDX: c06d6f70
[    0.004000] ESI: c17bd000 EDI: 00000000 EBP: c0531ea0 ESP: c0531e8c
[    0.004000]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[    0.004000] Process swapper (pid: 0, ti=c0531000 task=c04f3b60 task.ti=c0531000)
[    0.004000] Stack:
[    0.004000]  00000001 00000002 00000000 00000024 c17bd024 c0531ec0 c019c390 00000000
[    0.004000]  00000001 c17bd000 c17bd000 00000100 c052ee10 c0531ee8 c0198055 ffffffff
[    0.004000]  21668823 00000001 ffffffff 000000d0 00000010 c052ee10 c052ee10 c0531f08
[    0.004000] Call Trace:
[    0.004000]  [<c019c390>] ? kmemcheck_alloc_shadow+0x70/0x90
[    0.004000]  [<c0198055>] ? allocate_slab+0xc5/0x130
[    0.004000]  [<c0198112>] ? new_slab+0x22/0x130
[    0.004000]  [<c01987c4>] ? __slab_alloc+0x104/0x1e0
[    0.004000]  [<c0199ce3>] ? __kmalloc+0x113/0x160
[    0.004000]  [<c02672b0>] ? kvasprintf+0x30/0x60
[    0.004000]  [<c02672b0>] ? kvasprintf+0x30/0x60
[    0.004000]  [<c02672b0>] ? kvasprintf+0x30/0x60
[    0.004000]  [<c02672f1>] ? kasprintf+0x11/0x20
[    0.004000]  [<c054ba30>] ? kmem_cache_init+0xc0/0x140
[    0.004000]  [<c03ce3d2>] ? __start_notes+0x0/0xe
[    0.004000]  [<c0535932>] ? start_kernel+0x182/0x280
[    0.004000]  [<c05352b0>] ? unknown_bootoption+0x0/0x150
[    0.004000]  [<c0535080>] ? __init_begin+0x80/0xc0
[    0.004000] Code: c0 89 c2 74 37 83 7d f0 01 75 20 8b 00 83 e0 fe 0d 00 08 00 00 89 02 0f 01 3b 47 83 c6 24 3b 7d ec 72 cb 83 c4 08 5b 5e 5f 5d c3 <0f> 0b 8d b6 00 00 00 00 8d bc 27 00 00 00 00 eb fe 0f 0b 8d b6 
[    0.004000] EIP: [<c0122e01>] kmemcheck_hide_pages+0x51/0x80 SS:ESP 0068:c0531e8c
[    0.004000] ---[ end trace 4eaa2a86a8e2da22 ]---

Config is at http://I-love.SAKURA.ne.jp/tmp/config-2.6.29-rc7-next-20090310
Full log is at http://I-love.SAKURA.ne.jp/tmp/dmesg-2.6.29-rc7-next-20090310.txt

Regards.

Re: KMEMCHECK: linux-next: kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!

[Vegard Nossum]

2009/3/11 Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>:
> Hello.
>
> I encountered this.
>
> [    0.004000] ------------[ cut here ]------------
> [    0.004000] kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!

Hi, thanks for this report!

I have a feeling that the following patch might fix it. Please try it out
only if you have the time. I will also try to reproduce it when I have the
time myself.


Vegard


diff --git a/arch/x86/mm/init.c b/arch/x86/mm/init.c
index 6d63e3d..86f7398 100644
--- a/arch/x86/mm/init.c
+++ b/arch/x86/mm/init.c
@@ -146,7 +146,7 @@ unsigned long __init_refok init_memory_mapping(unsigned long start,
 	if (!after_bootmem)
 		init_gbpages();
 
-#ifdef CONFIG_DEBUG_PAGEALLOC
+#if defined(CONFIG_DEBUG_PAGEALLOC) || defined(CONFIG_KMEMCHECK)
 	/*
 	 * For CONFIG_DEBUG_PAGEALLOC, identity mapping will use small pages.
 	 * This will simplify cpa(), which otherwise needs to support splitting

Re: KMEMCHECK: linux-next: kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!

[Tetsuo Handa]

Hello.

Vegard Nossum wrote:
> > [    0.004000] ------------[ cut here ]------------
> > [    0.004000] kernel BUG at arch/x86/mm/kmemcheck/kmemcheck.c:297!
> 
> Hi, thanks for this report!
> 
> I have a feeling that the following patch might fix it. Please try it out
> only if you have the time. I will also try to reproduce it when I have the
> time myself.

I tested this patch on linux-next-20090310 and confirmed that this problem was
solved.

By the way, is there a possibility that delays introduced by kmemcheck trigger
false "CPU stalled" warning?
I got below warning message after applying this patch.

[   14.477987] pci 0000:00:18.7: PCI bridge, secondary bus 0000:22
[   14.480320] pci 0000:00:18.7:   IO window: disabled
[   14.482590] pci 0000:00:18.7:   MEM window: 0xdb200000-0xdb2fffff
[   14.485180] pci 0000:00:18.7:   PREFETCH window: 0x000000dda00000-0x000000ddafffff
[   14.618875] NET: Registered protocol family 2
[   14.744525] IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
[   15.762230] TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
[   18.989204] TCP bind hash table entries: 65536 (order: 9, 2621440 bytes)
[   24.007883] INFO: RCU detected CPU 0 stall (t=4294898298/2500 jiffies)
[   24.007883] Pid: 1, comm: swapper Not tainted 2.6.29-rc7-next-20090310-dirty #2
[   24.007883] Call Trace:
[   24.007883]  [<c01366d8>] ? printk+0x18/0x20
[   24.007883]  [<c0170254>] print_cpu_stall+0x44/0x90
[   24.007883]  [<c01702dd>] check_cpu_stall+0x3d/0xc0
[   24.007883]  [<c016ccce>] ? __touch_softlockup_watchdog+0xe/0x20
[   24.007883]  [<c016cf69>] ? softlockup_tick+0x169/0x190
[   24.007883]  [<c017091a>] __rcu_pending+0x1a/0xa0
[   24.007883]  [<c01709c9>] rcu_pending+0x29/0x60
[   24.007883]  [<c01401b6>] update_process_times+0x36/0x70
[   24.007883]  [<c0155e25>] tick_periodic+0x25/0x70
[   24.007883]  [<c0155e89>] tick_handle_periodic+0x19/0x80
[   24.007883]  [<c0102f3e>] ? restore_nocheck_notrace+0x0/0xe
[   24.007883]  [<c0115b64>] local_apic_timer_interrupt+0x54/0x60
[   24.007883]  [<c0115b9e>] smp_apic_timer_interrupt+0x2e/0x40
[   24.007883]  [<c01037c7>] apic_timer_interrupt+0x2f/0x34
[   24.007883]  [<c015ba2b>] ? lockdep_init_map+0x5b/0x570
[   24.007883]  [<c0273f02>] __spin_lock_init+0x32/0x60
[   24.007883]  [<c055c241>] tcp_init+0x1c1/0x350
[   24.007883]  [<c033fcca>] ? register_pernet_subsys+0x2a/0x30
[   24.007883]  [<c055cc40>] ? inet_init+0x0/0x1f0
[   24.007883]  [<c055cd40>] inet_init+0x100/0x1f0
[   24.007883]  [<c055cc40>] ? inet_init+0x0/0x1f0
[   24.007883]  [<c010103d>] do_one_initcall+0x2d/0x1a0
[   24.007883]  [<c015a37c>] ? validate_chain+0x3fc/0x540
[   24.007883]  [<c015a37c>] ? validate_chain+0x3fc/0x540
[   24.007883]  [<c012354e>] ? kmemcheck_pte_lookup+0xe/0x30
[   24.007883]  [<c015a37c>] ? validate_chain+0x3fc/0x540
[   24.007883]  [<c012354e>] ? kmemcheck_pte_lookup+0xe/0x30
[   24.007883]  [<c015a37c>] ? validate_chain+0x3fc/0x540
[   24.007883]  [<c015a37c>] ? validate_chain+0x3fc/0x540
[   24.007883]  [<c0157d14>] ? lock_release_holdtime+0x74/0xc0
[   24.007883]  [<c012ecd8>] ? scheduler_tick+0x68/0xb0
[   24.007883]  [<c015d3c7>] ? __lock_release+0x47/0x70
[   24.007883]  [<c012ecd8>] ? scheduler_tick+0x68/0xb0
[   24.007883]  [<c03cd47d>] ? _spin_unlock+0x1d/0x20
[   24.007883]  [<c012ece0>] ? scheduler_tick+0x70/0xb0
[   24.007883]  [<c01401cb>] ? update_process_times+0x4b/0x70
[   24.007883]  [<c0155e25>] ? tick_periodic+0x25/0x70
[   24.007883]  [<c0155e89>] ? tick_handle_periodic+0x19/0x80
[   24.007883]  [<c0102f3e>] ? restore_nocheck_notrace+0x0/0xe
[   24.007883]  [<c015b066>] ? trace_hardirqs_on_caller+0xe6/0x170
[   24.007883]  [<c0535a00>] ? start_kernel+0x250/0x280
[   24.007883]  [<c0265e34>] ? trace_hardirqs_on_thunk+0xc/0x10
[   24.007883]  [<c010590b>] ? do_softirq+0x4b/0xf0
[   24.007883]  [<c0102f3e>] ? restore_nocheck_notrace+0x0/0xe
[   24.007883]  [<c0535ad0>] ? kernel_init+0x0/0x90
[   24.007883]  [<c0535a5a>] do_initcalls+0x2a/0x40
[   24.007883]  [<c0535ad0>] ? kernel_init+0x0/0x90
[   24.007883]  [<c0535a8c>] do_basic_setup+0x1c/0x20
[   24.007883]  [<c0535b20>] kernel_init+0x50/0x90
[   24.007883]  [<c01038e7>] kernel_thread_helper+0x7/0x10
[   26.314302] TCP: Hash tables configured (established 131072 bind 65536)
[   26.316703] TCP reno registered
[   26.423914] NET: Registered protocol family 1
[   26.498394] checking if image is initramfs...it isn't (junk in compressed archive); looks like an initrd
[   26.667075] Freeing initrd memory: 1056k freed

I don't see this warning message if I choose CONFIG_KMEMCHECK=n .

Regards.