Re: [PATCH v3 3/5] drm/print: RFC add choice to use dynamic debug in drm-debug

[jim . cromie]

Thanks for the feedback!


On Tue, Jul 20, 2021 at 9:29 AM Daniel Vetter <daniel@xxxxxxxx> 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@xxxxxxxxx>
> > ---
> >  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