slab: odd BUG on kzalloc

DISCUSSION Sasha Levin 3 participants 5 messages Feb 17, 2013 – Feb 19, 2013 Memory management

lore

Share & tools

lore

Sasha Levin

author

2013-02-17 15:56 UTC #0 lore raw

Hi all,

I was fuzzing with trinity inside a KVM tools guest, running latest -next kernel, and hit the following bug:

[  169.773688] BUG: unable to handle kernel NULL pointer dereference at 0000000000000001
[  169.774976] IP: [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.775989] PGD 93e02067 PUD ac1a2067 PMD 0
[  169.776898] Oops: 0002 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  169.777923] Dumping ftrace buffer:
[  169.778595]    (ftrace buffer empty)
[  169.779352] Modules linked in:
[  169.779996] CPU 0
[  169.780031] Pid: 13438, comm: trinity Tainted: G        W    3.8.0-rc7-next-20130215-sasha-00003-gea816fa #286
[  169.780031] RIP: 0010:[<ffffffff81a15c2f>]  [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.780031] RSP: 0018:ffff8800aef19e00  EFLAGS: 00010206
[  169.780031] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000080
[  169.780031] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000001
[  169.780031] RBP: ffff8800aef19e68 R08: 0000000000000000 R09: 0000000000000001
[  169.780031] R10: 0000000000000001 R11: 0000000000000000 R12: ffff8800bb001b00
[  169.780031] R13: ffff8800bb001b00 R14: 0000000000000001 R15: 0000000000537000
[  169.780031] FS:  00007fb73581b700(0000) GS:ffff8800bb600000(0000) knlGS:0000000000000000
[  169.780031] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  169.780031] CR2: 0000000000000001 CR3: 00000000aed31000 CR4: 00000000000406f0
[  169.780031] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  169.780031] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  169.780031] Process trinity (pid: 13438, threadinfo ffff8800aef18000, task ffff8800aed7b000)
[  169.780031] Stack:
[  169.780031]  ffffffff81269586 ffff8800aef19e38 0000000000000280 ffffffff81291a2e
[  169.780031]  000080d0aa39d9e8 ffff8800aef19e48 0000000000000000 ffff8800aa39d9e8
[  169.780031]  ffff8800a65cc780 ffff8800aa39d960 00000000ffffffea 0000000000000000
[  169.780031] Call Trace:
[  169.780031]  [<ffffffff81269586>] ? kmem_cache_alloc_trace+0x176/0x330
[  169.780031]  [<ffffffff81291a2e>] ? alloc_pipe_info+0x3e/0xa0
[  169.780031]  [<ffffffff81291a2e>] alloc_pipe_info+0x3e/0xa0
[  169.780031]  [<ffffffff81291ac6>] get_pipe_inode+0x36/0xe0
[  169.780031]  [<ffffffff81291d63>] create_pipe_files+0x23/0x140
[  169.780031]  [<ffffffff81291ebd>] __do_pipe_flags+0x3d/0xe0
[  169.780031]  [<ffffffff81291fbb>] sys_pipe2+0x1b/0xa0
[  169.780031]  [<ffffffff83d96135>] ? tracesys+0x7e/0xe6
[  169.780031]  [<ffffffff8129204b>] sys_pipe+0xb/0x10
[  169.780031]  [<ffffffff83d96198>] tracesys+0xe1/0xe6
[  169.780031] Code: 1e 44 88 1f c3 90 90 90 90 90 90 90 49 89 f9 48 89 d1 83 e2 07 48 c1 e9 03 40 0f b6 f6 48 b8 01 01 01 01 01
01 01 01 48 0f af c6 <f3> 48 ab 89 d1 f3 aa 4c 89 c8 c3 66 66 66 90 66 66 66 90 66 66
[  169.780031] RIP  [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.780031]  RSP <ffff8800aef19e00>
[  169.780031] CR2: 0000000000000001
[  169.930103] ---[ end trace 4d135f3def21b4bd ]---

The code translates to the following in fs/pipe.c:alloc_pipe_info :

        pipe = kzalloc(sizeof(struct pipe_inode_info), GFP_KERNEL);
        if (pipe) {
                pipe->bufs = kzalloc(sizeof(struct pipe_buffer) * PIPE_DEF_BUFFERS, GFP_KERNEL); <=== this
                if (pipe->bufs) {
                        init_waitqueue_head(&pipe->wait);

Thanks,
Sasha

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Christoph Lameter

2013-02-19 00:35 UTC #1 lore raw

Maybe the result of free pointer corruption due to writing to an object after free. Please run again with slub_debug specified on the commandline to get detailed reports on how this came about.

Quoted 58 lines · Sasha Levin

Hi all,

I was fuzzing with trinity inside a KVM tools guest, running latest -next kernel, and hit the following bug:

[  169.773688] BUG: unable to handle kernel NULL pointer dereference at 0000000000000001
[  169.774976] IP: [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.775989] PGD 93e02067 PUD ac1a2067 PMD 0
[  169.776898] Oops: 0002 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  169.777923] Dumping ftrace buffer:
[  169.778595]    (ftrace buffer empty)
[  169.779352] Modules linked in:
[  169.779996] CPU 0
[  169.780031] Pid: 13438, comm: trinity Tainted: G        W    3.8.0-rc7-next-20130215-sasha-00003-gea816fa #286
[  169.780031] RIP: 0010:[<ffffffff81a15c2f>]  [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.780031] RSP: 0018:ffff8800aef19e00  EFLAGS: 00010206
[  169.780031] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000080
[  169.780031] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000001
[  169.780031] RBP: ffff8800aef19e68 R08: 0000000000000000 R09: 0000000000000001
[  169.780031] R10: 0000000000000001 R11: 0000000000000000 R12: ffff8800bb001b00
[  169.780031] R13: ffff8800bb001b00 R14: 0000000000000001 R15: 0000000000537000
[  169.780031] FS:  00007fb73581b700(0000) GS:ffff8800bb600000(0000) knlGS:0000000000000000
[  169.780031] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  169.780031] CR2: 0000000000000001 CR3: 00000000aed31000 CR4: 00000000000406f0
[  169.780031] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  169.780031] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  169.780031] Process trinity (pid: 13438, threadinfo ffff8800aef18000, task ffff8800aed7b000)
[  169.780031] Stack:
[  169.780031]  ffffffff81269586 ffff8800aef19e38 0000000000000280 ffffffff81291a2e
[  169.780031]  000080d0aa39d9e8 ffff8800aef19e48 0000000000000000 ffff8800aa39d9e8
[  169.780031]  ffff8800a65cc780 ffff8800aa39d960 00000000ffffffea 0000000000000000
[  169.780031] Call Trace:
[  169.780031]  [<ffffffff81269586>] ? kmem_cache_alloc_trace+0x176/0x330
[  169.780031]  [<ffffffff81291a2e>] ? alloc_pipe_info+0x3e/0xa0
[  169.780031]  [<ffffffff81291a2e>] alloc_pipe_info+0x3e/0xa0
[  169.780031]  [<ffffffff81291ac6>] get_pipe_inode+0x36/0xe0
[  169.780031]  [<ffffffff81291d63>] create_pipe_files+0x23/0x140
[  169.780031]  [<ffffffff81291ebd>] __do_pipe_flags+0x3d/0xe0
[  169.780031]  [<ffffffff81291fbb>] sys_pipe2+0x1b/0xa0
[  169.780031]  [<ffffffff83d96135>] ? tracesys+0x7e/0xe6
[  169.780031]  [<ffffffff8129204b>] sys_pipe+0xb/0x10
[  169.780031]  [<ffffffff83d96198>] tracesys+0xe1/0xe6
[  169.780031] Code: 1e 44 88 1f c3 90 90 90 90 90 90 90 49 89 f9 48 89 d1 83 e2 07 48 c1 e9 03 40 0f b6 f6 48 b8 01 01 01 01 01
01 01 01 48 0f af c6 <f3> 48 ab 89 d1 f3 aa 4c 89 c8 c3 66 66 66 90 66 66 66 90 66 66
[  169.780031] RIP  [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.780031]  RSP <ffff8800aef19e00>
[  169.780031] CR2: 0000000000000001
[  169.930103] ---[ end trace 4d135f3def21b4bd ]---

The code translates to the following in fs/pipe.c:alloc_pipe_info :

        pipe = kzalloc(sizeof(struct pipe_inode_info), GFP_KERNEL);
        if (pipe) {
                pipe->bufs = kzalloc(sizeof(struct pipe_buffer) * PIPE_DEF_BUFFERS, GFP_KERNEL); <=== this
                if (pipe->bufs) {
                        init_waitqueue_head(&pipe->wait);

Quoted 3 lines

Thanks,
Sasha

Sasha Levin

author

2013-02-19 18:18 UTC #2 lore raw

Quoted 4 lines · Christoph Lameter

Maybe the result of free pointer corruption due to writing to an object after free. Please run again with slub_debug specified on the commandline to get detailed reports on how this came about.

Quoted 63 lines

Quoted 61 lines · Sasha Levin

Hi all,

I was fuzzing with trinity inside a KVM tools guest, running latest -next kernel, and hit the following bug:

[  169.773688] BUG: unable to handle kernel NULL pointer dereference at 0000000000000001
[  169.774976] IP: [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.775989] PGD 93e02067 PUD ac1a2067 PMD 0
[  169.776898] Oops: 0002 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  169.777923] Dumping ftrace buffer:
[  169.778595]    (ftrace buffer empty)
[  169.779352] Modules linked in:
[  169.779996] CPU 0
[  169.780031] Pid: 13438, comm: trinity Tainted: G        W    3.8.0-rc7-next-20130215-sasha-00003-gea816fa #286
[  169.780031] RIP: 0010:[<ffffffff81a15c2f>]  [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.780031] RSP: 0018:ffff8800aef19e00  EFLAGS: 00010206
[  169.780031] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000080
[  169.780031] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000001
[  169.780031] RBP: ffff8800aef19e68 R08: 0000000000000000 R09: 0000000000000001
[  169.780031] R10: 0000000000000001 R11: 0000000000000000 R12: ffff8800bb001b00
[  169.780031] R13: ffff8800bb001b00 R14: 0000000000000001 R15: 0000000000537000
[  169.780031] FS:  00007fb73581b700(0000) GS:ffff8800bb600000(0000) knlGS:0000000000000000
[  169.780031] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  169.780031] CR2: 0000000000000001 CR3: 00000000aed31000 CR4: 00000000000406f0
[  169.780031] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  169.780031] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  169.780031] Process trinity (pid: 13438, threadinfo ffff8800aef18000, task ffff8800aed7b000)
[  169.780031] Stack:
[  169.780031]  ffffffff81269586 ffff8800aef19e38 0000000000000280 ffffffff81291a2e
[  169.780031]  000080d0aa39d9e8 ffff8800aef19e48 0000000000000000 ffff8800aa39d9e8
[  169.780031]  ffff8800a65cc780 ffff8800aa39d960 00000000ffffffea 0000000000000000
[  169.780031] Call Trace:
[  169.780031]  [<ffffffff81269586>] ? kmem_cache_alloc_trace+0x176/0x330
[  169.780031]  [<ffffffff81291a2e>] ? alloc_pipe_info+0x3e/0xa0
[  169.780031]  [<ffffffff81291a2e>] alloc_pipe_info+0x3e/0xa0
[  169.780031]  [<ffffffff81291ac6>] get_pipe_inode+0x36/0xe0
[  169.780031]  [<ffffffff81291d63>] create_pipe_files+0x23/0x140
[  169.780031]  [<ffffffff81291ebd>] __do_pipe_flags+0x3d/0xe0
[  169.780031]  [<ffffffff81291fbb>] sys_pipe2+0x1b/0xa0
[  169.780031]  [<ffffffff83d96135>] ? tracesys+0x7e/0xe6
[  169.780031]  [<ffffffff8129204b>] sys_pipe+0xb/0x10
[  169.780031]  [<ffffffff83d96198>] tracesys+0xe1/0xe6
[  169.780031] Code: 1e 44 88 1f c3 90 90 90 90 90 90 90 49 89 f9 48 89 d1 83 e2 07 48 c1 e9 03 40 0f b6 f6 48 b8 01 01 01 01 01
01 01 01 48 0f af c6 <f3> 48 ab 89 d1 f3 aa 4c 89 c8 c3 66 66 66 90 66 66 66 90 66 66
[  169.780031] RIP  [<ffffffff81a15c2f>] memset+0x1f/0xb0
[  169.780031]  RSP <ffff8800aef19e00>
[  169.780031] CR2: 0000000000000001
[  169.930103] ---[ end trace 4d135f3def21b4bd ]---

The code translates to the following in fs/pipe.c:alloc_pipe_info :

        pipe = kzalloc(sizeof(struct pipe_inode_info), GFP_KERNEL);
        if (pipe) {
                pipe->bufs = kzalloc(sizeof(struct pipe_buffer) * PIPE_DEF_BUFFERS, GFP_KERNEL); <=== this
                if (pipe->bufs) {
                        init_waitqueue_head(&pipe->wait);

Thanks,
Sasha

Looks like it's not specific to pipe(). I've also got this one now:

[  351.807837] BUG: unable to handle kernel NULL pointer dereference at 0000000000000001
[  351.807846] IP: [<ffffffff81a2e8cf>] memset+0x1f/0xb0
[  351.807851] PGD a3562067 PUD a2f4e067 PMD 0
[  351.807856] Oops: 0002 [#2] PREEMPT SMP DEBUG_PAGEALLOC
[  351.807871] Modules linked in:
[  351.807877] CPU 0
[  351.807878] Pid: 27224, comm: trinity Tainted: G      D W    3.8.0-rc7-next-20130219-sasha-00030-gc37ee25 #4
[  351.807883] RIP: 0010:[<ffffffff81a2e8cf>]  [<ffffffff81a2e8cf>] memset+0x1f/0xb0
[  351.807885] RSP: 0018:ffff8800b06abea0  EFLAGS: 00010206
[  351.807887] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000080
[  351.807889] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000001
[  351.807890] RBP: ffff8800b06abf08 R08: 00000000001da950 R09: 0000000000000001
[  351.807892] R10: 0000000000d14000 R11: 0000000000000000 R12: 0000000000000001
[  351.807893] R13: 00000000000080d0 R14: ffff8800bb001b00 R15: 0000000000000320
[  351.807896] FS:  00007fa640100700(0000) GS:ffff8800bb600000(0000) knlGS:0000000000000000
[  351.807898] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  351.807900] CR2: 0000000000000001 CR3: 00000000a4c68000 CR4: 00000000000406f0
[  351.807911] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  351.807918] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  351.807921] Process trinity (pid: 27224, threadinfo ffff8800b06aa000, task ffff8800a2ec0000)
[  351.807922] Stack:
[  351.807928]  ffffffff8126cd1f 00007fa6401006a8 0000000000d14000 ffff8800bb001b00
[  351.807933]  ffffffff812d5790 0000000000000004 0000000000000000 ffff8800b06abee8
[  351.807937]  0000000000000036 ffffffff83e529a0 0000000000000036 ffffffffffffffea
[  351.807938] Call Trace:
[  351.807948]  [<ffffffff8126cd1f>] ? kmem_cache_alloc_trace+0x19f/0x380
[  351.807966]  [<ffffffff812d5790>] ? fsnotify_alloc_group+0x20/0xe0
[  351.807971]  [<ffffffff812d5790>] fsnotify_alloc_group+0x20/0xe0
[  351.807976]  [<ffffffff812d9d78>] sys_fanotify_init+0xe8/0x280
[  351.807982]  [<ffffffff83da0718>] tracesys+0xe1/0xe6
[  351.808029] Code: 1e 44 88 1f c3 90 90 90 90 90 90 90 49 89 f9 48 89 d1 83 e2 07 48 c1 e9 03 40 0f b6 f6 48 b8 01 01 01 01 01
01 01 01 48 0f af c6 <f3> 48 ab 89 d1 f3 aa 4c 89 c8 c3 66 66 66 90 66 66 66 90 66 66
[  351.808033] RIP  [<ffffffff81a2e8cf>] memset+0x1f/0xb0
[  351.808035]  RSP <ffff8800b06abea0>
[  351.808036] CR2: 0000000000000001
[  351.808041] ---[ end trace f1c91196bf6ef436 ]---

Since I've managed to reproduce it, I'll go ahead and add slub_debug and see what it tells us.

Thanks,
Sasha

Dave Jones

2013-02-19 18:29 UTC #3 lore raw

Quoted 10 lines · Sasha Levin

Quoted 9 lines

[  169.930103] ---[ end trace 4d135f3def21b4bd ]---

The code translates to the following in fs/pipe.c:alloc_pipe_info :

        pipe = kzalloc(sizeof(struct pipe_inode_info), GFP_KERNEL);
        if (pipe) {
                pipe->bufs = kzalloc(sizeof(struct pipe_buffer) * PIPE_DEF_BUFFERS, GFP_KERNEL); <=== this
                if (pipe->bufs) {
                        init_waitqueue_head(&pipe->wait);

Quoted 3 lines

Looks like it's not specific to pipe(). I've also got this one now:
Since I've managed to reproduce it, I'll go ahead and add slub_debug and see what it tells us.

I'm curious, did you recently upgrade gcc, or other parts of the toolchain ? This, and one of the other 'weird' bugs you reported recently have me wondering if perhaps you're seeing a compiler bug.

Dave

Sasha Levin

author

2013-02-19 18:33 UTC #4 lore raw

Quoted 12 lines · Dave Jones

Quoted 10 lines · Sasha Levin

Quoted 9 lines

[  169.930103] ---[ end trace 4d135f3def21b4bd ]---

The code translates to the following in fs/pipe.c:alloc_pipe_info :

        pipe = kzalloc(sizeof(struct pipe_inode_info), GFP_KERNEL);
        if (pipe) {
                pipe->bufs = kzalloc(sizeof(struct pipe_buffer) * PIPE_DEF_BUFFERS, GFP_KERNEL); <=== this
                if (pipe->bufs) {
                        init_waitqueue_head(&pipe->wait);

Quoted 7 lines

Quoted 3 lines
Looks like it's not specific to pipe(). I've also got this one now:
Since I've managed to reproduce it, I'll go ahead and add slub_debug and see what it tells us.
I'm curious, did you recently upgrade gcc, or other parts of the toolchain ? This, and one of the other 'weird' bugs you reported recently have me wondering if perhaps you're seeing a compiler bug.

It happened once on a kernel built on my gentoo box with is generally up to date, but the other time the kernel was built on my mini-server running ubuntu, which isn't updated that often.

So I don't think compiler trickery is involved.

Thanks,
Sasha