* perf: invalid memory access in perf_swevent_del
@ 2014-05-10 23:34 Sasha Levin
2014-07-26 2:34 ` Sasha Levin
0 siblings, 1 reply; 4+ messages in thread
From: Sasha Levin @ 2014-05-10 23:34 UTC (permalink / raw)
To: Ingo Molnar, acme, Peter Zijlstra; +Cc: Dave Jones, LKML
Hi all,
While fuzzing with trinity inside a KVM tools guest running the latest -next
kernel I've stumbled on the following spew:
[ 6795.260300] BUG: unable to handle kernel paging request at ffff88002e36b5b8
[ 6795.261530] IP: perf_swevent_del (include/linux/list.h:617 include/linux/rculist.h:345 kernel/events/core.c:5671)
[ 6795.262689] PGD 26bc6067 PUD 26bc7067 PMD 705e61067 PTE 800000002e36b060
[ 6795.264634] Oops: 0002 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 6795.266144] Dumping ftrace buffer:
[ 6795.267203] (ftrace buffer empty)
[ 6795.268272] Modules linked in:
[ 6795.269159] CPU: 40 PID: 13449 Comm: trinity-c263 Tainted: G B W 3.15.0-rc4-next-20140508-sasha-00020-gec9304b-dirty #452
[ 6795.270163] task: ffff8800183d3000 ti: ffff880018356000 task.ti: ffff880018356000
[ 6795.270163] RIP: perf_swevent_del (include/linux/list.h:617 include/linux/rculist.h:345 kernel/events/core.c:5671)
[ 6795.270163] RSP: 0000:ffff880018357c80 EFLAGS: 00010046
[ 6795.270163] RAX: 0000000000000000 RBX: ffff8800183c9290 RCX: ffff880016b06c48
[ 6795.270163] RDX: ffff88002e36b5b8 RSI: 0000000000000000 RDI: ffff8800183c9290
[ 6795.270163] RBP: ffff880018357c80 R08: ffff880016b06d88 R09: 0000000000000005
[ 6795.270163] R10: ffff8800183d3000 R11: 0000000000000000 R12: ffff880016b06d7c
[ 6795.270163] R13: ffff880224fdbd90 R14: ffff880224fdbd94 R15: 0000008d7161175a
[ 6795.270163] FS: 00007f068aa56700(0000) GS:ffff880224e00000(0000) knlGS:0000000000000000
[ 6795.270163] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 6795.270163] CR2: ffff88002e36b5b8 CR3: 0000000018361000 CR4: 00000000000006a0
[ 6795.270163] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
[ 6795.270163] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
[ 6795.270163] Stack:
[ 6795.270163] ffff880018357cd0 ffffffff9f2780fb ffff880018357ca0 ffff880016b06d88
[ 6795.270163] ffff880018357cd0 ffff880016b06c48 ffff880224fdbd90 ffff880224fdbd94
[ 6795.270163] ffff880016b06d7c ffff880016b06d38 ffff880018357d30 ffffffff9f2784f6
[ 6795.270163] Call Trace:
[ 6795.270163] event_sched_out.isra.46 (include/linux/perf_event.h:634 kernel/events/core.c:1416)
[ 6795.270163] group_sched_out (kernel/events/core.c:1440)
[ 6795.270163] ctx_sched_out (kernel/events/core.c:2167 (discriminator 2))
[ 6795.270163] __perf_event_task_sched_out (kernel/events/core.c:2342 kernel/events/core.c:2367)
[ 6795.270163] ? __perf_event_task_sched_out (include/linux/rcupdate.h:867 kernel/events/core.c:2296 kernel/events/core.c:2367)
[ 6795.270163] ? update_curr (kernel/sched/stats.h:259 kernel/sched/fair.c:721)
[ 6795.270163] perf_event_task_sched_out (include/linux/perf_event.h:690)
[ 6795.270163] ? set_next_entity (kernel/sched/fair.c:7708 kernel/sched/fair.c:2891)
[ 6795.270163] ? pick_next_task_fair (kernel/sched/fair.c:4761)
[ 6795.270163] ? sched_clock (arch/x86/include/asm/paravirt.h:192 arch/x86/kernel/tsc.c:305)
[ 6795.270163] ? sched_clock_cpu (kernel/sched/clock.c:311)
[ 6795.270163] __schedule (kernel/sched/core.c:2077 kernel/sched/core.c:2115 kernel/sched/core.c:2239 kernel/sched/core.c:2728)
[ 6795.270163] ? _raw_spin_unlock (arch/x86/include/asm/preempt.h:98 include/linux/spinlock_api_smp.h:152 kernel/locking/spinlock.c:183)
[ 6795.270163] ? context_tracking_user_exit (arch/x86/include/asm/paravirt.h:809 (discriminator 2) kernel/context_tracking.c:182 (discriminator 2))
[ 6795.270163] schedule (kernel/sched/core.c:2765)
[ 6795.270163] schedule_user (kernel/sched/core.c:2778 include/linux/jump_label.h:105 include/linux/context_tracking_state.h:27 include/linux/context_tracking.h:20 kernel/sched/core.c:2779)
[ 6795.270163] retint_careful (arch/x86/kernel/entry_64.S:1109)
[ 6795.270163] Code: 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 5d c3 66 2e 0f 1f 84 00 00 00 00 00 48 8b 47 40 55 48 8b 57 48 48 89 e5 48 85 c0 <48> 89 02 74 04 48 89 50 08 49 b8 00 02 20 00 00 00 ad de 5d 4c
[ 6795.270163] RIP perf_swevent_del (include/linux/list.h:617 include/linux/rculist.h:345 kernel/events/core.c:5671)
[ 6795.270163] RSP <ffff880018357c80>
[ 6795.270163] CR2: ffff88002e36b5b8
Thanks,
Sasha
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: perf: invalid memory access in perf_swevent_del
2014-05-10 23:34 perf: invalid memory access in perf_swevent_del Sasha Levin
@ 2014-07-26 2:34 ` Sasha Levin
2014-07-28 17:04 ` Peter Zijlstra
0 siblings, 1 reply; 4+ messages in thread
From: Sasha Levin @ 2014-07-26 2:34 UTC (permalink / raw)
To: Ingo Molnar, acme, Peter Zijlstra; +Cc: Dave Jones, LKML
On 05/10/2014 07:34 PM, Sasha Levin wrote:
> Hi all,
>
> While fuzzing with trinity inside a KVM tools guest running the latest -next
> kernel I've stumbled on the following spew:
Ping? I'm still seeing corruption on perf_swevent_del and perf_swevent_init:
[ 488.092839] AddressSanitizer: use after free in perf_swevent_del+0x33/0x70 at addr ffff8805f430ea48
[ 488.094444] page:ffffea0017d0c380 count:0 mapcount:0 mapping: (null) index:0x0
[ 488.095681] page flags: 0x6fffff80008000(tail)
[ 488.096407] page dumped because: kasan error
[ 488.097116] CPU: 17 PID: 9306 Comm: trinity-main Not tainted 3.16.0-rc6-next-20140725-sasha-00048-ga713fc0-dirty #937
[ 488.098736] 00000000000000fb 0000000000000000 ffffea0017d0c380 ffff8805f444b740
[ 488.099933] ffffffffb6dc96f3 ffff8805f444b810 ffff8805f444b800 ffffffffb242d17c
[ 488.100020] ffff880be215f448 ffff880be215f45d ffff8805ff7e2dc0 ffff8805ff7e2dd0
[ 488.100020] Call Trace:
[ 488.100020] dump_stack (lib/dump_stack.c:52)
[ 488.100020] kasan_report_error (mm/kasan/report.c:98 mm/kasan/report.c:166)
[ 488.100020] ? kvm_clock_read (./arch/x86/include/asm/preempt.h:90 arch/x86/kernel/kvmclock.c:86)
[ 488.100020] ? sched_clock (./arch/x86/include/asm/paravirt.h:192 arch/x86/kernel/tsc.c:304)
[ 488.100020] ? sched_clock_local (kernel/sched/clock.c:214)
[ 488.100020] __asan_store8 (mm/kasan/kasan.c:400)
[ 488.100020] ? perf_swevent_del (include/linux/list.h:618 include/linux/rculist.h:345 kernel/events/core.c:5758)
[ 488.100020] perf_swevent_del (include/linux/list.h:618 include/linux/rculist.h:345 kernel/events/core.c:5758)
[ 488.100020] event_sched_out.isra.49 (kernel/events/core.c:1416)
[ 488.100020] group_sched_out (kernel/events/core.c:1442)
[ 488.100020] ctx_sched_out (kernel/events/core.c:2185 (discriminator 3))
[ 488.100020] __perf_event_task_sched_out (kernel/events/core.c:2360 kernel/events/core.c:2385)
[ 488.100020] ? __perf_event_task_sched_out (include/linux/rcupdate.h:806 kernel/events/core.c:2314 kernel/events/core.c:2385)
[ 488.100020] ? update_stats_wait_end (kernel/sched/fair.c:760)
[ 488.100020] perf_event_task_sched_out (include/linux/perf_event.h:702)
[ 488.100020] ? __schedule (kernel/sched/core.c:2773)
[ 488.100020] ? __schedule (kernel/sched/core.c:2773)
[ 488.100020] __schedule (kernel/sched/core.c:2146 kernel/sched/core.c:2184 kernel/sched/core.c:2308 kernel/sched/core.c:2810)
[ 488.100020] preempt_schedule_irq (./arch/x86/include/asm/paravirt.h:814 kernel/sched/core.c:2927)
[ 488.100020] retint_kernel (arch/x86/kernel/entry_64.S:935)
[ 488.100020] ? __asan_load4 (mm/kasan/kasan.c:358)
[ 488.100020] ? debug_lockdep_rcu_enabled (kernel/rcu/update.c:134)
[ 488.100020] __fget_light (include/linux/fdtable.h:77 fs/file.c:684)
[ 488.100020] __fdget_raw (fs/file.c:704)
[ 488.100020] path_init (include/linux/file.h:60 fs/namei.c:1873)
[ 488.100020] ? path_lookupat (fs/namei.c:1937)
[ 488.100020] ? trace_hardirqs_on (kernel/locking/lockdep.c:2607)
[ 488.100020] path_lookupat (fs/namei.c:1937)
[ 488.100020] ? poison_shadow (mm/kasan/kasan.c:76)
[ 488.100020] ? unpoison_shadow (mm/kasan/kasan.c:82)
[ 488.100020] ? kasan_slab_alloc (mm/kasan/kasan.c:206)
[ 488.100020] ? strncpy_from_user (./arch/x86/include/asm/word-at-a-time.h:48 lib/strncpy_from_user.c:44 lib/strncpy_from_user.c:109)
[ 488.100020] filename_lookup (fs/namei.c:1984)
[ 488.100020] user_path_at_empty (fs/namei.c:2135)
[ 488.100020] ? check_chain_key (kernel/locking/lockdep.c:2188)
[ 488.100020] ? put_lock_stats.isra.13 (./arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 488.100020] ? get_parent_ip (kernel/sched/core.c:2561)
[ 488.100020] user_path_at (fs/namei.c:2146)
[ 488.100020] vfs_fstatat (fs/stat.c:107)
[ 488.100020] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2600)
[ 488.100020] SYSC_newfstatat (fs/stat.c:298)
[ 488.100020] ? syscall_trace_enter (arch/x86/kernel/ptrace.c:1500 (discriminator 2))
[ 488.100020] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2600)
[ 488.100020] ? tracesys (arch/x86/kernel/entry_64.S:530)
[ 488.100020] SyS_newfstatat (fs/stat.c:291)
[ 488.100020] tracesys (arch/x86/kernel/entry_64.S:541)
[ 488.100020] Write of size 8 by thread T9306:
[ 488.100020] Memory state around the buggy address:
[ 488.100020] ffff8805f430e780: fc fc fc fc fc fc fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430e800: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430e880: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430e900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430e980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] >ffff8805f430ea00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ^
[ 488.100020] ffff8805f430ea80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430eb00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430eb80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430ec00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 488.100020] ffff8805f430ec80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 517.616094] =============================================================================
[ 517.619549] BUG kmalloc-4096 (Not tainted): Poison overwritten
[ 517.621321] -----------------------------------------------------------------------------
[ 517.621321]
[ 517.621321] Disabling lock debugging due to kernel taint
[ 517.621321] INFO: 0xffff8805f430ea48-0xffff8805f430eb77. First byte 0x0 instead of 0x6b
[ 517.621321] INFO: Allocated in perf_swevent_init+0x29f/0x440 age=14082 cpu=17 pid=9306
[ 517.621321] __slab_alloc+0x65e/0x740
[ 517.621321] kmem_cache_alloc_trace+0x17c/0x3a0
[ 517.621321] perf_swevent_init+0x29f/0x440
[ 517.621321] perf_init_event+0x293/0x340
[ 517.621321] perf_event_alloc+0x5b8/0x6e0
[ 517.621321] SYSC_perf_event_open+0x39b/0xf50
[ 517.621321] SyS_perf_event_open+0x9/0x10
[ 517.621321] tracesys+0xe1/0xe6
[ 517.621321] INFO: Freed in rcu_nocb_kthread+0x911/0x13f0 age=2958 cpu=3 pid=25
[ 517.621321] __slab_free+0x276/0x3e0
[ 517.621321] kfree+0x31a/0x390
[ 517.621321] rcu_nocb_kthread+0x911/0x13f0
[ 517.621321] kthread+0x144/0x170
[ 517.621321] ret_from_fork+0x7c/0xb0
[ 517.621321] INFO: Slab 0xffffea0017d0c200 objects=7 used=7 fp=0x (null) flags=0x6fffff80004080
[ 517.621321] INFO: Object 0xffff8805f430e7b0 @offset=26544 fp=0xffff8805f4308000
[...]
Thanks,
Sasha
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: perf: invalid memory access in perf_swevent_del
2014-07-26 2:34 ` Sasha Levin
@ 2014-07-28 17:04 ` Peter Zijlstra
2014-07-28 19:55 ` Sasha Levin
0 siblings, 1 reply; 4+ messages in thread
From: Peter Zijlstra @ 2014-07-28 17:04 UTC (permalink / raw)
To: Sasha Levin; +Cc: Ingo Molnar, acme, Dave Jones, LKML
[-- Attachment #1: Type: text/plain, Size: 4086 bytes --]
On Fri, Jul 25, 2014 at 10:34:11PM -0400, Sasha Levin wrote:
> On 05/10/2014 07:34 PM, Sasha Levin wrote:
> > Hi all,
> >
> > While fuzzing with trinity inside a KVM tools guest running the latest -next
> > kernel I've stumbled on the following spew:
>
> Ping? I'm still seeing corruption on perf_swevent_del and perf_swevent_init:
>
> [ 488.092839] AddressSanitizer: use after free in perf_swevent_del+0x33/0x70 at addr ffff8805f430ea48
> [ 488.100020] Call Trace:
> [ 488.100020] dump_stack (lib/dump_stack.c:52)
> [ 488.100020] kasan_report_error (mm/kasan/report.c:98 mm/kasan/report.c:166)
> [ 488.100020] __asan_store8 (mm/kasan/kasan.c:400)
> [ 488.100020] perf_swevent_del (include/linux/list.h:618 include/linux/rculist.h:345 kernel/events/core.c:5758)
> [ 488.100020] event_sched_out.isra.49 (kernel/events/core.c:1416)
> [ 488.100020] group_sched_out (kernel/events/core.c:1442)
> [ 488.100020] ctx_sched_out (kernel/events/core.c:2185 (discriminator 3))
> [ 488.100020] __perf_event_task_sched_out (kernel/events/core.c:2360 kernel/events/core.c:2385)
> [ 488.100020] perf_event_task_sched_out (include/linux/perf_event.h:702)
> [ 488.100020] Write of size 8 by thread T9306:
> [ 488.100020] Memory state around the buggy address:
> [ 488.100020] ffff8805f430e780: fc fc fc fc fc fc fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430e800: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430e880: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430e900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430e980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] >ffff8805f430ea00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ^
> [ 488.100020] ffff8805f430ea80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430eb00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430eb80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430ec00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> [ 488.100020] ffff8805f430ec80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
Useful, that kasan doesn't use POISON_FREE... :/
> [ 517.616094] =============================================================================
> [ 517.619549] BUG kmalloc-4096 (Not tainted): Poison overwritten
> [ 517.621321] -----------------------------------------------------------------------------
> [ 517.621321]
> [ 517.621321] Disabling lock debugging due to kernel taint
> [ 517.621321] INFO: 0xffff8805f430ea48-0xffff8805f430eb77. First byte 0x0 instead of 0x6b
> [ 517.621321] INFO: Allocated in perf_swevent_init+0x29f/0x440 age=14082 cpu=17 pid=9306
> [ 517.621321] __slab_alloc+0x65e/0x740
> [ 517.621321] kmem_cache_alloc_trace+0x17c/0x3a0
> [ 517.621321] perf_swevent_init+0x29f/0x440
> [ 517.621321] perf_init_event+0x293/0x340
> [ 517.621321] perf_event_alloc+0x5b8/0x6e0
> [ 517.621321] SYSC_perf_event_open+0x39b/0xf50
> [ 517.621321] SyS_perf_event_open+0x9/0x10
> [ 517.621321] tracesys+0xe1/0xe6
So this would be swevent_hlist_get_cpu()'s swevent_hlist allocation.
> [ 517.621321] INFO: Freed in rcu_nocb_kthread+0x911/0x13f0 age=2958 cpu=3 pid=25
> [ 517.621321] __slab_free+0x276/0x3e0
> [ 517.621321] kfree+0x31a/0x390
> [ 517.621321] rcu_nocb_kthread+0x911/0x13f0
> [ 517.621321] kthread+0x144/0x170
> [ 517.621321] ret_from_fork+0x7c/0xb0
> [ 517.621321] INFO: Slab 0xffffea0017d0c200 objects=7 used=7 fp=0x (null) flags=0x6fffff80004080
> [ 517.621321] INFO: Object 0xffff8805f430e7b0 @offset=26544 fp=0xffff8805f4308000
And this would be the corresponding free:
sw_perf_event_destroy()
swevent_hlist_put()
swevent_hlist_put_cpu()
swevent_hlist_release()
Which would suggest a refcounting boo-boo, cute.
Does your trinity do hotplug while creating/destroying events?
[-- Attachment #2: Type: application/pgp-signature, Size: 836 bytes --]
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: perf: invalid memory access in perf_swevent_del
2014-07-28 17:04 ` Peter Zijlstra
@ 2014-07-28 19:55 ` Sasha Levin
0 siblings, 0 replies; 4+ messages in thread
From: Sasha Levin @ 2014-07-28 19:55 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: Ingo Molnar, acme, Dave Jones, LKML
On 07/28/2014 01:04 PM, Peter Zijlstra wrote:
> Does your trinity do hotplug while creating/destroying events?
It might write to random /sysfs files, I've seen it do hotplugs of
about everything possible.
Thanks,
Sasha
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2014-07-28 19:55 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-05-10 23:34 perf: invalid memory access in perf_swevent_del Sasha Levin
2014-07-26 2:34 ` Sasha Levin
2014-07-28 17:04 ` Peter Zijlstra
2014-07-28 19:55 ` Sasha Levin
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox