ftrace_shutdown() checks for sanity of ftrace records
and if dyn_ftrace->flags is not zero, it will warn.
It can happen that 'flags' are set to FTRACE_FL_DISABLED at this point,
since some module was loaded, but before ftrace_module_enable()
cleared the flags for this module.
In other words the module.c is doing:
ftrace_module_init(mod); // calls ftrace_update_code() that sets flags=FTRACE_FL_DISABLED
... // here ftrace_shutdown() is called that warns, since
err = prepare_coming_module(mod); // didn't have a chance to clear FTRACE_FL_DISABLED
Fix it by ignoring disabled records.
It's similar to what __ftrace_hash_rec_update() is already doing.
Signed-off-by: Alexei Starovoitov <[email protected]>
---
kernel/trace/ftrace.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 2050a7652a86..326498baab83 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -2763,7 +2763,7 @@ static int ftrace_shutdown(struct ftrace_ops *ops, int command)
struct dyn_ftrace *rec;
do_for_each_ftrace_rec(pg, rec) {
- if (FTRACE_WARN_ON_ONCE(rec->flags))
+ if (FTRACE_WARN_ON_ONCE(rec->flags & ~FTRACE_FL_DISABLED))
pr_warn(" %pS flags:%lx\n",
(void *)rec->ip, rec->flags);
} while_for_each_ftrace_rec();
--
2.8.0
On Mon, 7 Nov 2016 15:14:20 -0800
Alexei Starovoitov <[email protected]> wrote:
> ftrace_shutdown() checks for sanity of ftrace records
> and if dyn_ftrace->flags is not zero, it will warn.
> It can happen that 'flags' are set to FTRACE_FL_DISABLED at this point,
> since some module was loaded, but before ftrace_module_enable()
> cleared the flags for this module.
>
> In other words the module.c is doing:
> ftrace_module_init(mod); // calls ftrace_update_code() that sets flags=FTRACE_FL_DISABLED
> ... // here ftrace_shutdown() is called that warns, since
> err = prepare_coming_module(mod); // didn't have a chance to clear FTRACE_FL_DISABLED
>
> Fix it by ignoring disabled records.
> It's similar to what __ftrace_hash_rec_update() is already doing.
>
Alexei,
Do you have a clear reproducer of this bug?
-- Steve
> Signed-off-by: Alexei Starovoitov <[email protected]>
> ---
> kernel/trace/ftrace.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index 2050a7652a86..326498baab83 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -2763,7 +2763,7 @@ static int ftrace_shutdown(struct ftrace_ops *ops, int command)
> struct dyn_ftrace *rec;
>
> do_for_each_ftrace_rec(pg, rec) {
> - if (FTRACE_WARN_ON_ONCE(rec->flags))
> + if (FTRACE_WARN_ON_ONCE(rec->flags & ~FTRACE_FL_DISABLED))
> pr_warn(" %pS flags:%lx\n",
> (void *)rec->ip, rec->flags);
> } while_for_each_ftrace_rec();
On Mon, Nov 14, 2016 at 02:24:28PM -0500, Steven Rostedt wrote:
> On Mon, 7 Nov 2016 15:14:20 -0800
> Alexei Starovoitov <[email protected]> wrote:
>
> > ftrace_shutdown() checks for sanity of ftrace records
> > and if dyn_ftrace->flags is not zero, it will warn.
> > It can happen that 'flags' are set to FTRACE_FL_DISABLED at this point,
> > since some module was loaded, but before ftrace_module_enable()
> > cleared the flags for this module.
> >
> > In other words the module.c is doing:
> > ftrace_module_init(mod); // calls ftrace_update_code() that sets flags=FTRACE_FL_DISABLED
> > ... // here ftrace_shutdown() is called that warns, since
> > err = prepare_coming_module(mod); // didn't have a chance to clear FTRACE_FL_DISABLED
> >
> > Fix it by ignoring disabled records.
> > It's similar to what __ftrace_hash_rec_update() is already doing.
> >
>
> Alexei,
>
> Do you have a clear reproducer of this bug?
Nope. No reproducer. It's very rare. Only stack trace that I posted earlier.
Since it kills ftrace everything that depends on it later spews a ton
of other warnings. So it's an important fix.