Re: [Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
On Mon, Dec 5, 2016 at 4:31 PM, Daniel Vetter wrote: > On Mon, Dec 05, 2016 at 11:24:44AM +, 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
Re: [Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
On Mon, Dec 05, 2016 at 11:24:44AM +, 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 > Cc: dri-de...@lists.freedesktop.org > Cc: Daniel Vetter > Cc: Chris Wilson > --- > 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 & categor
[Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
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 Cc: dri-de...@lists.freedesktop.org Cc: Daniel Vetter Cc: Chris Wilson --- 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 #include #include +#include #include #include @@
Re: [Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
On Thu, Dec 01, 2016 at 05:18:00PM +, 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 > Cc: Chris Wilson > --- > 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_ret
[Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG*
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 Cc: Chris Wilson --- 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 #include #include +#include #include #include @@ -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_NONE0x00 #define DRM_UT_CORE0x01 #define DRM_UT_DRIVER 0x02 #define DRM_UT_KMS 0x04 @@ -146,25 +146,22 @@ struct dma_bu