Patchset starts with 7 "cleanups";
- it changes section name from vague "__verbose" to "__dyndbg"
- cleaner docs, drop obsolete comment & useless debug prints, refine
verbosity, fix a BUG_ON, ram reporting miscounts.
It adds a few query parsing conveniences;
accept combined file:line & file:func forms
file inode.c:100-200 # file & line-range
file inode.c:start_* # file & function
Then it expands flags:
Adds 'u' user flag, allowing user to compose an arbitrary set of
callsites by marking them with 'u', without altering current
print-modifying flags.
Adds 'PFMLTU' flags, which negate their lower-case counterparts.
Extends flags-spec with filter-flags, which select callsites for
modification based upon their current flags. This lets user activate
the set of callsites marked with 'u' in a batch.
echo 'u+p' > control
This was previously submitted before events overtook.
v1: https://lkml.org/lkml/2019/10/29/989
v2: https://lkml.org/lkml/2019/11/27/547
Jim Cromie (16):
cleanups:
dyndbg-docs: eschew file /full/path query in docs
dyndbg: drop obsolete comment on ddebug_proc_open
dyndbg: refine debug verbosity
dyndbg: rename __verbose section to __dyndbg
dyndbg: fix overcounting of ram used by dyndbg
dyndbg: fix a BUG_ON in ddebug_describe_flags
dyndbg: make ddebug_tables list LIFO for add/remove_module
new features:
-parsing conveniences
dyndbg: refactor parse_linerange out of ddebug_parse_query
dyndbg: accept 'file foo.c:func1' and 'file foo.c:10-100'
-flags extensions
--internal rework
dyndbg: refactor ddebug_read_flags out of ddebug_parse_flags
dyndbg: combine flags & mask into a struct, use that
dyndbg: add filter parameter to ddebug_parse_flags
dyndbg: extend ddebug_parse_flags to accept optional filter-flags
dyndbg: prefer declarative init in caller, to memset in callee
--expose the features
dyndbg: add user-flag, negating-flags, and filtering on flags
dyndbg: allow negating flag-chars in modflags
.../admin-guide/dynamic-debug-howto.rst | 75 +++--
include/asm-generic/vmlinux.lds.h | 6 +-
include/linux/dynamic_debug.h | 5 +-
kernel/module.c | 2 +-
lib/dynamic_debug.c | 282 ++++++++++--------
5 files changed, 225 insertions(+), 145 deletions(-)
--
2.26.2
Accept these additional query forms:
echo "file $filestr +_" > control
path/to/file.c:100 # as from control, column 1
path/to/file.c:1-100 # or any legal line-range
path/to/file.c:func_A # as from an editor/browser
path/to/file.c:drm_\* # wildcards still work
path/to/file.c:*_foo # lead wildcard too
1st 2 examples are treated as line-ranges, 3,4 are treated as func's
Doc these changes, and sprinkle in a few extra wild-card examples and
trailing # explanation texts.
Signed-off-by: Jim Cromie <[email protected]>
---
.../admin-guide/dynamic-debug-howto.rst | 5 +++++
lib/dynamic_debug.c | 20 ++++++++++++++++++-
2 files changed, 24 insertions(+), 1 deletion(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 2854d418b31b..880d33d1782f 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -159,6 +159,7 @@ func
of each callsite. Example::
func svc_tcp_accept
+ func *recv* # in rfcomm, bluetooth, ping, tcp
file
The given string is compared against either the src-root relative
@@ -167,6 +168,9 @@ file
file svcsock.c
file kernel/freezer.c # ie column 1 of control file
+ file drivers/usb/* # all callsites under it
+ file inode.c:start_* # parse :tail as a func (above)
+ file inode.c:1-100 # parse :tail as a line-range (above)
module
The given string is compared against the module name
@@ -176,6 +180,7 @@ module
module sunrpc
module nfsd
+ module drm* # both drm, drm_kms_helper
format
The given string is searched for in the dynamic debug format
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index d43bc3547d3a..8f250c67acbe 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -321,6 +321,8 @@ static int parse_linerange(struct ddebug_query *query, const char *first)
} else {
query->last_lineno = query->first_lineno;
}
+ vpr_info("parsed line %d-%d\n", query->first_lineno,
+ query->last_lineno);
return 0;
}
@@ -357,6 +359,7 @@ static int ddebug_parse_query(char *words[], int nwords,
{
unsigned int i;
int rc = 0;
+ char *fline;
/* check we have an even number of words */
if (nwords % 2 != 0) {
@@ -373,7 +376,22 @@ static int ddebug_parse_query(char *words[], int nwords,
if (!strcmp(words[i], "func")) {
rc = check_set(&query->function, words[i+1], "func");
} else if (!strcmp(words[i], "file")) {
- rc = check_set(&query->filename, words[i+1], "file");
+ if (check_set(&query->filename, words[i+1], "file"))
+ return -EINVAL;
+
+ /* tail :$info is function or line-range */
+ fline = strchr(query->filename, ':');
+ if (!fline)
+ break;
+ *fline++ = '\0';
+ if (isalpha(*fline) || *fline == '*' || *fline == '?') {
+ /* take as function name */
+ if (check_set(&query->function, fline, "func"))
+ return -EINVAL;
+ } else
+ if (parse_linerange(query, fline))
+ return -EINVAL;
+
} else if (!strcmp(words[i], "module")) {
rc = check_set(&query->module, words[i+1], "module");
} else if (!strcmp(words[i], "format")) {
--
2.26.2
make the code-block reusable to later handle "file foo.c:101-200" etc.
This should be a 90%+ code-move, with minimal adaptations; reindent,
and scafolding.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 61 +++++++++++++++++++++++++--------------------
1 file changed, 34 insertions(+), 27 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 494856c04fa7..d43bc3547d3a 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -291,6 +291,39 @@ static inline int parse_lineno(const char *str, unsigned int *val)
return 0;
}
+static int parse_linerange(struct ddebug_query *query, const char *first)
+{
+ char *last = strchr(first, '-');
+
+ if (query->first_lineno || query->last_lineno) {
+ pr_err("match-spec: line used 2x\n");
+ return -EINVAL;
+ }
+ if (last)
+ *last++ = '\0';
+ if (parse_lineno(first, &query->first_lineno) < 0)
+ return -EINVAL;
+ if (last) {
+ /* range <first>-<last> */
+ if (parse_lineno(last, &query->last_lineno) < 0)
+ return -EINVAL;
+
+ /* special case for last lineno not specified */
+ if (query->last_lineno == 0)
+ query->last_lineno = UINT_MAX;
+
+ if (query->last_lineno < query->first_lineno) {
+ pr_err("last-line:%d < 1st-line:%d\n",
+ query->last_lineno,
+ query->first_lineno);
+ return -EINVAL;
+ }
+ } else {
+ query->last_lineno = query->first_lineno;
+ }
+ return 0;
+}
+
static int check_set(const char **dest, char *src, char *name)
{
int rc = 0;
@@ -349,34 +382,8 @@ static int ddebug_parse_query(char *words[], int nwords,
UNESCAPE_SPECIAL);
rc = check_set(&query->format, words[i+1], "format");
} else if (!strcmp(words[i], "line")) {
- char *first = words[i+1];
- char *last = strchr(first, '-');
- if (query->first_lineno || query->last_lineno) {
- pr_err("match-spec: line used 2x\n");
- return -EINVAL;
- }
- if (last)
- *last++ = '\0';
- if (parse_lineno(first, &query->first_lineno) < 0)
+ if (parse_linerange(query, words[i+1]))
return -EINVAL;
- if (last) {
- /* range <first>-<last> */
- if (parse_lineno(last, &query->last_lineno) < 0)
- return -EINVAL;
-
- /* special case for last lineno not specified */
- if (query->last_lineno == 0)
- query->last_lineno = UINT_MAX;
-
- if (query->last_lineno < query->first_lineno) {
- pr_err("last-line:%d < 1st-line:%d\n",
- query->last_lineno,
- query->first_lineno);
- return -EINVAL;
- }
- } else {
- query->last_lineno = query->first_lineno;
- }
} else {
pr_err("unknown keyword \"%s\"\n", words[i]);
return -EINVAL;
--
2.26.2
Currently, ddebug_parse_flags accepts [+-=][pflmt_]+ as flag-spec
strings. If we allow [pflmt_]*[+-=][pflmt_]+ instead, the (new) 1st
flagset can be used as a filter to select callsites, before applying
changes in the 2nd flagset. 1st step is to split out the flags-reader
so we can use it again.
The point of this is to allow user to compose an arbitrary set of
changes, by marking callsites with [fmlt] flags, and then to
activate that composed set in a single query.
#> echo '=_' > control # clear all flags
#> echo 'module usb* +fmlt' > control # build the marked set, repeat
#> echo 'fmlt+p' > control # activate
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 37 +++++++++++++++++++++++--------------
1 file changed, 23 insertions(+), 14 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 8f250c67acbe..005b8221a9d6 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -413,6 +413,26 @@ static int ddebug_parse_query(char *words[], int nwords,
return 0;
}
+static int ddebug_read_flags(const char *str, unsigned int *flags)
+{
+ int i;
+
+ for (; *str ; ++str) {
+ for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
+ if (*str == opt_array[i].opt_char) {
+ *flags |= opt_array[i].flag;
+ break;
+ }
+ }
+ if (i < 0) {
+ pr_err("unknown flag '%c' in \"%s\"\n", *str, str);
+ return -EINVAL;
+ }
+ }
+ vpr_info("flags=0x%x\n", *flags);
+ return 0;
+}
+
/*
* Parse `str' as a flags specification, format [-+=][p]+.
* Sets up *maskp and *flagsp to be used when changing the
@@ -423,7 +443,7 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
unsigned int *maskp)
{
unsigned flags = 0;
- int op = '=', i;
+ int op;
switch (*str) {
case '+':
@@ -437,19 +457,8 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
}
vpr_info("op='%c'\n", op);
- for (; *str ; ++str) {
- for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
- if (*str == opt_array[i].opt_char) {
- flags |= opt_array[i].flag;
- break;
- }
- }
- if (i < 0) {
- pr_err("unknown flag '%c' in \"%s\"\n", *str, str);
- return -EINVAL;
- }
- }
- vpr_info("flags=0x%x\n", flags);
+ if (ddebug_read_flags(str, &flags))
+ return -EINVAL;
/* calculate final *flagsp, *maskp according to mask and op */
switch (op) {
--
2.26.2
The verbose/debug logging done for `cat $MNT/dynamic_debug/control` is
voluminous (2 per control file entry + 2 per PAGE). Moreover, it just
prints pointer and sequence, which is not useful to a dyndbg user.
So just drop them.
Also require verbose>=2 for several other debug printks that are a bit
too chatty for typical needs;
ddebug_change() prints changes, once per modified callsite. Since
queries like "+p" will enable ~2300 callsites in a typical laptop, a
user probably doesnt need to see them often. ddebug_exec_queries()
still summarizes with verbose=1.
ddebug_(add|remove)_module() also print 1 line per action on a module,
not needed by typical modprobe user.
This leaves verbose=1 better focussed on the >control parsing process.
Signed-off-by: Jim Cromie <[email protected]>
---
lib/dynamic_debug.c | 21 ++++++++-------------
1 file changed, 8 insertions(+), 13 deletions(-)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index b877774dba96..5900c043e979 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -105,12 +105,15 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
return buf;
}
-#define vpr_info(fmt, ...) \
+#define vnpr_info(lvl, fmt, ...) \
do { \
- if (verbose) \
+ if (verbose >= lvl) \
pr_info(fmt, ##__VA_ARGS__); \
} while (0)
+#define vpr_info(fmt, ...) vnpr_info(1, fmt, ##__VA_ARGS__)
+#define v2pr_info(fmt, ...) vnpr_info(2, fmt, ##__VA_ARGS__)
+
static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
{
/* trim any trailing newlines */
@@ -198,7 +201,7 @@ static int ddebug_change(const struct ddebug_query *query,
static_branch_enable(&dp->key.dd_key_true);
#endif
dp->flags = newflags;
- vpr_info("changed %s:%d [%s]%s =%s\n",
+ v2pr_info("changed %s:%d [%s]%s =%s\n",
trim_prefix(dp->filename), dp->lineno,
dt->mod_name, dp->function,
ddebug_describe_flags(dp, flagbuf,
@@ -771,8 +774,6 @@ static void *ddebug_proc_start(struct seq_file *m, loff_t *pos)
struct _ddebug *dp;
int n = *pos;
- vpr_info("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);
-
mutex_lock(&ddebug_lock);
if (!n)
@@ -795,9 +796,6 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)
struct ddebug_iter *iter = m->private;
struct _ddebug *dp;
- vpr_info("called m=%p p=%p *pos=%lld\n",
- m, p, (unsigned long long)*pos);
-
if (p == SEQ_START_TOKEN)
dp = ddebug_iter_first(iter);
else
@@ -818,8 +816,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
struct _ddebug *dp = p;
char flagsbuf[10];
- vpr_info("called m=%p p=%p\n", m, p);
-
if (p == SEQ_START_TOKEN) {
seq_puts(m,
"# filename:lineno [module]function flags format\n");
@@ -842,7 +838,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
*/
static void ddebug_proc_stop(struct seq_file *m, void *p)
{
- vpr_info("called m=%p p=%p\n", m, p);
mutex_unlock(&ddebug_lock);
}
@@ -905,7 +900,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
list_add_tail(&dt->link, &ddebug_tables);
mutex_unlock(&ddebug_lock);
- vpr_info("%u debug prints in module %s\n", n, dt->mod_name);
+ v2pr_info("%u debug prints in module %s\n", n, dt->mod_name);
return 0;
}
@@ -964,7 +959,7 @@ int ddebug_remove_module(const char *mod_name)
struct ddebug_table *dt, *nextdt;
int ret = -ENOENT;
- vpr_info("removing module \"%s\"\n", mod_name);
+ v2pr_info("removing module \"%s\"\n", mod_name);
mutex_lock(&ddebug_lock);
list_for_each_entry_safe(dt, nextdt, &ddebug_tables, link) {
--
2.26.2
Extend flags modifications to allow [PFMLTU] negating flags.
This allows control-queries like:
#> Q () { echo file inode.c $* > control } # to type less
#> Q -P # same as +p
#> Q +U # same as -u
#> Q u-P # same as u+p
This allows flags in a callsite to be simultaneously set and cleared,
while still starting with the current flagstate (with +- ops).
Generally, you chose -p or +p 1st, then set or clear flags
accordingly.
Signed-off-by: Jim Cromie <[email protected]>
---
Documentation/admin-guide/dynamic-debug-howto.rst | 10 ++++++----
lib/dynamic_debug.c | 6 ++++--
2 files changed, 10 insertions(+), 6 deletions(-)
diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index 26a19f511afa..45470c9f0dad 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -252,9 +252,11 @@ only callsites with ``u`` and ``f`` cleared.
Flagsets cannot contain ``pP`` etc, a flag cannot be true and false.
-modflags containing upper-case flags is reserved/undefined for now.
-inverted-flags are currently ignored, usage gets trickier if given
-``-pXy``, it should leave x set.
+modflags may contain upper-case flags also, using these lets you
+invert the flag setting implied by the OP; '-pU' means disable
+printing, and mark that callsite with the user-flag to create a group,
+for optional further manipulation. Generally, '+p' and '-p' is your
+main choice, and use of negating flags in modflags is rare.
Notes::
@@ -264,7 +266,7 @@ For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only
For display, the flags are preceded by ``=``
(mnemonic: what the flags are currently equal to).
-Note the regexp ``^[-+=][flmptu_]+$`` matches a flags specification.
+Note the regexp ``/^[-+=][flmptu_]+$/i`` matches a flags specification.
To clear all flags at once, use ``=_`` or ``-flmptu``.
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index ee92e93cf23d..63ae6f77a0e4 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -485,15 +485,17 @@ static int ddebug_parse_flags(const char *str,
/* calculate final mods: flags, mask based upon op */
switch (op) {
+ unsigned int tmp;
case '=':
mods->mask = 0;
break;
case '+':
- mods->mask = ~0U;
+ mods->mask = ~mods->mask;
break;
case '-':
+ tmp = mods->mask;
mods->mask = ~mods->flags;
- mods->flags = 0;
+ mods->flags = tmp;
break;
}
--
2.26.2
On Fri, Jun 05, 2020 at 10:26:32AM -0600, Jim Cromie wrote:
> The verbose/debug logging done for `cat $MNT/dynamic_debug/control` is
> voluminous (2 per control file entry + 2 per PAGE). Moreover, it just
> prints pointer and sequence, which is not useful to a dyndbg user.
> So just drop them.
I'd assumed these messages where to help the dyndbg implementer rather
than the dyndbg user. If the verbose messages really are useful to help
users who (mis)configure .../control then should the enable/disable
control be shadowed in debugfs to make it easy to find?
Daniel.
>
> Also require verbose>=2 for several other debug printks that are a bit
> too chatty for typical needs;
>
> ddebug_change() prints changes, once per modified callsite. Since
> queries like "+p" will enable ~2300 callsites in a typical laptop, a
> user probably doesnt need to see them often. ddebug_exec_queries()
> still summarizes with verbose=1.
>
> ddebug_(add|remove)_module() also print 1 line per action on a module,
> not needed by typical modprobe user.
>
> This leaves verbose=1 better focussed on the >control parsing process.
>
> Signed-off-by: Jim Cromie <[email protected]>
> ---
> lib/dynamic_debug.c | 21 ++++++++-------------
> 1 file changed, 8 insertions(+), 13 deletions(-)
>
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index b877774dba96..5900c043e979 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -105,12 +105,15 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
> return buf;
> }
>
> -#define vpr_info(fmt, ...) \
> +#define vnpr_info(lvl, fmt, ...) \
> do { \
> - if (verbose) \
> + if (verbose >= lvl) \
> pr_info(fmt, ##__VA_ARGS__); \
> } while (0)
>
> +#define vpr_info(fmt, ...) vnpr_info(1, fmt, ##__VA_ARGS__)
> +#define v2pr_info(fmt, ...) vnpr_info(2, fmt, ##__VA_ARGS__)
> +
> static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
> {
> /* trim any trailing newlines */
> @@ -198,7 +201,7 @@ static int ddebug_change(const struct ddebug_query *query,
> static_branch_enable(&dp->key.dd_key_true);
> #endif
> dp->flags = newflags;
> - vpr_info("changed %s:%d [%s]%s =%s\n",
> + v2pr_info("changed %s:%d [%s]%s =%s\n",
> trim_prefix(dp->filename), dp->lineno,
> dt->mod_name, dp->function,
> ddebug_describe_flags(dp, flagbuf,
> @@ -771,8 +774,6 @@ static void *ddebug_proc_start(struct seq_file *m, loff_t *pos)
> struct _ddebug *dp;
> int n = *pos;
>
> - vpr_info("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);
> -
> mutex_lock(&ddebug_lock);
>
> if (!n)
> @@ -795,9 +796,6 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)
> struct ddebug_iter *iter = m->private;
> struct _ddebug *dp;
>
> - vpr_info("called m=%p p=%p *pos=%lld\n",
> - m, p, (unsigned long long)*pos);
> -
> if (p == SEQ_START_TOKEN)
> dp = ddebug_iter_first(iter);
> else
> @@ -818,8 +816,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> struct _ddebug *dp = p;
> char flagsbuf[10];
>
> - vpr_info("called m=%p p=%p\n", m, p);
> -
> if (p == SEQ_START_TOKEN) {
> seq_puts(m,
> "# filename:lineno [module]function flags format\n");
> @@ -842,7 +838,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> */
> static void ddebug_proc_stop(struct seq_file *m, void *p)
> {
> - vpr_info("called m=%p p=%p\n", m, p);
> mutex_unlock(&ddebug_lock);
> }
>
> @@ -905,7 +900,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
> list_add_tail(&dt->link, &ddebug_tables);
> mutex_unlock(&ddebug_lock);
>
> - vpr_info("%u debug prints in module %s\n", n, dt->mod_name);
> + v2pr_info("%u debug prints in module %s\n", n, dt->mod_name);
> return 0;
> }
>
> @@ -964,7 +959,7 @@ int ddebug_remove_module(const char *mod_name)
> struct ddebug_table *dt, *nextdt;
> int ret = -ENOENT;
>
> - vpr_info("removing module \"%s\"\n", mod_name);
> + v2pr_info("removing module \"%s\"\n", mod_name);
>
> mutex_lock(&ddebug_lock);
> list_for_each_entry_safe(dt, nextdt, &ddebug_tables, link) {
> --
> 2.26.2
>
On Mon, Jun 8, 2020 at 5:21 AM Daniel Thompson
<[email protected]> wrote:
>
> On Fri, Jun 05, 2020 at 10:26:32AM -0600, Jim Cromie wrote:
> > The verbose/debug logging done for `cat $MNT/dynamic_debug/control` is
> > voluminous (2 per control file entry + 2 per PAGE). Moreover, it just
> > prints pointer and sequence, which is not useful to a dyndbg user.
> > So just drop them.
>
> I'd assumed these messages where to help the dyndbg implementer rather
> than the dyndbg user.
So I thought I was guilty of adding those noisy pr_info()s in the
ddebug_proc_* functions,
but I have touched them, changing them to vpr_info().
In any case, I dont think theyre useful to the implementer either.
If the verbose messages really are useful to help
> users who (mis)configure .../control then should the enable/disable
> control be shadowed in debugfs to make it easy to find?
>
I would hesitate to change the API, even if this is just an add-on,
without changes to existing.
OTOH, I could see it added as /proc/dynamic_debug/verbose
with this patch, verbose=1 is better focused on showing the parsing process,
to give user more context as to what his query-command is doing
verbose=2 additionally shows callsites that match the query, including
any unchanged (iirc)
>
> Daniel.
>
> >
> > Also require verbose>=2 for several other debug printks that are a bit
> > too chatty for typical needs;
> >
> > ddebug_change() prints changes, once per modified callsite. Since
> > queries like "+p" will enable ~2300 callsites in a typical laptop, a
> > user probably doesnt need to see them often. ddebug_exec_queries()
> > still summarizes with verbose=1.
> >
> > ddebug_(add|remove)_module() also print 1 line per action on a module,
> > not needed by typical modprobe user.
> >
> > This leaves verbose=1 better focussed on the >control parsing process.
> >
> > Signed-off-by: Jim Cromie <[email protected]>
> > ---
On Tue, Jun 09, 2020 at 01:59:41PM -0600, [email protected] wrote:
> On Mon, Jun 8, 2020 at 5:21 AM Daniel Thompson
> <[email protected]> wrote:
> >
> > On Fri, Jun 05, 2020 at 10:26:32AM -0600, Jim Cromie wrote:
> > > The verbose/debug logging done for `cat $MNT/dynamic_debug/control` is
> > > voluminous (2 per control file entry + 2 per PAGE). Moreover, it just
> > > prints pointer and sequence, which is not useful to a dyndbg user.
> > > So just drop them.
> >
> > I'd assumed these messages where to help the dyndbg implementer rather
> > than the dyndbg user.
>
> So I thought I was guilty of adding those noisy pr_info()s in the
> ddebug_proc_* functions,
> but I have touched them, changing them to vpr_info().
> In any case, I dont think theyre useful to the implementer either.
>
> If the verbose messages really are useful to help
> > users who (mis)configure .../control then should the enable/disable
> > control be shadowed in debugfs to make it easy to find?
> >
>
> I would hesitate to change the API, even if this is just an add-on,
> without changes to existing.
> OTOH, I could see it added as /proc/dynamic_debug/verbose
/proc ?
I was assuming that if the verbose output of dynamic debug is useful to
the person trying to *use* dynamic_debug then it should be in
/sys/kernel/debug/dynamic_debug/verbose .
If they are only likely useful to the person trying to *implement*
dynamic_debug itself (or to check that the infrastructure is not broken)
then there is no reason to add them to debugfs.
> with this patch, verbose=1 is better focused on showing the parsing process,
> to give user more context as to what his query-command is doing
> verbose=2 additionally shows callsites that match the query, including
> any unchanged (iirc)
I'm still a little confused by what benefit having two levels of
verbosity really is. Why does a user need to turn on verbose mode to
figure out what is happening? Why isn't reading back
.../dynamic_debug/control (perhaps using grep and friends) sufficient?
Daniel.
On Wed, Jun 10, 2020 at 5:16 AM Daniel Thompson
<[email protected]> wrote:
>
> On Tue, Jun 09, 2020 at 01:59:41PM -0600, [email protected] wrote:
> > On Mon, Jun 8, 2020 at 5:21 AM Daniel Thompson
> > <[email protected]> wrote:
> > >
> > > On Fri, Jun 05, 2020 at 10:26:32AM -0600, Jim Cromie wrote:
> > > > The verbose/debug logging done for `cat $MNT/dynamic_debug/control` is
> > > > voluminous (2 per control file entry + 2 per PAGE). Moreover, it just
> > > > prints pointer and sequence, which is not useful to a dyndbg user.
> > > > So just drop them.
> > >
> > > I'd assumed these messages where to help the dyndbg implementer rather
> > > than the dyndbg user.
> >
> > So I thought I was guilty of adding those noisy pr_info()s in the
> > ddebug_proc_* functions,
> > but I have touched them, changing them to vpr_info().
> > In any case, I dont think theyre useful to the implementer either.
> >
> > If the verbose messages really are useful to help
> > > users who (mis)configure .../control then should the enable/disable
> > > control be shadowed in debugfs to make it easy to find?
> > >
> >
> > I would hesitate to change the API, even if this is just an add-on,
> > without changes to existing.
> > OTOH, I could see it added as /proc/dynamic_debug/verbose
>
> /proc ?
>
> I was assuming that if the verbose output of dynamic debug is useful to
> the person trying to *use* dynamic_debug then it should be in
> /sys/kernel/debug/dynamic_debug/verbose .
You are correct.
/proc/dynamic_debug/control does exist, so that debugfs isnt required,
but not verbose. I conflated them while typing.
so, if debugfs isnt present, neither is dynamic_debug/verbose,
and run-time verbosity changes arent possible
but dynamic_debug.verbose=1 still works as boot arg
(I believe, I havent built an non-debugfs kernel myself)
>
> If they are only likely useful to the person trying to *implement*
> dynamic_debug itself (or to check that the infrastructure is not broken)
> then there is no reason to add them to debugfs.
>
>
> > with this patch, verbose=1 is better focused on showing the parsing process,
> > to give user more context as to what his query-command is doing
> > verbose=2 additionally shows callsites that match the query, including
> > any unchanged (iirc)
>
> I'm still a little confused by what benefit having two levels of
> verbosity really is. Why does a user need to turn on verbose mode to
> figure out what is happening? Why isn't reading back
> .../dynamic_debug/control (perhaps using grep and friends) sufficient?
>
verbose=2 prints quite a bit more,
during boot, 290 lines vs 16.
After you see it a dozen times, you dont need it anymore.
but I think its still worth keeping
It also is more chatty about callsites changed by ` echo $querycmd > control `
`cat control` shows complete callsite & flagstate,
it cant also show how commands are processed & changes are applied.
>
> Daniel.
On 6/5/20 12:26 PM, Jim Cromie wrote:
> Accept these additional query forms:
>
> echo "file $filestr +_" > control
>
> path/to/file.c:100 # as from control, column 1
> path/to/file.c:1-100 # or any legal line-range
> path/to/file.c:func_A # as from an editor/browser
> path/to/file.c:drm_\* # wildcards still work
> path/to/file.c:*_foo # lead wildcard too
>
> 1st 2 examples are treated as line-ranges, 3,4 are treated as func's
>
> Doc these changes, and sprinkle in a few extra wild-card examples and
> trailing # explanation texts.
>
> Signed-off-by: Jim Cromie <[email protected]>
> ---
> .../admin-guide/dynamic-debug-howto.rst | 5 +++++
> lib/dynamic_debug.c | 20 ++++++++++++++++++-
> 2 files changed, 24 insertions(+), 1 deletion(-)
>
> diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
> index 2854d418b31b..880d33d1782f 100644
> --- a/Documentation/admin-guide/dynamic-debug-howto.rst
> +++ b/Documentation/admin-guide/dynamic-debug-howto.rst
> @@ -159,6 +159,7 @@ func
> of each callsite. Example::
>
> func svc_tcp_accept
> + func *recv* # in rfcomm, bluetooth, ping, tcp
>
> file
> The given string is compared against either the src-root relative
> @@ -167,6 +168,9 @@ file
>
> file svcsock.c
> file kernel/freezer.c # ie column 1 of control file
> + file drivers/usb/* # all callsites under it
> + file inode.c:start_* # parse :tail as a func (above)
> + file inode.c:1-100 # parse :tail as a line-range (above)
>
> module
> The given string is compared against the module name
> @@ -176,6 +180,7 @@ module
>
> module sunrpc
> module nfsd
> + module drm* # both drm, drm_kms_helper
>
> format
> The given string is searched for in the dynamic debug format
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index d43bc3547d3a..8f250c67acbe 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -321,6 +321,8 @@ static int parse_linerange(struct ddebug_query *query, const char *first)
> } else {
> query->last_lineno = query->first_lineno;
> }
> + vpr_info("parsed line %d-%d\n", query->first_lineno,
> + query->last_lineno);
> return 0;
> }
>
> @@ -357,6 +359,7 @@ static int ddebug_parse_query(char *words[], int nwords,
> {
> unsigned int i;
> int rc = 0;
> + char *fline;
>
> /* check we have an even number of words */
> if (nwords % 2 != 0) {
> @@ -373,7 +376,22 @@ static int ddebug_parse_query(char *words[], int nwords,
> if (!strcmp(words[i], "func")) {
> rc = check_set(&query->function, words[i+1], "func");
> } else if (!strcmp(words[i], "file")) {
> - rc = check_set(&query->filename, words[i+1], "file");
> + if (check_set(&query->filename, words[i+1], "file"))
> + return -EINVAL;
> +
> + /* tail :$info is function or line-range */
> + fline = strchr(query->filename, ':');
> + if (!fline)
> + break;
> + *fline++ = '\0';
> + if (isalpha(*fline) || *fline == '*' || *fline == '?') {
> + /* take as function name */
> + if (check_set(&query->function, fline, "func"))
> + return -EINVAL;
> + } else
> + if (parse_linerange(query, fline))
> + return -EINVAL;
> +
coding style here is to use braces for both branches.
> } else if (!strcmp(words[i], "module")) {
> rc = check_set(&query->module, words[i+1], "module");
> } else if (!strcmp(words[i], "format")) {
>
On 6/5/20 12:26 PM, Jim Cromie wrote:
> Patchset starts with 7 "cleanups";
> - it changes section name from vague "__verbose" to "__dyndbg"
> - cleaner docs, drop obsolete comment & useless debug prints, refine
> verbosity, fix a BUG_ON, ram reporting miscounts.
>
> It adds a few query parsing conveniences;
> accept combined file:line & file:func forms
>
> file inode.c:100-200 # file & line-range
> file inode.c:start_* # file & function
>
So I like the shortened notation there.
> Then it expands flags:
>
> Adds 'u' user flag, allowing user to compose an arbitrary set of
> callsites by marking them with 'u', without altering current
> print-modifying flags.
>
> Adds 'PFMLTU' flags, which negate their lower-case counterparts.
>
> Extends flags-spec with filter-flags, which select callsites for
> modification based upon their current flags. This lets user activate
> the set of callsites marked with 'u' in a batch.
>
> echo 'u+p' > control
>
I'm wondering if users are really going to use these and how much they
simplify things? Do you find them useful while debugging issues?
Especially now that now that we are looking to let people define
groupings.
Thanks,
-Jason
On Fri, Jun 12, 2020 at 3:31 PM Jason Baron <[email protected]> wrote:
>
>
>
> On 6/5/20 12:26 PM, Jim Cromie wrote:
> > Patchset starts with 7 "cleanups";
> > - it changes section name from vague "__verbose" to "__dyndbg"
> > - cleaner docs, drop obsolete comment & useless debug prints, refine
> > verbosity, fix a BUG_ON, ram reporting miscounts.
> >
> > It adds a few query parsing conveniences;
> > accept combined file:line & file:func forms
> >
> > file inode.c:100-200 # file & line-range
> > file inode.c:start_* # file & function
> >
>
> So I like the shortened notation there.
>
> > Then it expands flags:
> >
> > Adds 'u' user flag, allowing user to compose an arbitrary set of
> > callsites by marking them with 'u', without altering current
> > print-modifying flags.
> >
> > Adds 'PFMLTU' flags, which negate their lower-case counterparts.
> >
> > Extends flags-spec with filter-flags, which select callsites for
> > modification based upon their current flags. This lets user activate
> > the set of callsites marked with 'u' in a batch.
> >
> > echo 'u+p' > control
> >
>
> I'm wondering if users are really going to use these and how much they
> simplify things? Do you find them useful while debugging issues?
>
> Especially now that now that we are looking to let people define
> groupings.
>
> Thanks,
>
> -Jason
so we have
1- u flag - in modflags, allows marking of sets
2- filterflags - constrain matching sites to those marked
plus any other subcondition you might want on your marked set
3- negating flags
in filters, they allow complete match to all the bits.
dont want to touch callsites marked with Pt ?
(marked with t, without printing) now you can.
filters let you use current flagstate to select subsets of " +p >control"
+negations gives complete selectivity on that flagstate
in modflags theyre more convenience,
but setting and clearing 2+ bits atomically
lets you both use the u bit to enable printing
(inc module name filename) and retire that use of u,
or to change the logging output subtly (by dropping threads display,
or module-name)
I cant say its essential, but its so cheap (last patch) once negating
flags are in place,
which are needed for full selectivity filtering.
thanks
Jim