On Wed, Dec 07, 2016 at 06:35:29PM +0000, Robert Bragg wrote:
This is still missing corresponding documentation changes, and I haven't moved anything to drm_print.h yet, as suggested.
Sending out with a few functional improvements first to get agreement before documenting anything (changes summarised in v2: section below)
In particular, affecting the output format, I stole an idea from Tvrtko Ursulin to have the prefix for messages be based on the driver name, such as "[i915]" instead of always being "[drm]".
Depending on peoples thoughts on compatibility, we could consider removing the prefix given that the dynamic debug control interface has a way of specifying that messages should include a module name, function or line info like:
echo "module i915 +mfp" > dynamic_debug/control
That would enable all i915 debug messages with a module and function prefix.
A trade-off would be that anyone only using the drm.drm_debug interface to control messages would loose some information. If we really wanted we could have the best of both by adding a utility printing api that can recognise when printing due to a dynamic debug control query vs drm.drm_debug to conditionally add the prefix.
--- >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 doesn't strictly maintain format compatibility with the previous debug messages since the category is now added as part of the prefix like "[drm][kms] No FB found". Adding the categories with a consistent format makes it possible to enable categories with a dynamic debug query like: echo "format [kms] +p" > dynamic_debug/control
This maintains support for enabling debug messages using the drm_debug parameter. If dynamic debug is not enabled via CONFIG_DYNAMIC_DEBUG the debug messages essentially work as before, except with the inclusion of categories in the format strings as described above.
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 non _DEV macros are no longer defined in terms of passing NULL to a _DEV variant to avoid have the core.c dev_printk implementation adding "(NULL device *)". The previous drm_[dev_]prink function used to handle this as a special case.
Instead of using DRM_NAME to add [drm] to the start of every message, the prefix is now based on module_name(THIS_MODULE) so it will be [drm] or e.g. [i915] for the Intel driver. Later we might consider removing the prefix altogether considering that the dynamic debug control interface has a way of optionally adding the module, function or line to the formatting of messages.
v2: Add categories to format like "[drm][kms] No FB found" Only single conditional call per message (macros expand to less code) Uses __dynamic_pr_debug/dev_dbg for dynamic formatting features Use module name for msg prefix like [drm] or [i915]
Signed-off-by: Robert Bragg robert@sixbynine.org Cc: dri-devel@lists.freedesktop.org Cc: Daniel Vetter daniel.vetter@ffwll.ch Cc: Tvrtko Ursulin tvrtko.ursulin@intel.com
So assuming I understand it correctly - I like this 3way cascade of dynamic debug, then printk and no_printk fallback if CONFIG_DEBUG=n for the space concious. But I guess we do need to add a DRM Kconfig knob to set DEBUG, at least I'm not entirely sure how that's supposed to work. Or we might need to have our own #ifdef maze for this. Maybe we need to keep the old drm*printk stuff for that?
Anyway, I still think this is pretty cool, if we can get some common ground with Tvrtko's stuff and some acks and reviews then I can pull it in. -Daniel
drivers/gpu/drm/drm_drv.c | 47 ----------- include/drm/drmP.h | 202 +++++++++++++++++++++++++++++----------------- 2 files changed, 127 insertions(+), 122 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..0416114 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,15 +130,22 @@ 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_core 0x01 #define DRM_UT_DRIVER 0x02 +#define _DRM_UT_drv 0x02 #define DRM_UT_KMS 0x04 +#define _DRM_UT_kms 0x04 #define DRM_UT_PRIME 0x08 +#define _DRM_UT_prime 0x08 #define DRM_UT_ATOMIC 0x10 +#define _DRM_UT_atomic 0x10 #define DRM_UT_VBL 0x20 +#define _DRM_UT_vbl 0x20 #define DRM_UT_STATE 0x40
+#define _DRM_PREFIX module_name(THIS_MODULE)
/***********************************************************************/ /** \name DRM template customization defaults */ /*@{*/ @@ -146,25 +154,19 @@ 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_INFO(fmt, ...) \
- _DRM_PRINTK(, INFO, fmt, ##__VA_ARGS__)
-#define DRM_NOTE(fmt, ...) \
- _DRM_PRINTK(, NOTICE, fmt, ##__VA_ARGS__)
-#define DRM_WARN(fmt, ...) \
- _DRM_PRINTK(, WARNING, fmt, ##__VA_ARGS__)
-#define DRM_INFO_ONCE(fmt, ...) \
- _DRM_PRINTK(_once, INFO, fmt, ##__VA_ARGS__)
-#define DRM_NOTE_ONCE(fmt, ...) \
- _DRM_PRINTK(_once, NOTICE, fmt, ##__VA_ARGS__)
-#define DRM_WARN_ONCE(fmt, ...) \
- _DRM_PRINTK(_once, WARNING, fmt, ##__VA_ARGS__)
+#define DRM_INFO(fmt, args...) \
- pr_info("[%s] " fmt, _DRM_PREFIX, ##args)
+#define DRM_NOTE(fmt, args...) \
- pr_notice("[%s] " fmt, _DRM_PREFIX, ##args)
+#define DRM_WARN(fmt, args...) \
- pr_warn("[%s] " fmt, _DRM_PREFIX, ##args)
+#define DRM_INFO_ONCE(fmt, args...) \
- pr_info_once("[%s] " fmt, _DRM_PREFIX, ##args)
+#define DRM_NOTE_ONCE(fmt, args...) \
- pr_notice_once("[%s] " fmt, _DRM_PREFIX, ##args)
+#define DRM_WARN_ONCE(fmt, args...) \
- pr_warn_once("[%s] " fmt, _DRM_PREFIX, ##args)
/**
- Error output.
@@ -172,11 +174,10 @@ struct dma_buf_attachment;
- \param fmt printf() like format string.
- \param arg arguments
*/ -#define DRM_DEV_ERROR(dev, fmt, ...) \
- drm_dev_printk(dev, KERN_ERR, DRM_UT_NONE, __func__, " *ERROR*",\
fmt, ##__VA_ARGS__)-#define DRM_ERROR(fmt, ...) \
- drm_printk(KERN_ERR, DRM_UT_NONE, fmt, ##__VA_ARGS__)
+#define DRM_DEV_ERROR(dev, fmt, args...) \
- dev_err(dev, "[%s:%s]*ERROR*" fmt, _DRM_PREFIX, __func__, ##args)
+#define DRM_ERROR(fmt, args...) \
- pr_err("[%s:%s]*ERROR*" fmt, _DRM_PREFIX, __func__, ##args)
/**
- Rate limited error output. Like DRM_ERROR() but won't flood the log.
@@ -184,81 +185,129 @@ struct dma_buf_attachment;
- \param fmt printf() like format string.
- \param arg arguments
*/ -#define DRM_DEV_ERROR_RATELIMITED(dev, fmt, ...) \ +#define DRM_DEV_ERROR_RATELIMITED(dev, fmt, args...) \ ({ \ static DEFINE_RATELIMIT_STATE(_rs, \ DEFAULT_RATELIMIT_INTERVAL, \ DEFAULT_RATELIMIT_BURST); \ \ if (__ratelimit(&_rs)) \
DRM_DEV_ERROR(dev, fmt, ##__VA_ARGS__); \
DRM_DEV_ERROR(dev, fmt, ##args); \}) -#define DRM_ERROR_RATELIMITED(fmt, ...) \
- DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
-#define DRM_DEV_INFO(dev, fmt, ...) \
- drm_dev_printk(dev, KERN_INFO, DRM_UT_NONE, __func__, "", fmt, \
##__VA_ARGS__)-#define DRM_DEV_INFO_ONCE(dev, fmt, ...) \ +#define DRM_ERROR_RATELIMITED(fmt, args...) \ ({ \
- static bool __print_once __read_mostly; \
- if (!__print_once) { \
__print_once = true; \DRM_DEV_INFO(dev, fmt, ##__VA_ARGS__); \- } \
- static DEFINE_RATELIMIT_STATE(_rs, \
DEFAULT_RATELIMIT_INTERVAL, \DEFAULT_RATELIMIT_BURST); \\- if (__ratelimit(&_rs)) \
DRM_ERROR(fmt, ##args); \})
+#define DRM_DEV_INFO(dev, fmt, args...) \
- dev_info(dev, "[%s:%s] " fmt, _DRM_PREFIX, __func__, ##args)
+#define DRM_DEV_INFO_ONCE(dev, fmt, args...) \
- dev_info_once(dev, "[%s:%s] " fmt, _DRM_PREFIX, __func__, ##args)
/**
- Debug output.
- \param fmt printf() like format string.
- \param arg arguments
*/
+#if defined(CONFIG_DYNAMIC_DEBUG) +#define DRM_DEF_DYN_DEBUG_DATA(name, fmt) \
- DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt);
+#define DRM_DYN_DEBUG_BRANCH(descriptor) \
- DYNAMIC_DEBUG_BRANCH(descriptor)
+#define __drm_dyn_dev_dbg(descriptor, dev, fmt, args...) \
- __dynamic_dev_dbg(descriptor, dev, fmt, ##args)
+#define __drm_dyn_pr_debug(descriptor, fmt, args...) \
- __dynamic_pr_debug(descriptor, fmt, ##args)
+#else +#define DRM_DEF_DYN_DEBUG_DATA(name, fmt) do {} while(0) +#define DRM_DYN_DEBUG_BRANCH(descriptor) 0
+#define __drm_dyn_dev_dbg(descriptor, dev, fmt, args...) \
- dev_dbg(dev, fmt, ##args)
+#define __drm_dyn_pr_debug(descriptor, fmt, args...) \
- pr_debug(fmt, ##args)
+#endif
+/* If modifying, note the duplication of the format strings for the
- dynamic debug meta data and for passing to printk. We don't
- deref descriptor->format to handle building without
- CONFIG_DYNAMIC_DEBUG
- */
+#define _DRM_DEV_DEBUG(dev, cat, fmt, args...) \ +({ \
- DRM_DEF_DYN_DEBUG_DATA(descriptor, "[%s:%s]["#cat"] " fmt); \
- if (DRM_DYN_DEBUG_BRANCH(descriptor) || \
unlikely(drm_debug & _DRM_UT_##cat)) { \__drm_dyn_dev_dbg(&descriptor, dev, \"[%s:%s]["#cat"] " fmt, \_DRM_PREFIX, __func__, ##args); \- } \
+}) +#define _DRM_DEBUG(cat, fmt, args...) \ +({ \
- DRM_DEF_DYN_DEBUG_DATA(descriptor, "[%s:%s]["#cat"] " fmt); \
- if (DRM_DYN_DEBUG_BRANCH(descriptor) || \
unlikely(drm_debug & _DRM_UT_##cat)) { \__drm_dyn_pr_debug(&descriptor, \"[%s:%s]["#cat"] " fmt, \_DRM_PREFIX, __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, core, fmt, ##args)
+#define DRM_DEBUG(fmt, args...) \
- _DRM_DEBUG(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, drv, fmt, ##args)
+#define DRM_DEBUG_DRIVER(fmt, args...) \
- _DRM_DEBUG(drv, 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, kms, fmt, ##args)
+#define DRM_DEBUG_KMS(fmt, args...) \
- _DRM_DEBUG(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, prime, fmt, ##args)
+#define DRM_DEBUG_PRIME(fmt, args...) \
- _DRM_DEBUG(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, atomic, fmt, ##args)
+#define DRM_DEBUG_ATOMIC(fmt, args...) \
- _DRM_DEBUG(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, vbl, fmt, ##args)
+#define DRM_DEBUG_VBL(fmt, args...) \
- _DRM_DEBUG(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_printk(dev, KERN_DEBUG, DRM_UT_ ## level, \__func__, "", fmt, ##args); \
_DRM_DEV_DEBUG(dev, 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_DEBUG(category, fmt, ##args); \})
/** @@ -268,21 +317,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)
- _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, drv, fmt, ##args)
#define DRM_DEBUG_DRIVER_RATELIMITED(fmt, args...) \
- DRM_DEV_DEBUG_DRIVER_RATELIMITED(NULL, fmt, ##args)
- _DRM_DEV_DEFINE_DEBUG_RATELIMITED(drv, fmt, ##args)
#define DRM_DEV_DEBUG_KMS_RATELIMITED(dev, fmt, args...) \
- _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, KMS, 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)
- _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