* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-20 13:29 ` Daniel Vetter
0 siblings, 0 replies; 43+ messages in thread
From: Daniel Vetter @ 2021-07-20 13:29 UTC (permalink / raw)
To: Jim Cromie
Cc: Thomas Zimmermann, David Airlie, dri-devel, linux-kernel, jbaron,
Maxime Ripard, intel-gvt-dev, intel-gfx
On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, encoded
> in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> drm_debug_enabled() does a lot of unlikely bit-mask checks on
> drm.debug; we can use dynamic debug instead, and get all that
> static_key/jump_label goodness.
>
> Dynamic debug has no concept of category, but we can map the DRM_UT_*
> to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> prepend them to the given formats.
>
> Then we can use:
> `echo module drm format ^drm:core: +p > control`
>
> to enable every such "prefixed" pr_debug with one query. This new
> prefix changes pr_debug's output, so is user visible, but it seems
> unlikely to cause trouble for log watchers; they're not relying on the
> absence of class prefix strings.
>
> This conversion yields ~2100 new callsites on my i7/i915 laptop:
>
> dyndbg: 195 debug prints in module drm_kms_helper
> dyndbg: 298 debug prints in module drm
> dyndbg: 1630 debug prints in module i915
>
> CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> CONFIG_JUMP_LABEL is enabled; this because its required to get the
> promised optimizations.
>
> The indirection/switchover is layered into the macro scheme:
>
> 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> to map those bits to specific query/commands
> dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> here for POC, this should be in dynamic_debug.c
> with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
This is really awesome. For merging I think we need to discuss with dyn
debug folks whether they're all ok with this, but it's exported already
should should be fine.
>
> 1. A "converted" or "classy" DRM_UT_* map
>
> based on: DRM_UT_* ( symbol => bit-mask )
> named it: cDRM_UT_* ( symbol => format-class-prefix-string )
>
> So cDRM_UT_* is either:
> legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> enabled:
> #define cDRM_UT_KMS "drm:kms: "
> #define cDRM_UT_PRIME "drm:prime: "
> #define cDRM_UT_ATOMIC "drm:atomic: "
the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
(and git history isn't helpful either). What about just using
DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
DRM_DBG_CLASS_KMS.
Also would be really nice if we could make these a table or something, but
I guess with the macro magic that's not possible.
>
> DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> and elsewhere.
I think for the production version of these we need to retire/deprecate
them, at least for drm core. Otherwise you have an annoying mismatch
between drm.debug module option and dyn debug.
>
> 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>
> old names are now macros, calling either:
> legacy: -> to renamed fn
> enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
>
> these names are used in a fat layer of macros (3) which supply the
> category; those macros are used throughout drm code, yielding the
> ~2100 new prdbgs reported above.
>
> 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
>
> all these macros get "converted" to use cDRM_UT_*
> to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
>
> 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
>
> remove DRM_UT_ ## KMS as extra indirection
> pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
For merging, can we pull out the renames and reorgs from this patch, and
then maybe also the reorder the next patch in your series here to be
before the dyn debug stuff?
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
> drivers/gpu/drm/Kconfig | 13 +++++
> drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> 3 files changed, 158 insertions(+), 32 deletions(-)
I really like this, I think you can drop the RFC. A few more things that I
think we need:
- An overview kerneldoc section which explains the interfaces and how it
all works together. Essentially your commit message with some light
markup to make it look good.
- I think it would be really good to review the driver docs for all this
and make sure it's complete. Some of the interface functions aren't
documented yet (or maybe the ones that drivers shouldn't used need more
__ prefixes to denote them as internal, dunno).
- I guess deprecation notice for drm_debug_enabled() and all that, so that
we have a consistent interface. Doing the conversion will probably
highlight the need for a bit more infrastructure and tooling, e.g. the
bigger dump functions (like edid hex dump, or also the various decode
helpers we have for dp, hdmi infoframes and all that) ideally have a
single dyn_debug label to enable all of them instead of line-by-line.
Tbh no idea how this should work, might need dyndbg work too.
- For the driver side of this we probably want a
Documentation/gpu/TODO.rst entry if it's not all easy to convert
directly.
>
> diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> index 7ff89690a976..e4524ccba040 100644
> --- a/drivers/gpu/drm/Kconfig
> +++ b/drivers/gpu/drm/Kconfig
> @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
>
> If in doubt, say "N".
>
> +config DRM_USE_DYNAMIC_DEBUG
> + bool "use dynamic debug to implement drm.debug"
> + default n
> + depends on DRM
> + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> + depends on JUMP_LABEL
> + help
> + The drm debug category facility does a lot of unlikely bit-field
> + tests at runtime; while cheap individually, the cost accumulates.
> + This option uses dynamic debug facility (if configured and
> + using jump_label) to avoid those runtime checks, patching
> + the kernel when those debugs are desired.
Can't we just make this an internal option that's enabled automatically
when dyndbg is around? Plus a comment somewhere that we really recommend
enabling dyndbg for drm. Or would this mean that in certain dyndbg
configurations we'd loose all the debug lines, which would suck?
Anyway there's a pile of details, but the big picture I really like.
Especially that we can make dyndbg seamlessly support drm.debug is really
nice.
Cheers, Daniel
> +
> config DRM_DEBUG_SELFTEST
> tristate "kselftests for DRM"
> depends on DRM
> diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> index 111b932cf2a9..e2acdfc7088b 100644
> --- a/drivers/gpu/drm/drm_print.c
> +++ b/drivers/gpu/drm/drm_print.c
> @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> +
> +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> module_param_named(debug, __drm_debug, int, 0600);
>
> +#else
> +static char *format_class_prefixes[] = {
> + cDRM_UT_CORE,
> + cDRM_UT_DRIVER,
> + cDRM_UT_KMS,
> + cDRM_UT_PRIME,
> + cDRM_UT_ATOMIC,
> + cDRM_UT_VBL,
> + cDRM_UT_STATE,
> + cDRM_UT_LEASE,
> + cDRM_UT_DP,
> + cDRM_UT_DRMRES
> +};
> +
> +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> +
> +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> +{
> + unsigned int val;
> + unsigned long changes, result;
> + int rc, chgct = 0, totct = 0, bitpos;
> + char query[OUR_QUERY_SIZE];
> +
> + rc = kstrtouint(instr, 0, &val);
> + if (rc) {
> + pr_err("%s: failed\n", __func__);
> + return -EINVAL;
> + }
> + result = val;
> + changes = result ^ __drm_debug;
> +
> + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> +
> + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> +
> + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> + test_bit(bitpos, &result) ? '+' : '-');
> +
> + chgct = dynamic_debug_exec_queries(query, "drm*");
> + if (chgct < 0) {
> + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> + continue;
> + }
> + pr_debug("change ct:%d on %s\n", chgct, query);
> + totct += chgct;
> + }
> + pr_debug("total changes: %d\n", totct);
> + __drm_debug = result;
> + return 0;
> +}
> +
> +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> +{
> + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> + *((unsigned int *)kp->arg));
> +}
> +static const struct kernel_param_ops param_ops_debug = {
> + .set = param_set_dyndbg,
> + .get = param_get_dyndbg,
> +};
> +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> +
> +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> void __drm_puts_coredump(struct drm_printer *p, const char *str)
> {
> struct drm_print_iterator *iterator = p->arg;
> @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> }
> EXPORT_SYMBOL(drm_dev_printk);
>
> -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> const char *format, ...)
> {
> struct va_format vaf;
> @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>
> va_end(args);
> }
> -EXPORT_SYMBOL(drm_dev_dbg);
> +EXPORT_SYMBOL(_drm_dev_dbg);
>
> -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> {
> struct va_format vaf;
> va_list args;
> @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
>
> va_end(args);
> }
> -EXPORT_SYMBOL(__drm_dbg);
> +EXPORT_SYMBOL(___drm_dbg);
>
> void __drm_err(const char *format, ...)
> {
> diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> index ff5ac0e88321..499fa0b35200 100644
> --- a/include/drm/drm_print.h
> +++ b/include/drm/drm_print.h
> @@ -319,6 +319,51 @@ enum drm_debug_category {
> DRM_UT_DRMRES = 0x200,
> };
>
> +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> +
> +/* Use legacy drm-debug functions, and drm_debug_enabled().
> + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> + */
> +#define __drm_dbg(cls, fmt, ...) \
> + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> +#define drm_dev_dbg(dev, cls, fmt, ...) \
> + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> +
> +#define cDRM_UT_CORE DRM_UT_CORE
> +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> +#define cDRM_UT_KMS DRM_UT_KMS
> +#define cDRM_UT_PRIME DRM_UT_PRIME
> +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> +#define cDRM_UT_VBL DRM_UT_VBL
> +#define cDRM_UT_STATE DRM_UT_STATE
> +#define cDRM_UT_LEASE DRM_UT_LEASE
> +#define cDRM_UT_DP DRM_UT_DP
> +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> +
> +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> +/* use dynamic_debug to avoid drm_debug_enabled().
> + * dyndbg has no category, so we prefix the format with a "class"
> + * string; cDRM_UT_* maps to those class strings
> + */
> +#define __drm_dbg(cls, fmt, ...) \
> + pr_debug(cls # fmt, ##__VA_ARGS__)
> +#define drm_dev_dbg(dev, cls, fmt, ...) \
> + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> +
> +#define cDRM_UT_CORE "drm:core: "
> +#define cDRM_UT_DRIVER "drm:drvr: "
> +#define cDRM_UT_KMS "drm:kms: "
> +#define cDRM_UT_PRIME "drm:prime: "
> +#define cDRM_UT_ATOMIC "drm:atomic: "
> +#define cDRM_UT_VBL "drm:vbl: "
> +#define cDRM_UT_STATE "drm:state: "
> +#define cDRM_UT_LEASE "drm:lease: "
> +#define cDRM_UT_DP "drm:dp: "
> +#define cDRM_UT_DRMRES "drm:res "
> +
> +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> static inline bool drm_debug_enabled(enum drm_debug_category category)
> {
> return unlikely(__drm_debug & category);
> @@ -334,7 +379,7 @@ __printf(3, 4)
> void drm_dev_printk(const struct device *dev, const char *level,
> const char *format, ...);
> __printf(3, 4)
> -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> const char *format, ...);
>
> /**
> @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> * @fmt: printf() like format string.
> */
> #define DRM_DEV_DEBUG(dev, fmt, ...) \
> - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> /**
> * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> *
> @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> * @fmt: printf() like format string.
> */
> #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> /**
> * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> *
> @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> * @fmt: printf() like format string.
> */
> #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>
> /*
> * struct drm_device based logging
> @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>
>
> #define drm_dbg_core(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> #define drm_dbg(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> #define drm_dbg_kms(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> #define drm_dbg_prime(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> #define drm_dbg_atomic(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> #define drm_dbg_vbl(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> #define drm_dbg_state(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> #define drm_dbg_lease(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> #define drm_dbg_dp(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> #define drm_dbg_drmres(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
>
>
> /*
> @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> */
>
> __printf(2, 3)
> -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> __printf(1, 2)
> void __drm_err(const char *format, ...);
>
> @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> #define DRM_ERROR_RATELIMITED(fmt, ...) \
> DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
>
> +
> #define DRM_DEBUG(fmt, ...) \
> - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_DRIVER(fmt, ...) \
> - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_KMS(fmt, ...) \
> - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_PRIME(fmt, ...) \
> - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_ATOMIC(fmt, ...) \
> - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_VBL(fmt, ...) \
> - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_LEASE(fmt, ...) \
> - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_DP(fmt, ...) \
> - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
>
> -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> ({ \
> static DEFINE_RATELIMIT_STATE(rs_, \
> DEFAULT_RATELIMIT_INTERVAL, \
> DEFAULT_RATELIMIT_BURST); \
> const struct drm_device *drm_ = (drm); \
> \
> - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> + cDRM_UT, fmt, ##__VA_ARGS__); \
> })
>
> #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
>
> #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> --
> 2.31.1
>
--
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-20 13:29 ` Daniel Vetter
0 siblings, 0 replies; 43+ messages in thread
From: Daniel Vetter @ 2021-07-20 13:29 UTC (permalink / raw)
To: Jim Cromie
Cc: Thomas Zimmermann, David Airlie, dri-devel, linux-kernel, jbaron,
Rodrigo Vivi, intel-gvt-dev, intel-gfx, Zhi Wang
On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, encoded
> in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> drm_debug_enabled() does a lot of unlikely bit-mask checks on
> drm.debug; we can use dynamic debug instead, and get all that
> static_key/jump_label goodness.
>
> Dynamic debug has no concept of category, but we can map the DRM_UT_*
> to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> prepend them to the given formats.
>
> Then we can use:
> `echo module drm format ^drm:core: +p > control`
>
> to enable every such "prefixed" pr_debug with one query. This new
> prefix changes pr_debug's output, so is user visible, but it seems
> unlikely to cause trouble for log watchers; they're not relying on the
> absence of class prefix strings.
>
> This conversion yields ~2100 new callsites on my i7/i915 laptop:
>
> dyndbg: 195 debug prints in module drm_kms_helper
> dyndbg: 298 debug prints in module drm
> dyndbg: 1630 debug prints in module i915
>
> CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> CONFIG_JUMP_LABEL is enabled; this because its required to get the
> promised optimizations.
>
> The indirection/switchover is layered into the macro scheme:
>
> 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> to map those bits to specific query/commands
> dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> here for POC, this should be in dynamic_debug.c
> with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
This is really awesome. For merging I think we need to discuss with dyn
debug folks whether they're all ok with this, but it's exported already
should should be fine.
>
> 1. A "converted" or "classy" DRM_UT_* map
>
> based on: DRM_UT_* ( symbol => bit-mask )
> named it: cDRM_UT_* ( symbol => format-class-prefix-string )
>
> So cDRM_UT_* is either:
> legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> enabled:
> #define cDRM_UT_KMS "drm:kms: "
> #define cDRM_UT_PRIME "drm:prime: "
> #define cDRM_UT_ATOMIC "drm:atomic: "
the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
(and git history isn't helpful either). What about just using
DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
DRM_DBG_CLASS_KMS.
Also would be really nice if we could make these a table or something, but
I guess with the macro magic that's not possible.
>
> DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> and elsewhere.
I think for the production version of these we need to retire/deprecate
them, at least for drm core. Otherwise you have an annoying mismatch
between drm.debug module option and dyn debug.
>
> 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>
> old names are now macros, calling either:
> legacy: -> to renamed fn
> enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
>
> these names are used in a fat layer of macros (3) which supply the
> category; those macros are used throughout drm code, yielding the
> ~2100 new prdbgs reported above.
>
> 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
>
> all these macros get "converted" to use cDRM_UT_*
> to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
>
> 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
>
> remove DRM_UT_ ## KMS as extra indirection
> pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
For merging, can we pull out the renames and reorgs from this patch, and
then maybe also the reorder the next patch in your series here to be
before the dyn debug stuff?
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
> drivers/gpu/drm/Kconfig | 13 +++++
> drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> 3 files changed, 158 insertions(+), 32 deletions(-)
I really like this, I think you can drop the RFC. A few more things that I
think we need:
- An overview kerneldoc section which explains the interfaces and how it
all works together. Essentially your commit message with some light
markup to make it look good.
- I think it would be really good to review the driver docs for all this
and make sure it's complete. Some of the interface functions aren't
documented yet (or maybe the ones that drivers shouldn't used need more
__ prefixes to denote them as internal, dunno).
- I guess deprecation notice for drm_debug_enabled() and all that, so that
we have a consistent interface. Doing the conversion will probably
highlight the need for a bit more infrastructure and tooling, e.g. the
bigger dump functions (like edid hex dump, or also the various decode
helpers we have for dp, hdmi infoframes and all that) ideally have a
single dyn_debug label to enable all of them instead of line-by-line.
Tbh no idea how this should work, might need dyndbg work too.
- For the driver side of this we probably want a
Documentation/gpu/TODO.rst entry if it's not all easy to convert
directly.
>
> diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> index 7ff89690a976..e4524ccba040 100644
> --- a/drivers/gpu/drm/Kconfig
> +++ b/drivers/gpu/drm/Kconfig
> @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
>
> If in doubt, say "N".
>
> +config DRM_USE_DYNAMIC_DEBUG
> + bool "use dynamic debug to implement drm.debug"
> + default n
> + depends on DRM
> + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> + depends on JUMP_LABEL
> + help
> + The drm debug category facility does a lot of unlikely bit-field
> + tests at runtime; while cheap individually, the cost accumulates.
> + This option uses dynamic debug facility (if configured and
> + using jump_label) to avoid those runtime checks, patching
> + the kernel when those debugs are desired.
Can't we just make this an internal option that's enabled automatically
when dyndbg is around? Plus a comment somewhere that we really recommend
enabling dyndbg for drm. Or would this mean that in certain dyndbg
configurations we'd loose all the debug lines, which would suck?
Anyway there's a pile of details, but the big picture I really like.
Especially that we can make dyndbg seamlessly support drm.debug is really
nice.
Cheers, Daniel
> +
> config DRM_DEBUG_SELFTEST
> tristate "kselftests for DRM"
> depends on DRM
> diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> index 111b932cf2a9..e2acdfc7088b 100644
> --- a/drivers/gpu/drm/drm_print.c
> +++ b/drivers/gpu/drm/drm_print.c
> @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> +
> +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> module_param_named(debug, __drm_debug, int, 0600);
>
> +#else
> +static char *format_class_prefixes[] = {
> + cDRM_UT_CORE,
> + cDRM_UT_DRIVER,
> + cDRM_UT_KMS,
> + cDRM_UT_PRIME,
> + cDRM_UT_ATOMIC,
> + cDRM_UT_VBL,
> + cDRM_UT_STATE,
> + cDRM_UT_LEASE,
> + cDRM_UT_DP,
> + cDRM_UT_DRMRES
> +};
> +
> +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> +
> +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> +{
> + unsigned int val;
> + unsigned long changes, result;
> + int rc, chgct = 0, totct = 0, bitpos;
> + char query[OUR_QUERY_SIZE];
> +
> + rc = kstrtouint(instr, 0, &val);
> + if (rc) {
> + pr_err("%s: failed\n", __func__);
> + return -EINVAL;
> + }
> + result = val;
> + changes = result ^ __drm_debug;
> +
> + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> +
> + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> +
> + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> + test_bit(bitpos, &result) ? '+' : '-');
> +
> + chgct = dynamic_debug_exec_queries(query, "drm*");
> + if (chgct < 0) {
> + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> + continue;
> + }
> + pr_debug("change ct:%d on %s\n", chgct, query);
> + totct += chgct;
> + }
> + pr_debug("total changes: %d\n", totct);
> + __drm_debug = result;
> + return 0;
> +}
> +
> +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> +{
> + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> + *((unsigned int *)kp->arg));
> +}
> +static const struct kernel_param_ops param_ops_debug = {
> + .set = param_set_dyndbg,
> + .get = param_get_dyndbg,
> +};
> +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> +
> +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> void __drm_puts_coredump(struct drm_printer *p, const char *str)
> {
> struct drm_print_iterator *iterator = p->arg;
> @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> }
> EXPORT_SYMBOL(drm_dev_printk);
>
> -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> const char *format, ...)
> {
> struct va_format vaf;
> @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>
> va_end(args);
> }
> -EXPORT_SYMBOL(drm_dev_dbg);
> +EXPORT_SYMBOL(_drm_dev_dbg);
>
> -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> {
> struct va_format vaf;
> va_list args;
> @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
>
> va_end(args);
> }
> -EXPORT_SYMBOL(__drm_dbg);
> +EXPORT_SYMBOL(___drm_dbg);
>
> void __drm_err(const char *format, ...)
> {
> diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> index ff5ac0e88321..499fa0b35200 100644
> --- a/include/drm/drm_print.h
> +++ b/include/drm/drm_print.h
> @@ -319,6 +319,51 @@ enum drm_debug_category {
> DRM_UT_DRMRES = 0x200,
> };
>
> +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> +
> +/* Use legacy drm-debug functions, and drm_debug_enabled().
> + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> + */
> +#define __drm_dbg(cls, fmt, ...) \
> + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> +#define drm_dev_dbg(dev, cls, fmt, ...) \
> + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> +
> +#define cDRM_UT_CORE DRM_UT_CORE
> +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> +#define cDRM_UT_KMS DRM_UT_KMS
> +#define cDRM_UT_PRIME DRM_UT_PRIME
> +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> +#define cDRM_UT_VBL DRM_UT_VBL
> +#define cDRM_UT_STATE DRM_UT_STATE
> +#define cDRM_UT_LEASE DRM_UT_LEASE
> +#define cDRM_UT_DP DRM_UT_DP
> +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> +
> +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> +/* use dynamic_debug to avoid drm_debug_enabled().
> + * dyndbg has no category, so we prefix the format with a "class"
> + * string; cDRM_UT_* maps to those class strings
> + */
> +#define __drm_dbg(cls, fmt, ...) \
> + pr_debug(cls # fmt, ##__VA_ARGS__)
> +#define drm_dev_dbg(dev, cls, fmt, ...) \
> + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> +
> +#define cDRM_UT_CORE "drm:core: "
> +#define cDRM_UT_DRIVER "drm:drvr: "
> +#define cDRM_UT_KMS "drm:kms: "
> +#define cDRM_UT_PRIME "drm:prime: "
> +#define cDRM_UT_ATOMIC "drm:atomic: "
> +#define cDRM_UT_VBL "drm:vbl: "
> +#define cDRM_UT_STATE "drm:state: "
> +#define cDRM_UT_LEASE "drm:lease: "
> +#define cDRM_UT_DP "drm:dp: "
> +#define cDRM_UT_DRMRES "drm:res "
> +
> +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> +
> static inline bool drm_debug_enabled(enum drm_debug_category category)
> {
> return unlikely(__drm_debug & category);
> @@ -334,7 +379,7 @@ __printf(3, 4)
> void drm_dev_printk(const struct device *dev, const char *level,
> const char *format, ...);
> __printf(3, 4)
> -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> const char *format, ...);
>
> /**
> @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> * @fmt: printf() like format string.
> */
> #define DRM_DEV_DEBUG(dev, fmt, ...) \
> - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> /**
> * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> *
> @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> * @fmt: printf() like format string.
> */
> #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> /**
> * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> *
> @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> * @fmt: printf() like format string.
> */
> #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>
> /*
> * struct drm_device based logging
> @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>
>
> #define drm_dbg_core(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> #define drm_dbg(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> #define drm_dbg_kms(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> #define drm_dbg_prime(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> #define drm_dbg_atomic(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> #define drm_dbg_vbl(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> #define drm_dbg_state(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> #define drm_dbg_lease(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> #define drm_dbg_dp(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> #define drm_dbg_drmres(drm, fmt, ...) \
> - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
>
>
> /*
> @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> */
>
> __printf(2, 3)
> -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> __printf(1, 2)
> void __drm_err(const char *format, ...);
>
> @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> #define DRM_ERROR_RATELIMITED(fmt, ...) \
> DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
>
> +
> #define DRM_DEBUG(fmt, ...) \
> - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_DRIVER(fmt, ...) \
> - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_KMS(fmt, ...) \
> - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_PRIME(fmt, ...) \
> - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_ATOMIC(fmt, ...) \
> - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_VBL(fmt, ...) \
> - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_LEASE(fmt, ...) \
> - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
>
> #define DRM_DEBUG_DP(fmt, ...) \
> - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
>
> -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> ({ \
> static DEFINE_RATELIMIT_STATE(rs_, \
> DEFAULT_RATELIMIT_INTERVAL, \
> DEFAULT_RATELIMIT_BURST); \
> const struct drm_device *drm_ = (drm); \
> \
> - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> + cDRM_UT, fmt, ##__VA_ARGS__); \
> })
>
> #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
>
> #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> --
> 2.31.1
>
--
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
2021-07-20 13:29 ` Daniel Vetter
@ 2021-07-22 15:20 ` Sean Paul
-1 siblings, 0 replies; 43+ messages in thread
From: Sean Paul @ 2021-07-22 15:20 UTC (permalink / raw)
To: Daniel Vetter
On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, encoded
> > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > drm.debug; we can use dynamic debug instead, and get all that
> > static_key/jump_label goodness.
Hi Jim,
Thanks for your patches! Daniel pointed me at them in response to my drm_trace
patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
input on it. I think the 2 sets are mostly compatible, we'd just need to keep
drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
checks.
> >
> > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > prepend them to the given formats.
> >
> > Then we can use:
> > `echo module drm format ^drm:core: +p > control`
> >
> > to enable every such "prefixed" pr_debug with one query. This new
> > prefix changes pr_debug's output, so is user visible, but it seems
> > unlikely to cause trouble for log watchers; they're not relying on the
> > absence of class prefix strings.
> >
> > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> >
> > dyndbg: 195 debug prints in module drm_kms_helper
> > dyndbg: 298 debug prints in module drm
> > dyndbg: 1630 debug prints in module i915
> >
> > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > promised optimizations.
> >
> > The indirection/switchover is layered into the macro scheme:
> >
> > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > to map those bits to specific query/commands
> > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > here for POC, this should be in dynamic_debug.c
> > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
>
> This is really awesome.
Agreed, this is a very clever way of merging the 2 worlds!
> For merging I think we need to discuss with dyn
> debug folks whether they're all ok with this, but it's exported already
> should should be fine.
I wonder if this is a good time to reconsider our drm categories. IMO they're
overly broad and it's hard to get the right information without subscribing to
the firehose. It seems like dyndbg might be a good opportunity to unlock
subcategories of log messages.
More concretely, on CrOS we can't subscribe to atomic or state categories since
they're too noisy. However if there was a "fail" subcategory which dumped
state/atomic logs on check failures, that would be really compelling. Something
like:
drm:atomic:fail vs. drm:atomic
Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
dyndbg-aware clients to get better logs without having a huge table of
individual log signatures.
I'm not sure how tightly we'd want to control the subcategories. It could be
strict like the categories spelled out in drm_print.h, or an open prefix arg to
drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
provide enough flexibility to properly
Of course, none of this needs to be decided to land this initial support, it can
be bolted on later easily enough (I think).
>
> >
> > 1. A "converted" or "classy" DRM_UT_* map
> >
> > based on: DRM_UT_* ( symbol => bit-mask )
> > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> >
> > So cDRM_UT_* is either:
> > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > enabled:
> > #define cDRM_UT_KMS "drm:kms: "
> > #define cDRM_UT_PRIME "drm:prime: "
> > #define cDRM_UT_ATOMIC "drm:atomic: "
>
> the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> (and git history isn't helpful either). What about just using
> DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> DRM_DBG_CLASS_KMS.
>
> Also would be really nice if we could make these a table or something, but
> I guess with the macro magic that's not possible.
>
> >
> > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > and elsewhere.
>
> I think for the production version of these we need to retire/deprecate
> them, at least for drm core. Otherwise you have an annoying mismatch
> between drm.debug module option and dyn debug.
>
> >
> > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> >
> > old names are now macros, calling either:
> > legacy: -> to renamed fn
> > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> >
> > these names are used in a fat layer of macros (3) which supply the
> > category; those macros are used throughout drm code, yielding the
> > ~2100 new prdbgs reported above.
> >
> > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> >
> > all these macros get "converted" to use cDRM_UT_*
> > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> >
> > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> >
> > remove DRM_UT_ ## KMS as extra indirection
> > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
>
> For merging, can we pull out the renames and reorgs from this patch, and
> then maybe also the reorder the next patch in your series here to be
> before the dyn debug stuff?
>
> > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > ---
> > drivers/gpu/drm/Kconfig | 13 +++++
> > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > 3 files changed, 158 insertions(+), 32 deletions(-)
>
> I really like this, I think you can drop the RFC. A few more things that I
> think we need:
>
> - An overview kerneldoc section which explains the interfaces and how it
> all works together. Essentially your commit message with some light
> markup to make it look good.
>
> - I think it would be really good to review the driver docs for all this
> and make sure it's complete. Some of the interface functions aren't
> documented yet (or maybe the ones that drivers shouldn't used need more
> __ prefixes to denote them as internal, dunno).
>
> - I guess deprecation notice for drm_debug_enabled() and all that, so that
> we have a consistent interface. Doing the conversion will probably
> highlight the need for a bit more infrastructure and tooling, e.g. the
> bigger dump functions (like edid hex dump, or also the various decode
> helpers we have for dp, hdmi infoframes and all that) ideally have a
> single dyn_debug label to enable all of them instead of line-by-line.
> Tbh no idea how this should work, might need dyndbg work too.
Yeah, this is going to be tricky.
We'll probably need to enumerate these fully and if the process of gathering
the data is simple or already done in the course of the function, just avoid the
drm_debug_enabled() call with a CONFIG_DRM_DYNDBG check.
If the debug_enabled call gates a HW access, we probably need to query dyndbg
for the prefix the logs are associated with before gathering the log contents.
Sean
>
> - For the driver side of this we probably want a
> Documentation/gpu/TODO.rst entry if it's not all easy to convert
> directly.
>
> >
> > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > index 7ff89690a976..e4524ccba040 100644
> > --- a/drivers/gpu/drm/Kconfig
> > +++ b/drivers/gpu/drm/Kconfig
> > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> >
> > If in doubt, say "N".
> >
> > +config DRM_USE_DYNAMIC_DEBUG
> > + bool "use dynamic debug to implement drm.debug"
> > + default n
> > + depends on DRM
> > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > + depends on JUMP_LABEL
> > + help
> > + The drm debug category facility does a lot of unlikely bit-field
> > + tests at runtime; while cheap individually, the cost accumulates.
> > + This option uses dynamic debug facility (if configured and
> > + using jump_label) to avoid those runtime checks, patching
> > + the kernel when those debugs are desired.
>
> Can't we just make this an internal option that's enabled automatically
> when dyndbg is around? Plus a comment somewhere that we really recommend
> enabling dyndbg for drm. Or would this mean that in certain dyndbg
> configurations we'd loose all the debug lines, which would suck?
>
> Anyway there's a pile of details, but the big picture I really like.
> Especially that we can make dyndbg seamlessly support drm.debug is really
> nice.
>
> Cheers, Daniel
>
> > +
> > config DRM_DEBUG_SELFTEST
> > tristate "kselftests for DRM"
> > depends on DRM
> > diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> > index 111b932cf2a9..e2acdfc7088b 100644
> > --- a/drivers/gpu/drm/drm_print.c
> > +++ b/drivers/gpu/drm/drm_print.c
> > @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> > "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> > "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> > "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> > +
> > +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> > module_param_named(debug, __drm_debug, int, 0600);
> >
> > +#else
> > +static char *format_class_prefixes[] = {
> > + cDRM_UT_CORE,
> > + cDRM_UT_DRIVER,
> > + cDRM_UT_KMS,
> > + cDRM_UT_PRIME,
> > + cDRM_UT_ATOMIC,
> > + cDRM_UT_VBL,
> > + cDRM_UT_STATE,
> > + cDRM_UT_LEASE,
> > + cDRM_UT_DP,
> > + cDRM_UT_DRMRES
> > +};
> > +
> > +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> > +
> > +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> > +{
> > + unsigned int val;
> > + unsigned long changes, result;
> > + int rc, chgct = 0, totct = 0, bitpos;
> > + char query[OUR_QUERY_SIZE];
> > +
> > + rc = kstrtouint(instr, 0, &val);
> > + if (rc) {
> > + pr_err("%s: failed\n", __func__);
> > + return -EINVAL;
> > + }
> > + result = val;
> > + changes = result ^ __drm_debug;
> > +
> > + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> > +
> > + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> > +
> > + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> > + test_bit(bitpos, &result) ? '+' : '-');
> > +
> > + chgct = dynamic_debug_exec_queries(query, "drm*");
> > + if (chgct < 0) {
> > + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> > + continue;
> > + }
> > + pr_debug("change ct:%d on %s\n", chgct, query);
> > + totct += chgct;
> > + }
> > + pr_debug("total changes: %d\n", totct);
> > + __drm_debug = result;
> > + return 0;
> > +}
> > +
> > +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> > +{
> > + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> > + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> > + *((unsigned int *)kp->arg));
> > +}
> > +static const struct kernel_param_ops param_ops_debug = {
> > + .set = param_set_dyndbg,
> > + .get = param_get_dyndbg,
> > +};
> > +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> > +
> > +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > +
> > void __drm_puts_coredump(struct drm_printer *p, const char *str)
> > {
> > struct drm_print_iterator *iterator = p->arg;
> > @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> > }
> > EXPORT_SYMBOL(drm_dev_printk);
> >
> > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > const char *format, ...)
> > {
> > struct va_format vaf;
> > @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> >
> > va_end(args);
> > }
> > -EXPORT_SYMBOL(drm_dev_dbg);
> > +EXPORT_SYMBOL(_drm_dev_dbg);
> >
> > -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> > {
> > struct va_format vaf;
> > va_list args;
> > @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> >
> > va_end(args);
> > }
> > -EXPORT_SYMBOL(__drm_dbg);
> > +EXPORT_SYMBOL(___drm_dbg);
> >
> > void __drm_err(const char *format, ...)
> > {
> > diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> > index ff5ac0e88321..499fa0b35200 100644
> > --- a/include/drm/drm_print.h
> > +++ b/include/drm/drm_print.h
> > @@ -319,6 +319,51 @@ enum drm_debug_category {
> > DRM_UT_DRMRES = 0x200,
> > };
> >
> > +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> > +
> > +/* Use legacy drm-debug functions, and drm_debug_enabled().
> > + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> > + */
> > +#define __drm_dbg(cls, fmt, ...) \
> > + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> > +
> > +#define cDRM_UT_CORE DRM_UT_CORE
> > +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> > +#define cDRM_UT_KMS DRM_UT_KMS
> > +#define cDRM_UT_PRIME DRM_UT_PRIME
> > +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> > +#define cDRM_UT_VBL DRM_UT_VBL
> > +#define cDRM_UT_STATE DRM_UT_STATE
> > +#define cDRM_UT_LEASE DRM_UT_LEASE
> > +#define cDRM_UT_DP DRM_UT_DP
> > +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> > +
> > +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > +
> > +/* use dynamic_debug to avoid drm_debug_enabled().
> > + * dyndbg has no category, so we prefix the format with a "class"
> > + * string; cDRM_UT_* maps to those class strings
> > + */
> > +#define __drm_dbg(cls, fmt, ...) \
> > + pr_debug(cls # fmt, ##__VA_ARGS__)
> > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> > +
> > +#define cDRM_UT_CORE "drm:core: "
> > +#define cDRM_UT_DRIVER "drm:drvr: "
> > +#define cDRM_UT_KMS "drm:kms: "
> > +#define cDRM_UT_PRIME "drm:prime: "
> > +#define cDRM_UT_ATOMIC "drm:atomic: "
> > +#define cDRM_UT_VBL "drm:vbl: "
> > +#define cDRM_UT_STATE "drm:state: "
> > +#define cDRM_UT_LEASE "drm:lease: "
> > +#define cDRM_UT_DP "drm:dp: "
> > +#define cDRM_UT_DRMRES "drm:res "
> > +
> > +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > +
> > static inline bool drm_debug_enabled(enum drm_debug_category category)
> > {
> > return unlikely(__drm_debug & category);
> > @@ -334,7 +379,7 @@ __printf(3, 4)
> > void drm_dev_printk(const struct device *dev, const char *level,
> > const char *format, ...);
> > __printf(3, 4)
> > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > const char *format, ...);
> >
> > /**
> > @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > * @fmt: printf() like format string.
> > */
> > #define DRM_DEV_DEBUG(dev, fmt, ...) \
> > - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > /**
> > * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> > *
> > @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > * @fmt: printf() like format string.
> > */
> > #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> > - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > /**
> > * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> > *
> > @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > * @fmt: printf() like format string.
> > */
> > #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> > - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> >
> > /*
> > * struct drm_device based logging
> > @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> >
> >
> > #define drm_dbg_core(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > #define drm_dbg(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > #define drm_dbg_kms(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > #define drm_dbg_prime(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > #define drm_dbg_atomic(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > #define drm_dbg_vbl(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > #define drm_dbg_state(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> > #define drm_dbg_lease(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > #define drm_dbg_dp(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> > #define drm_dbg_drmres(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> >
> >
> > /*
> > @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > */
> >
> > __printf(2, 3)
> > -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> > __printf(1, 2)
> > void __drm_err(const char *format, ...);
> >
> > @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> > #define DRM_ERROR_RATELIMITED(fmt, ...) \
> > DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
> >
> > +
> > #define DRM_DEBUG(fmt, ...) \
> > - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_DRIVER(fmt, ...) \
> > - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_KMS(fmt, ...) \
> > - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_PRIME(fmt, ...) \
> > - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_ATOMIC(fmt, ...) \
> > - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_VBL(fmt, ...) \
> > - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_LEASE(fmt, ...) \
> > - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_DP(fmt, ...) \
> > - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> > + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
> >
> > -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> > +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> > ({ \
> > static DEFINE_RATELIMIT_STATE(rs_, \
> > DEFAULT_RATELIMIT_INTERVAL, \
> > DEFAULT_RATELIMIT_BURST); \
> > const struct drm_device *drm_ = (drm); \
> > \
> > - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> > - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> > - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> > + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> > + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> > + cDRM_UT, fmt, ##__VA_ARGS__); \
> > })
> >
> > #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> > - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> > + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
> >
> > #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> > drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> > --
> > 2.31.1
> >
>
> --
> Daniel Vetter
> Software Engineer, Intel Corporation
> http://blog.ffwll.ch
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/intel-gfx
--
Sean Paul, Software Engineer, Google / Chromium OS
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-22 15:20 ` Sean Paul
0 siblings, 0 replies; 43+ messages in thread
From: Sean Paul @ 2021-07-22 15:20 UTC (permalink / raw)
To: Daniel Vetter
On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, encoded
> > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > drm.debug; we can use dynamic debug instead, and get all that
> > static_key/jump_label goodness.
Hi Jim,
Thanks for your patches! Daniel pointed me at them in response to my drm_trace
patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
input on it. I think the 2 sets are mostly compatible, we'd just need to keep
drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
checks.
> >
> > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > prepend them to the given formats.
> >
> > Then we can use:
> > `echo module drm format ^drm:core: +p > control`
> >
> > to enable every such "prefixed" pr_debug with one query. This new
> > prefix changes pr_debug's output, so is user visible, but it seems
> > unlikely to cause trouble for log watchers; they're not relying on the
> > absence of class prefix strings.
> >
> > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> >
> > dyndbg: 195 debug prints in module drm_kms_helper
> > dyndbg: 298 debug prints in module drm
> > dyndbg: 1630 debug prints in module i915
> >
> > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > promised optimizations.
> >
> > The indirection/switchover is layered into the macro scheme:
> >
> > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > to map those bits to specific query/commands
> > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > here for POC, this should be in dynamic_debug.c
> > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
>
> This is really awesome.
Agreed, this is a very clever way of merging the 2 worlds!
> For merging I think we need to discuss with dyn
> debug folks whether they're all ok with this, but it's exported already
> should should be fine.
I wonder if this is a good time to reconsider our drm categories. IMO they're
overly broad and it's hard to get the right information without subscribing to
the firehose. It seems like dyndbg might be a good opportunity to unlock
subcategories of log messages.
More concretely, on CrOS we can't subscribe to atomic or state categories since
they're too noisy. However if there was a "fail" subcategory which dumped
state/atomic logs on check failures, that would be really compelling. Something
like:
drm:atomic:fail vs. drm:atomic
Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
dyndbg-aware clients to get better logs without having a huge table of
individual log signatures.
I'm not sure how tightly we'd want to control the subcategories. It could be
strict like the categories spelled out in drm_print.h, or an open prefix arg to
drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
provide enough flexibility to properly
Of course, none of this needs to be decided to land this initial support, it can
be bolted on later easily enough (I think).
>
> >
> > 1. A "converted" or "classy" DRM_UT_* map
> >
> > based on: DRM_UT_* ( symbol => bit-mask )
> > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> >
> > So cDRM_UT_* is either:
> > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > enabled:
> > #define cDRM_UT_KMS "drm:kms: "
> > #define cDRM_UT_PRIME "drm:prime: "
> > #define cDRM_UT_ATOMIC "drm:atomic: "
>
> the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> (and git history isn't helpful either). What about just using
> DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> DRM_DBG_CLASS_KMS.
>
> Also would be really nice if we could make these a table or something, but
> I guess with the macro magic that's not possible.
>
> >
> > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > and elsewhere.
>
> I think for the production version of these we need to retire/deprecate
> them, at least for drm core. Otherwise you have an annoying mismatch
> between drm.debug module option and dyn debug.
>
> >
> > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> >
> > old names are now macros, calling either:
> > legacy: -> to renamed fn
> > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> >
> > these names are used in a fat layer of macros (3) which supply the
> > category; those macros are used throughout drm code, yielding the
> > ~2100 new prdbgs reported above.
> >
> > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> >
> > all these macros get "converted" to use cDRM_UT_*
> > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> >
> > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> >
> > remove DRM_UT_ ## KMS as extra indirection
> > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
>
> For merging, can we pull out the renames and reorgs from this patch, and
> then maybe also the reorder the next patch in your series here to be
> before the dyn debug stuff?
>
> > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > ---
> > drivers/gpu/drm/Kconfig | 13 +++++
> > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > 3 files changed, 158 insertions(+), 32 deletions(-)
>
> I really like this, I think you can drop the RFC. A few more things that I
> think we need:
>
> - An overview kerneldoc section which explains the interfaces and how it
> all works together. Essentially your commit message with some light
> markup to make it look good.
>
> - I think it would be really good to review the driver docs for all this
> and make sure it's complete. Some of the interface functions aren't
> documented yet (or maybe the ones that drivers shouldn't used need more
> __ prefixes to denote them as internal, dunno).
>
> - I guess deprecation notice for drm_debug_enabled() and all that, so that
> we have a consistent interface. Doing the conversion will probably
> highlight the need for a bit more infrastructure and tooling, e.g. the
> bigger dump functions (like edid hex dump, or also the various decode
> helpers we have for dp, hdmi infoframes and all that) ideally have a
> single dyn_debug label to enable all of them instead of line-by-line.
> Tbh no idea how this should work, might need dyndbg work too.
Yeah, this is going to be tricky.
We'll probably need to enumerate these fully and if the process of gathering
the data is simple or already done in the course of the function, just avoid the
drm_debug_enabled() call with a CONFIG_DRM_DYNDBG check.
If the debug_enabled call gates a HW access, we probably need to query dyndbg
for the prefix the logs are associated with before gathering the log contents.
Sean
>
> - For the driver side of this we probably want a
> Documentation/gpu/TODO.rst entry if it's not all easy to convert
> directly.
>
> >
> > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > index 7ff89690a976..e4524ccba040 100644
> > --- a/drivers/gpu/drm/Kconfig
> > +++ b/drivers/gpu/drm/Kconfig
> > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> >
> > If in doubt, say "N".
> >
> > +config DRM_USE_DYNAMIC_DEBUG
> > + bool "use dynamic debug to implement drm.debug"
> > + default n
> > + depends on DRM
> > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > + depends on JUMP_LABEL
> > + help
> > + The drm debug category facility does a lot of unlikely bit-field
> > + tests at runtime; while cheap individually, the cost accumulates.
> > + This option uses dynamic debug facility (if configured and
> > + using jump_label) to avoid those runtime checks, patching
> > + the kernel when those debugs are desired.
>
> Can't we just make this an internal option that's enabled automatically
> when dyndbg is around? Plus a comment somewhere that we really recommend
> enabling dyndbg for drm. Or would this mean that in certain dyndbg
> configurations we'd loose all the debug lines, which would suck?
>
> Anyway there's a pile of details, but the big picture I really like.
> Especially that we can make dyndbg seamlessly support drm.debug is really
> nice.
>
> Cheers, Daniel
>
> > +
> > config DRM_DEBUG_SELFTEST
> > tristate "kselftests for DRM"
> > depends on DRM
> > diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> > index 111b932cf2a9..e2acdfc7088b 100644
> > --- a/drivers/gpu/drm/drm_print.c
> > +++ b/drivers/gpu/drm/drm_print.c
> > @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> > "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> > "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> > "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> > +
> > +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> > module_param_named(debug, __drm_debug, int, 0600);
> >
> > +#else
> > +static char *format_class_prefixes[] = {
> > + cDRM_UT_CORE,
> > + cDRM_UT_DRIVER,
> > + cDRM_UT_KMS,
> > + cDRM_UT_PRIME,
> > + cDRM_UT_ATOMIC,
> > + cDRM_UT_VBL,
> > + cDRM_UT_STATE,
> > + cDRM_UT_LEASE,
> > + cDRM_UT_DP,
> > + cDRM_UT_DRMRES
> > +};
> > +
> > +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> > +
> > +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> > +{
> > + unsigned int val;
> > + unsigned long changes, result;
> > + int rc, chgct = 0, totct = 0, bitpos;
> > + char query[OUR_QUERY_SIZE];
> > +
> > + rc = kstrtouint(instr, 0, &val);
> > + if (rc) {
> > + pr_err("%s: failed\n", __func__);
> > + return -EINVAL;
> > + }
> > + result = val;
> > + changes = result ^ __drm_debug;
> > +
> > + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> > +
> > + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> > +
> > + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> > + test_bit(bitpos, &result) ? '+' : '-');
> > +
> > + chgct = dynamic_debug_exec_queries(query, "drm*");
> > + if (chgct < 0) {
> > + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> > + continue;
> > + }
> > + pr_debug("change ct:%d on %s\n", chgct, query);
> > + totct += chgct;
> > + }
> > + pr_debug("total changes: %d\n", totct);
> > + __drm_debug = result;
> > + return 0;
> > +}
> > +
> > +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> > +{
> > + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> > + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> > + *((unsigned int *)kp->arg));
> > +}
> > +static const struct kernel_param_ops param_ops_debug = {
> > + .set = param_set_dyndbg,
> > + .get = param_get_dyndbg,
> > +};
> > +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> > +
> > +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > +
> > void __drm_puts_coredump(struct drm_printer *p, const char *str)
> > {
> > struct drm_print_iterator *iterator = p->arg;
> > @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> > }
> > EXPORT_SYMBOL(drm_dev_printk);
> >
> > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > const char *format, ...)
> > {
> > struct va_format vaf;
> > @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> >
> > va_end(args);
> > }
> > -EXPORT_SYMBOL(drm_dev_dbg);
> > +EXPORT_SYMBOL(_drm_dev_dbg);
> >
> > -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> > {
> > struct va_format vaf;
> > va_list args;
> > @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> >
> > va_end(args);
> > }
> > -EXPORT_SYMBOL(__drm_dbg);
> > +EXPORT_SYMBOL(___drm_dbg);
> >
> > void __drm_err(const char *format, ...)
> > {
> > diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> > index ff5ac0e88321..499fa0b35200 100644
> > --- a/include/drm/drm_print.h
> > +++ b/include/drm/drm_print.h
> > @@ -319,6 +319,51 @@ enum drm_debug_category {
> > DRM_UT_DRMRES = 0x200,
> > };
> >
> > +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> > +
> > +/* Use legacy drm-debug functions, and drm_debug_enabled().
> > + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> > + */
> > +#define __drm_dbg(cls, fmt, ...) \
> > + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> > +
> > +#define cDRM_UT_CORE DRM_UT_CORE
> > +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> > +#define cDRM_UT_KMS DRM_UT_KMS
> > +#define cDRM_UT_PRIME DRM_UT_PRIME
> > +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> > +#define cDRM_UT_VBL DRM_UT_VBL
> > +#define cDRM_UT_STATE DRM_UT_STATE
> > +#define cDRM_UT_LEASE DRM_UT_LEASE
> > +#define cDRM_UT_DP DRM_UT_DP
> > +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> > +
> > +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > +
> > +/* use dynamic_debug to avoid drm_debug_enabled().
> > + * dyndbg has no category, so we prefix the format with a "class"
> > + * string; cDRM_UT_* maps to those class strings
> > + */
> > +#define __drm_dbg(cls, fmt, ...) \
> > + pr_debug(cls # fmt, ##__VA_ARGS__)
> > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> > +
> > +#define cDRM_UT_CORE "drm:core: "
> > +#define cDRM_UT_DRIVER "drm:drvr: "
> > +#define cDRM_UT_KMS "drm:kms: "
> > +#define cDRM_UT_PRIME "drm:prime: "
> > +#define cDRM_UT_ATOMIC "drm:atomic: "
> > +#define cDRM_UT_VBL "drm:vbl: "
> > +#define cDRM_UT_STATE "drm:state: "
> > +#define cDRM_UT_LEASE "drm:lease: "
> > +#define cDRM_UT_DP "drm:dp: "
> > +#define cDRM_UT_DRMRES "drm:res "
> > +
> > +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > +
> > static inline bool drm_debug_enabled(enum drm_debug_category category)
> > {
> > return unlikely(__drm_debug & category);
> > @@ -334,7 +379,7 @@ __printf(3, 4)
> > void drm_dev_printk(const struct device *dev, const char *level,
> > const char *format, ...);
> > __printf(3, 4)
> > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > const char *format, ...);
> >
> > /**
> > @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > * @fmt: printf() like format string.
> > */
> > #define DRM_DEV_DEBUG(dev, fmt, ...) \
> > - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > /**
> > * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> > *
> > @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > * @fmt: printf() like format string.
> > */
> > #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> > - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > /**
> > * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> > *
> > @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > * @fmt: printf() like format string.
> > */
> > #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> > - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> >
> > /*
> > * struct drm_device based logging
> > @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> >
> >
> > #define drm_dbg_core(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > #define drm_dbg(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > #define drm_dbg_kms(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > #define drm_dbg_prime(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > #define drm_dbg_atomic(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > #define drm_dbg_vbl(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > #define drm_dbg_state(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> > #define drm_dbg_lease(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > #define drm_dbg_dp(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> > #define drm_dbg_drmres(drm, fmt, ...) \
> > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> >
> >
> > /*
> > @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > */
> >
> > __printf(2, 3)
> > -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> > __printf(1, 2)
> > void __drm_err(const char *format, ...);
> >
> > @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> > #define DRM_ERROR_RATELIMITED(fmt, ...) \
> > DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
> >
> > +
> > #define DRM_DEBUG(fmt, ...) \
> > - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_DRIVER(fmt, ...) \
> > - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_KMS(fmt, ...) \
> > - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_PRIME(fmt, ...) \
> > - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_ATOMIC(fmt, ...) \
> > - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_VBL(fmt, ...) \
> > - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_LEASE(fmt, ...) \
> > - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> >
> > #define DRM_DEBUG_DP(fmt, ...) \
> > - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> > + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
> >
> > -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> > +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> > ({ \
> > static DEFINE_RATELIMIT_STATE(rs_, \
> > DEFAULT_RATELIMIT_INTERVAL, \
> > DEFAULT_RATELIMIT_BURST); \
> > const struct drm_device *drm_ = (drm); \
> > \
> > - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> > - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> > - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> > + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> > + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> > + cDRM_UT, fmt, ##__VA_ARGS__); \
> > })
> >
> > #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> > - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> > + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
> >
> > #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> > drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> > --
> > 2.31.1
> >
>
> --
> Daniel Vetter
> Software Engineer, Intel Corporation
> http://blog.ffwll.ch
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/intel-gfx
--
Sean Paul, Software Engineer, Google / Chromium OS
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
2021-07-22 15:20 ` Sean Paul
(?)
@ 2021-07-27 14:02 ` Sean Paul
-1 siblings, 0 replies; 43+ messages in thread
From: Sean Paul @ 2021-07-27 14:02 UTC (permalink / raw)
To: Daniel Vetter, Jim Cromie, Maarten Lankhorst, Maxime Ripard,
Thomas Zimmermann, David Airlie, Zhenyu Wang, Zhi Wang,
Jani Nikula, Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML,
intel-gvt-dev, Intel Graphics Development, jbaron
On Thu, Jul 22, 2021 at 11:20 AM Sean Paul <sean@poorly.run> wrote:
>
Reply-all fail. Adding everyone else back to my response.
> On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> > On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > > drm's debug system uses distinct categories of debug messages, encoded
> > > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > > drm.debug; we can use dynamic debug instead, and get all that
> > > static_key/jump_label goodness.
>
> Hi Jim,
> Thanks for your patches! Daniel pointed me at them in response to my drm_trace
> patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
> input on it. I think the 2 sets are mostly compatible, we'd just need to keep
> drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
> checks.
>
> > >
> > > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > > prepend them to the given formats.
> > >
> > > Then we can use:
> > > `echo module drm format ^drm:core: +p > control`
> > >
> > > to enable every such "prefixed" pr_debug with one query. This new
> > > prefix changes pr_debug's output, so is user visible, but it seems
> > > unlikely to cause trouble for log watchers; they're not relying on the
> > > absence of class prefix strings.
> > >
> > > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> > >
> > > dyndbg: 195 debug prints in module drm_kms_helper
> > > dyndbg: 298 debug prints in module drm
> > > dyndbg: 1630 debug prints in module i915
> > >
> > > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > > promised optimizations.
> > >
> > > The indirection/switchover is layered into the macro scheme:
> > >
> > > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > > to map those bits to specific query/commands
> > > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > > here for POC, this should be in dynamic_debug.c
> > > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
> >
> > This is really awesome.
>
>
> Agreed, this is a very clever way of merging the 2 worlds!
>
>
> > For merging I think we need to discuss with dyn
> > debug folks whether they're all ok with this, but it's exported already
> > should should be fine.
>
> I wonder if this is a good time to reconsider our drm categories. IMO they're
> overly broad and it's hard to get the right information without subscribing to
> the firehose. It seems like dyndbg might be a good opportunity to unlock
> subcategories of log messages.
>
> More concretely, on CrOS we can't subscribe to atomic or state categories since
> they're too noisy. However if there was a "fail" subcategory which dumped
> state/atomic logs on check failures, that would be really compelling. Something
> like:
>
> drm:atomic:fail vs. drm:atomic
>
> Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
> dyndbg-aware clients to get better logs without having a huge table of
> individual log signatures.
>
> I'm not sure how tightly we'd want to control the subcategories. It could be
> strict like the categories spelled out in drm_print.h, or an open prefix arg to
> drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
> provide enough flexibility to properly
>
> Of course, none of this needs to be decided to land this initial support, it can
> be bolted on later easily enough (I think).
>
>
> >
> > >
> > > 1. A "converted" or "classy" DRM_UT_* map
> > >
> > > based on: DRM_UT_* ( symbol => bit-mask )
> > > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> > >
> > > So cDRM_UT_* is either:
> > > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > > enabled:
> > > #define cDRM_UT_KMS "drm:kms: "
> > > #define cDRM_UT_PRIME "drm:prime: "
> > > #define cDRM_UT_ATOMIC "drm:atomic: "
> >
> > the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> > (and git history isn't helpful either). What about just using
> > DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> > DRM_DBG_CLASS_KMS.
> >
> > Also would be really nice if we could make these a table or something, but
> > I guess with the macro magic that's not possible.
> >
> > >
> > > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > > and elsewhere.
> >
> > I think for the production version of these we need to retire/deprecate
> > them, at least for drm core. Otherwise you have an annoying mismatch
> > between drm.debug module option and dyn debug.
> >
> > >
> > > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> > >
> > > old names are now macros, calling either:
> > > legacy: -> to renamed fn
> > > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> > >
> > > these names are used in a fat layer of macros (3) which supply the
> > > category; those macros are used throughout drm code, yielding the
> > > ~2100 new prdbgs reported above.
> > >
> > > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> > >
> > > all these macros get "converted" to use cDRM_UT_*
> > > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> > >
> > > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> > >
> > > remove DRM_UT_ ## KMS as extra indirection
> > > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
> >
> > For merging, can we pull out the renames and reorgs from this patch, and
> > then maybe also the reorder the next patch in your series here to be
> > before the dyn debug stuff?
> >
> > > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > > ---
> > > drivers/gpu/drm/Kconfig | 13 +++++
> > > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > > 3 files changed, 158 insertions(+), 32 deletions(-)
> >
> > I really like this, I think you can drop the RFC. A few more things that I
> > think we need:
> >
> > - An overview kerneldoc section which explains the interfaces and how it
> > all works together. Essentially your commit message with some light
> > markup to make it look good.
> >
> > - I think it would be really good to review the driver docs for all this
> > and make sure it's complete. Some of the interface functions aren't
> > documented yet (or maybe the ones that drivers shouldn't used need more
> > __ prefixes to denote them as internal, dunno).
> >
> > - I guess deprecation notice for drm_debug_enabled() and all that, so that
> > we have a consistent interface. Doing the conversion will probably
> > highlight the need for a bit more infrastructure and tooling, e.g. the
> > bigger dump functions (like edid hex dump, or also the various decode
> > helpers we have for dp, hdmi infoframes and all that) ideally have a
> > single dyn_debug label to enable all of them instead of line-by-line.
> > Tbh no idea how this should work, might need dyndbg work too.
>
> Yeah, this is going to be tricky.
>
> We'll probably need to enumerate these fully and if the process of gathering
> the data is simple or already done in the course of the function, just avoid the
> drm_debug_enabled() call with a CONFIG_DRM_DYNDBG check.
>
> If the debug_enabled call gates a HW access, we probably need to query dyndbg
> for the prefix the logs are associated with before gathering the log contents.
>
> Sean
> >
> > - For the driver side of this we probably want a
> > Documentation/gpu/TODO.rst entry if it's not all easy to convert
> > directly.
> >
> > >
> > > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > > index 7ff89690a976..e4524ccba040 100644
> > > --- a/drivers/gpu/drm/Kconfig
> > > +++ b/drivers/gpu/drm/Kconfig
> > > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> > >
> > > If in doubt, say "N".
> > >
> > > +config DRM_USE_DYNAMIC_DEBUG
> > > + bool "use dynamic debug to implement drm.debug"
> > > + default n
> > > + depends on DRM
> > > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > > + depends on JUMP_LABEL
> > > + help
> > > + The drm debug category facility does a lot of unlikely bit-field
> > > + tests at runtime; while cheap individually, the cost accumulates.
> > > + This option uses dynamic debug facility (if configured and
> > > + using jump_label) to avoid those runtime checks, patching
> > > + the kernel when those debugs are desired.
> >
> > Can't we just make this an internal option that's enabled automatically
> > when dyndbg is around? Plus a comment somewhere that we really recommend
> > enabling dyndbg for drm. Or would this mean that in certain dyndbg
> > configurations we'd loose all the debug lines, which would suck?
> >
> > Anyway there's a pile of details, but the big picture I really like.
> > Especially that we can make dyndbg seamlessly support drm.debug is really
> > nice.
> >
> > Cheers, Daniel
> >
> > > +
> > > config DRM_DEBUG_SELFTEST
> > > tristate "kselftests for DRM"
> > > depends on DRM
> > > diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> > > index 111b932cf2a9..e2acdfc7088b 100644
> > > --- a/drivers/gpu/drm/drm_print.c
> > > +++ b/drivers/gpu/drm/drm_print.c
> > > @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> > > "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> > > "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> > > "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> > > +
> > > +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> > > module_param_named(debug, __drm_debug, int, 0600);
> > >
> > > +#else
> > > +static char *format_class_prefixes[] = {
> > > + cDRM_UT_CORE,
> > > + cDRM_UT_DRIVER,
> > > + cDRM_UT_KMS,
> > > + cDRM_UT_PRIME,
> > > + cDRM_UT_ATOMIC,
> > > + cDRM_UT_VBL,
> > > + cDRM_UT_STATE,
> > > + cDRM_UT_LEASE,
> > > + cDRM_UT_DP,
> > > + cDRM_UT_DRMRES
> > > +};
> > > +
> > > +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> > > +
> > > +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> > > +{
> > > + unsigned int val;
> > > + unsigned long changes, result;
> > > + int rc, chgct = 0, totct = 0, bitpos;
> > > + char query[OUR_QUERY_SIZE];
> > > +
> > > + rc = kstrtouint(instr, 0, &val);
> > > + if (rc) {
> > > + pr_err("%s: failed\n", __func__);
> > > + return -EINVAL;
> > > + }
> > > + result = val;
> > > + changes = result ^ __drm_debug;
> > > +
> > > + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> > > +
> > > + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> > > +
> > > + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> > > + test_bit(bitpos, &result) ? '+' : '-');
> > > +
> > > + chgct = dynamic_debug_exec_queries(query, "drm*");
> > > + if (chgct < 0) {
> > > + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> > > + continue;
> > > + }
> > > + pr_debug("change ct:%d on %s\n", chgct, query);
> > > + totct += chgct;
> > > + }
> > > + pr_debug("total changes: %d\n", totct);
> > > + __drm_debug = result;
> > > + return 0;
> > > +}
> > > +
> > > +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> > > +{
> > > + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> > > + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> > > + *((unsigned int *)kp->arg));
> > > +}
> > > +static const struct kernel_param_ops param_ops_debug = {
> > > + .set = param_set_dyndbg,
> > > + .get = param_get_dyndbg,
> > > +};
> > > +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> > > +
> > > +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > void __drm_puts_coredump(struct drm_printer *p, const char *str)
> > > {
> > > struct drm_print_iterator *iterator = p->arg;
> > > @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> > > }
> > > EXPORT_SYMBOL(drm_dev_printk);
> > >
> > > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > const char *format, ...)
> > > {
> > > struct va_format vaf;
> > > @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > >
> > > va_end(args);
> > > }
> > > -EXPORT_SYMBOL(drm_dev_dbg);
> > > +EXPORT_SYMBOL(_drm_dev_dbg);
> > >
> > > -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> > > {
> > > struct va_format vaf;
> > > va_list args;
> > > @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > >
> > > va_end(args);
> > > }
> > > -EXPORT_SYMBOL(__drm_dbg);
> > > +EXPORT_SYMBOL(___drm_dbg);
> > >
> > > void __drm_err(const char *format, ...)
> > > {
> > > diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> > > index ff5ac0e88321..499fa0b35200 100644
> > > --- a/include/drm/drm_print.h
> > > +++ b/include/drm/drm_print.h
> > > @@ -319,6 +319,51 @@ enum drm_debug_category {
> > > DRM_UT_DRMRES = 0x200,
> > > };
> > >
> > > +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> > > +
> > > +/* Use legacy drm-debug functions, and drm_debug_enabled().
> > > + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> > > + */
> > > +#define __drm_dbg(cls, fmt, ...) \
> > > + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> > > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > > + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> > > +
> > > +#define cDRM_UT_CORE DRM_UT_CORE
> > > +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> > > +#define cDRM_UT_KMS DRM_UT_KMS
> > > +#define cDRM_UT_PRIME DRM_UT_PRIME
> > > +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> > > +#define cDRM_UT_VBL DRM_UT_VBL
> > > +#define cDRM_UT_STATE DRM_UT_STATE
> > > +#define cDRM_UT_LEASE DRM_UT_LEASE
> > > +#define cDRM_UT_DP DRM_UT_DP
> > > +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> > > +
> > > +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > +/* use dynamic_debug to avoid drm_debug_enabled().
> > > + * dyndbg has no category, so we prefix the format with a "class"
> > > + * string; cDRM_UT_* maps to those class strings
> > > + */
> > > +#define __drm_dbg(cls, fmt, ...) \
> > > + pr_debug(cls # fmt, ##__VA_ARGS__)
> > > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > > + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> > > +
> > > +#define cDRM_UT_CORE "drm:core: "
> > > +#define cDRM_UT_DRIVER "drm:drvr: "
> > > +#define cDRM_UT_KMS "drm:kms: "
> > > +#define cDRM_UT_PRIME "drm:prime: "
> > > +#define cDRM_UT_ATOMIC "drm:atomic: "
> > > +#define cDRM_UT_VBL "drm:vbl: "
> > > +#define cDRM_UT_STATE "drm:state: "
> > > +#define cDRM_UT_LEASE "drm:lease: "
> > > +#define cDRM_UT_DP "drm:dp: "
> > > +#define cDRM_UT_DRMRES "drm:res "
> > > +
> > > +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > static inline bool drm_debug_enabled(enum drm_debug_category category)
> > > {
> > > return unlikely(__drm_debug & category);
> > > @@ -334,7 +379,7 @@ __printf(3, 4)
> > > void drm_dev_printk(const struct device *dev, const char *level,
> > > const char *format, ...);
> > > __printf(3, 4)
> > > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > const char *format, ...);
> > >
> > > /**
> > > @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > /**
> > > * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> > > *
> > > @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > /**
> > > * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> > > *
> > > @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > >
> > > /*
> > > * struct drm_device based logging
> > > @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > >
> > >
> > > #define drm_dbg_core(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_kms(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_prime(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_atomic(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_vbl(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_state(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_lease(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_dp(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_drmres(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > >
> > >
> > > /*
> > > @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > */
> > >
> > > __printf(2, 3)
> > > -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> > > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> > > __printf(1, 2)
> > > void __drm_err(const char *format, ...);
> > >
> > > @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> > > #define DRM_ERROR_RATELIMITED(fmt, ...) \
> > > DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
> > >
> > > +
> > > #define DRM_DEBUG(fmt, ...) \
> > > - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_DRIVER(fmt, ...) \
> > > - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_KMS(fmt, ...) \
> > > - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_PRIME(fmt, ...) \
> > > - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_ATOMIC(fmt, ...) \
> > > - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_VBL(fmt, ...) \
> > > - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_LEASE(fmt, ...) \
> > > - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_DP(fmt, ...) \
> > > - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
> > >
> > > -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> > > +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> > > ({ \
> > > static DEFINE_RATELIMIT_STATE(rs_, \
> > > DEFAULT_RATELIMIT_INTERVAL, \
> > > DEFAULT_RATELIMIT_BURST); \
> > > const struct drm_device *drm_ = (drm); \
> > > \
> > > - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> > > - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> > > - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> > > + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> > > + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> > > + cDRM_UT, fmt, ##__VA_ARGS__); \
> > > })
> > >
> > > #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> > > - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> > > + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
> > >
> > > #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> > > drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> > > --
> > > 2.31.1
> > >
> >
> > --
> > Daniel Vetter
> > Software Engineer, Intel Corporation
> > http://blog.ffwll.ch
> > _______________________________________________
> > Intel-gfx mailing list
> > Intel-gfx@lists.freedesktop.org
> > https://lists.freedesktop.org/mailman/listinfo/intel-gfx
>
> --
> Sean Paul, Software Engineer, Google / Chromium OS
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-27 14:02 ` Sean Paul
0 siblings, 0 replies; 43+ messages in thread
From: Sean Paul @ 2021-07-27 14:02 UTC (permalink / raw)
To: Daniel Vetter, Jim Cromie, Maarten Lankhorst, Maxime Ripard,
Thomas Zimmermann, David Airlie, Zhenyu Wang, Zhi Wang,
Jani Nikula, Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML,
intel-gvt-dev, Intel Graphics Development, jbaron
On Thu, Jul 22, 2021 at 11:20 AM Sean Paul <sean@poorly.run> wrote:
>
Reply-all fail. Adding everyone else back to my response.
> On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> > On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > > drm's debug system uses distinct categories of debug messages, encoded
> > > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > > drm.debug; we can use dynamic debug instead, and get all that
> > > static_key/jump_label goodness.
>
> Hi Jim,
> Thanks for your patches! Daniel pointed me at them in response to my drm_trace
> patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
> input on it. I think the 2 sets are mostly compatible, we'd just need to keep
> drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
> checks.
>
> > >
> > > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > > prepend them to the given formats.
> > >
> > > Then we can use:
> > > `echo module drm format ^drm:core: +p > control`
> > >
> > > to enable every such "prefixed" pr_debug with one query. This new
> > > prefix changes pr_debug's output, so is user visible, but it seems
> > > unlikely to cause trouble for log watchers; they're not relying on the
> > > absence of class prefix strings.
> > >
> > > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> > >
> > > dyndbg: 195 debug prints in module drm_kms_helper
> > > dyndbg: 298 debug prints in module drm
> > > dyndbg: 1630 debug prints in module i915
> > >
> > > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > > promised optimizations.
> > >
> > > The indirection/switchover is layered into the macro scheme:
> > >
> > > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > > to map those bits to specific query/commands
> > > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > > here for POC, this should be in dynamic_debug.c
> > > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
> >
> > This is really awesome.
>
>
> Agreed, this is a very clever way of merging the 2 worlds!
>
>
> > For merging I think we need to discuss with dyn
> > debug folks whether they're all ok with this, but it's exported already
> > should should be fine.
>
> I wonder if this is a good time to reconsider our drm categories. IMO they're
> overly broad and it's hard to get the right information without subscribing to
> the firehose. It seems like dyndbg might be a good opportunity to unlock
> subcategories of log messages.
>
> More concretely, on CrOS we can't subscribe to atomic or state categories since
> they're too noisy. However if there was a "fail" subcategory which dumped
> state/atomic logs on check failures, that would be really compelling. Something
> like:
>
> drm:atomic:fail vs. drm:atomic
>
> Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
> dyndbg-aware clients to get better logs without having a huge table of
> individual log signatures.
>
> I'm not sure how tightly we'd want to control the subcategories. It could be
> strict like the categories spelled out in drm_print.h, or an open prefix arg to
> drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
> provide enough flexibility to properly
>
> Of course, none of this needs to be decided to land this initial support, it can
> be bolted on later easily enough (I think).
>
>
> >
> > >
> > > 1. A "converted" or "classy" DRM_UT_* map
> > >
> > > based on: DRM_UT_* ( symbol => bit-mask )
> > > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> > >
> > > So cDRM_UT_* is either:
> > > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > > enabled:
> > > #define cDRM_UT_KMS "drm:kms: "
> > > #define cDRM_UT_PRIME "drm:prime: "
> > > #define cDRM_UT_ATOMIC "drm:atomic: "
> >
> > the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> > (and git history isn't helpful either). What about just using
> > DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> > DRM_DBG_CLASS_KMS.
> >
> > Also would be really nice if we could make these a table or something, but
> > I guess with the macro magic that's not possible.
> >
> > >
> > > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > > and elsewhere.
> >
> > I think for the production version of these we need to retire/deprecate
> > them, at least for drm core. Otherwise you have an annoying mismatch
> > between drm.debug module option and dyn debug.
> >
> > >
> > > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> > >
> > > old names are now macros, calling either:
> > > legacy: -> to renamed fn
> > > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> > >
> > > these names are used in a fat layer of macros (3) which supply the
> > > category; those macros are used throughout drm code, yielding the
> > > ~2100 new prdbgs reported above.
> > >
> > > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> > >
> > > all these macros get "converted" to use cDRM_UT_*
> > > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> > >
> > > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> > >
> > > remove DRM_UT_ ## KMS as extra indirection
> > > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
> >
> > For merging, can we pull out the renames and reorgs from this patch, and
> > then maybe also the reorder the next patch in your series here to be
> > before the dyn debug stuff?
> >
> > > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > > ---
> > > drivers/gpu/drm/Kconfig | 13 +++++
> > > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > > 3 files changed, 158 insertions(+), 32 deletions(-)
> >
> > I really like this, I think you can drop the RFC. A few more things that I
> > think we need:
> >
> > - An overview kerneldoc section which explains the interfaces and how it
> > all works together. Essentially your commit message with some light
> > markup to make it look good.
> >
> > - I think it would be really good to review the driver docs for all this
> > and make sure it's complete. Some of the interface functions aren't
> > documented yet (or maybe the ones that drivers shouldn't used need more
> > __ prefixes to denote them as internal, dunno).
> >
> > - I guess deprecation notice for drm_debug_enabled() and all that, so that
> > we have a consistent interface. Doing the conversion will probably
> > highlight the need for a bit more infrastructure and tooling, e.g. the
> > bigger dump functions (like edid hex dump, or also the various decode
> > helpers we have for dp, hdmi infoframes and all that) ideally have a
> > single dyn_debug label to enable all of them instead of line-by-line.
> > Tbh no idea how this should work, might need dyndbg work too.
>
> Yeah, this is going to be tricky.
>
> We'll probably need to enumerate these fully and if the process of gathering
> the data is simple or already done in the course of the function, just avoid the
> drm_debug_enabled() call with a CONFIG_DRM_DYNDBG check.
>
> If the debug_enabled call gates a HW access, we probably need to query dyndbg
> for the prefix the logs are associated with before gathering the log contents.
>
> Sean
> >
> > - For the driver side of this we probably want a
> > Documentation/gpu/TODO.rst entry if it's not all easy to convert
> > directly.
> >
> > >
> > > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > > index 7ff89690a976..e4524ccba040 100644
> > > --- a/drivers/gpu/drm/Kconfig
> > > +++ b/drivers/gpu/drm/Kconfig
> > > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> > >
> > > If in doubt, say "N".
> > >
> > > +config DRM_USE_DYNAMIC_DEBUG
> > > + bool "use dynamic debug to implement drm.debug"
> > > + default n
> > > + depends on DRM
> > > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > > + depends on JUMP_LABEL
> > > + help
> > > + The drm debug category facility does a lot of unlikely bit-field
> > > + tests at runtime; while cheap individually, the cost accumulates.
> > > + This option uses dynamic debug facility (if configured and
> > > + using jump_label) to avoid those runtime checks, patching
> > > + the kernel when those debugs are desired.
> >
> > Can't we just make this an internal option that's enabled automatically
> > when dyndbg is around? Plus a comment somewhere that we really recommend
> > enabling dyndbg for drm. Or would this mean that in certain dyndbg
> > configurations we'd loose all the debug lines, which would suck?
> >
> > Anyway there's a pile of details, but the big picture I really like.
> > Especially that we can make dyndbg seamlessly support drm.debug is really
> > nice.
> >
> > Cheers, Daniel
> >
> > > +
> > > config DRM_DEBUG_SELFTEST
> > > tristate "kselftests for DRM"
> > > depends on DRM
> > > diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> > > index 111b932cf2a9..e2acdfc7088b 100644
> > > --- a/drivers/gpu/drm/drm_print.c
> > > +++ b/drivers/gpu/drm/drm_print.c
> > > @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> > > "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> > > "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> > > "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> > > +
> > > +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> > > module_param_named(debug, __drm_debug, int, 0600);
> > >
> > > +#else
> > > +static char *format_class_prefixes[] = {
> > > + cDRM_UT_CORE,
> > > + cDRM_UT_DRIVER,
> > > + cDRM_UT_KMS,
> > > + cDRM_UT_PRIME,
> > > + cDRM_UT_ATOMIC,
> > > + cDRM_UT_VBL,
> > > + cDRM_UT_STATE,
> > > + cDRM_UT_LEASE,
> > > + cDRM_UT_DP,
> > > + cDRM_UT_DRMRES
> > > +};
> > > +
> > > +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> > > +
> > > +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> > > +{
> > > + unsigned int val;
> > > + unsigned long changes, result;
> > > + int rc, chgct = 0, totct = 0, bitpos;
> > > + char query[OUR_QUERY_SIZE];
> > > +
> > > + rc = kstrtouint(instr, 0, &val);
> > > + if (rc) {
> > > + pr_err("%s: failed\n", __func__);
> > > + return -EINVAL;
> > > + }
> > > + result = val;
> > > + changes = result ^ __drm_debug;
> > > +
> > > + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> > > +
> > > + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> > > +
> > > + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> > > + test_bit(bitpos, &result) ? '+' : '-');
> > > +
> > > + chgct = dynamic_debug_exec_queries(query, "drm*");
> > > + if (chgct < 0) {
> > > + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> > > + continue;
> > > + }
> > > + pr_debug("change ct:%d on %s\n", chgct, query);
> > > + totct += chgct;
> > > + }
> > > + pr_debug("total changes: %d\n", totct);
> > > + __drm_debug = result;
> > > + return 0;
> > > +}
> > > +
> > > +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> > > +{
> > > + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> > > + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> > > + *((unsigned int *)kp->arg));
> > > +}
> > > +static const struct kernel_param_ops param_ops_debug = {
> > > + .set = param_set_dyndbg,
> > > + .get = param_get_dyndbg,
> > > +};
> > > +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> > > +
> > > +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > void __drm_puts_coredump(struct drm_printer *p, const char *str)
> > > {
> > > struct drm_print_iterator *iterator = p->arg;
> > > @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> > > }
> > > EXPORT_SYMBOL(drm_dev_printk);
> > >
> > > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > const char *format, ...)
> > > {
> > > struct va_format vaf;
> > > @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > >
> > > va_end(args);
> > > }
> > > -EXPORT_SYMBOL(drm_dev_dbg);
> > > +EXPORT_SYMBOL(_drm_dev_dbg);
> > >
> > > -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> > > {
> > > struct va_format vaf;
> > > va_list args;
> > > @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > >
> > > va_end(args);
> > > }
> > > -EXPORT_SYMBOL(__drm_dbg);
> > > +EXPORT_SYMBOL(___drm_dbg);
> > >
> > > void __drm_err(const char *format, ...)
> > > {
> > > diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> > > index ff5ac0e88321..499fa0b35200 100644
> > > --- a/include/drm/drm_print.h
> > > +++ b/include/drm/drm_print.h
> > > @@ -319,6 +319,51 @@ enum drm_debug_category {
> > > DRM_UT_DRMRES = 0x200,
> > > };
> > >
> > > +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> > > +
> > > +/* Use legacy drm-debug functions, and drm_debug_enabled().
> > > + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> > > + */
> > > +#define __drm_dbg(cls, fmt, ...) \
> > > + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> > > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > > + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> > > +
> > > +#define cDRM_UT_CORE DRM_UT_CORE
> > > +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> > > +#define cDRM_UT_KMS DRM_UT_KMS
> > > +#define cDRM_UT_PRIME DRM_UT_PRIME
> > > +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> > > +#define cDRM_UT_VBL DRM_UT_VBL
> > > +#define cDRM_UT_STATE DRM_UT_STATE
> > > +#define cDRM_UT_LEASE DRM_UT_LEASE
> > > +#define cDRM_UT_DP DRM_UT_DP
> > > +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> > > +
> > > +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > +/* use dynamic_debug to avoid drm_debug_enabled().
> > > + * dyndbg has no category, so we prefix the format with a "class"
> > > + * string; cDRM_UT_* maps to those class strings
> > > + */
> > > +#define __drm_dbg(cls, fmt, ...) \
> > > + pr_debug(cls # fmt, ##__VA_ARGS__)
> > > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > > + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> > > +
> > > +#define cDRM_UT_CORE "drm:core: "
> > > +#define cDRM_UT_DRIVER "drm:drvr: "
> > > +#define cDRM_UT_KMS "drm:kms: "
> > > +#define cDRM_UT_PRIME "drm:prime: "
> > > +#define cDRM_UT_ATOMIC "drm:atomic: "
> > > +#define cDRM_UT_VBL "drm:vbl: "
> > > +#define cDRM_UT_STATE "drm:state: "
> > > +#define cDRM_UT_LEASE "drm:lease: "
> > > +#define cDRM_UT_DP "drm:dp: "
> > > +#define cDRM_UT_DRMRES "drm:res "
> > > +
> > > +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > static inline bool drm_debug_enabled(enum drm_debug_category category)
> > > {
> > > return unlikely(__drm_debug & category);
> > > @@ -334,7 +379,7 @@ __printf(3, 4)
> > > void drm_dev_printk(const struct device *dev, const char *level,
> > > const char *format, ...);
> > > __printf(3, 4)
> > > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > const char *format, ...);
> > >
> > > /**
> > > @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > /**
> > > * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> > > *
> > > @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > /**
> > > * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> > > *
> > > @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > >
> > > /*
> > > * struct drm_device based logging
> > > @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > >
> > >
> > > #define drm_dbg_core(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_kms(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_prime(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_atomic(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_vbl(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_state(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_lease(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_dp(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_drmres(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > >
> > >
> > > /*
> > > @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > */
> > >
> > > __printf(2, 3)
> > > -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> > > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> > > __printf(1, 2)
> > > void __drm_err(const char *format, ...);
> > >
> > > @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> > > #define DRM_ERROR_RATELIMITED(fmt, ...) \
> > > DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
> > >
> > > +
> > > #define DRM_DEBUG(fmt, ...) \
> > > - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_DRIVER(fmt, ...) \
> > > - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_KMS(fmt, ...) \
> > > - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_PRIME(fmt, ...) \
> > > - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_ATOMIC(fmt, ...) \
> > > - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_VBL(fmt, ...) \
> > > - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_LEASE(fmt, ...) \
> > > - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_DP(fmt, ...) \
> > > - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
> > >
> > > -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> > > +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> > > ({ \
> > > static DEFINE_RATELIMIT_STATE(rs_, \
> > > DEFAULT_RATELIMIT_INTERVAL, \
> > > DEFAULT_RATELIMIT_BURST); \
> > > const struct drm_device *drm_ = (drm); \
> > > \
> > > - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> > > - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> > > - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> > > + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> > > + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> > > + cDRM_UT, fmt, ##__VA_ARGS__); \
> > > })
> > >
> > > #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> > > - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> > > + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
> > >
> > > #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> > > drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> > > --
> > > 2.31.1
> > >
> >
> > --
> > Daniel Vetter
> > Software Engineer, Intel Corporation
> > http://blog.ffwll.ch
> > _______________________________________________
> > Intel-gfx mailing list
> > Intel-gfx@lists.freedesktop.org
> > https://lists.freedesktop.org/mailman/listinfo/intel-gfx
>
> --
> Sean Paul, Software Engineer, Google / Chromium OS
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-27 14:02 ` Sean Paul
0 siblings, 0 replies; 43+ messages in thread
From: Sean Paul @ 2021-07-27 14:02 UTC (permalink / raw)
To: Daniel Vetter, Jim Cromie, Maarten Lankhorst, Maxime Ripard,
Thomas Zimmermann, David Airlie, Zhenyu Wang, Zhi Wang,
Jani Nikula, Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML,
intel-gvt-dev, Intel Graphics Development, jbaron
On Thu, Jul 22, 2021 at 11:20 AM Sean Paul <sean@poorly.run> wrote:
>
Reply-all fail. Adding everyone else back to my response.
> On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> > On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > > drm's debug system uses distinct categories of debug messages, encoded
> > > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > > drm.debug; we can use dynamic debug instead, and get all that
> > > static_key/jump_label goodness.
>
> Hi Jim,
> Thanks for your patches! Daniel pointed me at them in response to my drm_trace
> patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
> input on it. I think the 2 sets are mostly compatible, we'd just need to keep
> drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
> checks.
>
> > >
> > > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > > prepend them to the given formats.
> > >
> > > Then we can use:
> > > `echo module drm format ^drm:core: +p > control`
> > >
> > > to enable every such "prefixed" pr_debug with one query. This new
> > > prefix changes pr_debug's output, so is user visible, but it seems
> > > unlikely to cause trouble for log watchers; they're not relying on the
> > > absence of class prefix strings.
> > >
> > > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> > >
> > > dyndbg: 195 debug prints in module drm_kms_helper
> > > dyndbg: 298 debug prints in module drm
> > > dyndbg: 1630 debug prints in module i915
> > >
> > > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > > promised optimizations.
> > >
> > > The indirection/switchover is layered into the macro scheme:
> > >
> > > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > > to map those bits to specific query/commands
> > > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > > here for POC, this should be in dynamic_debug.c
> > > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
> >
> > This is really awesome.
>
>
> Agreed, this is a very clever way of merging the 2 worlds!
>
>
> > For merging I think we need to discuss with dyn
> > debug folks whether they're all ok with this, but it's exported already
> > should should be fine.
>
> I wonder if this is a good time to reconsider our drm categories. IMO they're
> overly broad and it's hard to get the right information without subscribing to
> the firehose. It seems like dyndbg might be a good opportunity to unlock
> subcategories of log messages.
>
> More concretely, on CrOS we can't subscribe to atomic or state categories since
> they're too noisy. However if there was a "fail" subcategory which dumped
> state/atomic logs on check failures, that would be really compelling. Something
> like:
>
> drm:atomic:fail vs. drm:atomic
>
> Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
> dyndbg-aware clients to get better logs without having a huge table of
> individual log signatures.
>
> I'm not sure how tightly we'd want to control the subcategories. It could be
> strict like the categories spelled out in drm_print.h, or an open prefix arg to
> drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
> provide enough flexibility to properly
>
> Of course, none of this needs to be decided to land this initial support, it can
> be bolted on later easily enough (I think).
>
>
> >
> > >
> > > 1. A "converted" or "classy" DRM_UT_* map
> > >
> > > based on: DRM_UT_* ( symbol => bit-mask )
> > > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> > >
> > > So cDRM_UT_* is either:
> > > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > > enabled:
> > > #define cDRM_UT_KMS "drm:kms: "
> > > #define cDRM_UT_PRIME "drm:prime: "
> > > #define cDRM_UT_ATOMIC "drm:atomic: "
> >
> > the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> > (and git history isn't helpful either). What about just using
> > DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> > DRM_DBG_CLASS_KMS.
> >
> > Also would be really nice if we could make these a table or something, but
> > I guess with the macro magic that's not possible.
> >
> > >
> > > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > > and elsewhere.
> >
> > I think for the production version of these we need to retire/deprecate
> > them, at least for drm core. Otherwise you have an annoying mismatch
> > between drm.debug module option and dyn debug.
> >
> > >
> > > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> > >
> > > old names are now macros, calling either:
> > > legacy: -> to renamed fn
> > > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> > >
> > > these names are used in a fat layer of macros (3) which supply the
> > > category; those macros are used throughout drm code, yielding the
> > > ~2100 new prdbgs reported above.
> > >
> > > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> > >
> > > all these macros get "converted" to use cDRM_UT_*
> > > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> > >
> > > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> > >
> > > remove DRM_UT_ ## KMS as extra indirection
> > > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
> >
> > For merging, can we pull out the renames and reorgs from this patch, and
> > then maybe also the reorder the next patch in your series here to be
> > before the dyn debug stuff?
> >
> > > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > > ---
> > > drivers/gpu/drm/Kconfig | 13 +++++
> > > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > > 3 files changed, 158 insertions(+), 32 deletions(-)
> >
> > I really like this, I think you can drop the RFC. A few more things that I
> > think we need:
> >
> > - An overview kerneldoc section which explains the interfaces and how it
> > all works together. Essentially your commit message with some light
> > markup to make it look good.
> >
> > - I think it would be really good to review the driver docs for all this
> > and make sure it's complete. Some of the interface functions aren't
> > documented yet (or maybe the ones that drivers shouldn't used need more
> > __ prefixes to denote them as internal, dunno).
> >
> > - I guess deprecation notice for drm_debug_enabled() and all that, so that
> > we have a consistent interface. Doing the conversion will probably
> > highlight the need for a bit more infrastructure and tooling, e.g. the
> > bigger dump functions (like edid hex dump, or also the various decode
> > helpers we have for dp, hdmi infoframes and all that) ideally have a
> > single dyn_debug label to enable all of them instead of line-by-line.
> > Tbh no idea how this should work, might need dyndbg work too.
>
> Yeah, this is going to be tricky.
>
> We'll probably need to enumerate these fully and if the process of gathering
> the data is simple or already done in the course of the function, just avoid the
> drm_debug_enabled() call with a CONFIG_DRM_DYNDBG check.
>
> If the debug_enabled call gates a HW access, we probably need to query dyndbg
> for the prefix the logs are associated with before gathering the log contents.
>
> Sean
> >
> > - For the driver side of this we probably want a
> > Documentation/gpu/TODO.rst entry if it's not all easy to convert
> > directly.
> >
> > >
> > > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > > index 7ff89690a976..e4524ccba040 100644
> > > --- a/drivers/gpu/drm/Kconfig
> > > +++ b/drivers/gpu/drm/Kconfig
> > > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> > >
> > > If in doubt, say "N".
> > >
> > > +config DRM_USE_DYNAMIC_DEBUG
> > > + bool "use dynamic debug to implement drm.debug"
> > > + default n
> > > + depends on DRM
> > > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > > + depends on JUMP_LABEL
> > > + help
> > > + The drm debug category facility does a lot of unlikely bit-field
> > > + tests at runtime; while cheap individually, the cost accumulates.
> > > + This option uses dynamic debug facility (if configured and
> > > + using jump_label) to avoid those runtime checks, patching
> > > + the kernel when those debugs are desired.
> >
> > Can't we just make this an internal option that's enabled automatically
> > when dyndbg is around? Plus a comment somewhere that we really recommend
> > enabling dyndbg for drm. Or would this mean that in certain dyndbg
> > configurations we'd loose all the debug lines, which would suck?
> >
> > Anyway there's a pile of details, but the big picture I really like.
> > Especially that we can make dyndbg seamlessly support drm.debug is really
> > nice.
> >
> > Cheers, Daniel
> >
> > > +
> > > config DRM_DEBUG_SELFTEST
> > > tristate "kselftests for DRM"
> > > depends on DRM
> > > diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c
> > > index 111b932cf2a9..e2acdfc7088b 100644
> > > --- a/drivers/gpu/drm/drm_print.c
> > > +++ b/drivers/gpu/drm/drm_print.c
> > > @@ -52,8 +52,75 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat
> > > "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n"
> > > "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n"
> > > "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> > > +
> > > +#ifndef CONFIG_DRM_USE_DYNAMIC_DEBUG
> > > module_param_named(debug, __drm_debug, int, 0600);
> > >
> > > +#else
> > > +static char *format_class_prefixes[] = {
> > > + cDRM_UT_CORE,
> > > + cDRM_UT_DRIVER,
> > > + cDRM_UT_KMS,
> > > + cDRM_UT_PRIME,
> > > + cDRM_UT_ATOMIC,
> > > + cDRM_UT_VBL,
> > > + cDRM_UT_STATE,
> > > + cDRM_UT_LEASE,
> > > + cDRM_UT_DP,
> > > + cDRM_UT_DRMRES
> > > +};
> > > +
> > > +#define OUR_QUERY_SIZE 64 /* > strlen "format '^%s' %cp" + longest prefix */
> > > +
> > > +static int param_set_dyndbg(const char *instr, const struct kernel_param *kp)
> > > +{
> > > + unsigned int val;
> > > + unsigned long changes, result;
> > > + int rc, chgct = 0, totct = 0, bitpos;
> > > + char query[OUR_QUERY_SIZE];
> > > +
> > > + rc = kstrtouint(instr, 0, &val);
> > > + if (rc) {
> > > + pr_err("%s: failed\n", __func__);
> > > + return -EINVAL;
> > > + }
> > > + result = val;
> > > + changes = result ^ __drm_debug;
> > > +
> > > + pr_debug("changes:0x%lx from result:0x%lx\n", changes, result);
> > > +
> > > + for_each_set_bit(bitpos, &changes, ARRAY_SIZE(format_class_prefixes)) {
> > > +
> > > + sprintf(query, "format '^%s' %cp", format_class_prefixes[bitpos],
> > > + test_bit(bitpos, &result) ? '+' : '-');
> > > +
> > > + chgct = dynamic_debug_exec_queries(query, "drm*");
> > > + if (chgct < 0) {
> > > + pr_err("%s: exec err:%d on: %s\n", __func__, chgct, query);
> > > + continue;
> > > + }
> > > + pr_debug("change ct:%d on %s\n", chgct, query);
> > > + totct += chgct;
> > > + }
> > > + pr_debug("total changes: %d\n", totct);
> > > + __drm_debug = result;
> > > + return 0;
> > > +}
> > > +
> > > +static int param_get_dyndbg(char *buffer, const struct kernel_param *kp)
> > > +{
> > > + pr_debug("debug-val:0x%x %u\n", __drm_debug, *((unsigned int *)kp->arg));
> > > + return scnprintf(buffer, PAGE_SIZE, "%u\n",
> > > + *((unsigned int *)kp->arg));
> > > +}
> > > +static const struct kernel_param_ops param_ops_debug = {
> > > + .set = param_set_dyndbg,
> > > + .get = param_get_dyndbg,
> > > +};
> > > +module_param_cb(debug, ¶m_ops_debug, &__drm_debug, 0644);
> > > +
> > > +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > void __drm_puts_coredump(struct drm_printer *p, const char *str)
> > > {
> > > struct drm_print_iterator *iterator = p->arg;
> > > @@ -256,7 +323,7 @@ void drm_dev_printk(const struct device *dev, const char *level,
> > > }
> > > EXPORT_SYMBOL(drm_dev_printk);
> > >
> > > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > const char *format, ...)
> > > {
> > > struct va_format vaf;
> > > @@ -278,9 +345,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > >
> > > va_end(args);
> > > }
> > > -EXPORT_SYMBOL(drm_dev_dbg);
> > > +EXPORT_SYMBOL(_drm_dev_dbg);
> > >
> > > -void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...)
> > > {
> > > struct va_format vaf;
> > > va_list args;
> > > @@ -297,7 +364,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...)
> > >
> > > va_end(args);
> > > }
> > > -EXPORT_SYMBOL(__drm_dbg);
> > > +EXPORT_SYMBOL(___drm_dbg);
> > >
> > > void __drm_err(const char *format, ...)
> > > {
> > > diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
> > > index ff5ac0e88321..499fa0b35200 100644
> > > --- a/include/drm/drm_print.h
> > > +++ b/include/drm/drm_print.h
> > > @@ -319,6 +319,51 @@ enum drm_debug_category {
> > > DRM_UT_DRMRES = 0x200,
> > > };
> > >
> > > +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG)
> > > +
> > > +/* Use legacy drm-debug functions, and drm_debug_enabled().
> > > + * For cDRM_UT_* (converted category), identity map to DRM_UT_*
> > > + */
> > > +#define __drm_dbg(cls, fmt, ...) \
> > > + ___drm_dbg(cls, fmt, ##__VA_ARGS__)
> > > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > > + _drm_dev_dbg(dev, cls, fmt, ##__VA_ARGS__)
> > > +
> > > +#define cDRM_UT_CORE DRM_UT_CORE
> > > +#define cDRM_UT_DRIVER DRM_UT_DRIVER
> > > +#define cDRM_UT_KMS DRM_UT_KMS
> > > +#define cDRM_UT_PRIME DRM_UT_PRIME
> > > +#define cDRM_UT_ATOMIC DRM_UT_ATOMIC
> > > +#define cDRM_UT_VBL DRM_UT_VBL
> > > +#define cDRM_UT_STATE DRM_UT_STATE
> > > +#define cDRM_UT_LEASE DRM_UT_LEASE
> > > +#define cDRM_UT_DP DRM_UT_DP
> > > +#define cDRM_UT_DRMRES DRM_UT_DRMRES
> > > +
> > > +#else /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > +/* use dynamic_debug to avoid drm_debug_enabled().
> > > + * dyndbg has no category, so we prefix the format with a "class"
> > > + * string; cDRM_UT_* maps to those class strings
> > > + */
> > > +#define __drm_dbg(cls, fmt, ...) \
> > > + pr_debug(cls # fmt, ##__VA_ARGS__)
> > > +#define drm_dev_dbg(dev, cls, fmt, ...) \
> > > + dev_dbg(dev, cls # fmt, ##__VA_ARGS__)
> > > +
> > > +#define cDRM_UT_CORE "drm:core: "
> > > +#define cDRM_UT_DRIVER "drm:drvr: "
> > > +#define cDRM_UT_KMS "drm:kms: "
> > > +#define cDRM_UT_PRIME "drm:prime: "
> > > +#define cDRM_UT_ATOMIC "drm:atomic: "
> > > +#define cDRM_UT_VBL "drm:vbl: "
> > > +#define cDRM_UT_STATE "drm:state: "
> > > +#define cDRM_UT_LEASE "drm:lease: "
> > > +#define cDRM_UT_DP "drm:dp: "
> > > +#define cDRM_UT_DRMRES "drm:res "
> > > +
> > > +#endif /* !CONFIG_DRM_USE_DYNAMIC_DEBUG */
> > > +
> > > static inline bool drm_debug_enabled(enum drm_debug_category category)
> > > {
> > > return unlikely(__drm_debug & category);
> > > @@ -334,7 +379,7 @@ __printf(3, 4)
> > > void drm_dev_printk(const struct device *dev, const char *level,
> > > const char *format, ...);
> > > __printf(3, 4)
> > > -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > +void _drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > const char *format, ...);
> > >
> > > /**
> > > @@ -383,7 +428,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > /**
> > > * DRM_DEV_DEBUG_DRIVER() - Debug output for vendor specific part of the driver
> > > *
> > > @@ -391,7 +436,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG_DRIVER(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > /**
> > > * DRM_DEV_DEBUG_KMS() - Debug output for modesetting code
> > > *
> > > @@ -399,7 +444,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > * @fmt: printf() like format string.
> > > */
> > > #define DRM_DEV_DEBUG_KMS(dev, fmt, ...) \
> > > - drm_dev_dbg(dev, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg(dev, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > >
> > > /*
> > > * struct drm_device based logging
> > > @@ -443,25 +488,25 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > >
> > >
> > > #define drm_dbg_core(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_kms(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_prime(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_atomic(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_vbl(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_state(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_STATE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_STATE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_lease(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_dp(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DP, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DP, fmt, ##__VA_ARGS__)
> > > #define drm_dbg_drmres(drm, fmt, ...) \
> > > - drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > > + drm_dev_dbg((drm) ? (drm)->dev : NULL, cDRM_UT_DRMRES, fmt, ##__VA_ARGS__)
> > >
> > >
> > > /*
> > > @@ -471,7 +516,7 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> > > */
> > >
> > > __printf(2, 3)
> > > -void __drm_dbg(enum drm_debug_category category, const char *format, ...);
> > > +void ___drm_dbg(enum drm_debug_category category, const char *format, ...);
> > > __printf(1, 2)
> > > void __drm_err(const char *format, ...);
> > >
> > > @@ -500,44 +545,45 @@ void __drm_err(const char *format, ...);
> > > #define DRM_ERROR_RATELIMITED(fmt, ...) \
> > > DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
> > >
> > > +
> > > #define DRM_DEBUG(fmt, ...) \
> > > - __drm_dbg(DRM_UT_CORE, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_CORE, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_DRIVER(fmt, ...) \
> > > - __drm_dbg(DRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_DRIVER, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_KMS(fmt, ...) \
> > > - __drm_dbg(DRM_UT_KMS, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_KMS, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_PRIME(fmt, ...) \
> > > - __drm_dbg(DRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_PRIME, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_ATOMIC(fmt, ...) \
> > > - __drm_dbg(DRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_ATOMIC, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_VBL(fmt, ...) \
> > > - __drm_dbg(DRM_UT_VBL, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_VBL, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_LEASE(fmt, ...) \
> > > - __drm_dbg(DRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_LEASE, fmt, ##__VA_ARGS__)
> > >
> > > #define DRM_DEBUG_DP(fmt, ...) \
> > > - __drm_dbg(DRM_UT_DP, fmt, ## __VA_ARGS__)
> > > + __drm_dbg(cDRM_UT_DP, fmt, ## __VA_ARGS__)
> > >
> > > -#define __DRM_DEFINE_DBG_RATELIMITED(category, drm, fmt, ...) \
> > > +#define __DRM_DEFINE_DBG_RATELIMITED(DRM_UT, cDRM_UT, drm, fmt, ...) \
> > > ({ \
> > > static DEFINE_RATELIMIT_STATE(rs_, \
> > > DEFAULT_RATELIMIT_INTERVAL, \
> > > DEFAULT_RATELIMIT_BURST); \
> > > const struct drm_device *drm_ = (drm); \
> > > \
> > > - if (drm_debug_enabled(DRM_UT_ ## category) && __ratelimit(&rs_))\
> > > - drm_dev_printk(drm_ ? drm_->dev : NULL, \
> > > - KERN_DEBUG, fmt, ## __VA_ARGS__); \
> > > + if (drm_debug_enabled(DRM_UT) && __ratelimit(&rs_)) \
> > > + drm_dev_dbg((drm_) ? (drm_)->dev : NULL, \
> > > + cDRM_UT, fmt, ##__VA_ARGS__); \
> > > })
> > >
> > > #define drm_dbg_kms_ratelimited(drm, fmt, ...) \
> > > - __DRM_DEFINE_DBG_RATELIMITED(KMS, drm, fmt, ## __VA_ARGS__)
> > > + __DRM_DEFINE_DBG_RATELIMITED(DRM_UT_KMS, cDRM_UT_KMS, drm, fmt, ## __VA_ARGS__)
> > >
> > > #define DRM_DEBUG_KMS_RATELIMITED(fmt, ...) \
> > > drm_dbg_kms_ratelimited(NULL, fmt, ## __VA_ARGS__)
> > > --
> > > 2.31.1
> > >
> >
> > --
> > Daniel Vetter
> > Software Engineer, Intel Corporation
> > http://blog.ffwll.ch
> > _______________________________________________
> > Intel-gfx mailing list
> > Intel-gfx@lists.freedesktop.org
> > https://lists.freedesktop.org/mailman/listinfo/intel-gfx
>
> --
> Sean Paul, Software Engineer, Google / Chromium OS
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
2021-07-27 14:02 ` Sean Paul
(?)
@ 2021-07-28 21:22 ` jim.cromie
-1 siblings, 0 replies; 43+ messages in thread
From: jim.cromie @ 2021-07-28 21:22 UTC (permalink / raw)
To: Sean Paul
Cc: Daniel Vetter, Maarten Lankhorst, Maxime Ripard,
Thomas Zimmermann, David Airlie, Zhenyu Wang, Zhi Wang,
Jani Nikula, Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML,
intel-gvt-dev, Intel Graphics Development, Jason Baron
On Tue, Jul 27, 2021 at 10:03 AM Sean Paul <sean@poorly.run> wrote:
>
> On Thu, Jul 22, 2021 at 11:20 AM Sean Paul <sean@poorly.run> wrote:
> >
>
> Reply-all fail. Adding everyone else back to my response.
>
> > On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> > > On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > > > drm's debug system uses distinct categories of debug messages, encoded
> > > > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > > > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > > > drm.debug; we can use dynamic debug instead, and get all that
> > > > static_key/jump_label goodness.
> >
> > Hi Jim,
> > Thanks for your patches! Daniel pointed me at them in response to my drm_trace
> > patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
> > input on it. I think the 2 sets are mostly compatible, we'd just need to keep
> > drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
> > checks.
> >
> > > >
> > > > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > > > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > > > prepend them to the given formats.
> > > >
> > > > Then we can use:
> > > > `echo module drm format ^drm:core: +p > control`
> > > >
> > > > to enable every such "prefixed" pr_debug with one query. This new
> > > > prefix changes pr_debug's output, so is user visible, but it seems
> > > > unlikely to cause trouble for log watchers; they're not relying on the
> > > > absence of class prefix strings.
> > > >
> > > > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> > > >
> > > > dyndbg: 195 debug prints in module drm_kms_helper
> > > > dyndbg: 298 debug prints in module drm
> > > > dyndbg: 1630 debug prints in module i915
> > > >
> > > > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > > > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > > > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > > > promised optimizations.
> > > >
> > > > The indirection/switchover is layered into the macro scheme:
> > > >
> > > > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > > > to map those bits to specific query/commands
> > > > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > > > here for POC, this should be in dynamic_debug.c
> > > > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
> > >
> > > This is really awesome.
> >
> >
> > Agreed, this is a very clever way of merging the 2 worlds!
> >
> >
> > > For merging I think we need to discuss with dyn
> > > debug folks whether they're all ok with this, but it's exported already
> > > should should be fine.
> >
> > I wonder if this is a good time to reconsider our drm categories. IMO they're
> > overly broad and it's hard to get the right information without subscribing to
> > the firehose. It seems like dyndbg might be a good opportunity to unlock
> > subcategories of log messages.
> >
> > More concretely, on CrOS we can't subscribe to atomic or state categories since
> > they're too noisy. However if there was a "fail" subcategory which dumped
> > state/atomic logs on check failures, that would be really compelling. Something
> > like:
> >
> > drm:atomic:fail vs. drm:atomic
> >
YES
> > Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
> > dyndbg-aware clients to get better logs without having a huge table of
> > individual log signatures.
> >
> > I'm not sure how tightly we'd want to control the subcategories. It could be
> > strict like the categories spelled out in drm_print.h, or an open prefix arg to
> > drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
> > provide enough flexibility to properly
formalizing categories and subcategories is where the
practical selectivity of format ^prefix is determined.
While endless bikeshedding is a possible downside,
there are a few subtleties to note, so we can pick a harmonious 3-color scheme:
"drm:kms: " and "drm:kms:" are different (2nd, w/o trailing space,
allows subcats)
"drm:kms" is also different (includes "drm:kmsmart", whatever that would be)
"drm.kms" again. dot names anyone ?
ASIDE(s):
"drm:kms" and "drm:kms*" are different,
the latter does not work as you might reasonably expect.
This is because
commit 578b1e0701af34f9ef69daabda4431f1e8501109
Author: Changbin Du <changbin.du@intel.com>
Date: Thu Jan 23 15:54:14 2014 -0800
dynamic_debug: add wildcard support to filter files/functions/modules
Add wildcard '*'(matches zero or more characters) and '?' (matches one
character) support when qurying debug flags.
specifically left format out of the wildcarded query terms.
And that was rational since the format search was already special
(floating substring, not exact match or basename match)
and format foobar should work analogously to grep foobar, ie w/o wildcards.
while an implied "format *foobar*" is possible, I dont like the
regex-iness implied in that 1st '*'
(2)
dyndbg is extremely agnostic about prefixes used by authors/subsystems
"1:", "2:", "3:" is a lot like the original: void dev_printk(const
char *level, ..).
w/o the trailing colon, even more so (I will be checking what it does!)
"Lo:", "Mid:", "Hi:" was proposed in a patchset once, and is usable today.
some unification of explicit wildcard chars * & ? and format floating
substr seems practical,
with it, prefix matching could handle complicated error message regimes.
Specifically, http return codes like 100, 200, 400, 404 etc would work.
/ASIDE
In any case, lets not try to over-control the categories & optional
subcategories,
at least not with lots of structure. Afterall, only code review will
prevent something like:
pr_debug("%s: blah blah\n", hex(sha1))
(queries on it are highly selective, but not organized)
IMO, its potentially useful to be able to add ad-hoc categories,
review and taste can moderate the ad-hockery,
"drm:misc:" seems a reasonable catch-all, esp with 3rd level
selectivity possible
Consider Sean's example: "drm:atomic:fail", and variations:
"drm:atomic:ok" - not as useful, unless we wanted a counter.
I dont think we need to rule it out.
to the extent that theres a traceable event here (success)
theres some utility to be able to put something of a label on it.
"drm:atomic:fail-%s" - we could have a dictionary of reasons,
(with open dictionary, neologisms allowed, any reason not to?)
> >
> > Of course, none of this needs to be decided to land this initial support, it can
> > be bolted on later easily enough (I think).
> >
I think so too, one such revisit...
Eventually, the "drm:" part of the prefix may become sufficiently unnecessary
that we could drop it in the name of log brevity.
The selectivity lost to "format ^prefix" is recovered by adding
"module drm*" or similar,
so somemod.foobar's use of pr_debug("atomic: blabla") would be excluded,
Or a flag-day, where we swap over to drm.dot.naming.
Doing so modestly improves the use of ':' for a log-entry field separator.
(though probably not a material improvement, structured logs are
better for this)
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-28 21:22 ` jim.cromie
0 siblings, 0 replies; 43+ messages in thread
From: jim.cromie @ 2021-07-28 21:22 UTC (permalink / raw)
To: Sean Paul
Cc: David Airlie, dri-devel, LKML, Jason Baron, Maxime Ripard,
Thomas Zimmermann, intel-gvt-dev, Intel Graphics Development
On Tue, Jul 27, 2021 at 10:03 AM Sean Paul <sean@poorly.run> wrote:
>
> On Thu, Jul 22, 2021 at 11:20 AM Sean Paul <sean@poorly.run> wrote:
> >
>
> Reply-all fail. Adding everyone else back to my response.
>
> > On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> > > On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > > > drm's debug system uses distinct categories of debug messages, encoded
> > > > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > > > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > > > drm.debug; we can use dynamic debug instead, and get all that
> > > > static_key/jump_label goodness.
> >
> > Hi Jim,
> > Thanks for your patches! Daniel pointed me at them in response to my drm_trace
> > patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
> > input on it. I think the 2 sets are mostly compatible, we'd just need to keep
> > drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
> > checks.
> >
> > > >
> > > > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > > > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > > > prepend them to the given formats.
> > > >
> > > > Then we can use:
> > > > `echo module drm format ^drm:core: +p > control`
> > > >
> > > > to enable every such "prefixed" pr_debug with one query. This new
> > > > prefix changes pr_debug's output, so is user visible, but it seems
> > > > unlikely to cause trouble for log watchers; they're not relying on the
> > > > absence of class prefix strings.
> > > >
> > > > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> > > >
> > > > dyndbg: 195 debug prints in module drm_kms_helper
> > > > dyndbg: 298 debug prints in module drm
> > > > dyndbg: 1630 debug prints in module i915
> > > >
> > > > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > > > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > > > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > > > promised optimizations.
> > > >
> > > > The indirection/switchover is layered into the macro scheme:
> > > >
> > > > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > > > to map those bits to specific query/commands
> > > > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > > > here for POC, this should be in dynamic_debug.c
> > > > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
> > >
> > > This is really awesome.
> >
> >
> > Agreed, this is a very clever way of merging the 2 worlds!
> >
> >
> > > For merging I think we need to discuss with dyn
> > > debug folks whether they're all ok with this, but it's exported already
> > > should should be fine.
> >
> > I wonder if this is a good time to reconsider our drm categories. IMO they're
> > overly broad and it's hard to get the right information without subscribing to
> > the firehose. It seems like dyndbg might be a good opportunity to unlock
> > subcategories of log messages.
> >
> > More concretely, on CrOS we can't subscribe to atomic or state categories since
> > they're too noisy. However if there was a "fail" subcategory which dumped
> > state/atomic logs on check failures, that would be really compelling. Something
> > like:
> >
> > drm:atomic:fail vs. drm:atomic
> >
YES
> > Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
> > dyndbg-aware clients to get better logs without having a huge table of
> > individual log signatures.
> >
> > I'm not sure how tightly we'd want to control the subcategories. It could be
> > strict like the categories spelled out in drm_print.h, or an open prefix arg to
> > drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
> > provide enough flexibility to properly
formalizing categories and subcategories is where the
practical selectivity of format ^prefix is determined.
While endless bikeshedding is a possible downside,
there are a few subtleties to note, so we can pick a harmonious 3-color scheme:
"drm:kms: " and "drm:kms:" are different (2nd, w/o trailing space,
allows subcats)
"drm:kms" is also different (includes "drm:kmsmart", whatever that would be)
"drm.kms" again. dot names anyone ?
ASIDE(s):
"drm:kms" and "drm:kms*" are different,
the latter does not work as you might reasonably expect.
This is because
commit 578b1e0701af34f9ef69daabda4431f1e8501109
Author: Changbin Du <changbin.du@intel.com>
Date: Thu Jan 23 15:54:14 2014 -0800
dynamic_debug: add wildcard support to filter files/functions/modules
Add wildcard '*'(matches zero or more characters) and '?' (matches one
character) support when qurying debug flags.
specifically left format out of the wildcarded query terms.
And that was rational since the format search was already special
(floating substring, not exact match or basename match)
and format foobar should work analogously to grep foobar, ie w/o wildcards.
while an implied "format *foobar*" is possible, I dont like the
regex-iness implied in that 1st '*'
(2)
dyndbg is extremely agnostic about prefixes used by authors/subsystems
"1:", "2:", "3:" is a lot like the original: void dev_printk(const
char *level, ..).
w/o the trailing colon, even more so (I will be checking what it does!)
"Lo:", "Mid:", "Hi:" was proposed in a patchset once, and is usable today.
some unification of explicit wildcard chars * & ? and format floating
substr seems practical,
with it, prefix matching could handle complicated error message regimes.
Specifically, http return codes like 100, 200, 400, 404 etc would work.
/ASIDE
In any case, lets not try to over-control the categories & optional
subcategories,
at least not with lots of structure. Afterall, only code review will
prevent something like:
pr_debug("%s: blah blah\n", hex(sha1))
(queries on it are highly selective, but not organized)
IMO, its potentially useful to be able to add ad-hoc categories,
review and taste can moderate the ad-hockery,
"drm:misc:" seems a reasonable catch-all, esp with 3rd level
selectivity possible
Consider Sean's example: "drm:atomic:fail", and variations:
"drm:atomic:ok" - not as useful, unless we wanted a counter.
I dont think we need to rule it out.
to the extent that theres a traceable event here (success)
theres some utility to be able to put something of a label on it.
"drm:atomic:fail-%s" - we could have a dictionary of reasons,
(with open dictionary, neologisms allowed, any reason not to?)
> >
> > Of course, none of this needs to be decided to land this initial support, it can
> > be bolted on later easily enough (I think).
> >
I think so too, one such revisit...
Eventually, the "drm:" part of the prefix may become sufficiently unnecessary
that we could drop it in the name of log brevity.
The selectivity lost to "format ^prefix" is recovered by adding
"module drm*" or similar,
so somemod.foobar's use of pr_debug("atomic: blabla") would be excluded,
Or a flag-day, where we swap over to drm.dot.naming.
Doing so modestly improves the use of ':' for a log-entry field separator.
(though probably not a material improvement, structured logs are
better for this)
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-28 21:22 ` jim.cromie
0 siblings, 0 replies; 43+ messages in thread
From: jim.cromie @ 2021-07-28 21:22 UTC (permalink / raw)
To: Sean Paul
Cc: David Airlie, dri-devel, LKML, Jason Baron, Thomas Zimmermann,
Rodrigo Vivi, intel-gvt-dev, Intel Graphics Development,
Zhi Wang
On Tue, Jul 27, 2021 at 10:03 AM Sean Paul <sean@poorly.run> wrote:
>
> On Thu, Jul 22, 2021 at 11:20 AM Sean Paul <sean@poorly.run> wrote:
> >
>
> Reply-all fail. Adding everyone else back to my response.
>
> > On Tue, Jul 20, 2021 at 03:29:34PM +0200, Daniel Vetter wrote:
> > > On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > > > drm's debug system uses distinct categories of debug messages, encoded
> > > > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > > > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > > > drm.debug; we can use dynamic debug instead, and get all that
> > > > static_key/jump_label goodness.
> >
> > Hi Jim,
> > Thanks for your patches! Daniel pointed me at them in response to my drm_trace
> > patchset (https://patchwork.freedesktop.org/series/78133/). I'd love to get your
> > input on it. I think the 2 sets are mostly compatible, we'd just need to keep
> > drm_dev_dbg and do the CONFIG check in the function beside the trace_enabled
> > checks.
> >
> > > >
> > > > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > > > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > > > prepend them to the given formats.
> > > >
> > > > Then we can use:
> > > > `echo module drm format ^drm:core: +p > control`
> > > >
> > > > to enable every such "prefixed" pr_debug with one query. This new
> > > > prefix changes pr_debug's output, so is user visible, but it seems
> > > > unlikely to cause trouble for log watchers; they're not relying on the
> > > > absence of class prefix strings.
> > > >
> > > > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> > > >
> > > > dyndbg: 195 debug prints in module drm_kms_helper
> > > > dyndbg: 298 debug prints in module drm
> > > > dyndbg: 1630 debug prints in module i915
> > > >
> > > > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > > > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > > > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > > > promised optimizations.
> > > >
> > > > The indirection/switchover is layered into the macro scheme:
> > > >
> > > > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > > > to map those bits to specific query/commands
> > > > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > > > here for POC, this should be in dynamic_debug.c
> > > > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
> > >
> > > This is really awesome.
> >
> >
> > Agreed, this is a very clever way of merging the 2 worlds!
> >
> >
> > > For merging I think we need to discuss with dyn
> > > debug folks whether they're all ok with this, but it's exported already
> > > should should be fine.
> >
> > I wonder if this is a good time to reconsider our drm categories. IMO they're
> > overly broad and it's hard to get the right information without subscribing to
> > the firehose. It seems like dyndbg might be a good opportunity to unlock
> > subcategories of log messages.
> >
> > More concretely, on CrOS we can't subscribe to atomic or state categories since
> > they're too noisy. However if there was a "fail" subcategory which dumped
> > state/atomic logs on check failures, that would be really compelling. Something
> > like:
> >
> > drm:atomic:fail vs. drm:atomic
> >
YES
> > Both would be picked up if (drm.debug & DRM_DBG_ATOMIC), however it would allow
> > dyndbg-aware clients to get better logs without having a huge table of
> > individual log signatures.
> >
> > I'm not sure how tightly we'd want to control the subcategories. It could be
> > strict like the categories spelled out in drm_print.h, or an open prefix arg to
> > drm_dev_dbg. I suspect we'd want the former, but would want to be careful to
> > provide enough flexibility to properly
formalizing categories and subcategories is where the
practical selectivity of format ^prefix is determined.
While endless bikeshedding is a possible downside,
there are a few subtleties to note, so we can pick a harmonious 3-color scheme:
"drm:kms: " and "drm:kms:" are different (2nd, w/o trailing space,
allows subcats)
"drm:kms" is also different (includes "drm:kmsmart", whatever that would be)
"drm.kms" again. dot names anyone ?
ASIDE(s):
"drm:kms" and "drm:kms*" are different,
the latter does not work as you might reasonably expect.
This is because
commit 578b1e0701af34f9ef69daabda4431f1e8501109
Author: Changbin Du <changbin.du@intel.com>
Date: Thu Jan 23 15:54:14 2014 -0800
dynamic_debug: add wildcard support to filter files/functions/modules
Add wildcard '*'(matches zero or more characters) and '?' (matches one
character) support when qurying debug flags.
specifically left format out of the wildcarded query terms.
And that was rational since the format search was already special
(floating substring, not exact match or basename match)
and format foobar should work analogously to grep foobar, ie w/o wildcards.
while an implied "format *foobar*" is possible, I dont like the
regex-iness implied in that 1st '*'
(2)
dyndbg is extremely agnostic about prefixes used by authors/subsystems
"1:", "2:", "3:" is a lot like the original: void dev_printk(const
char *level, ..).
w/o the trailing colon, even more so (I will be checking what it does!)
"Lo:", "Mid:", "Hi:" was proposed in a patchset once, and is usable today.
some unification of explicit wildcard chars * & ? and format floating
substr seems practical,
with it, prefix matching could handle complicated error message regimes.
Specifically, http return codes like 100, 200, 400, 404 etc would work.
/ASIDE
In any case, lets not try to over-control the categories & optional
subcategories,
at least not with lots of structure. Afterall, only code review will
prevent something like:
pr_debug("%s: blah blah\n", hex(sha1))
(queries on it are highly selective, but not organized)
IMO, its potentially useful to be able to add ad-hoc categories,
review and taste can moderate the ad-hockery,
"drm:misc:" seems a reasonable catch-all, esp with 3rd level
selectivity possible
Consider Sean's example: "drm:atomic:fail", and variations:
"drm:atomic:ok" - not as useful, unless we wanted a counter.
I dont think we need to rule it out.
to the extent that theres a traceable event here (success)
theres some utility to be able to put something of a label on it.
"drm:atomic:fail-%s" - we could have a dictionary of reasons,
(with open dictionary, neologisms allowed, any reason not to?)
> >
> > Of course, none of this needs to be decided to land this initial support, it can
> > be bolted on later easily enough (I think).
> >
I think so too, one such revisit...
Eventually, the "drm:" part of the prefix may become sufficiently unnecessary
that we could drop it in the name of log brevity.
The selectivity lost to "format ^prefix" is recovered by adding
"module drm*" or similar,
so somemod.foobar's use of pr_debug("atomic: blabla") would be excluded,
Or a flag-day, where we swap over to drm.dot.naming.
Doing so modestly improves the use of ':' for a log-entry field separator.
(though probably not a material improvement, structured logs are
better for this)
^ permalink raw reply [flat|nested] 43+ messages in thread
* Re: [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
2021-07-20 13:29 ` Daniel Vetter
(?)
@ 2021-07-22 19:38 ` jim.cromie
-1 siblings, 0 replies; 43+ messages in thread
From: jim.cromie @ 2021-07-22 19:38 UTC (permalink / raw)
To: Jim Cromie, Maarten Lankhorst, Maxime Ripard, Thomas Zimmermann,
David Airlie, Zhenyu Wang, Zhi Wang, Jani Nikula,
Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML, intel-gvt-dev,
intel-gfx, Jason Baron
Cc: Daniel Vetter
Thanks for the feedback!
On Tue, Jul 20, 2021 at 9:29 AM Daniel Vetter <daniel@ffwll.ch> wrote:
>
> On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, encoded
> > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > drm.debug; we can use dynamic debug instead, and get all that
> > static_key/jump_label goodness.
> >
> > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > prepend them to the given formats.
> >
> > Then we can use:
> > `echo module drm format ^drm:core: +p > control`
> >
> > to enable every such "prefixed" pr_debug with one query. This new
> > prefix changes pr_debug's output, so is user visible, but it seems
> > unlikely to cause trouble for log watchers; they're not relying on the
> > absence of class prefix strings.
> >
> > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> >
> > dyndbg: 195 debug prints in module drm_kms_helper
> > dyndbg: 298 debug prints in module drm
> > dyndbg: 1630 debug prints in module i915
> >
> > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > promised optimizations.
> >
> > The indirection/switchover is layered into the macro scheme:
> >
> > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > to map those bits to specific query/commands
> > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > here for POC, this should be in dynamic_debug.c
> > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
>
> This is really awesome. For merging I think we need to discuss with dyn
> debug folks whether they're all ok with this, but it's exported already
> should should be fine.
>
Yay. FWIW, Im to blame for that export, with this use case in mind.
That said, I dont know if that macro can be written as I described,
but if not, then { BIT(0), "prefix-0", "description-0" }, { BIT(1)
.... } should work.
If its been done elsewhere, Id copy it, or imitate it.
> >
> > 1. A "converted" or "classy" DRM_UT_* map
> >
> > based on: DRM_UT_* ( symbol => bit-mask )
> > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> >
> > So cDRM_UT_* is either:
> > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > enabled:
> > #define cDRM_UT_KMS "drm:kms: "
> > #define cDRM_UT_PRIME "drm:prime: "
> > #define cDRM_UT_ATOMIC "drm:atomic: "
>
> the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> (and git history isn't helpful either). What about just using
> DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> DRM_DBG_CLASS_KMS.
>
yes.
> Also would be really nice if we could make these a table or something, but
> I guess with the macro magic that's not possible.
>
not obvious to me, I'll watch for an opportunity.
> >
> > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > and elsewhere.
>
> I think for the production version of these we need to retire/deprecate
> them, at least for drm core. Otherwise you have an annoying mismatch
> between drm.debug module option and dyn debug.
>
I will look at renaming it : __drm_debug_enabled
and making a macro for the old name.
so enabled, it would end up like
if (unlikely(1) && ... )
drivers/gpu/drm/drm_atomic_uapi.c
1457: if (drm_debug_enabled(DRM_UT_STATE))
drivers/gpu/drm/drm_dp_mst_topology.c
1358: if (unlikely(ret == -EIO) && drm_debug_enabled(DRM_UT_DP)) {
2875: if (unlikely(ret) && drm_debug_enabled(DRM_UT_DP)) {
2919: if (drm_debug_enabled(DRM_UT_DP)) {
> >
> > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> >
> > old names are now macros, calling either:
> > legacy: -> to renamed fn
> > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> >
> > these names are used in a fat layer of macros (3) which supply the
> > category; those macros are used throughout drm code, yielding the
> > ~2100 new prdbgs reported above.
> >
> > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> >
> > all these macros get "converted" to use cDRM_UT_*
> > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> >
> > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> >
> > remove DRM_UT_ ## KMS as extra indirection
> > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
>
> For merging, can we pull out the renames and reorgs from this patch, and
> then maybe also the reorder the next patch in your series here to be
> before the dyn debug stuff?
>
I will drop the 4. RATELIMITED tweaks.
FWIW, I have semi-working code to implement rate limiting
in dynamic debug, controlled by `+r > control`
which would touch this anyway.
wrt reordering 4/5, can you clarify ?
the i915 changes are 1/2 POC, so I'll assume you mean after getting 0.
into dyndbg
> > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > ---
> > drivers/gpu/drm/Kconfig | 13 +++++
> > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > 3 files changed, 158 insertions(+), 32 deletions(-)
>
> I really like this, I think you can drop the RFC. A few more things that I
> think we need:
>
> - An overview kerneldoc section which explains the interfaces and how it
> all works together. Essentially your commit message with some light
> markup to make it look good.
into include/drm/drm_print.h ?
>
> - I think it would be really good to review the driver docs for all this
> and make sure it's complete. Some of the interface functions aren't
> documented yet (or maybe the ones that drivers shouldn't used need more
> __ prefixes to denote them as internal, dunno).
>
I will look, but I dont have the experience here to make these
qualitative judgements
Also, I renamed drm_dev_dbg to _drm_dev_dbg, with a single underscore.
I'm now thinking this is reserved, and __ prefix is better (legal)
This isnt quite the same is lower-level implementation detail,
since it adds a CONFIG dependent alternative impl.
But I'll do this unless you have a better name
> - I guess deprecation notice for drm_debug_enabled() and all that, so that
> we have a consistent interface. Doing the conversion will probably
> highlight the need for a bit more infrastructure and tooling, e.g. the
> bigger dump functions (like edid hex dump, or also the various decode
> helpers we have for dp, hdmi infoframes and all that) ideally have a
> single dyn_debug label to enable all of them instead of line-by-line.
> Tbh no idea how this should work, might need dyndbg work too.
>
macrofying drm_debug_enabled() might work for this set.
possibly with different prefixes, forex: "drmx:*" or "drm:misc:"
> - For the driver side of this we probably want a
> Documentation/gpu/TODO.rst entry if it's not all easy to convert
> directly.
so there are 32 uses of drm_debug_enabled(DRM_UT_*)
and just 1 used in drm_dev_dbg (with category as arg)
I'll try to macrofy it, see if it will handle the 32 cases.
>
> >
> > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > index 7ff89690a976..e4524ccba040 100644
> > --- a/drivers/gpu/drm/Kconfig
> > +++ b/drivers/gpu/drm/Kconfig
> > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> >
> > If in doubt, say "N".
> >
> > +config DRM_USE_DYNAMIC_DEBUG
> > + bool "use dynamic debug to implement drm.debug"
> > + default n
> > + depends on DRM
> > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > + depends on JUMP_LABEL
> > + help
> > + The drm debug category facility does a lot of unlikely bit-field
> > + tests at runtime; while cheap individually, the cost accumulates.
> > + This option uses dynamic debug facility (if configured and
> > + using jump_label) to avoid those runtime checks, patching
> > + the kernel when those debugs are desired.
>
> Can't we just make this an internal option that's enabled automatically
> when dyndbg is around? Plus a comment somewhere that we really recommend
> enabling dyndbg for drm. Or would this mean that in certain dyndbg
> configurations we'd loose all the debug lines, which would suck?
>
We could indeed, I took the cautious approach.
keeping the CONFIG simplifies comparing DRM_USE_DD=y/n builds,
and changing default later is easy, and probably should have some numbers
about instructions saved and obj size increase.
> Anyway there's a pile of details, but the big picture I really like.
> Especially that we can make dyndbg seamlessly support drm.debug is really
> nice.
>
> Cheers, Daniel
>
thanks, Jim
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-22 19:38 ` jim.cromie
0 siblings, 0 replies; 43+ messages in thread
From: jim.cromie @ 2021-07-22 19:38 UTC (permalink / raw)
To: Jim Cromie, Maarten Lankhorst, Maxime Ripard, Thomas Zimmermann,
David Airlie, Zhenyu Wang, Zhi Wang, Jani Nikula,
Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML, intel-gvt-dev,
intel-gfx, Jason Baron
Thanks for the feedback!
On Tue, Jul 20, 2021 at 9:29 AM Daniel Vetter <daniel@ffwll.ch> wrote:
>
> On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, encoded
> > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > drm.debug; we can use dynamic debug instead, and get all that
> > static_key/jump_label goodness.
> >
> > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > prepend them to the given formats.
> >
> > Then we can use:
> > `echo module drm format ^drm:core: +p > control`
> >
> > to enable every such "prefixed" pr_debug with one query. This new
> > prefix changes pr_debug's output, so is user visible, but it seems
> > unlikely to cause trouble for log watchers; they're not relying on the
> > absence of class prefix strings.
> >
> > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> >
> > dyndbg: 195 debug prints in module drm_kms_helper
> > dyndbg: 298 debug prints in module drm
> > dyndbg: 1630 debug prints in module i915
> >
> > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > promised optimizations.
> >
> > The indirection/switchover is layered into the macro scheme:
> >
> > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > to map those bits to specific query/commands
> > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > here for POC, this should be in dynamic_debug.c
> > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
>
> This is really awesome. For merging I think we need to discuss with dyn
> debug folks whether they're all ok with this, but it's exported already
> should should be fine.
>
Yay. FWIW, Im to blame for that export, with this use case in mind.
That said, I dont know if that macro can be written as I described,
but if not, then { BIT(0), "prefix-0", "description-0" }, { BIT(1)
.... } should work.
If its been done elsewhere, Id copy it, or imitate it.
> >
> > 1. A "converted" or "classy" DRM_UT_* map
> >
> > based on: DRM_UT_* ( symbol => bit-mask )
> > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> >
> > So cDRM_UT_* is either:
> > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > enabled:
> > #define cDRM_UT_KMS "drm:kms: "
> > #define cDRM_UT_PRIME "drm:prime: "
> > #define cDRM_UT_ATOMIC "drm:atomic: "
>
> the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> (and git history isn't helpful either). What about just using
> DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> DRM_DBG_CLASS_KMS.
>
yes.
> Also would be really nice if we could make these a table or something, but
> I guess with the macro magic that's not possible.
>
not obvious to me, I'll watch for an opportunity.
> >
> > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > and elsewhere.
>
> I think for the production version of these we need to retire/deprecate
> them, at least for drm core. Otherwise you have an annoying mismatch
> between drm.debug module option and dyn debug.
>
I will look at renaming it : __drm_debug_enabled
and making a macro for the old name.
so enabled, it would end up like
if (unlikely(1) && ... )
drivers/gpu/drm/drm_atomic_uapi.c
1457: if (drm_debug_enabled(DRM_UT_STATE))
drivers/gpu/drm/drm_dp_mst_topology.c
1358: if (unlikely(ret == -EIO) && drm_debug_enabled(DRM_UT_DP)) {
2875: if (unlikely(ret) && drm_debug_enabled(DRM_UT_DP)) {
2919: if (drm_debug_enabled(DRM_UT_DP)) {
> >
> > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> >
> > old names are now macros, calling either:
> > legacy: -> to renamed fn
> > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> >
> > these names are used in a fat layer of macros (3) which supply the
> > category; those macros are used throughout drm code, yielding the
> > ~2100 new prdbgs reported above.
> >
> > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> >
> > all these macros get "converted" to use cDRM_UT_*
> > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> >
> > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> >
> > remove DRM_UT_ ## KMS as extra indirection
> > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
>
> For merging, can we pull out the renames and reorgs from this patch, and
> then maybe also the reorder the next patch in your series here to be
> before the dyn debug stuff?
>
I will drop the 4. RATELIMITED tweaks.
FWIW, I have semi-working code to implement rate limiting
in dynamic debug, controlled by `+r > control`
which would touch this anyway.
wrt reordering 4/5, can you clarify ?
the i915 changes are 1/2 POC, so I'll assume you mean after getting 0.
into dyndbg
> > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > ---
> > drivers/gpu/drm/Kconfig | 13 +++++
> > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > 3 files changed, 158 insertions(+), 32 deletions(-)
>
> I really like this, I think you can drop the RFC. A few more things that I
> think we need:
>
> - An overview kerneldoc section which explains the interfaces and how it
> all works together. Essentially your commit message with some light
> markup to make it look good.
into include/drm/drm_print.h ?
>
> - I think it would be really good to review the driver docs for all this
> and make sure it's complete. Some of the interface functions aren't
> documented yet (or maybe the ones that drivers shouldn't used need more
> __ prefixes to denote them as internal, dunno).
>
I will look, but I dont have the experience here to make these
qualitative judgements
Also, I renamed drm_dev_dbg to _drm_dev_dbg, with a single underscore.
I'm now thinking this is reserved, and __ prefix is better (legal)
This isnt quite the same is lower-level implementation detail,
since it adds a CONFIG dependent alternative impl.
But I'll do this unless you have a better name
> - I guess deprecation notice for drm_debug_enabled() and all that, so that
> we have a consistent interface. Doing the conversion will probably
> highlight the need for a bit more infrastructure and tooling, e.g. the
> bigger dump functions (like edid hex dump, or also the various decode
> helpers we have for dp, hdmi infoframes and all that) ideally have a
> single dyn_debug label to enable all of them instead of line-by-line.
> Tbh no idea how this should work, might need dyndbg work too.
>
macrofying drm_debug_enabled() might work for this set.
possibly with different prefixes, forex: "drmx:*" or "drm:misc:"
> - For the driver side of this we probably want a
> Documentation/gpu/TODO.rst entry if it's not all easy to convert
> directly.
so there are 32 uses of drm_debug_enabled(DRM_UT_*)
and just 1 used in drm_dev_dbg (with category as arg)
I'll try to macrofy it, see if it will handle the 32 cases.
>
> >
> > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > index 7ff89690a976..e4524ccba040 100644
> > --- a/drivers/gpu/drm/Kconfig
> > +++ b/drivers/gpu/drm/Kconfig
> > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> >
> > If in doubt, say "N".
> >
> > +config DRM_USE_DYNAMIC_DEBUG
> > + bool "use dynamic debug to implement drm.debug"
> > + default n
> > + depends on DRM
> > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > + depends on JUMP_LABEL
> > + help
> > + The drm debug category facility does a lot of unlikely bit-field
> > + tests at runtime; while cheap individually, the cost accumulates.
> > + This option uses dynamic debug facility (if configured and
> > + using jump_label) to avoid those runtime checks, patching
> > + the kernel when those debugs are desired.
>
> Can't we just make this an internal option that's enabled automatically
> when dyndbg is around? Plus a comment somewhere that we really recommend
> enabling dyndbg for drm. Or would this mean that in certain dyndbg
> configurations we'd loose all the debug lines, which would suck?
>
We could indeed, I took the cautious approach.
keeping the CONFIG simplifies comparing DRM_USE_DD=y/n builds,
and changing default later is easy, and probably should have some numbers
about instructions saved and obj size increase.
> Anyway there's a pile of details, but the big picture I really like.
> Especially that we can make dyndbg seamlessly support drm.debug is really
> nice.
>
> Cheers, Daniel
>
thanks, Jim
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
^ permalink raw reply [flat|nested] 43+ messages in thread* Re: [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2021-07-22 19:38 ` jim.cromie
0 siblings, 0 replies; 43+ messages in thread
From: jim.cromie @ 2021-07-22 19:38 UTC (permalink / raw)
To: Jim Cromie, Maarten Lankhorst, Maxime Ripard, Thomas Zimmermann,
David Airlie, Zhenyu Wang, Zhi Wang, Jani Nikula,
Joonas Lahtinen, Rodrigo Vivi, dri-devel, LKML, intel-gvt-dev,
intel-gfx, Jason Baron
Thanks for the feedback!
On Tue, Jul 20, 2021 at 9:29 AM Daniel Vetter <daniel@ffwll.ch> wrote:
>
> On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> > drm's debug system uses distinct categories of debug messages, encoded
> > in an enum (DRM_UT_<CATEGORY>), which are mapped to bits in drm.debug.
> > drm_debug_enabled() does a lot of unlikely bit-mask checks on
> > drm.debug; we can use dynamic debug instead, and get all that
> > static_key/jump_label goodness.
> >
> > Dynamic debug has no concept of category, but we can map the DRM_UT_*
> > to a set of distinct prefixes; "drm:core:", "drm:kms:" etc, and
> > prepend them to the given formats.
> >
> > Then we can use:
> > `echo module drm format ^drm:core: +p > control`
> >
> > to enable every such "prefixed" pr_debug with one query. This new
> > prefix changes pr_debug's output, so is user visible, but it seems
> > unlikely to cause trouble for log watchers; they're not relying on the
> > absence of class prefix strings.
> >
> > This conversion yields ~2100 new callsites on my i7/i915 laptop:
> >
> > dyndbg: 195 debug prints in module drm_kms_helper
> > dyndbg: 298 debug prints in module drm
> > dyndbg: 1630 debug prints in module i915
> >
> > CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
> > CONFIG_DYNAMIC_DEBUG or CONFIG_DYNAMIC_DEBUG_CORE is chosen, and if
> > CONFIG_JUMP_LABEL is enabled; this because its required to get the
> > promised optimizations.
> >
> > The indirection/switchover is layered into the macro scheme:
> >
> > 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
> > to map those bits to specific query/commands
> > dynamic_debug_exec_queries("format ^drm:kms: +p", "drm*");
> > here for POC, this should be in dynamic_debug.c
> > with a MODULE_PARAM_DEBUG_BITMAP(__drm_debug, { "prefix-1", "desc-1" }+)
>
> This is really awesome. For merging I think we need to discuss with dyn
> debug folks whether they're all ok with this, but it's exported already
> should should be fine.
>
Yay. FWIW, Im to blame for that export, with this use case in mind.
That said, I dont know if that macro can be written as I described,
but if not, then { BIT(0), "prefix-0", "description-0" }, { BIT(1)
.... } should work.
If its been done elsewhere, Id copy it, or imitate it.
> >
> > 1. A "converted" or "classy" DRM_UT_* map
> >
> > based on: DRM_UT_* ( symbol => bit-mask )
> > named it: cDRM_UT_* ( symbol => format-class-prefix-string )
> >
> > So cDRM_UT_* is either:
> > legacy: cDRM_UT_* <-- DRM_UT_* ( !CONFIG_DRM_USE_DYNAMIC_DEBUG )
> > enabled:
> > #define cDRM_UT_KMS "drm:kms: "
> > #define cDRM_UT_PRIME "drm:prime: "
> > #define cDRM_UT_ATOMIC "drm:atomic: "
>
> the cDRM looks a bit funny, plus I don't eve have an idea what _UT_ means
> (and git history isn't helpful either). What about just using
> DRM_DBG_CLASS_ as the prefix here for these indirection macros, i.e.
> DRM_DBG_CLASS_KMS.
>
yes.
> Also would be really nice if we could make these a table or something, but
> I guess with the macro magic that's not possible.
>
not obvious to me, I'll watch for an opportunity.
> >
> > DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> > and elsewhere.
>
> I think for the production version of these we need to retire/deprecate
> them, at least for drm core. Otherwise you have an annoying mismatch
> between drm.debug module option and dyn debug.
>
I will look at renaming it : __drm_debug_enabled
and making a macro for the old name.
so enabled, it would end up like
if (unlikely(1) && ... )
drivers/gpu/drm/drm_atomic_uapi.c
1457: if (drm_debug_enabled(DRM_UT_STATE))
drivers/gpu/drm/drm_dp_mst_topology.c
1358: if (unlikely(ret == -EIO) && drm_debug_enabled(DRM_UT_DP)) {
2875: if (unlikely(ret) && drm_debug_enabled(DRM_UT_DP)) {
2919: if (drm_debug_enabled(DRM_UT_DP)) {
> >
> > 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
> >
> > old names are now macros, calling either:
> > legacy: -> to renamed fn
> > enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
> >
> > these names are used in a fat layer of macros (3) which supply the
> > category; those macros are used throughout drm code, yielding the
> > ~2100 new prdbgs reported above.
> >
> > 3. names in (2) are invoked by DRM_DEBUG_<Category>, drm_dbg_<Category>.
> >
> > all these macros get "converted" to use cDRM_UT_*
> > to get right token type for both !/!! DRM_USE_DYNAMIC_DEBUG
> >
> > 4. simplification of __DRM_DEFINE_DBG_RATELIMITED macro
> >
> > remove DRM_UT_ ## KMS as extra indirection
> > pass both DRM_UT & cDRM_UT, for drm_debug_enabled & drm_dev_dbg
>
> For merging, can we pull out the renames and reorgs from this patch, and
> then maybe also the reorder the next patch in your series here to be
> before the dyn debug stuff?
>
I will drop the 4. RATELIMITED tweaks.
FWIW, I have semi-working code to implement rate limiting
in dynamic debug, controlled by `+r > control`
which would touch this anyway.
wrt reordering 4/5, can you clarify ?
the i915 changes are 1/2 POC, so I'll assume you mean after getting 0.
into dyndbg
> > Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> > ---
> > drivers/gpu/drm/Kconfig | 13 +++++
> > drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> > include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> > 3 files changed, 158 insertions(+), 32 deletions(-)
>
> I really like this, I think you can drop the RFC. A few more things that I
> think we need:
>
> - An overview kerneldoc section which explains the interfaces and how it
> all works together. Essentially your commit message with some light
> markup to make it look good.
into include/drm/drm_print.h ?
>
> - I think it would be really good to review the driver docs for all this
> and make sure it's complete. Some of the interface functions aren't
> documented yet (or maybe the ones that drivers shouldn't used need more
> __ prefixes to denote them as internal, dunno).
>
I will look, but I dont have the experience here to make these
qualitative judgements
Also, I renamed drm_dev_dbg to _drm_dev_dbg, with a single underscore.
I'm now thinking this is reserved, and __ prefix is better (legal)
This isnt quite the same is lower-level implementation detail,
since it adds a CONFIG dependent alternative impl.
But I'll do this unless you have a better name
> - I guess deprecation notice for drm_debug_enabled() and all that, so that
> we have a consistent interface. Doing the conversion will probably
> highlight the need for a bit more infrastructure and tooling, e.g. the
> bigger dump functions (like edid hex dump, or also the various decode
> helpers we have for dp, hdmi infoframes and all that) ideally have a
> single dyn_debug label to enable all of them instead of line-by-line.
> Tbh no idea how this should work, might need dyndbg work too.
>
macrofying drm_debug_enabled() might work for this set.
possibly with different prefixes, forex: "drmx:*" or "drm:misc:"
> - For the driver side of this we probably want a
> Documentation/gpu/TODO.rst entry if it's not all easy to convert
> directly.
so there are 32 uses of drm_debug_enabled(DRM_UT_*)
and just 1 used in drm_dev_dbg (with category as arg)
I'll try to macrofy it, see if it will handle the 32 cases.
>
> >
> > diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> > index 7ff89690a976..e4524ccba040 100644
> > --- a/drivers/gpu/drm/Kconfig
> > +++ b/drivers/gpu/drm/Kconfig
> > @@ -57,6 +57,19 @@ config DRM_DEBUG_MM
> >
> > If in doubt, say "N".
> >
> > +config DRM_USE_DYNAMIC_DEBUG
> > + bool "use dynamic debug to implement drm.debug"
> > + default n
> > + depends on DRM
> > + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > + depends on JUMP_LABEL
> > + help
> > + The drm debug category facility does a lot of unlikely bit-field
> > + tests at runtime; while cheap individually, the cost accumulates.
> > + This option uses dynamic debug facility (if configured and
> > + using jump_label) to avoid those runtime checks, patching
> > + the kernel when those debugs are desired.
>
> Can't we just make this an internal option that's enabled automatically
> when dyndbg is around? Plus a comment somewhere that we really recommend
> enabling dyndbg for drm. Or would this mean that in certain dyndbg
> configurations we'd loose all the debug lines, which would suck?
>
We could indeed, I took the cautious approach.
keeping the CONFIG simplifies comparing DRM_USE_DD=y/n builds,
and changing default later is easy, and probably should have some numbers
about instructions saved and obj size increase.
> Anyway there's a pile of details, but the big picture I really like.
> Especially that we can make dyndbg seamlessly support drm.debug is really
> nice.
>
> Cheers, Daniel
>
thanks, Jim
^ permalink raw reply [flat|nested] 43+ messages in thread
* Re: [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
2021-07-20 13:29 ` Daniel Vetter
(?)
@ 2022-03-05 16:06 ` Jim Cromie
-1 siblings, 0 replies; 43+ messages in thread
From: Jim Cromie @ 2022-03-05 16:06 UTC (permalink / raw)
To: daniel, Jim Cromie
Cc: airlied, dri-devel, intel-gfx, intel-gvt-dev, jani.nikula,
jbaron, joonas.lahtinen, linux-kernel, maarten.lankhorst,
mripard, rodrigo.vivi, tzimmermann, zhenyuw, zhi.a.wang
From: Daniel Vetter <daniel@ffwll.ch>
Hi Daniel, everyone,
Ive substantially updated this patchset,
and I thought it useful to reply here.
Im noting the biggest changes in context below, trimming heavily otherwize.
Also, Ive lost the msg in my gmail-cloud, so this lacks
the usual "Daniel said: " attribution, and the "> " marks.
Ive prefixed "< " to 1st line of my replies where it helps.
The current patchset is here:
https://patchwork.freedesktop.org/series/100290/
https://lore.kernel.org/lkml/20220217034829.64395-1-jim.cromie@gmail.com/
Its "failing" patchwork CI cuz of a macro warning in dyndbg, which
would be nice for CI to "pass" because its out of DRM tree, and
subject to a separate review process, and in the meantime, it would be
nice to see it under test.
Going item by item:
On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, encoded
> in an enum (DRM_UT_<CATEGORY>),
enum is now renumbered to 0-15 (fits in 4 bits)
drm_debug_enabled() does BIT(cat)
15 is unclassed/reserved
> Dynamic debug has no concept of category, but we can map the DRM_UT_*
now it has "class" keyword, and class_id:4 field.
#> echo module drm class 1 +p > control # 1=DRM_UT_KMS iirc
This interface is unused yet, DRM is its A-1 customer, are you shopping ?
Since its unused, it cannot break anything not using it :-)
> CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
still true.
> The indirection/switchover is layered into the macro scheme:
Heres where the biggest DRM centric changes (vs old) are:
The cDRM_UT_* => prefix-string mapping is gone; while it worked, it
made the literal format strings config dependent, and was more
complicated to explain. Fitting category into class_id is much
cleaner.
old way replaced drm*dbg with pr_debug (at surface level)
new way adapts drm*dbg to reuse the class-Factory macro under pr_debug.
This loses pr_debug's log-decorating feature, but DRM has its own
conventions, and extra decorations are unlikely to really add anything.
OTOH, drm could re-use those flags to optionalize some of its conventions.
> 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
now in dyndbg, where it belonged. now just uses class query inside.
This is really awesome. For merging I think we need to discuss with dyn
debug folks whether they're all ok with this, but it's exported already
should should be fine.
< Your (fresh) endorsement should help :-)
Particularly, the new dyndbg features need a user.
>
> 1. A "converted" or "classy" DRM_UT_* map
>
repeating, 2nd map is gone, DRM_UT_* is merely renumbered.
> DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> and elsewhere.
I think for the production version of these we need to retire/deprecate
them, at least for drm core. Otherwise you have an annoying mismatch
between drm.debug module option and dyn debug.
< I think this isnt relevant now, since symbols are preserved.
Also, the __drm_debug var is used directly by the CLASSBITS macro,
(and therefore the callbacks), so /sys/module/drm/parameters/debug is
preserved at an ABI-ish level. (__drm_debug now ulong, to work with BIT)
>
> 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>
> old names are now macros, calling either:
> legacy: -> to renamed fn
> enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
>
For merging, can we pull out the renames and reorgs from this patch, and
then maybe also the reorder the next patch in your series here to be
before the dyn debug stuff?
< the above adaptation is re-adapted to use dyndbg's new class-Factory
macro, other stuff is gone.
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
> drivers/gpu/drm/Kconfig | 13 +++++
> drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> 3 files changed, 158 insertions(+), 32 deletions(-)
update - drm parts are slightly smaller now :-)
[jimc@frodo wk-next]$ git diff --stat master
Documentation/admin-guide/dynamic-debug-howto.rst | 7 +++++
drivers/gpu/drm/Kconfig | 12 ++++++++
drivers/gpu/drm/Makefile | 2 ++
drivers/gpu/drm/drm_print.c | 56 ++++++++++++++++++++++------------
include/drm/drm_print.h | 80 +++++++++++++++++++++++++++++
include/linux/dynamic_debug.h | 113 +++++++++++++++++++++++++++++
lib/dynamic_debug.c | 140 +++++++++++++++++++++++++++++
7 files changed, 323 insertions(+), 87 deletions(-)
I really like this, I think you can drop the RFC. A few more things that I
think we need:
- An overview kerneldoc section which explains the interfaces and how it
all works together. Essentially your commit message with some light
markup to make it look good.
< not sure anything worth documenting has survived.
- I think it would be really good to review the driver docs for all this
and make sure it's complete. Some of the interface functions aren't
documented yet (or maybe the ones that drivers shouldn't used need more
__ prefixes to denote them as internal, dunno).
- I guess deprecation notice for drm_debug_enabled() and all that, so that
we have a consistent interface. Doing the conversion will probably
< this keeps drm_debug_enabled(), and __drm_debug, so those users are fine.
__drm_debug_enabled() is optimized version for macro-wrapped sites
highlight the need for a bit more infrastructure and tooling, e.g. the
bigger dump functions (like edid hex dump, or also the various decode
helpers we have for dp, hdmi infoframes and all that) ideally have a
single dyn_debug label to enable all of them instead of line-by-line.
Tbh no idea how this should work, might need dyndbg work too.
< Factory-macros should help here, havent looked.
- For the driver side of this we probably want a
Documentation/gpu/TODO.rst entry if it's not all easy to convert
directly.
> +config DRM_USE_DYNAMIC_DEBUG
> + bool "use dynamic debug to implement drm.debug"
> + default n
> + depends on DRM
> + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> + depends on JUMP_LABEL
> + help
> + The drm debug category facility does a lot of unlikely bit-field
> + tests at runtime; while cheap individually, the cost accumulates.
> + This option uses dynamic debug facility (if configured and
> + using jump_label) to avoid those runtime checks, patching
> + the kernel when those debugs are desired.
Can't we just make this an internal option that's enabled automatically
when dyndbg is around? Plus a comment somewhere that we really recommend
enabling dyndbg for drm. Or would this mean that in certain dyndbg
configurations we'd loose all the debug lines, which would suck?
< I have 'default y' now.
WRT losing debug lines, I cant think how, but it raises a thought; cuz
drm.debug uses .class_id, the mod,func,file info isnt needed to
support queries (other than ad-hoc at >control), drm could drop them.
Its already lost pr_debug's optional mod.func.ln prefix, and cannot
use them for that. (but Im foreshadowing, see bottom)
Anyway there's a pile of details, but the big picture I really like.
Especially that we can make dyndbg seamlessly support drm.debug is really
nice.
Cheers, Daniel
< Wait, theres more ! (here comes the tease) :-D
0. this patchset and others below are at:
ghlinux-ro https://github.com/jimc/linux.git (fetch)
lkp-robot <lkp@intel.com> has been helping a lot.
1. dd-drm branch - this patchset
commit 46a5bd89e47d0f7e4ad63b4f574815f01d4290a0
(HEAD -> dd-drm, ghlinux/dd-drm, ghlinux-ro/dd-drm)
passing robot tests.
2. dyn-drm-trc branch - on top of 1.dd-drm
commit 0473a8ecdb15ec0e63644b77da575905c5851462
(ghlinux/dyn-drm-trc, ghlinux-ro/dyn-drm-trc, dyn-drm-trc)
It starts with Vincent Whitchurch's patch:
https://lore.kernel.org/lkml/20211209150910.GA23668@axis.com/
which (oversimplifying) added a trace-event and called it from
pr_debug, and which met with some approval from Steve Rostedt.
It then recapitulates those changes in drm_*dbg.
3. dd-diet-next - on top of 2.dyn-drm-trc.
passes lkp-robot tests, but still problematic
This splits struct _ddebug in 2, then de-duplicates the _ddebug_site
records (containing repetitive module,filename,function). In my
fedora-ish config kernel containing ~3100 callsites in builtin
modules, I see ~40% reduction in 24/64 of the full data footprint.
Id expect a little more in modules, due to higher prdbgs/fns ratio.
forex: (69% compression here)
dyndbg: 3883 debug prints in module amdgpu (in 1190 functions)
Its incomplete 2x: needs some union-fu, and more work to drop the
.site pointer. This would drop 8/40 from struct _ddebug, recover another 8/56 of total footprint.
A noteworthy side-effect of this is that it becomes practical to drop
all _ddebug_site data for modules which don't need/want it.
DRM (in 2.dyn-drm-trc) is such a user; it gets the control it needs
using .class_id, and has no log-decoration facility which would use
the 3 fields. It should just get lots of "_na_"s in cat control.
Dyndbg can be easily fixed to not apply query-commands which specify
those terms to callsites which do not have the data.
Clearly, getting to here is gonna be a many-step process.
DRM buy-in will certainly help :-)
Cheers, Jim
^ permalink raw reply [flat|nested] 43+ messages in thread
* Re: [Intel-gfx] [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2022-03-05 16:06 ` Jim Cromie
0 siblings, 0 replies; 43+ messages in thread
From: Jim Cromie @ 2022-03-05 16:06 UTC (permalink / raw)
To: daniel, Jim Cromie
Cc: mripard, airlied, intel-gfx, linux-kernel, jbaron, dri-devel,
tzimmermann, rodrigo.vivi, intel-gvt-dev
From: Daniel Vetter <daniel@ffwll.ch>
Hi Daniel, everyone,
Ive substantially updated this patchset,
and I thought it useful to reply here.
Im noting the biggest changes in context below, trimming heavily otherwize.
Also, Ive lost the msg in my gmail-cloud, so this lacks
the usual "Daniel said: " attribution, and the "> " marks.
Ive prefixed "< " to 1st line of my replies where it helps.
The current patchset is here:
https://patchwork.freedesktop.org/series/100290/
https://lore.kernel.org/lkml/20220217034829.64395-1-jim.cromie@gmail.com/
Its "failing" patchwork CI cuz of a macro warning in dyndbg, which
would be nice for CI to "pass" because its out of DRM tree, and
subject to a separate review process, and in the meantime, it would be
nice to see it under test.
Going item by item:
On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, encoded
> in an enum (DRM_UT_<CATEGORY>),
enum is now renumbered to 0-15 (fits in 4 bits)
drm_debug_enabled() does BIT(cat)
15 is unclassed/reserved
> Dynamic debug has no concept of category, but we can map the DRM_UT_*
now it has "class" keyword, and class_id:4 field.
#> echo module drm class 1 +p > control # 1=DRM_UT_KMS iirc
This interface is unused yet, DRM is its A-1 customer, are you shopping ?
Since its unused, it cannot break anything not using it :-)
> CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
still true.
> The indirection/switchover is layered into the macro scheme:
Heres where the biggest DRM centric changes (vs old) are:
The cDRM_UT_* => prefix-string mapping is gone; while it worked, it
made the literal format strings config dependent, and was more
complicated to explain. Fitting category into class_id is much
cleaner.
old way replaced drm*dbg with pr_debug (at surface level)
new way adapts drm*dbg to reuse the class-Factory macro under pr_debug.
This loses pr_debug's log-decorating feature, but DRM has its own
conventions, and extra decorations are unlikely to really add anything.
OTOH, drm could re-use those flags to optionalize some of its conventions.
> 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
now in dyndbg, where it belonged. now just uses class query inside.
This is really awesome. For merging I think we need to discuss with dyn
debug folks whether they're all ok with this, but it's exported already
should should be fine.
< Your (fresh) endorsement should help :-)
Particularly, the new dyndbg features need a user.
>
> 1. A "converted" or "classy" DRM_UT_* map
>
repeating, 2nd map is gone, DRM_UT_* is merely renumbered.
> DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> and elsewhere.
I think for the production version of these we need to retire/deprecate
them, at least for drm core. Otherwise you have an annoying mismatch
between drm.debug module option and dyn debug.
< I think this isnt relevant now, since symbols are preserved.
Also, the __drm_debug var is used directly by the CLASSBITS macro,
(and therefore the callbacks), so /sys/module/drm/parameters/debug is
preserved at an ABI-ish level. (__drm_debug now ulong, to work with BIT)
>
> 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>
> old names are now macros, calling either:
> legacy: -> to renamed fn
> enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
>
For merging, can we pull out the renames and reorgs from this patch, and
then maybe also the reorder the next patch in your series here to be
before the dyn debug stuff?
< the above adaptation is re-adapted to use dyndbg's new class-Factory
macro, other stuff is gone.
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
> drivers/gpu/drm/Kconfig | 13 +++++
> drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> 3 files changed, 158 insertions(+), 32 deletions(-)
update - drm parts are slightly smaller now :-)
[jimc@frodo wk-next]$ git diff --stat master
Documentation/admin-guide/dynamic-debug-howto.rst | 7 +++++
drivers/gpu/drm/Kconfig | 12 ++++++++
drivers/gpu/drm/Makefile | 2 ++
drivers/gpu/drm/drm_print.c | 56 ++++++++++++++++++++++------------
include/drm/drm_print.h | 80 +++++++++++++++++++++++++++++
include/linux/dynamic_debug.h | 113 +++++++++++++++++++++++++++++
lib/dynamic_debug.c | 140 +++++++++++++++++++++++++++++
7 files changed, 323 insertions(+), 87 deletions(-)
I really like this, I think you can drop the RFC. A few more things that I
think we need:
- An overview kerneldoc section which explains the interfaces and how it
all works together. Essentially your commit message with some light
markup to make it look good.
< not sure anything worth documenting has survived.
- I think it would be really good to review the driver docs for all this
and make sure it's complete. Some of the interface functions aren't
documented yet (or maybe the ones that drivers shouldn't used need more
__ prefixes to denote them as internal, dunno).
- I guess deprecation notice for drm_debug_enabled() and all that, so that
we have a consistent interface. Doing the conversion will probably
< this keeps drm_debug_enabled(), and __drm_debug, so those users are fine.
__drm_debug_enabled() is optimized version for macro-wrapped sites
highlight the need for a bit more infrastructure and tooling, e.g. the
bigger dump functions (like edid hex dump, or also the various decode
helpers we have for dp, hdmi infoframes and all that) ideally have a
single dyn_debug label to enable all of them instead of line-by-line.
Tbh no idea how this should work, might need dyndbg work too.
< Factory-macros should help here, havent looked.
- For the driver side of this we probably want a
Documentation/gpu/TODO.rst entry if it's not all easy to convert
directly.
> +config DRM_USE_DYNAMIC_DEBUG
> + bool "use dynamic debug to implement drm.debug"
> + default n
> + depends on DRM
> + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> + depends on JUMP_LABEL
> + help
> + The drm debug category facility does a lot of unlikely bit-field
> + tests at runtime; while cheap individually, the cost accumulates.
> + This option uses dynamic debug facility (if configured and
> + using jump_label) to avoid those runtime checks, patching
> + the kernel when those debugs are desired.
Can't we just make this an internal option that's enabled automatically
when dyndbg is around? Plus a comment somewhere that we really recommend
enabling dyndbg for drm. Or would this mean that in certain dyndbg
configurations we'd loose all the debug lines, which would suck?
< I have 'default y' now.
WRT losing debug lines, I cant think how, but it raises a thought; cuz
drm.debug uses .class_id, the mod,func,file info isnt needed to
support queries (other than ad-hoc at >control), drm could drop them.
Its already lost pr_debug's optional mod.func.ln prefix, and cannot
use them for that. (but Im foreshadowing, see bottom)
Anyway there's a pile of details, but the big picture I really like.
Especially that we can make dyndbg seamlessly support drm.debug is really
nice.
Cheers, Daniel
< Wait, theres more ! (here comes the tease) :-D
0. this patchset and others below are at:
ghlinux-ro https://github.com/jimc/linux.git (fetch)
lkp-robot <lkp@intel.com> has been helping a lot.
1. dd-drm branch - this patchset
commit 46a5bd89e47d0f7e4ad63b4f574815f01d4290a0
(HEAD -> dd-drm, ghlinux/dd-drm, ghlinux-ro/dd-drm)
passing robot tests.
2. dyn-drm-trc branch - on top of 1.dd-drm
commit 0473a8ecdb15ec0e63644b77da575905c5851462
(ghlinux/dyn-drm-trc, ghlinux-ro/dyn-drm-trc, dyn-drm-trc)
It starts with Vincent Whitchurch's patch:
https://lore.kernel.org/lkml/20211209150910.GA23668@axis.com/
which (oversimplifying) added a trace-event and called it from
pr_debug, and which met with some approval from Steve Rostedt.
It then recapitulates those changes in drm_*dbg.
3. dd-diet-next - on top of 2.dyn-drm-trc.
passes lkp-robot tests, but still problematic
This splits struct _ddebug in 2, then de-duplicates the _ddebug_site
records (containing repetitive module,filename,function). In my
fedora-ish config kernel containing ~3100 callsites in builtin
modules, I see ~40% reduction in 24/64 of the full data footprint.
Id expect a little more in modules, due to higher prdbgs/fns ratio.
forex: (69% compression here)
dyndbg: 3883 debug prints in module amdgpu (in 1190 functions)
Its incomplete 2x: needs some union-fu, and more work to drop the
.site pointer. This would drop 8/40 from struct _ddebug, recover another 8/56 of total footprint.
A noteworthy side-effect of this is that it becomes practical to drop
all _ddebug_site data for modules which don't need/want it.
DRM (in 2.dyn-drm-trc) is such a user; it gets the control it needs
using .class_id, and has no log-decoration facility which would use
the 3 fields. It should just get lots of "_na_"s in cat control.
Dyndbg can be easily fixed to not apply query-commands which specify
those terms to callsites which do not have the data.
Clearly, getting to here is gonna be a many-step process.
DRM buy-in will certainly help :-)
Cheers, Jim
^ permalink raw reply [flat|nested] 43+ messages in thread
* Re: [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug
@ 2022-03-05 16:06 ` Jim Cromie
0 siblings, 0 replies; 43+ messages in thread
From: Jim Cromie @ 2022-03-05 16:06 UTC (permalink / raw)
To: daniel, Jim Cromie
Cc: airlied, intel-gfx, linux-kernel, jbaron, dri-devel, tzimmermann,
rodrigo.vivi, intel-gvt-dev, zhi.a.wang
From: Daniel Vetter <daniel@ffwll.ch>
Hi Daniel, everyone,
Ive substantially updated this patchset,
and I thought it useful to reply here.
Im noting the biggest changes in context below, trimming heavily otherwize.
Also, Ive lost the msg in my gmail-cloud, so this lacks
the usual "Daniel said: " attribution, and the "> " marks.
Ive prefixed "< " to 1st line of my replies where it helps.
The current patchset is here:
https://patchwork.freedesktop.org/series/100290/
https://lore.kernel.org/lkml/20220217034829.64395-1-jim.cromie@gmail.com/
Its "failing" patchwork CI cuz of a macro warning in dyndbg, which
would be nice for CI to "pass" because its out of DRM tree, and
subject to a separate review process, and in the meantime, it would be
nice to see it under test.
Going item by item:
On Wed, Jul 14, 2021 at 11:51:36AM -0600, Jim Cromie wrote:
> drm's debug system uses distinct categories of debug messages, encoded
> in an enum (DRM_UT_<CATEGORY>),
enum is now renumbered to 0-15 (fits in 4 bits)
drm_debug_enabled() does BIT(cat)
15 is unclassed/reserved
> Dynamic debug has no concept of category, but we can map the DRM_UT_*
now it has "class" keyword, and class_id:4 field.
#> echo module drm class 1 +p > control # 1=DRM_UT_KMS iirc
This interface is unused yet, DRM is its A-1 customer, are you shopping ?
Since its unused, it cannot break anything not using it :-)
> CONFIG_DRM_USE_DYNAMIC_DEBUG enables this, and is available if
still true.
> The indirection/switchover is layered into the macro scheme:
Heres where the biggest DRM centric changes (vs old) are:
The cDRM_UT_* => prefix-string mapping is gone; while it worked, it
made the literal format strings config dependent, and was more
complicated to explain. Fitting category into class_id is much
cleaner.
old way replaced drm*dbg with pr_debug (at surface level)
new way adapts drm*dbg to reuse the class-Factory macro under pr_debug.
This loses pr_debug's log-decorating feature, but DRM has its own
conventions, and extra decorations are unlikely to really add anything.
OTOH, drm could re-use those flags to optionalize some of its conventions.
> 0. A new callback on drm.debug which calls dynamic_debug_exec_queries
now in dyndbg, where it belonged. now just uses class query inside.
This is really awesome. For merging I think we need to discuss with dyn
debug folks whether they're all ok with this, but it's exported already
should should be fine.
< Your (fresh) endorsement should help :-)
Particularly, the new dyndbg features need a user.
>
> 1. A "converted" or "classy" DRM_UT_* map
>
repeating, 2nd map is gone, DRM_UT_* is merely renumbered.
> DRM_UT_* are unchanged, since theyre used in drm_debug_enabled()
> and elsewhere.
I think for the production version of these we need to retire/deprecate
them, at least for drm core. Otherwise you have an annoying mismatch
between drm.debug module option and dyn debug.
< I think this isnt relevant now, since symbols are preserved.
Also, the __drm_debug var is used directly by the CLASSBITS macro,
(and therefore the callbacks), so /sys/module/drm/parameters/debug is
preserved at an ABI-ish level. (__drm_debug now ulong, to work with BIT)
>
> 2. drm_dev_dbg & drm_debug are renamed (prefixed with '_')
>
> old names are now macros, calling either:
> legacy: -> to renamed fn
> enabled: -> dev_dbg & pr_debug, with cDRM-prefix # format.
>
For merging, can we pull out the renames and reorgs from this patch, and
then maybe also the reorder the next patch in your series here to be
before the dyn debug stuff?
< the above adaptation is re-adapted to use dyndbg's new class-Factory
macro, other stuff is gone.
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
> drivers/gpu/drm/Kconfig | 13 +++++
> drivers/gpu/drm/drm_print.c | 75 ++++++++++++++++++++++++--
> include/drm/drm_print.h | 102 ++++++++++++++++++++++++++----------
> 3 files changed, 158 insertions(+), 32 deletions(-)
update - drm parts are slightly smaller now :-)
[jimc@frodo wk-next]$ git diff --stat master
Documentation/admin-guide/dynamic-debug-howto.rst | 7 +++++
drivers/gpu/drm/Kconfig | 12 ++++++++
drivers/gpu/drm/Makefile | 2 ++
drivers/gpu/drm/drm_print.c | 56 ++++++++++++++++++++++------------
include/drm/drm_print.h | 80 +++++++++++++++++++++++++++++
include/linux/dynamic_debug.h | 113 +++++++++++++++++++++++++++++
lib/dynamic_debug.c | 140 +++++++++++++++++++++++++++++
7 files changed, 323 insertions(+), 87 deletions(-)
I really like this, I think you can drop the RFC. A few more things that I
think we need:
- An overview kerneldoc section which explains the interfaces and how it
all works together. Essentially your commit message with some light
markup to make it look good.
< not sure anything worth documenting has survived.
- I think it would be really good to review the driver docs for all this
and make sure it's complete. Some of the interface functions aren't
documented yet (or maybe the ones that drivers shouldn't used need more
__ prefixes to denote them as internal, dunno).
- I guess deprecation notice for drm_debug_enabled() and all that, so that
we have a consistent interface. Doing the conversion will probably
< this keeps drm_debug_enabled(), and __drm_debug, so those users are fine.
__drm_debug_enabled() is optimized version for macro-wrapped sites
highlight the need for a bit more infrastructure and tooling, e.g. the
bigger dump functions (like edid hex dump, or also the various decode
helpers we have for dp, hdmi infoframes and all that) ideally have a
single dyn_debug label to enable all of them instead of line-by-line.
Tbh no idea how this should work, might need dyndbg work too.
< Factory-macros should help here, havent looked.
- For the driver side of this we probably want a
Documentation/gpu/TODO.rst entry if it's not all easy to convert
directly.
> +config DRM_USE_DYNAMIC_DEBUG
> + bool "use dynamic debug to implement drm.debug"
> + default n
> + depends on DRM
> + depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> + depends on JUMP_LABEL
> + help
> + The drm debug category facility does a lot of unlikely bit-field
> + tests at runtime; while cheap individually, the cost accumulates.
> + This option uses dynamic debug facility (if configured and
> + using jump_label) to avoid those runtime checks, patching
> + the kernel when those debugs are desired.
Can't we just make this an internal option that's enabled automatically
when dyndbg is around? Plus a comment somewhere that we really recommend
enabling dyndbg for drm. Or would this mean that in certain dyndbg
configurations we'd loose all the debug lines, which would suck?
< I have 'default y' now.
WRT losing debug lines, I cant think how, but it raises a thought; cuz
drm.debug uses .class_id, the mod,func,file info isnt needed to
support queries (other than ad-hoc at >control), drm could drop them.
Its already lost pr_debug's optional mod.func.ln prefix, and cannot
use them for that. (but Im foreshadowing, see bottom)
Anyway there's a pile of details, but the big picture I really like.
Especially that we can make dyndbg seamlessly support drm.debug is really
nice.
Cheers, Daniel
< Wait, theres more ! (here comes the tease) :-D
0. this patchset and others below are at:
ghlinux-ro https://github.com/jimc/linux.git (fetch)
lkp-robot <lkp@intel.com> has been helping a lot.
1. dd-drm branch - this patchset
commit 46a5bd89e47d0f7e4ad63b4f574815f01d4290a0
(HEAD -> dd-drm, ghlinux/dd-drm, ghlinux-ro/dd-drm)
passing robot tests.
2. dyn-drm-trc branch - on top of 1.dd-drm
commit 0473a8ecdb15ec0e63644b77da575905c5851462
(ghlinux/dyn-drm-trc, ghlinux-ro/dyn-drm-trc, dyn-drm-trc)
It starts with Vincent Whitchurch's patch:
https://lore.kernel.org/lkml/20211209150910.GA23668@axis.com/
which (oversimplifying) added a trace-event and called it from
pr_debug, and which met with some approval from Steve Rostedt.
It then recapitulates those changes in drm_*dbg.
3. dd-diet-next - on top of 2.dyn-drm-trc.
passes lkp-robot tests, but still problematic
This splits struct _ddebug in 2, then de-duplicates the _ddebug_site
records (containing repetitive module,filename,function). In my
fedora-ish config kernel containing ~3100 callsites in builtin
modules, I see ~40% reduction in 24/64 of the full data footprint.
Id expect a little more in modules, due to higher prdbgs/fns ratio.
forex: (69% compression here)
dyndbg: 3883 debug prints in module amdgpu (in 1190 functions)
Its incomplete 2x: needs some union-fu, and more work to drop the
.site pointer. This would drop 8/40 from struct _ddebug, recover another 8/56 of total footprint.
A noteworthy side-effect of this is that it becomes practical to drop
all _ddebug_site data for modules which don't need/want it.
DRM (in 2.dyn-drm-trc) is such a user; it gets the control it needs
using .class_id, and has no log-decoration facility which would use
the 3 fields. It should just get lots of "_na_"s in cat control.
Dyndbg can be easily fixed to not apply query-commands which specify
those terms to callsites which do not have the data.
Clearly, getting to here is gonna be a many-step process.
DRM buy-in will certainly help :-)
Cheers, Jim
^ permalink raw reply [flat|nested] 43+ messages in thread