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_cb_data() derives from module_param_cb(), adding data param, and latter is redefined to use former.

It calls __module_param_call_with_data(), which accepts 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.

Signed-off-by: Jim Cromie jim.cromie@gmail.com --- v6: . const void* data - emil.l.velikov@gmail.com . better macro names s/_cbd/_cb_data/, s/_wdata/_with_data/ . more const, no cast - Willy --- 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..b8871e514de5 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_cb_data(name, ops, arg, perm, data) \ + __module_param_call_with_data(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_with_data(prefix, name, ops, arg, perm, level, flags, NULL) + +#define __module_param_call_with_data(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) \

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.

Signed-off-by: Jim Cromie jim.cromie@gmail.com --- v4+: . static decl of vector of bit->class descriptors - Emil.V . relocate gvt-makefile chunk from elsewhere --- 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

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:

Because the dyndbg callback is watching __drm_debug, it is coherent with drm_debug_enabled(), the switchover should be transparent.

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.

Signed-off-by: Jim Cromie jim.cromie@gmail.com --- v6: . add kernel doc . fix cpp paste, drop '#' v5: . 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 --- drivers/gpu/drm/Kconfig | 13 ++++ drivers/gpu/drm/drm_print.c | 49 +++++++++---- include/drm/drm_print.h | 142 ++++++++++++++++++++++++++++-------- 3 files changed, 160 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 9b66be54dd16..8775b67ecb30 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,86 @@ 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 */ + +/* join prefix+format in cpp so dyndbg can see it */ +#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: " /* not in MODULE_PARM_DESC */ + +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */ + static inline bool drm_debug_enabled(enum drm_debug_category category) { return unlikely(__drm_debug & category); @@ -334,8 +414,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 +463,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 +471,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 +479,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 +523,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 +551,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 +580,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 +611,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.

RFC: this creates multi-line log messages, does that break any syslog conventions ?

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 objective is to be able to independently steer some of the debug stream to an alternate tracing destination, by splitting drm_debug_enabled() into syslog & trace flavors, and enabling them separately with a drm.debug_trace knob.

2 advantages are identified: - syslog is heavyweight, alternate stream is lighter - steering selected categories separately means less traffic

Dynamic-Debug can do this better:

1- all work is behind jump-label's NOOP, Zero overhead when off.

2- perfect site selectivity, no unwanted traffic.

drm's debug categories are a general classification system, not one tailored to pick out the exact pool of pr_debugs to watch/trace.

With drm.debug built on dyndbg, the given "drm:<cat>:" system can be used to select a base trace-set, which can then be adjusted +/-, and/or augmented with unrelated pr_debugs that just happen to be useful. And this tweaking can be done at the command-line, and reduced to a script.

Then the string-prefix "drm:<cat>:" system can be extended to suit.

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 must unregister the same callsites they register, allowing protection of each client's dyndbg-state setup against overwrites by others, while allowing maximal sharing of 1 slot/callsite.

The internal call-chain gets some rework: it gets new void* tracer param, which dynamic_debug_exec_queries() hides from public.

And convert ddebug_exec_queries() to wrap __ddebug_exec_queries(), and move the query copy code to it.

public: passing down: dynamic_debug_(un)register_tracer tracer dynamic_debug_exec_queries tracer=NULL calling: ddebug_exec_queries copies ro-query, tracer __ddebug_exec_queries modifies query, tracer ddebug_exec_query modifies query, tracer

Then adjust most ddebug_exec_queries users to __ddebug_exec_queries

Intended Behavior: (things are in flux, RFC)

- register sets empty slot, doesn't 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).

SELFTEST: test_dynamic_debug.ko:

Uses the tracer facility to implement a selftest:

- DUT(x) calls a set of categorized pr_debugs x times - A custom tracer counts the number of calls (of T-enabled pr_debugs),

- test registers the tracer on the function, then iteratively: manipulates dyndbg states via query-cmds calls DUT(x) counts enabled callsite executions reports mismatches

- modprobe test_dynamic_debug broken_tracer=1 attaches a broken tracer: recursive on pr_debug Bad Things Happen. has thrown me interesting panics.

This needs more work. RFC. waste of time due to use_bad_tracer properties ?

NOTES:

Next step: replace tracer member with a hashtable lookup, done only when T. Registration then becomes populating the hashtable; mod->name would make a good key, which would limit tracer mapping granularity to 1 registrant per module, but not enablement, which is still the per-callsite bit.

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.

Signed-off-by: Jim Cromie jim.cromie@gmail.com ---

v5: (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 ?

v6: (this version) . add test module . add mod arg to *register, following exec_queries pattern . move code off file bottom to "better" spot . move kdoc to c from h

__dxq --- include/linux/dynamic_debug.h | 12 +- lib/Kconfig.debug | 11 ++ lib/Makefile | 1 + lib/dynamic_debug.c | 145 ++++++++++++++---- lib/test_dynamic_debug.c | 279 ++++++++++++++++++++++++++++++++++ 5 files changed, 418 insertions(+), 30 deletions(-) create mode 100644 lib/test_dynamic_debug.c

diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 51b7254daee0..8807367c7903 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) @@ -277,4 +282,9 @@ extern const struct kernel_param_ops param_ops_dyndbg; #define _DD_cat_help_(pfx) #endif

+int dynamic_debug_register_tracer(const char *query, const char *mod, + int (*tracer)(const char *fmt, char *prefix, char *label, struct va_format *vaf)); +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..f3454b2bfc8e 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -2486,6 +2486,17 @@ config TEST_STATIC_KEYS

If unsure, say N.

+config TEST_DYNAMIC_DEBUG + tristate "Test DYNAMIC_DEBUG" + depends on m + depends on DYNAMIC_DEBUG + help + This module registers a tracer callback to count enabled + pr_debugs in a 'do_debugging' function, then alters their + enablements, calls the function, and compares counts. + + 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 a43427c67c3f..60bf2c01db1a 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,42 @@ 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("ok: tracer enable\n"); + else { + /* register attempt */ + if (!dp->tracer) { + v2pr_info("register tracer\n"); + dp->tracer = tracer; + + } else if (tracer == dp->tracer) + v2pr_info("ok: tracer over-set\n"); + else + pr_warn("tracer register error\n"); + } + } else if (dp->flags & _DPRINTK_FLAGS_PRINT_TRACE) { + if (!tracer) + v2pr_info("ok: disable\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 +515,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 +538,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; @@ -516,7 +549,7 @@ 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(char *query, const char *modname, void *tracer) { char *split; int i, errs = 0, exitcode = 0, rc, nfound = 0; @@ -532,7 +565,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; @@ -549,6 +582,22 @@ static int ddebug_exec_queries(char *query, const char *modname) return nfound; }

+static int ddebug_exec_queries(const char *query_in, const char *modname, void *tracer) +{ + int rc; + + 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; + + rc = __ddebug_exec_queries(query, modname, tracer); + kfree(query); + return rc; + /** * dynamic_debug_exec_queries - select and change dynamic-debug prints * @query: query-string described in admin-guide/dynamic-debug-howto @@ -556,25 +605,12 @@ static int ddebug_exec_queries(char *query, const char *modname) * * This uses the >/proc/dynamic_debug/control reader, allowing module * authors to modify their dynamic-debug callsites. The modname is - * canonically struct module.mod_name, but can also be null or a + * canonically struct module.name, but can also be null or a * module-wildcard, for example: "drm*". */ 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(qry, modname, NULL); } EXPORT_SYMBOL_GPL(dynamic_debug_exec_queries);

@@ -603,7 +639,7 @@ int param_set_dyndbg(const char *instr, const struct kernel_param *kp) } rc = kstrtoul(instr, 0, &inbits); if (rc) { - pr_err("set_dyndbg: failed\n"); + pr_err("set_dyndbg: bad input: %s\n", instr); return rc; } vpr_info("set_dyndbg: input 0x%lx\n", inbits); @@ -612,7 +648,7 @@ int param_set_dyndbg(const char *instr, const struct kernel_param *kp) snprintf(query, FMT_QUERY_SIZE, "format '^%s' %cp", bitmap->prefix, test_bit(i, &inbits) ? '+' : '-');

- matches = ddebug_exec_queries(query, KP_MOD_NAME); + matches = __ddebug_exec_queries(query, KP_MOD_NAME, NULL);

v2pr_info("bit-%d: %d matches on '%s'\n", i, matches, query); totct += matches; @@ -703,8 +739,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 shouldn't matter, but maybe for consistency */ + } va_end(args); } EXPORT_SYMBOL(__dynamic_pr_debug); @@ -849,7 +897,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; @@ -1055,7 +1103,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 */ } @@ -1190,7 +1238,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); @@ -1220,3 +1268,42 @@ early_initcall(dynamic_debug_init);

/* Debugfs setup must be done later */ fs_initcall(dynamic_debug_init_control); + +/** + * dynamic_debug_register_tracer() - register a "printer" function + * @query: query-command string to select callsites getting the function + * @modname: added into query-command, may include wildcards + * @tracer: &vprintf-ish accepting 3 char* ptrs & a vaf + * + * Attach a tracer callback callsites selected by the query. If + * another tracer 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. + * + * Returns: <0 error + * >=0 matches on query, not changes by query + */ +int dynamic_debug_register_tracer(const char *query, const char *modname, + int (*tracer)(const char *fmt, char *prefix, char *label, struct va_format *vaf)) +{ + return ddebug_exec_queries(query, modname, tracer); +} +EXPORT_SYMBOL(dynamic_debug_register_tracer); + +/** + * dynamic_debug_unregister_tracer - unregister your "printer" function + * @query: query-command string to select callsites to reset + * @modname: name of module, or search string (ex: "drm*"), or null + * @tracer: reserved to validate unregisters against pirates + * + * Detach the tracer callback from callsites selected by the query, if + * it matches the callsite's tracer. This protects existing setups, + * while allowing maximal coexistence of (mostly) non-competing + * listeners. RFC. + */ +int dynamic_debug_unregister_tracer(const char *query, const char *modname, + int (*tracer)(const char *fmt, char *prefix, char *label, struct va_format *vaf)) +{ + return ddebug_exec_queries(query, modname, 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..802199e2507a --- /dev/null +++ b/lib/test_dynamic_debug.c @@ -0,0 +1,279 @@ +// SPDX-License-Identifier: GPL-2.0-only +/* + * Kernel module for testing dynamic_debug + * + * Author: + * Jim Cromie jim.cromie@gmail.com + */ + +/* + * test-setup: + * - use register_tracer to attach a test harness + * - a custom trace_printer which counts invocations of enabled pr_debugs + * - a DUT (device under test), calling categorized pr_debugs + * test-run: + * - manipulate the pr_debugs' enablements -> match_ct + * - call event generator with loop-ct + * its pr_debug()s are Traced: trace_ct++ + * - count and compare: mainly trace_ct, but also match_ct + */ + +#include <linux/module.h> + +static int trace_ct; /* the state var */ +static int test_ct; +static int errors; + +static int verbose; +module_param_named(verbose, verbose, int, 0444); +MODULE_PARM_DESC(verbose, "notice on tracer"); + +static int __test_resv; +module_param_named(test_reserve, __test_resv, int, 0444); +MODULE_PARM_DESC(test_reserve, "test 'reservation' against 'poaching'\n"); + +static int __broken_tracer; +module_param_named(broken_tracer, __broken_tracer, int, 0444); +MODULE_PARM_DESC(broken_tracer, + "use broken tracer, recursing with pr_debug\n" + "\tonly works at modprobe time\n"); + +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 int (*my_tracer) + (const char *decorator, char *prefix, char *label, struct va_format *vaf); + +static void pick_tracer(void) +{ + if (__broken_tracer) + my_tracer = bad_tracer; + else + my_tracer = good_tracer; +} + +/* call pr_debug (4 * reps) + 2 times, for tracer side-effects */ +static void DUT(int reps) +{ + int i; + + pr_debug("Entry:\n"); + pr_info(" DUT %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"); +} + +struct test_spec { + int matches; /* expected rc from applying qry */ + int loops; /* passed to DUT */ + int hits; /* should match trace_ct after gen */ + const char *mod; /* Anyof: wildcarded-string, null, &mod.name */ + const char *qry; /* echo $qry > control */ + const char *story; /* test purpose explanation progress */ +}; + +static void expect_count(struct test_spec *t) +{ + test_ct++; + if (trace_ct != t->hits) { + pr_err("fail#%d: got %d != %d by "%s"\tfor "%s"\n", + test_ct, trace_ct, t->hits, t->qry, t->story); + errors++; + } else + pr_info("pass#%d, hits %d, on "%s"\n", test_ct, t->hits, t->story); + + trace_ct = 0; +} + +static void expect_matches(int got, struct test_spec *t) +{ + if (got != t->matches) { + pr_warn(" nok: got %d != %d on "%s"\n", got, t->matches, t->qry); + errors++; + } else + pr_info(" ok: %d matches by "%s"\t for "%s"\n", got, t->qry, t->story); +} + +static void do_test_spec(struct test_spec *t) +{ + int match_count; + + match_count = dynamic_debug_exec_queries(t->qry, t->mod); + if (match_count < 0) { + pr_err("exec-queries fail rc:%d\n", match_count); + return; + } + expect_matches(match_count, t); + DUT(t->loops); + expect_count(t); +} + +static const char modnm[] = "test_dynamic_debug"; + +static void do_register_test(struct test_spec *t, int deep) +{ + int match_count; + + pr_debug("enter: %s\n", t->story); + if (deep) + pr_debug("register good tracer\n"); + + match_count = dynamic_debug_register_tracer(t->qry, t->mod, good_tracer); + if (match_count < 0) { + pr_err("exec-queries fail rc:%d\n", match_count); + return; + } + expect_matches(match_count, t); + DUT(t->loops); + expect_count(t); + + if (!deep) + return; + + pr_debug("unregister bad tracer\n"); + match_count = dynamic_debug_unregister_tracer(t->qry, t->mod, bad_tracer); + if (match_count < 0) { + pr_err("exec-queries fail rc:%d\n", match_count); + return; + } + expect_matches(match_count, t); + DUT(t->loops); + expect_count(t); + + pr_debug("unregister good tracer\n"); + match_count = dynamic_debug_unregister_tracer(t->qry, t->mod, good_tracer); + if (match_count < 0) { + pr_err("exec-queries fail rc:%d\n", match_count); + return; + } + expect_matches(match_count, t); + DUT(t->loops); + expect_count(t); +} + +struct test_spec registry_tests[] = { + + /* matches, loops, hits, modname, query, story */ + { 6, 1, 0, modnm, "func DUT +_", "probe: DUT 1" }, + { 6, 1, 2+4, modnm, "func DUT +T", "enable (T)" }, + { 6, 2, 10, modnm, "func DUT -_", "probe: DUT 2" }, + { 6, 3, 14, modnm, "func DUT +T", "over-enable, ok" }, + { 6, 2, 10, modnm, "func DUT -_", "probe: DUT 3" }, + { 6, 3, 0, modnm, "func DUT -T", "disable" }, + + /* 5 other callsites here */ + { 11, 1, 0, modnm, "+_", "probe: whole module" }, + { 11, 5, 22, modnm, "+T", "enable (T) whole module" }, + { 11, 1, 7, modnm, "+T", "re-enable whole module" }, + { 11, 3, 1, modnm, "-T", "disable whole module" }, + + { 3, 2, 0, modnm, "func test_* +_", "probe: count test_*" }, + { 3, 2, 0, modnm, "func test_* +_", "probe: count test_*" }, + + /* terminate registry tests in a known T state */ + { 6, 3, 14, modnm, "func DUT +T", "enable just function" }, +}; + +/* these tests rely on register stuff having been done ?? */ +struct test_spec exec_tests[] = { + /* + * preferred use of exec_queries(qry, modnm) is with true + * modnm, since that removes 'module $modnm' from the query + * string. (supports modprobe $modname dyndbg=+p). + * + * But start the old way. with Ts enabled. + */ + { 6, 1, 6, NULL, "module test_dynamic_debug func DUT +p", + "Hello! using original module-in-query style" }, + + { 11, 1, 6, modnm, "+p", "enable (p) whole module, run DUT 1x" }, + { 11, 1, 0, modnm, "-p", "disable (p) whole module, run DUT(1x)" }, + + { 6, 4, 18, modnm, "func DUT +T", "enable (T) DUT(4)" }, + + { 1, 4, 14, modnm, "format '^hi:' -T", "disable 1 callsite" }, + { 1, 4, 10, modnm, "format '^mid:' -T", "disable 1 callsite" }, + { 1, 4, 10, modnm, "format '^mid:' -T", "re-disable" }, + { 1, 5, 12, modnm, "format '^mid:' -T", "re-disable with more loops" }, + { 2, 4, 2, modnm, "format '^low:' -T", "disable with subclass" }, + { 1, 4, 2, modnm, "format '^low: ' -T", "re-disable, exclude subclass" }, + { 1, 4, 6, modnm, "format '^low: ' +T", "enable, exclude subclass" }, + { 1, 4, 10, modnm, "format '^low:lower:' +T", "enable the subclass" }, + { 1, 6, 14, modnm, "format '^low:lower:' +T", "re-enable the subclass" }, +}; + +struct test_spec ratelimit_tests[] = { + { 6, 3000, 0, modnm, "func DUT +Tr" } +}; + +static void do_test_vec(struct test_spec *t, int len) +{ + int i; + + for (i = 0; i < len; i++, t++) + do_test_spec(t); +} + +static void test_all(void) +{ + int i; + + pr_debug("Entry:\n"); + pick_tracer(); + + for (i = 0; i < ARRAY_SIZE(registry_tests); i++) + ; //do_register_test(&registry_tests[i], __test_resv); + + for (i = 0; i < ARRAY_SIZE(registry_tests); i++) + do_register_test(&registry_tests[i], 0); + + do_test_vec(exec_tests, ARRAY_SIZE(exec_tests)); + do_test_vec(ratelimit_tests, ARRAY_SIZE(ratelimit_tests)); +} + +static void report(char *who) +{ + if (errors) + pr_err("%s: failed %d of %d tests\n", who, errors, test_ct); + else + pr_notice("%s: passed %d tests\n", who, test_ct); +} + +static int __init test_dynamic_debug_init(void) +{ + pr_debug("Init:\n"); + + test_all(); + report("complete"); + + 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");