2022-03-11 22:14:20

by Jim Cromie

[permalink] [raw]
Subject: [PATCH 2/5] dyndbg: add class_id field and query support

DRM defines/uses 10 enum drm_debug_category's to create exclusive
classes of debug messages. To support this directly in dynamic-debug,
add the following:

- struct _ddebug.class_id:4 - 4 bits is enough
- define _DPRINTK_SITE_UNCLASSED 15 - see below

and the query support:
- struct _ddebug_query.class_id
- ddebug_parse_query - looks for "class" keyword, then calls..
- parse_class - accepts uint: 0-15, sets query.class_id and marker
- vpr_info_dq - displays new field
- ddebug_proc_show - append column with "cls:%d" if !UNCLASSED

With the patch, one can enable current/unclassed callsites by:

#> echo drm class 15 +p > /proc/dynamic_debug/control

parse_class() accepts 0 .. _DPRINTK_SITE_UNCLASSED, which allows the
>control interface to explicitly manipulate unclassed callsites.

After parsing keywords, ddebug_parse_query() sets .class_id=15, iff it
wasnt explicitly set. This allows future classed/categorized
callsites to be untouched by legacy (class unaware) queries.

DEFINE_DYNAMIC_DEBUG_METADATA gets _CLS(cls,) suffix and arg, and
initializes the new .class_id=cls field. The old name gets the default.

Then, these _CLS(cls,...) modifications are repeated up through the
stack of *dynamic_func_call* macros that use the METADATA initializer,
so as to actually supply the category into it.

NOTES:

_DPRINTK_SITE_UNCLASSED: this symbol is used to initialize all
existing/unclassed pr-debug callsites. Normally, the default would be
zero, but DRM_UT_CORE "uses" that value, in the sense that 0 is
exposed as a bit position in drm.debug. Using 15 allows identity
mapping from category to class, avoiding fiddly offsets.

Default .class_id = 15 means that ``echo +p > control`` no longer
toggles ALL the callsites, only the unclassed ones. This was only
useful for static-branch toggle load testing anyway.

RFC:

The new _CLS macro flavor gets a warning from DRM/dri-devel's CI,
but not from checkpatch (on this subject).

a8f6c71f283e dyndbg: add class_id field and query support
-:141: CHECK:MACRO_ARG_REUSE: Macro argument reuse 'id' - possible side-effects?
+#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
+ if (DYNAMIC_DEBUG_BRANCH(id)) \
+ func(&id, ##__VA_ARGS__); \
} while (0)

I couldn't fix it with a ``typeof(id) _id = id`` construct. I haven't
seen the warning myself, on the _CLS extended macro, nor the original.

CC: Rasmus Villemoes <[email protected]>
Signed-off-by: Jim Cromie <[email protected]>
---
.../admin-guide/dynamic-debug-howto.rst | 7 +++
include/linux/dynamic_debug.h | 54 ++++++++++++++-----
lib/dynamic_debug.c | 48 ++++++++++++++---
3 files changed, 88 insertions(+), 21 deletions(-)

diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
index a89cfa083155..8ef8d7dcd140 100644
--- a/Documentation/admin-guide/dynamic-debug-howto.rst
+++ b/Documentation/admin-guide/dynamic-debug-howto.rst
@@ -35,6 +35,7 @@ Dynamic debug has even more useful features:
- line number (including ranges of line numbers)
- module name
- format string
+ - class number:0-15

* Provides a debugfs control file: ``<debugfs>/dynamic_debug/control``
which can be read to display the complete list of known debug
@@ -143,6 +144,7 @@ against. Possible keywords are:::
'module' string |
'format' string |
'line' line-range
+ 'class' integer:[0-15]

line-range ::= lineno |
'-'lineno |
@@ -217,6 +219,11 @@ line
line -1605 // the 1605 lines from line 1 to line 1605
line 1600- // all lines from line 1600 to the end of the file

+class
+ This expects a single integer in range: 0-15.
+ 15 is used/reserved for existing/unclassed callsites,
+ and is defaulted in unless specified to >control
+
The flags specification comprises a change operation followed
by one or more flag characters. The change operation is one
of the characters::
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index dce631e678dd..d4b48f3cc6e8 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -6,6 +6,8 @@
#include <linux/jump_label.h>
#endif

+#include <linux/build_bug.h>
+
/*
* An instance of this structure is created in a special
* ELF section at every dynamic debug callsite. At runtime,
@@ -21,6 +23,9 @@ struct _ddebug {
const char *filename;
const char *format;
unsigned int lineno:18;
+#define CLS_BITS 4
+ unsigned int class_id:CLS_BITS;
+#define _DPRINTK_SITE_UNCLASSED ((1 << CLS_BITS) - 1)
/*
* The flags field controls the behaviour at the callsite.
* The bits here are changed dynamically when the user
@@ -87,7 +92,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
const struct ib_device *ibdev,
const char *fmt, ...);

-#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
+#define DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, cls, fmt) \
static struct _ddebug __aligned(8) \
__section("__dyndbg") name = { \
.modname = KBUILD_MODNAME, \
@@ -96,8 +101,14 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
.format = (fmt), \
.lineno = __LINE__, \
.flags = _DPRINTK_FLAGS_DEFAULT, \
+ .class_id = cls, \
_DPRINTK_KEY_INIT \
- }
+ }; \
+ BUILD_BUG_ON_MSG(cls > _DPRINTK_SITE_UNCLASSED, \
+ "classid value overflow")
+
+#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, _DPRINTK_SITE_UNCLASSED, fmt)

#ifdef CONFIG_JUMP_LABEL

@@ -128,18 +139,26 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,

#endif /* CONFIG_JUMP_LABEL */

-#define __dynamic_func_call(id, fmt, func, ...) do { \
- DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
- if (DYNAMIC_DEBUG_BRANCH(id)) \
- func(&id, ##__VA_ARGS__); \
+#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
+ if (DYNAMIC_DEBUG_BRANCH(id)) \
+ func(&id, ##__VA_ARGS__); \
} while (0)

-#define __dynamic_func_call_no_desc(id, fmt, func, ...) do { \
- DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
- if (DYNAMIC_DEBUG_BRANCH(id)) \
- func(__VA_ARGS__); \
+#define __dynamic_func_call_no_desc_cls(id, cls, fmt, func, ...) do { \
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
+ if (DYNAMIC_DEBUG_BRANCH(id)) \
+ func(__VA_ARGS__); \
} while (0)

+#define __dynamic_func_call(id, fmt, func, ...) \
+ __dynamic_func_call_cls(id, _DPRINTK_SITE_UNCLASSED, \
+ fmt, func, ##__VA_ARGS__)
+
+#define __dynamic_func_call_no_desc(id, fmt, func, ...) \
+ __dynamic_func_call_no_desc_cls(id, _DPRINTK_SITE_UNCLASSED, \
+ fmt, func, ##__VA_ARGS__)
+
/*
* "Factory macro" for generating a call to func, guarded by a
* DYNAMIC_DEBUG_BRANCH. The dynamic debug descriptor will be
@@ -148,15 +167,24 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
* the varargs. Note that fmt is repeated in invocations of this
* macro.
*/
+#define _dynamic_func_call_cls(cls, fmt, func, ...) \
+ __dynamic_func_call_cls(__UNIQUE_ID(ddebug), cls, fmt, func, ##__VA_ARGS__)
#define _dynamic_func_call(fmt, func, ...) \
- __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
+ _dynamic_func_call_cls(_DPRINTK_SITE_UNCLASSED, fmt, func, ##__VA_ARGS__)
+
/*
* A variant that does the same, except that the descriptor is not
* passed as the first argument to the function; it is only called
* with precisely the macro's varargs.
*/
-#define _dynamic_func_call_no_desc(fmt, func, ...) \
- __dynamic_func_call_no_desc(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
+#define _dynamic_func_call_no_desc_cls(fmt, cat, func, ...) \
+ __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), cat, \
+ fmt, func, ##__VA_ARGS__)
+
+#define _dynamic_func_call_no_desc(fmt, func, ...) \
+ __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), \
+ _DPRINTK_SITE_UNCLASSED, \
+ fmt, func, ##__VA_ARGS__)

#define dynamic_pr_debug(fmt, ...) \
_dynamic_func_call(fmt, __dynamic_pr_debug, \
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index a56c1286ffa4..ee2129becacc 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -55,6 +55,8 @@ struct ddebug_query {
const char *function;
const char *format;
unsigned int first_lineno, last_lineno;
+ unsigned int class_id;
+ unsigned int class_marked:1;
};

struct ddebug_iter {
@@ -134,13 +136,13 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
fmtlen--;
}

- v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u\n",
- msg,
- query->function ?: "",
- query->filename ?: "",
- query->module ?: "",
- fmtlen, query->format ?: "",
- query->first_lineno, query->last_lineno);
+ v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%u\n",
+ msg,
+ query->function ?: "",
+ query->filename ?: "",
+ query->module ?: "",
+ fmtlen, query->format ?: "",
+ query->first_lineno, query->last_lineno, query->class_id);
}

/*
@@ -170,6 +172,10 @@ static int ddebug_change(const struct ddebug_query *query,
for (i = 0; i < dt->num_ddebugs; i++) {
struct _ddebug *dp = &dt->ddebugs[i];

+ /* match against the class_id, either given or default */
+ if (query->class_id != dp->class_id)
+ continue;
+
/* match against the source filename */
if (query->filename &&
!match_wildcard(query->filename, dp->filename) &&
@@ -308,6 +314,21 @@ static inline int parse_lineno(const char *str, unsigned int *val)
return 0;
}

+static inline int parse_class(struct ddebug_query *query, const char *str)
+{
+ int rc;
+ unsigned int val;
+
+ rc = kstrtouint(str, 10, &val);
+ if (rc < 0 || val > _DPRINTK_SITE_UNCLASSED) {
+ pr_err("expecting class:[0-%d], not %s\n", _DPRINTK_SITE_UNCLASSED, str);
+ return -EINVAL;
+ }
+ query->class_id = val;
+ query->class_marked = 1;
+ return 0;
+}
+
static int parse_linerange(struct ddebug_query *query, const char *first)
{
char *last = strchr(first, '-');
@@ -421,6 +442,9 @@ static int ddebug_parse_query(char *words[], int nwords,
} else if (!strcmp(keyword, "line")) {
if (parse_linerange(query, arg))
return -EINVAL;
+ } else if (!strcmp(keyword, "class")) {
+ if (parse_class(query, arg))
+ return -EINVAL;
} else {
pr_err("unknown keyword \"%s\"\n", keyword);
return -EINVAL;
@@ -428,6 +452,10 @@ static int ddebug_parse_query(char *words[], int nwords,
if (rc)
return rc;
}
+ /* post-validate the query, set default */
+ if (!query->class_marked)
+ query->class_id = _DPRINTK_SITE_UNCLASSED;
+
vpr_info_dq(query, "parsed");
return 0;
}
@@ -900,7 +928,11 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
iter->table->mod_name, dp->function,
ddebug_describe_flags(dp->flags, &flags));
seq_escape(m, dp->format, "\t\r\n\"");
- seq_puts(m, "\"\n");
+ seq_puts(m, "\"");
+
+ if (dp->class_id != _DPRINTK_SITE_UNCLASSED)
+ seq_printf(m, " cls:%u", dp->class_id);
+ seq_puts(m, "\n");

return 0;
}
--
2.35.1


2022-03-11 23:14:22

by Jason Baron

[permalink] [raw]
Subject: Re: [PATCH 2/5] dyndbg: add class_id field and query support



On 3/10/22 23:47, Jim Cromie wrote:
> DRM defines/uses 10 enum drm_debug_category's to create exclusive
> classes of debug messages. To support this directly in dynamic-debug,
> add the following:
>
> - struct _ddebug.class_id:4 - 4 bits is enough
> - define _DPRINTK_SITE_UNCLASSED 15 - see below
>
> and the query support:
> - struct _ddebug_query.class_id
> - ddebug_parse_query - looks for "class" keyword, then calls..
> - parse_class - accepts uint: 0-15, sets query.class_id and marker
> - vpr_info_dq - displays new field
> - ddebug_proc_show - append column with "cls:%d" if !UNCLASSED
>
> With the patch, one can enable current/unclassed callsites by:
>
> #> echo drm class 15 +p > /proc/dynamic_debug/control
>

To me, this is hard to read, what the heck is '15'? I have to go look it
up in the control file and it's not descriptive. I think that using
classes/categories makes sense but I'm wondering if it can be a bit more
user friendly? Perhaps, we can pass an array of strings that is indexed
by the class id to each pr_debug() site that wants to use class. So
something like:

enum levels {
LOW,
MEDIUM,
HIGH
};

static const char * const level_to_strings[] = {
[LOW] = "low",
[MEDIUM] = "medium",
[HIGH] = "high",
};

And then you'd have a wrapper macros in your driver:

#define module_foo_pr_debug_class(level, fmt, args...)
pr_debug_class(level, level_to_strings, fmt, args);

Such that call sites look like:

module_foo_pr_debug_class(LOW, fmt, args...);

Such that you're not always passing the strings array around. Now, this
does mean another pointer for struct _ddebug and most wouldn't have it.
Maybe we could just add another linker section for these so as to save
space.

> parse_class() accepts 0 .. _DPRINTK_SITE_UNCLASSED, which allows the
>> control interface to explicitly manipulate unclassed callsites.
>
> After parsing keywords, ddebug_parse_query() sets .class_id=15, iff it
> wasnt explicitly set. This allows future classed/categorized
> callsites to be untouched by legacy (class unaware) queries.
>
> DEFINE_DYNAMIC_DEBUG_METADATA gets _CLS(cls,) suffix and arg, and
> initializes the new .class_id=cls field. The old name gets the default.
>
> Then, these _CLS(cls,...) modifications are repeated up through the
> stack of *dynamic_func_call* macros that use the METADATA initializer,
> so as to actually supply the category into it.
>
> NOTES:
>
> _DPRINTK_SITE_UNCLASSED: this symbol is used to initialize all
> existing/unclassed pr-debug callsites. Normally, the default would be
> zero, but DRM_UT_CORE "uses" that value, in the sense that 0 is
> exposed as a bit position in drm.debug. Using 15 allows identity
> mapping from category to class, avoiding fiddly offsets.
>
> Default .class_id = 15 means that ``echo +p > control`` no longer
> toggles ALL the callsites, only the unclassed ones. This was only
> useful for static-branch toggle load testing anyway.
>

I think that # echo +p > control should continue to work as is, why
should the introduction of classes change that ?

> RFC:
>
> The new _CLS macro flavor gets a warning from DRM/dri-devel's CI,
> but not from checkpatch (on this subject).
>
> a8f6c71f283e dyndbg: add class_id field and query support
> -:141: CHECK:MACRO_ARG_REUSE: Macro argument reuse 'id' - possible side-effects?
> +#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
> + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
> + if (DYNAMIC_DEBUG_BRANCH(id)) \
> + func(&id, ##__VA_ARGS__); \
> } while (0)
>
> I couldn't fix it with a ``typeof(id) _id = id`` construct. I haven't
> seen the warning myself, on the _CLS extended macro, nor the original.
>
> CC: Rasmus Villemoes <[email protected]>
> Signed-off-by: Jim Cromie <[email protected]>
> ---
> .../admin-guide/dynamic-debug-howto.rst | 7 +++
> include/linux/dynamic_debug.h | 54 ++++++++++++++-----
> lib/dynamic_debug.c | 48 ++++++++++++++---
> 3 files changed, 88 insertions(+), 21 deletions(-)
>
> diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
> index a89cfa083155..8ef8d7dcd140 100644
> --- a/Documentation/admin-guide/dynamic-debug-howto.rst
> +++ b/Documentation/admin-guide/dynamic-debug-howto.rst
> @@ -35,6 +35,7 @@ Dynamic debug has even more useful features:
> - line number (including ranges of line numbers)
> - module name
> - format string
> + - class number:0-15
>
> * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control``
> which can be read to display the complete list of known debug
> @@ -143,6 +144,7 @@ against. Possible keywords are:::
> 'module' string |
> 'format' string |
> 'line' line-range
> + 'class' integer:[0-15]
>
> line-range ::= lineno |
> '-'lineno |
> @@ -217,6 +219,11 @@ line
> line -1605 // the 1605 lines from line 1 to line 1605
> line 1600- // all lines from line 1600 to the end of the file
>
> +class
> + This expects a single integer in range: 0-15.
> + 15 is used/reserved for existing/unclassed callsites,
> + and is defaulted in unless specified to >control
> +
> The flags specification comprises a change operation followed
> by one or more flag characters. The change operation is one
> of the characters::
> diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
> index dce631e678dd..d4b48f3cc6e8 100644
> --- a/include/linux/dynamic_debug.h
> +++ b/include/linux/dynamic_debug.h
> @@ -6,6 +6,8 @@
> #include <linux/jump_label.h>
> #endif
>
> +#include <linux/build_bug.h>
> +
> /*
> * An instance of this structure is created in a special
> * ELF section at every dynamic debug callsite. At runtime,
> @@ -21,6 +23,9 @@ struct _ddebug {
> const char *filename;
> const char *format;
> unsigned int lineno:18;
> +#define CLS_BITS 4
> + unsigned int class_id:CLS_BITS;
> +#define _DPRINTK_SITE_UNCLASSED ((1 << CLS_BITS) - 1)
> /*
> * The flags field controls the behaviour at the callsite.
> * The bits here are changed dynamically when the user
> @@ -87,7 +92,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> const struct ib_device *ibdev,
> const char *fmt, ...);
>
> -#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
> +#define DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, cls, fmt) \
> static struct _ddebug __aligned(8) \
> __section("__dyndbg") name = { \
> .modname = KBUILD_MODNAME, \
> @@ -96,8 +101,14 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> .format = (fmt), \
> .lineno = __LINE__, \
> .flags = _DPRINTK_FLAGS_DEFAULT, \
> + .class_id = cls, \
> _DPRINTK_KEY_INIT \
> - }
> + }; \
> + BUILD_BUG_ON_MSG(cls > _DPRINTK_SITE_UNCLASSED, \
> + "classid value overflow")
> +
> +#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
> + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, _DPRINTK_SITE_UNCLASSED, fmt)
>
> #ifdef CONFIG_JUMP_LABEL
>
> @@ -128,18 +139,26 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
>
> #endif /* CONFIG_JUMP_LABEL */
>
> -#define __dynamic_func_call(id, fmt, func, ...) do { \
> - DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
> - if (DYNAMIC_DEBUG_BRANCH(id)) \
> - func(&id, ##__VA_ARGS__); \
> +#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
> + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
> + if (DYNAMIC_DEBUG_BRANCH(id)) \
> + func(&id, ##__VA_ARGS__); \
> } while (0)
>
> -#define __dynamic_func_call_no_desc(id, fmt, func, ...) do { \
> - DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
> - if (DYNAMIC_DEBUG_BRANCH(id)) \
> - func(__VA_ARGS__); \
> +#define __dynamic_func_call_no_desc_cls(id, cls, fmt, func, ...) do { \
> + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
> + if (DYNAMIC_DEBUG_BRANCH(id)) \
> + func(__VA_ARGS__); \
> } while (0)
>
> +#define __dynamic_func_call(id, fmt, func, ...) \
> + __dynamic_func_call_cls(id, _DPRINTK_SITE_UNCLASSED, \
> + fmt, func, ##__VA_ARGS__)
> +
> +#define __dynamic_func_call_no_desc(id, fmt, func, ...) \
> + __dynamic_func_call_no_desc_cls(id, _DPRINTK_SITE_UNCLASSED, \
> + fmt, func, ##__VA_ARGS__)
> +
> /*
> * "Factory macro" for generating a call to func, guarded by a
> * DYNAMIC_DEBUG_BRANCH. The dynamic debug descriptor will be
> @@ -148,15 +167,24 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> * the varargs. Note that fmt is repeated in invocations of this
> * macro.
> */
> +#define _dynamic_func_call_cls(cls, fmt, func, ...) \
> + __dynamic_func_call_cls(__UNIQUE_ID(ddebug), cls, fmt, func, ##__VA_ARGS__)
> #define _dynamic_func_call(fmt, func, ...) \
> - __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
> + _dynamic_func_call_cls(_DPRINTK_SITE_UNCLASSED, fmt, func, ##__VA_ARGS__)
> +
> /*
> * A variant that does the same, except that the descriptor is not
> * passed as the first argument to the function; it is only called
> * with precisely the macro's varargs.
> */
> -#define _dynamic_func_call_no_desc(fmt, func, ...) \
> - __dynamic_func_call_no_desc(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
> +#define _dynamic_func_call_no_desc_cls(fmt, cat, func, ...) \
> + __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), cat, \
> + fmt, func, ##__VA_ARGS__)
> +
> +#define _dynamic_func_call_no_desc(fmt, func, ...) \
> + __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), \
> + _DPRINTK_SITE_UNCLASSED, \
> + fmt, func, ##__VA_ARGS__)
>
> #define dynamic_pr_debug(fmt, ...) \
> _dynamic_func_call(fmt, __dynamic_pr_debug, \
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index a56c1286ffa4..ee2129becacc 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -55,6 +55,8 @@ struct ddebug_query {
> const char *function;
> const char *format;
> unsigned int first_lineno, last_lineno;
> + unsigned int class_id;
> + unsigned int class_marked:1;
> };
>
> struct ddebug_iter {
> @@ -134,13 +136,13 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
> fmtlen--;
> }
>
> - v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u\n",
> - msg,
> - query->function ?: "",
> - query->filename ?: "",
> - query->module ?: "",
> - fmtlen, query->format ?: "",
> - query->first_lineno, query->last_lineno);
> + v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%u\n",
> + msg,
> + query->function ?: "",
> + query->filename ?: "",
> + query->module ?: "",
> + fmtlen, query->format ?: "",
> + query->first_lineno, query->last_lineno, query->class_id);
> }
>
> /*
> @@ -170,6 +172,10 @@ static int ddebug_change(const struct ddebug_query *query,
> for (i = 0; i < dt->num_ddebugs; i++) {
> struct _ddebug *dp = &dt->ddebugs[i];
>
> + /* match against the class_id, either given or default */
> + if (query->class_id != dp->class_id)
> + continue;
> +

Could that instead be:

if (query->class_id != _DPRINTK_SITE_UNCLASSED && query->class_id != dp->class_id)
continue;

That way by default we fall through and enable callsites for queries that do not have
the 'class' keyboard specified. I think I would also disallow setting
_DPRINTK_SITE_UNCLASSED explicitly since it would now mean 'class *', and what if
we expand class_id size to greater than 15 at some point?

> /* match against the source filename */
> if (query->filename &&
> !match_wildcard(query->filename, dp->filename) &&
> @@ -308,6 +314,21 @@ static inline int parse_lineno(const char *str, unsigned int *val)
> return 0;
> }
>
> +static inline int parse_class(struct ddebug_query *query, const char *str)
> +{
> + int rc;
> + unsigned int val;
> +
> + rc = kstrtouint(str, 10, &val);
> + if (rc < 0 || val > _DPRINTK_SITE_UNCLASSED) {
> + pr_err("expecting class:[0-%d], not %s\n", _DPRINTK_SITE_UNCLASSED, str);
> + return -EINVAL;
> + }
> + query->class_id = val;
> + query->class_marked = 1;
> + return 0;
> +}
> +
> static int parse_linerange(struct ddebug_query *query, const char *first)
> {
> char *last = strchr(first, '-');
> @@ -421,6 +442,9 @@ static int ddebug_parse_query(char *words[], int nwords,
> } else if (!strcmp(keyword, "line")) {
> if (parse_linerange(query, arg))
> return -EINVAL;
> + } else if (!strcmp(keyword, "class")) {
> + if (parse_class(query, arg))
> + return -EINVAL;
> } else {
> pr_err("unknown keyword \"%s\"\n", keyword);
> return -EINVAL;
> @@ -428,6 +452,10 @@ static int ddebug_parse_query(char *words[], int nwords,
> if (rc)
> return rc;
> }
> + /* post-validate the query, set default */
> + if (!query->class_marked)
> + query->class_id = _DPRINTK_SITE_UNCLASSED;
> +
> vpr_info_dq(query, "parsed");
> return 0;
> }
> @@ -900,7 +928,11 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> iter->table->mod_name, dp->function,
> ddebug_describe_flags(dp->flags, &flags));
> seq_escape(m, dp->format, "\t\r\n\"");
> - seq_puts(m, "\"\n");
> + seq_puts(m, "\"");
> +
> + if (dp->class_id != _DPRINTK_SITE_UNCLASSED)
> + seq_printf(m, " cls:%u", dp->class_id);
> + seq_puts(m, "\n");
>
> return 0;
> }

2022-03-12 08:53:57

by Jim Cromie

[permalink] [raw]
Subject: Re: [PATCH 2/5] dyndbg: add class_id field and query support

On Fri, Mar 11, 2022 at 12:06 PM Jason Baron <[email protected]> wrote:
>
>
>
> On 3/10/22 23:47, Jim Cromie wrote:
> > DRM defines/uses 10 enum drm_debug_category's to create exclusive
> > classes of debug messages. To support this directly in dynamic-debug,
> > add the following:
> >
> > - struct _ddebug.class_id:4 - 4 bits is enough
> > - define _DPRINTK_SITE_UNCLASSED 15 - see below
> >
> > and the query support:
> > - struct _ddebug_query.class_id
> > - ddebug_parse_query - looks for "class" keyword, then calls..
> > - parse_class - accepts uint: 0-15, sets query.class_id and marker
> > - vpr_info_dq - displays new field
> > - ddebug_proc_show - append column with "cls:%d" if !UNCLASSED
> >
> > With the patch, one can enable current/unclassed callsites by:
> >
> > #> echo drm class 15 +p > /proc/dynamic_debug/control
> >
>
> To me, this is hard to read, what the heck is '15'? I have to go look it
> up in the control file and it's not descriptive. I think that using
> classes/categories makes sense but I'm wondering if it can be a bit more
> user friendly? Perhaps, we can pass an array of strings that is indexed
> by the class id to each pr_debug() site that wants to use class. So
> something like:
>

Im not at all averse to nice names, but as something added on.

1st, the interface to make friendlier is DRM's

echo 0x04 > /sys/module/drm/parameters/debug # which category ?

parm: debug:Enable debug output, where each bit enables a
debug category.
Bit 0 (0x01) will enable CORE messages (drm core code)
Bit 1 (0x02) will enable DRIVER messages (drm controller code)
Bit 2 (0x04) will enable KMS messages (modesetting code)

echo DRM_UT_DRIVER,DRM_UT_KMS > /sys/module/drm/parameters/debug #
now its pretty clear

If that works, its cuz DEFINE_DYNAMIC_DEBUG_CLASSBITS()
plucks class symbols out of its __VA_ARGS__, and #stringifes them.
So that macro could then build the 1-per-module static constant string array
and (only) the callbacks would be able to use it.

from there, it shouldnt be hard to ref that from the module's ddebug_table,
so parse_query could validate class args against the module given (or
fail if none given)

Speaking strictly, theres a gap:
echo module * class DRM_UT_KMS +p > control
is nonsense for * other than drm + drivers,
but its fair/safe to just disallow wildcards on modname for this purpose.

it does however imply that module foo must exist for FOO_CAT_1 to be usable.
thats not currently the case:
bash-5.1# echo module foo +p > /proc/dynamic_debug/control
[ 15.403749] dyndbg: read 14 bytes from userspace
[ 15.405413] dyndbg: query 0: "module foo +p" mod:*
[ 15.406486] dyndbg: split into words: "module" "foo" "+p"
[ 15.407070] dyndbg: op='+'
[ 15.407388] dyndbg: flags=0x1
[ 15.407809] dyndbg: *flagsp=0x1 *maskp=0xffffffff
[ 15.408300] dyndbg: parsed: func="" file="" module="foo" format=""
lineno=0-0 class=15
[ 15.409151] dyndbg: no matches for query
[ 15.409591] dyndbg: no-match: func="" file="" module="foo"
format="" lineno=0-0 class=15
[ 15.410524] dyndbg: processed 1 queries, with 0 matches, 0 errs
bash-5.1#

ISTM we can keep that "0 errs" response for that case, but still reject this:

echo module foo class FOO_NOT_HERE +p > /proc/dynamic_debug/control


> enum levels {
> LOW,
> MEDIUM,
> HIGH
> };

I want to steer clear of "level" anything,
since 2>1 implies non independence of the categories



>
> static const char * const level_to_strings[] = {
> [LOW] = "low",
> [MEDIUM] = "medium",
> [HIGH] = "high",
> };
>
> And then you'd have a wrapper macros in your driver:
>
> #define module_foo_pr_debug_class(level, fmt, args...)
> pr_debug_class(level, level_to_strings, fmt, args);
>
> Such that call sites look like:
>
> module_foo_pr_debug_class(LOW, fmt, args...);
>

That macro, minus the "module_foo_" prefix,
could go into dynamic_debug.h

I didnt do that, for 2 reasons:

DRM didnt need it - it had an enum var,
and a set of macros to encapsulate the categories.

- the "prototype" looks like this might be ok:
define LOW "low"
pr_debug_class(LOW, "mumble about something %p %p\n", foo, bar)
ok thats a stretch, but...

Basically, I didnt want to deal with creating a new interface. KIS

> Such that you're not always passing the strings array around. Now, this
> does mean another pointer for struct _ddebug and most wouldn't have it.
> Maybe we could just add another linker section for these so as to save
> space.

From a space consideration, adding DRM users means adding
thousands of callsites ~2k for i915, ~4k for amdgpu
Also increasing per/callsite memory seems counterproductive.

see DEFINE_DYNAMIC_DEBUG_CLASSBITS for the way forward.

> > parse_class() accepts 0 .. _DPRINTK_SITE_UNCLASSED, which allows the
> >> control interface to explicitly manipulate unclassed callsites.
> >
> > After parsing keywords, ddebug_parse_query() sets .class_id=15, iff it
> > wasnt explicitly set. This allows future classed/categorized
> > callsites to be untouched by legacy (class unaware) queries.
> >
> > DEFINE_DYNAMIC_DEBUG_METADATA gets _CLS(cls,) suffix and arg, and
> > initializes the new .class_id=cls field. The old name gets the default.
> >
> > Then, these _CLS(cls,...) modifications are repeated up through the
> > stack of *dynamic_func_call* macros that use the METADATA initializer,
> > so as to actually supply the category into it.
> >
> > NOTES:
> >
> > _DPRINTK_SITE_UNCLASSED: this symbol is used to initialize all
> > existing/unclassed pr-debug callsites. Normally, the default would be
> > zero, but DRM_UT_CORE "uses" that value, in the sense that 0 is
> > exposed as a bit position in drm.debug. Using 15 allows identity
> > mapping from category to class, avoiding fiddly offsets.
> >
> > Default .class_id = 15 means that ``echo +p > control`` no longer
> > toggles ALL the callsites, only the unclassed ones. This was only
> > useful for static-branch toggle load testing anyway.
> >
>
> I think that # echo +p > control should continue to work as is, why
> should the introduction of classes change that ?

1st, its a good way to flood your syslog, forex if theres a serial driver built.
And this might get dramatically worse if DRM_VBLANK got lumped in.

but basically, it still affects the same universe of callsites
as before DRM popped/s into existence (which could double the callsites)

ISTM ``echo "+p;-p" >control``
is primarily useful for work-load generation.
whether 1 cycle is 4k or 8k toggles is unimportant.



>
> > RFC:
> >
> > The new _CLS macro flavor gets a warning from DRM/dri-devel's CI,
> > but not from checkpatch (on this subject).
> >
> > a8f6c71f283e dyndbg: add class_id field and query support
> > -:141: CHECK:MACRO_ARG_REUSE: Macro argument reuse 'id' - possible side-effects?
> > +#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
> > + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
> > + if (DYNAMIC_DEBUG_BRANCH(id)) \
> > + func(&id, ##__VA_ARGS__); \
> > } while (0)
> >
> > I couldn't fix it with a ``typeof(id) _id = id`` construct. I haven't
> > seen the warning myself, on the _CLS extended macro, nor the original.
> >
> > CC: Rasmus Villemoes <[email protected]>
> > Signed-off-by: Jim Cromie <[email protected]>
> > ---
> > .../admin-guide/dynamic-debug-howto.rst | 7 +++
> > include/linux/dynamic_debug.h | 54 ++++++++++++++-----
> > lib/dynamic_debug.c | 48 ++++++++++++++---
> > 3 files changed, 88 insertions(+), 21 deletions(-)
> >
> > diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst
> > index a89cfa083155..8ef8d7dcd140 100644
> > --- a/Documentation/admin-guide/dynamic-debug-howto.rst
> > +++ b/Documentation/admin-guide/dynamic-debug-howto.rst
> > @@ -35,6 +35,7 @@ Dynamic debug has even more useful features:
> > - line number (including ranges of line numbers)
> > - module name
> > - format string
> > + - class number:0-15
> >
> > * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control``
> > which can be read to display the complete list of known debug
> > @@ -143,6 +144,7 @@ against. Possible keywords are:::
> > 'module' string |
> > 'format' string |
> > 'line' line-range
> > + 'class' integer:[0-15]
> >
> > line-range ::= lineno |
> > '-'lineno |
> > @@ -217,6 +219,11 @@ line
> > line -1605 // the 1605 lines from line 1 to line 1605
> > line 1600- // all lines from line 1600 to the end of the file
> >
> > +class
> > + This expects a single integer in range: 0-15.
> > + 15 is used/reserved for existing/unclassed callsites,
> > + and is defaulted in unless specified to >control
> > +
> > The flags specification comprises a change operation followed
> > by one or more flag characters. The change operation is one
> > of the characters::
> > diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
> > index dce631e678dd..d4b48f3cc6e8 100644
> > --- a/include/linux/dynamic_debug.h
> > +++ b/include/linux/dynamic_debug.h
> > @@ -6,6 +6,8 @@
> > #include <linux/jump_label.h>
> > #endif
> >
> > +#include <linux/build_bug.h>
> > +
> > /*
> > * An instance of this structure is created in a special
> > * ELF section at every dynamic debug callsite. At runtime,
> > @@ -21,6 +23,9 @@ struct _ddebug {
> > const char *filename;
> > const char *format;
> > unsigned int lineno:18;
> > +#define CLS_BITS 4
> > + unsigned int class_id:CLS_BITS;
> > +#define _DPRINTK_SITE_UNCLASSED ((1 << CLS_BITS) - 1)
> > /*
> > * The flags field controls the behaviour at the callsite.
> > * The bits here are changed dynamically when the user
> > @@ -87,7 +92,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> > const struct ib_device *ibdev,
> > const char *fmt, ...);
> >
> > -#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
> > +#define DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, cls, fmt) \
> > static struct _ddebug __aligned(8) \
> > __section("__dyndbg") name = { \
> > .modname = KBUILD_MODNAME, \
> > @@ -96,8 +101,14 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> > .format = (fmt), \
> > .lineno = __LINE__, \
> > .flags = _DPRINTK_FLAGS_DEFAULT, \
> > + .class_id = cls, \
> > _DPRINTK_KEY_INIT \
> > - }
> > + }; \
> > + BUILD_BUG_ON_MSG(cls > _DPRINTK_SITE_UNCLASSED, \
> > + "classid value overflow")
> > +
> > +#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
> > + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, _DPRINTK_SITE_UNCLASSED, fmt)
> >
> > #ifdef CONFIG_JUMP_LABEL
> >
> > @@ -128,18 +139,26 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> >
> > #endif /* CONFIG_JUMP_LABEL */
> >
> > -#define __dynamic_func_call(id, fmt, func, ...) do { \
> > - DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
> > - if (DYNAMIC_DEBUG_BRANCH(id)) \
> > - func(&id, ##__VA_ARGS__); \
> > +#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \
> > + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
> > + if (DYNAMIC_DEBUG_BRANCH(id)) \
> > + func(&id, ##__VA_ARGS__); \
> > } while (0)
> >
> > -#define __dynamic_func_call_no_desc(id, fmt, func, ...) do { \
> > - DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \
> > - if (DYNAMIC_DEBUG_BRANCH(id)) \
> > - func(__VA_ARGS__); \
> > +#define __dynamic_func_call_no_desc_cls(id, cls, fmt, func, ...) do { \
> > + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \
> > + if (DYNAMIC_DEBUG_BRANCH(id)) \
> > + func(__VA_ARGS__); \
> > } while (0)
> >
> > +#define __dynamic_func_call(id, fmt, func, ...) \
> > + __dynamic_func_call_cls(id, _DPRINTK_SITE_UNCLASSED, \
> > + fmt, func, ##__VA_ARGS__)
> > +
> > +#define __dynamic_func_call_no_desc(id, fmt, func, ...) \
> > + __dynamic_func_call_no_desc_cls(id, _DPRINTK_SITE_UNCLASSED, \
> > + fmt, func, ##__VA_ARGS__)
> > +
> > /*
> > * "Factory macro" for generating a call to func, guarded by a
> > * DYNAMIC_DEBUG_BRANCH. The dynamic debug descriptor will be
> > @@ -148,15 +167,24 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> > * the varargs. Note that fmt is repeated in invocations of this
> > * macro.
> > */
> > +#define _dynamic_func_call_cls(cls, fmt, func, ...) \
> > + __dynamic_func_call_cls(__UNIQUE_ID(ddebug), cls, fmt, func, ##__VA_ARGS__)
> > #define _dynamic_func_call(fmt, func, ...) \
> > - __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
> > + _dynamic_func_call_cls(_DPRINTK_SITE_UNCLASSED, fmt, func, ##__VA_ARGS__)
> > +
> > /*
> > * A variant that does the same, except that the descriptor is not
> > * passed as the first argument to the function; it is only called
> > * with precisely the macro's varargs.
> > */
> > -#define _dynamic_func_call_no_desc(fmt, func, ...) \
> > - __dynamic_func_call_no_desc(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__)
> > +#define _dynamic_func_call_no_desc_cls(fmt, cat, func, ...) \
> > + __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), cat, \
> > + fmt, func, ##__VA_ARGS__)
> > +
> > +#define _dynamic_func_call_no_desc(fmt, func, ...) \
> > + __dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), \
> > + _DPRINTK_SITE_UNCLASSED, \
> > + fmt, func, ##__VA_ARGS__)
> >
> > #define dynamic_pr_debug(fmt, ...) \
> > _dynamic_func_call(fmt, __dynamic_pr_debug, \
> > diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> > index a56c1286ffa4..ee2129becacc 100644
> > --- a/lib/dynamic_debug.c
> > +++ b/lib/dynamic_debug.c
> > @@ -55,6 +55,8 @@ struct ddebug_query {
> > const char *function;
> > const char *format;
> > unsigned int first_lineno, last_lineno;
> > + unsigned int class_id;
> > + unsigned int class_marked:1;
> > };
> >
> >

> > /*
> > @@ -170,6 +172,10 @@ static int ddebug_change(const struct ddebug_query *query,
> > for (i = 0; i < dt->num_ddebugs; i++) {
> > struct _ddebug *dp = &dt->ddebugs[i];
> >
> > + /* match against the class_id, either given or default */
> > + if (query->class_id != dp->class_id)
> > + continue;
> > +
>
> Could that instead be:
>
> if (query->class_id != _DPRINTK_SITE_UNCLASSED && query->class_id != dp->class_id)
> continue;
>

I think that is the effect currently.

query construction adds in the default if the term wasnt specified.

> That way by default we fall through and enable callsites for queries that do not have
> the 'class' keyboard specified.

thats what I was avoiding - I suppose its a matter of perspective

all existing callsites are unclassified. - ie 15
to preserve the universe affected by old queries,
adding 15 by default comports with this.
then when class !=15 callsites are added,
they are immune from effects by existing queries.

classed queries are the alternate universe.
and need "class N" in >control to get there.
Id expect DRM would like the isolation,
at least against inadvertent changes.

that said, ``echo +p >control`` can only affect 1 universe at a time.
ISTM this is fine,
the only thing lost is 1/2 the workload for
while true do echo "+p ; -p" >control; done

> I think I would also disallow setting
> _DPRINTK_SITE_UNCLASSED explicitly since it would now mean 'class *', and what if
> we expand class_id size to greater than 15 at some point?

it doesnt mean class *, it means class OTHER than 0-14

earlier version of parse_class disallowed 15 explicitly,
I changed it to simplify testing.

re-adding that constraint could be argued,
but if class 15 is the default when unspecified,
its hard to explain why "class 15" could draw an errror.

we'd just increase bit-field size, class_id:5
and bump 15 to 31.
is there an appropriate *_MAX macro to use,
to add the right implications / connotations ?
theres something vaguely overflowy / rollover-y here.
What choice words would convey it succinctly ?

>
> > /* match against the source filename */
> > if (query->filename &&
> > !match_wildcard(query->filename, dp->filename) &&
> > @@ -308,6 +314,21 @@ static inline int parse_lineno(const char *str, unsigned int *val)
> > return 0;
> > }
> >
> > +static inline int parse_class(struct ddebug_query *query, const char *str)
> > +{
> > + int rc;
> > + unsigned int val;
> > +
> > + rc = kstrtouint(str, 10, &val);
> > + if (rc < 0 || val > _DPRINTK_SITE_UNCLASSED) {
> > + pr_err("expecting class:[0-%d], not %s\n", _DPRINTK_SITE_UNCLASSED, str);
> > + return -EINVAL;
> > + }
> > + query->class_id = val;
> > + query->class_marked = 1;
> > + return 0;
> > +}
> > +
> > static int parse_linerange(struct ddebug_query *query, const char *first)
> > {
> > char *last = strchr(first, '-');
> > @@ -421,6 +442,9 @@ static int ddebug_parse_query(char *words[], int nwords,
> > } else if (!strcmp(keyword, "line")) {
> > if (parse_linerange(query, arg))
> > return -EINVAL;
> > + } else if (!strcmp(keyword, "class")) {
> > + if (parse_class(query, arg))
> > + return -EINVAL;
> > } else {
> > pr_err("unknown keyword \"%s\"\n", keyword);
> > return -EINVAL;
> > @@ -428,6 +452,10 @@ static int ddebug_parse_query(char *words[], int nwords,
> > if (rc)
> > return rc;
> > }
> > + /* post-validate the query, set default */
> > + if (!query->class_marked)
> > + query->class_id = _DPRINTK_SITE_UNCLASSED;
> > +
> > vpr_info_dq(query, "parsed");
> > return 0;
> > }
> > @@ -900,7 +928,11 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> > iter->table->mod_name, dp->function,
> > ddebug_describe_flags(dp->flags, &flags));
> > seq_escape(m, dp->format, "\t\r\n\"");
> > - seq_puts(m, "\"\n");
> > + seq_puts(m, "\"");
> > +
> > + if (dp->class_id != _DPRINTK_SITE_UNCLASSED)
> > + seq_printf(m, " cls:%u", dp->class_id);
> > + seq_puts(m, "\n");
> >
> > return 0;
> > }

2022-03-17 06:48:00

by Jason Baron

[permalink] [raw]
Subject: Re: [PATCH 2/5] dyndbg: add class_id field and query support



On 3/11/22 20:06, [email protected] wrote:
> On Fri, Mar 11, 2022 at 12:06 PM Jason Baron <[email protected]> wrote:
>>
>>
>>
>> On 3/10/22 23:47, Jim Cromie wrote:
>>> DRM defines/uses 10 enum drm_debug_category's to create exclusive
>>> classes of debug messages. To support this directly in dynamic-debug,
>>> add the following:
>>>
>>> - struct _ddebug.class_id:4 - 4 bits is enough
>>> - define _DPRINTK_SITE_UNCLASSED 15 - see below
>>>
>>> and the query support:
>>> - struct _ddebug_query.class_id
>>> - ddebug_parse_query - looks for "class" keyword, then calls..
>>> - parse_class - accepts uint: 0-15, sets query.class_id and marker
>>> - vpr_info_dq - displays new field
>>> - ddebug_proc_show - append column with "cls:%d" if !UNCLASSED
>>>
>>> With the patch, one can enable current/unclassed callsites by:
>>>
>>> #> echo drm class 15 +p > /proc/dynamic_debug/control
>>>
>>
>> To me, this is hard to read, what the heck is '15'? I have to go look it
>> up in the control file and it's not descriptive. I think that using
>> classes/categories makes sense but I'm wondering if it can be a bit more
>> user friendly? Perhaps, we can pass an array of strings that is indexed
>> by the class id to each pr_debug() site that wants to use class. So
>> something like:
>>
>
> Im not at all averse to nice names, but as something added on.
>
> 1st, the interface to make friendlier is DRM's
>
> echo 0x04 > /sys/module/drm/parameters/debug # which category ?
>
> parm: debug:Enable debug output, where each bit enables a
> debug category.
> Bit 0 (0x01) will enable CORE messages (drm core code)
> Bit 1 (0x02) will enable DRIVER messages (drm controller code)
> Bit 2 (0x04) will enable KMS messages (modesetting code)
>
> echo DRM_UT_DRIVER,DRM_UT_KMS > /sys/module/drm/parameters/debug #
> now its pretty clear
>
> If that works, its cuz DEFINE_DYNAMIC_DEBUG_CLASSBITS()
> plucks class symbols out of its __VA_ARGS__, and #stringifes them.
> So that macro could then build the 1-per-module static constant string array
> and (only) the callbacks would be able to use it.
>
> from there, it shouldnt be hard to ref that from the module's ddebug_table,
> so parse_query could validate class args against the module given (or
> fail if none given)
>
> Speaking strictly, theres a gap:
> echo module * class DRM_UT_KMS +p > control
> is nonsense for * other than drm + drivers,
> but its fair/safe to just disallow wildcards on modname for this purpose.
>
> it does however imply that module foo must exist for FOO_CAT_1 to be usable.
> thats not currently the case:
> bash-5.1# echo module foo +p > /proc/dynamic_debug/control
> [ 15.403749] dyndbg: read 14 bytes from userspace
> [ 15.405413] dyndbg: query 0: "module foo +p" mod:*
> [ 15.406486] dyndbg: split into words: "module" "foo" "+p"
> [ 15.407070] dyndbg: op='+'
> [ 15.407388] dyndbg: flags=0x1
> [ 15.407809] dyndbg: *flagsp=0x1 *maskp=0xffffffff
> [ 15.408300] dyndbg: parsed: func="" file="" module="foo" format=""
> lineno=0-0 class=15
> [ 15.409151] dyndbg: no matches for query
> [ 15.409591] dyndbg: no-match: func="" file="" module="foo"
> format="" lineno=0-0 class=15
> [ 15.410524] dyndbg: processed 1 queries, with 0 matches, 0 errs
> bash-5.1#
>
> ISTM we can keep that "0 errs" response for that case, but still reject this:
>
> echo module foo class FOO_NOT_HERE +p > /proc/dynamic_debug/control
>
>

Ok, yeah so I guess I'm thinking about the 'class' more as global namespace,
so that for example, it could span modules, or be specific to certain modules.
I'm also thinking of it as a 'string' which is maybe hierarchical, so that it's
clear what sub-system, or sub-sub-system it belongs to. So for DRM for example,
it could be a string like "DRM:CORE". The index num I think is still helpful for
implementation so we don't have to store a pointer size, but I don't think it's
really exposed (except perhaps in module params b/c drm is doing that already?).


>> enum levels {
>> LOW,
>> MEDIUM,
>> HIGH
>> };
>
> I want to steer clear of "level" anything,
> since 2>1 implies non independence of the categories
>
>

Agreed, that was a bad example on my part.

I've put together a rough patch on top of your series, to make my thinking
hopefully clear. I also think that the module param callback thing could be
implemented in this 'global' space with the 0-14 low numbers, by adding
some sort of offset into the table. IE you would add the low number +
the offset to get the 'string' to add to the ddebug query. I commented it
out in my patch below b/c I didn't implement that part.

Thoughts?


diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 664bb83778d2..b0bc1b536d54 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -8,6 +8,14 @@

#include <linux/build_bug.h>

+enum ddebug_categories {
+ FOO_BAR = 0,
+ DRM_A = 1,
+ DRM_B = 2,
+ DRM_C = 3,
+ //_DPRINTK_SITE_DEFAULT 63 is max
+};
+
/*
* An instance of this structure is created in a special
* ELF section at every dynamic debug callsite. At runtime,
@@ -23,9 +31,9 @@ struct _ddebug {
const char *filename;
const char *format;
unsigned int lineno:18;
-#define CLS_BITS 4
+#define CLS_BITS 6
unsigned int class_id:CLS_BITS;
-#define _DPRINTK_SITE_UNCLASSED ((1 << CLS_BITS) - 1)
+#define _DPRINTK_SITE_DEFAULT ((1 << CLS_BITS) - 1)
/*
* The flags field controls the behaviour at the callsite.
* The bits here are changed dynamically when the user
@@ -101,11 +109,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
.class_id = cls, \
_DPRINTK_KEY_INIT \
}; \
- BUILD_BUG_ON_MSG(cls > _DPRINTK_SITE_UNCLASSED, \
+ BUILD_BUG_ON_MSG(cls > _DPRINTK_SITE_DEFAULT, \
"classid value overflow")

#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
- DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, _DPRINTK_SITE_UNCLASSED, fmt)
+ DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, _DPRINTK_SITE_DEFAULT, fmt)

#ifdef CONFIG_JUMP_LABEL

@@ -149,11 +157,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
} while (0)

#define __dynamic_func_call(id, fmt, func, ...) \
- __dynamic_func_call_cls(id, _DPRINTK_SITE_UNCLASSED, \
+ __dynamic_func_call_cls(id, _DPRINTK_SITE_DEFAULT, \
fmt, func, ##__VA_ARGS__)

#define __dynamic_func_call_no_desc(id, fmt, func, ...) \
- __dynamic_func_call_no_desc_cls(id, _DPRINTK_SITE_UNCLASSED, \
+ __dynamic_func_call_no_desc_cls(id, _DPRINTK_SITE_DEFAULT, \
fmt, func, ##__VA_ARGS__)

/*
@@ -167,7 +175,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
#define _dynamic_func_call_cls(cls, fmt, func, ...) \
__dynamic_func_call_cls(__UNIQUE_ID(ddebug), cls, fmt, func, ##__VA_ARGS__)
#define _dynamic_func_call(fmt, func, ...) \
- _dynamic_func_call_cls(_DPRINTK_SITE_UNCLASSED, fmt, func, ##__VA_ARGS__)
+ _dynamic_func_call_cls(_DPRINTK_SITE_DEFAULT, fmt, func, ##__VA_ARGS__)

/*
* A variant that does the same, except that the descriptor is not
@@ -180,7 +188,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,

#define _dynamic_func_call_no_desc(fmt, func, ...) \
__dynamic_func_call_no_desc_cls(__UNIQUE_ID(ddebug), \
- _DPRINTK_SITE_UNCLASSED, \
+ _DPRINTK_SITE_DEFAULT, \
fmt, func, ##__VA_ARGS__)

#define dynamic_pr_debug(fmt, ...) \
@@ -284,7 +292,7 @@ struct dyndbg_classbits_param {
static struct dyndbg_classbits_param ddcats_##_var = { \
.bits = &(_var), \
.flags = _flgs, \
- .classes = { __VA_ARGS__, _DPRINTK_SITE_UNCLASSED } \
+ .classes = { __VA_ARGS__, _DPRINTK_SITE_DEFAULT } \
}; \
module_param_cb(fsname, &param_ops_dyndbg_classbits, \
&ddcats_##_var, 0644)
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 11c8d0771cd2..0f390638e46c 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -39,6 +39,14 @@

#include <rdma/ib_verbs.h>

+static const char * const cat_to_strings[] = {
+ [FOO_BAR] = "foo:bar",
+ [DRM_A] = "drm:A",
+ [DRM_B] = "drm:B",
+ [DRM_C] = "drm:C",
+ [_DPRINTK_SITE_DEFAULT] = "default",
+};
+
extern struct _ddebug __start___dyndbg[];
extern struct _ddebug __stop___dyndbg[];

@@ -55,8 +63,7 @@ struct ddebug_query {
const char *function;
const char *format;
unsigned int first_lineno, last_lineno;
- unsigned int class_id;
- unsigned int class_marked:1;
+ const char *class_string;
};

struct ddebug_iter {
@@ -136,13 +143,13 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
fmtlen--;
}

- v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%u\n",
+ v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%s\n",
msg,
query->function ?: "",
query->filename ?: "",
query->module ?: "",
fmtlen, query->format ?: "",
- query->first_lineno, query->last_lineno, query->class_id);
+ query->first_lineno, query->last_lineno, query->class_string);
}

/*
@@ -158,7 +165,7 @@ static int ddebug_change(const struct ddebug_query *query,
struct ddebug_table *dt;
unsigned int newflags;
unsigned int nfound = 0;
- struct flagsbuf fbuf;
+ struct flagsbuf fbuf, nbuf;

/* search for matching ddebugs */
mutex_lock(&ddebug_lock);
@@ -172,8 +179,8 @@ static int ddebug_change(const struct ddebug_query *query,
for (i = 0; i < dt->num_ddebugs; i++) {
struct _ddebug *dp = &dt->ddebugs[i];

- /* match against the class_id, either given or default */
- if (query->class_id != dp->class_id)
+ /* if class is not set fall through, ot check if it matches */
+ if (query->class_string && strcmp(query->class_string, cat_to_strings[dp->class_id]))
continue;

/* match against the source filename */
@@ -223,11 +230,12 @@ static int ddebug_change(const struct ddebug_query *query,
static_branch_enable(&dp->key.dd_key_true);
}
#endif
+ v4pr_info("changed %s:%d [%s]%s %s -> %s\n",
+ trim_prefix(dp->filename), dp->lineno,
+ dt->mod_name, dp->function,
+ ddebug_describe_flags(dp->flags, &fbuf),
+ ddebug_describe_flags(newflags, &nbuf));
dp->flags = newflags;
- v4pr_info("changed %s:%d [%s]%s =%s\n",
- trim_prefix(dp->filename), dp->lineno,
- dt->mod_name, dp->function,
- ddebug_describe_flags(dp->flags, &fbuf));
}
}
mutex_unlock(&ddebug_lock);
@@ -314,21 +322,6 @@ static inline int parse_lineno(const char *str, unsigned int *val)
return 0;
}

-static inline int parse_class(struct ddebug_query *query, const char *str)
-{
- int rc;
- unsigned int val;
-
- rc = kstrtouint(str, 10, &val);
- if (rc < 0 || val > _DPRINTK_SITE_UNCLASSED) {
- pr_err("expecting class:[0-%d], not %s\n", _DPRINTK_SITE_UNCLASSED, str);
- return -EINVAL;
- }
- query->class_id = val;
- query->class_marked = 1;
- return 0;
-}
-
static int parse_linerange(struct ddebug_query *query, const char *first)
{
char *last = strchr(first, '-');
@@ -443,8 +436,7 @@ static int ddebug_parse_query(char *words[], int nwords,
if (parse_linerange(query, arg))
return -EINVAL;
} else if (!strcmp(keyword, "class")) {
- if (parse_class(query, arg))
- return -EINVAL;
+ rc = check_set(&query->class_string, arg, "class");
} else {
pr_err("unknown keyword \"%s\"\n", keyword);
return -EINVAL;
@@ -452,9 +444,6 @@ static int ddebug_parse_query(char *words[], int nwords,
if (rc)
return rc;
}
- /* post-validate the query, set default */
- if (!query->class_marked)
- query->class_id = _DPRINTK_SITE_UNCLASSED;

vpr_info_dq(query, "parsed");
return 0;
@@ -616,6 +605,8 @@ int param_set_dyndbg_classbits(const char *instr, const struct kernel_param *kp)
}
vpr_info("set_dyndbg_classbits: new 0x%lx old 0x%lx\n", inbits, *dcp->bits);

+
+/*
for (i = 0; (i < _DPRINTK_SITE_UNCLASSED &&
dcp->classes[i] < _DPRINTK_SITE_UNCLASSED); i++) {

@@ -630,6 +621,7 @@ int param_set_dyndbg_classbits(const char *instr, const struct kernel_param *kp)
matches, dcp->classes[i]);
totct += matches;
}
+*/
*dcp->bits = inbits;
vpr_info("total matches: %d\n", totct);
return 0;
@@ -978,8 +970,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
seq_escape(m, dp->format, "\t\r\n\"");
seq_puts(m, "\"");

- if (dp->class_id != _DPRINTK_SITE_UNCLASSED)
- seq_printf(m, " cls:%u", dp->class_id);
+ seq_printf(m, " cat:%s", cat_to_strings[dp->class_id]);
seq_puts(m, "\n");

return 0;

2022-03-28 21:48:53

by Jim Cromie

[permalink] [raw]
Subject: Re: [PATCH 2/5] dyndbg: add class_id field and query support

On Mon, Mar 14, 2022 at 3:30 PM Jason Baron <[email protected]> wrote:
>
>
>
> On 3/11/22 20:06, [email protected] wrote:
> > On Fri, Mar 11, 2022 at 12:06 PM Jason Baron <[email protected]> wrote:
> >>
> >>
> >>
> >> On 3/10/22 23:47, Jim Cromie wrote:
> >>>
> >>> With the patch, one can enable current/unclassed callsites by:
> >>>
> >>> #> echo drm class 15 +p > /proc/dynamic_debug/control
> >>>
> >>
> >> To me, this is hard to read, what the heck is '15'? I have to go look it
> >> up in the control file and it's not descriptive. I think that using
> >> classes/categories makes sense but I'm wondering if it can be a bit more
> >> user friendly? Perhaps, we can pass an array of strings that is indexed
> >> by the class id to each pr_debug() site that wants to use class. So
> >> something like:

hi Jason,
Im now in basically full agreement with you

1. .class_id is a "global" space, in that all callsites have one.
2. 0-15 is an exceedingly small range for a global space

Fix that by
3. make it private (by removing "class N" parsing)
now nobody can do
echo module * class N +p >control

4. add private/per-module "string" -> class_id map
each module will have to declare the class-strings they use/accept
opt-in - want coordinated / shared names for DRM_UT_KMS etc.

5. validate input using the known class_string -> class_id

then, this is knowably right or wrong, depending on DRM_FOO:
echo module drm class DRM_FOO +p > control

it also means that
echo class DRM_UT_KMS +p >control
is both wellformed and minimal;
any module that has DRM_UT_KMS defined will know which class_id *they*
have mapped it to.
theres no global "DRM_UT_KMS" to be abused.

So Ive been working towards that..
Heres my current biggest roadblock

DEFINE_DYNAMIC_DEBUG_CLASSBITS
creates the class-strings[] array declaratively, at compile-time.
This array is attached to the kernel-param.args,
so it can be used by the callbacks (to construct the command)

But its not obviously available from outside the sysfs knob
that its attached to, as is needed to apply command >control generally.

If I can attach the class-strings[] to struct ddebug_table,
then ddebug_change() can use it to validate >control input.

So, how to attach ?
its got to work for both builtin & loadable modules.
(which precludes something in struct module ?)

I looked for a kernel_param_register callback, came up empty.
Trying to add it feels invasive / imposing.


> >
> > If that works, its cuz DEFINE_DYNAMIC_DEBUG_CLASSBITS()
> > plucks class symbols out of its __VA_ARGS__, and #stringifes them.
> > So that macro could then build the 1-per-module static constant string array
> > and (only) the callbacks would be able to use it.
> >

So Ive been tinkering hard on this macro, since its pretty central to
the interface defn.
heres some choices:

this is what Ive been working towards.
using enum symbols directly like this associates them by grep,
in contrast, class-strings are mealy-mouthed, milquetoast.

DEFINE_DYNAMIC_DEBUG_CLASSBITS(debug, __drm_debug, "p",
"enable drm.debug categories - 1 bit per category",
DRM_UT_CORE,
DRM_UT_DRIVER,
DRM_UT_KMS,
DRM_UT_PRIME,
DRM_UT_ATOMIC,
DRM_UT_VBL,
DRM_UT_STATE,
DRM_UT_LEASE,
DRM_UT_DP,
DRM_UT_DRMRES);

I found a slick MAP ( ) macro to do this:

#define DEFINE_DYNAMIC_DEBUG_CLASSBITS(fsname, _var, _flgs, desc, ...) \
MODULE_PARM_DESC(fsname, desc); \
static struct dyndbg_classbits_param ddcats_##_var = { \
.bits = &(_var), \
.flags = _flgs, \
.classes = { __VA_ARGS__, _DPRINTK_CLASS_DFLT }, \
.class_names = { mgMAP(__stringify, sCOMMA, \
__VA_ARGS__,
_DPRINTK_CLASS_DFLT) } \
}; \
module_param_cb(fsname, &param_ops_dyndbg_classbits, \
&ddcats_##_var, 0644)

__VA_ARGS__ is used 2x
.class_names is available for validating command >control

As much as I like the above, the MAP macro has a longer, more risky
path to the kernel

so a more modest alternative: module user defines class-strings in interface,
but they *must* align manually with the enum values they correspond to;
the order determines the bit-pos in the sysfs node,
since the interface no longer provides the enum values themselves.

DEFINE_DYNAMIC_DEBUG_CLASS_STRINGS(debug, __drm_debug, "p",
"enable drm.debug categories - 1 bit per category",
"DRM_UT_CORE",
"DRM_UT_DRIVER",
"DRM_UT_KMS",

different name allows CLASSBITs or similar in future, if MAP works out.
class-strings are completely defined by users, drm can drop UT naming

TLDR: FWIW

iSTM that the same macro will support the coordinated use of class-strings
across multiple modules.

drm_print.c - natural home for exposed sysfs node

amdgpu/, drm_helper/ i915/ nouveau/ will all need a DEFINE_DD added,
so that ddebug_change() can allow those .class_ids to be controlled.
sysfs perm inits can disable their nodes, since theyre coordinated.

> >
>
> Ok, yeah so I guess I'm thinking about the 'class' more as global namespace,
> so that for example, it could span modules, or be specific to certain modules.
> I'm also thinking of it as a 'string' which is maybe hierarchical, so that it's
> clear what sub-system, or sub-sub-system it belongs to. So for DRM for example,
> it could be a string like "DRM:CORE". The index num I think is still helpful for
> implementation so we don't have to store a pointer size, but I don't think it's
> really exposed (except perhaps in module params b/c drm is doing that already?).
>

So what Ive got here is as described above,
I just need a few bright ideas,
then I can bring it together.
got a spare tuit?

Jim