Re: [RFC][PATCH 00/12] various perf fixes

From: Dmitry Vyukov
Date: Mon Feb 15 2016 - 13:34:10 EST


On Mon, Feb 15, 2016 at 7:01 PM, Peter Zijlstra <peterz@xxxxxxxxxxxxx> wrote:
> On Mon, Feb 15, 2016 at 06:45:59PM +0100, Dmitry Vyukov wrote:
>> However, you need to add getpid and gettid syscalls to the list of
>> enabled syscalls in config (they are required for perf_event_open):
>>
>> "enable_syscalls": [
>> "getpid",
>> "gettid",
>> "perf_event_open",
>> "ioctl$PERF*",
>> "prctl$void",
>> "bpf$*",
>> "sched_yield"
>> ]
>>
>
> Yep, that made it work. I'll go have a look.


Glad it works for you. Thanks for bearing with me.

I will fix the confusing "not executing programs" messages.

Re gcc 5.3: it was released on the day I submitted the patch and 5.3
claims to contain only bug fixes, so I guess it is not there.


Btw, do you have CONFIG_KASAN enabled? I also see some some
use-after-free bugs. gcc 5.3 should fully support KASAN including
CONFIG_KASAN_INLINE=y (which is faster).


BUG: KASAN: use-after-free in perf_event_task_tick+0xb47/0xbd0 at addr
ffff880036cff2b8
Read of size 8 by task ksoftirqd/1/12

INFO: Allocated in alloc_perf_context+0x4c/0xf0 age=272 cpu=1 pid=1904
[< none >] ___slab_alloc+0x564/0x5b0 mm/slub.c:2470
[< none >] __slab_alloc+0x66/0xc0 mm/slub.c:2499
[< inline >] slab_alloc_node mm/slub.c:2562
[< inline >] slab_alloc mm/slub.c:2604
[< none >] kmem_cache_alloc_trace+0x25c/0x300 mm/slub.c:2621
[< inline >] kmalloc include/linux/slab.h:463
[< inline >] kzalloc include/linux/slab.h:607
[< none >] alloc_perf_context+0x4c/0xf0 kernel/events/core.c:3337
[< none >] find_get_context.isra.76+0x12a/0x5b0
kernel/events/core.c:3444
[< none >] SYSC_perf_event_open+0xed1/0x1ef0 kernel/events/core.c:8312
[< none >] SyS_perf_event_open+0x39/0x50 kernel/events/core.c:8173
[< none >] tracesys_phase2+0x88/0x8d arch/x86/entry/entry_64.S:269

INFO: Freed in free_ctx+0x47/0x60 age=0 cpu=3 pid=0
[< none >] __slab_free+0x1fc/0x320 mm/slub.c:2680
[< inline >] slab_free mm/slub.c:2835
[< none >] kfree+0x2ac/0x2c0 mm/slub.c:3664
[< none >] free_ctx+0x47/0x60 kernel/events/core.c:1017
[< inline >] __rcu_reclaim kernel/rcu/rcu.h:118
[< inline >] rcu_do_batch kernel/rcu/tree.c:2704
[< inline >] invoke_rcu_callbacks kernel/rcu/tree.c:2970
[< inline >] __rcu_process_callbacks kernel/rcu/tree.c:2937
[< none >] rcu_process_callbacks+0xd5b/0x1440 kernel/rcu/tree.c:2954
[< none >] __do_softirq+0x26a/0x920 kernel/softirq.c:273
[< inline >] invoke_softirq kernel/softirq.c:350
[< none >] irq_exit+0x18f/0x1d0 kernel/softirq.c:391
[< inline >] exiting_irq ./arch/x86/include/asm/apic.h:659
[< none >] smp_apic_timer_interrupt+0x7e/0xa0
arch/x86/kernel/apic/apic.c:932
[< none >] apic_timer_interrupt+0x8c/0xa0
arch/x86/entry/entry_64.S:520
[< inline >] arch_safe_halt ./arch/x86/include/asm/paravirt.h:117
[< none >] default_idle+0x52/0x2e0 arch/x86/kernel/process.c:304
[< none >] arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:295
[< none >] default_idle_call+0x48/0xa0 kernel/sched/idle.c:92
[< inline >] cpuidle_idle_call kernel/sched/idle.c:150
[< inline >] cpu_idle_loop kernel/sched/idle.c:246
[< none >] cpu_startup_entry+0x57e/0x720 kernel/sched/idle.c:294
[< none >] start_secondary+0x30a/0x450 arch/x86/kernel/smpboot.c:251

INFO: Slab 0xffffea0000db3f00 objects=16 used=1 fp=0xffff880036cff1f8
flags=0x1fffc0000004080
INFO: Object 0xffff880036cff1f8 @offset=12792 fp=0xffff880036cfee20

CPU: 1 PID: 12 Comm: ksoftirqd/1 Tainted: G B W 4.5.0-rc4+ #327
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
ffffffff87b05080 ffff88003ed07bc8 ffffffff82be46cf ffffffff00db3f00
fffffbfff0f60a10 ffff88003e804f00 ffff880036cff1f8 ffff880036cfc000
ffffea0000db3f00 ffff88003e25c740 ffff88003ed07bf8 ffffffff8175dea4

Call Trace:
[<ffffffff817678ce>] __asan_report_load8_noabort+0x3e/0x40
mm/kasan/report.c:295
[<ffffffff81629e17>] perf_event_task_tick+0xb47/0xbd0 kernel/events/core.c:3085
[<ffffffff813e7ac2>] scheduler_tick+0x102/0x290 kernel/sched/core.c:2976
[<ffffffff814b5f0c>] update_process_times+0x5c/0x70 kernel/time/timer.c:1425
[<ffffffff814e1b4f>] tick_sched_handle.isra.21+0xaf/0xe0
kernel/time/tick-sched.c:152
[<ffffffff814e2272>] tick_sched_timer+0x72/0x100 kernel/time/tick-sched.c:1088
[< inline >] __run_hrtimer kernel/time/hrtimer.c:1248
[<ffffffff814b7df3>] __hrtimer_run_queues+0x363/0xc20
kernel/time/hrtimer.c:1312
[<ffffffff814b9e12>] hrtimer_interrupt+0x182/0x430 kernel/time/hrtimer.c:1346
[<ffffffff8124e1d2>] local_apic_timer_interrupt+0x72/0xe0
arch/x86/kernel/apic/apic.c:907
[<ffffffff812516f9>] smp_apic_timer_interrupt+0x79/0xa0
arch/x86/kernel/apic/apic.c:931
[<ffffffff8666342c>] apic_timer_interrupt+0x8c/0xa0
arch/x86/entry/entry_64.S:520
<EOI> [<ffffffff8666213e>] _raw_spin_unlock_irqrestore+0x5e/0xc0
kernel/locking/spinlock.c:191
[< inline >] spin_unlock_irqrestore include/linux/spinlock.h:362
[<ffffffff817632ee>] __slab_free+0x1ae/0x320 mm/slub.c:2687