Message ID | 20210831202133.2165222-7-jim.cromie@gmail.com (mailing list archive) |
---|---|
State | New, archived |
Headers | show |
Series | use DYNAMIC_DEBUG to implement DRM.debug | expand |
On Tue, Aug 31, 2021 at 2:21 PM Jim Cromie <jim.cromie@gmail.com> wrote: > > Duplicate drm_debug_enabled() code into both "basic" and "dyndbg" > ifdef branches. Then add a pr_debug("todo: ...") into the "dyndbg" > branch. > > Then convert the "dyndbg" branch's code to a macro, so that its > pr_debug() get its callsite info from the invoking function, instead > of from drm_debug_enabled() itself. > > This gives us unique callsite info for the 8 remaining users of > drm_debug_enabled(), and lets us enable them individually to see how > much logging traffic they generate. The oft-visited callsites can > then be reviewed for runtime cost and possible optimizations. > > Heres what we get: > > bash-5.1# modprobe drm > dyndbg: 384 debug prints in module drm > bash-5.1# grep todo: /proc/dynamic_debug/control > drivers/gpu/drm/drm_edid.c:1843 [drm]connector_bad_edid =_ "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_print.c:309 [drm]___drm_dbg =p "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_print.c:286 [drm]__drm_dev_dbg =p "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_vblank.c:1491 [drm]drm_vblank_restore =_ "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_vblank.c:787 [drm]drm_crtc_vblank_helper_get_vblank_timestamp_internal =_ "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_vblank.c:410 [drm]drm_crtc_accurate_vblank_count =_ "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_atomic_uapi.c:1457 [drm]drm_mode_atomic_ioctl =_ "todo: maybe avoid via dyndbg\012" > drivers/gpu/drm/drm_edid_load.c:178 [drm]edid_load =_ "todo: maybe avoid via dyndbg\012" > > At quick glance, edid won't qualify, drm_print might, drm_vblank is > strongest chance, maybe atomic-ioctl too. > > Signed-off-by: Jim Cromie <jim.cromie@gmail.com> > --- heres 120 seconds of enabled todos, from this patch [jimc@frodo wk-next]$ journalctl -b0 | grep todo | grep 'frodo kernel' [jimc@frodo wk-next]$ sudo su -c 'echo format ^todo: +pfml > /proc/dynamic_debug/control; sleep 120; echo format ^todo: -p > /proc/dynamic_debug/control' [sudo] password for jimc: [jimc@frodo wk-next]$ journalctl -b0 | grep todo | grep 'frodo kernel' > todo-120-log [jimc@frodo wk-next]$ wc todo-120-log 228 2516 24066 todo-120-log so overall thats not too much work, not so many bitchecks as to be worth avoiding. I think I'll try hitting it with my new igt-tools hammer, see what breaks :-) [jimc@frodo wk-next]$ hsto todo-120-log 120 : drm:drm_crtc_vblank_helper_get_vblank_timestamp_internal:787: todo: maybe avoid via dyndbg 40 : i915:process_csb:1904: todo: maybe avoid via dyndbg 20 : drm:drm_vblank_restore:1491: todo: maybe avoid via dyndbg 20 : drm:drm_crtc_accurate_vblank_count:410: todo: maybe avoid via dyndbg 20 : i915:skl_print_wm_changes:6068: todo: maybe avoid via dyndbg 2 : dyndbg: applied: func="" file="" module="" format="^todo:" lineno=0-0 2 : dyndbg: parsed: func="" file="" module="" format="^todo:" lineno=0-0 1 : dyndbg: split into words: "format" "^todo:" "-p" 1 : dyndbg: split into words: "format" "^todo:" "+pfml" 1 : dyndbg: query 0: "format ^todo: -p" mod:* 1 : dyndbg: query 0: "format ^todo: +pfml" mod:*
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 973443040561..03f9ae83fade 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -378,6 +378,11 @@ enum drm_debug_category { #define DRM_DBG_CAT_DP DRM_UT_DP #define DRM_DBG_CAT_DRMRES DRM_UT_DRMRES +static inline bool drm_debug_enabled(enum drm_debug_category category) +{ + return unlikely(__drm_debug & category); +} + #else /* CONFIG_DRM_USE_DYNAMIC_DEBUG */ /* join prefix+format in cpp so dyndbg can see it */ @@ -397,12 +402,13 @@ enum drm_debug_category { #define DRM_DBG_CAT_DP "drm:dp: " #define DRM_DBG_CAT_DRMRES "drm:res: " /* not in MODULE_PARM_DESC */ -#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */ +#define drm_debug_enabled(category) \ + ({ \ + pr_debug("todo: maybe avoid via dyndbg\n"); \ + unlikely(__drm_debug & category); \ + }) -static inline bool drm_debug_enabled(enum drm_debug_category category) -{ - return unlikely(__drm_debug & category); -} +#endif /* CONFIG_DRM_USE_DYNAMIC_DEBUG */ /* * struct device based logging
Duplicate drm_debug_enabled() code into both "basic" and "dyndbg" ifdef branches. Then add a pr_debug("todo: ...") into the "dyndbg" branch. Then convert the "dyndbg" branch's code to a macro, so that its pr_debug() get its callsite info from the invoking function, instead of from drm_debug_enabled() itself. This gives us unique callsite info for the 8 remaining users of drm_debug_enabled(), and lets us enable them individually to see how much logging traffic they generate. The oft-visited callsites can then be reviewed for runtime cost and possible optimizations. Heres what we get: bash-5.1# modprobe drm dyndbg: 384 debug prints in module drm bash-5.1# grep todo: /proc/dynamic_debug/control drivers/gpu/drm/drm_edid.c:1843 [drm]connector_bad_edid =_ "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_print.c:309 [drm]___drm_dbg =p "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_print.c:286 [drm]__drm_dev_dbg =p "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_vblank.c:1491 [drm]drm_vblank_restore =_ "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_vblank.c:787 [drm]drm_crtc_vblank_helper_get_vblank_timestamp_internal =_ "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_vblank.c:410 [drm]drm_crtc_accurate_vblank_count =_ "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_atomic_uapi.c:1457 [drm]drm_mode_atomic_ioctl =_ "todo: maybe avoid via dyndbg\012" drivers/gpu/drm/drm_edid_load.c:178 [drm]edid_load =_ "todo: maybe avoid via dyndbg\012" At quick glance, edid won't qualify, drm_print might, drm_vblank is strongest chance, maybe atomic-ioctl too. Signed-off-by: Jim Cromie <jim.cromie@gmail.com> --- include/drm/drm_print.h | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-)