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

[Dmitry Vyukov]

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