2018-12-04 19:14:38

by Anders Roxell

[permalink] [raw]
Subject: [PATCH] tracing: add cond_resched to ftrace_replace_code()

When running in qemu on an kernel built with allmodconfig and debug
options (in particular kcov and ubsan) enabled, ftrace_replace_code
function call take minutes. The ftrace selftest calls
ftrace_replace_code to look >40000 through
ftrace_make_call/ftrace_make_nop, and these end up calling
__aarch64_insn_write/aarch64_insn_patch_text_nosync.

Microseconds add up because this is called in a loop for each dyn_ftrace
record, and this triggers the softlockup watchdog unless we let it sleep
occasionally.

Rework so that we call cond_resched() if !irqs_disabled() && !preempt_count().

Suggested-by: Steven Rostedt (VMware) <[email protected]>
Signed-off-by: Anders Roxell <[email protected]>
---
kernel/trace/ftrace.c | 10 ++++++++++
1 file changed, 10 insertions(+)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index c375e33239f7..582e3441e318 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -2419,11 +2419,14 @@ void __weak ftrace_replace_code(int enable)
{
struct dyn_ftrace *rec;
struct ftrace_page *pg;
+ bool schedulable;
int failed;

if (unlikely(ftrace_disabled))
return;

+ schedulable = !irqs_disabled() && !preempt_count();
+
do_for_each_ftrace_rec(pg, rec) {

if (rec->flags & FTRACE_FL_DISABLED)
@@ -2435,6 +2438,13 @@ void __weak ftrace_replace_code(int enable)
/* Stop processing */
return;
}
+ /*
+ * Some archs calls this function with interrupts or preemption
+ * disabled. Howeve, other archs don't and this can cause a
+ * tremendous unneeded latency.
+ */
+ if (schedulable)
+ cond_resched();
} while_for_each_ftrace_rec();
}

--
2.19.2



2018-12-04 19:21:30

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing: add cond_resched to ftrace_replace_code()

On Tue, 4 Dec 2018 20:12:28 +0100
Anders Roxell <[email protected]> wrote:

> When running in qemu on an kernel built with allmodconfig and debug
> options (in particular kcov and ubsan) enabled, ftrace_replace_code
> function call take minutes. The ftrace selftest calls
> ftrace_replace_code to look >40000 through
> ftrace_make_call/ftrace_make_nop, and these end up calling
> __aarch64_insn_write/aarch64_insn_patch_text_nosync.
>
> Microseconds add up because this is called in a loop for each dyn_ftrace
> record, and this triggers the softlockup watchdog unless we let it sleep
> occasionally.
>
> Rework so that we call cond_resched() if !irqs_disabled() && !preempt_count().
>
> Suggested-by: Steven Rostedt (VMware) <[email protected]>
> Signed-off-by: Anders Roxell <[email protected]>
> ---
> kernel/trace/ftrace.c | 10 ++++++++++
> 1 file changed, 10 insertions(+)
>
> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index c375e33239f7..582e3441e318 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -2419,11 +2419,14 @@ void __weak ftrace_replace_code(int enable)
> {
> struct dyn_ftrace *rec;
> struct ftrace_page *pg;
> + bool schedulable;
> int failed;
>
> if (unlikely(ftrace_disabled))
> return;
>
> + schedulable = !irqs_disabled() && !preempt_count();
> +
> do_for_each_ftrace_rec(pg, rec) {
>
> if (rec->flags & FTRACE_FL_DISABLED)
> @@ -2435,6 +2438,13 @@ void __weak ftrace_replace_code(int enable)
> /* Stop processing */
> return;
> }
> + /*
> + * Some archs calls this function with interrupts or preemption
> + * disabled. Howeve, other archs don't and this can cause a
> + * tremendous unneeded latency.
> + */

Actually, could you move the comment up where schedulable gets set?

Thanks!

-- Steve

> + if (schedulable)
> + cond_resched();
> } while_for_each_ftrace_rec();
> }
>


2018-12-04 19:22:42

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing: add cond_resched to ftrace_replace_code()

On Tue, 4 Dec 2018 14:19:08 -0500
Steven Rostedt <[email protected]> wrote:

> > @@ -2435,6 +2438,13 @@ void __weak ftrace_replace_code(int enable)
> > /* Stop processing */
> > return;
> > }
> > + /*
> > + * Some archs calls this function with interrupts or preemption
> > + * disabled. Howeve, other archs don't and this can cause a

typo "However". But could you write it this way:

"However, for other archs that can preempt, this can cause an
tremendous unneeded latency."

Thanks!

-- Steve

> > + * tremendous unneeded latency.
> > + */
>
> Actually, could you move the comment up where schedulable gets set?
>
> Thanks!
>
> -- Steve
>
> > + if (schedulable)
> > + cond_resched();
> > } while_for_each_ftrace_rec();
> > }
> >
>


2018-12-04 19:27:09

by Anders Roxell

[permalink] [raw]
Subject: Re: [PATCH] tracing: add cond_resched to ftrace_replace_code()

On Tue, 4 Dec 2018 at 20:21, Steven Rostedt <[email protected]> wrote:
>
> On Tue, 4 Dec 2018 14:19:08 -0500
> Steven Rostedt <[email protected]> wrote:
>
> > > @@ -2435,6 +2438,13 @@ void __weak ftrace_replace_code(int enable)
> > > /* Stop processing */
> > > return;
> > > }
> > > + /*
> > > + * Some archs calls this function with interrupts or preemption
> > > + * disabled. Howeve, other archs don't and this can cause a
>
> typo "However". But could you write it this way:
>
> "However, for other archs that can preempt, this can cause an
> tremendous unneeded latency."
>

I'll fix this and move it up (where I added it in the first place but
moved it) =)

Cheers,
Anders

> Thanks!
>
> -- Steve
>
> > > + * tremendous unneeded latency.
> > > + */
> >
> > Actually, could you move the comment up where schedulable gets set?
> >
> > Thanks!
> >
> > -- Steve
> >
> > > + if (schedulable)
> > > + cond_resched();
> > > } while_for_each_ftrace_rec();
> > > }
> > >
> >
>

2018-12-04 19:31:42

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing: add cond_resched to ftrace_replace_code()

On Tue, 4 Dec 2018 20:25:31 +0100
Anders Roxell <[email protected]> wrote:

> On Tue, 4 Dec 2018 at 20:21, Steven Rostedt <[email protected]> wrote:
> >
> > On Tue, 4 Dec 2018 14:19:08 -0500
> > Steven Rostedt <[email protected]> wrote:
> >
> > > > @@ -2435,6 +2438,13 @@ void __weak ftrace_replace_code(int enable)
> > > > /* Stop processing */
> > > > return;
> > > > }
> > > > + /*
> > > > + * Some archs calls this function with interrupts or preemption
> > > > + * disabled. Howeve, other archs don't and this can cause a
> >
> > typo "However". But could you write it this way:
> >
> > "However, for other archs that can preempt, this can cause an
> > tremendous unneeded latency."
> >
>
> I'll fix this and move it up (where I added it in the first place but
> moved it) =)
>

I also noticed a grammar issue:

"Some archs call this function .."

-- Steve

2018-12-04 19:37:04

by Anders Roxell

[permalink] [raw]
Subject: Re: [PATCH] tracing: add cond_resched to ftrace_replace_code()

On Tue, 4 Dec 2018 at 20:29, Steven Rostedt <[email protected]> wrote:
>
> On Tue, 4 Dec 2018 20:25:31 +0100
> Anders Roxell <[email protected]> wrote:
>
> > On Tue, 4 Dec 2018 at 20:21, Steven Rostedt <[email protected]> wrote:
> > >
> > > On Tue, 4 Dec 2018 14:19:08 -0500
> > > Steven Rostedt <[email protected]> wrote:
> > >
> > > > > @@ -2435,6 +2438,13 @@ void __weak ftrace_replace_code(int enable)
> > > > > /* Stop processing */
> > > > > return;
> > > > > }
> > > > > + /*
> > > > > + * Some archs calls this function with interrupts or preemption
> > > > > + * disabled. Howeve, other archs don't and this can cause a
> > >
> > > typo "However". But could you write it this way:
> > >
> > > "However, for other archs that can preempt, this can cause an
> > > tremendous unneeded latency."
> > >
> >
> > I'll fix this and move it up (where I added it in the first place but
> > moved it) =)
> >
>
> I also noticed a grammar issue:
>
> "Some archs call this function .."

I will fix that.

Cheers,
Anders