From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 25742 invoked by alias); 12 Jun 2018 16:01:38 -0000 Mailing-List: contact systemtap-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Post: List-Help: , Sender: systemtap-owner@sourceware.org Received: (qmail 25239 invoked by uid 48); 12 Jun 2018 16:01:29 -0000 From: "serhei.public at gmail dot com" To: systemtap@sourceware.org Subject: [Bug kprobes/23276] New: 'suspicious RCU usage' on rawhide 4.18.0-0.rc0 Date: Tue, 12 Jun 2018 16:01:00 -0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: new X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: systemtap X-Bugzilla-Component: kprobes X-Bugzilla-Version: unspecified X-Bugzilla-Keywords: X-Bugzilla-Severity: normal X-Bugzilla-Who: serhei.public at gmail dot com X-Bugzilla-Status: UNCONFIRMED X-Bugzilla-Resolution: X-Bugzilla-Priority: P2 X-Bugzilla-Assigned-To: systemtap at sourceware dot org X-Bugzilla-Target-Milestone: --- X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: bug_id short_desc product version bug_status bug_severity priority component assigned_to reporter target_milestone Message-ID: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Bugzilla-URL: http://sourceware.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-SW-Source: 2018-q2/txt/msg00100.txt.bz2 https://sourceware.org/bugzilla/show_bug.cgi?id=3D23276 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] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D [ +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/r= untime_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 =3D 2, debug_locks =3D 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=20=20= =20=20 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] [ +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] [ +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] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D [ +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 =3D 2, debug_locks =3D 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=20=20= =20=20 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] [ +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 7= 4 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 c= 3 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: 000000000000= 0002 [ +0.000002] RDX: 0000000000000000 RSI: ffffffffad7df010 RDI: 000000000000= 0046 [ +0.000001] RBP: ffffffffc06be145 R08: ffff9ce77b203ae9 R09: 0000000052d2= 710c [ +0.000001] R10: ffffffffaeec4500 R11: ffffffffae96d5d8 R12: ffff9ce77b20= 3a98 [ +0.000001] R13: ffff9ce77b203aa8 R14: ffff9ce77b203aa0 R15: ffffffffad2d= 8f16 [ +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=20=20= =20=20 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 7= 4 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 c= 3 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: 000000000000= 0002 [ +0.000001] RDX: 0000000000000000 RSI: ffffffffad7df010 RDI: 000000000000= 0046 [ +0.000001] RBP: ffffffffc06be144 R08: ffff9ce77b203541 R09: 0000000052c2= f313 [ +0.000001] R10: ffff9ce77b3d8d00 R11: 0000000000000000 R12: ffff9ce77b20= 34f0 [ +0.000002] R13: ffff9ce77b203500 R14: ffff9ce77b2034f8 R15: ffffffffad2d= 8f16 [ +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: 000000000000= 06e0 [ +0.000001] DR0: ffffffffc04d4108 DR1: 0000000000000000 DR2: 000000000000= 0000 [ +0.000001] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 000000000000= 0600 [ +0.000001] Call Trace: [ +0.000001] [ +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] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D [ +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 =3D 2, debug_locks =3D 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=20=20= =20=20 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] [ +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] [ +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] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D [ +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/r= untime_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 =3D 2, debug_locks =3D 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=20=20= =20=20 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] [ +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] [ +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] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D [ +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/r= untime_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 =3D 2, debug_locks =3D 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=20=20= =20=20 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] [ +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] [ +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). --=20 You are receiving this mail because: You are the assignee for the bug.