hi Jason, Greg, Daniel, dri-everyone,
drm_debug_enabled() is called a lot (by drm-debug api) to do unlikely bit-tests to selectively enable debug printing; this is a good job for DYNAMIC_DEBUG, IFF it is built with JUMP_LABEL.
This patchset enables the use of dynamic-debug to avoid those drm_debug_enabled() overheads, if CONFIG_DRM_USE_DYNAMIC_DEBUG=y.
v5: much rework
- based on Daniel Vetter's feedback, not RFC anymore. (except last one)
- move POC bit_map callback code into dynamic_debug add .data to struct kernel_param add DEFINE_DYNAMIC_DEBUG_CATEGORIES : a declarative interface for bits => control-queries this is all new functionality.
- use DEFINE_DYNAMIC_DEBUG_CATEGORIES in i915, amdgpu adds selectivity/control to existing categorizations
- DRM_USE_DYNAMIC_DEBUG replace DRM_UT_<CAT> (an enum) with DRM_CAT_<CAT> (a prefix string, cpp-prepended to format) _UT_ still present, drm_debug_enabled() still used todo: change __drm_debug param-var to read DDD_CATEGORIES's param-var might suffice to keep parallel schemes coherent.
- RFC add tracer func as syslog alternate test_dynamic_debug.ko: uses tracer for observability, does selftest has some misuse risk; calling pr_debug recursively.
v4: (brown-bagger, various fixes after snips) v3: fixes missed SOB, && on BOL, commit-log tweaks v2: https://lore.kernel.org/lkml/20210711055003.528167-1-jim.cromie@gmail.com/ v1: https://lore.kernel.org/lkml/20201204035318.332419-1-jim.cromie@gmail.com/
Doing so creates many new pr_debug callsites, otherwise i915 has ~120 prdbgs, and drm has just 1;
bash-5.1# modprobe i915 dyndbg: 8 debug prints in module video dyndbg: 305 debug prints in module drm dyndbg: 207 debug prints in module drm_kms_helper dyndbg: 2 debug prints in module ttm dyndbg: 1720 debug prints in module i915
On amdgpu, enabling it adds ~3200 prdbgs, currently at 56 bytes each. So CONFIG_DRM_USE_DYNAMIC_DEBUG=y affects resource requirements. Im working on a diet-plan.
Im running this patchset bare-metal on an i7/i915 laptop & an r9/amdgpu desktop (both as loadable modules). I booted the amdgpu box with:
BOOT_IMAGE=(hd2,gpt2)/vmlinuz-5.14.0-rc4-d7a-00009-g5db471cba844 \ root=UUID=mumble ro \ rootflags=subvol=root00 rhgb \ dynamic_debug.verbose=3 main.dyndbg=+p \ amdgpu.debug=1 amdgpu.test=1 \ "amdgpu.dyndbg=format ^[ +p"
That last line enables ~1700 prdbg callsites with a format like '[DML' etc at boot, and amdgpu.test=1 triggers 90 seconds of tests, yielding ~76k prdbgs in 409 seconds, before I turned them off with:
echo module amdgpu -p > /proc/dynamic_debug/control
Its worth noting, this changes the dyndbg-state underneath settings applied with `echo > parameters/debug`; the latter is qualitatively writeonly, maybe a param_get should return "NA" "-1"
this merged cleanly, on top of commit d65ef4634e5c795a6a4df1d198992c70e9692fb3 (drm-tip/drm-tip)
Jim Cromie (9): drm/print: fixup spelling in a comment moduleparam: add data member to struct kernel_param dyndbg: add DEFINE_DYNAMIC_DEBUG_CATEGORIES and callbacks i915/gvt: remove spaces in pr_debug "gvt: core:" etc prefixes i915/gvt: use DEFINE_DYNAMIC_DEBUG_CATEGORIES to create "gvt:core:" etc categories amdgpu: use DEFINE_DYNAMIC_DEBUG_CATEGORIES to control categorized pr_debugs drm_print: add choice to use dynamic debug in drm-debug amdgpu_ucode: reduce number of pr_debug calls dyndbg: RFC add tracer facility RFC
drivers/gpu/drm/Kconfig | 13 + drivers/gpu/drm/amd/amdgpu/amdgpu_ucode.c | 293 ++++++++++-------- .../gpu/drm/amd/display/dc/core/dc_debug.c | 44 ++- drivers/gpu/drm/drm_print.c | 49 ++- drivers/gpu/drm/i915/gvt/Makefile | 4 + drivers/gpu/drm/i915/gvt/debug.h | 18 +- drivers/gpu/drm/i915/i915_params.c | 35 +++ include/drm/drm_print.h | 143 +++++++-- include/linux/dynamic_debug.h | 82 ++++- include/linux/moduleparam.h | 11 +- lib/Kconfig.debug | 10 + lib/Makefile | 1 + lib/dynamic_debug.c | 171 ++++++++-- lib/test_dynamic_debug.c | 247 +++++++++++++++ 14 files changed, 901 insertions(+), 220 deletions(-) create mode 100644 lib/test_dynamic_debug.c
s/prink/printk/ - no functional changes
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- include/drm/drm_print.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 9b66be54dd16..15a089a87c22 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -327,7 +327,7 @@ static inline bool drm_debug_enabled(enum drm_debug_category category) /* * struct device based logging * - * Prefer drm_device based logging over device or prink based logging. + * Prefer drm_device based logging over device or printk based logging. */
__printf(3, 4)
Add a const void* data member to the struct, to allow attaching private data that will be used soon by a setter method (via kp->data) to perform more elaborate actions.
To attach the data at compile time, add new macros:
module_param_cbd() derives from module_param_cb(), adding data param, and latter is redefined to use former.
It calls __module_param_call_wdata(), which accepts a new data param and inits .data with it. Re-define __module_param_call() to use it.
Use of this new data member will be rare, it might be worth redoing this as a separate/sub-type to de-bloat the base case.
--- v4+: . const void* data - emil.l.velikov@gmail.com
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- include/linux/moduleparam.h | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-)
diff --git a/include/linux/moduleparam.h b/include/linux/moduleparam.h index eed280fae433..878387e0b2d9 100644 --- a/include/linux/moduleparam.h +++ b/include/linux/moduleparam.h @@ -78,6 +78,7 @@ struct kernel_param { const struct kparam_string *str; const struct kparam_array *arr; }; + const void *data; };
extern const struct kernel_param __start___param[], __stop___param[]; @@ -175,6 +176,9 @@ struct kparam_array #define module_param_cb(name, ops, arg, perm) \ __module_param_call(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, 0)
+#define module_param_cbd(name, ops, arg, perm, data) \ + __module_param_call_wdata(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, 0, data) + #define module_param_cb_unsafe(name, ops, arg, perm) \ __module_param_call(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, \ KERNEL_PARAM_FL_UNSAFE) @@ -284,14 +288,17 @@ struct kparam_array
/* This is the fundamental function for registering boot/module parameters. */ -#define __module_param_call(prefix, name, ops, arg, perm, level, flags) \ +#define __module_param_call(prefix, name, ops, arg, perm, level, flags) \ + __module_param_call_wdata(prefix, name, ops, arg, perm, level, flags, NULL) + +#define __module_param_call_wdata(prefix, name, ops, arg, perm, level, flags, data) \ /* Default value instead of permissions? */ \ static const char __param_str_##name[] = prefix #name; \ static struct kernel_param __moduleparam_const __param_##name \ __used __section("__param") \ __aligned(__alignof__(struct kernel_param)) \ = { __param_str_##name, THIS_MODULE, ops, \ - VERIFY_OCTAL_PERMISSIONS(perm), level, flags, { arg } } + VERIFY_OCTAL_PERMISSIONS(perm), level, flags, { arg }, data }
/* Obsolete - use module_param_cb() */ #define module_param_call(name, _set, _get, arg, perm) \
On Fri, Aug 13, 2021 at 09:17:10AM -0600, Jim Cromie wrote:
Add a const void* data member to the struct, to allow attaching private data that will be used soon by a setter method (via kp->data) to perform more elaborate actions.
To attach the data at compile time, add new macros:
module_param_cbd() derives from module_param_cb(), adding data param, and latter is redefined to use former.
It calls __module_param_call_wdata(), which accepts a new data param and inits .data with it. Re-define __module_param_call() to use it.
Use of this new data member will be rare, it might be worth redoing this as a separate/sub-type to de-bloat the base case.
...
+#define module_param_cbd(name, ops, arg, perm, data) \
- __module_param_call_wdata(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, 0, data)
Cryptic name. Moreover, inconsistent with the rest. What about module_param_cb_data() ?
#define module_param_cb_unsafe(name, ops, arg, perm) \ __module_param_call(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, \ KERNEL_PARAM_FL_UNSAFE)
(above left for the above comment)
...
+#define __module_param_call_wdata(prefix, name, ops, arg, perm, level, flags, data) \
Similar __module_param_call_with_data()
On Fri, Aug 13, 2021 at 9:44 AM Andy Shevchenko andriy.shevchenko@linux.intel.com wrote:
On Fri, Aug 13, 2021 at 09:17:10AM -0600, Jim Cromie wrote:
Add a const void* data member to the struct, to allow attaching private data that will be used soon by a setter method (via kp->data) to perform more elaborate actions.
To attach the data at compile time, add new macros:
module_param_cbd() derives from module_param_cb(), adding data param, and latter is redefined to use former.
It calls __module_param_call_wdata(), which accepts a new data param and inits .data with it. Re-define __module_param_call() to use it.
Use of this new data member will be rare, it might be worth redoing this as a separate/sub-type to de-bloat the base case.
...
+#define module_param_cbd(name, ops, arg, perm, data) \
__module_param_call_wdata(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, 0, data)Cryptic name. Moreover, inconsistent with the rest. What about module_param_cb_data() ?
#define module_param_cb_unsafe(name, ops, arg, perm) \ __module_param_call(MODULE_PARAM_PREFIX, name, ops, arg, perm, -1, \ KERNEL_PARAM_FL_UNSAFE)
(above left for the above comment)
...
+#define __module_param_call_wdata(prefix, name, ops, arg, perm, level, flags, data) \
Similar __module_param_call_with_data()
-- With Best Regards, Andy Shevchenko
yes to all renames, revised. thanks
DEFINE_DYNAMIC_DEBUG_CATEGORIES(name, var, bitmap_desc, @bit_descs) allows users to define a drm.debug style (bitmap) sysfs interface, and to specify the desired mapping from bits[0-N] to the format-prefix'd pr_debug()s to be controlled.
DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug_gvt, __gvt_debug, "i915/gvt bitmap desc", /** * search-prefixes, passed to dd-exec_queries * defines bits 0-N in order. * leading ^ is tacitly inserted (by callback currently) * trailing space used here excludes subcats. * helper macro needs more work * macro to autogen ++$i, 0x%x$i ? */ _DD_cat_("gvt:cmd: "), _DD_cat_("gvt:core: "), _DD_cat_("gvt:dpy: "), _DD_cat_("gvt:el: "), _DD_cat_("gvt:irq: "), _DD_cat_("gvt:mm: "), _DD_cat_("gvt:mmio: "), _DD_cat_("gvt:render: "), _DD_cat_("gvt:sched: "));
dynamic_debug.c: add 3 new elements:
- int param_set_dyndbg() - int param_get_dyndbg() - struct kernel_param_ops param_ops_dyndbg
Following the model of kernel/params.c STANDARD_PARAM_DEFS, All 3 are non-static and exported.
dynamic_debug.h:
Add DEFINE_DYNAMIC_DEBUG_CATEGORIES() described above, and a do-nothing stub.
Note that it also calls MODULE_PARM_DESC for the user, but expects the user to catenate all the bit-descriptions together (as is done in drm.debug), and in the following uses in amdgpu, i915.
This in the hope that someone can offer an auto-incrementing label-generating macro, producing "\tbit-4 0x10\t" etc, and can show how to apply it to __VA_ARGS__.
Also extern the struct kernel_param param_ops_dyndbg symbol, as is done in moduleparams.h for all the STANDARD params.
USAGE NOTES:
Using dyndbg to query on "format ^$prefix" requires that the prefix be present in the compiled-in format string; where run-time prefixing is used, that format would be "%s...", which is not usefully selectable.
Adding structural query terms (func,file,lineno) could help (module is already done), but DEFINE_DYNAMIC_DEBUG_CATEGORIES can't do that now, adding it needs a better reason imo.
Dyndbg is completely agnostic wrt the categorization scheme used, to play well with any prefix convention already in use. Ad-hoc categories and sub-categories are implicitly allowed, author discipline and review is expected.
Here are some examples:
"1","2","3" 2 doesnt imply 1. otherwize, sorta like printk levels "1:","2:","3:" are better, avoiding [1-9]\d+ ambiguity "hi:","mid:","low:" are reasonable, and imply independence "todo:","rfc:" might be handy "A:".."Z:" uhm, yeah
Hierarchical classes/categories are natural:
"drm:<CAT>:" is used in later commit "drm:<CAT>:<SUB>:" is a natural extension. "drm:atomic:fail:" has been proposed, sounds directly useful
Some properties of a hierarchical category deserve explication:
Trailing spaces matter !
With 1..3-space ("drm: ", "drm:atomic: ", "drm:atomic:fail: "), the ":" doesnt terminate the search-space, the trailing space does. So a "drm:" search specification will match all DRM categories & subcategories, and will not be useful in an interface where all categories are controlled together. That said, "drm:atomic:" & "drm:atomic: " are different, and both are useful in cases.
Ad-Hoc sub-categories:
These have a caveat wrt wrapper macros adding prefixes like "drm:atomic: "; the trailing space in the prefix means that drm_dbg("fail: ...") renders as "drm:atomic: fail: ", which obviously isn't ideal wrt clear and simple bitmaps.
A possible solution is to have a FOO_() version of every FOO() macro which (anti-mnemonically) elides the trailing space, which is normally inserted by a modified FOO(). Doing this would enforce a policy decision that "debug categories will be space terminated", with an pressure-relief valve.
Summarizing:
- "drm:kms: " & "drm:kms:" are different - "drm:kms" also different - includes drm:kms2: - "drm:kms:\t" also different - "drm:kms:*" doesnt work, no wildcard on format atm.
Order matters in DEFINE_DYNAMIC_DEBUG_CATEGORIES(... @bit_descs)
@bit_descs (array) position determines the bit mapping to the prefix, so to keep a stable map, new categories or 3rd level categories must be added to the end.
Since bits are/will-stay applied 0-N, the later bits can countermand the earlier ones, but its tricky - consider;
DD_CATs(... "drm:atomic:", ""drm:atomic:fail:" ) // misleading
The 1st search-term is misleading, because it includes (modifies) subcategories, but then 2nd overrides it. So don't do that.
There is still plenty of bikeshedding to do.
--- v4+:
. rename to DEFINE_DYNAMIC_DEBUG_CATEGORIES from DEFINE_DYNDBG_BITMAP . in query, replace hardcoded "i915" w kp->mod->name . static inline the stubs . const *str in structs, const array. -Emil . dyndbg: add do-nothing DEFINE_DYNAMIC_DEBUG_CATEGORIES if !DD_CORE . call MOD_PARM_DESC(name, "$desc") for users . simplify callback, remove bit-change detection . config errs reported by lkp@intel.com
ddh-helpers
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- include/linux/dynamic_debug.h | 50 ++++++++++++++++++++++++++++ lib/dynamic_debug.c | 62 ++++++++++++++++++++++++++++++++++- 2 files changed, 111 insertions(+), 1 deletion(-)
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index dce631e678dd..42cfb37d4870 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -52,6 +52,7 @@ struct _ddebug { } __attribute__((aligned(8)));
+struct kernel_param;
#if defined(CONFIG_DYNAMIC_DEBUG_CORE)
@@ -181,6 +182,9 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, KERN_DEBUG, prefix_str, prefix_type, \ rowsize, groupsize, buf, len, ascii)
+int param_set_dyndbg(const char *instr, const struct kernel_param *kp); +int param_get_dyndbg(char *buffer, const struct kernel_param *kp); + #else /* !CONFIG_DYNAMIC_DEBUG_CORE */
#include <linux/string.h> @@ -227,6 +231,52 @@ static inline int dynamic_debug_exec_queries(const char *query, const char *modn return 0; }
+static inline int param_set_dyndbg(const char *instr, const struct kernel_param *kp) +{ return 0; } +static inline int param_get_dyndbg(char *buffer, const struct kernel_param *kp) +{ return 0; } + #endif /* !CONFIG_DYNAMIC_DEBUG_CORE */
+struct dyndbg_bitdesc { + /* bitpos is inferred from index in containing array */ + const char *prefix; + const char *help; +}; + +#if defined(CONFIG_DYNAMIC_DEBUG) || \ + (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE)) +/** + * DEFINE_DYNAMIC_DEBUG_CATEGORIES() - define debug categories, bitmap, sysfs-knob + * @fsname: parameter basename under /sys + * @var: C-identifier holding state + * @_desc: string summarizing the controls provided + * @...: list of struct dyndbg_bitdesc initializations + * + * Defines /sys/modules/$modname/parameters/@fsname, and @bit_descs, + * which maps bits 0-N to categories of pr_debugs to be controlled. + * This is effectively write only, because controlled callsites can be + * further modified via >control. + * + * Also calls MODULE_PARM_DESC(fsname, _desc), with the intent to + * generate the bit_legend and apply it to the given bit_descs + */ +#define DEFINE_DYNAMIC_DEBUG_CATEGORIES(fsname, var, _desc, ...) \ + MODULE_PARM_DESC(fsname, _desc); \ + static struct dyndbg_bitdesc const dyndbg_cats_##fsname[] = \ + { __VA_ARGS__, { NULL, NULL } }; \ + module_param_cbd(fsname, ¶m_ops_dyndbg, &var, 0644, \ + &dyndbg_cats_##fsname); + +#define _DD_cat_(pfx) { .prefix = pfx, .help = "help for " pfx } +#define _DD_cat_help_(pfx) "\t " pfx "\t- help for " pfx "\n" + +extern const struct kernel_param_ops param_ops_dyndbg; +#else +#define DEFINE_DYNAMIC_DEBUG_CATEGORIES(fsname, var, bitmap_desc, ...) \ + MODULE_PARM_DESC(fsname, "auto: " bitmap_desc); +#define _DD_cat_(pfx) +#define _DD_cat_help_(pfx) +#endif + #endif diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index cb5abb42c16a..6bc645a663e7 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -529,7 +529,7 @@ static int ddebug_exec_queries(char *query, const char *modname) if (!query || !*query || *query == '#') continue;
- vpr_info("query %d: "%s"\n", i, query); + vpr_info("query %d: "%s" %s\n", i, query, (modname) ? modname : "");
rc = ddebug_exec_query(query, modname); if (rc < 0) { @@ -1154,3 +1154,63 @@ early_initcall(dynamic_debug_init);
/* Debugfs setup must be done later */ fs_initcall(dynamic_debug_init_control); + +#include <linux/moduleparam.h> + +#define OUR_QUERY_SIZE 128 /* typically need <40 */ + +/** + * param_set_dyndbg() - drm.debug style bitmap to format-prefix categories + * @instr: string echo>d to sysfs + * @kp: struct kernel_param* ->data has bitmap + * Exported to support DEFINE_DYNAMIC_DEBUG_CATEGORIES + */ +int param_set_dyndbg(const char *instr, const struct kernel_param *kp) +{ + unsigned long inbits; + int rc, i, chgct = 0, totct = 0; + char query[OUR_QUERY_SIZE]; + struct dyndbg_bitdesc *bitmap = (struct dyndbg_bitdesc *) kp->data; + + rc = kstrtoul(instr, 0, &inbits); + if (rc) { + pr_err("set_dyndbg: failed\n"); + return -EINVAL; + } + vpr_info("set_dyndbg: input 0x%lx\n", inbits); + + for (i = 0; !!bitmap[i].prefix; i++) { + + sprintf(query, "format '^%s' %cp", bitmap[i].prefix, + test_bit(i, &inbits) ? '+' : '-'); + + chgct = dynamic_debug_exec_queries(query, kp->mod->name); + + v2pr_info("bit-%d: %d changes by '%s'\n", i, chgct, query); + totct += chgct; + } + vpr_info("total changes: %d\n", totct); + return 0; +} +EXPORT_SYMBOL(param_set_dyndbg); + +/** + * param_get_dyndbg() - drm.debug style bitmap to format-prefix categories + * @buffer: string returned to user via sysfs + * @kp: struct kernel_param* + * Exported to support DEFINE_DYNAMIC_DEBUG_CATEGORIES interfaces, not + * useful; pr_debugs may be altered after setting via >control + */ +int param_get_dyndbg(char *buffer, const struct kernel_param *kp) +{ + return scnprintf(buffer, PAGE_SIZE, "%u\n", + *((unsigned int *)kp->arg)); +} +EXPORT_SYMBOL(param_get_dyndbg); + +const struct kernel_param_ops param_ops_dyndbg = { + .set = param_set_dyndbg, + .get = param_get_dyndbg, +}; +/* support DEFINE_DYNAMIC_DEBUG_CATEGORIES users */ +EXPORT_SYMBOL(param_ops_dyndbg);
On Fri, Aug 13, 2021 at 09:17:11AM -0600, Jim Cromie wrote:
DEFINE_DYNAMIC_DEBUG_CATEGORIES(name, var, bitmap_desc, @bit_descs) allows users to define a drm.debug style (bitmap) sysfs interface, and to specify the desired mapping from bits[0-N] to the format-prefix'd pr_debug()s to be controlled.
DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug_gvt, __gvt_debug, "i915/gvt bitmap desc", /** * search-prefixes, passed to dd-exec_queries * defines bits 0-N in order. * leading ^ is tacitly inserted (by callback currently) * trailing space used here excludes subcats. * helper macro needs more work * macro to autogen ++$i, 0x%x$i ? */ _DD_cat_("gvt:cmd: "), _DD_cat_("gvt:core: "), _DD_cat_("gvt:dpy: "), _DD_cat_("gvt:el: "), _DD_cat_("gvt:irq: "), _DD_cat_("gvt:mm: "), _DD_cat_("gvt:mmio: "), _DD_cat_("gvt:render: "), _DD_cat_("gvt:sched: "));
dynamic_debug.c: add 3 new elements:
- int param_set_dyndbg()
- int param_get_dyndbg()
- struct kernel_param_ops param_ops_dyndbg
Following the model of kernel/params.c STANDARD_PARAM_DEFS, All 3 are non-static and exported.
dynamic_debug.h:
Add DEFINE_DYNAMIC_DEBUG_CATEGORIES() described above, and a do-nothing stub.
Note that it also calls MODULE_PARM_DESC for the user, but expects the user to catenate all the bit-descriptions together (as is done in drm.debug), and in the following uses in amdgpu, i915.
This in the hope that someone can offer an auto-incrementing label-generating macro, producing "\tbit-4 0x10\t" etc, and can show how to apply it to __VA_ARGS__.
Also extern the struct kernel_param param_ops_dyndbg symbol, as is done in moduleparams.h for all the STANDARD params.
USAGE NOTES:
Using dyndbg to query on "format ^$prefix" requires that the prefix be present in the compiled-in format string; where run-time prefixing is used, that format would be "%s...", which is not usefully selectable.
Adding structural query terms (func,file,lineno) could help (module is already done), but DEFINE_DYNAMIC_DEBUG_CATEGORIES can't do that now, adding it needs a better reason imo.
Dyndbg is completely agnostic wrt the categorization scheme used, to play well with any prefix convention already in use. Ad-hoc categories and sub-categories are implicitly allowed, author discipline and review is expected.
Here are some examples:
"1","2","3" 2 doesnt imply 1. otherwize, sorta like printk levels "1:","2:","3:" are better, avoiding [1-9]\d+ ambiguity "hi:","mid:","low:" are reasonable, and imply independence "todo:","rfc:" might be handy "A:".."Z:" uhm, yeah
Hierarchical classes/categories are natural:
"drm:<CAT>:" is used in later commit "drm:<CAT>:<SUB>:" is a natural extension. "drm:atomic:fail:" has been proposed, sounds directly useful
Some properties of a hierarchical category deserve explication:
Trailing spaces matter !
With 1..3-space ("drm: ", "drm:atomic: ", "drm:atomic:fail: "), the ":" doesnt terminate the search-space, the trailing space does. So a "drm:" search specification will match all DRM categories & subcategories, and will not be useful in an interface where all categories are controlled together. That said, "drm:atomic:" & "drm:atomic: " are different, and both are useful in cases.
Ad-Hoc sub-categories:
These have a caveat wrt wrapper macros adding prefixes like "drm:atomic: "; the trailing space in the prefix means that drm_dbg("fail: ...") renders as "drm:atomic: fail: ", which obviously isn't ideal wrt clear and simple bitmaps.
A possible solution is to have a FOO_() version of every FOO() macro which (anti-mnemonically) elides the trailing space, which is normally inserted by a modified FOO(). Doing this would enforce a policy decision that "debug categories will be space terminated", with an pressure-relief valve.
Summarizing:
- "drm:kms: " & "drm:kms:" are different
- "drm:kms" also different - includes drm:kms2:
- "drm:kms:\t" also different
- "drm:kms:*" doesnt work, no wildcard on format atm.
Order matters in DEFINE_DYNAMIC_DEBUG_CATEGORIES(... @bit_descs)
@bit_descs (array) position determines the bit mapping to the prefix, so to keep a stable map, new categories or 3rd level categories must be added to the end.
Since bits are/will-stay applied 0-N, the later bits can countermand the earlier ones, but its tricky - consider;
DD_CATs(... "drm:atomic:", ""drm:atomic:fail:" ) // misleadingThe 1st search-term is misleading, because it includes (modifies) subcategories, but then 2nd overrides it. So don't do that.
There is still plenty of bikeshedding to do.
v4+:
. rename to DEFINE_DYNAMIC_DEBUG_CATEGORIES from DEFINE_DYNDBG_BITMAP . in query, replace hardcoded "i915" w kp->mod->name . static inline the stubs . const *str in structs, const array. -Emil . dyndbg: add do-nothing DEFINE_DYNAMIC_DEBUG_CATEGORIES if !DD_CORE . call MOD_PARM_DESC(name, "$desc") for users . simplify callback, remove bit-change detection . config errs reported by lkp@intel.com
ddh-helpers
Signed-off-by: Jim Cromie jim.cromie@gmail.com
So, it is signed or not? I didn't get (perhaps due to misplaced changlog?).
...
} __attribute__((aligned(8)));
Do we need two blank lines here?
+struct kernel_param;
...
+int param_set_dyndbg(const char *instr, const struct kernel_param *kp) +{
- unsigned long inbits;
- int rc, i, chgct = 0, totct = 0;
- char query[OUR_QUERY_SIZE];
- struct dyndbg_bitdesc *bitmap = (struct dyndbg_bitdesc *) kp->data;
So you need space after ')' ?
- rc = kstrtoul(instr, 0, &inbits);
- if (rc) {
pr_err("set_dyndbg: failed\n");
return -EINVAL;
Why not to return rc?
- }
- vpr_info("set_dyndbg: input 0x%lx\n", inbits);
- for (i = 0; !!bitmap[i].prefix; i++) {
Hmm... Why not simply
for (bitmap = ...; bitmap->prefix; bitmap++) {
?
Redundant blank line.
sprintf(query, "format '^%s' %cp", bitmap[i].prefix,test_bit(i, &inbits) ? '+' : '-');
snprintf() ?
chgct = dynamic_debug_exec_queries(query, kp->mod->name);v2pr_info("bit-%d: %d changes by '%s'\n", i, chgct, query);totct += chgct;- }
- vpr_info("total changes: %d\n", totct);
- return 0;
+}
...
- return scnprintf(buffer, PAGE_SIZE, "%u\n",
*((unsigned int *)kp->arg));
One line.
On Fri, Aug 13, 2021 at 06:51:05PM +0300, Andy Shevchenko wrote:
On Fri, Aug 13, 2021 at 09:17:11AM -0600, Jim Cromie wrote:
+int param_set_dyndbg(const char *instr, const struct kernel_param *kp) +{
- unsigned long inbits;
- int rc, i, chgct = 0, totct = 0;
- char query[OUR_QUERY_SIZE];
- struct dyndbg_bitdesc *bitmap = (struct dyndbg_bitdesc *) kp->data;
So you need space after ')' ?
More importantly, if ->data is of type 'void *', it is bad style to cast the pointer at all. I can't tell what type 'data' has; if it is added to kernel_param as part of this series, I wasn't cc'd on the patch that did that.
Taking embedded spaces out of existing prefixes makes them better class-prefixes; simplifying the nested quoting needed otherwise:
$> echo "format '^gvt: core:' +p" >control
Dropping the internal spaces means any trailing space in a query will more clearly terminate the prefix being searched for.
Consider a generic drm-debug example:
# turn off ATOMIC reports echo format "^drm:atomic: " -p > control
# turn off all ATOMIC:* reports, including any sub-categories echo format "^drm:atomic:" -p > control
# turn on ATOMIC:FAIL: reports echo format "^drm:atomic:fail: " +p > control
Removing embedded spaces in the class-prefixes simplifies the corresponding match-prefix. This means that "quoted" match-prefixes are only needed when the trailing space is desired, in order to exclude explicitly sub-categorized pr-debugs; in this example, "drm:atomic:fail:".
RFC: maybe the prefix catenation should paste in the " " class-prefix terminator explicitly. A pr_debug_() flavor could exclude the " ", allowing ad-hoc sub-categorization by appending for example, "fail:" to "drm:atomic:".
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- drivers/gpu/drm/i915/gvt/debug.h | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-)
diff --git a/drivers/gpu/drm/i915/gvt/debug.h b/drivers/gpu/drm/i915/gvt/debug.h index c6027125c1ec..b4021f41c546 100644 --- a/drivers/gpu/drm/i915/gvt/debug.h +++ b/drivers/gpu/drm/i915/gvt/debug.h @@ -36,30 +36,30 @@ do { \ } while (0)
#define gvt_dbg_core(fmt, args...) \ - pr_debug("gvt: core: "fmt, ##args) + pr_debug("gvt:core: "fmt, ##args)
#define gvt_dbg_irq(fmt, args...) \ - pr_debug("gvt: irq: "fmt, ##args) + pr_debug("gvt:irq: "fmt, ##args)
#define gvt_dbg_mm(fmt, args...) \ - pr_debug("gvt: mm: "fmt, ##args) + pr_debug("gvt:mm: "fmt, ##args)
#define gvt_dbg_mmio(fmt, args...) \ - pr_debug("gvt: mmio: "fmt, ##args) + pr_debug("gvt:mmio: "fmt, ##args)
#define gvt_dbg_dpy(fmt, args...) \ - pr_debug("gvt: dpy: "fmt, ##args) + pr_debug("gvt:dpy: "fmt, ##args)
#define gvt_dbg_el(fmt, args...) \ - pr_debug("gvt: el: "fmt, ##args) + pr_debug("gvt:el: "fmt, ##args)
#define gvt_dbg_sched(fmt, args...) \ - pr_debug("gvt: sched: "fmt, ##args) + pr_debug("gvt:sched: "fmt, ##args)
#define gvt_dbg_render(fmt, args...) \ - pr_debug("gvt: render: "fmt, ##args) + pr_debug("gvt:render: "fmt, ##args)
#define gvt_dbg_cmd(fmt, args...) \ - pr_debug("gvt: cmd: "fmt, ##args) + pr_debug("gvt:cmd: "fmt, ##args)
#endif
The gvt component of this driver has ~120 pr_debugs, in 9 categories quite similar to those in DRM. Following the interface model of drm.debug, add a parameter to map bits to these categorizations.
DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug_gvt, __gvt_debug, "dyndbg bitmap desc", { "gvt:cmd: ", "command processing" }, { "gvt:core: ", "core help" }, { "gvt:dpy: ", "display help" }, { "gvt:el: ", "help" }, { "gvt:irq: ", "help" }, { "gvt:mm: ", "help" }, { "gvt:mmio: ", "help" }, { "gvt:render: ", "help" }, { "gvt:sched: " "help" });
The actual patch has a few details different, cmd_help() macro emits the initialization construct.
if CONFIG_DRM_USE_DYNAMIC_DEBUG, then -DDYNAMIC_DEBUG_MODULE is added cflags, by gvt/Makefile.
--- v4+: . static decl of vector of bit->class descriptors - Emil.V . relocate gvt-makefile chunk from elsewhere
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- drivers/gpu/drm/i915/gvt/Makefile | 4 ++++ drivers/gpu/drm/i915/i915_params.c | 35 ++++++++++++++++++++++++++++++ 2 files changed, 39 insertions(+)
diff --git a/drivers/gpu/drm/i915/gvt/Makefile b/drivers/gpu/drm/i915/gvt/Makefile index ea8324abc784..846ba73b8de6 100644 --- a/drivers/gpu/drm/i915/gvt/Makefile +++ b/drivers/gpu/drm/i915/gvt/Makefile @@ -7,3 +7,7 @@ GVT_SOURCE := gvt.o aperture_gm.o handlers.o vgpu.o trace_points.o firmware.o \
ccflags-y += -I $(srctree)/$(src) -I $(srctree)/$(src)/$(GVT_DIR)/ i915-y += $(addprefix $(GVT_DIR)/, $(GVT_SOURCE)) + +#ifdef CONFIG_DRM_USE_DYNAMIC_DEBUG +ccflags-y += -DDYNAMIC_DEBUG_MODULE +#endif diff --git a/drivers/gpu/drm/i915/i915_params.c b/drivers/gpu/drm/i915/i915_params.c index e07f4cfea63a..683e942a074e 100644 --- a/drivers/gpu/drm/i915/i915_params.c +++ b/drivers/gpu/drm/i915/i915_params.c @@ -265,3 +265,38 @@ void i915_params_free(struct i915_params *params) I915_PARAMS_FOR_EACH(FREE); #undef FREE } + +#ifdef DRM_USE_DYNAMIC_DEBUG +/* todo: needs DYNAMIC_DEBUG_MODULE in some cases */ + +unsigned long __gvt_debug; +EXPORT_SYMBOL(__gvt_debug); + +#define _help(key) "\t "" key ""\t: help for " key "\n" + +#define I915_GVT_CATEGORIES(name) \ + " Enable debug output via /sys/module/i915/parameters/" #name \ + ", where each bit enables a debug category.\n" \ + _help("gvt:cmd:") \ + _help("gvt:core:") \ + _help("gvt:dpy:") \ + _help("gvt:el:") \ + _help("gvt:irq:") \ + _help("gvt:mm:") \ + _help("gvt:mmio:") \ + _help("gvt:render:") \ + _help("gvt:sched:") + +DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug_gvt, __gvt_debug, + I915_GVT_CATEGORIES(debug_gvt), + _DD_cat_("gvt:cmd:"), + _DD_cat_("gvt:core:"), + _DD_cat_("gvt:dpy:"), + _DD_cat_("gvt:el:"), + _DD_cat_("gvt:irq:"), + _DD_cat_("gvt:mm:"), + _DD_cat_("gvt:mmio:"), + _DD_cat_("gvt:render:"), + _DD_cat_("gvt:sched:")); + +#endif
logger_types.h defines many DC_LOG_*() categorized debug wrappers. Most of these use DRM debug API, so are controllable using drm.debug, but others use bare pr_debug("$prefix: .."), each with a different class-prefix matching "^[\w+]:"
Use DEFINE_DYNAMIC_DEBUG_CATEGORIES to create a /sys debug_dc parameter, modinfos, and to specify a map from bits -> categorized pr_debugs to be controlled.
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- .../gpu/drm/amd/display/dc/core/dc_debug.c | 44 ++++++++++++++++++- 1 file changed, 43 insertions(+), 1 deletion(-)
diff --git a/drivers/gpu/drm/amd/display/dc/core/dc_debug.c b/drivers/gpu/drm/amd/display/dc/core/dc_debug.c index 21be2a684393..69e68d721512 100644 --- a/drivers/gpu/drm/amd/display/dc/core/dc_debug.c +++ b/drivers/gpu/drm/amd/display/dc/core/dc_debug.c @@ -36,8 +36,50 @@
#include "resource.h"
-#define DC_LOGGER_INIT(logger) +#ifdef DRM_USE_DYNAMIC_DEBUG +/* define a drm.debug style dyndbg pr-debug control point */ +#include <linux/dynamic_debug.h> + +unsigned long __debug_dc; +EXPORT_SYMBOL(__debug_dc); + +#define _help_(key) "\t " key "\t- help for " key "\n" + +/* Id like to do these inside DEFINE_DYNAMIC_DEBUG_CATEGORIES, if possible */ +#define DC_DYNDBG_BITMAP_DESC(name) \ + "Control pr_debugs via /sys/module/amdgpu/parameters/" #name \ + ", where each bit controls a debug category.\n" \ + _help_("[SURFACE]:") \ + _help_("[CURSOR]:") \ + _help_("[PFLIP]:") \ + _help_("[VBLANK]:") \ + _help_("[HW_LINK_TRAINING]:") \ + _help_("[HW_AUDIO]:") \ + _help_("[SCALER]:") \ + _help_("[BIOS]:") \ + _help_("[BANDWIDTH_CALCS]:") \ + _help_("[DML]:") \ + _help_("[IF_TRACE]:") \ + _help_("[GAMMA]:") \ + _help_("[SMU_MSG]:") + +DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug_dc, __debug_dc, + DC_DYNDBG_BITMAP_DESC(debug_dc), + _DD_cat_("[CURSOR]:"), + _DD_cat_("[PFLIP]:"), + _DD_cat_("[VBLANK]:"), + _DD_cat_("[HW_LINK_TRAINING]:"), + _DD_cat_("[HW_AUDIO]:"), + _DD_cat_("[SCALER]:"), + _DD_cat_("[BIOS]:"), + _DD_cat_("[BANDWIDTH_CALCS]:"), + _DD_cat_("[DML]:"), + _DD_cat_("[IF_TRACE]:"), + _DD_cat_("[GAMMA]:"), + _DD_cat_("[SMU_MSG]:")); +#endif
+#define DC_LOGGER_INIT(logger)
#define SURFACE_TRACE(...) do {\ if (dc->debug.surface_trace) \
drm's debug system writes 10 distinct categories of messages to syslog using a small API[1]: drm_dbg*(10 names), DRM_DEBUG*(8 names), DRM_DEV_DEBUG*(3 names). There are thousands of these callsites, each categorized by their authors.
These callsites can be enabled at runtime by their category, each controlled by a bit in drm.debug (/sys/modules/drm/parameter/debug). In the current "basic" implementation, drm_debug_enabled() tests these bits in __drm_debug each time an API[1] call is executed; while cheap individually, the costs accumulate.
This patch uses dynamic-debug with jump-label to patch enabled calls onto their respective NOOP slots, avoiding all runtime bit-checks of __drm_debug.
Dynamic debug has no concept of category, but we can emulate one by replacing enum categories with a set of prefix-strings; "drm:core:", "drm:kms:" "drm:driver:" etc, and prepend them (at compile time) to the given formats.
Then we can use: `echo module drm format "^drm:core: " +p > control`
to enable the whole category with one query.
This conversion yields ~2100 new callsites on my i7/i915 laptop:
dyndbg: 195 debug prints in module drm_kms_helper dyndbg: 298 debug prints in module drm dyndbg: 1630 debug prints in module i915
CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if CONFIG_JUMP_LABEL is enabled; this because its required to get the promised optimizations.
The "basic" -> "dyndbg" switchover is layered into the macro scheme
A. use DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug, __drm_debug, "DRM debug category-per-bit control", { "drm:core:", "enable CORE debug messages" }, { "drm:kms:", "enable KMS debug messages" }, ...);
B. A "classy" version of DRM_UT_<CATs> map, named DRM_DBG_CAT_<CATs>
DRM_DBG_CLASS_<CATs> was proposed, I had agreed, but reconsidered; CATEGORY is already DRM's term-of-art, and adding a near-synonym 'CLASS' only adds ambiguity.
"basic": DRM_DBG_CAT_<CATs> <=== DRM_UT_<CATs>. Identity map. "dyndbg": #define DRM_DBG_CAT_KMS "drm:kms: " #define DRM_DBG_CAT_PRIME "drm:prime: " #define DRM_DBG_CAT_ATOMIC "drm:atomic: "
DRM_UT_* are preserved, since theyre used elsewhere. We can probably reduce its use further, but thats a separate thing.
C. drm_dev_dbg() & drm_debug() are interposed with macros
basic: forward to renamed fn, with args preserved enabled: redirect to pr_debug, dev_dbg, with CATEGORY # format
this is where drm_debug_enabled() is avoided. prefix is prepended at compile-time, no category at runtime.
D. API[1] uses DRM_DBG_CAT_<CAT>s these already use (C), now they use (B) too, to get the correct token type for "basic" and "dyndbg" configs.
NOTES:
Code Review is expected to catch lack of correspondence between bit=>prefix definitions (the selector) and the prefixes used in the API[1] layer above pr_debug()
I've coded the search-prefixes/categories with a trailing space, which excludes any sub-categories added later. This convention protects any "drm:atomic:fail:" callsites from getting stomped on by `echo 0 > debug`. Other categories could differ, but we need some default.
Dyndbg requires that the prefix be in the compiled-in format string; run-time prefixing evades callsite selection by category.
pr_debug("%s: ...", __func__, ...) // not ideal
With "lineno X" in a query, its possible to enable single callsites, but it is tedious, and useless in a category context.
Unfortunately __func__ is not a macro, and cannot be catenated at preprocess/compile time.
pr_debug("Entry: ...") // +fml gives useful log-info pr_debug("Exit: ...") // hard to catch them all
But "func foo" added to query-command would work, should it be useful enough to justify extending the declarative interface.
--- v4+:
. use DEFINE_DYNAMIC_DEBUG_CATEGORIES in drm_print.c . s/DRM_DBG_CLASS_/DRM_DBG_CAT_/ - dont need another term . default=y in KBuild entry - per @DanVet . move some commit-log prose to dyndbg commit . add-prototyes to (param_get/set)_dyndbg . more wrinkles found by lkp@intel.com . relocate ratelimit chunk from elsewhere . add kernel doc
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- drivers/gpu/drm/Kconfig | 13 ++++ drivers/gpu/drm/drm_print.c | 49 +++++++++---- include/drm/drm_print.h | 141 ++++++++++++++++++++++++++++-------- 3 files changed, 159 insertions(+), 44 deletions(-)
diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig index 7ff89690a976..97e38d86fd27 100644 --- a/drivers/gpu/drm/Kconfig +++ b/drivers/gpu/drm/Kconfig @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
If in doubt, say "N".
+config DRM_USE_DYNAMIC_DEBUG + bool "use dynamic debug to implement drm.debug" + default y + depends on DRM + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE + depends on JUMP_LABEL + help + The "basic" drm.debug facility does a lot of unlikely + bit-field tests at runtime; while cheap individually, the + cost accumulates. DYNAMIC_DEBUG patches pr_debug()s in/out + of the running kernel, so avoids those bit-test overheads, + and is therefore recommended. + config DRM_DEBUG_SELFTEST tristate "kselftests for DRM" depends on DRM diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 111b932cf2a9..72b940a30779 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -28,6 +28,7 @@ #include <stdarg.h>
#include <linux/io.h> +#include <linux/module.h> #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> @@ -43,16 +44,36 @@ unsigned int __drm_debug; EXPORT_SYMBOL(__drm_debug);
-MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" -"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" -"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" -"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" -"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" -"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" -"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" -"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" -"\t\tBit 8 (0x100) will enable DP messages (displayport code)"); +#define DRM_DEBUG_DESC \ +"Enable debug output, where each bit enables a debug category.\n" \ +"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" \ +"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" \ +"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" \ +"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" \ +"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" \ +"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" \ +"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" \ +"\t\tBit 8 (0x100) will enable DP messages (displayport code)." + +#ifdef CONFIG_DRM_USE_DYNAMIC_DEBUG +#include <linux/dynamic_debug.h> +DEFINE_DYNAMIC_DEBUG_CATEGORIES(debug, __drm_debug, + DRM_DEBUG_DESC, + _DD_cat_(DRM_DBG_CAT_CORE), + _DD_cat_(DRM_DBG_CAT_DRIVER), + _DD_cat_(DRM_DBG_CAT_KMS), + _DD_cat_(DRM_DBG_CAT_PRIME), + _DD_cat_(DRM_DBG_CAT_ATOMIC), + _DD_cat_(DRM_DBG_CAT_VBL), + _DD_cat_(DRM_DBG_CAT_STATE), + _DD_cat_(DRM_DBG_CAT_LEASE), + _DD_cat_(DRM_DBG_CAT_DP), + _DD_cat_(DRM_DBG_CAT_DRMRES)); + +#else +MODULE_PARM_DESC(debug, DRM_DEBUG_DESC); module_param_named(debug, __drm_debug, int, 0600); +#endif
void __drm_puts_coredump(struct drm_printer *p, const char *str) { @@ -256,8 +277,8 @@ void drm_dev_printk(const struct device *dev, const char *level, } EXPORT_SYMBOL(drm_dev_printk);
-void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...) +void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, + const char *format, ...) { struct va_format vaf; va_list args; @@ -278,9 +299,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
va_end(args); } -EXPORT_SYMBOL(drm_dev_dbg); +EXPORT_SYMBOL(__drm_dev_dbg);
-void __drm_dbg(enum drm_debug_category category, const char *format, ...) +void ___drm_dbg(enum drm_debug_category category, const char *format, ...) { struct va_format vaf; va_list args; @@ -297,7 +318,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
va_end(args); } -EXPORT_SYMBOL(__drm_dbg); +EXPORT_SYMBOL(___drm_dbg);
void __drm_err(const char *format, ...) { diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 15a089a87c22..aca56b456277 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -252,15 +252,15 @@ static inline struct drm_printer drm_err_printer(const char *prefix) /** * enum drm_debug_category - The DRM debug categories * - * Each of the DRM debug logging macros use a specific category, and the logging - * is filtered by the drm.debug module parameter. This enum specifies the values - * for the interface. + * The drm.debug logging API[1] has 10 enumerated categories of + * messages, issued by 3 families of macros: 10 drm_dbg_<CATs>, 8 + * DRM_DEBUG_<CATs>, and 3 DRM_DEV_DEBUG_<CATs>. * * Each DRM_DEBUG_<CATEGORY> macro logs to DRM_UT_<CATEGORY> category, except * DRM_DEBUG() logs to DRM_UT_CORE. * - * Enabling verbose debug messages is done through the drm.debug parameter, each - * category being enabled by a bit: + * Enabling categories of debug messages is done through the drm.debug + * parameter, each category being enabled by a bit: * * - drm.debug=0x1 will enable CORE messages * - drm.debug=0x2 will enable DRIVER messages @@ -319,6 +319,85 @@ enum drm_debug_category { DRM_UT_DRMRES = 0x200, };
+/** + * DOC: DRM_USE_DYNAMIC_DEBUG - using dyndbg in drm.debug + * + * In the "basic" drm.debug implementation outlined above, each time a + * drm-debug API[1] call is executed, drm_debug_enabled(cat) tests + * drm.debug vs cat before printing. + * + * DYNAMIC_DEBUG (aka: dyndbg) patches pr_debug()s in^out of the + * running kernel, so it can avoid drm_debug_enabled() and skip lots + * of unlikely bit tests. + * + * dyndbg has no concept of category, but we can prepend a + * class-prefix string: "drm:core: ", "drm:kms: ", "drm:driver: " etc, + * to pr_debug's format (at compile time). + * + * Then control the category + * `echo module drm format "^drm:core: " +p > control` + * `dynamic_debug_exec_queries("format '^drm:core: ' +p", "drm");` + * + * To do this for "basic" | "dyndbg", adaptation adds some macro indirection: + * + * 0. use dyndbg support to define the bits => prefixes map, attach callback. + * + * DYNDBG_BITMAP_DESC(debug, __drm_debug, + * "drm.debug - overview", + * { "drm:core:", "enable CORE debug messages" }, + * { "drm:kms:", "enable KMS debug messages" }, ...); + * + * 1. DRM_DBG_CAT_<CAT> + * + * This set of symbols replaces DRM_UT_<CAT> in the drm-debug API; it + * is either a copy of DRM_UT_<CAT>, or the class-prefix strings. + * + * 2. drm_dev_dbg & drm_debug are called by drm.debug API + * + * These are now macros, either forwarding to renamed functions, or + * prepending the class string to the format, and invoking pr_debug + * directly. Since the API is all macros, dyndbg remembers + * per-pr_debug: module,file,func,line,format and uses that to find + * and enable them. + */ +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) + +#define __drm_dbg(cls, fmt, ...) \ + ___drm_dbg(cls, fmt, ##__VA_ARGS__) +#define drm_dev_dbg(dev, cls, fmt, ...) \ + __drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__) + +#define DRM_DBG_CAT_CORE DRM_UT_CORE +#define DRM_DBG_CAT_DRIVER DRM_UT_DRIVER +#define DRM_DBG_CAT_KMS DRM_UT_KMS +#define DRM_DBG_CAT_PRIME DRM_UT_PRIME +#define DRM_DBG_CAT_ATOMIC DRM_UT_ATOMIC +#define DRM_DBG_CAT_VBL DRM_UT_VBL +#define DRM_DBG_CAT_STATE DRM_UT_STATE +#define DRM_DBG_CAT_LEASE DRM_UT_LEASE +#define DRM_DBG_CAT_DP DRM_UT_DP +#define DRM_DBG_CAT_DRMRES DRM_UT_DRMRES + +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */ + +#define __drm_dbg(cls, fmt, ...) \ + pr_debug(cls # fmt, ##__VA_ARGS__) +#define drm_dev_dbg(dev, cls, fmt, ...) \ + dev_dbg(dev, cls # fmt, ##__VA_ARGS__) + +#define DRM_DBG_CAT_CORE "drm:core: " +#define DRM_DBG_CAT_DRIVER "drm:drvr: " +#define DRM_DBG_CAT_KMS "drm:kms: " +#define DRM_DBG_CAT_PRIME "drm:prime: " +#define DRM_DBG_CAT_ATOMIC "drm:atomic: " +#define DRM_DBG_CAT_VBL "drm:vbl: " +#define DRM_DBG_CAT_STATE "drm:state: " +#define DRM_DBG_CAT_LEASE "drm:lease: " +#define DRM_DBG_CAT_DP "drm:dp: " +#define DRM_DBG_CAT_DRMRES "drm:res " + +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */ + static inline bool drm_debug_enabled(enum drm_debug_category category) { return unlikely(__drm_debug & category); @@ -334,8 +413,8 @@ __printf(3, 4) void drm_dev_printk(const struct device *dev, const char *level, const char *format, ...); __printf(3, 4) -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...); +void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, + const char *format, ...);
/** * DRM_DEV_ERROR() - Error output. @@ -383,7 +462,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, * @fmt: printf() like format string. */ #define DRM_DEV_DEBUG(dev, fmt, ...) \ - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__) + drm_dev_dbg(dev, DRM_DBG_CAT_CORE, fmt, ##__VA_ARGS__) /** * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver * @@ -391,7 +470,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, * @fmt: printf() like format string. */ #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \ - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__) + drm_dev_dbg(dev, DRM_DBG_CAT_DRIVER, fmt, ##__VA_ARGS__) /** * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code * @@ -399,7 +478,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, * @fmt: printf() like format string. */ #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \ - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__) + drm_dev_dbg(dev, DRM_DBG_CAT_KMS, fmt, ##__VA_ARGS__)
/* * struct drm_device based logging @@ -443,25 +522,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
#define drm_dbg_core(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_CORE, fmt, ##__VA_ARGS__) #define drm_dbg(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_DRIVER, fmt, ##__VA_ARGS__) #define drm_dbg_kms(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_KMS, fmt, ##__VA_ARGS__) #define drm_dbg_prime(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_PRIME, fmt, ##__VA_ARGS__) #define drm_dbg_atomic(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_ATOMIC, fmt, ##__VA_ARGS__) #define drm_dbg_vbl(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_VBL, fmt, ##__VA_ARGS__) #define drm_dbg_state(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_STATE, fmt, ##__VA_ARGS__) #define drm_dbg_lease(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_LEASE, fmt, ##__VA_ARGS__) #define drm_dbg_dp(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_DP, fmt, ##__VA_ARGS__) #define drm_dbg_drmres(drm, fmt, ...) \ - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__) + drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_DBG_CAT_DRMRES, fmt, ##__VA_ARGS__)
/* @@ -471,7 +550,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, */
__printf(2, 3) -void __drm_dbg(enum drm_debug_category category, const char *format, ...); +void ___drm_dbg(enum drm_debug_category category, const char *format, ...); __printf(1, 2) void __drm_err(const char *format, ...);
@@ -500,29 +579,30 @@ void __drm_err(const char *format, ...); #define DRM_ERROR_RATELIMITED(fmt, ...) \ DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
+ #define DRM_DEBUG(fmt, ...) \ - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_CORE, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_DRIVER(fmt, ...) \ - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_DRIVER, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_KMS(fmt, ...) \ - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_KMS, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_PRIME(fmt, ...) \ - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_PRIME, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_ATOMIC(fmt, ...) \ - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_ATOMIC, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_VBL(fmt, ...) \ - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_VBL, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_LEASE(fmt, ...) \ - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_LEASE, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_DP(fmt, ...) \ - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__) + __drm_dbg(DRM_DBG_CAT_DP, fmt, ## __VA_ARGS__)
#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \ ({ \ @@ -530,7 +610,8 @@ void __drm_err(const char *format, ...); const struct drm_device *drm_ = (drm); \ \ if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_)) \ - drm_dev_printk(drm_ ? drm_->dev : NULL, KERN_DEBUG, fmt, ## __VA_ARGS__); \ + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \ + DRM_DBG_CAT_ ## category, fmt, ##__VA_ARGS__); \ })
#define drm_dbg_kms_ratelimited(drm, fmt, ...) \
There are blocks of DRM_DEBUG calls, consolidate their args into single calls. With dynamic-debug in use, each callsite consumes 56 bytes of ro callsite data, and this patch removes about 65 calls, so it saves ~3.5kb.
no functional changes.
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- drivers/gpu/drm/amd/amdgpu/amdgpu_ucode.c | 293 ++++++++++++---------- 1 file changed, 158 insertions(+), 135 deletions(-)
diff --git a/drivers/gpu/drm/amd/amdgpu/amdgpu_ucode.c b/drivers/gpu/drm/amd/amdgpu/amdgpu_ucode.c index 2834981f8c08..14a9fef1f4c6 100644 --- a/drivers/gpu/drm/amd/amdgpu/amdgpu_ucode.c +++ b/drivers/gpu/drm/amd/amdgpu/amdgpu_ucode.c @@ -30,17 +30,26 @@
static void amdgpu_ucode_print_common_hdr(const struct common_firmware_header *hdr) { - DRM_DEBUG("size_bytes: %u\n", le32_to_cpu(hdr->size_bytes)); - DRM_DEBUG("header_size_bytes: %u\n", le32_to_cpu(hdr->header_size_bytes)); - DRM_DEBUG("header_version_major: %u\n", le16_to_cpu(hdr->header_version_major)); - DRM_DEBUG("header_version_minor: %u\n", le16_to_cpu(hdr->header_version_minor)); - DRM_DEBUG("ip_version_major: %u\n", le16_to_cpu(hdr->ip_version_major)); - DRM_DEBUG("ip_version_minor: %u\n", le16_to_cpu(hdr->ip_version_minor)); - DRM_DEBUG("ucode_version: 0x%08x\n", le32_to_cpu(hdr->ucode_version)); - DRM_DEBUG("ucode_size_bytes: %u\n", le32_to_cpu(hdr->ucode_size_bytes)); - DRM_DEBUG("ucode_array_offset_bytes: %u\n", - le32_to_cpu(hdr->ucode_array_offset_bytes)); - DRM_DEBUG("crc32: 0x%08x\n", le32_to_cpu(hdr->crc32)); + DRM_DEBUG("size_bytes: %u\n" + "header_size_bytes: %u\n" + "header_version_major: %u\n" + "header_version_minor: %u\n" + "ip_version_major: %u\n" + "ip_version_minor: %u\n" + "ucode_version: 0x%08x\n" + "ucode_size_bytes: %u\n" + "ucode_array_offset_bytes: %u\n" + "crc32: 0x%08x\n", + le32_to_cpu(hdr->size_bytes), + le32_to_cpu(hdr->header_size_bytes), + le16_to_cpu(hdr->header_version_major), + le16_to_cpu(hdr->header_version_minor), + le16_to_cpu(hdr->ip_version_major), + le16_to_cpu(hdr->ip_version_minor), + le32_to_cpu(hdr->ucode_version), + le32_to_cpu(hdr->ucode_size_bytes), + le32_to_cpu(hdr->ucode_array_offset_bytes), + le32_to_cpu(hdr->crc32)); }
void amdgpu_ucode_print_mc_hdr(const struct common_firmware_header *hdr) @@ -55,9 +64,9 @@ void amdgpu_ucode_print_mc_hdr(const struct common_firmware_header *hdr) const struct mc_firmware_header_v1_0 *mc_hdr = container_of(hdr, struct mc_firmware_header_v1_0, header);
- DRM_DEBUG("io_debug_size_bytes: %u\n", - le32_to_cpu(mc_hdr->io_debug_size_bytes)); - DRM_DEBUG("io_debug_array_offset_bytes: %u\n", + DRM_DEBUG("io_debug_size_bytes: %u\n" + "io_debug_array_offset_bytes: %u\n", + le32_to_cpu(mc_hdr->io_debug_size_bytes), le32_to_cpu(mc_hdr->io_debug_array_offset_bytes)); } else { DRM_ERROR("Unknown MC ucode version: %u.%u\n", version_major, version_minor); @@ -82,13 +91,17 @@ void amdgpu_ucode_print_smc_hdr(const struct common_firmware_header *hdr) switch (version_minor) { case 0: v2_0_hdr = container_of(hdr, struct smc_firmware_header_v2_0, v1_0.header); - DRM_DEBUG("ppt_offset_bytes: %u\n", le32_to_cpu(v2_0_hdr->ppt_offset_bytes)); - DRM_DEBUG("ppt_size_bytes: %u\n", le32_to_cpu(v2_0_hdr->ppt_size_bytes)); + DRM_DEBUG("ppt_offset_bytes: %u\n" + "ppt_size_bytes: %u\n", + le32_to_cpu(v2_0_hdr->ppt_offset_bytes), + le32_to_cpu(v2_0_hdr->ppt_size_bytes)); break; case 1: v2_1_hdr = container_of(hdr, struct smc_firmware_header_v2_1, v1_0.header); - DRM_DEBUG("pptable_count: %u\n", le32_to_cpu(v2_1_hdr->pptable_count)); - DRM_DEBUG("pptable_entry_offset: %u\n", le32_to_cpu(v2_1_hdr->pptable_entry_offset)); + DRM_DEBUG("pptable_count: %u\n" + "pptable_entry_offset: %u\n", + le32_to_cpu(v2_1_hdr->pptable_count), + le32_to_cpu(v2_1_hdr->pptable_entry_offset)); break; default: break; @@ -111,10 +124,12 @@ void amdgpu_ucode_print_gfx_hdr(const struct common_firmware_header *hdr) const struct gfx_firmware_header_v1_0 *gfx_hdr = container_of(hdr, struct gfx_firmware_header_v1_0, header);
- DRM_DEBUG("ucode_feature_version: %u\n", - le32_to_cpu(gfx_hdr->ucode_feature_version)); - DRM_DEBUG("jt_offset: %u\n", le32_to_cpu(gfx_hdr->jt_offset)); - DRM_DEBUG("jt_size: %u\n", le32_to_cpu(gfx_hdr->jt_size)); + DRM_DEBUG("ucode_feature_version: %u\n" + "jt_offset: %u\n" + "jt_size: %u\n", + le32_to_cpu(gfx_hdr->ucode_feature_version), + le32_to_cpu(gfx_hdr->jt_offset), + le32_to_cpu(gfx_hdr->jt_size)); } else { DRM_ERROR("Unknown GFX ucode version: %u.%u\n", version_major, version_minor); } @@ -132,82 +147,88 @@ void amdgpu_ucode_print_rlc_hdr(const struct common_firmware_header *hdr) const struct rlc_firmware_header_v1_0 *rlc_hdr = container_of(hdr, struct rlc_firmware_header_v1_0, header);
- DRM_DEBUG("ucode_feature_version: %u\n", - le32_to_cpu(rlc_hdr->ucode_feature_version)); - DRM_DEBUG("save_and_restore_offset: %u\n", - le32_to_cpu(rlc_hdr->save_and_restore_offset)); - DRM_DEBUG("clear_state_descriptor_offset: %u\n", - le32_to_cpu(rlc_hdr->clear_state_descriptor_offset)); - DRM_DEBUG("avail_scratch_ram_locations: %u\n", - le32_to_cpu(rlc_hdr->avail_scratch_ram_locations)); - DRM_DEBUG("master_pkt_description_offset: %u\n", + DRM_DEBUG("ucode_feature_version: %u\n" + "save_and_restore_offset: %u\n" + "clear_state_descriptor_offset: %u\n" + "avail_scratch_ram_locations: %u\n" + "master_pkt_description_offset: %u\n", + le32_to_cpu(rlc_hdr->ucode_feature_version), + le32_to_cpu(rlc_hdr->save_and_restore_offset), + le32_to_cpu(rlc_hdr->clear_state_descriptor_offset), + le32_to_cpu(rlc_hdr->avail_scratch_ram_locations), le32_to_cpu(rlc_hdr->master_pkt_description_offset)); + } else if (version_major == 2) { const struct rlc_firmware_header_v2_0 *rlc_hdr = container_of(hdr, struct rlc_firmware_header_v2_0, header);
- DRM_DEBUG("ucode_feature_version: %u\n", - le32_to_cpu(rlc_hdr->ucode_feature_version)); - DRM_DEBUG("jt_offset: %u\n", le32_to_cpu(rlc_hdr->jt_offset)); - DRM_DEBUG("jt_size: %u\n", le32_to_cpu(rlc_hdr->jt_size)); - DRM_DEBUG("save_and_restore_offset: %u\n", - le32_to_cpu(rlc_hdr->save_and_restore_offset)); - DRM_DEBUG("clear_state_descriptor_offset: %u\n", - le32_to_cpu(rlc_hdr->clear_state_descriptor_offset)); - DRM_DEBUG("avail_scratch_ram_locations: %u\n", - le32_to_cpu(rlc_hdr->avail_scratch_ram_locations)); - DRM_DEBUG("reg_restore_list_size: %u\n", - le32_to_cpu(rlc_hdr->reg_restore_list_size)); - DRM_DEBUG("reg_list_format_start: %u\n", - le32_to_cpu(rlc_hdr->reg_list_format_start)); - DRM_DEBUG("reg_list_format_separate_start: %u\n", + DRM_DEBUG("ucode_feature_version: %u\n" + "jt_offset: %u\n" + "jt_size: %u\n" + "save_and_restore_offset: %u\n" + "clear_state_descriptor_offset: %u\n" + "avail_scratch_ram_locations: %u\n" + "reg_restore_list_size: %u\n" + "reg_list_format_start: %u\n" + "reg_list_format_separate_start: %u\n", + le32_to_cpu(rlc_hdr->ucode_feature_version), + le32_to_cpu(rlc_hdr->jt_offset), + le32_to_cpu(rlc_hdr->jt_size), + le32_to_cpu(rlc_hdr->save_and_restore_offset), + le32_to_cpu(rlc_hdr->clear_state_descriptor_offset), + le32_to_cpu(rlc_hdr->avail_scratch_ram_locations), + le32_to_cpu(rlc_hdr->reg_restore_list_size), + le32_to_cpu(rlc_hdr->reg_list_format_start), le32_to_cpu(rlc_hdr->reg_list_format_separate_start)); - DRM_DEBUG("starting_offsets_start: %u\n", - le32_to_cpu(rlc_hdr->starting_offsets_start)); - DRM_DEBUG("reg_list_format_size_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_format_size_bytes)); - DRM_DEBUG("reg_list_format_array_offset_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_format_array_offset_bytes)); - DRM_DEBUG("reg_list_size_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_size_bytes)); - DRM_DEBUG("reg_list_array_offset_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_array_offset_bytes)); - DRM_DEBUG("reg_list_format_separate_size_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_format_separate_size_bytes)); - DRM_DEBUG("reg_list_format_separate_array_offset_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_format_separate_array_offset_bytes)); - DRM_DEBUG("reg_list_separate_size_bytes: %u\n", - le32_to_cpu(rlc_hdr->reg_list_separate_size_bytes)); - DRM_DEBUG("reg_list_separate_array_offset_bytes: %u\n", + + DRM_DEBUG("starting_offsets_start: %u\n" + "reg_list_format_size_bytes: %u\n" + "reg_list_format_array_offset_bytes: %u\n" + "reg_list_size_bytes: %u\n" + "reg_list_array_offset_bytes: %u\n" + "reg_list_format_separate_size_bytes: %u\n" + "reg_list_format_separate_array_offset_bytes: %u\n" + "reg_list_separate_size_bytes: %u\n" + "reg_list_separate_array_offset_bytes: %u\n", + le32_to_cpu(rlc_hdr->starting_offsets_start), + le32_to_cpu(rlc_hdr->reg_list_format_size_bytes), + le32_to_cpu(rlc_hdr->reg_list_format_array_offset_bytes), + le32_to_cpu(rlc_hdr->reg_list_size_bytes), + le32_to_cpu(rlc_hdr->reg_list_array_offset_bytes), + le32_to_cpu(rlc_hdr->reg_list_format_separate_size_bytes), + le32_to_cpu(rlc_hdr->reg_list_format_separate_array_offset_bytes), + le32_to_cpu(rlc_hdr->reg_list_separate_size_bytes), le32_to_cpu(rlc_hdr->reg_list_separate_array_offset_bytes)); + if (version_minor == 1) { const struct rlc_firmware_header_v2_1 *v2_1 = container_of(rlc_hdr, struct rlc_firmware_header_v2_1, v2_0); - DRM_DEBUG("reg_list_format_direct_reg_list_length: %u\n", - le32_to_cpu(v2_1->reg_list_format_direct_reg_list_length)); - DRM_DEBUG("save_restore_list_cntl_ucode_ver: %u\n", - le32_to_cpu(v2_1->save_restore_list_cntl_ucode_ver)); - DRM_DEBUG("save_restore_list_cntl_feature_ver: %u\n", - le32_to_cpu(v2_1->save_restore_list_cntl_feature_ver)); - DRM_DEBUG("save_restore_list_cntl_size_bytes %u\n", - le32_to_cpu(v2_1->save_restore_list_cntl_size_bytes)); - DRM_DEBUG("save_restore_list_cntl_offset_bytes: %u\n", - le32_to_cpu(v2_1->save_restore_list_cntl_offset_bytes)); - DRM_DEBUG("save_restore_list_gpm_ucode_ver: %u\n", - le32_to_cpu(v2_1->save_restore_list_gpm_ucode_ver)); - DRM_DEBUG("save_restore_list_gpm_feature_ver: %u\n", - le32_to_cpu(v2_1->save_restore_list_gpm_feature_ver)); - DRM_DEBUG("save_restore_list_gpm_size_bytes %u\n", - le32_to_cpu(v2_1->save_restore_list_gpm_size_bytes)); - DRM_DEBUG("save_restore_list_gpm_offset_bytes: %u\n", - le32_to_cpu(v2_1->save_restore_list_gpm_offset_bytes)); - DRM_DEBUG("save_restore_list_srm_ucode_ver: %u\n", - le32_to_cpu(v2_1->save_restore_list_srm_ucode_ver)); - DRM_DEBUG("save_restore_list_srm_feature_ver: %u\n", - le32_to_cpu(v2_1->save_restore_list_srm_feature_ver)); - DRM_DEBUG("save_restore_list_srm_size_bytes %u\n", - le32_to_cpu(v2_1->save_restore_list_srm_size_bytes)); - DRM_DEBUG("save_restore_list_srm_offset_bytes: %u\n", + + DRM_DEBUG("reg_list_format_direct_reg_list_length: %u\n" + "save_restore_list_cntl_ucode_ver: %u\n" + "save_restore_list_cntl_feature_ver: %u\n" + "save_restore_list_cntl_size_bytes %u\n" + "save_restore_list_cntl_offset_bytes: %u\n" + "save_restore_list_gpm_ucode_ver: %u\n" + "save_restore_list_gpm_feature_ver: %u\n" + "save_restore_list_gpm_size_bytes %u\n" + "save_restore_list_gpm_offset_bytes: %u\n" + "save_restore_list_srm_ucode_ver: %u\n" + "save_restore_list_srm_feature_ver: %u\n" + "save_restore_list_srm_size_bytes %u\n" + "save_restore_list_srm_offset_bytes: %u\n", + le32_to_cpu(v2_1->reg_list_format_direct_reg_list_length), + le32_to_cpu(v2_1->save_restore_list_cntl_ucode_ver), + le32_to_cpu(v2_1->save_restore_list_cntl_feature_ver), + le32_to_cpu(v2_1->save_restore_list_cntl_size_bytes), + le32_to_cpu(v2_1->save_restore_list_cntl_offset_bytes), + le32_to_cpu(v2_1->save_restore_list_gpm_ucode_ver), + le32_to_cpu(v2_1->save_restore_list_gpm_feature_ver), + le32_to_cpu(v2_1->save_restore_list_gpm_size_bytes), + le32_to_cpu(v2_1->save_restore_list_gpm_offset_bytes), + le32_to_cpu(v2_1->save_restore_list_srm_ucode_ver), + le32_to_cpu(v2_1->save_restore_list_srm_feature_ver), + le32_to_cpu(v2_1->save_restore_list_srm_size_bytes), le32_to_cpu(v2_1->save_restore_list_srm_offset_bytes)); } } else { @@ -227,12 +248,14 @@ void amdgpu_ucode_print_sdma_hdr(const struct common_firmware_header *hdr) const struct sdma_firmware_header_v1_0 *sdma_hdr = container_of(hdr, struct sdma_firmware_header_v1_0, header);
- DRM_DEBUG("ucode_feature_version: %u\n", - le32_to_cpu(sdma_hdr->ucode_feature_version)); - DRM_DEBUG("ucode_change_version: %u\n", - le32_to_cpu(sdma_hdr->ucode_change_version)); - DRM_DEBUG("jt_offset: %u\n", le32_to_cpu(sdma_hdr->jt_offset)); - DRM_DEBUG("jt_size: %u\n", le32_to_cpu(sdma_hdr->jt_size)); + DRM_DEBUG("ucode_feature_version: %u\n" + "ucode_change_version: %u\n" + "jt_offset: %u\n" + "jt_size: %u\n", + le32_to_cpu(sdma_hdr->ucode_feature_version), + le32_to_cpu(sdma_hdr->ucode_change_version), + le32_to_cpu(sdma_hdr->jt_offset), + le32_to_cpu(sdma_hdr->jt_size)); if (version_minor >= 1) { const struct sdma_firmware_header_v1_1 *sdma_v1_1_hdr = container_of(sdma_hdr, struct sdma_firmware_header_v1_1, v1_0); @@ -256,36 +279,36 @@ void amdgpu_ucode_print_psp_hdr(const struct common_firmware_header *hdr) const struct psp_firmware_header_v1_0 *psp_hdr = container_of(hdr, struct psp_firmware_header_v1_0, header);
- DRM_DEBUG("ucode_feature_version: %u\n", - le32_to_cpu(psp_hdr->sos.fw_version)); - DRM_DEBUG("sos_offset_bytes: %u\n", - le32_to_cpu(psp_hdr->sos.offset_bytes)); - DRM_DEBUG("sos_size_bytes: %u\n", + DRM_DEBUG("ucode_feature_version: %u\n" + "sos_offset_bytes: %u\n" + "sos_size_bytes: %u\n", + le32_to_cpu(psp_hdr->sos.fw_version), + le32_to_cpu(psp_hdr->sos.offset_bytes), le32_to_cpu(psp_hdr->sos.size_bytes)); if (version_minor == 1) { const struct psp_firmware_header_v1_1 *psp_hdr_v1_1 = container_of(psp_hdr, struct psp_firmware_header_v1_1, v1_0); - DRM_DEBUG("toc_header_version: %u\n", - le32_to_cpu(psp_hdr_v1_1->toc.fw_version)); - DRM_DEBUG("toc_offset_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_1->toc.offset_bytes)); - DRM_DEBUG("toc_size_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_1->toc.size_bytes)); - DRM_DEBUG("kdb_header_version: %u\n", - le32_to_cpu(psp_hdr_v1_1->kdb.fw_version)); - DRM_DEBUG("kdb_offset_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_1->kdb.offset_bytes)); - DRM_DEBUG("kdb_size_bytes: %u\n", + DRM_DEBUG("toc_header_version: %u\n" + "toc_offset_bytes: %u\n" + "toc_size_bytes: %u\n" + "kdb_header_version: %u\n" + "kdb_offset_bytes: %u\n" + "kdb_size_bytes: %u\n", + le32_to_cpu(psp_hdr_v1_1->toc.fw_version), + le32_to_cpu(psp_hdr_v1_1->toc.offset_bytes), + le32_to_cpu(psp_hdr_v1_1->toc.size_bytes), + le32_to_cpu(psp_hdr_v1_1->kdb.fw_version), + le32_to_cpu(psp_hdr_v1_1->kdb.offset_bytes), le32_to_cpu(psp_hdr_v1_1->kdb.size_bytes)); } if (version_minor == 2) { const struct psp_firmware_header_v1_2 *psp_hdr_v1_2 = container_of(psp_hdr, struct psp_firmware_header_v1_2, v1_0); - DRM_DEBUG("kdb_header_version: %u\n", - le32_to_cpu(psp_hdr_v1_2->kdb.fw_version)); - DRM_DEBUG("kdb_offset_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_2->kdb.offset_bytes)); - DRM_DEBUG("kdb_size_bytes: %u\n", + DRM_DEBUG("kdb_header_version: %u\n" + "kdb_offset_bytes: %u\n" + "kdb_size_bytes: %u\n", + le32_to_cpu(psp_hdr_v1_2->kdb.fw_version), + le32_to_cpu(psp_hdr_v1_2->kdb.offset_bytes), le32_to_cpu(psp_hdr_v1_2->kdb.size_bytes)); } if (version_minor == 3) { @@ -293,23 +316,23 @@ void amdgpu_ucode_print_psp_hdr(const struct common_firmware_header *hdr) container_of(psp_hdr, struct psp_firmware_header_v1_1, v1_0); const struct psp_firmware_header_v1_3 *psp_hdr_v1_3 = container_of(psp_hdr_v1_1, struct psp_firmware_header_v1_3, v1_1); - DRM_DEBUG("toc_header_version: %u\n", - le32_to_cpu(psp_hdr_v1_3->v1_1.toc.fw_version)); - DRM_DEBUG("toc_offset_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_3->v1_1.toc.offset_bytes)); - DRM_DEBUG("toc_size_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_3->v1_1.toc.size_bytes)); - DRM_DEBUG("kdb_header_version: %u\n", - le32_to_cpu(psp_hdr_v1_3->v1_1.kdb.fw_version)); - DRM_DEBUG("kdb_offset_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_3->v1_1.kdb.offset_bytes)); - DRM_DEBUG("kdb_size_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_3->v1_1.kdb.size_bytes)); - DRM_DEBUG("spl_header_version: %u\n", - le32_to_cpu(psp_hdr_v1_3->spl.fw_version)); - DRM_DEBUG("spl_offset_bytes: %u\n", - le32_to_cpu(psp_hdr_v1_3->spl.offset_bytes)); - DRM_DEBUG("spl_size_bytes: %u\n", + DRM_DEBUG("toc_header_version: %u\n" + "toc_offset_bytes: %u\n" + "toc_size_bytes: %u\n" + "kdb_header_version: %u\n" + "kdb_offset_bytes: %u\n" + "kdb_size_bytes: %u\n" + "spl_header_version: %u\n" + "spl_offset_bytes: %u\n" + "spl_size_bytes: %u\n", + le32_to_cpu(psp_hdr_v1_3->v1_1.toc.fw_version), + le32_to_cpu(psp_hdr_v1_3->v1_1.toc.offset_bytes), + le32_to_cpu(psp_hdr_v1_3->v1_1.toc.size_bytes), + le32_to_cpu(psp_hdr_v1_3->v1_1.kdb.fw_version), + le32_to_cpu(psp_hdr_v1_3->v1_1.kdb.offset_bytes), + le32_to_cpu(psp_hdr_v1_3->v1_1.kdb.size_bytes), + le32_to_cpu(psp_hdr_v1_3->spl.fw_version), + le32_to_cpu(psp_hdr_v1_3->spl.offset_bytes), le32_to_cpu(psp_hdr_v1_3->spl.size_bytes)); } } else { @@ -330,9 +353,9 @@ void amdgpu_ucode_print_gpu_info_hdr(const struct common_firmware_header *hdr) const struct gpu_info_firmware_header_v1_0 *gpu_info_hdr = container_of(hdr, struct gpu_info_firmware_header_v1_0, header);
- DRM_DEBUG("version_major: %u\n", - le16_to_cpu(gpu_info_hdr->version_major)); - DRM_DEBUG("version_minor: %u\n", + DRM_DEBUG("version_major: %u\n" + "version_minor: %u\n", + le16_to_cpu(gpu_info_hdr->version_major), le16_to_cpu(gpu_info_hdr->version_minor)); } else { DRM_ERROR("Unknown gpu_info ucode version: %u.%u\n", version_major, version_minor);
Sean Paul seanpaul@chromium.org proposed, in https://patchwork.freedesktop.org/series/78133/ drm/trace: Mirror DRM debug logs to tracefs
That patchset's goal is to be able to duplicate the debug stream to a tracing destination, by splitting drm_debug_enabled() into syslog & trace flavors, and enabling them separately. That clashes rather deeply with this patchset's goal; to avoid drm_debug_enabled() using dyndbg.
Instead, this puts the print-to-trace decision in dyndbg, after the is-it-enabled test (which is a noop), so it has near zero additional cost (other than memory increase); the print-to-trace test is only done on enabled callsites.
The basic elements:
- add a new struct _ddebug member: (*tracer)(char *format, ...) - add a new T flag to enable tracer - adjust the static-key-enable/disable condition for (p|T) - if (p) before printk, since T enables too. - if (T) call tracer if its true
= int dynamic_debug_register_tracer(query, modname, tracer); = int dynamic_debug_unregister_tracer(query, modname, cookie);
This new interface lets clients set/unset a tracer function on each callsite matching the query, for example: "drm:atomic:fail:".
Clients are expected to unregister the same callsites they register (a cookie), allowing protection of each client's dyndbg-state setup against overwrites by others.
Intended Behavior: (things are in flux, RFC)
- register sets empty slot, doesnt overwrite the query selects callsites, and sets +T (grammar requires +-action)
- register allows same-tracer over-set wo warn 2nd register can then enable superset, subset, disjoint set
- unregister clears slot if it matches cookie/tracer query selects set, -T (as tested) tolerates over-clears
- dd-exec-queries(+/-T) can modify the enablements not sure its needed, but it falls out..
The code is currently in-line in ddebug_change(), to be moved to separate fn, rc determines flow, may also veto/alter changes by altering flag-settings - tbd.
TBD: Im not sure what happens when exec-queries(+T) hits a site wo a tracer (silence I think. maybe not ideal).
internal call-chain gets a tracer param: New arg: public: dynamic_debug_exec_queries ro-string copy moved ... 1 ddebug_exec_queries tracer=NULL ... to here 2 ddebug_exec_query tracer=NULL
call-chain gets (re)used: with !NULL
public: dynamic_debug_register_tracer tracer=client's w ro-string 1 ddebug_exec_queries tracer ...
SELFTEST: test_dynamic_debug.ko:
Uses the tracer facility to do a selftest:
- A custom tracer counts the number of calls (of T-enabled pr_debugs), - do_debugging(x) calls a set of categorized pr_debugs x times
- test registers the tracer on the function, then iteratively: manipulates dyndbg states via query-cmds runs do_debugging() counts enabled callsite executions reports mismatches
- modprobe test_dynamic_debug use_bad_tracer=1 attaches a bad/recursive tracer Bad Things Happen. has thrown me interesting panics.
NOTES:
This needs more work. RFC.
ERRORS (or WARNINGS):
It should be an error to +T a callsite which has no aux_print set (ie already registered with a query that selected that callsite). This tacitly enforces registration.
Then +T,-T can toggle those aux_print callsites (or subsets of them) to tailor the debug-stream for the purpose. Controlling flow is the best work limiter.
--- v4+: (this patch sent after (on top of) v4)
. fix "too many arguments to function", and name the args: int (*aux_print)(const char *fmt, char *prefix, char *label, void *); prefix : is a slot for dynamic_emit_prefix, or for custom buffer insert label : for builtin-caller used by drm-trace-print void* : vaf, add type constraint later.
. fix printk (to syslog) needs if (+p), since +T also enables . add prototypes for un/register_aux_print . change iface names: s/aux_print/tracer/ . also s/trace_print/tracer/ . struct va_format *vaf - tighten further ?
Signed-off-by: Jim Cromie jim.cromie@gmail.com --- include/linux/dynamic_debug.h | 32 ++++- lib/Kconfig.debug | 10 ++ lib/Makefile | 1 + lib/dynamic_debug.c | 109 +++++++++++---- lib/test_dynamic_debug.c | 247 ++++++++++++++++++++++++++++++++++ 5 files changed, 372 insertions(+), 27 deletions(-) create mode 100644 lib/test_dynamic_debug.c
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 42cfb37d4870..cbcb1c94cec3 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -20,6 +20,7 @@ struct _ddebug { const char *function; const char *filename; const char *format; + int (*tracer)(const char *fmt, char *prefix, char *label, struct va_format *vaf); unsigned int lineno:18; /* * The flags field controls the behaviour at the callsite. @@ -27,7 +28,11 @@ struct _ddebug { * writes commands to <debugfs>/dynamic_debug/control */ #define _DPRINTK_FLAGS_NONE 0 -#define _DPRINTK_FLAGS_PRINT (1<<0) /* printk() a message using the format */ +#define _DPRINTK_FLAGS_PRINT (1<<0) /* printk() a message */ +#define _DPRINTK_FLAGS_PRINT_TRACE (1<<5) /* call (*tracer) */ + +#define _DPRINTK_ENABLED (_DPRINTK_FLAGS_PRINT | _DPRINTK_FLAGS_PRINT_TRACE) + #define _DPRINTK_FLAGS_INCL_MODNAME (1<<1) #define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<2) #define _DPRINTK_FLAGS_INCL_LINENO (1<<3) @@ -279,4 +284,29 @@ extern const struct kernel_param_ops param_ops_dyndbg; #define _DD_cat_help_(pfx) #endif
+/** + * dynamic_debug_register_tracer - register a "printer" function + * @query: query-command string to select callsites getting the function + * @tracer: &vprintf-ish accepting 3 char* ptrs & a vaf + * + * Attach a printer function to callsites selected by query. + * If another printer is already attached, warn and skip, applying the + * rest of the query. This protects existing setups, while allowing + * maximal coexistence of (mostly) non-competing listeners. RFC. + */ +int dynamic_debug_register_tracer(const char *query, const char *mod, + int (*tracer) (const char *fmt, char *prefix, char *label, struct va_format *vaf)); +/** + * dynamic_debug_unregister_tracer - unregister your "printer" function + * @query: query-command string to select callsites to reset + * @cookie: reserved to validate unregisters against pirates + * + * Detach this printer function (@cookie) from callsites selected by + * the query, when @cookie == callsite. This protects existing + * setups, while allowing maximal coexistence of (mostly) + * non-competing listeners. RFC. + */ +int dynamic_debug_unregister_tracer(const char *query, const char *mod, + int (*cookie) (const char *fmt, char *prefix, char *label, struct va_format *vaf)); + #endif diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index 5ddd575159fb..5038f81d3fc6 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -2486,6 +2486,16 @@ config TEST_STATIC_KEYS
If unsure, say N.
+config TEST_DYNAMIC_DEBUG + tristate "Test DYNAMIC_DEBUG" + depends on m + depends on DYNAMIC_DEBUG + help + Test the print_aux registration with a counting fn, + then test expected counts during the execution. + + If unsure, say N. + config TEST_KMOD tristate "kmod stress tester" depends on m diff --git a/lib/Makefile b/lib/Makefile index 5efd1b435a37..01c3c76980ba 100644 --- a/lib/Makefile +++ b/lib/Makefile @@ -82,6 +82,7 @@ obj-$(CONFIG_TEST_SORT) += test_sort.o obj-$(CONFIG_TEST_USER_COPY) += test_user_copy.o obj-$(CONFIG_TEST_STATIC_KEYS) += test_static_keys.o obj-$(CONFIG_TEST_STATIC_KEYS) += test_static_key_base.o +obj-$(CONFIG_TEST_DYNAMIC_DEBUG) += test_dynamic_debug.o obj-$(CONFIG_TEST_PRINTF) += test_printf.o obj-$(CONFIG_TEST_SCANF) += test_scanf.o obj-$(CONFIG_TEST_BITMAP) += test_bitmap.o diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 6bc645a663e7..9ba180976636 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -85,6 +85,7 @@ static inline const char *trim_prefix(const char *path)
static struct { unsigned flag:8; char opt_char; } opt_array[] = { { _DPRINTK_FLAGS_PRINT, 'p' }, + { _DPRINTK_FLAGS_PRINT_TRACE, 'T' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, @@ -146,7 +147,8 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg) * logs the changes. Takes ddebug_lock. */ static int ddebug_change(const struct ddebug_query *query, - struct flag_settings *modifiers) + struct flag_settings *modifiers, + int (*tracer)(const char *, char *, char *, struct va_format *)) { int i; struct ddebug_table *dt; @@ -205,11 +207,43 @@ static int ddebug_change(const struct ddebug_query *query, newflags = (dp->flags & modifiers->mask) | modifiers->flags; if (newflags == dp->flags) continue; + + /* handle T flag */ + if (newflags & _DPRINTK_FLAGS_PRINT_TRACE) { + if (!tracer) + v2pr_info("tracer enable\n"); + else { + /* register attempt */ + if (!dp->tracer) { + v2pr_info("register tracer\n"); + dp->tracer = tracer; + } + else if (tracer == dp->tracer) + v2pr_info("tracer equal, ok\n"); + else + pr_warn("tracer register error\n"); + } + } else if (dp->flags & _DPRINTK_FLAGS_PRINT_TRACE) { + if (!tracer) + v2pr_info("ok: disabling\n"); + else { + /* only unregister has a !!tracer */ + if (!dp->tracer) + pr_warn("nok: tracer already unset\n"); + + else if (dp->tracer == tracer) { + v2pr_info("ok: cookie match, unregistering\n"); + dp->tracer = NULL; + } + else + pr_warn("nok: tracer cookie match fail\n"); + } + } #ifdef CONFIG_JUMP_LABEL - if (dp->flags & _DPRINTK_FLAGS_PRINT) { - if (!(modifiers->flags & _DPRINTK_FLAGS_PRINT)) + if (dp->flags & _DPRINTK_ENABLED) { + if (!(modifiers->flags & _DPRINTK_ENABLED)) static_branch_disable(&dp->key.dd_key_true); - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT) + } else if (modifiers->flags & _DPRINTK_ENABLED) static_branch_enable(&dp->key.dd_key_true); #endif dp->flags = newflags; @@ -482,7 +516,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers) return 0; }
-static int ddebug_exec_query(char *query_string, const char *modname) +static int ddebug_exec_query(char *query_string, const char *modname, void *tracer) { struct flag_settings modifiers = {}; struct ddebug_query query = {}; @@ -505,7 +539,7 @@ static int ddebug_exec_query(char *query_string, const char *modname) return -EINVAL; } /* actually go and implement the change */ - nfound = ddebug_change(&query, &modifiers); + nfound = ddebug_change(&query, &modifiers, tracer); vpr_info_dq(&query, nfound ? "applied" : "no-match");
return nfound; @@ -515,10 +549,19 @@ static int ddebug_exec_query(char *query_string, const char *modname) last error or number of matching callsites. Module name is either in param (for boot arg) or perhaps in query string. */ -static int ddebug_exec_queries(char *query, const char *modname) +static int ddebug_exec_queries(const char *query_in, const char *modname, void *tracer) { char *split; int i, errs = 0, exitcode = 0, rc, nfound = 0; + char *query; /* writable copy of query_in */ + + if (!query_in) { + pr_err("non-null query/command string expected\n"); + return -EINVAL; + } + query = kstrndup(query_in, PAGE_SIZE, GFP_KERNEL); + if (!query) + return -ENOMEM;
for (i = 0; query; query = split) { split = strpbrk(query, ";\n"); @@ -531,7 +574,7 @@ static int ddebug_exec_queries(char *query, const char *modname)
vpr_info("query %d: "%s" %s\n", i, query, (modname) ? modname : "");
- rc = ddebug_exec_query(query, modname); + rc = ddebug_exec_query(query, modname, tracer); if (rc < 0) { errs++; exitcode = rc; @@ -540,6 +583,7 @@ static int ddebug_exec_queries(char *query, const char *modname) } i++; } + kfree(query); vpr_info("processed %d queries, with %d matches, %d errs\n", i, nfound, errs);
@@ -560,20 +604,7 @@ static int ddebug_exec_queries(char *query, const char *modname) */ int dynamic_debug_exec_queries(const char *query, const char *modname) { - int rc; - char *qry; /* writable copy of query */ - - if (!query) { - pr_err("non-null query/command string expected\n"); - return -EINVAL; - } - qry = kstrndup(query, PAGE_SIZE, GFP_KERNEL); - if (!qry) - return -ENOMEM; - - rc = ddebug_exec_queries(qry, modname); - kfree(qry); - return rc; + return ddebug_exec_queries(query, modname, NULL); } EXPORT_SYMBOL_GPL(dynamic_debug_exec_queries);
@@ -637,8 +668,20 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) vaf.fmt = fmt; vaf.va = &args;
- printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf); + if (descriptor->flags & _DPRINTK_ENABLED) + dynamic_emit_prefix(descriptor, buf); + + if (descriptor->flags & _DPRINTK_FLAGS_PRINT) + printk(KERN_DEBUG "%s%pV", buf, &vaf);
+ if (descriptor->flags & _DPRINTK_FLAGS_PRINT_TRACE) { + + if (descriptor->tracer) { + (*descriptor->tracer)("%s:%ps %pV", buf, + __builtin_return_address(0), &vaf); + } + /* else shouldnt matter, but maybe for consistency */ + } va_end(args); } EXPORT_SYMBOL(__dynamic_pr_debug); @@ -783,7 +826,7 @@ static ssize_t ddebug_proc_write(struct file *file, const char __user *ubuf, return PTR_ERR(tmpbuf); vpr_info("read %d bytes from userspace\n", (int)len);
- ret = ddebug_exec_queries(tmpbuf, NULL); + ret = ddebug_exec_queries(tmpbuf, NULL, NULL); kfree(tmpbuf); if (ret < 0) return ret; @@ -989,7 +1032,7 @@ static int ddebug_dyndbg_param_cb(char *param, char *val, if (strcmp(param, "dyndbg")) return on_err; /* determined by caller */
- ddebug_exec_queries((val ? val : "+p"), modname); + ddebug_exec_queries((val ? val : "+p"), modname, NULL);
return 0; /* query failure shouldn't stop module load */ } @@ -1124,7 +1167,7 @@ static int __init dynamic_debug_init(void) /* apply ddebug_query boot param, dont unload tables on err */ if (ddebug_setup_string[0] != '\0') { pr_warn("ddebug_query param name is deprecated, change it to dyndbg\n"); - ret = ddebug_exec_queries(ddebug_setup_string, NULL); + ret = ddebug_exec_queries(ddebug_setup_string, NULL, NULL); if (ret < 0) pr_warn("Invalid ddebug boot param %s\n", ddebug_setup_string); @@ -1214,3 +1257,17 @@ const struct kernel_param_ops param_ops_dyndbg = { }; /* support DEFINE_DYNAMIC_DEBUG_CATEGORIES users */ EXPORT_SYMBOL(param_ops_dyndbg); + +int dynamic_debug_register_tracer(const char *query, const char *mod, + int (*tracer) (const char *fmt, char *prefix, char *label, struct va_format *vaf)) +{ + return ddebug_exec_queries(query, mod, tracer); +} +EXPORT_SYMBOL(dynamic_debug_register_tracer); + +int dynamic_debug_unregister_tracer(const char *query, const char *mod, + int (*tracer) (const char *fmt, char *prefix, char *label, struct va_format *vaf)) +{ + return ddebug_exec_queries(query, mod, tracer); +} +EXPORT_SYMBOL(dynamic_debug_unregister_tracer); diff --git a/lib/test_dynamic_debug.c b/lib/test_dynamic_debug.c new file mode 100644 index 000000000000..e837398bd885 --- /dev/null +++ b/lib/test_dynamic_debug.c @@ -0,0 +1,247 @@ +// SPDX-License-Identifier: GPL-2.0-only +/* + * Kernel module for testing dynamic_debug + * + * Authors: + * Jim Cromie jim.cromie@gmail.com + */ + +/* + * test-setup: use trace_print attachment interface as a test harness, + * define a custom trace_printer which counts invocations, and a + * pr_debug event generator function which calls a set of categorized + * pr_debugs. + * test-run: manipulate the pr_debug's enablement, run the event + * generator, and check for the expected side effects. + */ + +#include <linux/module.h> + +static int __bad_tracer; + +static int trace_ct = 0; +static int test_ct = 0; +static int errors = 0; +static int verbose = 0; + + +module_param_named(use_bad_tracer, __bad_tracer, int, 0644); +MODULE_PARM_DESC(use_bad_tracer, + "use broken tracer, recursing with pr_debug\n" + "\tonly works at modprobe time\n"); + +static int (*my_tracer)(const char *decorator, char *prefix, char *label, struct va_format *vaf); + +static int good_tracer(const char *decorator, char *prefix, char *label, struct va_format *vaf) +{ + trace_ct++; + if (verbose) + pr_notice("my_tracer: %pV", vaf); + return 0; +} + +static int bad_tracer(const char *decorator, char *prefix, char *label, struct va_format *vaf) +{ + /* dont try pr_debug, it recurses back here */ + pr_debug("oops! recursion, crash?\n"); + return 0; +} + +static void pick_tracer(void) +{ + if (__bad_tracer) + my_tracer = bad_tracer; + else + my_tracer = good_tracer; +} + +static int expect_count(int want, const char *story) +{ + test_ct++; + if (want != trace_ct) { + pr_err("expect_count: want %d, got %d: %s\n", want, trace_ct, story); + errors++; + trace_ct = 0; + return 1; + } + pr_info("pass %d, hits %d, on "%s"\n", test_ct, want, story); + trace_ct = 0; + return 0; +} + +/* call pr_debug (4 * reps) + 2 times, for tracer side-effects */ +static void do_debugging(int reps) +{ + int i; + + pr_debug("Entry:\n"); + pr_info(" do_debugging %d time(s)\n", reps); + for (i = 0; i < reps; i++) { + pr_debug("hi: %d\n", i); + pr_debug("mid: %d\n", i); + pr_debug("low: %d\n", i); + pr_debug("low:lower: %d subcategory test\n", i); + } + pr_debug("Exit:\n"); +} + +static void expect_matches(int want, int got, const char *story) +{ + // todo: got <0 are errors, bubbled up + if (got != want) + pr_warn(" match_count wrong: want %d got %d on "%s"\n", want, got, story); + else + pr_info(" ok: %d matches by "%s"\n", want, story); + + // ? count errs ? separately ? +} + +static int report(char *who) +{ + if (errors) + pr_err("%s failed %d of %d tests\n", who, errors, test_ct); + else + pr_info("%s passed %d tests\n", who, test_ct); + return errors; +} + +struct exec_test { + int matches; + int loops; + int hits; + const char *mod; + const char *qry; +}; + +static void do_exec_test(struct exec_test *tst) +{ + int match_count; + + match_count = dynamic_debug_exec_queries(tst->qry, tst->mod); + expect_matches(tst->matches, match_count, tst->qry); + do_debugging(tst->loops); + expect_count(tst->hits, tst->qry); +} + +static const char my_mod[] = "test_dynamic_debug"; + +/* these tests rely on register stuff having been done ?? */ +struct exec_test exec_tests[] = { + + /* standard use is my_mod, for `modprobe $module dyndbg=+p` */ + + /* no modification probe */ + { 6, 2, 0, my_mod, "func do_debugging +_" }, + + /* use original single string query style */ + { 6, 3, 0, NULL, "module test_dynamic_debug func do_debugging -T" }, + + /* this is mildly preferred */ + { 6, 3, 0, my_mod, "func do_debugging -T" }, + + /* enable all DUT */ + { 6, 4, 18, my_mod, "func do_debugging +T" }, + + /* disable 1 call */ + { 1, 4, 14, my_mod, "format '^hi:' -T" }, + + /* disable 1 call */ + { 1, 4, 10, my_mod, "format '^mid:' -T" }, + + /* repeat same disable */ + { 1, 4, 10, my_mod, "format '^mid:' -T" }, + + /* repeat same disable, diff run ct */ + { 1, 5, 12, my_mod, "format '^mid:' -T" }, + + /* include subclass */ + { 2, 4, 2, my_mod, "format '^low:' -T" }, + + /* re-disable, exclude subclass */ + { 1, 4, 2, my_mod, "format '^low: ' -T" }, + + /* enable, exclude subclass */ + { 1, 4, 6, my_mod, "format '^low: ' +T" }, + + /* enable the subclass */ + { 1, 4, 10, my_mod, "format '^low:lower:' +T" }, + + /* enable the subclass */ + { 1, 6, 14, my_mod, "format '^low:lower:' +T" }, +}; + +struct register_test { + int matches; + int loops; + int hits; + const char *mod; + const char *qry; +}; + +static void do_register_test(struct register_test *tst) +{ + int match_count; + + match_count = dynamic_debug_register_tracer(tst->qry, tst->mod, my_tracer); + expect_matches(tst->matches, match_count, tst->qry); + do_debugging(tst->loops); + expect_count(tst->hits, tst->qry); +} + +struct register_test register_tests[] = { + + { 6, 3, 14, my_mod, "func do_debugging +T" }, + + { 10, 3, 0, my_mod, "+_" }, //, my_tracer }, + { 11, 3, 0, my_mod, "+T" }, //, my_tracer }, +}; + +static int __init test_dynamic_debug_init(void) +{ + int match_count; /* rc from ddebug_exec_queries. meh. */ + int i; + + pick_tracer(); + + pr_debug("Entry:\n"); + do_debugging(3); + expect_count(0, "nothing unless dyndbg=+T at modprobe"); + + for (i = 0; i < ARRAY_SIZE(register_tests); i++) + do_register_test(®ister_tests[i]); + + do_debugging(2); + expect_count(10, "do_debugging 2 times after +T"); + + for (i = 0; i < ARRAY_SIZE(exec_tests); i++) + do_exec_test(&exec_tests[i]); + + match_count = dynamic_debug_unregister_tracer( + "func do_debugging -T", "test_dynamic_debug", my_tracer); + + expect_matches(6, match_count, + "unregister do_debugging()s tracers"); + do_debugging(4); + expect_count(0, "everything is off"); + + match_count = dynamic_debug_unregister_tracer( + "func do_debugging -T", "test_dynamic_debug", my_tracer); + + expect_matches(6, match_count, + "re-unregister, same count, not a change count"); + report("init"); + pr_debug("Exit:\n"); + return 0; +} + +static void __exit test_dynamic_debug_exit(void) +{ + report("exit"); + pr_debug("Exit:"); +} + +module_init(test_dynamic_debug_init); +module_exit(test_dynamic_debug_exit); + +MODULE_AUTHOR("Jim Cromie jim.cromie@gmail.com"); +MODULE_LICENSE("GPL");
dri-devel@lists.freedesktop.org
-
Andy Shevchenko -
Jim Cromie -
jim.cromie＠gmail.com
-
Matthew Wilcox