Re: BUG due to mm-instrumentation
Jan Kiszka <[email protected]> Tue, 26 Feb 2008 15:29:25 +0100
| Newsgroups | gmane.linux.kernel.tracing |
|---|---|
| Message-ID | <[email protected]> |
Mathieu Desnoyers wrote: > * Jan Kiszka ([email protected]) wrote: >> Hi, >> >> I just ran into an interesting BUG on an LTT-patched (Xenomai) kernel, >> but with markers & LTT disabled: >> >> Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: >> [<ffffffff802c4c75>] page_to_pfn+0x9/0x3d >> PGD 2082f067 PUD 58caf067 PMD 0 >> Oops: 0000 [1] SMP >> CPU 2 >> Modules linked in: scsi_mod libata ahci ata_piix fan jbd mbcache ext3 raid0 edd sd_mod raid1 xor async_tx async_memcpy async_xor raid456 sg cdrom button i2c_core edac_core rtc_lib e1000 pci_hotplr >> Pid: 1592, comm: ld Not tainted 2.6.24.2-xeno_64 #12 >> RIP: 0010:[<ffffffff802c4c75>] [<ffffffff802c4c75>] page_to_pfn+0x9/0x3d >> RSP: 0018:ffff810058c21868 EFLAGS: 00010246 >> RAX: 0000000000000000 RBX: 0000000000041250 RCX: ffff810000011968 >> RDX: 0000000000000000 RSI: ffff810000011950 RDI: 0000000000000000 >> RBP: ffff810058c21868 R08: 0000000000000000 R09: 00000000000007d9 >> R10: 0000000000000000 R11: 0000000000000001 R12: 00000000000c1250 >> R13: ffff810000011950 R14: 0000000000000000 R15: 0000000000000000 >> FS: 00002b9d20c6fb00(0000) GS:ffff81007df79340(0000) knlGS:0000000000000000 >> CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b >> CR2: 0000000000000000 CR3: 000000007bd25000 CR4: 00000000000006e0 >> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 >> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 >> Process ld (pid: 1592, threadinfo ffff810058c20000, task ffff81007c161040) >> Stack: ffff810058c218f8 ffffffff802c7909 0000000000000001 0000100000000000 >> 0000000000001000 ffff810000011958 000412003dc403b4 00000010000e1250 >> 0000000000000000 ffff81007c161040 0000000003163370 ffff81006288e748 >> Call Trace: >> [<ffffffff802c7909>] __alloc_pages+0x355/0x368 >> [<ffffffff802e5e54>] kmem_getpages+0xa9/0x161 >> [<ffffffff802e739d>] cache_grow+0xb3/0x27c >> [<ffffffff802e7a6e>] cache_alloc_refill+0x1b0/0x201 >> [<ffffffff802e7d08>] kmem_cache_alloc+0xda/0x136 >> [<ffffffff880733e5>] :jbd:journal_add_journal_head+0x35/0x167 >> [<ffffffff8806f938>] :jbd:journal_dirty_data+0x3e/0x1da >> [<ffffffff8808943d>] :ext3:ext3_journal_dirty_data+0x1d/0x46 >> [<ffffffff88088718>] :ext3:walk_page_buffers+0x70/0x97 >> [<ffffffff88089420>] :ext3:ext3_journal_dirty_data+0x0/0x46 >> [<ffffffff8808b1ff>] :ext3:ext3_ordered_write_end+0x77/0xed >> [<ffffffff802c2916>] generic_file_buffered_write+0x1dc/0x6aa >> [<ffffffff8023d34e>] current_fs_time+0x27/0x2e >> [<ffffffff8809874c>] :ext3:ext3_xattr_security_get+0x26/0x28 >> [<ffffffff802c3147>] __generic_file_aio_write_nolock+0x363/0x397 >> [<ffffffff802c31e7>] generic_file_aio_write+0x6c/0xc8 >> [<ffffffff8808745b>] :ext3:ext3_file_write+0x23/0xa3 >> [<ffffffff802ebed1>] do_sync_write+0xf0/0x137 >> [<ffffffff80366872>] __up_read+0x94/0x9c >> [<ffffffff8024d3b9>] autoremove_wake_function+0x0/0x3d >> [<ffffffff802d597e>] vma_merge+0x143/0x1f3 >> [<ffffffff80272fae>] ipipe_check_context+0xc/0xf6 >> [<ffffffff80272fae>] ipipe_check_context+0xc/0xf6 >> [<ffffffff8047c5c3>] cond_resched+0x9/0x3e >> [<ffffffff802ec701>] vfs_write+0xcc/0x155 >> [<ffffffff802eccae>] sys_write+0x4c/0x75 >> [<ffffffff8020c1f2>] system_call+0x92/0x97 >> >> >> Code: 48 8b 07 48 c1 e8 3a 48 8b 14 c5 d0 28 5e 80 48 b8 b7 6d db >> RIP [<ffffffff802c4c75>] page_to_pfn+0x9/0x3d >> RSP <ffff810058c21868> >> CR2: 0000000000000000 >> ---[ end trace 6f19d1f5ca1f738f ]--- >> >> >> This problem obviously starts with >> >> struct page * fastcall >> __alloc_pages(gfp_t gfp_mask, unsigned int order, >> struct zonelist *zonelist) >> { >> >> [...] >> >> nopage: >> if (!(gfp_mask & __GFP_NOWARN) && printk_ratelimit()) { >> printk(KERN_WARNING "%s: page allocation failure." >> " order:%d, mode:0x%x\n", >> p->comm, order, gfp_mask); >> dump_stack(); >> show_mem(); >> } >> got_pg: >> trace_mark(mm_page_alloc, "order %u pfn %lu", order, page_to_pfn(page)); >> return page; >> } >> >> >> So we can come along trace_mark with page==NULL. But this is something >> page_to_pfn dislikes (with CONFIG_DISCONTIGMEM at least), and I also >> don't think mm_page_alloc is supposed to trace unsuccessful allocations. >> Shouldn't we put >> >> if (page) >> trace_mark(...); >> > > I would rather go for > > trace_mark(mm_page_alloc, "order %u pfn %lu", order, page?page_to_pfn(page):0); > > So it would be embedded within the disabled branch. So you want to record page==NULL? > >> here? >> >> >> The second point is that I didn't want tracing for this build at all. >> But looking at the disassembly, >> >> ffffffff802c78f1: e8 ba 15 f7 ff callq ffffffff80238eb0 <printk> >> ffffffff802c78f6: e8 ac 67 f4 ff callq ffffffff8020e0a7 <dump_stack> >> ffffffff802c78fb: e8 ef d1 f5 ff callq ffffffff80224aef <show_mem> >> ffffffff802c7900: 48 8b 7d b0 mov -0x50(%rbp),%rdi >> ffffffff802c7904: e8 63 d3 ff ff callq ffffffff802c4c6c <page_to_pfn> >> ffffffff802c7909: 48 8b 45 b0 mov -0x50(%rbp),%rax >> ffffffff802c790d: 48 83 c4 58 add $0x58,%rsp >> ffffffff802c7911: 5b pop %rbx >> ffffffff802c7912: 41 5c pop %r12 >> ffffffff802c7914: 41 5d pop %r13 >> ffffffff802c7916: 41 5e pop %r14 >> ffffffff802c7918: 41 5f pop %r15 >> ffffffff802c791a: c9 leaveq >> ffffffff802c791b: c3 retq >> >> we see a useless page_to_pfn call. Is this is due to >> __mark_check_format, trying to match format against arguments even >> without CONFIG_MARKERS? Compiler issue? >> > > Hrm, this is not good. Can you try the following with your config ? > > #else /* !CONFIG_MARKERS */ > #define __trace_mark(name, call_private, format, args...) \ > if (0) \ > __mark_check_format(format, ## args) > > It should still do the format string test, but completely compile out > the code. > > (please try with a "wrong" format string to see if the compiler still > complains) Yes, works perfectly! For test reference: #define trace_mark(name, format, args...) \ if (0) __mark_check_format(format, ## args) #define __printf(a,b) __attribute__((format(printf,a,b))) static inline void __printf(1, 2) __mark_check_format(const char *fmt, ...) { } extern int foo(int x); int bar(int y) { trace_mark(my_trace, "foo %p", foo(y)); return 0; } Thanks, Jan -- Siemens AG, Corporate Technology, CT SE 2 Corporate Competence Center Embedded Linux