Re: [PATCH v2 10/15] dyndbg: add open and close commands for trace

From: Łukasz Bartosik
Date: Sun Dec 17 2023 - 20:07:40 EST


sob., 16 gru 2023 o 07:17 <jim.cromie@xxxxxxxxx> napisał(a):
>
> ** entering the bikeshed **
>
> On Thu, Nov 30, 2023 at 4:41 PM Łukasz Bartosik <lb@xxxxxxxxxxxx> wrote:
> >
> > Add open and close commands for opening and closing trace instances.
> > The open command has to be mandatory followed by a trace instance name.
> > If a trace instance already exists in <debugfs>/tracing/instances
> > directory then the open command will reuse it otherwise a new trace
> > instance with a name provided to the open will be created. Close
> > command closes previously opened trace instance. The close will
> > fail if a user tries to close non-existent trace instances or an
> > instance which was not previously opened.
> >
> > For example the following command will open (create or reuse existing)
> > trace instance located in <debugfs>/tracing/instances/usbcore:
> >
> > echo "open usbcore" > <debugfs>/dynamic_debug/control
> >
> > Signed-off-by: Łukasz Bartosik <lb@xxxxxxxxxxxx>
> > ---
> > lib/Kconfig.debug | 1 +
> > lib/dynamic_debug.c | 193 ++++++++++++++++++++++++++++++++++++++++++++
> > 2 files changed, 194 insertions(+)
> >
> > diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
> > index 5bc56c7247a2..f184c3c91ba3 100644
> > --- a/lib/Kconfig.debug
> > +++ b/lib/Kconfig.debug
> > @@ -181,6 +181,7 @@ config DYNAMIC_DEBUG_CORE
> > bool "Enable core function of dynamic debug support"
> > depends on PRINTK
> > depends on (DEBUG_FS || PROC_FS)
> > + depends on TRACING
> > help
> > Enable core functional support of dynamic debug. It is useful
> > when you want to tie dynamic debug to your kernel modules with
> > diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> > index 0dc9ec76b867..43e94023a4eb 100644
> > --- a/lib/dynamic_debug.c
> > +++ b/lib/dynamic_debug.c
> > @@ -36,6 +36,7 @@
> > #include <linux/sched.h>
> > #include <linux/device.h>
> > #include <linux/netdevice.h>
> > +#include <linux/trace.h>
> >
> > #define CREATE_TRACE_POINTS
> > #include <trace/events/dyndbg.h>
> > @@ -73,6 +74,25 @@ struct flag_settings {
> > unsigned int mask;
> > };
> >
> > +#define DD_OPEN_CMD "open"
> > +#define DD_CLOSE_CMD "close"
> > +#define DD_TR_EVENT "0"
> > +
> > +struct ddebug_trace_inst {
> > + const char *name;
> > + struct trace_array *arr;
> > +};
>
> can we bikeshed the struct name here ?
> inst is not a great abbreviation, its hard to say,
> and tends to look like a spelling error.
>
> _tr_ appearing later on in function names isnt great either.
>

Would like me to replace all _tr_ with _trace_ ? Or do you other
suggestion to names ?

> dd_private_tracebuf ??
>

I will change the name

> I could get used to EVENT for the global tracebuf,
> but I dont find it entirely natural.
> Is it a convention in any way ?
>
> FWIW, I chose "class" as synonymous with (modelled after)
> drm's category, but spelled different (and shorter)
>
>
>
> > +
> > +/*
> > + * TRACE_DST_MAX value is reserved for writing
> > + * debug logs to trace events (prdbg, devdbg)
> > + */
> > +struct ddebug_trace {
> > + struct ddebug_trace_inst inst[TRACE_DST_MAX-1];
> > + DECLARE_BITMAP(bmap, TRACE_DST_MAX-1);
> > + int bmap_size;
> > +};
>
> some kind of tbl in the name ?
> struct _ddebug_info contains descriptors and classes,
> struct dd_tracebuf_tbl_info ??

Ack

> (maybe not, but hopefully it prompts better)
>
> Also, since it touches on the 0 as EVENTS global trace-buf,
> does it simplify if we just waste index 0 in the inst[] array,
> and change MAX to LAST ?
> Or is it too much magic in 0 this way ?
>

Wasting index 0 might work. I will verify if there are no major
obstacles and will change if nothing pops up.

> > +
> > static DEFINE_MUTEX(ddebug_lock);
> > static LIST_HEAD(ddebug_tables);
> > static int verbose;
> > @@ -80,6 +100,8 @@ module_param(verbose, int, 0644);
> > MODULE_PARM_DESC(verbose, " dynamic_debug/control processing "
> > "( 0 = off (default), 1 = module add/rm, 2 = >control summary, 3 = parsing, 4 = per-site changes)");
> >
> > +static struct ddebug_trace tr = { .bmap_size = TRACE_DST_MAX-1 };
>
> cryptic name.
> it does appear ~20x in kernel/trace/trace_events.c
> usually as trace_array_put(tr)
>
> trc_tbl ?
>

Ack

> and where is the map itself established ?
>

DECLARE_BITMAP(bmap, TRACE_DST_MAX-1); in struct ddebug_trace

> > +
> > static inline struct dd_ctrl *get_ctrl(struct _ddebug *desc)
> > {
> > return &desc->ctrl;
> > @@ -171,6 +193,148 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
> > query->first_lineno, query->last_lineno, query->class_string);
> > }
> >
> > +static bool is_ddebug_cmd(const char *str)
>
> is_dd_trace_cmd()
>

Ack

> > +{
> > + if (!strcmp(str, DD_OPEN_CMD) ||
> > + !strcmp(str, DD_CLOSE_CMD))
>
> single line < 80 chr ?
>

Ack

> > + return true;
> > +
> > + return false;
> > +}
> > +
> > +static bool validate_tr_name(const char *str)
>
> something less procedural sounding, and more is-ok?
> dd_good_trace_name ?
>

Ack

> > +{
> > + /* "0" is reserved for writing debug logs to trace events (prdbg, devdbg) */
> > + if (!strcmp(str, DD_TR_EVENT))
> > + return false;
> > +
> > + /* we allow trace instance names to include ^\w+ and underscore */
> > + while (*str != '\0') {
> > + if (!isalnum(*str) && *str != '_')
> > + return false;
> > + str++;
> > + }
> > +
> > + return true;
> > +}
> > +
> > +static int find_tr_instance(const char *name)
>
> is this finding a slot ?

This function finds index of trace instance which was previously
"opened" (with open command)

> not that slot is meaningful, but instance is at risk of overuse.
>

What is your suggestion for a function name ?

> > +{
> > + int idx;
> > +
> > + for_each_set_bit(idx, tr.bmap, tr.bmap_size)
> > + if (!strcmp(tr.inst[idx].name, name))
> > + return idx;
> > +
> > + return -ENOENT;
> > +}
> > +
> > +static int handle_tr_opend_cmd(const char *arg)
>
> handle_open_?trace_cmd or handle_trace_?open_cmd ?
>

I will change to handle_trace_open_cmd

> > +{
> > + struct ddebug_trace_inst *inst;
> > + int idx, ret = 0;
> > +
> > + mutex_lock(&ddebug_lock);
> > +
> > + idx = find_first_zero_bit(tr.bmap, tr.bmap_size);
> > + if (idx == tr.bmap_size) {
> > + ret = -ENOSPC;
> > + goto end;
> > + }
> > +
> > + if (!validate_tr_name(arg)) {
> > + pr_err("invalid instance name:%s\n", arg);
> > + ret = -EINVAL;
> > + goto end;
> > + }
> > +
> > + if (find_tr_instance(arg) >= 0) {
> > + pr_err("instance is already opened name:%s\n ", arg);
> > + ret = -EEXIST;
> > + goto end;
> > + }
> > +
> > + inst = &tr.inst[idx];
> > + inst->name = kstrdup(arg, GFP_KERNEL);
> > + if (!inst->name) {
> > + ret = -ENOMEM;
> > + goto end;
> > + }
> > +
> > + inst->arr = trace_array_get_by_name(inst->name);
> > + if (!inst->arr) {
>
> any advice (pr_notice) worth giving if this happens ?

I will add

> conversely, does this get need a corresponding put ?
> yes - I see it in the close-cmd-handler
> if so, can we check the inst->arr before (re-)calling get-by-name ?
>

The open/close commands make sure that we won't call trace_array_get_by_name
on the same trace instance again before it is closed. The open command
will fail if it is called again for already opened instance.
The open command increases reference count of the instance and close
command decrements it.
Checking inst->arr without holding its reference would be risky.

> Or does doing this tie up the instance,
> blocking the user from deleting it ?
>

Function trace_array_get_by_name also increases reference count of a
given trace instance
which prohibits a user from deleting it.

> > + ret = -EINVAL;
> > + goto end;trace_array_get_by_name
> > + }
> > +
> > + ret = trace_array_init_printk(inst->arr);
> > + if (ret) {
> > + trace_array_put(inst->arr);
> > + trace_array_destroy(inst->arr);
> > + goto end;
> > + }
> > +
> > + set_bit(idx, tr.bmap);
> > + v3pr_info("opened trace instance idx=%d, name=%s\n", idx, arg);
> > +end:
> > + mutex_unlock(&ddebug_lock);
> > + return ret;
> > +}
> > +
> > +static int handle_tr_close_cmd(const char *arg)
> > +{
> > + struct ddebug_trace_inst *inst;
> > + int idx, ret = 0;
> > +
> > + mutex_lock(&ddebug_lock);
> > +
> > + idx = find_tr_instance(arg);
> > + if (idx < 0) {
> > + ret = idx;
> > + goto end;
> > + }
> > +
> > + inst = &tr.inst[idx];
> > +
> > + trace_array_put(inst->arr);
> > + /*
> > + * don't destroy trace instance but let user do it manually
> > + * with rmdir command at a convenient time later, if it is
> > + * destroyed here all debug logs will be lost
> > + *
>
> aha. thx for this comment. it clarifies something I asked somewhere
>

;)

> > + * trace_array_destroy(inst->arr);
> > + */
> > + inst->arr = NULL;
> > +
> > + kfree(inst->name);
> > + inst->name = NULL;
> > +
> > + clear_bit(idx, tr.bmap);
> > + v3pr_info("closed trace instance idx=%d, name=%s\n", idx, arg);
> > +end:
> > + mutex_unlock(&ddebug_lock);
> > + return ret;
> > +}
> > +
> > +static int ddebug_parse_cmd(char *words[], int nwords)
> > +{
> > + int ret;
> > +
> > + if (nwords != 1)
> > + return -EINVAL;
> > +
> > + if (!strcmp(words[0], DD_OPEN_CMD))
> > + ret = handle_tr_opend_cmd(words[1]);
>
> just return handle_() ?
> and drop following else
>

Ack

> > + else if (!strcmp(words[0], DD_CLOSE_CMD))
> > + ret = handle_tr_close_cmd(words[1]);
> > + else {
> > + pr_err("invalid command %s\n", words[0]);
> > + ret = -EINVAL;
>
> just return here.
>

Ack

Thanks,
Lukasz


> > +}
> > +
> > static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table const *dt,
> > const char *class_string, int *class_id)
> > {
> > @@ -567,6 +731,11 @@ static int ddebug_exec_query(char *query_string, const char *modname)
> > pr_err("tokenize failed\n");
> > return -EINVAL;
> > }
> > +
> > + /* check for open, close commands */
> > + if (is_ddebug_cmd(words[0]))
> > + return ddebug_parse_cmd(words, nwords-1);
> > +
> > /* check flags 1st (last arg) so query is pairs of spec,val */
> > if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
> > pr_err("flags parse failed\n");
> > @@ -1191,6 +1360,20 @@ static struct _ddebug *ddebug_iter_next(struct ddebug_iter *iter)
> > return &iter->table->ddebugs[iter->idx];
> > }
> >
> > +/*
> > + * Check if the iterator points to the last _ddebug object
> > + * to traverse.
> > + */
> > +static bool ddebug_iter_is_last(struct ddebug_iter *iter)
> > +{
> > + if (iter->table == NULL)
> > + return false;
> > + if (iter->idx-1 < 0 &&
> > + list_is_last(&iter->table->link, &ddebug_tables))
> > + return true;
> > + return false;
> > +}
> > +
> > /*
> > * Seq_ops start method. Called at the start of every
> > * read() call from userspace. Takes the ddebug_lock and
> > @@ -1281,6 +1464,16 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> > }
> > seq_puts(m, "\n");
> >
> > + if (ddebug_iter_is_last(iter) &&
> > + !bitmap_empty(tr.bmap, tr.bmap_size)) {
> > + int idx;
> > +
> > + seq_puts(m, "\n");
> > + seq_puts(m, "Opened trace instances:\n");
> > + for_each_set_bit(idx, tr.bmap, tr.bmap_size)
> > + seq_printf(m, "%s\n", tr.inst[idx].name);
> > + }
> > +
> > return 0;
> > }
> >
> > --
> > 2.43.0.rc2.451.g8631bc7472-goog
> >