Re: BUG due to mm-instrumentation

* 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.

> 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)

Mathieu

> Jan
> 
> -- 
> Siemens AG, Corporate Technology, CT SE 2
> Corporate Competence Center Embedded Linux
> _______________________________________________
> Ltt-dev mailing list
> [email protected]
> http://listserv.shafik.org/mailman/listinfo/ltt-dev
> 

-- 
Mathieu Desnoyers
Computer Engineering Ph.D. Student, Ecole Polytechnique de Montreal
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68