2011-03-08 22:18:09

by Steven Rostedt

[permalink] [raw]
Subject: [PATCH][RFC] tracing: Enable tracepoints via module parameters

A few months ago it was suggested to have a way to enable tracepoints in
a module when it is loaded. I tried various methods, but this one seems
to be the least intrusive. In fact, it requires no modification to the
module code.

The trace event now adds its own MODULE_INFO() and kernel_param_ops that
and links the information about a tracepoint into the module's __param
section. A module can be loaded with a tracepoint active by adding
trace_<tracepoint>=1 as one of the parameters.

The following patch is in:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git

branch: rfc/trace


Steven Rostedt (1):
tracing: Enable tracepoints via module parameters

----
include/linux/ftrace_event.h | 4 +++
include/trace/ftrace.h | 22 ++++++++++++++++-
kernel/trace/trace_events.c | 52 ++++++++++++++++++++++++++++++++++++++++++
3 files changed, 76 insertions(+), 2 deletions(-)
---------------------------
commit b514aa1b59148994a47086cdd46db7f994b4789e
Author: Steven Rostedt <[email protected]>
Date: Tue Mar 8 17:06:14 2011 -0500

tracing: Enable tracepoints via module parameters

Add the tracepoints within the module to the module info section
and allow the tracepoints to be enabled when the module is loaded.

For example:

[root]# modinfo samples/trace_events/trace-events-sample.ko
filename: samples/trace_events/trace-events-sample.ko
license: GPL
description: trace-events-sample
author: Steven Rostedt
tracepoint: foo_bar
srcversion: F6AC4B8D911A5C5B9CCDD7B
depends:
vermagic: 2.6.38-rc5+ SMP preempt mod_unload

Notice that the trace-events-sample tracepoint "foo_bar" shows
up in the modinfo. When loading the module with:

# insmod trace-events-sample.ko trace_foo_bar=1

The tracepoint "foo_bar" will be enabled.

Cc: Yuanhan Liu <[email protected]>
Cc: Chris Wilson <[email protected]>
Cc: Rusty Russell <[email protected]>
Signed-off-by: Steven Rostedt <[email protected]>

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 47e3997..b672889 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -124,6 +124,8 @@ void tracing_record_cmdline(struct task_struct *tsk);

struct event_filter;

+extern struct kernel_param_ops ftrace_mod_ops;
+
enum trace_reg {
TRACE_REG_REGISTER,
TRACE_REG_UNREGISTER,
@@ -155,6 +157,7 @@ enum {
TRACE_EVENT_FL_FILTERED_BIT,
TRACE_EVENT_FL_RECORDED_CMD_BIT,
TRACE_EVENT_FL_CAP_ANY_BIT,
+ TRACE_EVENT_FL_MOD_ENABLE_BIT,
};

enum {
@@ -162,6 +165,7 @@ enum {
TRACE_EVENT_FL_FILTERED = (1 << TRACE_EVENT_FL_FILTERED_BIT),
TRACE_EVENT_FL_RECORDED_CMD = (1 << TRACE_EVENT_FL_RECORDED_CMD_BIT),
TRACE_EVENT_FL_CAP_ANY = (1 << TRACE_EVENT_FL_CAP_ANY_BIT),
+ TRACE_EVENT_FL_MOD_ENABLE = (1 << TRACE_EVENT_FL_MOD_ENABLE_BIT),
};

struct ftrace_event_call {
diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index 3e68366..3d4a6ee 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -561,6 +561,22 @@ static inline void ftrace_test_probe_##call(void) \
#undef __get_dynamic_array
#undef __get_str

+/*
+ * Add ftrace trace points in modules to be set by module
+ * parameters. This adds "trace_##call" as a module parameter.
+ * The user could enable trace points on module load with:
+ * trace_##call=1 as a module parameter.
+ */
+#undef ftrace_mod_params
+#ifdef MODULE
+#define ftrace_mod_params(call) \
+ module_param_cb(trace_##call, &ftrace_mod_ops, \
+ &event_##call, 0644); \
+ MODULE_INFO(tracepoint, #call)
+#else
+#define ftrace_mod_params(call)
+#endif
+
#undef TP_printk
#define TP_printk(fmt, args...) "\"" fmt "\", " __stringify(args)

@@ -588,7 +604,8 @@ static struct ftrace_event_call __used event_##call = { \
.print_fmt = print_fmt_##template, \
}; \
static struct ftrace_event_call __used \
-__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
+__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call;\
+ftrace_mod_params(call)

#undef DEFINE_EVENT_PRINT
#define DEFINE_EVENT_PRINT(template, call, proto, args, print) \
@@ -602,7 +619,8 @@ static struct ftrace_event_call __used event_##call = { \
.print_fmt = print_fmt_##call, \
}; \
static struct ftrace_event_call __used \
-__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
+__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call; \
+ftrace_mod_params(call)

#include TRACE_INCLUDE(TRACE_INCLUDE_FILE)

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index 5f499e0..5223751 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -1285,6 +1285,7 @@ static void trace_module_add_events(struct module *mod)
{
struct ftrace_module_file_ops *file_ops = NULL;
struct ftrace_event_call **call, **start, **end;
+ int ret;

start = mod->trace_events;
end = mod->trace_events + mod->num_trace_events;
@@ -1300,6 +1301,14 @@ static void trace_module_add_events(struct module *mod)
__trace_add_event_call(*call, mod,
&file_ops->id, &file_ops->enable,
&file_ops->filter, &file_ops->format);
+ /* If the module tracepoint parameter was set */
+ if ((*call)->flags & TRACE_EVENT_FL_MOD_ENABLE) {
+ (*call)->flags = 0;
+ ret = ftrace_event_enable_disable(*call, 1);
+ if (ret < 0)
+ pr_warning("unable to enable tracepoint %s",
+ (*call)->name);
+ }
}
}

@@ -1457,6 +1466,49 @@ static __init int event_trace_init(void)
}
fs_initcall(event_trace_init);

+/* Allow modules to load with enabled trace points */
+int ftrace_mod_param_set(const char *val, const struct kernel_param *kp)
+{
+ struct ftrace_event_call *call = kp->arg;
+
+ /* This is set like param_set_bool() */
+
+ /* No equals means "set"... */
+ if (!val)
+ val = "1";
+
+ /* One of =[yYnN01] */
+ switch (val[0]) {
+ case 'y': case 'Y': case '1':
+ break;
+ case 'n': case 'N': case '0':
+ /* Do nothing */
+ return 0;
+ default:
+ return -EINVAL;
+ }
+
+ /* Set flag to tell ftrace to enable this event on init */
+ call->flags = TRACE_EVENT_FL_MOD_ENABLE;
+
+ return 0;
+}
+
+int ftrace_mod_param_get(char *buffer, const struct kernel_param *kp)
+{
+ struct ftrace_event_call *call = kp->arg;
+
+ return sprintf(buffer, "%d",
+ !!(call->flags &
+ (TRACE_EVENT_FL_MOD_ENABLE | TRACE_EVENT_FL_ENABLED)));
+}
+
+struct kernel_param_ops ftrace_mod_ops = {
+ .set = ftrace_mod_param_set,
+ .get = ftrace_mod_param_get,
+};
+EXPORT_SYMBOL(ftrace_mod_ops);
+
#ifdef CONFIG_FTRACE_STARTUP_TEST

static DEFINE_SPINLOCK(test_spinlock);


2011-03-08 22:42:42

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 2011-03-08 at 17:18 -0500, Steven Rostedt wrote:
> A few months ago it was suggested to have a way to enable tracepoints in
> a module when it is loaded. I tried various methods, but this one seems
> to be the least intrusive. In fact, it requires no modification to the
> module code.

I forgot to include the link to where this was brought up before:

https://lkml.org/lkml/2010/11/9/79

-- Steve

2011-03-08 23:23:05

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

* Steven Rostedt ([email protected]) wrote:
> A few months ago it was suggested to have a way to enable tracepoints in
> a module when it is loaded. I tried various methods, but this one seems
> to be the least intrusive. In fact, it requires no modification to the
> module code.
>
> The trace event now adds its own MODULE_INFO() and kernel_param_ops that
> and links the information about a tracepoint into the module's __param
> section. A module can be loaded with a tracepoint active by adding
> trace_<tracepoint>=1 as one of the parameters.

Hi Steven,

Can you walk me through the expected sequence someone wanting to enable a few
specific module tracepoints would have to go through ? I'm thinking here about
the context of a distro which has on-demand module loading. The scenario I am
thinking about is a distro specifying a basic set of tracepoints to enable in a
"standard catch-all tracing configuration", which includes some tracepoints in
yet-unloaded modules. I'm trying to figure out what the end user experience will
look like if we go for the solution you propose here.

Thanks,

Mathieu

>
> The following patch is in:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
>
> branch: rfc/trace
>
>
> Steven Rostedt (1):
> tracing: Enable tracepoints via module parameters
>
> ----
> include/linux/ftrace_event.h | 4 +++
> include/trace/ftrace.h | 22 ++++++++++++++++-
> kernel/trace/trace_events.c | 52 ++++++++++++++++++++++++++++++++++++++++++
> 3 files changed, 76 insertions(+), 2 deletions(-)
> ---------------------------
> commit b514aa1b59148994a47086cdd46db7f994b4789e
> Author: Steven Rostedt <[email protected]>
> Date: Tue Mar 8 17:06:14 2011 -0500
>
> tracing: Enable tracepoints via module parameters
>
> Add the tracepoints within the module to the module info section
> and allow the tracepoints to be enabled when the module is loaded.
>
> For example:
>
> [root]# modinfo samples/trace_events/trace-events-sample.ko
> filename: samples/trace_events/trace-events-sample.ko
> license: GPL
> description: trace-events-sample
> author: Steven Rostedt
> tracepoint: foo_bar
> srcversion: F6AC4B8D911A5C5B9CCDD7B
> depends:
> vermagic: 2.6.38-rc5+ SMP preempt mod_unload
>
> Notice that the trace-events-sample tracepoint "foo_bar" shows
> up in the modinfo. When loading the module with:
>
> # insmod trace-events-sample.ko trace_foo_bar=1
>
> The tracepoint "foo_bar" will be enabled.
>
> Cc: Yuanhan Liu <[email protected]>
> Cc: Chris Wilson <[email protected]>
> Cc: Rusty Russell <[email protected]>
> Signed-off-by: Steven Rostedt <[email protected]>
>
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index 47e3997..b672889 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -124,6 +124,8 @@ void tracing_record_cmdline(struct task_struct *tsk);
>
> struct event_filter;
>
> +extern struct kernel_param_ops ftrace_mod_ops;
> +
> enum trace_reg {
> TRACE_REG_REGISTER,
> TRACE_REG_UNREGISTER,
> @@ -155,6 +157,7 @@ enum {
> TRACE_EVENT_FL_FILTERED_BIT,
> TRACE_EVENT_FL_RECORDED_CMD_BIT,
> TRACE_EVENT_FL_CAP_ANY_BIT,
> + TRACE_EVENT_FL_MOD_ENABLE_BIT,
> };
>
> enum {
> @@ -162,6 +165,7 @@ enum {
> TRACE_EVENT_FL_FILTERED = (1 << TRACE_EVENT_FL_FILTERED_BIT),
> TRACE_EVENT_FL_RECORDED_CMD = (1 << TRACE_EVENT_FL_RECORDED_CMD_BIT),
> TRACE_EVENT_FL_CAP_ANY = (1 << TRACE_EVENT_FL_CAP_ANY_BIT),
> + TRACE_EVENT_FL_MOD_ENABLE = (1 << TRACE_EVENT_FL_MOD_ENABLE_BIT),
> };
>
> struct ftrace_event_call {
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index 3e68366..3d4a6ee 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -561,6 +561,22 @@ static inline void ftrace_test_probe_##call(void) \
> #undef __get_dynamic_array
> #undef __get_str
>
> +/*
> + * Add ftrace trace points in modules to be set by module
> + * parameters. This adds "trace_##call" as a module parameter.
> + * The user could enable trace points on module load with:
> + * trace_##call=1 as a module parameter.
> + */
> +#undef ftrace_mod_params
> +#ifdef MODULE
> +#define ftrace_mod_params(call) \
> + module_param_cb(trace_##call, &ftrace_mod_ops, \
> + &event_##call, 0644); \
> + MODULE_INFO(tracepoint, #call)
> +#else
> +#define ftrace_mod_params(call)
> +#endif
> +
> #undef TP_printk
> #define TP_printk(fmt, args...) "\"" fmt "\", " __stringify(args)
>
> @@ -588,7 +604,8 @@ static struct ftrace_event_call __used event_##call = { \
> .print_fmt = print_fmt_##template, \
> }; \
> static struct ftrace_event_call __used \
> -__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
> +__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call;\
> +ftrace_mod_params(call)
>
> #undef DEFINE_EVENT_PRINT
> #define DEFINE_EVENT_PRINT(template, call, proto, args, print) \
> @@ -602,7 +619,8 @@ static struct ftrace_event_call __used event_##call = { \
> .print_fmt = print_fmt_##call, \
> }; \
> static struct ftrace_event_call __used \
> -__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
> +__attribute__((section("_ftrace_events"))) *__event_##call = &event_##call; \
> +ftrace_mod_params(call)
>
> #include TRACE_INCLUDE(TRACE_INCLUDE_FILE)
>
> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index 5f499e0..5223751 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -1285,6 +1285,7 @@ static void trace_module_add_events(struct module *mod)
> {
> struct ftrace_module_file_ops *file_ops = NULL;
> struct ftrace_event_call **call, **start, **end;
> + int ret;
>
> start = mod->trace_events;
> end = mod->trace_events + mod->num_trace_events;
> @@ -1300,6 +1301,14 @@ static void trace_module_add_events(struct module *mod)
> __trace_add_event_call(*call, mod,
> &file_ops->id, &file_ops->enable,
> &file_ops->filter, &file_ops->format);
> + /* If the module tracepoint parameter was set */
> + if ((*call)->flags & TRACE_EVENT_FL_MOD_ENABLE) {
> + (*call)->flags = 0;
> + ret = ftrace_event_enable_disable(*call, 1);
> + if (ret < 0)
> + pr_warning("unable to enable tracepoint %s",
> + (*call)->name);
> + }
> }
> }
>
> @@ -1457,6 +1466,49 @@ static __init int event_trace_init(void)
> }
> fs_initcall(event_trace_init);
>
> +/* Allow modules to load with enabled trace points */
> +int ftrace_mod_param_set(const char *val, const struct kernel_param *kp)
> +{
> + struct ftrace_event_call *call = kp->arg;
> +
> + /* This is set like param_set_bool() */
> +
> + /* No equals means "set"... */
> + if (!val)
> + val = "1";
> +
> + /* One of =[yYnN01] */
> + switch (val[0]) {
> + case 'y': case 'Y': case '1':
> + break;
> + case 'n': case 'N': case '0':
> + /* Do nothing */
> + return 0;
> + default:
> + return -EINVAL;
> + }
> +
> + /* Set flag to tell ftrace to enable this event on init */
> + call->flags = TRACE_EVENT_FL_MOD_ENABLE;
> +
> + return 0;
> +}
> +
> +int ftrace_mod_param_get(char *buffer, const struct kernel_param *kp)
> +{
> + struct ftrace_event_call *call = kp->arg;
> +
> + return sprintf(buffer, "%d",
> + !!(call->flags &
> + (TRACE_EVENT_FL_MOD_ENABLE | TRACE_EVENT_FL_ENABLED)));
> +}
> +
> +struct kernel_param_ops ftrace_mod_ops = {
> + .set = ftrace_mod_param_set,
> + .get = ftrace_mod_param_get,
> +};
> +EXPORT_SYMBOL(ftrace_mod_ops);
> +
> #ifdef CONFIG_FTRACE_STARTUP_TEST
>
> static DEFINE_SPINLOCK(test_spinlock);
>
>

--
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com

2011-03-08 23:32:58

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 2011-03-08 at 18:22 -0500, Mathieu Desnoyers wrote:
> * Steven Rostedt ([email protected]) wrote:
> > A few months ago it was suggested to have a way to enable tracepoints in
> > a module when it is loaded. I tried various methods, but this one seems
> > to be the least intrusive. In fact, it requires no modification to the
> > module code.
> >
> > The trace event now adds its own MODULE_INFO() and kernel_param_ops that
> > and links the information about a tracepoint into the module's __param
> > section. A module can be loaded with a tracepoint active by adding
> > trace_<tracepoint>=1 as one of the parameters.
>
> Hi Steven,
>
> Can you walk me through the expected sequence someone wanting to enable a few
> specific module tracepoints would have to go through ? I'm thinking here about
> the context of a distro which has on-demand module loading. The scenario I am
> thinking about is a distro specifying a basic set of tracepoints to enable in a
> "standard catch-all tracing configuration", which includes some tracepoints in
> yet-unloaded modules. I'm trying to figure out what the end user experience will
> look like if we go for the solution you propose here.
>

You would add it like any other module parameter.

Just update it in your /etc/modprobe.d/ directory.

-- Steve

2011-03-09 00:07:57

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

* Steven Rostedt ([email protected]) wrote:
> On Tue, 2011-03-08 at 18:22 -0500, Mathieu Desnoyers wrote:
> > * Steven Rostedt ([email protected]) wrote:
> > > A few months ago it was suggested to have a way to enable tracepoints in
> > > a module when it is loaded. I tried various methods, but this one seems
> > > to be the least intrusive. In fact, it requires no modification to the
> > > module code.
> > >
> > > The trace event now adds its own MODULE_INFO() and kernel_param_ops that
> > > and links the information about a tracepoint into the module's __param
> > > section. A module can be loaded with a tracepoint active by adding
> > > trace_<tracepoint>=1 as one of the parameters.
> >
> > Hi Steven,
> >
> > Can you walk me through the expected sequence someone wanting to enable a few
> > specific module tracepoints would have to go through ? I'm thinking here about
> > the context of a distro which has on-demand module loading. The scenario I am
> > thinking about is a distro specifying a basic set of tracepoints to enable in a
> > "standard catch-all tracing configuration", which includes some tracepoints in
> > yet-unloaded modules. I'm trying to figure out what the end user experience will
> > look like if we go for the solution you propose here.
> >
>
> You would add it like any other module parameter.
>
> Just update it in your /etc/modprobe.d/ directory.

So what you are saying here is that modifying /etc/modprobe.d/ is the actual
interface you propose presenting to the end-users to control their tracepoints ?

Maybe I am missing something, but this interface seems to lack the layer of
finish we might want to put into a user-visible API. I don't really see how
distributions can hope to automate any of this for their end-user without making
a mess of the /etc/modprobe.d/ they ship with.

Thanks,

Mathieu

--
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com

2011-03-09 00:14:20

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 2011-03-08 at 19:07 -0500, Mathieu Desnoyers wrote:

> So what you are saying here is that modifying /etc/modprobe.d/ is the actual
> interface you propose presenting to the end-users to control their tracepoints ?

If you want to have them enabled on boot, sure.

> Maybe I am missing something, but this interface seems to lack the layer of
> finish we might want to put into a user-visible API. I don't really see how
> distributions can hope to automate any of this for their end-user without making
> a mess of the /etc/modprobe.d/ they ship with.

What distros enable tracepoints by default?

If you want to enable a tracepoint on module load simply do:

modprobe mymod trace_my_tracepoint=1

Otherwise modify your modprobe.d directory. This is the way users have
been doing module parameters for years.

That's pretty simple to me.

-- Steve

2011-03-09 00:29:25

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

* Steven Rostedt ([email protected]) wrote:
> On Tue, 2011-03-08 at 19:07 -0500, Mathieu Desnoyers wrote:
>
> > So what you are saying here is that modifying /etc/modprobe.d/ is the actual
> > interface you propose presenting to the end-users to control their tracepoints ?
>
> If you want to have them enabled on boot, sure.

No, I'm not talking about enabling tracepoints on boot here. Let's think about a
basic use-case: a distro packages a tracer, and provides a "default" set of
tracepoints that can be enabled when tracing is needed. Therefore, these
tracepoints are not enabled at boot -- they are rather enabled when tracing
starts. Some of these tracepoints are in dynamically loaded modules. Some of
these modules are automatically loaded by the distro (e.g. when a USB device is
plugged in).

The specific module tracepoints should therefore only be enabled when both of
the following conditions are true:

A - the end-user want to trace
B - the module is loaded

But it looks like hooking on modinfo will only let you unconditionally enable
the module tracepoints during normal system operations (even when tracing is
off), or not at all unless you previously load the module (which does not fit
with the reality of distributions automagically loading modules on demand while
tracing runs).

>
> > Maybe I am missing something, but this interface seems to lack the layer of
> > finish we might want to put into a user-visible API. I don't really see how
> > distributions can hope to automate any of this for their end-user without making
> > a mess of the /etc/modprobe.d/ they ship with.
>
> What distros enable tracepoints by default?

Do you mean enable as having a probe connected, or just CONFIG_TRACEPOINTS=y ?

>
> If you want to enable a tracepoint on module load simply do:
>
> modprobe mymod trace_my_tracepoint=1
>
> Otherwise modify your modprobe.d directory. This is the way users have
> been doing module parameters for years.
>
> That's pretty simple to me.

Everything is always so much easier when your end-user target is yourself.
What are users for anyway ? :-P

Mathieu

--
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com

2011-03-09 00:52:19

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 2011-03-08 at 19:29 -0500, Mathieu Desnoyers wrote:
> * Steven Rostedt ([email protected]) wrote:
> > On Tue, 2011-03-08 at 19:07 -0500, Mathieu Desnoyers wrote:
> >
> > > So what you are saying here is that modifying /etc/modprobe.d/ is the actual
> > > interface you propose presenting to the end-users to control their tracepoints ?
> >
> > If you want to have them enabled on boot, sure.
>
> No, I'm not talking about enabling tracepoints on boot here. Let's think about a
> basic use-case: a distro packages a tracer, and provides a "default" set of
> tracepoints that can be enabled when tracing is needed. Therefore, these
> tracepoints are not enabled at boot -- they are rather enabled when tracing
> starts. Some of these tracepoints are in dynamically loaded modules. Some of
> these modules are automatically loaded by the distro (e.g. when a USB device is
> plugged in).

What distro are we talking about? What distro provides a "default" set
of tracepoints?


>
> The specific module tracepoints should therefore only be enabled when both of
> the following conditions are true:
>
> A - the end-user want to trace
> B - the module is loaded
>
> But it looks like hooking on modinfo will only let you unconditionally enable
> the module tracepoints during normal system operations (even when tracing is
> off), or not at all unless you previously load the module (which does not fit
> with the reality of distributions automagically loading modules on demand while
> tracing runs).

Lets keep it simple please. Right now my proposal does more than what we
currently have. Perhaps we could change the enabling to only enable if
"tracing is on", or some /proc/sys/kernel/X flag is set.


> >
> > > Maybe I am missing something, but this interface seems to lack the layer of
> > > finish we might want to put into a user-visible API. I don't really see how
> > > distributions can hope to automate any of this for their end-user without making
> > > a mess of the /etc/modprobe.d/ they ship with.
> >
> > What distros enable tracepoints by default?
>
> Do you mean enable as having a probe connected, or just CONFIG_TRACEPOINTS=y ?

I mean having the probe connected as distros already have
CONFIG_TRACEPOINTS on. What was your meaning when you said "distro
specifying a basic set of tracepoints to enable"?


>
> >
> > If you want to enable a tracepoint on module load simply do:
> >
> > modprobe mymod trace_my_tracepoint=1
> >
> > Otherwise modify your modprobe.d directory. This is the way users have
> > been doing module parameters for years.
> >
> > That's pretty simple to me.
>
> Everything is always so much easier when your end-user target is yourself.
> What are users for anyway ? :-P

Users are for testing code ;)

But that's a good question. As I wrote this because I'm purging my inbox
and came across Yuanhan Liu's patch set. I'm curios to what Yuanhan's
motivation for this change was.

-- Steve

2011-03-09 01:17:21

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

* Steven Rostedt ([email protected]) wrote:
> On Tue, 2011-03-08 at 19:29 -0500, Mathieu Desnoyers wrote:
> > * Steven Rostedt ([email protected]) wrote:
> > > On Tue, 2011-03-08 at 19:07 -0500, Mathieu Desnoyers wrote:
> > >
> > > > So what you are saying here is that modifying /etc/modprobe.d/ is the actual
> > > > interface you propose presenting to the end-users to control their tracepoints ?
> > >
> > > If you want to have them enabled on boot, sure.
> >
> > No, I'm not talking about enabling tracepoints on boot here. Let's think about a
> > basic use-case: a distro packages a tracer, and provides a "default" set of
> > tracepoints that can be enabled when tracing is needed. Therefore, these
> > tracepoints are not enabled at boot -- they are rather enabled when tracing
> > starts. Some of these tracepoints are in dynamically loaded modules. Some of
> > these modules are automatically loaded by the distro (e.g. when a USB device is
> > plugged in).
>
> What distro are we talking about? What distro provides a "default" set
> of tracepoints?

I'm afraid I cannot say, at this point, which distro I am refering to, because
that would be a little forward of me to push news before official feature
announcements.

And about the "default" tracepoints, let's mainly think about tracepoints that
would be specified from a trace control application. E.g. the user wants a type
of tracing that collects all information required to solve a category of
problem, and they get enabled automatically.

> >
> > The specific module tracepoints should therefore only be enabled when both of
> > the following conditions are true:
> >
> > A - the end-user want to trace
> > B - the module is loaded
> >
> > But it looks like hooking on modinfo will only let you unconditionally enable
> > the module tracepoints during normal system operations (even when tracing is
> > off), or not at all unless you previously load the module (which does not fit
> > with the reality of distributions automagically loading modules on demand while
> > tracing runs).
>
> Lets keep it simple please. Right now my proposal does more than what we
> currently have. Perhaps we could change the enabling to only enable if
> "tracing is on", or some /proc/sys/kernel/X flag is set.

Well, thinking a little more about it, I won't be using this way of enabling
tracepoints in my tracer, so please feel free to make it as simple as you like.
I'm just providing feedback on what the ftrace/perf end user experience will
look like and, sadly, it does not look good at all by the look of this proposal.

>
>
> > >
> > > > Maybe I am missing something, but this interface seems to lack the layer of
> > > > finish we might want to put into a user-visible API. I don't really see how
> > > > distributions can hope to automate any of this for their end-user without making
> > > > a mess of the /etc/modprobe.d/ they ship with.
> > >
> > > What distros enable tracepoints by default?
> >
> > Do you mean enable as having a probe connected, or just CONFIG_TRACEPOINTS=y ?
>
> I mean having the probe connected as distros already have
> CONFIG_TRACEPOINTS on. What was your meaning when you said "distro
> specifying a basic set of tracepoints to enable"?

I meant that distros can contain packages that are interested in a specific set
of tracepoints (views/analysis are tracepoint data consumers), so they can
specify a set of tracepoints to enable when tracing is activated.

>
>
> >
> > >
> > > If you want to enable a tracepoint on module load simply do:
> > >
> > > modprobe mymod trace_my_tracepoint=1
> > >
> > > Otherwise modify your modprobe.d directory. This is the way users have
> > > been doing module parameters for years.
> > >
> > > That's pretty simple to me.
> >
> > Everything is always so much easier when your end-user target is yourself.
> > What are users for anyway ? :-P
>
> Users are for testing code ;)
>
> But that's a good question. As I wrote this because I'm purging my inbox
> and came across Yuanhan Liu's patch set. I'm curios to what Yuanhan's
> motivation for this change was.

Yep.

Hopefully my feedback can be of some use.

Thanks,

Mathieu

--
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com

2011-03-09 02:01:41

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 2011-03-08 at 20:17 -0500, Mathieu Desnoyers wrote:

> I'm afraid I cannot say, at this point, which distro I am refering to, because
> that would be a little forward of me to push news before official feature
> announcements.

Well, I guess I'm safe at saying it aint Red Hat ;)

>
> And about the "default" tracepoints, let's mainly think about tracepoints that
> would be specified from a trace control application. E.g. the user wants a type
> of tracing that collects all information required to solve a category of
> problem, and they get enabled automatically.

Well, since tracepoints can change (come and go), this tool had better
be very flexible.


> Well, thinking a little more about it, I won't be using this way of enabling
> tracepoints in my tracer, so please feel free to make it as simple as you like.
> I'm just providing feedback on what the ftrace/perf end user experience will
> look like and, sadly, it does not look good at all by the look of this proposal.

Sadly it matters what the point of this change was for. 1) this does not
affect the way perf enables/disable tracepoints. I'm sure it could
easily add a syscall interface that would keep a nice wall from the
user. 2) it was to enable tracing in ftrace as soon as a module is
loaded. Ideally from a modprobe, not boot time tracing. Although, I
probably could add something to for that too. But that would come later.


> I meant that distros can contain packages that are interested in a specific set
> of tracepoints (views/analysis are tracepoint data consumers), so they can
> specify a set of tracepoints to enable when tracing is activated.

Yep, and this patch is not aimed at that. I am interesting in things
that analyze specific data. But this patch was not something to address
that. And it could easily exist with other means that do.

> >
> > But that's a good question. As I wrote this because I'm purging my inbox
> > and came across Yuanhan Liu's patch set. I'm curios to what Yuanhan's
> > motivation for this change was.
>
> Yep.

Yep, I'm looking forward to a response. For myself, I like this patch
because there has been times I needed to enable a tracepoint as soon as
the module was loaded and not a long time afterward (which is what
happens when you do modprobe and echo by hand).

>
> Hopefully my feedback can be of some use.

For who?

-- Steve

2011-03-09 02:01:52

by Yuanhan Liu

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, Mar 08, 2011 at 07:52:04PM -0500, Steven Rostedt wrote:
> On Tue, 2011-03-08 at 19:29 -0500, Mathieu Desnoyers wrote:
> > * Steven Rostedt ([email protected]) wrote:
> > > On Tue, 2011-03-08 at 19:07 -0500, Mathieu Desnoyers wrote:

[snip]

> >
> > >
> > > If you want to enable a tracepoint on module load simply do:
> > >
> > > modprobe mymod trace_my_tracepoint=1
> > >
> > > Otherwise modify your modprobe.d directory. This is the way users have
> > > been doing module parameters for years.
> > >
> > > That's pretty simple to me.
> >
> > Everything is always so much easier when your end-user target is yourself.
> > What are users for anyway ? :-P
>
> Users are for testing code ;)

As another end-user, this looks fine (also simple) to me ;)

>
> But that's a good question. As I wrote this because I'm purging my inbox
> and came across Yuanhan Liu's patch set. I'm curios to what Yuanhan's
> motivation for this change was.

The motivation of my original patch is simple: try to not miss any trace
events. I guess it's a kind of feature that trace(or module) should
have ;)


Thanks,
Yuanhan Liu

2011-03-09 02:12:18

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Wed, 2011-03-09 at 10:01 +0800, Yuanhan Liu wrote:

> > Users are for testing code ;)
>
> As another end-user, this looks fine (also simple) to me ;)

Ah, you find this patch I have simple?

>
> >
> > But that's a good question. As I wrote this because I'm purging my inbox
> > and came across Yuanhan Liu's patch set. I'm curios to what Yuanhan's
> > motivation for this change was.
>
> The motivation of my original patch is simple: try to not miss any trace
> events. I guess it's a kind of feature that trace(or module) should
> have ;)

Hmm, I probably could add a trace option that simply tells ftrace to
enable events as modules are loaded.

Thanks!

-- Steve

2011-03-09 02:19:42

by Yuanhan Liu

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, Mar 08, 2011 at 09:12:14PM -0500, Steven Rostedt wrote:
> On Wed, 2011-03-09 at 10:01 +0800, Yuanhan Liu wrote:
>
> > > Users are for testing code ;)
> >
> > As another end-user, this looks fine (also simple) to me ;)
>
> Ah, you find this patch I have simple?

Nop, I mean the way to enable it.

>
> >
> > >
> > > But that's a good question. As I wrote this because I'm purging my inbox
> > > and came across Yuanhan Liu's patch set. I'm curios to what Yuanhan's
> > > motivation for this change was.
> >
> > The motivation of my original patch is simple: try to not miss any trace
> > events. I guess it's a kind of feature that trace(or module) should
> > have ;)
>
> Hmm, I probably could add a trace option that simply tells ftrace to
> enable events as modules are loaded.
>
> Thanks!
>
> -- Steve
>

2011-03-09 02:31:03

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

* Steven Rostedt ([email protected]) wrote:
> On Tue, 2011-03-08 at 20:17 -0500, Mathieu Desnoyers wrote:
>
> >
> > And about the "default" tracepoints, let's mainly think about tracepoints that
> > would be specified from a trace control application. E.g. the user wants a type
> > of tracing that collects all information required to solve a category of
> > problem, and they get enabled automatically.
>
> Well, since tracepoints can change (come and go), this tool had better
> be very flexible.

The idea is that a tool activates a set of tracepoints, gather trace data, and
then use the metainformation to figure out which of the tracepoints it requested
are there. If some of the tracepoints it needs are not there, it bails out.

>
>
> > Well, thinking a little more about it, I won't be using this way of enabling
> > tracepoints in my tracer, so please feel free to make it as simple as you like.
> > I'm just providing feedback on what the ftrace/perf end user experience will
> > look like and, sadly, it does not look good at all by the look of this proposal.
>
> Sadly it matters what the point of this change was for. 1) this does not
> affect the way perf enables/disable tracepoints. I'm sure it could
> easily add a syscall interface that would keep a nice wall from the
> user. 2) it was to enable tracing in ftrace as soon as a module is
> loaded. Ideally from a modprobe, not boot time tracing. Although, I
> probably could add something to for that too. But that would come later.
>
>
> > I meant that distros can contain packages that are interested in a specific set
> > of tracepoints (views/analysis are tracepoint data consumers), so they can
> > specify a set of tracepoints to enable when tracing is activated.
>
> Yep, and this patch is not aimed at that. I am interesting in things
> that analyze specific data. But this patch was not something to address
> that. And it could easily exist with other means that do.

As long as this method of enabling TRACE_EVENT probes located in modules before
these are loaded does not become the single and only one, I'm fine with it. It
makes sense for the kernel-developer use-case. Although past experience taught
me to be careful about the "we'll allow better interfaces to come later"
approach.

[...]

> >
> > Hopefully my feedback can be of some use.
>
> For who?

For who CC'd me on this thread. ;-)

Thanks,

Mathieu

--
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com

2011-03-11 03:38:03

by Rusty Russell

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 08 Mar 2011 17:18:04 -0500, Steven Rostedt <[email protected]> wrote:
> A few months ago it was suggested to have a way to enable tracepoints in
> a module when it is loaded. I tried various methods, but this one seems
> to be the least intrusive. In fact, it requires no modification to the
> module code.

This seems quite nice!

Importantly, do you like it better than the previous version? I like it
because it doesn't touch my code, but that's not a fair test.

A few minor things:
1) Can we document this somewhere more persistent too? ftrace.txt?
2) Your documentation should probably just use "trace_foo_bar" and omit
the "=1". Because we can :)
3) Can we share more with param_set_bool? Nice to have it in one place
when someone decides the kernel really needs to accept "=true" or
whatever.
4) =n should really unset the flag, so args fight correctly.

eg (wildly untested):

int ftrace_mod_param_set(const char *val, const struct kernel_param *kp)
{
struct ftrace_event_call *call = kp->arg;
struct kernel_param bool_kp;
bool set;
int err;

/* We work exactly like param_set_bool. */
bool_kp.arg = &set;
bool_kp.flags = KPARAM_ISBOOL;
err = param_set_bool(val, &bool_kp);
if (err)
return err;

/* Set flag to tell ftrace to enable this event on init */
if (set)
call->flags = TRACE_EVENT_FL_MOD_ENABLE;
else
call->flags &= ~TRACE_EVENT_FL_MOD_ENABLE;

return 0;
}

Cheers,
Rusty.

2013-08-13 15:14:47

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Fri, 11 Mar 2011 10:03:09 +1030
Rusty Russell <[email protected]> wrote:

[ Resurrection from the dead! ]

> On Tue, 08 Mar 2011 17:18:04 -0500, Steven Rostedt <[email protected]> wrote:
> > A few months ago it was suggested to have a way to enable tracepoints in
> > a module when it is loaded. I tried various methods, but this one seems
> > to be the least intrusive. In fact, it requires no modification to the
> > module code.
>
> This seems quite nice!
>
> Importantly, do you like it better than the previous version? I like it
> because it doesn't touch my code, but that's not a fair test.
>
> A few minor things:
> 1) Can we document this somewhere more persistent too? ftrace.txt?

I'll need to update this.

> 2) Your documentation should probably just use "trace_foo_bar" and omit
> the "=1". Because we can :)

And it does.

> 3) Can we share more with param_set_bool? Nice to have it in one place
> when someone decides the kernel really needs to accept "=true" or
> whatever.

I'll look into this.

> 4) =n should really unset the flag, so args fight correctly.
>
> eg (wildly untested):
>
> int ftrace_mod_param_set(const char *val, const struct kernel_param *kp)
> {
> struct ftrace_event_call *call = kp->arg;
> struct kernel_param bool_kp;
> bool set;
> int err;
>
> /* We work exactly like param_set_bool. */
> bool_kp.arg = &set;
> bool_kp.flags = KPARAM_ISBOOL;
> err = param_set_bool(val, &bool_kp);
> if (err)
> return err;
>
> /* Set flag to tell ftrace to enable this event on init */
> if (set)
> call->flags = TRACE_EVENT_FL_MOD_ENABLE;
> else
> call->flags &= ~TRACE_EVENT_FL_MOD_ENABLE;
>
> return 0;
> }

I can add this too.

But the thing about this that bothers me is that there's no way to say,
"Enable all tracepoints in this module on load". I would like a way to
do that, but I don't know of a way to do that without modifying the
module code. Have any ideas? Basically, I would love to have:

insmod foo tracepoints=all

or something and have all tracepoints enabled.

I started playing with tricks in the include/trace/ftrace.h file to
automatically create a general module parameter, but modules like KVM
include multiple trace headers which means anything I make will be
duplicated in the module and wont work.

Well, I'll go back to this original patch set (as I've been asked three
times within the last few months if there's a way to have tracepoints
enabled on module load).

-- Steve

2013-08-13 22:34:57

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

* Steven Rostedt ([email protected]) wrote:
[...]
> But the thing about this that bothers me is that there's no way to say,
> "Enable all tracepoints in this module on load". I would like a way to
> do that, but I don't know of a way to do that without modifying the
> module code. Have any ideas? Basically, I would love to have:
>
> insmod foo tracepoints=all
>
> or something and have all tracepoints enabled.

If it can help, here is a very similar scenario: tracepoints in
lttng-ust (user land) deal with dynamically loaded libraries that are
loaded at any point during program execution, which is very much similar
to the kernel module use-case discussed here.

The way a user interacts with lttng to enable, e.g. all tracepoints
within "app_component" would be:

lttng enable-event -u 'app_component:*'

Then, whenever a library containing tracepoints is loaded, the
tracepoints contained within the library are registered to lttng-ust,
and it enables all tracepoint matching the user-specified wildcard.

What I like about this approach, if applied to kernel modules, is that
it does not require users to interact with module load parameters to
specify which tracepoints should be enabled: this is all done through
the regular tracer UI, thus greatly improving user experience.

Thoughts ?

Thanks,

Mathieu

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

2013-08-13 23:10:00

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 13 Aug 2013 18:34:53 -0400
Mathieu Desnoyers <[email protected]> wrote:


> What I like about this approach, if applied to kernel modules, is that
> it does not require users to interact with module load parameters to
> specify which tracepoints should be enabled: this is all done through
> the regular tracer UI, thus greatly improving user experience.
>

I have thought about adding a file that would let you enable generic
tracepoints as they are created. Doesn't even need to be specifically
modules, but kprobes as well.

But that's agnostic to this patch. One thing I like about the patch is
that it has modinfo show you the available tracepoints in a module.

-- Steve

2013-08-15 03:23:27

by Rusty Russell

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

Steven Rostedt <[email protected]> writes:
> But the thing about this that bothers me is that there's no way to say,
> "Enable all tracepoints in this module on load". I would like a way to
> do that, but I don't know of a way to do that without modifying the
> module code. Have any ideas? Basically, I would love to have:
>
> insmod foo tracepoints=all
>
> or something and have all tracepoints enabled.

"without modifying the module code"? Why? The code isn't that scary,
and this seems useful.

Cheers,
Rusty.

2013-08-15 03:32:32

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Thu, 15 Aug 2013 11:32:10 +0930
Rusty Russell <[email protected]> wrote:

> Steven Rostedt <[email protected]> writes:
> > But the thing about this that bothers me is that there's no way to say,
> > "Enable all tracepoints in this module on load". I would like a way to
> > do that, but I don't know of a way to do that without modifying the
> > module code. Have any ideas? Basically, I would love to have:
> >
> > insmod foo tracepoints=all
> >
> > or something and have all tracepoints enabled.
>
> "without modifying the module code"? Why? The code isn't that scary,
> and this seems useful.

I'm not afraid of the code, I'm afraid of you ;-) I hear you have
killer puppies.


OK, then when I get some time, I may cook something up.

Thanks,

-- Steve

2021-04-19 21:55:52

by Dan Williams

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

[ drop Rusty, add Jessica and Emmanuel ]

On Wed, 2013-08-14 at 23:32 -0400, Steven Rostedt wrote:
> On Thu, 15 Aug 2013 11:32:10 +0930
> Rusty Russell <[email protected]> wrote:
>
> > Steven Rostedt <[email protected]> writes:
> > > But the thing about this that bothers me is that there's no way
> > > to say,
> > > "Enable all tracepoints in this module on load". I would like a
> > > way to
> > > do that, but I don't know of a way to do that without modifying
> > > the
> > > module code. Have any ideas? Basically, I would love to have:
> > >
> > > insmod foo tracepoints=all
> > >
> > > or something and have all tracepoints enabled.
> >
> > "without modifying the module code"? Why? The code isn't that
> > scary,
> > and this seems useful.
>
> I'm not afraid of the code, I'm afraid of you ;-) I hear you have
> killer puppies.
>
>
> OK, then when I get some time, I may cook something up.
>
> Thanks,
>
> -- Steve

Revive an old thread...

Steven, did you ever end up with a solution to the "enable tracing at
module load" problem?

I see some people getting admonished to use ftrace over dev_dbg() [1],
but one of the features that keeps dev_dbg() proliferating is its
generic "$mod_name.dyndbg=" module parameter support for selective
debug enabling at boot / module-load.

It would be useful to be able to do
/sys/kernel/debug/dynamic_debug/control enabling for tracepoints, but
also module::function_name patterns for "got here" style debugging. I'd
be happy to help with this, but wanted to understand where you left
things.

[1]: https://lore.kernel.org/linux-wireless/YHRFy3aq%[email protected]/

2021-04-19 22:27:47

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Mon, 19 Apr 2021 21:54:13 +0000
"Williams, Dan J" <[email protected]> wrote:

> [ drop Rusty, add Jessica and Emmanuel ]

Probably could have kept Jessica on as she's the module maintainer.

>
> On Wed, 2013-08-14 at 23:32 -0400, Steven Rostedt wrote:
> > On Thu, 15 Aug 2013 11:32:10 +0930

Wow, this is coming back from the dead! No thread rests in peace!

> > Rusty Russell <[email protected]> wrote:
> >
> > > Steven Rostedt <[email protected]> writes:
> > > > But the thing about this that bothers me is that there's no way
> > > > to say,
> > > > "Enable all tracepoints in this module on load". I would like a
> > > > way to
> > > > do that, but I don't know of a way to do that without modifying
> > > > the
> > > > module code. Have any ideas? Basically, I would love to have:
> > > >
> > > > insmod foo tracepoints=all
> > > >
> > > > or something and have all tracepoints enabled.
> > >
> > > "without modifying the module code"? Why? The code isn't that
> > > scary,
> > > and this seems useful.
> >
> > I'm not afraid of the code, I'm afraid of you ;-) I hear you have
> > killer puppies.
> >
> >
> > OK, then when I get some time, I may cook something up.


"when I get some time" HAHAHAHAHAHAH!!!! That was what? 8 years ago!

> >
> > Thanks,
> >
> > -- Steve
>
> Revive an old thread...

I'll say!

>
> Steven, did you ever end up with a solution to the "enable tracing at
> module load" problem?

For tracepoints, no. For function tracing, yes!

>
> I see some people getting admonished to use ftrace over dev_dbg() [1],
> but one of the features that keeps dev_dbg() proliferating is its
> generic "$mod_name.dyndbg=" module parameter support for selective
> debug enabling at boot / module-load.
>
> It would be useful to be able to do
> /sys/kernel/debug/dynamic_debug/control enabling for tracepoints, but
> also module::function_name patterns for "got here" style debugging. I'd
> be happy to help with this, but wanted to understand where you left
> things.
>
> [1]: https://lore.kernel.org/linux-wireless/YHRFy3aq%[email protected]/

I don't think I did anything with trace events, I'll have to dig deeper.
But today you have this:

# cd /sys/kernel/tracing

# rmmod bridge

# echo ':mod:bridge' > set_ftrace_filter

# cat set_ftrace_filter
:mod:bridge

# echo function > current_tracer

# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 0/0 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |

# modprobe bridge

# cat set_ftrace_filter
br_switchdev_event [bridge]
br_device_event [bridge]
br_net_exit [bridge]
br_boolopt_get [bridge]
br_boolopt_multi_get [bridge]
br_opt_toggle [bridge]
br_boolopt_toggle [bridge]
br_boolopt_multi_toggle [bridge]
br_dev_set_multicast_list [bridge]
br_get_link_ksettings [bridge]
[..]

# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 10/10 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
modprobe-2364 [006] .... 12929.869510: br_init <-do_one_initcall
modprobe-2364 [006] .... 12929.869513: br_fdb_init <-br_init
modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
modprobe-2364 [006] .... 12929.869523: br_device_event <-call_netdevice_register_net_notifiers
modprobe-2364 [006] .... 12929.869523: br_device_event <-call_netdevice_register_net_notifiers
modprobe-2364 [006] .... 12929.869524: br_netlink_init <-br_init
modprobe-2364 [006] .... 12929.869524: br_mdb_init <-br_netlink_init


So yes, function tracing now allows setting a filter to trace only the
functions for a given module, and if that module is not yet loaded, it
stores the filter until it is.

To do something similar for tracepoints, I think we still need to add it as
a module parameter.

-- Steve

2021-04-20 01:27:31

by Dan Williams

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Mon, Apr 19, 2021 at 3:11 PM Steven Rostedt <[email protected]> wrote:
>
> On Mon, 19 Apr 2021 21:54:13 +0000
> "Williams, Dan J" <[email protected]> wrote:
>
> > [ drop Rusty, add Jessica and Emmanuel ]
>
> Probably could have kept Jessica on as she's the module maintainer.

Oh, you misread, I swapped out Rusty for Jessica on the Cc.

>
> >
> > On Wed, 2013-08-14 at 23:32 -0400, Steven Rostedt wrote:
> > > On Thu, 15 Aug 2013 11:32:10 +0930
>
> Wow, this is coming back from the dead! No thread rests in peace!

No one can escape the all seeing eye of lore, and it makes it so easy
to reply to ancient stuff. I thought it useful to kick the zombie
because this thread is the first thing that comes up in the Google
search of:

"enable tracepoint at module load"

>
> > > Rusty Russell <[email protected]> wrote:
> > >
> > > > Steven Rostedt <[email protected]> writes:
> > > > > But the thing about this that bothers me is that there's no way
> > > > > to say,
> > > > > "Enable all tracepoints in this module on load". I would like a
> > > > > way to
> > > > > do that, but I don't know of a way to do that without modifying
> > > > > the
> > > > > module code. Have any ideas? Basically, I would love to have:
> > > > >
> > > > > insmod foo tracepoints=all
> > > > >
> > > > > or something and have all tracepoints enabled.
> > > >
> > > > "without modifying the module code"? Why? The code isn't that
> > > > scary,
> > > > and this seems useful.
> > >
> > > I'm not afraid of the code, I'm afraid of you ;-) I hear you have
> > > killer puppies.
> > >
> > >
> > > OK, then when I get some time, I may cook something up.
>
>
> "when I get some time" HAHAHAHAHAHAH!!!! That was what? 8 years ago!

free time coming up... any day now.

>
> > >
> > > Thanks,
> > >
> > > -- Steve
> >
> > Revive an old thread...
>
> I'll say!
>
> >
> > Steven, did you ever end up with a solution to the "enable tracing at
> > module load" problem?
>
> For tracepoints, no. For function tracing, yes!
>
> >
> > I see some people getting admonished to use ftrace over dev_dbg() [1],
> > but one of the features that keeps dev_dbg() proliferating is its
> > generic "$mod_name.dyndbg=" module parameter support for selective
> > debug enabling at boot / module-load.
> >
> > It would be useful to be able to do
> > /sys/kernel/debug/dynamic_debug/control enabling for tracepoints, but
> > also module::function_name patterns for "got here" style debugging. I'd
> > be happy to help with this, but wanted to understand where you left
> > things.
> >
> > [1]: https://lore.kernel.org/linux-wireless/YHRFy3aq%[email protected]/
>
> I don't think I did anything with trace events, I'll have to dig deeper.
> But today you have this:
>
> # cd /sys/kernel/tracing
>
> # rmmod bridge
>
> # echo ':mod:bridge' > set_ftrace_filter
>
> # cat set_ftrace_filter
> :mod:bridge
>
> # echo function > current_tracer
>
> # cat trace
> # tracer: function
> #
> # entries-in-buffer/entries-written: 0/0 #P:8
> #
> # _-----=> irqs-off
> # / _----=> need-resched
> # | / _---=> hardirq/softirq
> # || / _--=> preempt-depth
> # ||| / delay
> # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> # | | | |||| | |
>
> # modprobe bridge
>
> # cat set_ftrace_filter
> br_switchdev_event [bridge]
> br_device_event [bridge]
> br_net_exit [bridge]
> br_boolopt_get [bridge]
> br_boolopt_multi_get [bridge]
> br_opt_toggle [bridge]
> br_boolopt_toggle [bridge]
> br_boolopt_multi_toggle [bridge]
> br_dev_set_multicast_list [bridge]
> br_get_link_ksettings [bridge]
> [..]
>
> # cat trace
> # tracer: function
> #
> # entries-in-buffer/entries-written: 10/10 #P:8
> #
> # _-----=> irqs-off
> # / _----=> need-resched
> # | / _---=> hardirq/softirq
> # || / _--=> preempt-depth
> # ||| / delay
> # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> # | | | |||| | |
> modprobe-2364 [006] .... 12929.869510: br_init <-do_one_initcall
> modprobe-2364 [006] .... 12929.869513: br_fdb_init <-br_init
> modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2364 [006] .... 12929.869522: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2364 [006] .... 12929.869523: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2364 [006] .... 12929.869523: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2364 [006] .... 12929.869524: br_netlink_init <-br_init
> modprobe-2364 [006] .... 12929.869524: br_mdb_init <-br_netlink_init
>
>
> So yes, function tracing now allows setting a filter to trace only the
> functions for a given module, and if that module is not yet loaded, it
> stores the filter until it is.

Ah, thanks for the pointer. So if I wanted to convert a kernel command like:

libnvdimm.dyndbg

...it would be something like:

ftrace=function ftrace_filter=:mod:libnvdimm

...and then "cat /sys/kernel/tracing/trace" instead of "dmesg" to
retrieve... assuming only "got here" style debug was being attempted.

> To do something similar for tracepoints, I think we still need to add it as
> a module parameter.

The dev_dbg() filter language is attractive, it's too bad
trace_printk() has such a high runtime cost as combining dynamic-debug
and tracing would seem to be a panacea.

2021-04-20 12:57:34

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Mon, 19 Apr 2021 18:25:54 -0700
Dan Williams <[email protected]> wrote:

> On Mon, Apr 19, 2021 at 3:11 PM Steven Rostedt <[email protected]> wrote:
> >
> > On Mon, 19 Apr 2021 21:54:13 +0000
> > "Williams, Dan J" <[email protected]> wrote:
> >
> > > [ drop Rusty, add Jessica and Emmanuel ]
> >
> > Probably could have kept Jessica on as she's the module maintainer.
>
> Oh, you misread, I swapped out Rusty for Jessica on the Cc.

Ah, I read that as "Rusty and Jessica".



> > So yes, function tracing now allows setting a filter to trace only the
> > functions for a given module, and if that module is not yet loaded, it
> > stores the filter until it is.
>
> Ah, thanks for the pointer. So if I wanted to convert a kernel command like:
>
> libnvdimm.dyndbg
>
> ...it would be something like:
>
> ftrace=function ftrace_filter=:mod:libnvdimm

Hmm, that may not work, but if it doesn't, it would be trivial to add it.

>
> ...and then "cat /sys/kernel/tracing/trace" instead of "dmesg" to
> retrieve... assuming only "got here" style debug was being attempted.
>
> > To do something similar for tracepoints, I think we still need to add it as
> > a module parameter.
>
> The dev_dbg() filter language is attractive, it's too bad

Not sure what you mean by that. What filter language. Tracepoints do have a
pretty good filtering too.


> trace_printk() has such a high runtime cost as combining dynamic-debug
> and tracing would seem to be a panacea.

trace_printk() has a high runtime cost? Besides that it's not allowed on
production code (see nasty banner), it is made to be extremely fast.
Although, it does do sprintf() work.

Would adding automatic module parameters be an issue? That is, you can add
in the insmod command line a parameter that will enable tracepoints. We
could have a way to even see them from the modinfo. I think I had that
working once, and it wasn't really that hard to do.

-- Steve

2021-04-20 13:30:48

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

----- On Apr 20, 2021, at 8:55 AM, rostedt [email protected] wrote:
[...]
>
> Would adding automatic module parameters be an issue? That is, you can add
> in the insmod command line a parameter that will enable tracepoints. We
> could have a way to even see them from the modinfo. I think I had that
> working once, and it wasn't really that hard to do.

There is one thing we should consider here in terms of namespacing: those module
command line parameters should be specific to each tracer (e.g. ftrace, perf, ebpf).

LTTng for instance already tackles early module load tracing in a different
way: users can enable instrumentation of yet-to-be loaded kernel modules. So
it would not make sense in that scheme to have module load parameters.

It's a different trade-off in terms of error reporting though: for instance,
LTTng won't report an error if a user does a typo when entering an event name.

So I think those command line parameters should be tracer-specific, do you agree ?

Thanks,

Mathieu

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

2021-04-20 14:58:36

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 20 Apr 2021 09:29:27 -0400 (EDT)
Mathieu Desnoyers <[email protected]> wrote:

> ----- On Apr 20, 2021, at 8:55 AM, rostedt [email protected] wrote:
> [...]
> >
> > Would adding automatic module parameters be an issue? That is, you can add
> > in the insmod command line a parameter that will enable tracepoints. We
> > could have a way to even see them from the modinfo. I think I had that
> > working once, and it wasn't really that hard to do.
>
> There is one thing we should consider here in terms of namespacing: those module
> command line parameters should be specific to each tracer (e.g. ftrace, perf, ebpf).
>
> LTTng for instance already tackles early module load tracing in a different
> way: users can enable instrumentation of yet-to-be loaded kernel modules. So
> it would not make sense in that scheme to have module load parameters.
>
> It's a different trade-off in terms of error reporting though: for instance,
> LTTng won't report an error if a user does a typo when entering an event name.
>
> So I think those command line parameters should be tracer-specific, do you agree ?


No, I do not agree. I would like to make it consistent with the kernel
command line. As you can put in: "trace_event=sched_switch" and the
sched_switch trace point will be enable (for the tracefs directory) on boot
up. The same should be for modules as well.

It shouldn't affect LTTng, as you already have a way to enable them as they
get loaded.

-- Steve

2021-04-20 15:16:09

by Mathieu Desnoyers

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

----- On Apr 20, 2021, at 10:55 AM, rostedt [email protected] wrote:

> On Tue, 20 Apr 2021 09:29:27 -0400 (EDT)
> Mathieu Desnoyers <[email protected]> wrote:
>
>> ----- On Apr 20, 2021, at 8:55 AM, rostedt [email protected] wrote:
>> [...]
>> >
>> > Would adding automatic module parameters be an issue? That is, you can add
>> > in the insmod command line a parameter that will enable tracepoints. We
>> > could have a way to even see them from the modinfo. I think I had that
>> > working once, and it wasn't really that hard to do.
>>
>> There is one thing we should consider here in terms of namespacing: those module
>> command line parameters should be specific to each tracer (e.g. ftrace, perf,
>> ebpf).
>>
>> LTTng for instance already tackles early module load tracing in a different
>> way: users can enable instrumentation of yet-to-be loaded kernel modules. So
>> it would not make sense in that scheme to have module load parameters.
>>
>> It's a different trade-off in terms of error reporting though: for instance,
>> LTTng won't report an error if a user does a typo when entering an event name.
>>
>> So I think those command line parameters should be tracer-specific, do you agree
>> ?
>
>
> No, I do not agree. I would like to make it consistent with the kernel
> command line. As you can put in: "trace_event=sched_switch" and the
> sched_switch trace point will be enable (for the tracefs directory) on boot
> up. The same should be for modules as well.
>
> It shouldn't affect LTTng, as you already have a way to enable them as they
> get loaded.

That sounds fine. So that would be within the "trace_event" (and not tracepoint)
namespace for module load parameters as well ?

Thanks,

Mathieu

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

2021-04-20 15:38:42

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 20 Apr 2021 11:15:10 -0400 (EDT)
Mathieu Desnoyers <[email protected]> wrote:

> That sounds fine. So that would be within the "trace_event" (and not tracepoint)
> namespace for module load parameters as well ?

Right, it would be "trace_event=...." not "tracepoint=..."

-- Steve

2021-04-20 19:57:52

by Dan Williams

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, Apr 20, 2021 at 5:55 AM Steven Rostedt <[email protected]> wrote:
[..]
> > > So yes, function tracing now allows setting a filter to trace only the
> > > functions for a given module, and if that module is not yet loaded, it
> > > stores the filter until it is.
> >
> > Ah, thanks for the pointer. So if I wanted to convert a kernel command like:
> >
> > libnvdimm.dyndbg
> >
> > ...it would be something like:
> >
> > ftrace=function ftrace_filter=:mod:libnvdimm
>
> Hmm, that may not work, but if it doesn't, it would be trivial to add it.
>
> >
> > ...and then "cat /sys/kernel/tracing/trace" instead of "dmesg" to
> > retrieve... assuming only "got here" style debug was being attempted.
> >
> > > To do something similar for tracepoints, I think we still need to add it as
> > > a module parameter.
> >
> > The dev_dbg() filter language is attractive, it's too bad
>
> Not sure what you mean by that. What filter language. Tracepoints do have a
> pretty good filtering too.

I'm trying to replicate dev_dbg() usability with tracing. So, when
people say "don't use dev_dbg() for that" that tracing can reliably
replace everything that dev_dbg() was offering. What I think that
looks like is the ability to turn on function tracing by a function
name glob in addition to any tracepoints in those same functions all
from the kernel boot command line, or a module parameter.

> > trace_printk() has such a high runtime cost as combining dynamic-debug
> > and tracing would seem to be a panacea.
>
> trace_printk() has a high runtime cost? Besides that it's not allowed on
> production code (see nasty banner), it is made to be extremely fast.
> Although, it does do sprintf() work.

I was referring to the banner. dev_dbg() does not have that production
code restriction.

> Would adding automatic module parameters be an issue? That is, you can add
> in the insmod command line a parameter that will enable tracepoints. We
> could have a way to even see them from the modinfo. I think I had that
> working once, and it wasn't really that hard to do.

Yeah, that's what you seemed to have working at the beginning of this thread:

https://lore.kernel.org/lkml/[email protected]/

2021-04-20 20:34:06

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, 20 Apr 2021 12:54:39 -0700
Dan Williams <[email protected]> wrote:

> On Tue, Apr 20, 2021 at 5:55 AM Steven Rostedt <[email protected]> wrote:
> > >
> > > The dev_dbg() filter language is attractive, it's too bad
> >
> > Not sure what you mean by that. What filter language. Tracepoints do have a
> > pretty good filtering too.
>
> I'm trying to replicate dev_dbg() usability with tracing. So, when
> people say "don't use dev_dbg() for that" that tracing can reliably
> replace everything that dev_dbg() was offering. What I think that
> looks like is the ability to turn on function tracing by a function
> name glob in addition to any tracepoints in those same functions all
> from the kernel boot command line, or a module parameter.

You can enable functions on the kernel command line in globs (and trace
events as well). And if the kernel command line doesn't work properly (it's
not as tested as the run time side is), it should be trivial to fix it.


>
> > > trace_printk() has such a high runtime cost as combining dynamic-debug
> > > and tracing would seem to be a panacea.
> >
> > trace_printk() has a high runtime cost? Besides that it's not allowed on
> > production code (see nasty banner), it is made to be extremely fast.
> > Although, it does do sprintf() work.
>
> I was referring to the banner. dev_dbg() does not have that production
> code restriction.

You can have a tracepoint like trace_printk that doesn't give a banner.
Basically, the reason trace_printk() has that restriction is because you
can't filter it like you can trace events. It's similar to a printk(). If I
had allowed trace_printk() in the kernel, it would be all over the place,
and it would just add a bunch of noise to the trace output, because its
either on or off. And if you have trace_printk() and so would all other
systems, and then you would deal with trace_printk()s from everyone which
could drown out the ones you want. Hence, I added that banner to keep that
from happening. trace_printk() will even drown out events. (I hate it when
I leave one in my debug kernel, and it adds a bunch of noise against what
I'm trying to debug with events!).

But you can add your own trace point, and even make it generic. That's what
bpf did for their bpf_trace_printk. You could convert dev_dbg() into a
tracepoint!


static __printf(2, 3) int __dev_dbg(const struct device *dev, char *fmt, ...)
{
static char buf[DEV_DEBUG_PRINTK_SIZE];
unsigned long flags;
va_list ap;
int ret;

raw_spin_lock_irqsave(&dev_dbg_printk_lock, flags);
va_start(ap, fmt);
ret = vsnprintf(buf, sizeof(buf), fmt, ap);
va_end(ap);
/* vsnprintf() will not append null for zero-length strings */
if (ret == 0)
buf[0] = '\0';
trace_dev_dbg_printk(dev, buf);
raw_spin_unlock_irqrestore(&dev_dbg_printk_lock, flags);

return ret;
}

#define dev_dbg(dev, fmt, ...) \
do { \
if (trace_dev_dbg_printk_enabled()) \
__dev_dbg(dev, fmt, ##__VA_ARGS__); \
} while (0)

Note, the "trace_dev_dbg_printk_enabled()" is a static branch, which means
it is a nop when the dev_dbg_printk tracepoint is not enabled, and is a jmp
to the __dev_dbg() logic when it is enabled. It's not a conditional branch.

And have:

TRACE_EVENT(dev_dbg_printk,

TP_PROTO(const struct device *dev, const char *dbg_str),

TP_ARGS(dev, dbg_str),

TP_STRUCT__entry(
__field(const struct device *dev)
__string(dev_name, dev_name(dev))
__string(dbg_str, dbg_str)
),

TP_fast_assign(
__entry->dev = dev;
__assign_str(dev_name, dev_name(dev))
__assign_str(dbg_str, dbg_str);
),

TP_printk("%p dev=%s %s", __entry->dev, __get_string(dev_name), __get_str(dbg_str))
);

And then you could even filter on the device name, or even parts of the
string, as you can filter events, and even have them have glob matches.

>
> > Would adding automatic module parameters be an issue? That is, you can add
> > in the insmod command line a parameter that will enable tracepoints. We
> > could have a way to even see them from the modinfo. I think I had that
> > working once, and it wasn't really that hard to do.
>
> Yeah, that's what you seemed to have working at the beginning of this thread:
>
> https://lore.kernel.org/lkml/[email protected]/

Yeah, and I should brush that off and resubmit ;-)

-- Steve

2021-04-21 06:36:23

by Dan Williams

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Tue, Apr 20, 2021 at 1:33 PM Steven Rostedt <[email protected]> wrote:
>
> On Tue, 20 Apr 2021 12:54:39 -0700
> Dan Williams <[email protected]> wrote:
>
> > On Tue, Apr 20, 2021 at 5:55 AM Steven Rostedt <[email protected]> wrote:
> > > >
> > > > The dev_dbg() filter language is attractive, it's too bad
> > >
> > > Not sure what you mean by that. What filter language. Tracepoints do have a
> > > pretty good filtering too.
> >
> > I'm trying to replicate dev_dbg() usability with tracing. So, when
> > people say "don't use dev_dbg() for that" that tracing can reliably
> > replace everything that dev_dbg() was offering. What I think that
> > looks like is the ability to turn on function tracing by a function
> > name glob in addition to any tracepoints in those same functions all
> > from the kernel boot command line, or a module parameter.
>
> You can enable functions on the kernel command line in globs (and trace
> events as well). And if the kernel command line doesn't work properly (it's
> not as tested as the run time side is), it should be trivial to fix it.
>
>
> >
> > > > trace_printk() has such a high runtime cost as combining dynamic-debug
> > > > and tracing would seem to be a panacea.
> > >
> > > trace_printk() has a high runtime cost? Besides that it's not allowed on
> > > production code (see nasty banner), it is made to be extremely fast.
> > > Although, it does do sprintf() work.
> >
> > I was referring to the banner. dev_dbg() does not have that production
> > code restriction.
>
> You can have a tracepoint like trace_printk that doesn't give a banner.
> Basically, the reason trace_printk() has that restriction is because you
> can't filter it like you can trace events. It's similar to a printk(). If I
> had allowed trace_printk() in the kernel, it would be all over the place,
> and it would just add a bunch of noise to the trace output, because its
> either on or off. And if you have trace_printk() and so would all other
> systems, and then you would deal with trace_printk()s from everyone which
> could drown out the ones you want. Hence, I added that banner to keep that
> from happening. trace_printk() will even drown out events. (I hate it when
> I leave one in my debug kernel, and it adds a bunch of noise against what
> I'm trying to debug with events!).
>
> But you can add your own trace point, and even make it generic. That's what
> bpf did for their bpf_trace_printk. You could convert dev_dbg() into a
> tracepoint!
>
>
> static __printf(2, 3) int __dev_dbg(const struct device *dev, char *fmt, ...)
> {
> static char buf[DEV_DEBUG_PRINTK_SIZE];
> unsigned long flags;
> va_list ap;
> int ret;
>
> raw_spin_lock_irqsave(&dev_dbg_printk_lock, flags);
> va_start(ap, fmt);
> ret = vsnprintf(buf, sizeof(buf), fmt, ap);
> va_end(ap);
> /* vsnprintf() will not append null for zero-length strings */
> if (ret == 0)
> buf[0] = '\0';
> trace_dev_dbg_printk(dev, buf);
> raw_spin_unlock_irqrestore(&dev_dbg_printk_lock, flags);
>
> return ret;
> }
>
> #define dev_dbg(dev, fmt, ...) \
> do { \
> if (trace_dev_dbg_printk_enabled()) \
> __dev_dbg(dev, fmt, ##__VA_ARGS__); \
> } while (0)
>
> Note, the "trace_dev_dbg_printk_enabled()" is a static branch, which means
> it is a nop when the dev_dbg_printk tracepoint is not enabled, and is a jmp
> to the __dev_dbg() logic when it is enabled. It's not a conditional branch.
>
> And have:
>
> TRACE_EVENT(dev_dbg_printk,
>
> TP_PROTO(const struct device *dev, const char *dbg_str),
>
> TP_ARGS(dev, dbg_str),
>
> TP_STRUCT__entry(
> __field(const struct device *dev)
> __string(dev_name, dev_name(dev))
> __string(dbg_str, dbg_str)
> ),
>
> TP_fast_assign(
> __entry->dev = dev;
> __assign_str(dev_name, dev_name(dev))
> __assign_str(dbg_str, dbg_str);
> ),
>
> TP_printk("%p dev=%s %s", __entry->dev, __get_string(dev_name), __get_str(dbg_str))
> );
>
> And then you could even filter on the device name, or even parts of the
> string, as you can filter events, and even have them have glob matches.

Oooh, I might run with this, it's been on my backlog to go investigate
and you just threw out a solution. Imagine being able to to specify
't' instead of 'p' for a given debug print so that dev_dbg() users can
move from console to trace buffer, but also tracing users have access
to more tracepoints that happen to appear at useful dev_dbg()
locations.

Thanks, Steven!

2021-04-21 09:51:12

by Rasmus Villemoes

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On 20/04/2021 22.32, Steven Rostedt wrote:
> On Tue, 20 Apr 2021 12:54:39 -0700
> Dan Williams <[email protected]> wrote:
>
>> On Tue, Apr 20, 2021 at 5:55 AM Steven Rostedt <[email protected]> wrote:
>>>>
>>>> The dev_dbg() filter language is attractive, it's too bad
>>>
>>> Not sure what you mean by that. What filter language. Tracepoints do have a
>>> pretty good filtering too.
>>

> But you can add your own trace point, and even make it generic. That's what
> bpf did for their bpf_trace_printk. You could convert dev_dbg() into a
> tracepoint!
>
>
> static __printf(2, 3) int __dev_dbg(const struct device *dev, char *fmt, ...)
> {
> static char buf[DEV_DEBUG_PRINTK_SIZE];
> unsigned long flags;
> va_list ap;
> int ret;
>
> raw_spin_lock_irqsave(&dev_dbg_printk_lock, flags);
> va_start(ap, fmt);
> ret = vsnprintf(buf, sizeof(buf), fmt, ap);
> va_end(ap);
> /* vsnprintf() will not append null for zero-length strings */
> if (ret == 0)
> buf[0] = '\0';

Wrong. snprintf(buf, 16, "") will work just fine and cause a '\0' to be
written to buf[0]. As will snprintf(buf, 16, "%s", ""), and any other
case where there ends up being no characters printed.

The only case where snprintf does not guarantee nul-termination is when
the _buffer size_ is 0, in which case vsnprintf obviously cannot and
must not write anything at all (that's used for the "how much do I need
to allocate" situation).

>
> #define dev_dbg(dev, fmt, ...) \
> do { \
> if (trace_dev_dbg_printk_enabled()) \
> __dev_dbg(dev, fmt, ##__VA_ARGS__); \
> } while (0)
>
> Note, the "trace_dev_dbg_printk_enabled()" is a static branch, which means
> it is a nop when the dev_dbg_printk tracepoint is not enabled, and is a jmp
> to the __dev_dbg() logic when it is enabled. It's not a conditional branch.

dynamic_debug has been implemented in terms of static_keys for a long
time. And that's a per-dev_dbg invocation static key. IIUC, the above
would cause every single dev_dbg in the kernel to pass through the "grab
a raw spin lock and do the snprintf" thing even when one is just
interested in the dev_dbgs inside a single driver or function.

Rasmus

2021-04-21 19:05:55

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Wed, 21 Apr 2021 09:30:01 +0200
Rasmus Villemoes <[email protected]> wrote:

> On 20/04/2021 22.32, Steven Rostedt wrote:
> > On Tue, 20 Apr 2021 12:54:39 -0700
> > Dan Williams <[email protected]> wrote:
> >
> >> On Tue, Apr 20, 2021 at 5:55 AM Steven Rostedt <[email protected]> wrote:
> >>>>
> >>>> The dev_dbg() filter language is attractive, it's too bad
> >>>
> >>> Not sure what you mean by that. What filter language. Tracepoints do have a
> >>> pretty good filtering too.
> >>
>
> > But you can add your own trace point, and even make it generic. That's what
> > bpf did for their bpf_trace_printk. You could convert dev_dbg() into a
> > tracepoint!
> >
> >
> > static __printf(2, 3) int __dev_dbg(const struct device *dev, char *fmt, ...)
> > {
> > static char buf[DEV_DEBUG_PRINTK_SIZE];
> > unsigned long flags;
> > va_list ap;
> > int ret;
> >
> > raw_spin_lock_irqsave(&dev_dbg_printk_lock, flags);
> > va_start(ap, fmt);
> > ret = vsnprintf(buf, sizeof(buf), fmt, ap);
> > va_end(ap);
> > /* vsnprintf() will not append null for zero-length strings */
> > if (ret == 0)
> > buf[0] = '\0';
>
> Wrong. snprintf(buf, 16, "") will work just fine and cause a '\0' to be
> written to buf[0]. As will snprintf(buf, 16, "%s", ""), and any other
> case where there ends up being no characters printed.

I just cut and pasted the bpf_trace_printk() code and modified it for here.

https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/kernel/trace/bpf_trace.c#n404


>
> The only case where snprintf does not guarantee nul-termination is when
> the _buffer size_ is 0, in which case vsnprintf obviously cannot and
> must not write anything at all (that's used for the "how much do I need
> to allocate" situation).
>
> >
> > #define dev_dbg(dev, fmt, ...) \
> > do { \
> > if (trace_dev_dbg_printk_enabled()) \
> > __dev_dbg(dev, fmt, ##__VA_ARGS__); \
> > } while (0)
> >
> > Note, the "trace_dev_dbg_printk_enabled()" is a static branch, which means
> > it is a nop when the dev_dbg_printk tracepoint is not enabled, and is a jmp
> > to the __dev_dbg() logic when it is enabled. It's not a conditional branch.
>
> dynamic_debug has been implemented in terms of static_keys for a long
> time. And that's a per-dev_dbg invocation static key. IIUC, the above
> would cause every single dev_dbg in the kernel to pass through the "grab
> a raw spin lock and do the snprintf" thing even when one is just
> interested in the dev_dbgs inside a single driver or function.

If you want to make it per device, I'm sure three's a way. Or allocate a
per-cpu buffer for the sprintf storage, and then you only need to disable
interrupts. And if you make the storage 4 levels deep per CPU (like
trace_printk does), then you only need to disable preemption and not even
interrupts.

The above wasn't a patch submission. It was a proof of concept. Everything
you brought up can be trivially dealt with.

-- Steve

2021-04-21 20:39:45

by Rasmus Villemoes

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On 21/04/2021 16.20, Steven Rostedt wrote:
> On Wed, 21 Apr 2021 09:30:01 +0200
> Rasmus Villemoes <[email protected]> wrote:
>
>> On 20/04/2021 22.32, Steven Rostedt wrote:
>>> /* vsnprintf() will not append null for zero-length strings */
>>> if (ret == 0)
>>> buf[0] = '\0';
>>
>> Wrong. snprintf(buf, 16, "") will work just fine and cause a '\0' to be
>> written to buf[0]. As will snprintf(buf, 16, "%s", ""), and any other
>> case where there ends up being no characters printed.
>
> I just cut and pasted the bpf_trace_printk() code and modified it for here.

OK, thanks for the pointer, lemme go write a patch to remove that
bogosity before it gets cargo-culted further.

> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/kernel/trace/bpf_trace.c#n404
>
>>>
>>> #define dev_dbg(dev, fmt, ...) \
>>> do { \
>>> if (trace_dev_dbg_printk_enabled()) \
>>> __dev_dbg(dev, fmt, ##__VA_ARGS__); \
>>> } while (0)
>>>
>>> Note, the "trace_dev_dbg_printk_enabled()" is a static branch, which means
>>> it is a nop when the dev_dbg_printk tracepoint is not enabled, and is a jmp
>>> to the __dev_dbg() logic when it is enabled. It's not a conditional branch.
>>
>> dynamic_debug has been implemented in terms of static_keys for a long
>> time. And that's a per-dev_dbg invocation static key. IIUC, the above
>> would cause every single dev_dbg in the kernel to pass through the "grab
>> a raw spin lock and do the snprintf" thing even when one is just
>> interested in the dev_dbgs inside a single driver or function.
>
> If you want to make it per device, I'm sure three's a way. Or allocate a
> per-cpu buffer for the sprintf storage, and then you only need to disable
> interrupts. And if you make the storage 4 levels deep per CPU (like
> trace_printk does), then you only need to disable preemption and not even
> interrupts.
>
> The above wasn't a patch submission. It was a proof of concept. Everything
> you brought up can be trivially dealt with.

I don't "want" anything. I just fail to see what advantage that proof of
concept would bring over the current dev_dbg implementation.

Rasmus

2021-04-21 22:32:20

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters

On Wed, 21 Apr 2021 16:50:30 +0200
Rasmus Villemoes <[email protected]> wrote:

> I don't "want" anything. I just fail to see what advantage that proof of
> concept would bring over the current dev_dbg implementation.

That you don't need to go through the console. The trace ring buffer is
much faster than printk (you can record millions of traces a second,
and barely notice the overhead, which is why you can trace scheduling and
high frequency interrupts), and if you want, you get your very own buffer
to record to, without any noise from anything else, with features like
filtering, histograms, stack traces, etc.

The tracing infrastructure has a lot more to offer than printk does.

-- Steve