syzbot


WARNING: suspicious RCU usage in trace_call_bpf

Status: fixed on 2019/10/04 12:05
Subsystems: bpf trace
[Documentation on labels]
Reported-by: syzbot+1c843dc17610ca4c764f@syzkaller.appspotmail.com
Fix commit: 865e63b04e9b tracing: Add back in rcu_irq_enter/exit_irqson() for rcuidle tracepoints
First crash: 2091d, last: 2072d
Fix bisection: fixed by (bisect log) :
commit 8ecebf4d767e2307a946c8905278d6358eda35c3
Author: Robbie Ko <robbieko@synology.com>
Date: Mon Aug 6 02:30:30 2018 +0000

  Btrfs: fix unexpected failure of nocow buffered writes after snapshotting when low on space

  
Discussions (3)
Title Replies (including bot) Last reply
Reminder: 36 open syzbot bugs in "net/bpf" subsystem 1 (1) 2019/07/03 06:01
Reminder: 30 open syzbot bugs in "net/bpf" subsystem 1 (1) 2019/06/24 05:01
WARNING: suspicious RCU usage in trace_call_bpf 0 (1) 2018/09/03 09:21

Sample crash report:
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

Crashes (327):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2018/09/01 22:54 bpf dc6417949297 a4718693 .config console log report syz C ci-upstream-bpf-kasan-gce
2018/09/01 22:29 bpf-next 93ee30f3e8b4 a4718693 .config console log report syz C ci-upstream-bpf-next-kasan-gce
2018/09/01 22:54 linux-next a880148cb2af a4718693 .config console log report syz C ci-upstream-linux-next-kasan-gce-root
2018/09/06 10:18 upstream b36fdc6853a3 0bb7a7eb .config console log report ci-upstream-kasan-gce-smack-root
2018/09/06 04:59 upstream b36fdc6853a3 873745f2 .config console log report ci-upstream-kasan-gce-selinux-root
2018/09/05 16:10 upstream 28619527b8a7 196410e4 .config console log report ci-upstream-kasan-gce-root
2018/09/20 18:02 bpf-next 2dfd184abd38 4fb3cca1 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 13:21 bpf-next 2dfd184abd38 565a5452 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 11:43 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 10:28 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 09:26 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 08:40 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 05:36 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/20 01:07 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 22:14 bpf-next 2dfd184abd38 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 20:37 bpf-next 534e0e52bc23 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 18:57 bpf-next 534e0e52bc23 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 17:54 bpf-next 534e0e52bc23 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 12:05 bpf-next 534e0e52bc23 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 10:50 bpf-next 534e0e52bc23 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 04:28 bpf-next 7900efc19214 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/19 00:04 bpf-next 7900efc19214 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 22:41 bpf-next 7900efc19214 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 20:14 bpf-next 7900efc19214 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 17:34 bpf-next 7900efc19214 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 14:00 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 12:19 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 10:31 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 09:07 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 07:46 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 05:32 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 04:28 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 03:01 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/18 01:14 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 22:31 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 20:08 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 18:36 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 16:10 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 12:51 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 11:35 bpf-next 70e88c758a6b 7f125108 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 06:47 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 03:59 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 01:22 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/17 00:16 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/16 20:59 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/16 19:44 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/16 18:19 bpf-next 70e88c758a6b a343a400 .config console log report ci-upstream-bpf-next-kasan-gce
2018/09/01 18:03 bpf-next 93ee30f3e8b4 a4718693 .config console log report ci-upstream-bpf-next-kasan-gce
* Struck through repros no longer work on HEAD.