Re: perf: perf_fuzzer WARNING: ring_buffer.c:546 __rb_free_aux

From: Vince Weaver <vincent.weaver@maine.edu>
To: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Vince Weaver <vincent.weaver@maine.edu>,
	linux-kernel@vger.kernel.org,
	Peter Zijlstra <peterz@infradead.org>,
	Ingo Molnar <mingo@redhat.com>,
	Arnaldo Carvalho de Melo <acme@kernel.org>
Subject: Re: perf: perf_fuzzer WARNING: ring_buffer.c:546 __rb_free_aux
Date: Thu, 17 Nov 2016 14:02:08 -0500 (EST)	[thread overview]
Message-ID: <alpine.DEB.2.20.1611171353250.11652@macbook-air> (raw)
In-Reply-To: <87a8d7o06b.fsf@ashishki-desk.ger.corp.intel.com>

On Thu, 10 Nov 2016, Alexander Shishkin wrote:

> Yeah, this really shouldn't be happening. How reproducible is this? Any
> clues that may help me reproduce it?

I hit this again on the skylake machine, but it takes a while (many days
of fuzzing).

Also maybe related, it hits this WARN_ONCE in perf_mmap_close() first

	               /* this has to be the last one */
                rb_free_aux(rb);
                WARN_ON_ONCE(atomic_read(&rb->aux_refcount));

[122026.776273] ------------[ cut here ]------------
[122026.785852] WARNING: CPU: 0 PID: 6027 at kernel/events/core.c:5004 perf_mmap_close+0x45c/0x470
[122026.974275] CPU: 0 PID: 6027 Comm: perf_fuzzer Tainted: G             L  4.9.0-rc5+ #11
[122026.989250] Hardware name: LENOVO 10FY0017US/SKYBAY, BIOS FWKT53A   06/06/2016
[122027.002786]  ffff8801e8117d50 ffffffffa9ebe748 0000000000000000 0000000000000000
[122027.017321]  ffff8801e8117d98 ffffffffa9ab6ee7 ffff8801f134e040 0000138ce8117de8
[122027.031891]  ffff8801dd805200 ffff8801ebe62580 ffff8801eec68610 ffff8801ebe62808
[122027.046386] Call Trace:
[122027.051269]  [<ffffffffa9ebe748>] dump_stack+0x63/0x8b
[122027.061116]  [<ffffffffa9ab6ee7>] __warn+0x117/0x140
[122027.070598]  [<ffffffffa9ab701d>] warn_slowpath_null+0x1d/0x20
[122027.081720]  [<ffffffffa9c2e71c>] perf_mmap_close+0x45c/0x470
[122027.092646]  [<ffffffffa9c229c0>] ? perf_iterate_ctx+0x280/0x280
[122027.307118]  [<ffffffffa9c984a4>] remove_vma+0x54/0xc0
[122027.516151]  [<ffffffffa9c9c617>] do_munmap+0x367/0x650
[122027.722320]  [<ffffffffa9c9d17f>] SyS_munmap+0x5f/0x80
[122027.929219]  [<ffffffffa9c9d120>] ? vm_munmap+0x70/0x70
[122028.136622]  [<ffffffffa9a053f0>] do_syscall_64+0xe0/0x270
[122028.345615]  [<ffffffffaa344e2f>] entry_SYSCALL64_slow_path+0x25/0x25
[122028.558691] ---[ end trace 806838d55bf2c098 ]---

followed a while later by

[150064.587195] ------------[ cut here ]------------
[150064.594626] WARNING: CPU: 0 PID: 0 at kernel/events/ring_buffer.c:546 __rb_free_aux+0x1cb/0x1d0
[150064.709271] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W    L  4.9.0-rc5+ #11
[150064.719631] Hardware name: LENOVO 10FY0017US/SKYBAY, BIOS FWKT53A   06/06/2016
[150064.729680]  ffff8801f5a07ce0 ffffffffa9ebe748 0000000000000000 0000000000000000
[150064.740027]  ffff8801f5a07d28 ffffffffa9ab6ee7 ffffffffaa812540 00000222de0dca00
[150064.750380]  ffff8801e50ed340 ffff8801f5a14740 ffff8801e50ed340 0000000000000000
[150064.760683] Call Trace:
[150064.765834]  <IRQ> [150064.767909]  [<ffffffffa9ebe748>] dump_stack+0x63/0x8b
[150064.775798]  [<ffffffffa9ab6ee7>] __warn+0x117/0x140
[150064.783473]  [<ffffffffa9ab701d>] warn_slowpath_null+0x1d/0x20
[150064.792064]  [<ffffffffa9c31c6b>] __rb_free_aux+0x1cb/0x1d0
[150064.800362]  [<ffffffffa9c331b8>] rb_free_aux+0x18/0x20
[150064.808266]  [<ffffffffa9c3367a>] perf_aux_output_end+0x19a/0x220
[150064.817015]  [<ffffffffa9a136d4>] bts_event_stop+0x104/0x1d0
[150064.825268]  [<ffffffffa9a137b3>] bts_event_del+0x13/0x20
[150064.833160]  [<ffffffffa9c26794>] event_sched_out.isra.91+0x1c4/0x5d0
[150064.842060]  [<ffffffffa9a0725c>] ? x86_pmu_disable+0x6c/0x80
[150064.850208]  [<ffffffffa9c26d9e>] group_sched_out+0x6e/0x110
[150064.858221]  [<ffffffffa9c26f80>] __perf_event_disable+0x140/0x1b0
[150064.866696]  [<ffffffffa9c1c79f>] event_function+0x10f/0x1e0
[150064.874605]  [<ffffffffa9c26e40>] ? group_sched_out+0x110/0x110
[150064.882767]  [<ffffffffa9c1c690>] ? cpu_clock_event_read+0x10/0x10
[150064.891144]  [<ffffffffa9c1e880>] ? perf_cgroup_attach+0x70/0x70
[150064.899332]  [<ffffffffa9c1e8f6>] remote_function+0x76/0xa0
[150064.907068]  [<ffffffffa9b78973>] flush_smp_call_function_queue+0xb3/0x1d0
[150064.916149]  [<ffffffffa9b79773>] generic_smp_call_function_single_interrupt+0x13/0x60
[150064.926282]  [<ffffffffa9a748b0>] smp_call_function_single_interrupt+0x40/0x50
[150064.935716]  [<ffffffffaa346f92>] call_function_single_interrupt+0x82/0x90
[150064.944835]  <EOI> [150064.946918]  [<ffffffffa9b213ea>] ? sched_idle_set_state+0x2a/0x40
[150064.955373]  [<ffffffffaa1348a8>] ? cpuidle_enter_state+0x158/0x320
[150064.963900]  [<ffffffffaa134ac7>] cpuidle_enter+0x17/0x20
[150064.971550]  [<ffffffffa9b2138d>] call_cpuidle+0x4d/0x80
[150064.979131]  [<ffffffffa9b21687>] cpu_startup_entry+0x1b7/0x290
[150064.987287]  [<ffffffffaa33aca7>] rest_init+0x87/0x90
[150064.994610]  [<ffffffffaa9613ad>] start_kernel+0x59c/0x5bf
[150065.002351]  [<ffffffffaa960120>] ? early_idt_handler_array+0x120/0x120
[150065.011260]  [<ffffffffaa9604b2>] x86_64_start_reservations+0x24/0x26
[150065.019993]  [<ffffffffaa960600>] x86_64_start_kernel+0x14c/0x16f
[150065.028338] ---[ end trace 806838d55bf2c099 ]---