This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
[Bug kprobes/23276] New: 'suspicious RCU usage' on rawhide 4.18.0-0.rc0
- From: "serhei.public at gmail dot com" <sourceware-bugzilla at sourceware dot org>
- To: systemtap at sourceware dot org
- Date: Tue, 12 Jun 2018 16:01:26 +0000
- Subject: [Bug kprobes/23276] New: 'suspicious RCU usage' on rawhide 4.18.0-0.rc0
- Auto-submitted: auto-generated
https://sourceware.org/bugzilla/show_bug.cgi?id=23276
Bug ID: 23276
Summary: 'suspicious RCU usage' on rawhide 4.18.0-0.rc0
Product: systemtap
Version: unspecified
Status: UNCONFIRMED
Severity: normal
Priority: P2
Component: kprobes
Assignee: systemtap at sourceware dot org
Reporter: serhei.public at gmail dot com
Target Milestone: ---
With Rawhide kernel 4.18.0-0.rc0, getting the following dmesg from the
autotester:
[Jun11 19:14] stap_61cee45e5765364295112bccded04275__24890: systemtap:
4.0/0.171, base:
0000000002ed075d, memory: 3460data/52text/27ctx/2063net/82alloc kb, probes: 202
[ +2.032087] =============================
[ +0.000003] WARNING: suspicious RCU usage
[ +0.000005] 4.18.0-0.rc0.git5.1.fc29.x86_64 #1 Tainted: G OE
[ +0.000003] -----------------------------
[ +0.000004]
/notnfs/smakarov/stap-checkout/stap_install/share/systemtap/runtime/linux/runtime_context.h:76
suspicious rcu_dereference_check() usage!
[ +0.000003]
other info that might help us debug this:
[ +0.000003]
RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
[ +0.000003] RCU used illegally from extended quiescent state!
[ +0.000003] no locks held by swapper/2/0.
[ +0.000003]
stack backtrace:
[ +0.000005] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G OE
4.18.0-0.rc0.git5.1.fc29.x86_64 #1
[ +0.000003] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-2.fc27
04/01/2014
[ +0.000003] Call Trace:
[ +0.000004] <IRQ>
[ +0.000012] dump_stack+0x85/0xc0
[ +0.001138] _stp_runtime_entryfn_get_context+0x86/0x90
[stap_61cee45e5765364295112bccded04275__24890]
[ +0.000028] ? enter_kprobe_probe+0xb5/0x3a0
[stap_61cee45e5765364295112bccded04275__24890]
[ +0.000011] ? irq_enter+0x1/0x70
[ +0.000008] ? kprobe_ftrace_handler+0x97/0x100
[ +0.000009] ? ftrace_ops_assist_func+0x75/0xf0
[ +0.000461] ? 0xffffffffc04a80bf
[ +0.000018] ? apic_timer_interrupt+0xa/0x20
[ +0.000007] ? irq_enter+0x1/0x70
[ +0.000009] ? irq_enter+0x5/0x70
[ +0.000005] ? smp_apic_timer_interrupt+0x1c/0x2c0
[ +0.000006] ? apic_timer_interrupt+0xf/0x20
[ +0.000004] </IRQ>
[ +0.000020] ? native_safe_halt+0x2/0x10
[ +0.000007] ? default_idle+0x1f/0x180
[ +0.000010] ? do_idle+0x1f5/0x270
[ +0.000011] ? cpu_startup_entry+0x6f/0x80
[ +0.000008] ? start_secondary+0x1b3/0x200
[ +0.000008] ? secondary_startup_64+0xa5/0xb0
[ +0.000216] =============================
[ +0.000002] WARNING: suspicious RCU usage
[ +0.000001] 4.18.0-0.rc0.git5.1.fc29.x86_64 #1 Tainted: G OE
[ +0.000001] -----------------------------
[ +0.000004] arch/x86/kernel/traps.c:290 entry code didn't wake RCU!
[ +0.000002] other info that might help us debug this:
[ +0.000002] RCU used illegally from idle CPU!
[ +0.000001] rcu_scheduler_active = 2, debug_locks = 1
[ +0.000002] RCU used illegally from extended quiescent state!
[ +0.000001] 1 lock held by swapper/2/0:
[ +0.000001] #0: 000000007b71c679 (logbuf_lock){-.-.}, at:
vprintk_emit+0xfd/0x540
[ +0.000007] stack backtrace:
[ +0.000001] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G OE
4.18.0-0.rc0.git5.1.fc29.x86_64 #1
[ +0.000001] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-2.fc27
04/01/2014
[ +0.000001] Call Trace:
[ +0.000001] <IRQ>
[ +0.000001] dump_stack+0x85/0xc0
[ +0.000001] do_error_trap+0x185/0x1a0
[ +0.000002] ? trace_hardirqs_off_thunk+0x1a/0x1c
[ +0.000001] invalid_op+0x14/0x20
[ +0.000001] RIP: 0010:module_assert_mutex_or_preempt+0x2e/0x40
[ +0.000001] Code: 00 8b 05 85 b9 6f 01 85 c0 74 09 e8 3c 3d fd ff 85 c0 74 01
c3 be ff ff ff ff 48 c7 c7 10 f0 7d ad e8 86 db fa ff 85 c0 75 ea <0f> 0b c3 0f
1f 44 00 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00
[ +0.000060] RSP: 0018:ffff9ce77b203a20 EFLAGS: 00010046
[ +0.000002] RAX: 0000000000000000 RBX: ffffffffc06be145 RCX: 0000000000000002
[ +0.000002] RDX: 0000000000000000 RSI: ffffffffad7df010 RDI: 0000000000000046
[ +0.000001] RBP: ffffffffc06be145 R08: ffff9ce77b203ae9 R09: 0000000052d2710c
[ +0.000001] R10: ffffffffaeec4500 R11: ffffffffae96d5d8 R12: ffff9ce77b203a98
[ +0.000001] R13: ffff9ce77b203aa8 R14: ffff9ce77b203aa0 R15: ffffffffad2d8f16
[ +0.000002] WAR_stp_runtime_entryfn_get_context+0x85/0x90
[stap_61cee45e5765364295112bccded04275__24890]
[ +0.000001] stap_61cee45e5765364295112bccded04275__24890(OE) uinput
nf_conntrack_netbios_ns nf_conntrack_broadcast devlink xt_CT ip6t_rpfilter
ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat
ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6
nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat
nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c
iptable_mangle iptable_raw iptable_security ebtable_filter ebtables
ip6table_filter ip6_tables sunrpc snd_hda_codec_generic snd_hda_intel
snd_hda_codec snd_hda_core snd_hwdep snd_seq joydev snd_seq_device snd_pcm
snd_timer virtio_balloon snd soundcore i2c_piix4 8139too qxl drm_kms_helper ttm
drm serio_raw virtio_blk virtio_console ata_generic 8139cp mii pata_acpi
qemu_fw_cfg
[ +0.000060] [last unloaded: stap_55cf9342ec9f8dd00d6844446722b11_24392]
[ +0.000004] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G OE
4.18.0-0.rc0.git5.1.fc29.x86_64 #1
[ +0.000001] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-2.fc27
04/01/2014
[ +0.000001] RIP: 0010:module_assert_mutex_or_preempt+0x2e/0x40
[ +0.000001] Code: 00 8b 05 85 b9 6f 01 85 c0 74 09 e8 3c 3d fd ff 85 c0 74 01
c3 be ff ff ff ff 48 c7 c7 10 f0 7d ad e8 86 db fa ff 85 c0 75 ea <0f> 0b c3 0f
1f 44 00 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00
[ +0.000055] RSP: 0018:ffff9ce77b203478 EFLAGS: 00010046
[ +0.000002] RAX: 0000000000000000 RBX: ffffffffc06be144 RCX: 0000000000000002
[ +0.000001] RDX: 0000000000000000 RSI: ffffffffad7df010 RDI: 0000000000000046
[ +0.000001] RBP: ffffffffc06be144 R08: ffff9ce77b203541 R09: 0000000052c2f313
[ +0.000001] R10: ffff9ce77b3d8d00 R11: 0000000000000000 R12: ffff9ce77b2034f0
[ +0.000002] R13: ffff9ce77b203500 R14: ffff9ce77b2034f8 R15: ffffffffad2d8f16
[ +0.000001] FS: 0000000000000000(0000) GS:ffff9ce77b200000(0000)
knlGS:0000000000000000
[ +0.000002] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ +0.000002] CR2: 00007ff92692f598 CR3: 000000002a0ea000 CR4: 00000000000006e0
[ +0.000001] DR0: ffffffffc04d4108 DR1: 0000000000000000 DR2: 0000000000000000
[ +0.000001] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
[ +0.000001] Call Trace:
[ +0.000001] <IRQ>
[ +0.000001] __module_address+0
[ +0.000003] Lost 505 message(s)!
[ +30.060459] stap_fe72e0969e7a0dfe3c9d082ea5c5ca3c__25387: systemtap:
4.0/0.171, base:
00000000dba24f97, memory: 3460data/52text/27ctx/2063net/82alloc kb, probes: 202
[ +2.308311] =============================
[ +0.000002] WARNING: suspicious RCU usage
[ +0.000004] 4.18.0-0.rc0.git5.1.fc29.x86_64 #1 Tainted: G W OE
[ +0.000003] -----------------------------
[ +0.000004]
/notnfs/smakarov/stap-checkout/stap_install/share/systemtap/runtime/linux/
runtime_context.h:76 suspicious rcu_dereference_check() usage!
[ +0.000002]
other info that might help us debug this:
[ +0.000004]
RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
[ +0.000003] RCU used illegally from extended quiescent state!
[ +0.000003] no locks held by swapper/0/0.
[ +0.000003]
stack backtrace:
[ +0.000005] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W OE
4.18.0-0.rc0.git
5.1.fc29.x86_64 #1
[ +0.000003] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-2.fc27
04/01/2014
[ +0.000002] Call Trace:
[ +0.000004] <IRQ>
[ +0.000011] dump_stack+0x85/0xc0
[ +0.000030] _stp_runtime_entryfn_get_context+0x86/0x90
[stap_fe72e0969e7a0dfe3c9d082ea5c5ca3c__25387]
[ +0.000025] ? enter_kprobe_probe+0xb5/0x3a0
[stap_fe72e0969e7a0dfe3c9d082ea5c5ca3c__25387]
[ +0.000012] ? irq_enter+0x1/0x70
[ +0.000008] ? kprobe_ftrace_handler+0x97/0x100
[ +0.000009] ? ftrace_ops_assist_func+0x75/0xf0
[ +0.000021] ? 0xffffffffc04a80bf
[ +0.000019] ? apic_timer_interrupt+0xa/0x20
[ +0.000006] ? irq_enter+0x1/0x70
[ +0.000009] ? irq_enter+0x5/0x70
[ +0.000005] ? smp_apic_timer_interrupt+0x1c/0x2c0
[ +0.000006] ? apic_timer_interrupt+0xf/0x20
[ +0.000003] </IRQ>
[ +0.000017] ? native_safe_halt+0x2/0x10
[ +0.000007] ? default_idle+0x1f/0x180
[ +0.000009] ? do_idle+0x1f5/0x270
[ +0.000010] ? cpu_startup_entry+0x6f/0x80
[ +0.000017] ? start_kernel+0x567/0x587
[ +0.000012] ? secondary_startup_64+0xa5/0xb0
[Jun11 19:15] stap_5edf7cc3741a456c5a5d56b31620e2f1__25886: systemtap:
4.0/0.171, base:
0000000002ed075d, memory: 3460data/52text/27ctx/2063net/82alloc kb, probes: 202
[ +2.254638] =============================
[ +0.000002] WARNING: suspicious RCU usage
[ +0.000004] 4.18.0-0.rc0.git5.1.fc29.x86_64 #1 Tainted: G W OE
[ +0.000003] -----------------------------
[ +0.000004]
/notnfs/smakarov/stap-checkout/stap_install/share/systemtap/runtime/linux/runtime_context.h:76
suspicious rcu_dereference_check() usage!
[ +0.000002]
other info that might help us debug this:
[ +0.000003]
RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
[ +0.000003] RCU used illegally from extended quiescent state!
[ +0.000003] no locks held by swapper/1/0.
[ +0.000002]
stack backtrace:
[ +0.000005] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W OE
4.18.0-0.rc0.git5.1.fc29.x86_64 #1
[ +0.000003] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-2.fc27
04/01/2014
[ +0.000003] Call Trace:
[ +0.000004] <IRQ>
[ +0.000011] dump_stack+0x85/0xc0
[ +0.000033] _stp_runtime_entryfn_get_context+0x86/0x90
[stap_5edf7cc3741a456c5a5d56b31620e2f1__25886]
[ +0.000023] ? enter_kprobe_probe+0xb5/0x3a0
[stap_5edf7cc3741a456c5a5d56b31620e2f1__25886]
[ +0.000010] ? irq_enter+0x1/0x70
[ +0.000008] ? kprobe_ftrace_handler+0x97/0x100
[ +0.000009] ? ftrace_ops_assist_func+0x75/0xf0
[ +0.000019] ? 0xffffffffc04a80bf
[ +0.000018] ? apic_timer_interrupt+0xa/0x20
[ +0.000006] ? irq_enter+0x1/0x70
[ +0.000009] ? irq_enter+0x5/0x70
[ +0.000004] ? smp_apic_timer_interrupt+0x1c/0x2c0
[ +0.000006] ? apic_timer_interrupt+0xf/0x20
[ +0.000004] </IRQ>
[ +0.000018] ? native_safe_halt+0x2/0x10
[ +0.000007] ? default_idle+0x1f/0x180
[ +0.000009] ? do_idle+0x1f5/0x270
[ +0.000010] ? cpu_startup_entry+0x6f/0x80
[ +0.000009] ? start_secondary+0x1b3/0x200
[ +0.000008] ? secondary_startup_64+0xa5/0xb0
[ +31.545700] stap_99eefb40f93f2571f5bf3f967972831b__26385: systemtap:
4.0/0.171, base:
00000000dba24f97, memory: 3544data/76text/29ctx/2063net/82alloc kb, probes: 202
[ +2.244447] =============================
[ +0.000003] WARNING: suspicious RCU usage
[ +0.000004] 4.18.0-0.rc0.git5.1.fc29.x86_64 #1 Tainted: G W OE
[ +0.000002] -----------------------------
[ +0.000005]
/notnfs/smakarov/stap-checkout/stap_install/share/systemtap/runtime/linux/runtime_context.h:76
suspicious rcu_dereference_check() usage!
[ +0.000002]
other info that might help us debug this:
[ +0.000003]
RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 1
[ +0.000003] RCU used illegally from extended quiescent state!
[ +0.000003] no locks held by swapper/2/0.
[ +0.000003]
stack backtrace:
[ +0.000005] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G W OE
4.18.0-0.rc0.git5.1.fc29.x86_64 #1
[ +0.000003] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-2.fc27
04/01/2014
[ +0.000003] Call Trace:
[ +0.000004] <IRQ>
[ +0.000010] dump_stack+0x85/0xc0
[ +0.000038] _stp_runtime_entryfn_get_context+0x86/0x90
[stap_99eefb40f93f2571f5bf3f967972831b__26385]
[ +0.000040] ? enter_kprobe_probe+0xb5/0x3a0
[stap_99eefb40f93f2571f5bf3f967972831b__26385]
[ +0.000011] ? irq_enter+0x1/0x70
[ +0.000007] ? kprobe_ftrace_handler+0x97/0x100
[ +0.000009] ? ftrace_ops_assist_func+0x75/0xf0
[ +0.000005] ? rcu_read_lock_sched_held+0x6b/0x80
[ +0.000005] ? rcu_process_callbacks+0x479/0x7b0
[ +0.000018] ? 0xffffffffc04a80bf
[ +0.000018] ? irq_enter+0x1/0x70
[ +0.000009] ? irq_enter+0x5/0x70
[ +0.000005] ? scheduler_ipi+0xa5/0x130
[ +0.000006] ? reschedule_interrupt+0xf/0x20
[ +0.000004] </IRQ>
[ +0.000018] ? native_safe_halt+0x2/0x10
[ +0.000008] ? default_idle+0x1f/0x180
[ +0.000008] ? do_idle+0x1f5/0x270
[ +0.000011] ? cpu_startup_entry+0x6f/0x80
[ +0.000008] ? start_secondary+0x1b3/0x200
[ +0.000007] ? secondary_startup_64+0xa5/0xb0
The full testsuite run hangs (does not finish, system unresponsive) sometime
after the suspicious tests (many more tests finish before that happens).
--
You are receiving this mail because:
You are the assignee for the bug.