[Bug runtime/22182] New: On rawhide, we're getting lots of 'suspicious RCU usage' kernel warnings

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

[Bug runtime/22182] New: On rawhide, we're getting lots of 'suspicious RCU usage' kernel warnings

glaubitz at physik dot fu-berlin.de
https://sourceware.org/bugzilla/show_bug.cgi?id=22182

            Bug ID: 22182
           Summary: On rawhide, we're getting lots of 'suspicious RCU
                    usage' kernel warnings
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: runtime
          Assignee: systemtap at sourceware dot org
          Reporter: dsmith at redhat dot com
  Target Milestone: ---

On rawhide (4.14.0-0.rc0.git6.1.fc28.x86_64+debug), we're getting lots of
"suspicious RCU usage" kernel warnings when running the testsuite. Here is the
start of the warnings:

====
[ 5970.181257] =============================
[ 5970.181669] WARNING: suspicious RCU usage
[ 5970.182094] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.182831] -----------------------------
[ 5970.183246] /usr/local/share/systemtap/runtime/linux/runtime_context.h:76
suspicious rcu_dereference_check() usage!
[ 5970.184300]
[ 5970.184300] other info that might help us debug this:
[ 5970.184300]
[ 5970.185116]
[ 5970.185116] RCU used illegally from idle CPU!
[ 5970.185116] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.186250] RCU used illegally from extended quiescent state!
[ 5970.186835] no locks held by swapper/0/0.
[ 5970.187255]
[ 5970.187255] stack backtrace:
[ 5970.187709] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.188704] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.189297] Call Trace:
[ 5970.189559]  <IRQ>
[ 5970.189782]
[ 5970.189969] =============================
[ 5970.190377] WARNING: suspicious RCU usage
[ 5970.190787] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.191522] -----------------------------
[ 5970.191937] ./include/linux/rcupdate.h:632 rcu_read_lock() used illegally
while idle!
[ 5970.192720]
[ 5970.192720] other info that might help us debug this:
[ 5970.192720]
[ 5970.193537]
[ 5970.193537] RCU used illegally from idle CPU!
[ 5970.193537] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.194631] RCU used illegally from extended quiescent state!
[ 5970.195219] 1 lock held by swapper/0/0:
[ 5970.195613]  #0:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.196522]
[ 5970.196522] stack backtrace:
[ 5970.197091] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.198088] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.198671] Call Trace:
[ 5970.198942]  <IRQ>
[ 5970.199174]
[ 5970.199351] =============================
[ 5970.199762] WARNING: suspicious RCU usage
[ 5970.200180] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.200903] -----------------------------
[ 5970.201322] ./include/linux/rcupdate.h:683 rcu_read_unlock() used illegally
while idle!
[ 5970.202128]
[ 5970.202128] other info that might help us debug this:
[ 5970.202128]
[ 5970.202943]
[ 5970.202943] RCU used illegally from idle CPU!
[ 5970.202943] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.204043] RCU used illegally from extended quiescent state!
[ 5970.204629] 2 locks held by swapper/0/0:
[ 5970.205045]  #0:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.205954]  #1:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.206847]
[ 5970.206847] stack backtrace:
[ 5970.207304] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.208333] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.208973] Call Trace:
[ 5970.209234]  <IRQ>
[ 5970.209452]
[ 5970.209631] =============================
[ 5970.210052] WARNING: suspicious RCU usage
[ 5970.210474] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.211217] -----------------------------
[ 5970.211639] ./include/linux/rcupdate.h:632 rcu_read_lock() used illegally
while idle!
[ 5970.212498]
[ 5970.212498] other info that might help us debug this:
[ 5970.212498]
[ 5970.213324]
[ 5970.213324] RCU used illegally from idle CPU!
[ 5970.213324] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.214467] RCU used illegally from extended quiescent state!
[ 5970.215061] 3 locks held by swapper/0/0:
[ 5970.215464]  #0:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.216380]  #1:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.217332]  #2:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.218180]
[ 5970.218180] stack backtrace:
[ 5970.218639] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.219614] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.220203] Call Trace:
[ 5970.220458]  <IRQ>
[ 5970.220678]
[ 5970.220858] =============================
[ 5970.221275] WARNING: suspicious RCU usage
[ 5970.221680] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.222417] -----------------------------
[ 5970.222829] ./include/linux/rcupdate.h:683 rcu_read_unlock() used illegally
while idle!
[ 5970.223646]
[ 5970.223646] other info that might help us debug this:
[ 5970.223646]
[ 5970.224464]
[ 5970.224464] RCU used illegally from idle CPU!
[ 5970.224464] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.225557] RCU used illegally from extended quiescent state!
[ 5970.226054] 4 locks held by swapper/0/0:
[ 5970.226510]  #0:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.227670]  #1:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.228694]  #2:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.229587]  #3:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.230607]
[ 5970.230607] stack backtrace:
[ 5970.231257] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.232535] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.233121] Call Trace:
[ 5970.233379]  <IRQ>
[ 5970.233617]  dump_stack+0x8e/0xd6
[ 5970.233976]  lockdep_rcu_suspicious+0xc5/0x100
[ 5970.234436]  is_bpf_text_address+0xe0/0xf0
[ 5970.234863]  __kernel_text_address+0x8b/0xb0
[ 5970.235312]  show_trace_log_lvl+0x195/0x410
[ 5970.235755]  ? dump_stack+0x8e/0xd6
[ 5970.236128]  show_stack+0x34/0x50
[ 5970.236474]  dump_stack+0x8e/0xd6
[ 5970.236825]  lockdep_rcu_suspicious+0xc5/0x100
[ 5970.237286]  is_bpf_text_address+0xb6/0xf0
[ 5970.237711]  __kernel_text_address+0x8b/0xb0
[ 5970.238158]  show_trace_log_lvl+0x195/0x410
[ 5970.238599]  ? dump_stack+0x8e/0xd6
[ 5970.238968]  show_stack+0x34/0x50
[ 5970.239312]  dump_stack+0x8e/0xd6
[ 5970.239657]  lockdep_rcu_suspicious+0xc5/0x100
[ 5970.240125]  __is_insn_slot_addr+0x118/0x120
[ 5970.240568]  __kernel_text_address+0x6c/0xb0
[ 5970.241011]  show_trace_log_lvl+0x195/0x410
[ 5970.241453]  ? dump_stack+0x8e/0xd6
[ 5970.241823]  show_stack+0x34/0x50
[ 5970.242174]  dump_stack+0x8e/0xd6
[ 5970.242520]  lockdep_rcu_suspicious+0xc5/0x100
[ 5970.242989]  __is_insn_slot_addr+0xeb/0x120
[ 5970.243423]  __kernel_text_address+0x6c/0xb0
[ 5970.243866]  show_trace_log_lvl+0x195/0x410
[ 5970.244313]  ? dump_stack+0x8e/0xd6
[ 5970.244684]
[ 5970.244847] =============================
[ 5970.245268] WARNING: suspicious RCU usage
[ 5970.245681] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.246417] -----------------------------
[ 5970.246829] arch/x86/kernel/traps.c:293 entry code didn't wake RCU!
[ 5970.247468]
[ 5970.247468] other info that might help us debug this:
[ 5970.247468]
[ 5970.248265]
[ 5970.248265] RCU used illegally from idle CPU!
[ 5970.248265] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.249366] RCU used illegally from extended quiescent state!
[ 5970.249961] 4 locks held by swapper/0/0:
[ 5970.250368]  #0:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.251274]  #1:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.252171]  #2:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.253063]  #3:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.253947]
[ 5970.253947] stack backtrace:
[ 5970.254397] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.255387] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.255973] Call Trace:
[ 5970.256234]  <IRQ>
[ 5970.256458]  dump_stack+0x8e/0xd6
[ 5970.256809]  lockdep_rcu_suspicious+0xc5/0x100
[ 5970.257276]  do_error_trap+0x145/0x160
[ 5970.257667]  ? kvm_sched_clock_read+0x25/0x40
[ 5970.258126]  ? console_unlock+0x2e5/0x560
[ 5970.258546]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[ 5970.259039]
[ 5970.259204] =============================
[ 5970.259619] WARNING: suspicious RCU usage
[ 5970.260037] 4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1 Tainted: G           OE
[ 5970.260769] -----------------------------
[ 5970.261193] kernel/notifier.c:548 notify_die called but RCU thinks we're
quiescent!
[ 5970.262087]
[ 5970.262087] other info that might help us debug this:
[ 5970.262087]
[ 5970.262894]
[ 5970.262894] RCU used illegally from idle CPU!
[ 5970.262894] rcu_scheduler_active = 2, debug_locks = 1
[ 5970.263984] RCU used illegally from extended quiescent state!
[ 5970.264568] 4 locks held by swapper/0/0:
[ 5970.264975]  #0:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.265861]  #1:  (rcu_read_lock){....}, at: [<ffffffffa219d8e5>]
__is_insn_slot_addr+0x5/0x120
[ 5970.266750]  #2:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.267632]  #3:  (rcu_read_lock){....}, at: [<ffffffffa21eeb05>]
is_bpf_text_address+0x5/0xf0
[ 5970.268521]
[ 5970.268521] stack backtrace:
[ 5970.268976] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           OE  
4.14.0-0.rc0.git6.1.fc28.x86_64+debug #1
[ 5970.269962] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 5970.270546] Call Trace:
[ 5970.270800]  <IRQ>
[ 5970.271031]  dump_stack+0x8e/0xd6
[ 5970.271383]  lockdep_rcu_suspicious+0xc5/0x100
[ 5970.271840]  notify_die+0x90/0xa0
[ 5970.272195]  do_error_trap+0x66/0x160
[ 5970.272575]  ? kvm_sched_clock_read+0x25/0x40
[ 5970.273029]  ? console_unlock+0x2e5/0x560
[ 5970.273448]  ? trace_hardirqs_off_thunk+0x1a/0x1c
====

--
You are receiving this mail because:
You are the assignee for the bug.
Reply | Threaded
Open this post in threaded view
|

[Bug runtime/22182] On rawhide, we're getting lots of 'suspicious RCU usage' kernel warnings

glaubitz at physik dot fu-berlin.de
https://sourceware.org/bugzilla/show_bug.cgi?id=22182

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
                 CC|                            |fche at redhat dot com
         Resolution|---                         |DUPLICATE

--- Comment #1 from Frank Ch. Eigler <fche at redhat dot com> ---
my guess is this is dupe of another RCU bug, and possibly something related to
kprobes-optimization (which we reluctantly have disabled again in commit
288c53892.

*** This bug has been marked as a duplicate of bug 23276 ***

--
You are receiving this mail because:
You are the assignee for the bug.