Re: WARNING in tracepoint_probe_unregister

[Jens Axboe]

On 11/07/2017 11:06 AM, Dmitry Vyukov wrote:
> On Sun, Nov 5, 2017 at 4:47 PM, Jens Axboe <axboe@xxxxxxxxx> wrote:
>> On 11/05/2017 01:09 AM, Dmitry Vyukov wrote:
>>> On Sun, Nov 5, 2017 at 11:05 AM, syzbot
>>> <bot+f00b2fc1cf284703bf4107c0ea565aafd9b536d0@xxxxxxxxxxxxxxxxxxxxxxxxx>
>>> wrote:
>>>> Hello,
>>>>
>>>> syzkaller hit the following crash on
>>>> 36ef71cae353f88fd6e095e2aaa3e5953af1685d
>>>> git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/master
>>>> compiler: gcc (GCC) 7.1.1 20170620
>>>> .config is attached
>>>> Raw console output is attached.
>>>> C reproducer is attached
>>>> syzkaller reproducer is attached. See https://goo.gl/kgGztJ
>>>> for information about syzkaller reproducers
>>>>
>>>>
>>>> WARNING: CPU: 1 PID: 2992 at kernel/tracepoint.c:243 tracepoint_remove_func
>>>> kernel/tracepoint.c:243 [inline]
>>>> WARNING: CPU: 1 PID: 2992 at kernel/tracepoint.c:243
>>>> tracepoint_probe_unregister+0x6b3/0x870 kernel/tracepoint.c:324
>>>> Kernel panic - not syncing: panic_on_warn set ...
>>>>
>>>> CPU: 1 PID: 2992 Comm: syzkaller812809 Not tainted 4.14.0-rc5-next-20171018+
>>>> #8
>>>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
>>>> Call Trace:
>>>>  __dump_stack lib/dump_stack.c:16 [inline]
>>>>  dump_stack+0x194/0x257 lib/dump_stack.c:52
>>>>  panic+0x1e4/0x41c kernel/panic.c:183
>>>>  __warn+0x1c4/0x1e0 kernel/panic.c:546
>>>>  report_bug+0x211/0x2d0 lib/bug.c:183
>>>>  fixup_bug+0x40/0x90 arch/x86/kernel/traps.c:177
>>>>  do_trap_no_signal arch/x86/kernel/traps.c:211 [inline]
>>>>  do_trap+0x260/0x390 arch/x86/kernel/traps.c:260
>>>>  do_error_trap+0x120/0x390 arch/x86/kernel/traps.c:297
>>>>  do_invalid_op+0x1b/0x20 arch/x86/kernel/traps.c:310
>>>>  invalid_op+0x18/0x20 arch/x86/entry/entry_64.S:905
>>>> RIP: 0010:tracepoint_remove_func kernel/tracepoint.c:243 [inline]
>>>> RIP: 0010:tracepoint_probe_unregister+0x6b3/0x870 kernel/tracepoint.c:324
>>>> RSP: 0018:ffff8800397df890 EFLAGS: 00010293
>>>> RAX: ffff88003982e8c0 RBX: 00000000fffffffe RCX: ffffffff81710233
>>>> RDX: 0000000000000000 RSI: ffffffff85b679c0 RDI: 0000000000000282
>>>> RBP: ffff8800397df9a8 R08: 0000000000000001 R09: 1ffff100072fbe6e
>>>> R10: ffff8800397df880 R11: 0000000000000001 R12: ffffffff8175b5e0
>>>> R13: dffffc0000000000 R14: 0000000000000000 R15: ffff8800397df980
>>>>  unregister_trace_block_rq_remap include/trace/events/block.h:602 [inline]
>>>>  blk_unregister_tracepoints+0x1e/0x160 kernel/trace/blktrace.c:1079
>>>>  blk_trace_cleanup+0x28/0x30 kernel/trace/blktrace.c:336
>>>>  blk_trace_remove+0x55/0x80 kernel/trace/blktrace.c:348
>>>>  sg_ioctl+0x5eb/0x2d90 drivers/scsi/sg.c:1098
>>>>  vfs_ioctl fs/ioctl.c:45 [inline]
>>>>  do_vfs_ioctl+0x1b1/0x1520 fs/ioctl.c:685
>>>>  SYSC_ioctl fs/ioctl.c:700 [inline]
>>>>  SyS_ioctl+0x8f/0xc0 fs/ioctl.c:691
>>>>  entry_SYSCALL_64_fastpath+0x1f/0xbe
>>>> RIP: 0033:0x4396a9
>>>> RSP: 002b:00007ffd4d3facb8 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
>>>> RAX: ffffffffffffffda RBX: 00000000006ccac0 RCX: 00000000004396a9
>>>> RDX: 000000002002d000 RSI: 4000000000001276 RDI: 0000000000000004
>>>> RBP: 0000000000000082 R08: 00000000000000fe R09: 0000000000000000
>>>> R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000038
>>>> R13: ffffffffffffffff R14: 0000000000401eb0 R15: 0000000000000000
>>>> Dumping ftrace buffer:
>>>>    (ftrace buffer empty)
>>>> Kernel Offset: disabled
>>>> Rebooting in 86400 seconds..
>>>
>>>
>>> Jens, this has the same root cause as "WARNING in
>>> tracepoint_probe_register_prio":
>>> https://groups.google.com/forum/#!msg/syzkaller-bugs/9IolqTA_NUk/LgLFZ6hQAQAJ
>>> right?
>>
>> Yep, it is - can/did you check the patch I sent out yesterday for this?
>> Here it is again.
> 
> I re-run the attached reproducer and it does not trigger the warning
> with the patch:
> 
> Tested-by: Dmitry Vyukov <dvyukov@xxxxxxxxxx>

Great, thanks for testing!

-- 
Jens Axboe