All of lore.kernel.org
 help / color / mirror / Atom feed
* [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
@ 2016-12-05 11:24 Robert Bragg
  2016-12-05 16:31 ` Daniel Vetter
  2016-12-05 18:54 ` ✓ Fi.CI.BAT: success for drm: Enable dynamic debug for DRM_[DEV]_DEBUG* (rev2) Patchwork
  0 siblings, 2 replies; 6+ messages in thread
From: Robert Bragg @ 2016-12-05 11:24 UTC (permalink / raw)
  To: dri-devel; +Cc: Daniel Vetter, intel-gfx

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@sixbynine.org>
Cc: dri-devel@lists.freedesktop.org
Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
Cc: Chris Wilson <chris@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

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

^ permalink raw reply related	[flat|nested] 6+ messages in thread
* Re: [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
  2016-12-05 11:24 [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG* Robert Bragg
@ 2016-12-05 16:31 ` Daniel Vetter
  2016-12-07 19:15   ` Robert Bragg
  2016-12-05 18:54 ` ✓ Fi.CI.BAT: success for drm: Enable dynamic debug for DRM_[DEV]_DEBUG* (rev2) Patchwork
  1 sibling, 1 reply; 6+ messages in thread
From: Daniel Vetter @ 2016-12-05 16:31 UTC (permalink / raw)
  To: Robert Bragg; +Cc: Daniel Vetter, intel-gfx, dri-devel

On Mon, Dec 05, 2016 at 11:24:44AM +0000, Robert Bragg wrote:
> 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.

Really nice idea, and I agree that unifying drm.debug with dynamic debug
in some way would be useful. We could implement your idea by reworking the
existing debug helpers to auto-prepend the right string. That also opens
up the door for much more fine-grained bucketing maybe, only challenge is
that we should document things somewhere.

>   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?

I think the only thing we have to keep working (somehow) is drm.debug. The
exact output format doesn't really matter at all. Getting drm.debug to
work when dynamic debugging is enabled probably requires exporting some
functions, so that we can set the right ddebug options from the drm.debug
mod-option write handler. There's special mod-option macros that allow you
to specify write handlers, so that part is ok.

The other bit of backwards compat we imo need is that by default we should
still keep drm.debug working, even when dynamic debugging is disabled.
Having a third option that uses no_printk or similar (to get rid of all
the debug strings and dead-code-eliminate all the related output code)

> --- >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@sixbynine.org>
> Cc: dri-devel@lists.freedesktop.org
> Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
> Cc: Chris Wilson <chris@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

Since I brought up some changes for the debug stuff itself, would it make
sense to split that from the general macro rework for all the non-debug
output, and merge that first?

Another thing to look into: I think it'd be good to move all the print
definitions into drm_print.[hc], since drmP.h is a mess, and drm_drv.c not
really the right place. That would then also allow us to easily document
all the variants, and put something like the intro message for this commit
into the overview DOC: section.
-Daniel
-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

^ permalink raw reply	[flat|nested] 6+ messages in thread
* ✓ Fi.CI.BAT: success for drm: Enable dynamic debug for DRM_[DEV]_DEBUG* (rev2)
  2016-12-05 11:24 [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG* Robert Bragg
  2016-12-05 16:31 ` Daniel Vetter
@ 2016-12-05 18:54 ` Patchwork
  1 sibling, 0 replies; 6+ messages in thread
From: Patchwork @ 2016-12-05 18:54 UTC (permalink / raw)
  To: Robert Bragg; +Cc: intel-gfx

== Series Details ==

Series: drm: Enable dynamic debug for DRM_[DEV]_DEBUG* (rev2)
URL   : https://patchwork.freedesktop.org/series/16235/
State : success

== Summary ==

Series 16235v2 drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
https://patchwork.freedesktop.org/api/1.0/series/16235/revisions/2/mbox/


fi-bdw-5557u     total:247  pass:232  dwarn:0   dfail:0   fail:0   skip:15 
fi-bsw-n3050     total:247  pass:207  dwarn:0   dfail:0   fail:0   skip:40 
fi-bxt-t5700     total:247  pass:219  dwarn:0   dfail:0   fail:0   skip:28 
fi-byt-j1900     total:247  pass:219  dwarn:0   dfail:0   fail:0   skip:28 
fi-byt-n2820     total:247  pass:215  dwarn:0   dfail:0   fail:0   skip:32 
fi-hsw-4770      total:247  pass:227  dwarn:0   dfail:0   fail:0   skip:20 
fi-hsw-4770r     total:247  pass:227  dwarn:0   dfail:0   fail:0   skip:20 
fi-ilk-650       total:247  pass:194  dwarn:0   dfail:0   fail:0   skip:53 
fi-ivb-3520m     total:247  pass:225  dwarn:0   dfail:0   fail:0   skip:22 
fi-ivb-3770      total:247  pass:225  dwarn:0   dfail:0   fail:0   skip:22 
fi-kbl-7500u     total:247  pass:225  dwarn:0   dfail:0   fail:0   skip:22 
fi-skl-6260u     total:247  pass:233  dwarn:0   dfail:0   fail:0   skip:14 
fi-skl-6700hq    total:247  pass:226  dwarn:0   dfail:0   fail:0   skip:21 
fi-skl-6770hq    total:247  pass:233  dwarn:0   dfail:0   fail:0   skip:14 
fi-snb-2520m     total:247  pass:215  dwarn:0   dfail:0   fail:0   skip:32 
fi-snb-2600      total:247  pass:214  dwarn:0   dfail:0   fail:0   skip:33 
fi-skl-6700k failed to connect after reboot

a17bd268c6f9e1076a9aea44573ff58b0caeb44d drm-tip: 2016y-12m-05d-11h-19m-41s UTC integration manifest
47ab954 drm: Enable dynamic debug for DRM_[DEV]_DEBUG*

== Logs ==

For more details see: https://intel-gfx-ci.01.org/CI/Patchwork_3190/
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

^ permalink raw reply	[flat|nested] 6+ messages in thread
* Re: [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
  2016-12-05 16:31 ` Daniel Vetter
@ 2016-12-07 19:15   ` Robert Bragg
  0 siblings, 0 replies; 6+ messages in thread
From: Robert Bragg @ 2016-12-07 19:15 UTC (permalink / raw)
  To: Daniel Vetter; +Cc: Daniel Vetter, Intel Graphics Development, ML dri-devel


[-- Attachment #1.1: Type: text/plain, Size: 22604 bytes --]

On Mon, Dec 5, 2016 at 4:31 PM, Daniel Vetter <daniel@ffwll.ch> wrote:

> On Mon, Dec 05, 2016 at 11:24:44AM +0000, Robert Bragg wrote:
> > 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.
>
> Really nice idea, and I agree that unifying drm.debug with dynamic debug
> in some way would be useful. We could implement your idea by reworking the
> existing debug helpers to auto-prepend the right string. That also opens
> up the door for much more fine-grained bucketing maybe, only challenge is
> that we should document things somewhere.
>

yup, I don't mind writing some doc updates for this if it looks worthwhile.


>
> >   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?
>
> I think the only thing we have to keep working (somehow) is drm.debug. The
> exact output format doesn't really matter at all. Getting drm.debug to
> work when dynamic debugging is enabled probably requires exporting some
> functions, so that we can set the right ddebug options from the drm.debug
> mod-option write handler. There's special mod-option macros that allow you
> to specify write handlers, so that part is ok.
>

dynamic_debug.h exposes a macro for declaring your own dynamic debug meta
data as well as a macro for testing whether the message has been enabled.

I'm handling compatibility by using those macros so I can still test the
drm.drm_debug flags.

Handling compatibility in terms of running control queries from the kernel
would be a bit more tricky since we'd need to export some api from
dynamic_debug.c as well as adding a write handler for drm_debug. Also the
enabledness of messages is boolean not refcounted so I suppose there could
be slightly annoying interactions if mixing both - though that could be
documented.

The only disadvantage I can think of currently for not handling
compatibility in terms of running control queries is that the dynamic debug
macros can normally avoid evaluating any conditions on the cpu while a
message is disabled, based on jump labels/static branches. We were already
evaluating a condition for disabled drm debug messages though, so it seems
reasonable to continue for now.


>
> The other bit of backwards compat we imo need is that by default we should
> still keep drm.debug working, even when dynamic debugging is disabled.
> Having a third option that uses no_printk or similar (to get rid of all
> the debug strings and dead-code-eliminate all the related output code)
>

Yeah, I think the current code already handles this, but sorry if it's not
clear.

This version is #ifdefed so that if dynamic debug isn't enabled the dynamic
debug path reduces to a no_prink

I'm considering CONFIG_DYNAMIC_DEBUG being enabled or not and when enabled
I check drm_debug and the dynamic debug state, when disabled I'm just
checking the drm_debug flags and the dynamic debugs bits boil out.

In my updated patch things we re-jigged a little so pr_debug and dev_dbg
are used when CONFIG_DYNAMIC_DEBUG is not enabled, and these internally
boil down to no_printk if DEBUG is disabled. Actually we might want to
consider if that's the desired behaviour - since DRM_DEBUG wasn't
previously affected by DEBUG being defined or not.


> > --- >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@sixbynine.org>
> > Cc: dri-devel@lists.freedesktop.org
> > Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
> > Cc: Chris Wilson <chris@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
>
> Since I brought up some changes for the debug stuff itself, would it make
> sense to split that from the general macro rework for all the non-debug
> output, and merge that first?
>
> Another thing to look into: I think it'd be good to move all the print
> definitions into drm_print.[hc], since drmP.h is a mess, and drm_drv.c not
> really the right place. That would then also allow us to easily document
> all the variants, and put something like the intro message for this commit
> into the overview DOC: section.
> -Daniel
> --
> Daniel Vetter
> Software Engineer, Intel Corporation
> http://blog.ffwll.ch
>

[-- Attachment #1.2: Type: text/html, Size: 30100 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

^ permalink raw reply	[flat|nested] 6+ messages in thread
* Re: [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
  2016-12-01 17:18 [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG* Robert Bragg
@ 2016-12-02  8:01 ` Daniel Vetter
  0 siblings, 0 replies; 6+ messages in thread
From: Daniel Vetter @ 2016-12-02  8:01 UTC (permalink / raw)
  To: Robert Bragg; +Cc: intel-gfx

On Thu, Dec 01, 2016 at 05:18:00PM +0000, Robert Bragg wrote:
> I'm currently considering the use of DRM_ERROR in i915 perf for steam
> config validation errors (i.e. userspace misconfigurations) that should
> be changed so that i-g-t tests aren't treated as failures when
> triggering these.
> 
> I initially proposed changing these to DRM_INFO messages and
> intentionally wanted to avoid DRM_DEBUG since in my limited experience
> DRM_DEBUG messages aren't practical to work with.
> 
> I thought I'd see if DRM_DEBUG could be updated to have a bit more fine
> grained control in case that might help sway my view.
> 
> Tbh, although I think something like this could be nice to have, I'm
> still not really convinced that debug messages are a great fit for
> helping userspace developers hitting EINVAL errors. Such developers
> don't need to be drm/i915 developers and imho shouldn't be expected to
> know of the existence of optional debug messages, and if you don't know
> of there existence then the control interface isn't important and they
> won't help anyone.

Sounds like we'd need a bit more documentation in drm-uapi.rst ;-) We
really can't spam dmesg by default for userspace fail, e.g. if you open a
file that isn't there dmesg also doesn't tell you what exactly went wrong
(e.g. which directory in your path it couldn't find).

But I wanted to trick someone into looking into dynamic debugging since
forever, since the current drm.debug firehose is indeed unmanageable by
default. So I very much like the idea you're pushing for here.

But needs to be discussed on dri-devel, pls resubmit with that on cc.

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

;-)

Cheers, Daniel

> 
> 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.
> 
> I haven't so far looked to see what affect these have on linked object
> sizes.
> 
> Signed-off-by: Robert Bragg <robert@sixbynine.org>
> Cc: Chris Wilson <chris@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 cc6c253..5b2dbcd 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 b352a7b..d61d937 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
> 
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/intel-gfx

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

^ permalink raw reply	[flat|nested] 6+ messages in thread
* [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
@ 2016-12-01 17:18 Robert Bragg
  2016-12-02  8:01 ` Daniel Vetter
  0 siblings, 1 reply; 6+ messages in thread
From: Robert Bragg @ 2016-12-01 17:18 UTC (permalink / raw)
  To: intel-gfx

I'm currently considering the use of DRM_ERROR in i915 perf for steam
config validation errors (i.e. userspace misconfigurations) that should
be changed so that i-g-t tests aren't treated as failures when
triggering these.

I initially proposed changing these to DRM_INFO messages and
intentionally wanted to avoid DRM_DEBUG since in my limited experience
DRM_DEBUG messages aren't practical to work with.

I thought I'd see if DRM_DEBUG could be updated to have a bit more fine
grained control in case that might help sway my view.

Tbh, although I think something like this could be nice to have, I'm
still not really convinced that debug messages are a great fit for
helping userspace developers hitting EINVAL errors. Such developers
don't need to be drm/i915 developers and imho shouldn't be expected to
know of the existence of optional debug messages, and if you don't know
of there existence then the control interface isn't important and they
won't help anyone.

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

I haven't so far looked to see what affect these have on linked object
sizes.

Signed-off-by: Robert Bragg <robert@sixbynine.org>
Cc: Chris Wilson <chris@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 cc6c253..5b2dbcd 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 b352a7b..d61d937 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

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

^ permalink raw reply related	[flat|nested] 6+ messages in thread
end of thread, other threads:[~2016-12-07 19:15 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-12-05 11:24 [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG* Robert Bragg
2016-12-05 16:31 ` Daniel Vetter
2016-12-07 19:15   ` Robert Bragg
2016-12-05 18:54 ` ✓ Fi.CI.BAT: success for drm: Enable dynamic debug for DRM_[DEV]_DEBUG* (rev2) Patchwork
  -- strict thread matches above, loose matches on Subject: below --
2016-12-01 17:18 [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG* Robert Bragg
2016-12-02  8:01 ` Daniel Vetter

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.