Message-ID: <1083900143.1198.1547141113001.JavaMail.zimbra@efficios.com>
Date:   Thu, 10 Jan 2019 12:25:13 -0500 (EST)
From:   Mathieu Desnoyers <mathieu.desnoyers@...icios.com>
To:     rostedt <rostedt@...dmis.org>
Cc:     "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>,
        linux-kernel <linux-kernel@...r.kernel.org>,
        Peter Zijlstra <peterz@...radead.org>
Subject: Re: Possible use of RCU while in extended QS: idle vs RCU read-side
 in interrupt vs rcu_eqs_exit

----- On Jan 10, 2019, at 9:11 AM, Mathieu Desnoyers mathieu.desnoyers@...icios.com wrote:

> ----- On Jan 10, 2019, at 8:44 AM, Mathieu Desnoyers
> mathieu.desnoyers@...icios.com wrote:
> 
>> ----- On Jan 10, 2019, at 8:08 AM, rostedt rostedt@...dmis.org wrote:
>> 
>>> On Wed, 9 Jan 2019 20:38:51 -0500 (EST)
>>> Mathieu Desnoyers <mathieu.desnoyers@...icios.com> wrote:
>>> 
>>>> Hi Paul,
>>>> 
>>>> I've had a user report that trace_sched_waking() appears to be
>>>> invoked while !rcu_is_watching() in some situation, so I started
>>>> digging into the scheduler idle code.
>>> 
>>> I'm wondering if this isn't a bug. Do you have the backtrace for where
>>> trace_sched_waking() was called without rcu watching?
>> 
>> I strongly suspect a bug as well. I'm awaiting a reproducer from the
>> user whom reported this issue so I can add a WARN_ON_ONCE(!rcu_is_watching())
>> in the scheduler code near trace_sched_waking() and gather a backtrace.
>> 
>> It still has to be confirmed, but I suspect this have been triggered
>> within a HyperV guest. It may therefore be related to a virtualized environment.
>> 
>> I'll try to ask more specifically on which environment this was encountered.
> 
> So it ends up it happens directly on hardware on a Linux laptop. Here is
> the stacktrace:
> 
> vmlinux!try_to_wake_up
> vmlinux!default_wake_function
> vmlinux!pollwake
> vmlinux!__wake_up_common
> vmlinux!__wake_up_common_lock
> vmlinux!__wake_up
> vmlinux!perf_event_wakeup
> vmlinux!perf_pending_event
> vmlinux!irq_work_run_list
> vmlinux!irq_work_run
> vmlinux!smp_irq_work_iterrupt
> vmlinux!irq_work_interrupt
> vmlinux!finish_task_switch
> vmlinux!__schedule
> vmlinux!schedule_idle
> vmlinux!do_idle
> vmlinux!cpu_startup_entry
> vmlinux!start_secondary
> vmlinux!secondary_startup_64
> 
> Does it raise any red flag ?

Based on this backtrace, I think I start to get a better understanding
of the situation.

The initial problem reported to me was that ftrace was showing some sched_waking
events in its trace that were missed by perf.

I presumed this was because of the !rcu_is_watching() check, but I think I was
wrong.

This backtrace seems to show that perf is itself triggering a sched_waking()
event. It there is probably a check that discards nested events within perf,
which would discard this from perf traces, but ftrace (and lttng) would trace
it just fine.

Thoughts ?

Thanks,

Mathieu


> 
> Thanks,
> 
> Mathieu
> 
>> 
>> Thanks,
>> 
>> Mathieu
>> 
>>> 
>>> -- Steve
>>> 
>>>> 
>>>> It appears that interrupts are re-enabled before rcu_eqs_exit() is
>>>> invoked when exiting idle code from the scheduler.
>>>> 
>>>> I wonder what happens if an interrupt handler (including scheduler code)
>>>> happens to issue a RCU read-side critical section before rcu_eqs_exit()
>>>> is called ? Is there some code on interrupt entry that ensures rcu eqs
>>>> state is exited in such scenario ?
>>>> 
>>>> Thanks,
>>>> 
>>>> Mathieu
>> 
>> --
>> Mathieu Desnoyers
>> EfficiOS Inc.
>> http://www.efficios.com
> 
> --
> Mathieu Desnoyers
> EfficiOS Inc.
> http://www.efficios.com

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Powered by blists - more mailing lists