* [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable
@ 2018-08-06 3:40 Joel Fernandes (Google)
2018-08-06 14:05 ` Masami Hiramatsu
0 siblings, 1 reply; 6+ messages in thread
From: Joel Fernandes (Google) @ 2018-08-06 3:40 UTC (permalink / raw)
To: linux-kernel
Cc: kernel-team, Joel Fernandes (Google),
Ingo Molnar, Steven Rostedt, Masami Hiramatsu, paulmck,
mathieu.desnoyers, namhyung, peterz
Recently we tried to make the preemptirqsoff tracer to use irqsoff
tracepoint probes. However this causes issues as reported by Masami:
[2.271078] Testing tracer preemptirqsoff: .. no entries found ..FAILED!
[2.381015] WARNING: CPU: 0 PID: 1 at /home/mhiramat/ksrc/linux/kernel/
trace/trace.c:1512 run_tracer_selftest+0xf3/0x154
This is due to the tracepoint code increasing the preempt nesting count
by calling an additional preempt_disable before calling into the
preemptoff tracer which messes up the preempt_count() check in
tracer_hardirqs_off.
To fix this, make the irqsoff tracer probes balance the additional outer
preempt_disable with a preempt_enable_notrace.
The other way to fix this is to just use SRCU for all tracepoints.
However we can't do that because we can't use NMIs from RCU context.
Fixes: c3bc8fd637a9 ("tracing: Centralize preemptirq tracepoints
and unify their usage")
Fixes: e6753f23d961 ("tracepoint: Make rcuidle tracepoint callers use SRCU")
Reported-by: Masami Hiramatsu <mhiramat@kernel.org>
Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
---
kernel/trace/trace_irqsoff.c | 26 ++++++++++++++++++++++++++
1 file changed, 26 insertions(+)
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 770cd30cda40..ffbf1505d5bc 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -603,14 +603,40 @@ static void irqsoff_tracer_stop(struct trace_array *tr)
*/
static void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
{
+ /*
+ * Tracepoint probes are expected to be called with preempt disabled,
+ * We don't care about being called with preempt disabled but we need
+ * to know in the future if that changes so we can remove the next
+ * preempt_enable.
+ */
+ WARN_ON_ONCE(!preempt_count());
+
+ /* Tracepoint probes disable preemption atleast once, account for that */
+ preempt_enable_notrace();
+
if (!preempt_trace() && irq_trace())
stop_critical_timing(a0, a1);
+
+ preempt_disable_notrace();
}
static void tracer_hardirqs_off(void *none, unsigned long a0, unsigned long a1)
{
+ /*
+ * Tracepoint probes are expected to be called with preempt disabled,
+ * We don't care about being called with preempt disabled but we need
+ * to know in the future if that changes so we can remove the next
+ * preempt_enable.
+ */
+ WARN_ON_ONCE(!preempt_count());
+
+ /* Tracepoint probes disable preemption atleast once, account for that */
+ preempt_enable_notrace();
+
if (!preempt_trace() && irq_trace())
start_critical_timing(a0, a1);
+
+ preempt_disable_notrace();
}
static int irqsoff_tracer_init(struct trace_array *tr)
--
2.18.0.597.ga71716f1ad-goog
^ permalink raw reply related [flat|nested] 6+ messages in thread
* Re: [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable
2018-08-06 3:40 [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable Joel Fernandes (Google)
@ 2018-08-06 14:05 ` Masami Hiramatsu
2018-08-06 14:14 ` Joel Fernandes
0 siblings, 1 reply; 6+ messages in thread
From: Masami Hiramatsu @ 2018-08-06 14:05 UTC (permalink / raw)
To: Joel Fernandes (Google)
Cc: linux-kernel, kernel-team, Ingo Molnar, Steven Rostedt,
Masami Hiramatsu, paulmck, mathieu.desnoyers, namhyung, peterz
On Sun, 5 Aug 2018 20:40:49 -0700
"Joel Fernandes (Google)" <joel@joelfernandes.org> wrote:
> Recently we tried to make the preemptirqsoff tracer to use irqsoff
> tracepoint probes. However this causes issues as reported by Masami:
>
> [2.271078] Testing tracer preemptirqsoff: .. no entries found ..FAILED!
> [2.381015] WARNING: CPU: 0 PID: 1 at /home/mhiramat/ksrc/linux/kernel/
> trace/trace.c:1512 run_tracer_selftest+0xf3/0x154
>
> This is due to the tracepoint code increasing the preempt nesting count
> by calling an additional preempt_disable before calling into the
> preemptoff tracer which messes up the preempt_count() check in
> tracer_hardirqs_off.
>
> To fix this, make the irqsoff tracer probes balance the additional outer
> preempt_disable with a preempt_enable_notrace.
I've tested it and ensured this fixes the problem.
Tested-by: Masami Hiramatsu <mhiramat@kernel.org>
And I have a comment on this code.
>
> The other way to fix this is to just use SRCU for all tracepoints.
> However we can't do that because we can't use NMIs from RCU context.
>
> Fixes: c3bc8fd637a9 ("tracing: Centralize preemptirq tracepoints
> and unify their usage")
> Fixes: e6753f23d961 ("tracepoint: Make rcuidle tracepoint callers use SRCU")
> Reported-by: Masami Hiramatsu <mhiramat@kernel.org>
> Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
> ---
> kernel/trace/trace_irqsoff.c | 26 ++++++++++++++++++++++++++
> 1 file changed, 26 insertions(+)
>
> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> index 770cd30cda40..ffbf1505d5bc 100644
> --- a/kernel/trace/trace_irqsoff.c
> +++ b/kernel/trace/trace_irqsoff.c
> @@ -603,14 +603,40 @@ static void irqsoff_tracer_stop(struct trace_array *tr)
> */
> static void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
> {
To ensure this function must not be preempted even if we increment preempt
count, I think you should check irq_disabled() whole this process, put below
here.
if (unlikely(!irq_disabled()))
return;
Since irq_disabled() will be checked in irq_trace() anyway, so no problem
to return here when !irq_disabled().
> + /*
> + * Tracepoint probes are expected to be called with preempt disabled,
> + * We don't care about being called with preempt disabled but we need
> + * to know in the future if that changes so we can remove the next
> + * preempt_enable.
> + */
> + WARN_ON_ONCE(!preempt_count());
> +
> + /* Tracepoint probes disable preemption atleast once, account for that */
* Even we do this here, we are sure that irq is disabled in this context.
* which means preemption is kept disabled.
> + preempt_enable_notrace();
> +
> if (!preempt_trace() && irq_trace())
> stop_critical_timing(a0, a1);
> +
> + preempt_disable_notrace();
> }
>
> static void tracer_hardirqs_off(void *none, unsigned long a0, unsigned long a1)
> {
Same here.
Any though :) ?
Thank you,
> + /*
> + * Tracepoint probes are expected to be called with preempt disabled,
> + * We don't care about being called with preempt disabled but we need
> + * to know in the future if that changes so we can remove the next
> + * preempt_enable.
> + */
> + WARN_ON_ONCE(!preempt_count());
> +
> + /* Tracepoint probes disable preemption atleast once, account for that */
> + preempt_enable_notrace();
> +
> if (!preempt_trace() && irq_trace())
> start_critical_timing(a0, a1);
> +
> + preempt_disable_notrace();
> }
>
> static int irqsoff_tracer_init(struct trace_array *tr)
> --
> 2.18.0.597.ga71716f1ad-goog
>
--
Masami Hiramatsu <mhiramat@kernel.org>
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable
2018-08-06 14:05 ` Masami Hiramatsu
@ 2018-08-06 14:14 ` Joel Fernandes
2018-08-10 12:55 ` Masami Hiramatsu
0 siblings, 1 reply; 6+ messages in thread
From: Joel Fernandes @ 2018-08-06 14:14 UTC (permalink / raw)
To: Masami Hiramatsu
Cc: Joel Fernandes (Google),
LKML, Cc: Android Kernel, Ingo Molnar, Steven Rostedt,
Paul McKenney, Mathieu Desnoyers, Namhyung Kim, Peter Zijlstra
On Mon, Aug 6, 2018 at 7:05 AM, Masami Hiramatsu <mhiramat@kernel.org> wrote:
> On Sun, 5 Aug 2018 20:40:49 -0700
> "Joel Fernandes (Google)" <joel@joelfernandes.org> wrote:
>
>> Recently we tried to make the preemptirqsoff tracer to use irqsoff
>> tracepoint probes. However this causes issues as reported by Masami:
>>
>> [2.271078] Testing tracer preemptirqsoff: .. no entries found ..FAILED!
>> [2.381015] WARNING: CPU: 0 PID: 1 at /home/mhiramat/ksrc/linux/kernel/
>> trace/trace.c:1512 run_tracer_selftest+0xf3/0x154
>>
>> This is due to the tracepoint code increasing the preempt nesting count
>> by calling an additional preempt_disable before calling into the
>> preemptoff tracer which messes up the preempt_count() check in
>> tracer_hardirqs_off.
>>
>> To fix this, make the irqsoff tracer probes balance the additional outer
>> preempt_disable with a preempt_enable_notrace.
>
> I've tested it and ensured this fixes the problem.
>
> Tested-by: Masami Hiramatsu <mhiramat@kernel.org>
Thanks!
>> The other way to fix this is to just use SRCU for all tracepoints.
>> However we can't do that because we can't use NMIs from RCU context.
>>
>> Fixes: c3bc8fd637a9 ("tracing: Centralize preemptirq tracepoints
>> and unify their usage")
>> Fixes: e6753f23d961 ("tracepoint: Make rcuidle tracepoint callers use SRCU")
>> Reported-by: Masami Hiramatsu <mhiramat@kernel.org>
>> Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
>> ---
>> kernel/trace/trace_irqsoff.c | 26 ++++++++++++++++++++++++++
>> 1 file changed, 26 insertions(+)
>>
>> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
>> index 770cd30cda40..ffbf1505d5bc 100644
>> --- a/kernel/trace/trace_irqsoff.c
>> +++ b/kernel/trace/trace_irqsoff.c
>> @@ -603,14 +603,40 @@ static void irqsoff_tracer_stop(struct trace_array *tr)
>> */
>> static void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
>> {
>
> To ensure this function must not be preempted even if we increment preempt
> count, I think you should check irq_disabled() whole this process, put below
> here.
>
> if (unlikely(!irq_disabled()))
> return;
>
> Since irq_disabled() will be checked in irq_trace() anyway, so no problem
> to return here when !irq_disabled().
IRQs can never be enabled here. The trace hooks are called only after
disabling interrupts, or before enabling them. Right?
thanks,
- Joel
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable
2018-08-06 14:14 ` Joel Fernandes
@ 2018-08-10 12:55 ` Masami Hiramatsu
2018-08-10 13:01 ` Joel Fernandes
0 siblings, 1 reply; 6+ messages in thread
From: Masami Hiramatsu @ 2018-08-10 12:55 UTC (permalink / raw)
To: Joel Fernandes
Cc: Joel Fernandes (Google),
LKML, Cc: Android Kernel, Ingo Molnar, Steven Rostedt,
Paul McKenney, Mathieu Desnoyers, Namhyung Kim, Peter Zijlstra
On Mon, 6 Aug 2018 07:14:35 -0700
Joel Fernandes <joelaf@google.com> wrote:
> On Mon, Aug 6, 2018 at 7:05 AM, Masami Hiramatsu <mhiramat@kernel.org> wrote:
> > On Sun, 5 Aug 2018 20:40:49 -0700
> > "Joel Fernandes (Google)" <joel@joelfernandes.org> wrote:
> >
> >> Recently we tried to make the preemptirqsoff tracer to use irqsoff
> >> tracepoint probes. However this causes issues as reported by Masami:
> >>
> >> [2.271078] Testing tracer preemptirqsoff: .. no entries found ..FAILED!
> >> [2.381015] WARNING: CPU: 0 PID: 1 at /home/mhiramat/ksrc/linux/kernel/
> >> trace/trace.c:1512 run_tracer_selftest+0xf3/0x154
> >>
> >> This is due to the tracepoint code increasing the preempt nesting count
> >> by calling an additional preempt_disable before calling into the
> >> preemptoff tracer which messes up the preempt_count() check in
> >> tracer_hardirqs_off.
> >>
> >> To fix this, make the irqsoff tracer probes balance the additional outer
> >> preempt_disable with a preempt_enable_notrace.
> >
> > I've tested it and ensured this fixes the problem.
> >
> > Tested-by: Masami Hiramatsu <mhiramat@kernel.org>
>
> Thanks!
>
> >> The other way to fix this is to just use SRCU for all tracepoints.
> >> However we can't do that because we can't use NMIs from RCU context.
> >>
> >> Fixes: c3bc8fd637a9 ("tracing: Centralize preemptirq tracepoints
> >> and unify their usage")
> >> Fixes: e6753f23d961 ("tracepoint: Make rcuidle tracepoint callers use SRCU")
> >> Reported-by: Masami Hiramatsu <mhiramat@kernel.org>
> >> Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
> >> ---
> >> kernel/trace/trace_irqsoff.c | 26 ++++++++++++++++++++++++++
> >> 1 file changed, 26 insertions(+)
> >>
> >> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> >> index 770cd30cda40..ffbf1505d5bc 100644
> >> --- a/kernel/trace/trace_irqsoff.c
> >> +++ b/kernel/trace/trace_irqsoff.c
> >> @@ -603,14 +603,40 @@ static void irqsoff_tracer_stop(struct trace_array *tr)
> >> */
> >> static void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
> >> {
> >
> > To ensure this function must not be preempted even if we increment preempt
> > count, I think you should check irq_disabled() whole this process, put below
> > here.
> >
> > if (unlikely(!irq_disabled()))
> > return;
> >
> > Since irq_disabled() will be checked in irq_trace() anyway, so no problem
> > to return here when !irq_disabled().
>
> IRQs can never be enabled here. The trace hooks are called only after
> disabling interrupts, or before enabling them. Right?
>
Even though, it should be verified or atleast commented on the function header.
Thank you,
--
Masami Hiramatsu <mhiramat@kernel.org>
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable
2018-08-10 12:55 ` Masami Hiramatsu
@ 2018-08-10 13:01 ` Joel Fernandes
2018-08-10 13:06 ` Steven Rostedt
0 siblings, 1 reply; 6+ messages in thread
From: Joel Fernandes @ 2018-08-10 13:01 UTC (permalink / raw)
To: Masami Hiramatsu
Cc: Joel Fernandes (Google),
LKML, Cc: Android Kernel, Ingo Molnar, Steven Rostedt,
Paul McKenney, Mathieu Desnoyers, Namhyung Kim, Peter Zijlstra
On Fri, Aug 10, 2018 at 5:55 AM, Masami Hiramatsu <mhiramat@kernel.org> wrote:
[..]
>>
>> >> The other way to fix this is to just use SRCU for all tracepoints.
>> >> However we can't do that because we can't use NMIs from RCU context.
>> >>
>> >> Fixes: c3bc8fd637a9 ("tracing: Centralize preemptirq tracepoints
>> >> and unify their usage")
>> >> Fixes: e6753f23d961 ("tracepoint: Make rcuidle tracepoint callers use SRCU")
>> >> Reported-by: Masami Hiramatsu <mhiramat@kernel.org>
>> >> Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
>> >> ---
>> >> kernel/trace/trace_irqsoff.c | 26 ++++++++++++++++++++++++++
>> >> 1 file changed, 26 insertions(+)
>> >>
>> >> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
>> >> index 770cd30cda40..ffbf1505d5bc 100644
>> >> --- a/kernel/trace/trace_irqsoff.c
>> >> +++ b/kernel/trace/trace_irqsoff.c
>> >> @@ -603,14 +603,40 @@ static void irqsoff_tracer_stop(struct trace_array *tr)
>> >> */
>> >> static void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
>> >> {
>> >
>> > To ensure this function must not be preempted even if we increment preempt
>> > count, I think you should check irq_disabled() whole this process, put below
>> > here.
>> >
>> > if (unlikely(!irq_disabled()))
>> > return;
>> >
>> > Since irq_disabled() will be checked in irq_trace() anyway, so no problem
>> > to return here when !irq_disabled().
>>
>> IRQs can never be enabled here. The trace hooks are called only after
>> disabling interrupts, or before enabling them. Right?
>>
>
> Even though, it should be verified or atleast commented on the function header.
Ok. ftrace/core has been fixed since since so this patch is outdated
and isn't needed any more, but I agree a separate patch doc comment
would help make it clear about this fact. Both IRQ and preempt
tracepoints work this way, they fire only within their critical
section.
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable
2018-08-10 13:01 ` Joel Fernandes
@ 2018-08-10 13:06 ` Steven Rostedt
0 siblings, 0 replies; 6+ messages in thread
From: Steven Rostedt @ 2018-08-10 13:06 UTC (permalink / raw)
To: Joel Fernandes
Cc: Masami Hiramatsu, Joel Fernandes (Google),
LKML, Cc: Android Kernel, Ingo Molnar, Paul McKenney,
Mathieu Desnoyers, Namhyung Kim, Peter Zijlstra
On Fri, 10 Aug 2018 06:01:34 -0700
Joel Fernandes <joelaf@google.com> wrote:
> > Even though, it should be verified or atleast commented on the function header.
>
> Ok. ftrace/core has been fixed since since so this patch is outdated
> and isn't needed any more, but I agree a separate patch doc comment
> would help make it clear about this fact. Both IRQ and preempt
> tracepoints work this way, they fire only within their critical
> section.
Note, I'm keeping the patch in the git history. As an artifact that can
be found easily when looking at this code for further enhancements.
Feel free to send a patch that adds comments to these callbacks.
-- Steve
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2018-08-10 13:06 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-08-06 3:40 [PATCH ftrace/core] tracing: irqsoff: Account for additional preempt_disable Joel Fernandes (Google)
2018-08-06 14:05 ` Masami Hiramatsu
2018-08-06 14:14 ` Joel Fernandes
2018-08-10 12:55 ` Masami Hiramatsu
2018-08-10 13:01 ` Joel Fernandes
2018-08-10 13:06 ` Steven Rostedt
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).