[Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*

Robert Bragg robert at sixbynine.org
Mon Dec 5 11:24:44 UTC 2016


Forgot to send to dri-devel when I first sent this out...

The few times I've looked at using DRM_DEBUG messages, I haven't found
them very helpful considering how noisy some of the categories are. More
than once now I've preferred to go in and modify individual files to
affect what messages I see and re-build.

After recently converting some of the i915_perf.c messages to use
DRM_DEBUG, I thought I'd see if DRM_DEBUG could be updated to have a bit
more fine grained control than the current category flags.

A few things to note with this first iteration:

- I haven't looked to see what affect the change has on linked object
  sizes.

- It seems like it could be nice if dynamic debug could effectively make
  the drm_debug parameter redundant but dynamic debug doesn't give us a
  way to categorise messages so maybe we'd want to consider including
  categories in messages something like:

  "[drm][kms] No FB found"

  This way all kms messages could be enabled via:
  echo "format [kms] +p" > dynamic_debug/control

  Note with this simple scheme categories would no longer be mutually
  exclusive which could be a nice bonus.

  Since it would involve changing the output format, I wonder how
  concerned others might be about breaking some userspace (maybe CI test
  runners) that for some reason grep for specific messages?

--- >8 --- (git am --scissors)

Dynamic debug messages (ref: Documentation/dynamic-debug-howto.txt)
allow fine grained control over which debug messages are enabled with
runtime control through /sysfs/kernel/debug/dynamic_debug/control

This provides more control than the current drm.drm_debug parameter
which for some use cases is impractical to use given how chatty
some drm debug categories are.

For example all debug messages in i915_drm.c can be enabled with:
echo "file i915_perf.c +p" > dynamic_debug/control

This aims to maintain compatibility with controlling debug messages
using the drm_debug parameter. The new dynamic debug macros are called
by default but conditionally calling [dev_]printk if the category flag
is set (side stepping the dynamic debug condition in that case)

This removes the drm_[dev_]printk wrappers considering that the dynamic
debug macros are only useful if they can track the __FILE__, __func__
and __LINE__ where they are called. The wrapper didn't seem necessary in
the DRM_UT_NONE case with no category flag.

The output format should be compatible, unless the _DEV macros are
passed a NULL dev pointer considering how the core.c dev_printk
implementation adds "(NULL device *)" to the message in that case while
the drm wrapper would fallback to a plain printk in this case.
Previously some of non-dev drm debug macros were defined in terms of
passing NULL to a dev version but that's avoided now due to this
difference.

Signed-off-by: Robert Bragg <robert at sixbynine.org>
Cc: dri-devel at lists.freedesktop.org
Cc: Daniel Vetter <daniel.vetter at ffwll.ch>
Cc: Chris Wilson <chris at chris-wilson.co.uk>
---
 drivers/gpu/drm/drm_drv.c |  47 -------------
 include/drm/drmP.h        | 168 +++++++++++++++++++++++++++++-----------------
 2 files changed, 108 insertions(+), 107 deletions(-)

diff --git a/drivers/gpu/drm/drm_drv.c b/drivers/gpu/drm/drm_drv.c
index f74b7d0..25d00aa 100644
--- a/drivers/gpu/drm/drm_drv.c
+++ b/drivers/gpu/drm/drm_drv.c
@@ -65,53 +65,6 @@ static struct idr drm_minors_idr;
 
 static struct dentry *drm_debugfs_root;
 
-#define DRM_PRINTK_FMT "[" DRM_NAME ":%s]%s %pV"
-
-void drm_dev_printk(const struct device *dev, const char *level,
-		    unsigned int category, const char *function_name,
-		    const char *prefix, const char *format, ...)
-{
-	struct va_format vaf;
-	va_list args;
-
-	if (category != DRM_UT_NONE && !(drm_debug & category))
-		return;
-
-	va_start(args, format);
-	vaf.fmt = format;
-	vaf.va = &args;
-
-	if (dev)
-		dev_printk(level, dev, DRM_PRINTK_FMT, function_name, prefix,
-			   &vaf);
-	else
-		printk("%s" DRM_PRINTK_FMT, level, function_name, prefix, &vaf);
-
-	va_end(args);
-}
-EXPORT_SYMBOL(drm_dev_printk);
-
-void drm_printk(const char *level, unsigned int category,
-		const char *format, ...)
-{
-	struct va_format vaf;
-	va_list args;
-
-	if (category != DRM_UT_NONE && !(drm_debug & category))
-		return;
-
-	va_start(args, format);
-	vaf.fmt = format;
-	vaf.va = &args;
-
-	printk("%s" "[" DRM_NAME ":%ps]%s %pV",
-	       level, __builtin_return_address(0),
-	       strcmp(level, KERN_ERR) == 0 ? " *ERROR*" : "", &vaf);
-
-	va_end(args);
-}
-EXPORT_SYMBOL(drm_printk);
-
 /*
  * DRM Minors
  * A DRM device can provide several char-dev interfaces on the DRM-Major. Each
diff --git a/include/drm/drmP.h b/include/drm/drmP.h
index a9cfd33..680f359 100644
--- a/include/drm/drmP.h
+++ b/include/drm/drmP.h
@@ -58,6 +58,7 @@
 #include <linux/vmalloc.h>
 #include <linux/workqueue.h>
 #include <linux/dma-fence.h>
+#include <linux/dynamic_debug.h>
 
 #include <asm/mman.h>
 #include <asm/pgalloc.h>
@@ -129,7 +130,6 @@ struct dma_buf_attachment;
  * run-time by echoing the debug value in its sysfs node:
  *   # echo 0xf > /sys/module/drm/parameters/debug
  */
-#define DRM_UT_NONE		0x00
 #define DRM_UT_CORE 		0x01
 #define DRM_UT_DRIVER		0x02
 #define DRM_UT_KMS		0x04
@@ -146,25 +146,22 @@ struct dma_buf_attachment;
 /** \name Macros to make printk easier */
 /*@{*/
 
-#define _DRM_PRINTK(once, level, fmt, ...)				\
-	do {								\
-		printk##once(KERN_##level "[" DRM_NAME "] " fmt,	\
-			     ##__VA_ARGS__);				\
-	} while (0)
+#define _DRM_FMT_PREFIX "[" DRM_NAME "] "
+#define _DRM_FMT_FUNC_PREFIX "[" DRM_NAME ":%s] "
 
 #define DRM_INFO(fmt, ...)						\
-	_DRM_PRINTK(, INFO, fmt, ##__VA_ARGS__)
+	pr_info(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__)
 #define DRM_NOTE(fmt, ...)						\
-	_DRM_PRINTK(, NOTICE, fmt, ##__VA_ARGS__)
+	pr_notice(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__)
 #define DRM_WARN(fmt, ...)						\
-	_DRM_PRINTK(, WARNING, fmt, ##__VA_ARGS__)
+	pr_warn(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__)
 
 #define DRM_INFO_ONCE(fmt, ...)						\
-	_DRM_PRINTK(_once, INFO, fmt, ##__VA_ARGS__)
+	pr_info_once(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__)
 #define DRM_NOTE_ONCE(fmt, ...)						\
-	_DRM_PRINTK(_once, NOTICE, fmt, ##__VA_ARGS__)
+	pr_notice_once(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__)
 #define DRM_WARN_ONCE(fmt, ...)						\
-	_DRM_PRINTK(_once, WARNING, fmt, ##__VA_ARGS__)
+	pr_warn_once(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__)
 
 /**
  * Error output.
@@ -173,10 +170,11 @@ struct dma_buf_attachment;
  * \param arg arguments
  */
 #define DRM_DEV_ERROR(dev, fmt, ...)					\
-	drm_dev_printk(dev, KERN_ERR, DRM_UT_NONE, __func__, " *ERROR*",\
-		       fmt, ##__VA_ARGS__)
+	dev_err(dev, _DRM_FMT_FUNC_PREFIX "*ERROR*" fmt, __func__,	\
+		##__VA_ARGS__)
 #define DRM_ERROR(fmt, ...)						\
-	drm_printk(KERN_ERR, DRM_UT_NONE, fmt,	##__VA_ARGS__)
+	pr_err(_DRM_FMT_FUNC_PREFIX "*ERROR*" fmt, __func__,	        \
+	       ##__VA_ARGS__)
 
 /**
  * Rate limited error output.  Like DRM_ERROR() but won't flood the log.
@@ -193,21 +191,14 @@ struct dma_buf_attachment;
 	if (__ratelimit(&_rs))						\
 		DRM_DEV_ERROR(dev, fmt, ##__VA_ARGS__);			\
 })
-#define DRM_ERROR_RATELIMITED(fmt, ...)					\
-	DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
+#define DRM_ERROR_RATELIMITED(fmt, args...)				\
+	DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##args)
 
-#define DRM_DEV_INFO(dev, fmt, ...)					\
-	drm_dev_printk(dev, KERN_INFO, DRM_UT_NONE, __func__, "", fmt,	\
-		       ##__VA_ARGS__)
+#define DRM_DEV_INFO(dev, fmt, args...)					\
+	dev_info(dev, _DRM_FMT_FUNC_PREFIX fmt, __func__, ##args)
 
-#define DRM_DEV_INFO_ONCE(dev, fmt, ...)				\
-({									\
-	static bool __print_once __read_mostly;				\
-	if (!__print_once) {						\
-		__print_once = true;					\
-		DRM_DEV_INFO(dev, fmt, ##__VA_ARGS__);			\
-	}								\
-})
+#define DRM_DEV_INFO_ONCE(dev, fmt, args...)				\
+	dev_info_once(dev, _DRM_FMT_FUNC_PREFIX fmt, __func__, ##args)
 
 /**
  * Debug output.
@@ -215,50 +206,104 @@ struct dma_buf_attachment;
  * \param fmt printf() like format string.
  * \param arg arguments
  */
+
+#if defined(CONFIG_DYNAMIC_DEBUG)
+/* We don't use pr_debug and dev_dbg directly since we want to
+ * maintain format compatibility with non-dynamic drm debug messages
+ */
+#define _DRM_DYNAMIC_DEV_DEBUG(dev, fmt, args...)			\
+({									\
+	DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);			\
+	if (DYNAMIC_DEBUG_BRANCH(descriptor))				\
+		dev_printk(KERN_DEBUG, dev, fmt, ##args);		\
+})
+#define _DRM_DYNAMIC_DEBUG(fmt, args...)				\
+({									\
+	DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);			\
+	if (DYNAMIC_DEBUG_BRANCH(descriptor))				\
+		printk(KERN_DEBUG fmt, ##args);				\
+})
+#else
+#define _DRM_DYNAMIC_DEV_DEBUG(dev, fmt, args...)			\
+	no_printk(fmt, ##args)
+#define _DRM_DYNAMIC_DEBUG(fmt, args...)				\
+	no_printk(fmt, ##args)
+#endif
+
+/* The conditional use of pr_debug/dev_dbg here allows us to take
+ * advantage of the kernel's dynamic debug feature by default (ref
+ * Documentation/dynamic-debug-howto.txt) while maintaining
+ * compatibility with using drm.drm_debug to turn on sets of messages
+ *
+ * Note: pr_debug and dev_dbg can't be called by a wrapper function
+ * otherwise they can't track the __FILE__, __func__ and __LINE__
+ * where they are called.
+ */
+#define _DRM_DEV_DEBUG(dev, category, fmt, args...)			\
+({									\
+	if (unlikely(drm_debug & category)) {				\
+	    dev_printk(KERN_DEBUG, dev, _DRM_FMT_FUNC_PREFIX fmt,	\
+		       __func__, ##args);				\
+	} else {							\
+	    _DRM_DYNAMIC_DEV_DEBUG(dev, _DRM_FMT_FUNC_PREFIX fmt,	\
+				   __func__, ##args);			\
+	}								\
+})
+#define _DRM_DEBUG(category, fmt, args...)				\
+({									\
+	if (unlikely(drm_debug & category)) {				\
+	    printk(KERN_DEBUG _DRM_FMT_FUNC_PREFIX fmt,			\
+		   __func__, ##args);					\
+	} else								\
+	    _DRM_DYNAMIC_DEBUG(_DRM_FMT_FUNC_PREFIX fmt,		\
+			       __func__, ##args);			\
+})
+
 #define DRM_DEV_DEBUG(dev, fmt, args...)				\
-	drm_dev_printk(dev, KERN_DEBUG, DRM_UT_CORE, __func__, "", fmt,	\
-		       ##args)
-#define DRM_DEBUG(fmt, ...)						\
-	drm_printk(KERN_DEBUG, DRM_UT_CORE, fmt, ##__VA_ARGS__)
+	_DRM_DEV_DEBUG(dev, DRM_UT_CORE, fmt, ##args)
+#define DRM_DEBUG(fmt, args...)						\
+	_DRM_DEBUG(DRM_UT_CORE, fmt, ##args)
 
 #define DRM_DEV_DEBUG_DRIVER(dev, fmt, args...)				\
-	drm_dev_printk(dev, KERN_DEBUG, DRM_UT_DRIVER, __func__, "",	\
-		       fmt, ##args)
-#define DRM_DEBUG_DRIVER(fmt, ...)					\
-	drm_printk(KERN_DEBUG, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
+	_DRM_DEV_DEBUG(dev, DRM_UT_DRIVER, fmt, ##args)
+#define DRM_DEBUG_DRIVER(fmt, args...)					\
+	_DRM_DEBUG(DRM_UT_DRIVER, fmt, ##args)
 
 #define DRM_DEV_DEBUG_KMS(dev, fmt, args...)				\
-	drm_dev_printk(dev, KERN_DEBUG, DRM_UT_KMS, __func__, "", fmt,	\
-		       ##args)
-#define DRM_DEBUG_KMS(fmt, ...)					\
-	drm_printk(KERN_DEBUG, DRM_UT_KMS, fmt, ##__VA_ARGS__)
+	_DRM_DEV_DEBUG(dev, DRM_UT_KMS, fmt, ##args)
+#define DRM_DEBUG_KMS(fmt, args...)					\
+	_DRM_DEBUG(DRM_UT_KMS, fmt, ##args)
 
 #define DRM_DEV_DEBUG_PRIME(dev, fmt, args...)				\
-	drm_dev_printk(dev, KERN_DEBUG, DRM_UT_PRIME, __func__, "",	\
-		       fmt, ##args)
-#define DRM_DEBUG_PRIME(fmt, ...)					\
-	drm_printk(KERN_DEBUG, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
+	_DRM_DEV_DEBUG(dev, DRM_UT_PRIME, fmt, ##args)
+#define DRM_DEBUG_PRIME(fmt, args...)					\
+	_DRM_DEBUG(DRM_UT_PRIME, fmt, ##args)
 
 #define DRM_DEV_DEBUG_ATOMIC(dev, fmt, args...)				\
-	drm_dev_printk(dev, KERN_DEBUG, DRM_UT_ATOMIC, __func__, "",	\
-		       fmt, ##args)
-#define DRM_DEBUG_ATOMIC(fmt, ...)					\
-	drm_printk(KERN_DEBUG, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
+	_DRM_DEV_DEBUG(dev, DRM_UT_ATOMIC, fmt, ##args)
+#define DRM_DEBUG_ATOMIC(fmt, args...)					\
+	_DRM_DEBUG(DRM_UT_ATOMIC, fmt, ##args)
 
 #define DRM_DEV_DEBUG_VBL(dev, fmt, args...)				\
-	drm_dev_printk(dev, KERN_DEBUG, DRM_UT_VBL, __func__, "", fmt,	\
-		       ##args)
-#define DRM_DEBUG_VBL(fmt, ...)					\
-	drm_printk(KERN_DEBUG, DRM_UT_VBL, fmt, ##__VA_ARGS__)
+	_DRM_DEV_DEBUG(dev, DRM_UT_VBL, fmt, ##args)
+#define DRM_DEBUG_VBL(fmt, args...)					\
+	_DRM_DEBUG(DRM_UT_VBL, fmt, ##args)
 
-#define _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, level, fmt, args...)	\
+#define _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, category, fmt, args...)	\
+({									\
+	static DEFINE_RATELIMIT_STATE(_rs,				\
+				      DEFAULT_RATELIMIT_INTERVAL,	\
+				      DEFAULT_RATELIMIT_BURST);		\
+	if (__ratelimit(&_rs))						\
+		_DRM_DEV_DEBUG(dev, DRM_UT_ ## category, fmt, ##args);	\
+})
+#define _DRM_DEFINE_DEBUG_RATELIMITED(category, fmt, args...)	\
 ({									\
 	static DEFINE_RATELIMIT_STATE(_rs,				\
 				      DEFAULT_RATELIMIT_INTERVAL,	\
 				      DEFAULT_RATELIMIT_BURST);		\
 	if (__ratelimit(&_rs))						\
-		drm_dev_printk(dev, KERN_DEBUG, DRM_UT_ ## level,	\
-			       __func__, "", fmt, ##args);		\
+		_DRM_DEBUG(DRM_UT_ ## category, fmt, ##args);		\
 })
 
 /**
@@ -268,21 +313,24 @@ struct dma_buf_attachment;
  * \param arg arguments
  */
 #define DRM_DEV_DEBUG_RATELIMITED(dev, fmt, args...)			\
-	DEV__DRM_DEFINE_DEBUG_RATELIMITED(dev, CORE, fmt, ##args)
+	_DRM_DEFINE_DEBUG_RATELIMITED(dev, CORE, fmt, ##args)
 #define DRM_DEBUG_RATELIMITED(fmt, args...)				\
-	DRM_DEV_DEBUG_RATELIMITED(NULL, fmt, ##args)
+	_DRM_DEFINE_DEBUG_RATELIMITED(CORE, fmt, ##args)
+
 #define DRM_DEV_DEBUG_DRIVER_RATELIMITED(dev, fmt, args...)		\
 	_DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, DRIVER, fmt, ##args)
 #define DRM_DEBUG_DRIVER_RATELIMITED(fmt, args...)			\
-	DRM_DEV_DEBUG_DRIVER_RATELIMITED(NULL, fmt, ##args)
+	_DRM_DEV_DEFINE_DEBUG_RATELIMITED(DRIVER, fmt, ##args)
+
 #define DRM_DEV_DEBUG_KMS_RATELIMITED(dev, fmt, args...)		\
 	_DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, KMS, fmt, ##args)
 #define DRM_DEBUG_KMS_RATELIMITED(fmt, args...)				\
-	DRM_DEV_DEBUG_KMS_RATELIMITED(NULL, fmt, ##args)
+	_DRM_DEFINE_DEBUG_RATELIMITED(KMS, fmt, ##args)
+
 #define DRM_DEV_DEBUG_PRIME_RATELIMITED(dev, fmt, args...)		\
 	_DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, PRIME, fmt, ##args)
 #define DRM_DEBUG_PRIME_RATELIMITED(fmt, args...)			\
-	DRM_DEV_DEBUG_PRIME_RATELIMITED(NULL, fmt, ##args)
+	_DRM_DEFINE_DEBUG_RATELIMITED(PRIME, fmt, ##args)
 
 /* Format strings and argument splitters to simplify printing
  * various "complex" objects
-- 
2.10.2



More information about the Intel-gfx mailing list