linux-kernel - WARNING: suspicious RCU usage in trace_call

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Message-ID: <00000000000072d3ab0574f40f80@google.com>
Date:   Mon, 03 Sep 2018 02:21:03 -0700
From:   syzbot <syzbot+1c843dc17610ca4c764f@...kaller.appspotmail.com>
To:     ast@...nel.org, daniel@...earbox.net, linux-kernel@...r.kernel.org,
        mingo@...hat.com, netdev@...r.kernel.org, rostedt@...dmis.org,
        syzkaller-bugs@...glegroups.com
Subject: WARNING: suspicious RCU usage in trace_call_bpf

Hello,

syzbot found the following crash on:

HEAD commit:    dc6417949297 Merge branch 'net_sched-reject-unknown-tcfa_a..
git tree:       bpf
console output: https://syzkaller.appspot.com/x/log.txt?x=10bc513e400000
kernel config:  https://syzkaller.appspot.com/x/.config?x=531a917630d2a492
dashboard link: https://syzkaller.appspot.com/bug?extid=1c843dc17610ca4c764f
compiler:       gcc (GCC) 8.0.1 20180413 (experimental)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=13071951400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=119e710a400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+1c843dc17610ca4c764f@...kaller.appspotmail.com

random: sshd: uninitialized urandom read (32 bytes read)
random: sshd: uninitialized urandom read (32 bytes read)
random: sshd: uninitialized urandom read (32 bytes read)

=============================
WARNING: suspicious RCU usage
4.19.0-rc1+ #44 Not tainted
-----------------------------
include/linux/rcupdate.h:631 rcu_read_lock() used illegally while idle!

other info that might help us debug this:


RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
RCU used illegally from extended quiescent state!
1 lock held by swapper/0/0:
  #0: 000000004b34587c (rcu_read_lock){....}, at: trace_call_bpf+0xf8/0x640  
kernel/trace/bpf_trace.c:46

stack backtrace:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.19.0-rc1+ #44
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
  lockdep_rcu_suspicious+0x14a/0x153 kernel/locking/lockdep.c:4537
  rcu_read_lock include/linux/rcupdate.h:630 [inline]
  trace_call_bpf+0x533/0x640 kernel/trace/bpf_trace.c:72
  perf_trace_run_bpf_submit+0x15c/0x3b0 kernel/events/core.c:8264
  perf_trace_preemptirq_template+0x3dd/0x650  
include/trace/events/preemptirq.h:14
  trace_irq_enable_rcuidle include/trace/events/preemptirq.h:40 [inline]
  trace_hardirqs_on_caller+0x227/0x2b0 kernel/trace/trace_preemptirq.c:51

=============================
WARNING: suspicious RCU usage
  trace_hardirqs_on_thunk+0x1a/0x1c
4.19.0-rc1+ #44 Not tainted
-----------------------------
  retint_kernel+0x10/0x10
kernel/trace/bpf_trace.c:72 suspicious rcu_dereference_check() usage!
RIP: 0010:native_safe_halt+0x6/0x10 arch/x86/include/asm/irqflags.h:56

other info that might help us debug this:

Code: c7 48 89 45 d8 e8 ba 60 e7 fa 48 8b 45 d8 e9 d2 fe ff ff 48 89 df e8  
a9 60 e7 fa eb 8a 90 90 90 90 90 90 90 55 48 89 e5 fb f4 <5d> c3 0f 1f 84  
00 00 00 00 00 55 48 89 e5 f4 5d c3 90 90 90 90 90

RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
RSP: 0018:ffffffff88007bb8 EFLAGS: 00000286
RCU used illegally from extended quiescent state!
  ORIG_RAX: ffffffffffffff13
1 lock held by swapper/1/0:
RAX: dffffc0000000000 RBX: 1ffffffff1000f7b RCX: 0000000000000000
  #0:
RDX: 1ffffffff10237b8 RSI: 0000000000000001 RDI: ffffffff8811bdc0
000000004b34587c
RBP: ffffffff88007bb8 R08: ffffffff88075e00 R09: 0000000000000000
  (
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
rcu_read_lock
R13: ffffffff88007c78 R14: 0000000000000000 R15: 0000000000000000
){....}
  arch_safe_halt arch/x86/include/asm/paravirt.h:94 [inline]
  default_idle+0xc2/0x410 arch/x86/kernel/process.c:498
, at: trace_call_bpf+0xf8/0x640 kernel/trace/bpf_trace.c:46

stack backtrace:
  arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:489
  default_idle_call+0x6d/0x90 kernel/sched/idle.c:93
  cpuidle_idle_call kernel/sched/idle.c:153 [inline]
  do_idle+0x3aa/0x580 kernel/sched/idle.c:262
  cpu_startup_entry+0x10c/0x120 kernel/sched/idle.c:368
  rest_init+0xe1/0xe4 init/main.c:442
  start_kernel+0x913/0x94e init/main.c:739
  x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:452
  x86_64_start_kernel+0x76/0x79 arch/x86/kernel/head64.c:433
  secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:242

CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.19.0-rc1+ #44
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
=============================
WARNING: suspicious RCU usage
Call Trace:
4.19.0-rc1+ #44 Not tainted
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
-----------------------------
include/linux/rcupdate.h:680 rcu_read_unlock() used illegally while idle!

other info that might help us debug this:


RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
  lockdep_rcu_suspicious+0x14a/0x153 kernel/locking/lockdep.c:4537
RCU used illegally from extended quiescent state!
  trace_call_bpf+0x4cb/0x640 kernel/trace/bpf_trace.c:72
1 lock held by swapper/0/0:
  #0:
000000004b34587c
  (
  perf_trace_run_bpf_submit+0x15c/0x3b0 kernel/events/core.c:8264
rcu_read_lock
){....}
, at: trace_call_bpf+0xf8/0x640 kernel/trace/bpf_trace.c:46

stack backtrace:
  perf_trace_preemptirq_template+0x3dd/0x650  
include/trace/events/preemptirq.h:14
  trace_irq_enable_rcuidle include/trace/events/preemptirq.h:40 [inline]
  trace_hardirqs_on+0x22e/0x2c0 kernel/trace/trace_preemptirq.c:25
  default_idle+0x8d/0x410 arch/x86/kernel/process.c:498
  arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:489
  default_idle_call+0x6d/0x90 kernel/sched/idle.c:93
  cpuidle_idle_call kernel/sched/idle.c:153 [inline]
  do_idle+0x3aa/0x580 kernel/sched/idle.c:262
  cpu_startup_entry+0x10c/0x120 kernel/sched/idle.c:368
  start_secondary+0x433/0x5d0 arch/x86/kernel/smpboot.c:271
  secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:242
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.19.0-rc1+ #44
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:77 [inline]
  dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
  lockdep_rcu_suspicious+0x14a/0x153 kernel/locking/lockdep.c:4537
  rcu_read_unlock include/linux/rcupdate.h:679 [inline]
  trace_call_bpf+0x579/0x640 kernel/trace/bpf_trace.c:72
  perf_trace_run_bpf_submit+0x15c/0x3b0 kernel/events/core.c:8264
  perf_trace_preemptirq_template+0x3dd/0x650  
include/trace/events/preemptirq.h:14
  trace_irq_enable_rcuidle include/trace/events/preemptirq.h:40 [inline]
  trace_hardirqs_on_caller+0x227/0x2b0 kernel/trace/trace_preemptirq.c:51
  trace_hardirqs_on_thunk+0x1a/0x1c
  retint_kernel+0x10/0x10
RIP: 0010:native_safe_halt+0x6/0x10 arch/x86/include/asm/irqflags.h:56
Code: c7 48 89 45 d8 e8 ba 60 e7 fa 48 8b 45 d8 e9 d2 fe ff ff 48 89 df e8  
a9 60 e7 fa eb 8a 90 90 90 90 90 90 90 55 48 89 e5 fb f4 <5d> c3 0f 1f 84  
00 00 00 00 00 55 48 89 e5 f4 5d c3 90 90 90 90 90
RSP: 0018:ffffffff88007bb8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: dffffc0000000000 RBX: 1ffffffff1000f7b RCX: 0000000000000000
RDX: 1ffffffff10237b8 RSI: 0000000000000001 RDI: ffffffff8811bdc0
RBP: ffffffff88007bb8 R08: ffffffff88075e00 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffffffff88007c78 R14: 0000000000000000 R15: 0000000000000000
  arch_safe_halt arch/x86/include/asm/paravirt.h:94 [inline]
  default_idle+0xc2/0x410 arch/x86/kernel/process.c:498
  arch_cpu_idle+0x10/0x20 arch/x86/kernel/process.c:489
  default_idle_call+0x6d/0x90 kernel/sched/idle.c:93
  cpuidle_idle_call kernel/sched/idle.c:153 [inline]
  do_idle+0x3aa/0x580 kernel/sched/idle.c:262
  cpu_startup_entry+0x10c/0x120 kernel/sched/idle.c:368
  rest_init+0xe1/0xe4 init/main.c:442
  start_kernel+0x913/0x94e init/main.c:739
  x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:452
  x86_64_start_kernel+0x76/0x79 arch/x86/kernel/head64.c:433
  secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:242


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@...glegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with  
syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches