[RFC PATCH 0/2] drm: use dynamic_debug

[RFC PATCH 0/2] drm: use dynamic_debug

[Jim Cromie]

hello gentle readers,

These 2 rfc patches convert part of drm-world to use dynamic debug.

1st one addresses drm.debug category based logging.  If DYNAMIC_DEBUG
is configured, then CONFIG_DRM_USE_DYNAMIC_DEBUG controls whether
dynamic-debug is used to avoid runtime costs of drm_debug_enabled().
We require CONFIG_JUMP_LABEL too, since we are selling its
optimization.

This change adds many new callsites to /proc/dynamic_debug/control;
~300 in drm, ~200 in drm_kms_helper, as well as ~1500 in i915 driver,
and ~3200 in amdgpu.  So there are substantial implications here.

2nd one is for i915, which I have in my laptop.  `grep pr_debug` found
~90 callsites with a meaningful format-prefix-string, to demonstrate
use of "format ^prefix" to control user categorized debugs.

Jim Cromie (2):
  drm: RFC add choice to use dynamic debug in drm-debug
  i915: POC use dynamic_debug_exec_queries to control pr_debugs in gvt

 drivers/gpu/drm/Kconfig            | 13 +++++
 drivers/gpu/drm/drm_print.c        | 75 ++++++++++++++++++++++--
 drivers/gpu/drm/i915/gvt/Makefile  |  1 +
 drivers/gpu/drm/i915/i915_params.c | 74 ++++++++++++++++++++++++
 include/drm/drm_print.h            | 92 ++++++++++++++++++++++--------
 5 files changed, 228 insertions(+), 27 deletions(-)

-- 
2.28.0

[RFC PATCH 1/2] drm: RFC add choice to use dynamic debug in drm-debug

[Jim Cromie]

drm's debug system uses distinct categories of debug messages, mapped
to bits in drm.debug.  Currently, code does a lot of unlikely bit-mask
checks on drm.debug (in drm_debug_enabled), we can use dynamic debug
instead, and get all that jump_label goodness.

RFC: dynamic debug has no concept of category, but we can do without
one if we can prepend a class-prefix to each printk format.  Then we
can use "format ^prefix" to select the whole category with one query.
This is a log-facing and user visible change, but it seems unlikely to
cause trouble for log watchers; they're not relying on the absence of
class prefix strings.

This conversion yields ~2100 new callsites on my i7 laptop:

  dyndbg: 195 debug prints in module drm_kms_helper
  dyndbg: 298 debug prints in module drm
  dyndbg: 1630 debug prints in module i915

Since this change has wide-ranging effects (many drm drivers, with
many callsites, and kernel image growth), and most vendors don't
enable DYNAMIC_DEBUG, we supplement the existing mechanism, adding
CONFIG_DRM_USE_DYNAMIC_DEBUG to enable the new one.

The indirection/switchover has a few parts:

1 a new callback on drm.debug which calls dynamic_debug_exec_queries
  to map those bits to specific query/commands
  dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");

2 a "converted" or "classy" DRM_UT_* map
  similar to DRM_UT_* ( symbol => bit-mask )
  named it  cDRM_UT_* ( symbol => format-class-prefix-string )

  cDRM_UT_* is either ( CONFIG_DRM_USE_DYNAMIC_DEBUG )
  legacy: cDRM_UT_* <-- DRM_UT_*
  enabled:
  +#define cDRM_UT_KMS    "drm:kms: "
  +#define cDRM_UT_PRIME  "drm:prime: "
  +#define cDRM_UT_ATOMIC "drm:atomic: "

  these are similar to "gvt: cmd:" in i915/gvt
  and effectively a replacement for DRM_NAME
  please bikeshed on keys, values. latter are log-facing.

3 drm_dev_dbg & drm_debug are renamed (prefixed with '_')
  old names are now macros, which are ifdefd
  legacy:  -> to renamed fn
  enabled: -> dev_dbg & pr_debug, after prepending prefix to format.

4 names in (2) are called from DRM_DEBUG_<Category> and drm_dbg_<Category>.
  all these get "converted" to use cDRM_UT_*, to get right token type.

RFC: for dynamic debug, category is a source-facing addition;
something like pr_debug_cat(cat, ...) would do it, iff cat is a
compile-time const.  Note that cat isn't needed in the printing, it
would be saved into a new field in struct _ddebug, and used only for
callsite selection, activation and control.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 drivers/gpu/drm/Kconfig     | 13 ++++++
 drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++++++--
 include/drm/drm_print.h     | 92 +++++++++++++++++++++++++++----------
 3 files changed, 153 insertions(+), 27 deletions(-)

diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
index 147d61b9674e..854bc1ad21fb 100644
--- a/drivers/gpu/drm/Kconfig
+++ b/drivers/gpu/drm/Kconfig
@@ -54,6 +54,19 @@ config DRM_DEBUG_MM
 
 	  If in doubt, say "N".
 
+config DRM_USE_DYNAMIC_DEBUG
+	bool "use dynamic debug to implement drm.debug"
+	default n
+	depends on DRM
+	depends on DYNAMIC_DEBUG
+	depends on JUMP_LABEL
+	help
+	  The drm debug category facility does a lot of unlikely bit-field
+	  tests at runtime; while cheap individually, the cost accumulates.
+	  This option uses dynamic debug facility (if configured and
+	  using jump_label) to avoid those runtime checks, patching
+	  the kernel when those debugs are desired.
+
 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..e2acdfc7088b 100644
--- a/drivers/gpu/drm/drm_print.c
+++ b/drivers/gpu/drm/drm_print.c
@@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
 "\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)");
+
+#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
 module_param_named(debug, __drm_debug, int, 0600);
 
+#else
+static char *format_class_prefixes[] = {
+	cDRM_UT_CORE,
+	cDRM_UT_DRIVER,
+	cDRM_UT_KMS,
+	cDRM_UT_PRIME,
+	cDRM_UT_ATOMIC,
+	cDRM_UT_VBL,
+	cDRM_UT_STATE,
+	cDRM_UT_LEASE,
+	cDRM_UT_DP,
+	cDRM_UT_DRMRES
+};
+
+#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
+
+static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
+{
+	unsigned int val;
+	unsigned long changes, result;
+	int rc, chgct = 0, totct = 0, bitpos;
+	char query[OUR_QUERY_SIZE];
+
+	rc = kstrtouint(instr, 0, &val);
+	if (rc) {
+		pr_err("%s: failed\n", __func__);
+		return -EINVAL;
+	}
+	result = val;
+	changes = result ^ __drm_debug;
+
+	pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
+
+	for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
+
+		sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
+			test_bit(bitpos, &result) ? '+' : '-');
+
+		chgct = dynamic_debug_exec_queries(query, "drm*");
+		if (chgct < 0) {
+			pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
+			continue;
+		}
+		pr_debug("change ct:%d on %s\n", chgct, query);
+		totct += chgct;
+	}
+	pr_debug("total changes: %d\n", totct);
+	__drm_debug = result;
+	return 0;
+}
+
+static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
+{
+	pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
+	return scnprintf(buffer, PAGE_SIZE, "%u\n",
+			 *((unsigned int *)kp->arg));
+}
+static const struct kernel_param_ops param_ops_debug = {
+	.set = param_set_dyndbg,
+	.get = param_get_dyndbg,
+};
+module_param_cb(debug, &param_ops_debug, &__drm_debug, 0644);
+
+#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
+
 void __drm_puts_coredump(struct drm_printer *p, const char *str)
 {
 	struct drm_print_iterator *iterator = p->arg;
@@ -256,7 +323,7 @@ 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,
+void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
 		 const char *format, ...)
 {
 	struct va_format vaf;
@@ -278,9 +345,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 +364,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 f32d179e139d..2bd5c38aa100 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -319,6 +319,51 @@ enum drm_debug_category {
 	DRM_UT_DRMRES		= 0x200,
 };
 
+#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
+
+/* Use legacy drm-debug functions, implying drm_debug_enabled().
+ * For cDRM_UT_* (converted category), identity map to DRM_UT_*
+ */
+#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 cDRM_UT_CORE	DRM_UT_CORE
+#define cDRM_UT_DRIVER	DRM_UT_DRIVER
+#define cDRM_UT_KMS	DRM_UT_KMS
+#define cDRM_UT_PRIME	DRM_UT_PRIME
+#define cDRM_UT_ATOMIC	DRM_UT_ATOMIC
+#define cDRM_UT_VBL	DRM_UT_VBL
+#define cDRM_UT_STATE	DRM_UT_STATE
+#define cDRM_UT_LEASE	DRM_UT_LEASE
+#define cDRM_UT_DP	DRM_UT_DP
+#define cDRM_UT_DRMRES	DRM_UT_DRMRES
+
+#else /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
+
+/* use dynamic_debug to avoid drm_debug_enabled.
+ * dyndbg has no category, so we prefix format with a class-string,
+ * and alter cDRM_UT_* to provide those class strings
+ */
+#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 cDRM_UT_CORE	"drm:core: "
+#define cDRM_UT_DRIVER	"drm:drvr: "
+#define cDRM_UT_KMS	"drm:kms: "
+#define cDRM_UT_PRIME	"drm:prime: "
+#define cDRM_UT_ATOMIC	"drm:atomic: "
+#define cDRM_UT_VBL	"drm:vbl: "
+#define cDRM_UT_STATE	"drm:state: "
+#define cDRM_UT_LEASE	"drm:lease: "
+#define cDRM_UT_DP	"drm:dp: "
+#define cDRM_UT_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,7 +379,7 @@ __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,
+void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
 		 const char *format, ...);
 
 /**
@@ -383,7 +428,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, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
 /**
  * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
  *
@@ -391,7 +436,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, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
 /**
  * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
  *
@@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
 
 
 #define drm_dbg_core(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
 #define drm_dbg(drm, fmt, ...)						\
-	drm_dev_dbg((drm)->dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
 #define drm_dbg_kms(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
 #define drm_dbg_prime(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
 #define drm_dbg_atomic(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
 #define drm_dbg_vbl(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_VBL, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
 #define drm_dbg_state(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_STATE, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
 #define drm_dbg_lease(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
 #define drm_dbg_dp(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_DP, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_DP, fmt, ##__VA_ARGS__)
 #define drm_dbg_drmres(drm, fmt, ...)					\
-	drm_dev_dbg((drm)->dev, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
+	drm_dev_dbg((drm)->dev, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
 
 
 /*
@@ -471,7 +516,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 +545,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(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_DRIVER(fmt, ...)					\
-	__drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
+	__drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_KMS(fmt, ...)						\
-	__drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
+	__drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_PRIME(fmt, ...)					\
-	__drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
+	__drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_ATOMIC(fmt, ...)					\
-	__drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
+	__drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_VBL(fmt, ...)						\
-	__drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
+	__drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_LEASE(fmt, ...)					\
-	__drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
+	__drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
 
 #define DRM_DEBUG_DP(fmt, ...)						\
-	__drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
+	__drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
 
 
 #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...)				\
@@ -531,7 +577,7 @@ void __drm_err(const char *format, ...);
 				      DEFAULT_RATELIMIT_INTERVAL,       \
 				      DEFAULT_RATELIMIT_BURST);         \
 	if (__ratelimit(&_rs))						\
-		drm_dev_dbg(NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__);	\
+		drm_dev_dbg(NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__);	\
 })
 
 /*
-- 
2.28.0

[RFC PATCH 2/2] i915: POC use dynamic_debug_exec_queries to control pr_debugs in gvt

[Jim Cromie]

The gvt component of this driver has ~120 pr_debugs, in 9 "classes".
Following model of drm.debug, add a parameter to map bits to these
classes.

In Makefile, add DYNAMIC_DEBUG_MODULE.  This converts gvt's pr_debugs,
even if the rest of drm is not using CONFIG_DRM_USE_DYNAMIC_DEBUG.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 drivers/gpu/drm/i915/gvt/Makefile  |  1 +
 drivers/gpu/drm/i915/i915_params.c | 74 ++++++++++++++++++++++++++++++
 2 files changed, 75 insertions(+)

diff --git a/drivers/gpu/drm/i915/gvt/Makefile b/drivers/gpu/drm/i915/gvt/Makefile
index ea8324abc784..e38a1eb618bd 100644
--- a/drivers/gpu/drm/i915/gvt/Makefile
+++ b/drivers/gpu/drm/i915/gvt/Makefile
@@ -6,4 +6,5 @@ GVT_SOURCE := gvt.o aperture_gm.o handlers.o vgpu.o trace_points.o firmware.o \
 	fb_decoder.o dmabuf.o page_track.o
 
 ccflags-y				+= -I $(srctree)/$(src) -I $(srctree)/$(src)/$(GVT_DIR)/
+ccflags-y				+= -DDYNAMIC_DEBUG_MODULE
 i915-y					+= $(addprefix $(GVT_DIR)/, $(GVT_SOURCE))
diff --git a/drivers/gpu/drm/i915/i915_params.c b/drivers/gpu/drm/i915/i915_params.c
index 7f139ea4a90b..ecc825558e00 100644
--- a/drivers/gpu/drm/i915/i915_params.c
+++ b/drivers/gpu/drm/i915/i915_params.c
@@ -260,3 +260,77 @@ void i915_params_free(struct i915_params *params)
 	I915_PARAMS_FOR_EACH(FREE);
 #undef FREE
 }
+
+/* POC for callback -> dynamic_debug_exec_queries */
+unsigned long __gvt_debug;
+EXPORT_SYMBOL(__gvt_debug);
+
+static char *format_prefix_classes[] = {
+	"gvt: cmd: ",
+	"gvt: core: ",
+	"gvt: dpy: ",
+	"gvt: el: ",
+	"gvt: irq: ",
+	"gvt: mm: ",
+	"gvt: mmio: ",
+	"gvt: render: ",
+	"gvt: sched: "
+};
+#define NUM_CLASSES	ARRAY_SIZE(format_prefix_classes)
+#define OUR_QUERY_SIZE	128 /* we need about 20 */
+
+#include <linux/module.h>
+
+static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
+{
+	unsigned int val;
+	unsigned long changes, result;
+	int rc, chgct = 0, totct = 0, bitpos;
+	char query[OUR_QUERY_SIZE];
+
+	rc = kstrtouint(instr, 0, &val);
+	if (rc) {
+		pr_err("set_dyndbg: failed\n");
+		return -EINVAL;
+	}
+	result = val;
+	pr_info("set_dyndbg: result:0x%lx from %s\n", result, instr);
+
+	changes = result ^ __gvt_debug;
+
+	for_each_set_bit(bitpos, &changes, NUM_CLASSES) {
+
+		sprintf(query, "format '^%s' %cp", format_prefix_classes[bitpos],
+			test_bit(bitpos, &result) ? '+' : '-');
+
+		chgct = dynamic_debug_exec_queries(query, "i915");
+
+		pr_info("%d changes on: %s\n", chgct, query);
+		totct += chgct;
+	}
+	pr_info("total changes: %d\n", totct);
+	__gvt_debug = result;
+	return 0;
+}
+static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
+{
+	return scnprintf(buffer, PAGE_SIZE, "%u\n",
+			 *((unsigned int *)kp->arg));
+}
+static const struct kernel_param_ops param_ops_dyndbg = {
+	.set = param_set_dyndbg,
+	.get = param_get_dyndbg,
+};
+
+MODULE_PARM_DESC(debug_gvt, " gvt debug categories:"
+		 "\n\t0x1\t gvt: cmd:"
+		 "\n\t0x2\t gvt: core:"
+		 "\n\t0x4\t gvt: dpy:"
+		 "\n\t0x8\t gvt: el:"
+		 "\n\t0x10\t gvt: irq:"
+		 "\n\t0x20\t gvt: mm:"
+		 "\n\t0x40\t gvt: mmio:"
+		 "\n\t0x80\t gvt: render:"
+		 "\n\t0x100\t gvt: sched:" "\n");
+
+module_param_cb(debug_gvt, &param_ops_dyndbg, &__gvt_debug, 0644);
-- 
2.28.0

Re: [RFC PATCH 1/2] drm: RFC add choice to use dynamic debug in drm-debug

[Ville Syrjälä]

On Thu, Dec 03, 2020 at 08:53:17PM -0700, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, mapped
> to bits in drm.debug.  Currently, code does a lot of unlikely bit-mask
> checks on drm.debug (in drm_debug_enabled), we can use dynamic debug
> instead, and get all that jump_label goodness.

whatis jump_label?

One thing that bugs me about the current drm_dbg() stuff is that
it's a function, and thus we pay the cost of setting up the
arguments even when debugs are not enabled. I played around a bit
with making it a macro again with the unlikely bit check moved
into the macro. That did seem to make some of the asm a bit nicer
where the debug stuff got shoved out the main codepath, but
it did result in a slight net increase in code size. What I didn't
have time to do is check if this has any measurable speed effect
on eg. TEST_ONLY commits.

And while doing that I started to ponder if we could use something
like the alternate() instruction stuff to patch the code at runtime
in order to turn all those debug checks into nops when debugging
is not enabled. But I couldn't immediately find any generic
infrastructure for it. So now I wonder if this jump_label is something
like that?

> 
> RFC: dynamic debug has no concept of category, but we can do without
> one if we can prepend a class-prefix to each printk format.  Then we
> can use "format ^prefix" to select the whole category with one query.
> This is a log-facing and user visible change, but it seems unlikely to
> cause trouble for log watchers; they're not relying on the absence of
> class prefix strings.
> 
> This conversion yields ~2100 new callsites on my i7 laptop:
> 
>   dyndbg: 195 debug prints in module drm_kms_helper
>   dyndbg: 298 debug prints in module drm
>   dyndbg: 1630 debug prints in module i915
> 
> Since this change has wide-ranging effects (many drm drivers, with
> many callsites, and kernel image growth), and most vendors don't
> enable DYNAMIC_DEBUG, we supplement the existing mechanism, adding
> CONFIG_DRM_USE_DYNAMIC_DEBUG to enable the new one.
> 
> The indirection/switchover has a few parts:
> 
> 1 a new callback on drm.debug which calls dynamic_debug_exec_queries
>   to map those bits to specific query/commands
>   dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> 
> 2 a "converted" or "classy" DRM_UT_* map
>   similar to DRM_UT_* ( symbol => bit-mask )
>   named it  cDRM_UT_* ( symbol => format-class-prefix-string )
> 
>   cDRM_UT_* is either ( CONFIG_DRM_USE_DYNAMIC_DEBUG )
>   legacy: cDRM_UT_* <-- DRM_UT_*
>   enabled:
>   +#define cDRM_UT_KMS    "drm:kms: "
>   +#define cDRM_UT_PRIME  "drm:prime: "
>   +#define cDRM_UT_ATOMIC "drm:atomic: "
> 
>   these are similar to "gvt: cmd:" in i915/gvt
>   and effectively a replacement for DRM_NAME
>   please bikeshed on keys, values. latter are log-facing.
> 
> 3 drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>   old names are now macros, which are ifdefd
>   legacy:  -> to renamed fn
>   enabled: -> dev_dbg & pr_debug, after prepending prefix to format.
> 
> 4 names in (2) are called from DRM_DEBUG_<Category> and drm_dbg_<Category>.
>   all these get "converted" to use cDRM_UT_*, to get right token type.
> 
> RFC: for dynamic debug, category is a source-facing addition;
> something like pr_debug_cat(cat, ...) would do it, iff cat is a
> compile-time const.  Note that cat isn't needed in the printing, it
> would be saved into a new field in struct _ddebug, and used only for
> callsite selection, activation and control.
> 
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  drivers/gpu/drm/Kconfig     | 13 ++++++
>  drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++++++--
>  include/drm/drm_print.h     | 92 +++++++++++++++++++++++++++----------
>  3 files changed, 153 insertions(+), 27 deletions(-)
> 
> diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> index 147d61b9674e..854bc1ad21fb 100644
> --- a/drivers/gpu/drm/Kconfig
> +++ b/drivers/gpu/drm/Kconfig
> @@ -54,6 +54,19 @@ config DRM_DEBUG_MM
>  
>  	  If in doubt, say "N".
>  
> +config DRM_USE_DYNAMIC_DEBUG
> +	bool "use dynamic debug to implement drm.debug"
> +	default n
> +	depends on DRM
> +	depends on DYNAMIC_DEBUG
> +	depends on JUMP_LABEL
> +	help
> +	  The drm debug category facility does a lot of unlikely bit-field
> +	  tests at runtime; while cheap individually, the cost accumulates.
> +	  This option uses dynamic debug facility (if configured and
> +	  using jump_label) to avoid those runtime checks, patching
> +	  the kernel when those debugs are desired.
> +
>  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..e2acdfc7088b 100644
> --- a/drivers/gpu/drm/drm_print.c
> +++ b/drivers/gpu/drm/drm_print.c
> @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
>  "\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)");
> +
> +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
>  module_param_named(debug, __drm_debug, int, 0600);
>  
> +#else
> +static char *format_class_prefixes[] = {
> +	cDRM_UT_CORE,
> +	cDRM_UT_DRIVER,
> +	cDRM_UT_KMS,
> +	cDRM_UT_PRIME,
> +	cDRM_UT_ATOMIC,
> +	cDRM_UT_VBL,
> +	cDRM_UT_STATE,
> +	cDRM_UT_LEASE,
> +	cDRM_UT_DP,
> +	cDRM_UT_DRMRES
> +};
> +
> +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> +
> +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> +{
> +	unsigned int val;
> +	unsigned long changes, result;
> +	int rc, chgct = 0, totct = 0, bitpos;
> +	char query[OUR_QUERY_SIZE];
> +
> +	rc = kstrtouint(instr, 0, &val);
> +	if (rc) {
> +		pr_err("%s: failed\n", __func__);
> +		return -EINVAL;
> +	}
> +	result = val;
> +	changes = result ^ __drm_debug;
> +
> +	pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> +
> +	for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> +
> +		sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> +			test_bit(bitpos, &result) ? '+' : '-');
> +
> +		chgct = dynamic_debug_exec_queries(query, "drm*");
> +		if (chgct < 0) {
> +			pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> +			continue;
> +		}
> +		pr_debug("change ct:%d on %s\n", chgct, query);
> +		totct += chgct;
> +	}
> +	pr_debug("total changes: %d\n", totct);
> +	__drm_debug = result;
> +	return 0;
> +}
> +
> +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> +{
> +	pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> +	return scnprintf(buffer, PAGE_SIZE, "%u\n",
> +			 *((unsigned int *)kp->arg));
> +}
> +static const struct kernel_param_ops param_ops_debug = {
> +	.set = param_set_dyndbg,
> +	.get = param_get_dyndbg,
> +};
> +module_param_cb(debug, &param_ops_debug, &__drm_debug, 0644);
> +
> +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
>  void __drm_puts_coredump(struct drm_printer *p, const char *str)
>  {
>  	struct drm_print_iterator *iterator = p->arg;
> @@ -256,7 +323,7 @@ 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,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>  		 const char *format, ...)
>  {
>  	struct va_format vaf;
> @@ -278,9 +345,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 +364,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 f32d179e139d..2bd5c38aa100 100644
> --- a/include/drm/drm_print.h
> +++ b/include/drm/drm_print.h
> @@ -319,6 +319,51 @@ enum drm_debug_category {
>  	DRM_UT_DRMRES		= 0x200,
>  };
>  
> +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> +
> +/* Use legacy drm-debug functions, implying drm_debug_enabled().
> + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> + */
> +#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 cDRM_UT_CORE	DRM_UT_CORE
> +#define cDRM_UT_DRIVER	DRM_UT_DRIVER
> +#define cDRM_UT_KMS	DRM_UT_KMS
> +#define cDRM_UT_PRIME	DRM_UT_PRIME
> +#define cDRM_UT_ATOMIC	DRM_UT_ATOMIC
> +#define cDRM_UT_VBL	DRM_UT_VBL
> +#define cDRM_UT_STATE	DRM_UT_STATE
> +#define cDRM_UT_LEASE	DRM_UT_LEASE
> +#define cDRM_UT_DP	DRM_UT_DP
> +#define cDRM_UT_DRMRES	DRM_UT_DRMRES
> +
> +#else /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> +/* use dynamic_debug to avoid drm_debug_enabled.
> + * dyndbg has no category, so we prefix format with a class-string,
> + * and alter cDRM_UT_* to provide those class strings
> + */
> +#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 cDRM_UT_CORE	"drm:core: "
> +#define cDRM_UT_DRIVER	"drm:drvr: "
> +#define cDRM_UT_KMS	"drm:kms: "
> +#define cDRM_UT_PRIME	"drm:prime: "
> +#define cDRM_UT_ATOMIC	"drm:atomic: "
> +#define cDRM_UT_VBL	"drm:vbl: "
> +#define cDRM_UT_STATE	"drm:state: "
> +#define cDRM_UT_LEASE	"drm:lease: "
> +#define cDRM_UT_DP	"drm:dp: "
> +#define cDRM_UT_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,7 +379,7 @@ __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,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>  		 const char *format, ...);
>  
>  /**
> @@ -383,7 +428,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, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>  /**
>   * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
>   *
> @@ -391,7 +436,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, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>  /**
>   * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
>   *
> @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>  
>  
>  #define drm_dbg_core(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>  #define drm_dbg(drm, fmt, ...)						\
> -	drm_dev_dbg((drm)->dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>  #define drm_dbg_kms(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>  #define drm_dbg_prime(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
>  #define drm_dbg_atomic(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
>  #define drm_dbg_vbl(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
>  #define drm_dbg_state(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
>  #define drm_dbg_lease(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
>  #define drm_dbg_dp(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_DP, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_DP, fmt, ##__VA_ARGS__)
>  #define drm_dbg_drmres(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
>  
>  
>  /*
> @@ -471,7 +516,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 +545,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(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_DRIVER(fmt, ...)					\
> -	__drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_KMS(fmt, ...)						\
> -	__drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_PRIME(fmt, ...)					\
> -	__drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_ATOMIC(fmt, ...)					\
> -	__drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_VBL(fmt, ...)						\
> -	__drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_LEASE(fmt, ...)					\
> -	__drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_DP(fmt, ...)						\
> -	__drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> +	__drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
>  
>  
>  #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...)				\
> @@ -531,7 +577,7 @@ void __drm_err(const char *format, ...);
>  				      DEFAULT_RATELIMIT_INTERVAL,       \
>  				      DEFAULT_RATELIMIT_BURST);         \
>  	if (__ratelimit(&_rs))						\
> -		drm_dev_dbg(NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__);	\
> +		drm_dev_dbg(NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__);	\
>  })
>  
>  /*
> -- 
> 2.28.0
> 
> _______________________________________________
> dri-devel mailing list
> dri-devel@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/dri-devel

-- 
Ville Syrjälä
Intel

Re: [RFC PATCH 1/2] drm: RFC add choice to use dynamic debug in drm-debug

[jim.cromie]

On Fri, Dec 4, 2020 at 8:42 AM Ville Syrjälä
<ville.syrjala@linux.intel.com> wrote:
>
> On Thu, Dec 03, 2020 at 08:53:17PM -0700, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, mapped
> > to bits in drm.debug.  Currently, code does a lot of unlikely bit-mask
> > checks on drm.debug (in drm_debug_enabled), we can use dynamic debug
> > instead, and get all that jump_label goodness.
>
> whatis jump_label?

Sorry, I should have at least capitalized that, and spelled it differently

kernel/Makefile
118:obj-$(CONFIG_JUMP_LABEL) += jump_label.o

it is the hot-patching substrate underneath it all.
static-key, static-call, etc?
dynamic-debug uses static-key directly.



>
> One thing that bugs me about the current drm_dbg() stuff is that
> it's a function, and thus we pay the cost of setting up the
> arguments even when debugs are not enabled. I played around a bit
> with making it a macro again with the unlikely bit check moved
> into the macro. That did seem to make some of the asm a bit nicer
> where the debug stuff got shoved out the main codepath, but
> it did result in a slight net increase in code size. What I didn't
> have time to do is check if this has any measurable speed effect
> on eg. TEST_ONLY commits.
>
> And while doing that I started to ponder if we could use something
> like the alternate() instruction stuff to patch the code at runtime
> in order to turn all those debug checks into nops when debugging
> is not enabled. But I couldn't immediately find any generic
> infrastructure for it. So now I wonder if this jump_label is something
> like that?
>

this is the droid youre looking for ;-)

> >

> --
> Ville Syrjälä
> Intel

Re: [RFC PATCH 1/2] drm: RFC add choice to use dynamic debug in drm-debug

[Ville Syrjälä]

On Thu, Dec 03, 2020 at 08:53:17PM -0700, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, mapped
> to bits in drm.debug.  Currently, code does a lot of unlikely bit-mask
> checks on drm.debug (in drm_debug_enabled), we can use dynamic debug
> instead, and get all that jump_label goodness.
> 
> RFC: dynamic debug has no concept of category, but we can do without
> one if we can prepend a class-prefix to each printk format.  Then we
> can use "format ^prefix" to select the whole category with one query.
> This is a log-facing and user visible change, but it seems unlikely to
> cause trouble for log watchers; they're not relying on the absence of
> class prefix strings.
> 
> This conversion yields ~2100 new callsites on my i7 laptop:
> 
>   dyndbg: 195 debug prints in module drm_kms_helper
>   dyndbg: 298 debug prints in module drm
>   dyndbg: 1630 debug prints in module i915
> 
> Since this change has wide-ranging effects (many drm drivers, with
> many callsites, and kernel image growth), and most vendors don't
> enable DYNAMIC_DEBUG, we supplement the existing mechanism, adding
> CONFIG_DRM_USE_DYNAMIC_DEBUG to enable the new one.
> 
> The indirection/switchover has a few parts:
> 
> 1 a new callback on drm.debug which calls dynamic_debug_exec_queries
>   to map those bits to specific query/commands
>   dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> 
> 2 a "converted" or "classy" DRM_UT_* map
>   similar to DRM_UT_* ( symbol => bit-mask )
>   named it  cDRM_UT_* ( symbol => format-class-prefix-string )
> 
>   cDRM_UT_* is either ( CONFIG_DRM_USE_DYNAMIC_DEBUG )
>   legacy: cDRM_UT_* <-- DRM_UT_*
>   enabled:
>   +#define cDRM_UT_KMS    "drm:kms: "
>   +#define cDRM_UT_PRIME  "drm:prime: "
>   +#define cDRM_UT_ATOMIC "drm:atomic: "
> 
>   these are similar to "gvt: cmd:" in i915/gvt
>   and effectively a replacement for DRM_NAME
>   please bikeshed on keys, values. latter are log-facing.
> 
> 3 drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>   old names are now macros, which are ifdefd
>   legacy:  -> to renamed fn
>   enabled: -> dev_dbg & pr_debug, after prepending prefix to format.
> 
> 4 names in (2) are called from DRM_DEBUG_<Category> and drm_dbg_<Category>.
>   all these get "converted" to use cDRM_UT_*, to get right token type.
> 
> RFC: for dynamic debug, category is a source-facing addition;
> something like pr_debug_cat(cat, ...) would do it, iff cat is a
> compile-time const.  Note that cat isn't needed in the printing, it
> would be saved into a new field in struct _ddebug, and used only for
> callsite selection, activation and control.
> 
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  drivers/gpu/drm/Kconfig     | 13 ++++++
>  drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++++++--
>  include/drm/drm_print.h     | 92 +++++++++++++++++++++++++++----------
>  3 files changed, 153 insertions(+), 27 deletions(-)
> 
> diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> index 147d61b9674e..854bc1ad21fb 100644
> --- a/drivers/gpu/drm/Kconfig
> +++ b/drivers/gpu/drm/Kconfig
> @@ -54,6 +54,19 @@ config DRM_DEBUG_MM
>  
>  	  If in doubt, say "N".
>  
> +config DRM_USE_DYNAMIC_DEBUG
> +	bool "use dynamic debug to implement drm.debug"
> +	default n
> +	depends on DRM
> +	depends on DYNAMIC_DEBUG
> +	depends on JUMP_LABEL
> +	help
> +	  The drm debug category facility does a lot of unlikely bit-field
> +	  tests at runtime; while cheap individually, the cost accumulates.
> +	  This option uses dynamic debug facility (if configured and
> +	  using jump_label) to avoid those runtime checks, patching
> +	  the kernel when those debugs are desired.
> +
>  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..e2acdfc7088b 100644
> --- a/drivers/gpu/drm/drm_print.c
> +++ b/drivers/gpu/drm/drm_print.c
> @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
>  "\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)");
> +
> +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
>  module_param_named(debug, __drm_debug, int, 0600);
>  
> +#else
> +static char *format_class_prefixes[] = {
> +	cDRM_UT_CORE,
> +	cDRM_UT_DRIVER,
> +	cDRM_UT_KMS,
> +	cDRM_UT_PRIME,
> +	cDRM_UT_ATOMIC,
> +	cDRM_UT_VBL,
> +	cDRM_UT_STATE,
> +	cDRM_UT_LEASE,
> +	cDRM_UT_DP,
> +	cDRM_UT_DRMRES
> +};
> +
> +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> +
> +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> +{
> +	unsigned int val;
> +	unsigned long changes, result;
> +	int rc, chgct = 0, totct = 0, bitpos;
> +	char query[OUR_QUERY_SIZE];
> +
> +	rc = kstrtouint(instr, 0, &val);
> +	if (rc) {
> +		pr_err("%s: failed\n", __func__);
> +		return -EINVAL;
> +	}
> +	result = val;
> +	changes = result ^ __drm_debug;
> +
> +	pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> +
> +	for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> +
> +		sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> +			test_bit(bitpos, &result) ? '+' : '-');
> +
> +		chgct = dynamic_debug_exec_queries(query, "drm*");
> +		if (chgct < 0) {
> +			pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> +			continue;
> +		}
> +		pr_debug("change ct:%d on %s\n", chgct, query);
> +		totct += chgct;
> +	}
> +	pr_debug("total changes: %d\n", totct);
> +	__drm_debug = result;
> +	return 0;
> +}

Is there an actual need to go through dyndbg and do all this stringy
stuff, or would just eg. a static keys array for the debug categories
get us the benefits of jump_label?

> +
> +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> +{
> +	pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> +	return scnprintf(buffer, PAGE_SIZE, "%u\n",
> +			 *((unsigned int *)kp->arg));
> +}
> +static const struct kernel_param_ops param_ops_debug = {
> +	.set = param_set_dyndbg,
> +	.get = param_get_dyndbg,
> +};
> +module_param_cb(debug, &param_ops_debug, &__drm_debug, 0644);
> +
> +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
>  void __drm_puts_coredump(struct drm_printer *p, const char *str)
>  {
>  	struct drm_print_iterator *iterator = p->arg;
> @@ -256,7 +323,7 @@ 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,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>  		 const char *format, ...)
>  {
>  	struct va_format vaf;
> @@ -278,9 +345,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 +364,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 f32d179e139d..2bd5c38aa100 100644
> --- a/include/drm/drm_print.h
> +++ b/include/drm/drm_print.h
> @@ -319,6 +319,51 @@ enum drm_debug_category {
>  	DRM_UT_DRMRES		= 0x200,
>  };
>  
> +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> +
> +/* Use legacy drm-debug functions, implying drm_debug_enabled().
> + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> + */
> +#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 cDRM_UT_CORE	DRM_UT_CORE
> +#define cDRM_UT_DRIVER	DRM_UT_DRIVER
> +#define cDRM_UT_KMS	DRM_UT_KMS
> +#define cDRM_UT_PRIME	DRM_UT_PRIME
> +#define cDRM_UT_ATOMIC	DRM_UT_ATOMIC
> +#define cDRM_UT_VBL	DRM_UT_VBL
> +#define cDRM_UT_STATE	DRM_UT_STATE
> +#define cDRM_UT_LEASE	DRM_UT_LEASE
> +#define cDRM_UT_DP	DRM_UT_DP
> +#define cDRM_UT_DRMRES	DRM_UT_DRMRES
> +
> +#else /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> +/* use dynamic_debug to avoid drm_debug_enabled.
> + * dyndbg has no category, so we prefix format with a class-string,
> + * and alter cDRM_UT_* to provide those class strings
> + */
> +#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 cDRM_UT_CORE	"drm:core: "
> +#define cDRM_UT_DRIVER	"drm:drvr: "
> +#define cDRM_UT_KMS	"drm:kms: "
> +#define cDRM_UT_PRIME	"drm:prime: "
> +#define cDRM_UT_ATOMIC	"drm:atomic: "
> +#define cDRM_UT_VBL	"drm:vbl: "
> +#define cDRM_UT_STATE	"drm:state: "
> +#define cDRM_UT_LEASE	"drm:lease: "
> +#define cDRM_UT_DP	"drm:dp: "
> +#define cDRM_UT_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,7 +379,7 @@ __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,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>  		 const char *format, ...);
>  
>  /**
> @@ -383,7 +428,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, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>  /**
>   * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
>   *
> @@ -391,7 +436,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, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>  /**
>   * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
>   *
> @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>  
>  
>  #define drm_dbg_core(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>  #define drm_dbg(drm, fmt, ...)						\
> -	drm_dev_dbg((drm)->dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>  #define drm_dbg_kms(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>  #define drm_dbg_prime(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
>  #define drm_dbg_atomic(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
>  #define drm_dbg_vbl(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
>  #define drm_dbg_state(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
>  #define drm_dbg_lease(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
>  #define drm_dbg_dp(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_DP, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_DP, fmt, ##__VA_ARGS__)
>  #define drm_dbg_drmres(drm, fmt, ...)					\
> -	drm_dev_dbg((drm)->dev, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> +	drm_dev_dbg((drm)->dev, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
>  
>  
>  /*
> @@ -471,7 +516,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 +545,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(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_DRIVER(fmt, ...)					\
> -	__drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_KMS(fmt, ...)						\
> -	__drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_PRIME(fmt, ...)					\
> -	__drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_ATOMIC(fmt, ...)					\
> -	__drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_VBL(fmt, ...)						\
> -	__drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_LEASE(fmt, ...)					\
> -	__drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> +	__drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
>  
>  #define DRM_DEBUG_DP(fmt, ...)						\
> -	__drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> +	__drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
>  
>  
>  #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...)				\
> @@ -531,7 +577,7 @@ void __drm_err(const char *format, ...);
>  				      DEFAULT_RATELIMIT_INTERVAL,       \
>  				      DEFAULT_RATELIMIT_BURST);         \
>  	if (__ratelimit(&_rs))						\
> -		drm_dev_dbg(NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__);	\
> +		drm_dev_dbg(NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__);	\
>  })
>  
>  /*
> -- 
> 2.28.0
> 
> _______________________________________________
> dri-devel mailing list
> dri-devel@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/dri-devel

-- 
Ville Syrjälä
Intel

Re: [RFC PATCH 1/2] drm: RFC add choice to use dynamic debug in drm-debug

[jim.cromie]

On Fri, Dec 11, 2020 at 8:34 AM Ville Syrjälä
<ville.syrjala@linux.intel.com> wrote:
>
> On Thu, Dec 03, 2020 at 08:53:17PM -0700, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, mapped
> > to bits in drm.debug.  Currently, code does a lot of unlikely bit-mask
> > checks on drm.debug (in drm_debug_enabled), we can use dynamic debug
> > instead, and get all that jump_label goodness.

> Is there an actual need to go through dyndbg and do all this stringy
> stuff, or would just eg. a static keys array for the debug categories
> get us the benefits of jump_label?
>

You certainly can strip the car, take the engine.
but you might need some of the drivetrain too.
maybe you want to skip the heated seats ?
dyndbg has some stuff you dont need, for sure.

for one, its heavy on data per callsite, with a static-key and
overhead for each.

But Id be wary that the jump-label code-patching is a slow path,
so trying to change hundreds of jump-sites with one static-key field
may run into problems with long lock hold times, etc.

There is a batching mechanism built-in to the jump-label stuff somewhere,
my impression is that it amortized system-wide syncs while being RT aware.


I've been working on trimming dyndbg down, at least the memory.
I'll be sending it out shortly, but heres a preview:


Subject: [RFC PATCH v2 0/7] dynamic debug diet plan

V2 is a rethought diet plan for dyndbg (I meant -v1 as rfc).

at highest level, patchset does:
1- move struct _ddebug "selector" fields to new struct _ddebug_callsite
2- make ddebug_callsites optional, good for some users
3- allow dropping callsites by those users.

1-v2. Rasmus noted that I shouldn't move format with the other fields,
and I realized that the "module:function:line" dynamic prefixes are
ultimately just log decorations, and are not needed for certain use
cases, including drm (with category -> prefix adaptation).

The drm use case:

- can benefit from jump-labels to avoid drm_debug_enabled()
- can map categories to format-prefixes: "drm:core:" "drm:kms:" etc
- can use dynamic_debug_exec_queries("format ^drm:core: +p", NULL)
- drm + amdgpu have ~3200 drm-debugs, drm + i915 have ~1600

If drm dropped optional site info, net 16 bytes saved / callsite, maybe more...

dropping optional info : module file func means loss of log "decorations"
and slimmer contents of control file.  uncategorized pr-debugs can be
avoided when dropping callsites.   Even with dropped info,
format, line, module queries can select individual sites precisely.

As of now, we still need the __dyndbg_callsites linker section; the
3-drop is just a forget-the-addy, not a kfree.

But compression is possible. v1 tried using zram, with mixed success.
v2 is a better foundation to re-try the zram.