| Message ID | 20161207183529.11256-1-robert@sixbynine.org (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
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 >
On Thu, Dec 8, 2016 at 12:17 AM, Daniel Vetter <daniel@ffwll.ch> wrote: > > 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? Right, I wasn't really sure who/what's responsible for defining DEBUG. I just found this convention documented in Documentation/CodingStyle: > Coming up with good debugging messages can be quite a challenge; and once > you have them, they can be a huge help for remote troubleshooting. However > debug message printing is handled differently than printing other non-debug > messages. While the other pr_XXX() functions print unconditionally, > pr_debug() does not; it is compiled out by default, unless either DEBUG is > defined or CONFIG_DYNAMIC_DEBUG is set. That is true for dev_dbg() also, > and a related convention uses VERBOSE_DEBUG to add dev_vdbg() messages to > the ones already enabled by DEBUG. > > Many subsystems have Kconfig debug options to turn on -DDEBUG in the > corresponding Makefile; in other cases specific files #define DEBUG. And > when a debug message should be unconditionally printed, such as if it is > already inside a debug-related #ifdef section, printk(KERN_DEBUG ...) can be > used. So I think if we want to follow something similar, we're missing a general kconfig option like CONFIG_DEBUG_DRM that would handle adding -DDDEBUG across drm core and the drivers. I did notice that a couple of drm drivers do have their own options for this: CONFIG_OMAP2_DSS_DEBUG and CONFIG_DRM_TEGRA_DEBUG. > > > 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 > > > > -- > Daniel Vetter > Software Engineer, Intel Corporation > http://blog.ffwll.ch
Hi, On 07/12/2016 18:35, 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. To check if I got it right, that would put the prefix on debug messages while the rest would not have it? (With the option of dropping the prefix in general that is.) Or you thought just removing the prefix from debug messages? > 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. I think prefix by default, on non-debug messages, is required. We could perhaps make it like "drm: message", and not "[drm] message", to match the rest of the kernel? > > --- >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 If I got it right from the patch the actual debug format is: "[drm:function_name][kms] Message" Correct? In which case I would suggest different grouping, where category comes before the function name. For example: "[drm:kms:function_name] Message" I also find a lot of square braces hard to read. So the current "[function [module]]" is not my favourite so plus points for this initiative as well. In general this looks like a good cleanup and improvement so ack from me. Regards, Tvrtko P.S. Also eliminate DRM_NAME in this work? > > 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> > --- > 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 >
On Thu, Dec 08, 2016 at 11:57:25AM +0000, Robert Bragg wrote: > On Thu, Dec 8, 2016 at 12:17 AM, Daniel Vetter <daniel@ffwll.ch> wrote: > > > > 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? > > Right, I wasn't really sure who/what's responsible for defining DEBUG. > > I just found this convention documented in Documentation/CodingStyle: > > > Coming up with good debugging messages can be quite a challenge; and once > > you have them, they can be a huge help for remote troubleshooting. However > > debug message printing is handled differently than printing other non-debug > > messages. While the other pr_XXX() functions print unconditionally, > > pr_debug() does not; it is compiled out by default, unless either DEBUG is > > defined or CONFIG_DYNAMIC_DEBUG is set. That is true for dev_dbg() also, > > and a related convention uses VERBOSE_DEBUG to add dev_vdbg() messages to > > the ones already enabled by DEBUG. > > > > Many subsystems have Kconfig debug options to turn on -DDEBUG in the > > corresponding Makefile; in other cases specific files #define DEBUG. And > > when a debug message should be unconditionally printed, such as if it is > > already inside a debug-related #ifdef section, printk(KERN_DEBUG ...) can be > > used. > > So I think if we want to follow something similar, we're missing a > general kconfig option like CONFIG_DEBUG_DRM that would handle adding > -DDDEBUG across drm core and the drivers. I did notice that a couple > of drm drivers do have their own options for this: > CONFIG_OMAP2_DSS_DEBUG and CONFIG_DRM_TEGRA_DEBUG. Yeah, CONFIG_DEBUG_DRM to set -DDEBUG (and default y for backwards compat) is probably what we need. I think we can leave drivers as-is for now, maintainers can decide for themselves whether they want to chain to the overall drm debug (should be much easier with dyndebug since then they can define their own components for filtering) or leave their separate debug Kconfig knob. -Daniel
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
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> --- drivers/gpu/drm/drm_drv.c | 47 ----------- include/drm/drmP.h | 202 +++++++++++++++++++++++++++++----------------- 2 files changed, 127 insertions(+), 122 deletions(-)