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

On Fri, Mar 11, 2022 at 12:06 PM Jason Baron jbaron@akamai.com 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 linux@rasmusvillemoes.dk Signed-off-by: Jim Cromie jim.cromie@gmail.com

---

.../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;
  

}