[Bug runtime/20192] New: "suspicious RCU usage." warning from kernel when running testsuite

["wcohen at redhat dot com" <sourceware-bugzilla at sourceware dot org>]

https://sourceware.org/bugzilla/show_bug.cgi?id=20192

            Bug ID: 20192
           Summary: "suspicious RCU usage." warning from kernel when
                    running testsuite
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: runtime
          Assignee: systemtap at sourceware dot org
          Reporter: wcohen at redhat dot com
  Target Milestone: ---

When running the systemtap testsuite on an locally built arm64 kernel
(4.7.0-rc1+) and systemtap (commit bedfbdce09896263d5fc2171e5f91164fb813fce)
one of the tests seemed to trigger the following output on the console:


Running /root/systemtap_write/systemtap/testsuite/systemtap.base/pr14546.exp
...
[53071.438708] 
[53071.440198] ===============================
[53071.444358] [ INFO: suspicious RCU usage. ]
[53071.448521] 4.7.0-rc1+ #2 Tainted: G        W  OE  
[53071.453372] -------------------------------
[53071.457531]
/root/systemtap_write/install/share/systemtap/runtime/linux/runtime_context.h:64
suspicious rcu_dereference_check() usage!
[53071.469555] 
[53071.469555] other info that might help us debug this:
[53071.469555] 
[53071.477518] 
[53071.477518] RCU used illegally from idle CPU!
[53071.477518] rcu_scheduler_active = 1, debug_locks = 0
[53071.488332] RCU used illegally from extended quiescent state!
[53071.494048] no locks held by swapper/1/0.
[53071.498034] 
[53071.498034] stack backtrace:
[53071.502370] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G        W  OE  
4.7.0-rc1+ #2
[53071.509813] Hardware name: AppliedMicro Mustang/Mustang, BIOS 1.1.0 Oct 20
2015
[53071.517084] Call trace:
[53071.519522] [<fffffc0008088ba8>] dump_backtrace+0x0/0x1f0
[53071.524894] [<fffffc0008088dbc>] show_stack+0x24/0x30
[53071.529921] [<fffffc0008461adc>] dump_stack+0xb4/0xf0
[53071.534948] [<fffffc0008127698>] lockdep_rcu_suspicious+0xe8/0x120
[53071.541109] [<fffffc0002b911a8>] _stp_runtime_entryfn_get_context+0xd8/0x100
[stap_06d0d9ff274800cb17977f1e3fcc25fc_1_3015]
[53071.552193] [<fffffc0002b9aca4>] enter_kprobe_probe+0x10c/0x380
[stap_06d0d9ff274800cb17977f1e3fcc25fc_1_3015]
[53071.562144] [<fffffc00088ef1a0>] kprobe_breakpoint_handler+0xb8/0x1a0
[53071.568552] [<fffffc0008084ae4>] brk_handler+0x5c/0x98
[53071.573663] [<fffffc0008081244>] do_debug_exception+0x64/0xe0
[53071.579379] Exception stack(0xfffffe01ffe23d60 to 0xfffffe01ffe23e80)
[53071.585787] 3d60: fffffe01dc1a8000 fffffc0008db9d80 fffffe01ffe23f30
fffffc00080d06e0
[53071.593577] 3d80: 00000000800001c5 000000000000003d 0000000000000001
0000000000000000
[53071.601367] 3da0: fffffc0000000000 fffffc0000000000 fffffe01ffe23e20
fffffc00088ed6ec
[53071.609156] 3dc0: 00000000000001c0 fffffe01ffe25f80 fffffc000815c4d8
fffffe01ffe24f00
[53071.616946] 3de0: fffffc0008e01000 fffffe01ffe3d800 fffffc0008e00000
0000000000000001
[53071.624735] 3e00: fffffe01ffe23e20 fffffc00088ed6f4 fffffc0008db9d80
fffffe00c8a70920
[53071.632525] 3e20: fffffe01ffe39d80 00000201f7080000 0000000000000000
00000000000c008c
[53071.640314] 3e40: fffffc0009172a80 fffffc000815c4c4 fffffc0008e8e000
fffffe01dc1a8000
[53071.648105] 3e60: 0000000000002140 0000000000000000 0000000000000000
000f41d9c36c0000
[53071.655894] [<fffffc00080824b4>] el1_dbg+0x18/0x6c
[53071.660661] [<fffffc000808f29c>] handle_IPI+0x2b4/0x3a8
[53071.665858] [<fffffc0008081560>] gic_handle_irq+0x98/0xb8
[53071.671227] Exception stack(0xfffffe01ffe23fd0 to 0xfffffe01ffe240f0)
[53071.677635] 3fc0:                                   fffffe01dc1abe10
fffffc0008e01d40
[53071.685424] 3fe0: fffffe01dc1abf30 fffffc000808556c 0000000060000145
0000000000000000
[53071.693214] 4000: fffffe01dc1abf30 fffffe01dc1abe10 0000000000000000
0000000000000000
[53071.701003] 4020: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
[53071.708793] 4040: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
[53071.716582] 4060: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
[53071.724372] 4080: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
[53071.732161] 40a0: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
[53071.739951] 40c0: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
[53071.747740] 40e0: 0000000000000000 0000000000000000
[53071.752591] [<fffffc00080825e4>] el1_irq+0xa4/0x100
[53071.757444] [<fffffc000808556c>] arch_cpu_idle+0x2c/0x250
[53071.762815] [<fffffc000811c5b8>] default_idle_call+0x20/0x38
[53071.768445] [<fffffc000811c89c>] cpu_startup_entry+0x2cc/0x348
[53071.774247] [<fffffc000808ea74>] secondary_start_kernel+0x194/0x208
[53071.780481] [<0000004000083198>] 0x4000083198

It looks like the code triggering the problem is the following from
runtime/linux/context.h:

static inline struct context * _stp_runtime_get_context(void)
{
        return rcu_dereference_sched(contexts[smp_processor_id()]);
}

static struct context * _stp_runtime_entryfn_get_context(void)
{
        struct context* __restrict__ c = NULL;
        preempt_disable ();
        c = _stp_runtime_get_context();
        if (c != NULL) {
                if (atomic_inc_return(&c->busy) == 1)
                        return c;
                atomic_dec(&c->busy);
        }
        preempt_enable_no_resched();
        return NULL;
}

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