[PATCH v7 0/9] dyndbg: drm.debug adaptation

Jim Cromie posted 9 patches 3 years, 6 months ago
drivers/gpu/drm/Kconfig                 | 12 ++++
drivers/gpu/drm/Makefile                |  2 +
drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c | 14 +++++
drivers/gpu/drm/display/drm_dp_helper.c | 13 +++++
drivers/gpu/drm/drm_crtc_helper.c       | 13 +++++
drivers/gpu/drm/drm_print.c             | 48 +++++++++++----
drivers/gpu/drm/i915/i915_params.c      | 12 ++++
drivers/gpu/drm/nouveau/nouveau_drm.c   | 13 +++++
include/drm/drm_print.h                 | 78 +++++++++++++++++++------
9 files changed, 174 insertions(+), 31 deletions(-)
[PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Jim Cromie 3 years, 6 months ago
hi Greg, Dan, Jason, DRM-folk,

heres follow-up to V6:
  rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
  rework drm_debug_enabled{_raw,_instrumented,} per Dan.

It excludes:
  nouveau parts (immature)
  tracefs parts (I missed --to=Steve on v6)
  split _ddebug_site and de-duplicate experiment (way unready)

IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.

If these are good to apply, I'll rebase and repost the rest separately.

These are also available at:
https://github.com/jimc/linux/releases/tag/dyndbg%2Fdd-drm-class-911

RFC:

DECLARE_DYNDBG_CLASSMAP's interface can be improved: class-names are
currently strings, like "DRM_UT_CORE", which must have corresponding
ENUM symbols defined.  It would be better to just pass DRM_UT_CORE,
etc, and stringify the va-args inside the macro while initializing
classnames member.  But how ?


Jim Cromie (9):
  drm_print: condense enum drm_debug_category
  drm: POC drm on dyndbg - use in core, 2 helpers, 3 drivers.
  drm_print: interpose drm_*dbg with forwarding macros
  drm_print: wrap drm_*_dbg in dyndbg descriptor factory macro
  drm-print.h: include dyndbg header
  drm-print: add drm_dbg_driver to improve namespace symmetry
  drm_print: optimize drm_debug_enabled for jump-label
  drm_print: prefer bare printk KERN_DEBUG on generic fn
  drm_print: add _ddebug descriptor to drm_*dbg prototypes

 drivers/gpu/drm/Kconfig                 | 12 ++++
 drivers/gpu/drm/Makefile                |  2 +
 drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c | 14 +++++
 drivers/gpu/drm/display/drm_dp_helper.c | 13 +++++
 drivers/gpu/drm/drm_crtc_helper.c       | 13 +++++
 drivers/gpu/drm/drm_print.c             | 48 +++++++++++----
 drivers/gpu/drm/i915/i915_params.c      | 12 ++++
 drivers/gpu/drm/nouveau/nouveau_drm.c   | 13 +++++
 include/drm/drm_print.h                 | 78 +++++++++++++++++++------
 9 files changed, 174 insertions(+), 31 deletions(-)

-- 
2.37.3
[PATCH 0/7] DYNAMIC_DEBUG fixups for rc
Posted by Jim Cromie 3 years, 4 months ago
hi Jason, Greg, DRM-folk,

drm.debug-on-dyndbg has a regression due to a chicken-&-egg problem;
drm.debug is applied to enable dyndbg callsites before the dependent
modules' callsites are available to be enabled.

My "fixes" are unready, so lets just mark it BROKEN for now.

Meanwhile, heres some other fixes, a comment tweak, a proof of
non-bug, an internal simplification, and a cleanup/improvement to the
main macro (API):

Split DECLARE_DYNDBG_CLASSMAP in 1/2; REFERENCE_DYNDBG_CLASSMAP now
refers to a classmap DECLARE'd just once.  I think this gives a path
away from the coordination-by-identical-classmaps "feature" that Jani
and others thought was "weird" (my term).


Jim Cromie (7):
  drm: mark drm.debug-on-dyndbg as BROKEN for now
  drm_print: fixup improve stale comment
  test-dyndbg: fixup CLASSMAP usage error
  test-dyndbg: show that DEBUG enables prdbgs at compiletime
  dyndbg: fix readback value on LEVEL_NAMES interfaces
  dyndbg: clone DECLARE_DYNDBG_CLASSMAP to REFERENCE_DYNDBG_CLASSMAP
  dyndbg: replace classmap list with a vector

 drivers/gpu/drm/Kconfig                 |  1 +
 drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c |  2 +-
 drivers/gpu/drm/display/drm_dp_helper.c |  2 +-
 drivers/gpu/drm/drm_crtc_helper.c       |  2 +-
 drivers/gpu/drm/i915/i915_params.c      |  2 +-
 drivers/gpu/drm/nouveau/nouveau_drm.c   |  2 +-
 include/drm/drm_print.h                 |  5 +-
 include/linux/dynamic_debug.h           | 10 ++++
 lib/dynamic_debug.c                     | 63 +++++++++++++------------
 lib/test_dynamic_debug.c                |  4 +-
 10 files changed, 57 insertions(+), 36 deletions(-)

-- 
2.38.1
Re: [PATCH 0/7] DYNAMIC_DEBUG fixups for rc
Posted by Greg KH 3 years, 4 months ago
On Fri, Nov 11, 2022 at 03:17:08PM -0700, Jim Cromie wrote:
> hi Jason, Greg, DRM-folk,
> 
> drm.debug-on-dyndbg has a regression due to a chicken-&-egg problem;
> drm.debug is applied to enable dyndbg callsites before the dependent
> modules' callsites are available to be enabled.
> 
> My "fixes" are unready, so lets just mark it BROKEN for now.
> 
> Meanwhile, heres some other fixes, a comment tweak, a proof of
> non-bug, an internal simplification, and a cleanup/improvement to the
> main macro (API):
> 
> Split DECLARE_DYNDBG_CLASSMAP in 1/2; REFERENCE_DYNDBG_CLASSMAP now
> refers to a classmap DECLARE'd just once.  I think this gives a path
> away from the coordination-by-identical-classmaps "feature" that Jani
> and others thought was "weird" (my term).
> 

Acked-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
[PATCH 1/7] drm: mark drm.debug-on-dyndbg as BROKEN for now
Posted by Jim Cromie 3 years, 4 months ago
drm.debug-on-dyndbg has a regression, due to a chicken-egg
initialization problem:

1- modprobe i915
   i915 needs drm.ko, which is loaded 1st

2- "modprobe drm drm.debug=0x1ff" (virtual/implied)
   drm.debug is set post-initialization, from boot-args etc

3- `modprobe i915` finishes

W/O drm.debug-on-dyndbg that just works, because all drm_dbg*
callsites use drm_debug_enabled() to check __drm_debug & DEM_UT_<CAT>
before printing.

But the whole point of drm.debug-on-dyndbg is to avoid that runtime
test, by enabling (at post-modinit) a static-key at each callsite in
the just-loaded module.

And since drm.ko is loaded before all dependent modules, none are
"just-loaded", and no drm.debug callsites are present yet, except
those in drm.ko itself.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 drivers/gpu/drm/Kconfig | 1 +
 1 file changed, 1 insertion(+)

diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
index 34f5a092c99e..0d1e59e6bb7e 100644
--- a/drivers/gpu/drm/Kconfig
+++ b/drivers/gpu/drm/Kconfig
@@ -54,6 +54,7 @@ config DRM_DEBUG_MM
 config DRM_USE_DYNAMIC_DEBUG
 	bool "use dynamic debug to implement drm.debug"
 	default y
+	depends on BROKEN	# chicken-egg initial enable problem
 	depends on DRM
 	depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
 	depends on JUMP_LABEL
-- 
2.38.1
Re: [PATCH 1/7] drm: mark drm.debug-on-dyndbg as BROKEN for now
Posted by Greg KH 3 years, 4 months ago
On Fri, Nov 11, 2022 at 03:17:09PM -0700, Jim Cromie wrote:
> drm.debug-on-dyndbg has a regression, due to a chicken-egg
> initialization problem:
> 
> 1- modprobe i915
>    i915 needs drm.ko, which is loaded 1st
> 
> 2- "modprobe drm drm.debug=0x1ff" (virtual/implied)
>    drm.debug is set post-initialization, from boot-args etc
> 
> 3- `modprobe i915` finishes
> 
> W/O drm.debug-on-dyndbg that just works, because all drm_dbg*
> callsites use drm_debug_enabled() to check __drm_debug & DEM_UT_<CAT>
> before printing.
> 
> But the whole point of drm.debug-on-dyndbg is to avoid that runtime
> test, by enabling (at post-modinit) a static-key at each callsite in
> the just-loaded module.
> 
> And since drm.ko is loaded before all dependent modules, none are
> "just-loaded", and no drm.debug callsites are present yet, except
> those in drm.ko itself.
> 
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  drivers/gpu/drm/Kconfig | 1 +
>  1 file changed, 1 insertion(+)
> 
> diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> index 34f5a092c99e..0d1e59e6bb7e 100644
> --- a/drivers/gpu/drm/Kconfig
> +++ b/drivers/gpu/drm/Kconfig
> @@ -54,6 +54,7 @@ config DRM_DEBUG_MM
>  config DRM_USE_DYNAMIC_DEBUG
>  	bool "use dynamic debug to implement drm.debug"
>  	default y
> +	depends on BROKEN	# chicken-egg initial enable problem
>  	depends on DRM
>  	depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
>  	depends on JUMP_LABEL
> -- 
> 2.38.1

This should go through the drm tree now.  The rest probably should also
go that way and not through my tree as well.

thanks,

greg k-h
Re: [Intel-gfx] [PATCH 1/7] drm: mark drm.debug-on-dyndbg as BROKEN for now
Posted by Ville Syrjälä 3 years, 4 months ago
On Fri, Nov 11, 2022 at 03:17:09PM -0700, Jim Cromie wrote:
> drm.debug-on-dyndbg has a regression, due to a chicken-egg
> initialization problem:
> 
> 1- modprobe i915
>    i915 needs drm.ko, which is loaded 1st
> 
> 2- "modprobe drm drm.debug=0x1ff" (virtual/implied)
>    drm.debug is set post-initialization, from boot-args etc
> 
> 3- `modprobe i915` finishes
> 
> W/O drm.debug-on-dyndbg that just works, because all drm_dbg*
> callsites use drm_debug_enabled() to check __drm_debug & DEM_UT_<CAT>
> before printing.
> 
> But the whole point of drm.debug-on-dyndbg is to avoid that runtime
> test, by enabling (at post-modinit) a static-key at each callsite in
> the just-loaded module.
> 
> And since drm.ko is loaded before all dependent modules, none are
> "just-loaded", and no drm.debug callsites are present yet, except
> those in drm.ko itself.
> 
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  drivers/gpu/drm/Kconfig | 1 +
>  1 file changed, 1 insertion(+)
> 
> diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig
> index 34f5a092c99e..0d1e59e6bb7e 100644
> --- a/drivers/gpu/drm/Kconfig
> +++ b/drivers/gpu/drm/Kconfig
> @@ -54,6 +54,7 @@ config DRM_DEBUG_MM
>  config DRM_USE_DYNAMIC_DEBUG
>  	bool "use dynamic debug to implement drm.debug"
>  	default y

Could you switch to 'default n' as well? i915 CI actually enables
BROKEN so that we can test some more experimental stuff which is
hidden behind BROKEN for normal users.

> +	depends on BROKEN	# chicken-egg initial enable problem
>  	depends on DRM
>  	depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
>  	depends on JUMP_LABEL
> -- 
> 2.38.1

-- 
Ville Syrjälä
Intel
[PATCH 2/7] drm_print: fixup improve stale comment
Posted by Jim Cromie 3 years, 4 months ago
Cited commit uses stale macro name, fix this.  And improve the explanation.

When DRM_USE_DYNAMIC_DEBUG=y, DECLARE_DYNDBG_CLASSMAP() does the
mapping of DRM_UT_* onto BITs in drm.debug.  While this is still using
the drm_debug_category enum to do the mapping, its doing so somewhat
indirectly, with the ordered set of DRM_UT_* enum-vals.  This requires
that the macro args: DRM_UT_* list must be kept in sync.

fixes: f158936b60a7 (drm: POC drm on dyndbg - use in core, 2 helpers, 3 drivers.)
Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
. emphasize ABI non-change despite enum val change - Jani
---
 include/drm/drm_print.h | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h
index a44fb7ef257f..06deb58d5af4 100644
--- a/include/drm/drm_print.h
+++ b/include/drm/drm_print.h
@@ -276,7 +276,10 @@ static inline struct drm_printer drm_err_printer(const char *prefix)
  *
  */
 enum drm_debug_category {
-	/* These names must match those in DYNAMIC_DEBUG_CLASSBITS */
+	/*
+	 * Keep DECLARE_DYNDBG_CLASSMAP args in sync with changes
+	 * here, the values define BIT()s in drm.debug, so are ABI.
+	 */
 	/**
 	 * @DRM_UT_CORE: Used in the generic drm code: drm_ioctl.c, drm_mm.c,
 	 * drm_memory.c, ...
-- 
2.38.1
[PATCH 3/7] test-dyndbg: fixup CLASSMAP usage error
Posted by Jim Cromie 3 years, 4 months ago
more careful reading of test output reveals:

lib/test_dynamic_debug.c:103 [test_dynamic_debug]do_cats =pmf "doing categories\n"
lib/test_dynamic_debug.c:105 [test_dynamic_debug]do_cats =p "LOW msg\n" class:MID
lib/test_dynamic_debug.c:106 [test_dynamic_debug]do_cats =p "MID msg\n" class:HI
lib/test_dynamic_debug.c:107 [test_dynamic_debug]do_cats =_ "HI msg\n" class unknown, _id:13

That last line is wrong, the HI class is declared.

But the enum's 1st val (explicitly initialized) was wrong; it must be
_base, not _base+1 (a DECLARE_DYNDBG_CLASSMAP param).  So the last
enumeration exceeded the range of mapped class-id's, which triggered
the "class unknown" report.  Basically, I coded in an error, and
forgot to verify it and remove it.

RFC:

This patch fixes a bad usage of DEFINE_DYNDBG_CLASSMAP(), showing that
it is too error-prone.  As noted in test-dynamic-debug.c comments:

 * Using the CLASSMAP api:
 * - classmaps must have corresponding enum
 * - enum symbols must match/correlate with class-name strings in the map.
 * - base must equal enum's 1st value
 * - multiple maps must set their base to share the 0-62 class_id space !!
 *   (build-bug-on tips welcome)

Those shortcomings could largely be fixed with a __stringify_list
(which doesn't exist) used in DEFINE_DYNAMIC_DEBUG_CLASSMAP(), on
__VA_ARGS__ a 2nd time.  Then, DRM would pass DRM_UT_* ; all the
categories, in order, and not their stringifications, which created
all the usage complications above.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/test_dynamic_debug.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/test_dynamic_debug.c b/lib/test_dynamic_debug.c
index 8dd250ad022b..a01f0193a419 100644
--- a/lib/test_dynamic_debug.c
+++ b/lib/test_dynamic_debug.c
@@ -75,7 +75,7 @@ DD_SYS_WRAP(disjoint_bits, p);
 DD_SYS_WRAP(disjoint_bits, T);
 
 /* symbolic input, independent bits */
-enum cat_disjoint_names { LOW = 11, MID, HI };
+enum cat_disjoint_names { LOW = 10, MID, HI };
 DECLARE_DYNDBG_CLASSMAP(map_disjoint_names, DD_CLASS_TYPE_DISJOINT_NAMES, 10,
 			"LOW", "MID", "HI");
 DD_SYS_WRAP(disjoint_names, p);
-- 
2.38.1
[PATCH 4/7] test-dyndbg: show that DEBUG enables prdbgs at compiletime
Posted by Jim Cromie 3 years, 4 months ago
Dyndbg is required to enable prdbgs at compile-time if DEBUG is
defined.  Show this works; add the defn to test_dynamic_debug.c,
and manually inspect/verify its effect at module load:

[   15.292810] dyndbg: module:test_dynamic_debug attached 4 classes
[   15.293189] dyndbg:  32 debug prints in module test_dynamic_debug
[   15.293715] test_dd: init start
[   15.293716] test_dd: doing categories
[   15.293716] test_dd: LOW msg
...
[   15.293733] test_dd: L6 msg
[   15.293733] test_dd: L7 msg
[   15.293733] test_dd: init done

NOTES:

As is observable above, define DEBUG enables all prdbgs, including
those in mod_init-fn, and more notably, the "class"d ones (callsites
with non-default class_ids).

This differs from the >control interface, which in order to properly
protect a client's class'd prdbgs, requires a "class FOO" in queries
to change them.  Note that the DEBUG is in the module source file.

This yields an occaisional surprise; the following disables all the
compile-time enabled plain prdbgs, but leaves the class'd ones
enabled.

 :#> modprobe test_dynamic_debug dyndbg==_

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/test_dynamic_debug.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/lib/test_dynamic_debug.c b/lib/test_dynamic_debug.c
index a01f0193a419..9d48689dc0ab 100644
--- a/lib/test_dynamic_debug.c
+++ b/lib/test_dynamic_debug.c
@@ -8,6 +8,8 @@
 
 #define pr_fmt(fmt) "test_dd: " fmt
 
+#define DEBUG
+
 #include <linux/module.h>
 
 /* run tests by reading or writing sysfs node: do_prints */
-- 
2.38.1
[PATCH 5/7] dyndbg: fix readback value on LEVEL_NAMES interfaces
Posted by Jim Cromie 3 years, 4 months ago
Since sysfs knobs should generally read-back what was just written
(unless theres a good reason to do otherwise), this result (using
test_dynamic_debug.ko) is suboptimal:

  echo L3 > p_level_names
  cat p_level_names
  4

Fix this with a -1 offset in LEVEL_NAMES readback.

NOTE:

Calling this a BUG is debatable, and the above is slightly inaccurate
wrt "read-back"; whats written is a LEVEL_NAME (a string).  Whats read
back is an integer, giving the 'edge' of the 'low-pass-filter'

The actual test looks like:

RTT: L4 -> p_level_names : 4 :: DOING: levels 4-1
[   17.509594] dyndbg: "L4" > p_level_names:0x4
[   17.510115] dyndbg: apply: 0x1f to: 0xf
[   17.510506] dyndbg: query 0: "class L4 +p" mod:*
[   17.510992] dyndbg: split into words: "class" "L4" "+p"
[   17.511521] dyndbg: op='+'
[   17.511811] dyndbg: flags=0x1
[   17.512127] dyndbg: *flagsp=0x1 *maskp=0xffffffff
[   17.512604] dyndbg: parsed: func="" file="" module="" format="" lineno=0-0 class=L4
[   17.513414] dyndbg: applied: func="" file="" module="" format="" lineno=0-0 class=L4
[   17.514204] dyndbg: processed 1 queries, with 1 matches, 0 errs
[   17.514809] dyndbg: bit_4: 1 matches on class: L4 -> 0x1f
[   17.515355] dyndbg: p_level_names: changed bit-4: "L4" f->1f
[   17.515933] dyndbg: total matches: 1
crap [[ 5 != 4 ]]

This -1 adjustment just reports the edge consistently with its
input-mapping.

Fixes: b9400852c080 (dyndbg: add drm.debug style (drm/parameters/debug) bitmap support)

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 009f2ead09c1..48ca1387a409 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -794,6 +794,8 @@ int param_get_dyndbg_classes(char *buffer, const struct kernel_param *kp)
 		return scnprintf(buffer, PAGE_SIZE, "0x%lx\n", *dcp->bits);
 
 	case DD_CLASS_TYPE_LEVEL_NAMES:
+		return scnprintf(buffer, PAGE_SIZE, "%d\n", *dcp->lvl - 1);
+
 	case DD_CLASS_TYPE_LEVEL_NUM:
 		return scnprintf(buffer, PAGE_SIZE, "%d\n", *dcp->lvl);
 	default:
-- 
2.38.1
[PATCH 6/7] dyndbg: clone DECLARE_DYNDBG_CLASSMAP to REFERENCE_DYNDBG_CLASSMAP
Posted by Jim Cromie 3 years, 4 months ago
DECLARE_DYNDBG_CLASSMAPs job is to allow modules to declare the debug
classes/categories they want dyndbg to >control.  Its args name the
class-names, and the sysfs interface style (usually a class-bitmap).
A separate module_param_cb wires the sysfs node to the classmap.

In DRM, multiple modules declare identical DRM_UT_* classmaps, so that
they are modified across those modules in a coordinated way, by either
explicit class DRM_UT_* queries to >control, or by writes to drm.debug
(/sys/module/drm/parameters/debug).

This coordination-by-identical-declarations is weird, so this patch
splits the macro into DECLARE and REFERENCE (USE?) flavors.  This
distinction improves the api; DECLARE is used once to specify the
classmap, and multiple users REFERENCE the single declaration
explicitly.

Currently the latter just reuses the former, and still needs all the
same args, but that can be tuned later; the DECLARE can initialize the
(extern/global) struct classmap, and REFERENCE can, well reference
that struct.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
RFC: s/REFERENCE_/USE_/ ??
---
 drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c |  2 +-
 drivers/gpu/drm/display/drm_dp_helper.c |  2 +-
 drivers/gpu/drm/drm_crtc_helper.c       |  2 +-
 drivers/gpu/drm/i915/i915_params.c      |  2 +-
 drivers/gpu/drm/nouveau/nouveau_drm.c   |  2 +-
 include/linux/dynamic_debug.h           | 10 ++++++++++
 6 files changed, 15 insertions(+), 5 deletions(-)

diff --git a/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c b/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c
index 3c9fecdd6b2f..5c733d96fe4c 100644
--- a/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c
+++ b/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c
@@ -188,7 +188,7 @@ int amdgpu_vcnfw_log;
 
 static void amdgpu_drv_delayed_reset_work_handler(struct work_struct *work);
 
-DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
+REFERENCE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
 			"DRM_UT_CORE",
 			"DRM_UT_DRIVER",
 			"DRM_UT_KMS",
diff --git a/drivers/gpu/drm/display/drm_dp_helper.c b/drivers/gpu/drm/display/drm_dp_helper.c
index 16565a0a5da6..1f20c1e721a4 100644
--- a/drivers/gpu/drm/display/drm_dp_helper.c
+++ b/drivers/gpu/drm/display/drm_dp_helper.c
@@ -41,7 +41,7 @@
 
 #include "drm_dp_helper_internal.h"
 
-DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
+REFERENCE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
 			"DRM_UT_CORE",
 			"DRM_UT_DRIVER",
 			"DRM_UT_KMS",
diff --git a/drivers/gpu/drm/drm_crtc_helper.c b/drivers/gpu/drm/drm_crtc_helper.c
index 7d86020b5244..4675c95c90b4 100644
--- a/drivers/gpu/drm/drm_crtc_helper.c
+++ b/drivers/gpu/drm/drm_crtc_helper.c
@@ -51,7 +51,7 @@
 
 #include "drm_crtc_helper_internal.h"
 
-DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
+REFERENCE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
 			"DRM_UT_CORE",
 			"DRM_UT_DRIVER",
 			"DRM_UT_KMS",
diff --git a/drivers/gpu/drm/i915/i915_params.c b/drivers/gpu/drm/i915/i915_params.c
index d1e4d528cb17..14ebbbf53821 100644
--- a/drivers/gpu/drm/i915/i915_params.c
+++ b/drivers/gpu/drm/i915/i915_params.c
@@ -29,7 +29,7 @@
 #include "i915_params.h"
 #include "i915_drv.h"
 
-DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
+REFERENCE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
 			"DRM_UT_CORE",
 			"DRM_UT_DRIVER",
 			"DRM_UT_KMS",
diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c b/drivers/gpu/drm/nouveau/nouveau_drm.c
index fd99ec0f4257..b943bf2a36fe 100644
--- a/drivers/gpu/drm/nouveau/nouveau_drm.c
+++ b/drivers/gpu/drm/nouveau/nouveau_drm.c
@@ -71,7 +71,7 @@
 #include "nouveau_svm.h"
 #include "nouveau_dmem.h"
 
-DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
+REFERENCE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT_BITS, 0,
 			"DRM_UT_CORE",
 			"DRM_UT_DRIVER",
 			"DRM_UT_KMS",
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 41682278d2e8..76430bac7f79 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -111,6 +111,16 @@ struct ddebug_class_map {
 #define NUM_TYPE_ARGS(eltype, ...)				\
         (sizeof((eltype[]){__VA_ARGS__}) / sizeof(eltype))
 
+/*
+ * refer to the classmap instantiated once, by the macro above.  This
+ * distinguishes the multiple users of drm.debug from the single
+ * definition, allowing them to specialize.  ATM its a pass-thru, but
+ * it should help regularize the admittedly wierd sharing by identical
+ * definitions.
+ */
+#define REFERENCE_DYNDBG_CLASSMAP(_var, _maptype, _base, ...)		\
+	DECLARE_DYNDBG_CLASSMAP(_var, _maptype, _base, __VA_ARGS__)
+
 /* encapsulate linker provided built-in (or module) dyndbg data */
 struct _ddebug_info {
 	struct _ddebug *descs;
-- 
2.38.1
[PATCH 7/7] dyndbg: replace classmap list with a vector
Posted by Jim Cromie 3 years, 4 months ago
Classmaps are stored/linked in a section/array, but are each added to
the module's ddebug_table.maps list-head.

This is unnecessary; even when ddebug_attach_classmap() is handling
the builtin section (with classmaps for multiple builtin modules), its
contents are ordered, so a module's possibly multiple classmaps will
be consecutive in the section, and could be treated as a vector/block,
since both start-addy and subrange length are in the ddebug_info arg.

So this changes:

struct ddebug_table gets: classes for the start-addy, num_classes for
the length (placed to improve struct packing).

The loading: in ddebug_attach_module_classes(), replace the
for-the-modname list-add loop, with a forloop that finds the module's
subrange (start,length) of matching classmaps within the possibly
builtin classmaps vector, and saves those to the ddebug_table.

The reading/using: change list-foreach loops in ddebug_class_name() &
ddebug_find_valid_class() to walk the array from start to length.

Also move #define __outvar up, above an added use in a fn-prototype.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c | 61 ++++++++++++++++++++++++---------------------
 1 file changed, 32 insertions(+), 29 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 48ca1387a409..fd5296dbb40f 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -45,10 +45,11 @@ extern struct ddebug_class_map __start___dyndbg_classes[];
 extern struct ddebug_class_map __stop___dyndbg_classes[];
 
 struct ddebug_table {
-	struct list_head link, maps;
+	struct list_head link;
 	const char *mod_name;
-	unsigned int num_ddebugs;
 	struct _ddebug *ddebugs;
+	struct ddebug_class_map *classes;
+	unsigned int num_ddebugs, num_classes;
 };
 
 struct ddebug_query {
@@ -146,13 +147,15 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
 		  query->first_lineno, query->last_lineno, query->class_string);
 }
 
+#define __outvar /* filled by callee */
 static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table const *dt,
-							  const char *class_string, int *class_id)
+							const char *class_string,
+							__outvar int *class_id)
 {
 	struct ddebug_class_map *map;
-	int idx;
+	int i, idx;
 
-	list_for_each_entry(map, &dt->maps, link) {
+	for (map = dt->classes, i = 0; i < dt->num_classes; i++, map++) {
 		idx = match_string(map->class_names, map->length, class_string);
 		if (idx >= 0) {
 			*class_id = idx + map->base;
@@ -163,7 +166,6 @@ static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table cons
 	return NULL;
 }
 
-#define __outvar /* filled by callee */
 /*
  * Search the tables for _ddebug's which match the given `query' and
  * apply the `flags' and `mask' to them.  Returns number of matching
@@ -1109,9 +1111,10 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)
 
 static const char *ddebug_class_name(struct ddebug_iter *iter, struct _ddebug *dp)
 {
-	struct ddebug_class_map *map;
+	struct ddebug_class_map *map = iter->table->classes;
+	int i, nc = iter->table->num_classes;
 
-	list_for_each_entry(map, &iter->table->maps, link)
+	for (i = 0; i < nc; i++, map++)
 		if (class_in_range(dp->class_id, map))
 			return map->class_names[dp->class_id - map->base];
 
@@ -1195,30 +1198,31 @@ static const struct proc_ops proc_fops = {
 	.proc_write = ddebug_proc_write
 };
 
-static void ddebug_attach_module_classes(struct ddebug_table *dt,
-					 struct ddebug_class_map *classes,
-					 int num_classes)
+static void ddebug_attach_module_classes(struct ddebug_table *dt, struct _ddebug_info *di)
 {
 	struct ddebug_class_map *cm;
-	int i, j, ct = 0;
+	int i, nc = 0;
 
-	for (cm = classes, i = 0; i < num_classes; i++, cm++) {
+	/*
+	 * Find this module's classmaps in a subrange/wholerange of
+	 * the builtin/modular classmap vector/section.  Save the start
+	 * and length of the subrange at its edges.
+	 */
+	for (cm = di->classes, i = 0; i < di->num_classes; i++, cm++) {
 
 		if (!strcmp(cm->mod_name, dt->mod_name)) {
-
-			v2pr_info("class[%d]: module:%s base:%d len:%d ty:%d\n", i,
-				  cm->mod_name, cm->base, cm->length, cm->map_type);
-
-			for (j = 0; j < cm->length; j++)
-				v3pr_info(" %d: %d %s\n", j + cm->base, j,
-					  cm->class_names[j]);
-
-			list_add(&cm->link, &dt->maps);
-			ct++;
+			if (!nc) {
+				v2pr_info("start subrange, class[%d]: module:%s base:%d len:%d ty:%d\n",
+					  i, cm->mod_name, cm->base, cm->length, cm->map_type);
+				dt->classes = cm;
+			}
+			nc++;
 		}
 	}
-	if (ct)
-		vpr_info("module:%s attached %d classes\n", dt->mod_name, ct);
+	if (nc) {
+		dt->num_classes = nc;
+		vpr_info("module:%s attached %d classes\n", dt->mod_name, nc);
+	}
 }
 
 /*
@@ -1252,10 +1256,9 @@ static int __ddebug_add_module(struct _ddebug_info *di, unsigned int base,
 	dt->num_ddebugs = di->num_descs;
 
 	INIT_LIST_HEAD(&dt->link);
-	INIT_LIST_HEAD(&dt->maps);
 
 	if (di->classes && di->num_classes)
-		ddebug_attach_module_classes(dt, di->classes, di->num_classes);
+		ddebug_attach_module_classes(dt, di);
 
 	mutex_lock(&ddebug_lock);
 	list_add_tail(&dt->link, &ddebug_tables);
@@ -1344,8 +1347,8 @@ static void ddebug_remove_all_tables(void)
 	mutex_lock(&ddebug_lock);
 	while (!list_empty(&ddebug_tables)) {
 		struct ddebug_table *dt = list_entry(ddebug_tables.next,
-						      struct ddebug_table,
-						      link);
+						     struct ddebug_table,
+						     link);
 		ddebug_table_free(dt);
 	}
 	mutex_unlock(&ddebug_lock);
-- 
2.38.1
Re: [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Greg KH 3 years, 6 months ago
On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> hi Greg, Dan, Jason, DRM-folk,
> 
> heres follow-up to V6:
>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> 
> It excludes:
>   nouveau parts (immature)
>   tracefs parts (I missed --to=Steve on v6)
>   split _ddebug_site and de-duplicate experiment (way unready)
> 
> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> 
> If these are good to apply, I'll rebase and repost the rest separately.

All now queued up, thanks.

greg k-h
Re: [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Ville Syrjälä 3 years, 5 months ago
On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > hi Greg, Dan, Jason, DRM-folk,
> > 
> > heres follow-up to V6:
> >   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> >   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > 
> > It excludes:
> >   nouveau parts (immature)
> >   tracefs parts (I missed --to=Steve on v6)
> >   split _ddebug_site and de-duplicate experiment (way unready)
> > 
> > IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > 
> > If these are good to apply, I'll rebase and repost the rest separately.
> 
> All now queued up, thanks.

This stuff broke i915 debugs. When I first load i915 no debug prints are
produced. If I then go fiddle around in /sys/module/drm/parameters/debug
the debug prints start to suddenly work.

-- 
Ville Syrjälä
Intel
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Jani Nikula 3 years, 5 months ago
On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
>> > hi Greg, Dan, Jason, DRM-folk,
>> > 
>> > heres follow-up to V6:
>> >   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
>> >   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
>> > 
>> > It excludes:
>> >   nouveau parts (immature)
>> >   tracefs parts (I missed --to=Steve on v6)
>> >   split _ddebug_site and de-duplicate experiment (way unready)
>> > 
>> > IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
>> > 
>> > If these are good to apply, I'll rebase and repost the rest separately.
>> 
>> All now queued up, thanks.
>
> This stuff broke i915 debugs. When I first load i915 no debug prints are
> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> the debug prints start to suddenly work.

Wait what? I always assumed the default behaviour would stay the same,
which is usually how we roll. It's a regression in my books. We've got a
CI farm that's not very helpful in terms of dmesg logging right now
because of this.

BR,
Jani.


-- 
Jani Nikula, Intel Open Source Graphics Center
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Jason Baron 3 years, 5 months ago

On 10/21/22 05:18, Jani Nikula wrote:
> On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
>> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
>>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
>>>> hi Greg, Dan, Jason, DRM-folk,
>>>>
>>>> heres follow-up to V6:
>>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
>>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
>>>>
>>>> It excludes:
>>>>   nouveau parts (immature)
>>>>   tracefs parts (I missed --to=Steve on v6)
>>>>   split _ddebug_site and de-duplicate experiment (way unready)
>>>>
>>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
>>>>
>>>> If these are good to apply, I'll rebase and repost the rest separately.
>>>
>>> All now queued up, thanks.
>>
>> This stuff broke i915 debugs. When I first load i915 no debug prints are
>> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
>> the debug prints start to suddenly work.
> 
> Wait what? I always assumed the default behaviour would stay the same,
> which is usually how we roll. It's a regression in my books. We've got a
> CI farm that's not very helpful in terms of dmesg logging right now
> because of this.
> 
> BR,
> Jani.
> 
> 

That doesn't sound good - so you are saying that prior to this change some
of the drm debugs were default enabled. But now you have to manually enable
them?

Thanks,

-Jason
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by jim.cromie@gmail.com 3 years, 5 months ago
On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
>
>
>
> On 10/21/22 05:18, Jani Nikula wrote:
> > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> >>>> hi Greg, Dan, Jason, DRM-folk,
> >>>>
> >>>> heres follow-up to V6:
> >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> >>>>
> >>>> It excludes:
> >>>>   nouveau parts (immature)
> >>>>   tracefs parts (I missed --to=Steve on v6)
> >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> >>>>
> >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> >>>>
> >>>> If these are good to apply, I'll rebase and repost the rest separately.
> >>>
> >>> All now queued up, thanks.
> >>
> >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> >> the debug prints start to suddenly work.
> >
> > Wait what? I always assumed the default behaviour would stay the same,
> > which is usually how we roll. It's a regression in my books. We've got a
> > CI farm that's not very helpful in terms of dmesg logging right now
> > because of this.
> >
> > BR,
> > Jani.
> >
> >
>
> That doesn't sound good - so you are saying that prior to this change some
> of the drm debugs were default enabled. But now you have to manually enable
> them?
>
> Thanks,
>
> -Jason


Im just seeing this now.
Any new details ?

I didnt knowingly change something, but since its apparently happening,
heres a 1st WAG at a possible cause

commit ccc2b496324c13e917ef05f563626f4e7826bef1
Author: Jim Cromie <jim.cromie@gmail.com>
Date:   Sun Sep 11 23:28:51 2022 -0600

    drm_print: prefer bare printk KERN_DEBUG on generic fn

    drm_print.c calls pr_debug() just once, from __drm_printfn_debug(),
    which is a generic/service fn.  The callsite is compile-time enabled
    by DEBUG in both DYNAMIC_DEBUG=y/n builds.

    For dyndbg builds, reverting this callsite back to bare printk is
    correcting a few anti-features:

    1- callsite is generic, serves multiple drm users.
       it is soft-wired on currently by #define DEBUG
       could accidentally: #> echo -p > /proc/dynamic_debug/control

    2- optional "decorations" by dyndbg are unhelpful/misleading here,
       they describe only the generic site, not end users

    IOW, 1,2 are unhelpful at best, and possibly confusing.

    reverting yields a nominal data and text shrink:

       text    data     bss     dec     hex filename
     462583   36604   54592 553779   87333 /kernel/drivers/gpu/drm/drm.ko
     462515   36532   54592 553639   872a7 -dirty/kernel/drivers/gpu/drm/drm.ko

    Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
    Link: https://lore.kernel.org/r/20220912052852.1123868-9-jim.cromie@gmail.com
    Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Ville Syrjälä 3 years, 5 months ago
On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> >
> >
> >
> > On 10/21/22 05:18, Jani Nikula wrote:
> > > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > >>>> hi Greg, Dan, Jason, DRM-folk,
> > >>>>
> > >>>> heres follow-up to V6:
> > >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > >>>>
> > >>>> It excludes:
> > >>>>   nouveau parts (immature)
> > >>>>   tracefs parts (I missed --to=Steve on v6)
> > >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> > >>>>
> > >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > >>>>
> > >>>> If these are good to apply, I'll rebase and repost the rest separately.
> > >>>
> > >>> All now queued up, thanks.
> > >>
> > >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > >> the debug prints start to suddenly work.
> > >
> > > Wait what? I always assumed the default behaviour would stay the same,
> > > which is usually how we roll. It's a regression in my books. We've got a
> > > CI farm that's not very helpful in terms of dmesg logging right now
> > > because of this.
> > >
> > > BR,
> > > Jani.
> > >
> > >
> >
> > That doesn't sound good - so you are saying that prior to this change some
> > of the drm debugs were default enabled. But now you have to manually enable
> > them?
> >
> > Thanks,
> >
> > -Jason
> 
> 
> Im just seeing this now.
> Any new details ?

No. We just disabled it as BROKEN for now. I was just today thinking
about sending that patch out if no solutin is forthcoming soon since
we need this working before 6.1 is released.

Pretty sure you should see the problem immediately with any driver 
(at least if it's built as a module, didn't try builtin). Or at least
can't think what would make i915 any more special.

> 
> I didnt knowingly change something, but since its apparently happening,
> heres a 1st WAG at a possible cause
> 
> commit ccc2b496324c13e917ef05f563626f4e7826bef1
> Author: Jim Cromie <jim.cromie@gmail.com>
> Date:   Sun Sep 11 23:28:51 2022 -0600
> 
>     drm_print: prefer bare printk KERN_DEBUG on generic fn
> 
>     drm_print.c calls pr_debug() just once, from __drm_printfn_debug(),
>     which is a generic/service fn.  The callsite is compile-time enabled
>     by DEBUG in both DYNAMIC_DEBUG=y/n builds.
> 
>     For dyndbg builds, reverting this callsite back to bare printk is
>     correcting a few anti-features:
> 
>     1- callsite is generic, serves multiple drm users.
>        it is soft-wired on currently by #define DEBUG
>        could accidentally: #> echo -p > /proc/dynamic_debug/control
> 
>     2- optional "decorations" by dyndbg are unhelpful/misleading here,
>        they describe only the generic site, not end users
> 
>     IOW, 1,2 are unhelpful at best, and possibly confusing.
> 
>     reverting yields a nominal data and text shrink:
> 
>        text    data     bss     dec     hex filename
>      462583   36604   54592 553779   87333 /kernel/drivers/gpu/drm/drm.ko
>      462515   36532   54592 553639   872a7 -dirty/kernel/drivers/gpu/drm/drm.ko
> 
>     Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
>     Link: https://lore.kernel.org/r/20220912052852.1123868-9-jim.cromie@gmail.com
>     Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

-- 
Ville Syrjälä
Intel
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by jim.cromie@gmail.com 3 years, 5 months ago
On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
<ville.syrjala@linux.intel.com> wrote:
>
> On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> > On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> > >
> > >
> > >
> > > On 10/21/22 05:18, Jani Nikula wrote:
> > > > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > > >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > > >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > > >>>> hi Greg, Dan, Jason, DRM-folk,
> > > >>>>
> > > >>>> heres follow-up to V6:
> > > >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > > >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > > >>>>
> > > >>>> It excludes:
> > > >>>>   nouveau parts (immature)
> > > >>>>   tracefs parts (I missed --to=Steve on v6)
> > > >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> > > >>>>
> > > >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > > >>>>
> > > >>>> If these are good to apply, I'll rebase and repost the rest separately.
> > > >>>
> > > >>> All now queued up, thanks.
> > > >>
> > > >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > > >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > > >> the debug prints start to suddenly work.
> > > >
> > > > Wait what? I always assumed the default behaviour would stay the same,
> > > > which is usually how we roll. It's a regression in my books. We've got a
> > > > CI farm that's not very helpful in terms of dmesg logging right now
> > > > because of this.
> > > >
> > > > BR,
> > > > Jani.
> > > >
> > > >
> > >
> > > That doesn't sound good - so you are saying that prior to this change some
> > > of the drm debugs were default enabled. But now you have to manually enable
> > > them?
> > >
> > > Thanks,
> > >
> > > -Jason
> >
> >
> > Im just seeing this now.
> > Any new details ?
>
> No. We just disabled it as BROKEN for now. I was just today thinking
> about sending that patch out if no solutin is forthcoming soon since
> we need this working before 6.1 is released.
>
> Pretty sure you should see the problem immediately with any driver
> (at least if it's built as a module, didn't try builtin). Or at least
> can't think what would make i915 any more special.
>

So, I should note -
99% of my time & energy on this dyndbg + drm patchset
has been done using virtme,
so my world-view (and dev-hack-test env) has been smaller, simpler
maybe its been fatally simplistic.

ive just rebuilt v6.0  (before the trouble)
and run it thru my virtual home box,
I didnt see any unfamiliar drm-debug output
that I might have inadvertently altered somehow

I have some real HW I can put a reference kernel on,0
to look for the missing output, but its all gonna take some time,
esp to tighten up my dev-test-env

in the meantime, there is:

config DRM_USE_DYNAMIC_DEBUG
bool "use dynamic debug to implement drm.debug"
default y
depends on DRM
depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
depends on JUMP_LABEL
help
  Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
  Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
  bytes per callsite, the .data costs can be substantial, and
  are therefore configurable.

Does changing the default fix things for i915 dmesg ?
or is the problem deeper ?

theres also this Makefile addition, which I might have oversimplified

CFLAGS-$(CONFIG_DRM_USE_DYNAMIC_DEBUG) += -DDYNAMIC_DEBUG_MODULE
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Ville Syrjälä 3 years, 5 months ago
On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
> On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
> <ville.syrjala@linux.intel.com> wrote:
> >
> > On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> > > On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> > > >
> > > >
> > > >
> > > > On 10/21/22 05:18, Jani Nikula wrote:
> > > > > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > > > >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > > > >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > > > >>>> hi Greg, Dan, Jason, DRM-folk,
> > > > >>>>
> > > > >>>> heres follow-up to V6:
> > > > >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > > > >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > > > >>>>
> > > > >>>> It excludes:
> > > > >>>>   nouveau parts (immature)
> > > > >>>>   tracefs parts (I missed --to=Steve on v6)
> > > > >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> > > > >>>>
> > > > >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > > > >>>>
> > > > >>>> If these are good to apply, I'll rebase and repost the rest separately.
> > > > >>>
> > > > >>> All now queued up, thanks.
> > > > >>
> > > > >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > > > >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > > > >> the debug prints start to suddenly work.
> > > > >
> > > > > Wait what? I always assumed the default behaviour would stay the same,
> > > > > which is usually how we roll. It's a regression in my books. We've got a
> > > > > CI farm that's not very helpful in terms of dmesg logging right now
> > > > > because of this.
> > > > >
> > > > > BR,
> > > > > Jani.
> > > > >
> > > > >
> > > >
> > > > That doesn't sound good - so you are saying that prior to this change some
> > > > of the drm debugs were default enabled. But now you have to manually enable
> > > > them?
> > > >
> > > > Thanks,
> > > >
> > > > -Jason
> > >
> > >
> > > Im just seeing this now.
> > > Any new details ?
> >
> > No. We just disabled it as BROKEN for now. I was just today thinking
> > about sending that patch out if no solutin is forthcoming soon since
> > we need this working before 6.1 is released.
> >
> > Pretty sure you should see the problem immediately with any driver
> > (at least if it's built as a module, didn't try builtin). Or at least
> > can't think what would make i915 any more special.
> >
> 
> So, I should note -
> 99% of my time & energy on this dyndbg + drm patchset
> has been done using virtme,
> so my world-view (and dev-hack-test env) has been smaller, simpler
> maybe its been fatally simplistic.
> 
> ive just rebuilt v6.0  (before the trouble)
> and run it thru my virtual home box,
> I didnt see any unfamiliar drm-debug output
> that I might have inadvertently altered somehow
> 
> I have some real HW I can put a reference kernel on,0
> to look for the missing output, but its all gonna take some time,
> esp to tighten up my dev-test-env
> 
> in the meantime, there is:
> 
> config DRM_USE_DYNAMIC_DEBUG
> bool "use dynamic debug to implement drm.debug"
> default y
> depends on DRM
> depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> depends on JUMP_LABEL
> help
>   Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
>   Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
>   bytes per callsite, the .data costs can be substantial, and
>   are therefore configurable.
> 
> Does changing the default fix things for i915 dmesg ?

I think we want to mark it BROKEN in addition to make sure no one
enables it by accident. We already got one bug report where I had to
ask the reporter to rebuild their kernel since this had gotten
enabled and we didn't get any debugs from the driver probe.

> or is the problem deeper ?
> 
> theres also this Makefile addition, which I might have oversimplified
> 
> CFLAGS-$(CONFIG_DRM_USE_DYNAMIC_DEBUG) += -DDYNAMIC_DEBUG_MODULE

-- 
Ville Syrjälä
Intel
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by jim.cromie@gmail.com 3 years, 5 months ago
On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
<ville.syrjala@linux.intel.com> wrote:
>
> On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
> > On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
> > <ville.syrjala@linux.intel.com> wrote:
> > >
> > > On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> > > > On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> > > > >
> > > > >
> > > > >
> > > > > On 10/21/22 05:18, Jani Nikula wrote:
> > > > > > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > > > > >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > > > > >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > > > > >>>> hi Greg, Dan, Jason, DRM-folk,
> > > > > >>>>
> > > > > >>>> heres follow-up to V6:
> > > > > >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > > > > >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > > > > >>>>
> > > > > >>>> It excludes:
> > > > > >>>>   nouveau parts (immature)
> > > > > >>>>   tracefs parts (I missed --to=Steve on v6)
> > > > > >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> > > > > >>>>
> > > > > >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > > > > >>>>
> > > > > >>>> If these are good to apply, I'll rebase and repost the rest separately.
> > > > > >>>
> > > > > >>> All now queued up, thanks.
> > > > > >>
> > > > > >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > > > > >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > > > > >> the debug prints start to suddenly work.
> > > > > >
> > > > > > Wait what? I always assumed the default behaviour would stay the same,
> > > > > > which is usually how we roll. It's a regression in my books. We've got a
> > > > > > CI farm that's not very helpful in terms of dmesg logging right now
> > > > > > because of this.
> > > > > >
> > > > > > BR,
> > > > > > Jani.
> > > > > >
> > > > > >
> > > > >
> > > > > That doesn't sound good - so you are saying that prior to this change some
> > > > > of the drm debugs were default enabled. But now you have to manually enable
> > > > > them?
> > > > >
> > > > > Thanks,
> > > > >
> > > > > -Jason
> > > >
> > > >
> > > > Im just seeing this now.
> > > > Any new details ?
> > >
> > > No. We just disabled it as BROKEN for now. I was just today thinking
> > > about sending that patch out if no solutin is forthcoming soon since
> > > we need this working before 6.1 is released.
> > >
> > > Pretty sure you should see the problem immediately with any driver
> > > (at least if it's built as a module, didn't try builtin). Or at least
> > > can't think what would make i915 any more special.
> > >
> >
> > So, I should note -
> > 99% of my time & energy on this dyndbg + drm patchset
> > has been done using virtme,
> > so my world-view (and dev-hack-test env) has been smaller, simpler
> > maybe its been fatally simplistic.
> >
> > ive just rebuilt v6.0  (before the trouble)
> > and run it thru my virtual home box,
> > I didnt see any unfamiliar drm-debug output
> > that I might have inadvertently altered somehow
> >
> > I have some real HW I can put a reference kernel on,0
> > to look for the missing output, but its all gonna take some time,
> > esp to tighten up my dev-test-env
> >
> > in the meantime, there is:
> >
> > config DRM_USE_DYNAMIC_DEBUG
> > bool "use dynamic debug to implement drm.debug"
> > default y
> > depends on DRM
> > depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > depends on JUMP_LABEL
> > help
> >   Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
> >   Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
> >   bytes per callsite, the .data costs can be substantial, and
> >   are therefore configurable.
> >
> > Does changing the default fix things for i915 dmesg ?
>
> I think we want to mark it BROKEN in addition to make sure no one

Ok, I get the distinction now.
youre spelling that
  depends on BROKEN

I have a notional explanation, and a conflating commit:

can you eliminate
git log -p ccc2b496324c13e917ef05f563626f4e7826bef1

as the cause ?



commit ccc2b496324c13e917ef05f563626f4e7826bef1
Author: Jim Cromie <jim.cromie@gmail.com>
Date:   Sun Sep 11 23:28:51 2022 -0600

    drm_print: prefer bare printk KERN_DEBUG on generic fn

    drm_print.c calls pr_debug() just once, from __drm_printfn_debug(),
    which is a generic/service fn.  The callsite is compile-time enabled
    by DEBUG in both DYNAMIC_DEBUG=y/n builds.

    For dyndbg builds, reverting this callsite back to bare printk is
    correcting a few anti-features:

    1- callsite is generic, serves multiple drm users.
       it is soft-wired on currently by #define DEBUG
       could accidentally: #> echo -p > /proc/dynamic_debug/control

    2- optional "decorations" by dyndbg are unhelpful/misleading here,
       they describe only the generic site, not end users

    IOW, 1,2 are unhelpful at best, and possibly confusing.


This shouldnt have turned off any debug of any kind
(drm.debug nor plain pr_debug)

but that former callsite no longer does the modname:func:line prefixing
that could have been in effect and relied upon (tested for) by your CI


I do need to clarify, I dont know exactly what debug/logging output
is missing such that CI is failing

related,
Ive added DEBUG to test-dynmamic-debug,
to prove the compile-time enablement of pr_debugs.
patch forthcoming, with a couple other fixes.





> enables it by accident. We already got one bug report where I had to
> ask the reporter to rebuild their kernel since this had gotten
> enabled and we didn't get any debugs from the driver probe.
>
> > or is the problem deeper ?
> >
> > theres also this Makefile addition, which I might have oversimplified
> >
> > CFLAGS-$(CONFIG_DRM_USE_DYNAMIC_DEBUG) += -DDYNAMIC_DEBUG_MODULE
>
> --
> Ville Syrjälä
> Intel
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Ville Syrjälä 3 years, 5 months ago
On Sun, Oct 30, 2022 at 08:42:52AM -0600, jim.cromie@gmail.com wrote:
> On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
> <ville.syrjala@linux.intel.com> wrote:
> >
> > On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
> > > On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
> > > <ville.syrjala@linux.intel.com> wrote:
> > > >
> > > > On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> > > > > On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> > > > > >
> > > > > >
> > > > > >
> > > > > > On 10/21/22 05:18, Jani Nikula wrote:
> > > > > > > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > > > > > >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > > > > > >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > > > > > >>>> hi Greg, Dan, Jason, DRM-folk,
> > > > > > >>>>
> > > > > > >>>> heres follow-up to V6:
> > > > > > >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > > > > > >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > > > > > >>>>
> > > > > > >>>> It excludes:
> > > > > > >>>>   nouveau parts (immature)
> > > > > > >>>>   tracefs parts (I missed --to=Steve on v6)
> > > > > > >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> > > > > > >>>>
> > > > > > >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > > > > > >>>>
> > > > > > >>>> If these are good to apply, I'll rebase and repost the rest separately.
> > > > > > >>>
> > > > > > >>> All now queued up, thanks.
> > > > > > >>
> > > > > > >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > > > > > >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > > > > > >> the debug prints start to suddenly work.
> > > > > > >
> > > > > > > Wait what? I always assumed the default behaviour would stay the same,
> > > > > > > which is usually how we roll. It's a regression in my books. We've got a
> > > > > > > CI farm that's not very helpful in terms of dmesg logging right now
> > > > > > > because of this.
> > > > > > >
> > > > > > > BR,
> > > > > > > Jani.
> > > > > > >
> > > > > > >
> > > > > >
> > > > > > That doesn't sound good - so you are saying that prior to this change some
> > > > > > of the drm debugs were default enabled. But now you have to manually enable
> > > > > > them?
> > > > > >
> > > > > > Thanks,
> > > > > >
> > > > > > -Jason
> > > > >
> > > > >
> > > > > Im just seeing this now.
> > > > > Any new details ?
> > > >
> > > > No. We just disabled it as BROKEN for now. I was just today thinking
> > > > about sending that patch out if no solutin is forthcoming soon since
> > > > we need this working before 6.1 is released.
> > > >
> > > > Pretty sure you should see the problem immediately with any driver
> > > > (at least if it's built as a module, didn't try builtin). Or at least
> > > > can't think what would make i915 any more special.
> > > >
> > >
> > > So, I should note -
> > > 99% of my time & energy on this dyndbg + drm patchset
> > > has been done using virtme,
> > > so my world-view (and dev-hack-test env) has been smaller, simpler
> > > maybe its been fatally simplistic.
> > >
> > > ive just rebuilt v6.0  (before the trouble)
> > > and run it thru my virtual home box,
> > > I didnt see any unfamiliar drm-debug output
> > > that I might have inadvertently altered somehow
> > >
> > > I have some real HW I can put a reference kernel on,0
> > > to look for the missing output, but its all gonna take some time,
> > > esp to tighten up my dev-test-env
> > >
> > > in the meantime, there is:
> > >
> > > config DRM_USE_DYNAMIC_DEBUG
> > > bool "use dynamic debug to implement drm.debug"
> > > default y
> > > depends on DRM
> > > depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > > depends on JUMP_LABEL
> > > help
> > >   Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
> > >   Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
> > >   bytes per callsite, the .data costs can be substantial, and
> > >   are therefore configurable.
> > >
> > > Does changing the default fix things for i915 dmesg ?
> >
> > I think we want to mark it BROKEN in addition to make sure no one
> 
> Ok, I get the distinction now.
> youre spelling that
>   depends on BROKEN
> 
> I have a notional explanation, and a conflating commit:
> 
> can you eliminate
> git log -p ccc2b496324c13e917ef05f563626f4e7826bef1
> 
> as the cause ?

Reverting that doesn't help.

> 
> 
> 
> commit ccc2b496324c13e917ef05f563626f4e7826bef1
> Author: Jim Cromie <jim.cromie@gmail.com>
> Date:   Sun Sep 11 23:28:51 2022 -0600
> 
>     drm_print: prefer bare printk KERN_DEBUG on generic fn
> 
>     drm_print.c calls pr_debug() just once, from __drm_printfn_debug(),
>     which is a generic/service fn.  The callsite is compile-time enabled
>     by DEBUG in both DYNAMIC_DEBUG=y/n builds.
> 
>     For dyndbg builds, reverting this callsite back to bare printk is
>     correcting a few anti-features:
> 
>     1- callsite is generic, serves multiple drm users.
>        it is soft-wired on currently by #define DEBUG
>        could accidentally: #> echo -p > /proc/dynamic_debug/control
> 
>     2- optional "decorations" by dyndbg are unhelpful/misleading here,
>        they describe only the generic site, not end users
> 
>     IOW, 1,2 are unhelpful at best, and possibly confusing.
> 
> 
> This shouldnt have turned off any debug of any kind
> (drm.debug nor plain pr_debug)
> 
> but that former callsite no longer does the modname:func:line prefixing
> that could have been in effect and relied upon (tested for) by your CI
> 
> 
> I do need to clarify, I dont know exactly what debug/logging output
> is missing such that CI is failing

CI isn't failing. But any logs it produces are 100% useless,
as are any user reported logs.

The debugs that are missing are anything not coming directly
from drm.ko.

The stuff that I see being printed by i915.ko are drm_info()
and the drm_printer stuff from i915_welcome_messages(). That
also implies that drm_debug_enabled(DRM_UT_DRIVER) does at
least still work correctly.

I suspect that the problem is just that the debug calls
aren't getting patched in when a module loads. And fiddling
with the modparam after the fact does trigger that somehow.

-- 
Ville Syrjälä
Intel
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by jim.cromie@gmail.com 3 years, 5 months ago
On Mon, Oct 31, 2022 at 7:07 AM Ville Syrjälä
<ville.syrjala@linux.intel.com> wrote:
>
> On Sun, Oct 30, 2022 at 08:42:52AM -0600, jim.cromie@gmail.com wrote:
> > On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
> > <ville.syrjala@linux.intel.com> wrote:
> > >
> > > On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
> > > > On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
> > > > <ville.syrjala@linux.intel.com> wrote:
> > > > >
> > > > > On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> > > > > > On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > On 10/21/22 05:18, Jani Nikula wrote:
> > > > > > > > On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > > > > > > >> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > > > > > > >>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > > > > > > >>>> hi Greg, Dan, Jason, DRM-folk,
> > > > > > > >>>>
> > > > > > > >>>> heres follow-up to V6:
> > > > > > > >>>>   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > > > > > > >>>>   rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > > > > > > >>>>
> > > > > > > >>>> It excludes:
> > > > > > > >>>>   nouveau parts (immature)
> > > > > > > >>>>   tracefs parts (I missed --to=Steve on v6)
> > > > > > > >>>>   split _ddebug_site and de-duplicate experiment (way unready)
> > > > > > > >>>>
> > > > > > > >>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > > > > > > >>>>
> > > > > > > >>>> If these are good to apply, I'll rebase and repost the rest separately.
> > > > > > > >>>
> > > > > > > >>> All now queued up, thanks.
> > > > > > > >>
> > > > > > > >> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > > > > > > >> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > > > > > > >> the debug prints start to suddenly work.
> > > > > > > >
> > > > > > > > Wait what? I always assumed the default behaviour would stay the same,
> > > > > > > > which is usually how we roll. It's a regression in my books. We've got a
> > > > > > > > CI farm that's not very helpful in terms of dmesg logging right now
> > > > > > > > because of this.
> > > > > > > >
> > > > > > > > BR,
> > > > > > > > Jani.
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > > > That doesn't sound good - so you are saying that prior to this change some
> > > > > > > of the drm debugs were default enabled. But now you have to manually enable
> > > > > > > them?
> > > > > > >
> > > > > > > Thanks,
> > > > > > >
> > > > > > > -Jason
> > > > > >
> > > > > >
> > > > > > Im just seeing this now.
> > > > > > Any new details ?
> > > > >
> > > > > No. We just disabled it as BROKEN for now. I was just today thinking
> > > > > about sending that patch out if no solutin is forthcoming soon since
> > > > > we need this working before 6.1 is released.
> > > > >
> > > > > Pretty sure you should see the problem immediately with any driver
> > > > > (at least if it's built as a module, didn't try builtin). Or at least
> > > > > can't think what would make i915 any more special.
> > > > >
> > > >
> > > > So, I should note -
> > > > 99% of my time & energy on this dyndbg + drm patchset
> > > > has been done using virtme,
> > > > so my world-view (and dev-hack-test env) has been smaller, simpler
> > > > maybe its been fatally simplistic.
> > > >
> > > > ive just rebuilt v6.0  (before the trouble)
> > > > and run it thru my virtual home box,
> > > > I didnt see any unfamiliar drm-debug output
> > > > that I might have inadvertently altered somehow
> > > >
> > > > I have some real HW I can put a reference kernel on,0
> > > > to look for the missing output, but its all gonna take some time,
> > > > esp to tighten up my dev-test-env
> > > >
> > > > in the meantime, there is:
> > > >
> > > > config DRM_USE_DYNAMIC_DEBUG
> > > > bool "use dynamic debug to implement drm.debug"
> > > > default y
> > > > depends on DRM
> > > > depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > > > depends on JUMP_LABEL
> > > > help
> > > >   Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
> > > >   Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
> > > >   bytes per callsite, the .data costs can be substantial, and
> > > >   are therefore configurable.
> > > >
> > > > Does changing the default fix things for i915 dmesg ?
> > >
> > > I think we want to mark it BROKEN in addition to make sure no one
> >
> > Ok, I get the distinction now.
> > youre spelling that
> >   depends on BROKEN
> >
> > I have a notional explanation, and a conflating commit:
> >
> > can you eliminate
> > git log -p ccc2b496324c13e917ef05f563626f4e7826bef1
> >
> > as the cause ?
>
> Reverting that doesn't help.
>

thanks for eliminating it.

> >
> > I do need to clarify, I dont know exactly what debug/logging output
> > is missing such that CI is failing
>
> CI isn't failing. But any logs it produces are 100% useless,
> as are any user reported logs.
>
> The debugs that are missing are anything not coming directly
> from drm.ko.
>
> The stuff that I see being printed by i915.ko are drm_info()
> and the drm_printer stuff from i915_welcome_messages(). That
> also implies that drm_debug_enabled(DRM_UT_DRIVER) does at
> least still work correctly.
>
> I suspect that the problem is just that the debug calls
> aren't getting patched in when a module loads. And fiddling
> with the modparam after the fact does trigger that somehow.
>

ok, heres the 'tape' of a virtme boot,
then modprobe going wrong.

[    1.785873] dyndbg:   2 debug prints in module intel_rapl_msr
[    2.040598] virtme-init: udev is done
virtme-init: console is ttyS0

> load drm driver
bash-5.2# modprobe i915

> drm module is loaded 1st

[    6.549451] dyndbg: add-module: drm.302 sites
[    6.549991] dyndbg: class[0]: module:drm base:0 len:10 ty:0
[    6.550647] dyndbg:  0: 0 DRM_UT_CORE
[    6.551097] dyndbg:  1: 1 DRM_UT_DRIVER
[    6.551531] dyndbg:  2: 2 DRM_UT_KMS
[    6.551931] dyndbg:  3: 3 DRM_UT_PRIME
[    6.552402] dyndbg:  4: 4 DRM_UT_ATOMIC
[    6.552799] dyndbg:  5: 5 DRM_UT_VBL
[    6.553270] dyndbg:  6: 6 DRM_UT_STATE
[    6.553634] dyndbg:  7: 7 DRM_UT_LEASE
[    6.554043] dyndbg:  8: 8 DRM_UT_DP
[    6.554392] dyndbg:  9: 9 DRM_UT_DRMRES
[    6.554776] dyndbg: module:drm attached 1 classes
[    6.555241] dyndbg: 302 debug prints in module drm

> here modprobe reads /etc/modprobe.d/drm-test.conf:
options drm dyndbg="class DRM_UT_CORE +p; class DRM_UT_DRIVER +p"
and dyndbg applies it

[    6.564284] dyndbg: module: drm dyndbg="class DRM_UT_CORE +p; class
DRM_UT_DRIVER +p"
[    6.564957] dyndbg: query 0: "class DRM_UT_CORE +p" mod:drm
[    6.565348] dyndbg: split into words: "class" "DRM_UT_CORE" "+p"
[    6.565836] dyndbg: op='+'
[    6.566059] dyndbg: flags=0x1
[    6.566321] dyndbg: *flagsp=0x1 *maskp=0xffffffff
[    6.566875] dyndbg: parsed: func="" file="" module="drm" format=""
lineno=0-0 class=DRM_UT_CORE
[    6.568753] dyndbg: applied: func="" file="" module="drm" format=""
lineno=0-0 class=DRM_UT_CORE
[    6.569473] dyndbg: query 1: "class DRM_UT_DRIVER +p" mod:drm
[    6.570139] dyndbg: split into words: "class" "DRM_UT_DRIVER" "+p"
[    6.570522] dyndbg: op='+'
[    6.570699] dyndbg: flags=0x1
[    6.570893] dyndbg: *flagsp=0x1 *maskp=0xffffffff
[    6.571200] dyndbg: parsed: func="" file="" module="drm" format=""
lineno=0-0 class=DRM_UT_DRIVER
[    6.571778] dyndbg: no matches for query
[    6.572031] dyndbg: no-match: func="" file="" module="drm"
format="" lineno=0-0 class=DRM_UT_DRIVER
[    6.572615] dyndbg: processed 2 queries, with 61 matches, 0 errs
[    6.573286] ACPI: bus type drm_connector registered

next required module is loaded, but drm.debug isnt propagated.

[    6.578645] dyndbg: add-module: drm_kms_helper.94 sites
[    6.579487] dyndbg: class[0]: module:drm_kms_helper base:0 len:10 ty:0
[    6.580639] dyndbg:  0: 0 DRM_UT_CORE
[    6.581135] dyndbg:  1: 1 DRM_UT_DRIVER
[    6.581651] dyndbg:  2: 2 DRM_UT_KMS
[    6.582178] dyndbg:  3: 3 DRM_UT_PRIME
[    6.582927] dyndbg:  4: 4 DRM_UT_ATOMIC
[    6.583627] dyndbg:  5: 5 DRM_UT_VBL
[    6.584350] dyndbg:  6: 6 DRM_UT_STATE
[    6.584999] dyndbg:  7: 7 DRM_UT_LEASE
[    6.585699] dyndbg:  8: 8 DRM_UT_DP
[    6.586354] dyndbg:  9: 9 DRM_UT_DRMRES
[    6.587040] dyndbg: module:drm_kms_helper attached 1 classes
[    6.588103] dyndbg:  94 debug prints in module drm_kms_helper

and so on

[    6.595628] dyndbg: add-module: drm_display_helper.150 sites
[    6.596442] dyndbg: class[0]: module:drm_display_helper base:0 len:10 ty:0
[    6.597453] dyndbg:  0: 0 DRM_UT_CORE
...
[    6.601678] dyndbg: module:drm_display_helper attached 1 classes
[    6.602335] dyndbg: 150 debug prints in module drm_display_helper

[    6.692760] dyndbg: add-module: i915.1657 sites
[    6.693023] dyndbg: class[0]: module:i915 base:0 len:10 ty:0
[    6.693323] dyndbg:  0: 0 DRM_UT_CORE
....
[    6.695220] dyndbg: module:i915 attached 1 classes
[    6.695463] dyndbg: 1657 debug prints in module i915
bash-5.2#
bash-5.2#


So, what I think I need to add:

ddebug_add_module()  scans the module being loaded,
looking for a param thats wired to dyndbg's modparam callback.
Then it calls that callback, with the val of the sysfs-node
(drm.debug in this case), and the module (i915)

the callback will then run the query to enable callsites per drm.debug.

I'll guess the kparams I need to find are in a section somewhere
Anyone want to toss a lawn-dart at the code I need to look at, copy ?

> --
> Ville Syrjälä
> Intel

thanks again
Jim
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Jason Baron 3 years, 5 months ago

On 10/31/22 6:11 PM, jim.cromie@gmail.com wrote:
> On Mon, Oct 31, 2022 at 7:07 AM Ville Syrjälä
> <ville.syrjala@linux.intel.com> wrote:
>> On Sun, Oct 30, 2022 at 08:42:52AM -0600, jim.cromie@gmail.com wrote:
>>> On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
>>> <ville.syrjala@linux.intel.com> wrote:
>>>> On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
>>>>> On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
>>>>> <ville.syrjala@linux.intel.com> wrote:
>>>>>> On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
>>>>>>> On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
>>>>>>>>
>>>>>>>>
>>>>>>>> On 10/21/22 05:18, Jani Nikula wrote:
>>>>>>>>> On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
>>>>>>>>>> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
>>>>>>>>>>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
>>>>>>>>>>>> hi Greg, Dan, Jason, DRM-folk,
>>>>>>>>>>>>
>>>>>>>>>>>> heres follow-up to V6:
>>>>>>>>>>>>    rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
>>>>>>>>>>>>    rework drm_debug_enabled{_raw,_instrumented,} per Dan.
>>>>>>>>>>>>
>>>>>>>>>>>> It excludes:
>>>>>>>>>>>>    nouveau parts (immature)
>>>>>>>>>>>>    tracefs parts (I missed --to=Steve on v6)
>>>>>>>>>>>>    split _ddebug_site and de-duplicate experiment (way unready)
>>>>>>>>>>>>
>>>>>>>>>>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
>>>>>>>>>>>>
>>>>>>>>>>>> If these are good to apply, I'll rebase and repost the rest separately.
>>>>>>>>>>> All now queued up, thanks.
>>>>>>>>>> This stuff broke i915 debugs. When I first load i915 no debug prints are
>>>>>>>>>> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
>>>>>>>>>> the debug prints start to suddenly work.
>>>>>>>>> Wait what? I always assumed the default behaviour would stay the same,
>>>>>>>>> which is usually how we roll. It's a regression in my books. We've got a
>>>>>>>>> CI farm that's not very helpful in terms of dmesg logging right now
>>>>>>>>> because of this.
>>>>>>>>>
>>>>>>>>> BR,
>>>>>>>>> Jani.
>>>>>>>>>
>>>>>>>>>
>>>>>>>> That doesn't sound good - so you are saying that prior to this change some
>>>>>>>> of the drm debugs were default enabled. But now you have to manually enable
>>>>>>>> them?
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>>
>>>>>>>> -Jason
>>>>>>>
>>>>>>> Im just seeing this now.
>>>>>>> Any new details ?
>>>>>> No. We just disabled it as BROKEN for now. I was just today thinking
>>>>>> about sending that patch out if no solutin is forthcoming soon since
>>>>>> we need this working before 6.1 is released.
>>>>>>
>>>>>> Pretty sure you should see the problem immediately with any driver
>>>>>> (at least if it's built as a module, didn't try builtin). Or at least
>>>>>> can't think what would make i915 any more special.
>>>>>>
>>>>> So, I should note -
>>>>> 99% of my time & energy on this dyndbg + drm patchset
>>>>> has been done using virtme,
>>>>> so my world-view (and dev-hack-test env) has been smaller, simpler
>>>>> maybe its been fatally simplistic.
>>>>>
>>>>> ive just rebuilt v6.0  (before the trouble)
>>>>> and run it thru my virtual home box,
>>>>> I didnt see any unfamiliar drm-debug output
>>>>> that I might have inadvertently altered somehow
>>>>>
>>>>> I have some real HW I can put a reference kernel on,0
>>>>> to look for the missing output, but its all gonna take some time,
>>>>> esp to tighten up my dev-test-env
>>>>>
>>>>> in the meantime, there is:
>>>>>
>>>>> config DRM_USE_DYNAMIC_DEBUG
>>>>> bool "use dynamic debug to implement drm.debug"
>>>>> default y
>>>>> depends on DRM
>>>>> depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
>>>>> depends on JUMP_LABEL
>>>>> help
>>>>>    Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
>>>>>    Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
>>>>>    bytes per callsite, the .data costs can be substantial, and
>>>>>    are therefore configurable.
>>>>>
>>>>> Does changing the default fix things for i915 dmesg ?
>>>> I think we want to mark it BROKEN in addition to make sure no one
>>> Ok, I get the distinction now.
>>> youre spelling that
>>>    depends on BROKEN
>>>
>>> I have a notional explanation, and a conflating commit:
>>>
>>> can you eliminate
>>> git log -p ccc2b496324c13e917ef05f563626f4e7826bef1
>>>
>>> as the cause ?
>> Reverting that doesn't help.
>>
> thanks for eliminating it.
>
>>> I do need to clarify, I dont know exactly what debug/logging output
>>> is missing such that CI is failing
>> CI isn't failing. But any logs it produces are 100% useless,
>> as are any user reported logs.
>>
>> The debugs that are missing are anything not coming directly
>> from drm.ko.
>>
>> The stuff that I see being printed by i915.ko are drm_info()
>> and the drm_printer stuff from i915_welcome_messages(). That
>> also implies that drm_debug_enabled(DRM_UT_DRIVER) does at
>> least still work correctly.
>>
>> I suspect that the problem is just that the debug calls
>> aren't getting patched in when a module loads. And fiddling
>> with the modparam after the fact does trigger that somehow.
>>
> ok, heres the 'tape' of a virtme boot,
> then modprobe going wrong.
>
> [    1.785873] dyndbg:   2 debug prints in module intel_rapl_msr
> [    2.040598] virtme-init: udev is done
> virtme-init: console is ttyS0
>
>> load drm driver
> bash-5.2# modprobe i915
>
>> drm module is loaded 1st
> [    6.549451] dyndbg: add-module: drm.302 sites
> [    6.549991] dyndbg: class[0]: module:drm base:0 len:10 ty:0
> [    6.550647] dyndbg:  0: 0 DRM_UT_CORE
> [    6.551097] dyndbg:  1: 1 DRM_UT_DRIVER
> [    6.551531] dyndbg:  2: 2 DRM_UT_KMS
> [    6.551931] dyndbg:  3: 3 DRM_UT_PRIME
> [    6.552402] dyndbg:  4: 4 DRM_UT_ATOMIC
> [    6.552799] dyndbg:  5: 5 DRM_UT_VBL
> [    6.553270] dyndbg:  6: 6 DRM_UT_STATE
> [    6.553634] dyndbg:  7: 7 DRM_UT_LEASE
> [    6.554043] dyndbg:  8: 8 DRM_UT_DP
> [    6.554392] dyndbg:  9: 9 DRM_UT_DRMRES
> [    6.554776] dyndbg: module:drm attached 1 classes
> [    6.555241] dyndbg: 302 debug prints in module drm
>
>> here modprobe reads /etc/modprobe.d/drm-test.conf:
> options drm dyndbg="class DRM_UT_CORE +p; class DRM_UT_DRIVER +p"
> and dyndbg applies it

Hi,

I'm a bit confused with this. My understanding is that there
is a 'regression' here from how this used to work. But the
'class' keyword is new - are we sure this is the command-line
we are trying to fix?

>
> [    6.564284] dyndbg: module: drm dyndbg="class DRM_UT_CORE +p; class
> DRM_UT_DRIVER +p"
> [    6.564957] dyndbg: query 0: "class DRM_UT_CORE +p" mod:drm
> [    6.565348] dyndbg: split into words: "class" "DRM_UT_CORE" "+p"
> [    6.565836] dyndbg: op='+'
> [    6.566059] dyndbg: flags=0x1
> [    6.566321] dyndbg: *flagsp=0x1 *maskp=0xffffffff
> [    6.566875] dyndbg: parsed: func="" file="" module="drm" format=""
> lineno=0-0 class=DRM_UT_CORE
> [    6.568753] dyndbg: applied: func="" file="" module="drm" format=""
> lineno=0-0 class=DRM_UT_CORE
> [    6.569473] dyndbg: query 1: "class DRM_UT_DRIVER +p" mod:drm
> [    6.570139] dyndbg: split into words: "class" "DRM_UT_DRIVER" "+p"
> [    6.570522] dyndbg: op='+'
> [    6.570699] dyndbg: flags=0x1
> [    6.570893] dyndbg: *flagsp=0x1 *maskp=0xffffffff
> [    6.571200] dyndbg: parsed: func="" file="" module="drm" format=""
> lineno=0-0 class=DRM_UT_DRIVER
> [    6.571778] dyndbg: no matches for query
> [    6.572031] dyndbg: no-match: func="" file="" module="drm"
> format="" lineno=0-0 class=DRM_UT_DRIVER
> [    6.572615] dyndbg: processed 2 queries, with 61 matches, 0 errs
> [    6.573286] ACPI: bus type drm_connector registered
>
> next required module is loaded, but drm.debug isnt propagated.
>
> [    6.578645] dyndbg: add-module: drm_kms_helper.94 sites
> [    6.579487] dyndbg: class[0]: module:drm_kms_helper base:0 len:10 ty:0
> [    6.580639] dyndbg:  0: 0 DRM_UT_CORE
> [    6.581135] dyndbg:  1: 1 DRM_UT_DRIVER
> [    6.581651] dyndbg:  2: 2 DRM_UT_KMS
> [    6.582178] dyndbg:  3: 3 DRM_UT_PRIME
> [    6.582927] dyndbg:  4: 4 DRM_UT_ATOMIC
> [    6.583627] dyndbg:  5: 5 DRM_UT_VBL
> [    6.584350] dyndbg:  6: 6 DRM_UT_STATE
> [    6.584999] dyndbg:  7: 7 DRM_UT_LEASE
> [    6.585699] dyndbg:  8: 8 DRM_UT_DP
> [    6.586354] dyndbg:  9: 9 DRM_UT_DRMRES
> [    6.587040] dyndbg: module:drm_kms_helper attached 1 classes
> [    6.588103] dyndbg:  94 debug prints in module drm_kms_helper
>
> and so on
>
> [    6.595628] dyndbg: add-module: drm_display_helper.150 sites
> [    6.596442] dyndbg: class[0]: module:drm_display_helper base:0 len:10 ty:0
> [    6.597453] dyndbg:  0: 0 DRM_UT_CORE
> ...
> [    6.601678] dyndbg: module:drm_display_helper attached 1 classes
> [    6.602335] dyndbg: 150 debug prints in module drm_display_helper
>
> [    6.692760] dyndbg: add-module: i915.1657 sites
> [    6.693023] dyndbg: class[0]: module:i915 base:0 len:10 ty:0
> [    6.693323] dyndbg:  0: 0 DRM_UT_CORE
> ....
> [    6.695220] dyndbg: module:i915 attached 1 classes
> [    6.695463] dyndbg: 1657 debug prints in module i915
> bash-5.2#
> bash-5.2#
>
>
> So, what I think I need to add:
>
> ddebug_add_module()  scans the module being loaded,
> looking for a param thats wired to dyndbg's modparam callback.
> Then it calls that callback, with the val of the sysfs-node
> (drm.debug in this case), and the module (i915)

Ok, I thought the sysfs callbacks only happen when
the sysfs file is written? And thus this works once
when the sysfs file is explicitly written by the user
after boot but not before then?

Thanks,

-Jason

>
> the callback will then run the query to enable callsites per drm.debug.
>
> I'll guess the kparams I need to find are in a section somewhere
> Anyone want to toss a lawn-dart at the code I need to look at, copy ?
>
>> --
>> Ville Syrjälä
>> Intel
> thanks again
> Jim

Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by Ville Syrjälä 3 years, 5 months ago
On Mon, Oct 31, 2022 at 08:20:54PM -0400, Jason Baron wrote:
> 
> 
> On 10/31/22 6:11 PM, jim.cromie@gmail.com wrote:
> > On Mon, Oct 31, 2022 at 7:07 AM Ville Syrjälä
> > <ville.syrjala@linux.intel.com> wrote:
> >> On Sun, Oct 30, 2022 at 08:42:52AM -0600, jim.cromie@gmail.com wrote:
> >>> On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
> >>> <ville.syrjala@linux.intel.com> wrote:
> >>>> On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
> >>>>> On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
> >>>>> <ville.syrjala@linux.intel.com> wrote:
> >>>>>> On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> >>>>>>> On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> >>>>>>>>
> >>>>>>>>
> >>>>>>>> On 10/21/22 05:18, Jani Nikula wrote:
> >>>>>>>>> On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> >>>>>>>>>> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> >>>>>>>>>>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> >>>>>>>>>>>> hi Greg, Dan, Jason, DRM-folk,
> >>>>>>>>>>>>
> >>>>>>>>>>>> heres follow-up to V6:
> >>>>>>>>>>>>    rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> >>>>>>>>>>>>    rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> >>>>>>>>>>>>
> >>>>>>>>>>>> It excludes:
> >>>>>>>>>>>>    nouveau parts (immature)
> >>>>>>>>>>>>    tracefs parts (I missed --to=Steve on v6)
> >>>>>>>>>>>>    split _ddebug_site and de-duplicate experiment (way unready)
> >>>>>>>>>>>>
> >>>>>>>>>>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> >>>>>>>>>>>>
> >>>>>>>>>>>> If these are good to apply, I'll rebase and repost the rest separately.
> >>>>>>>>>>> All now queued up, thanks.
> >>>>>>>>>> This stuff broke i915 debugs. When I first load i915 no debug prints are
> >>>>>>>>>> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> >>>>>>>>>> the debug prints start to suddenly work.
> >>>>>>>>> Wait what? I always assumed the default behaviour would stay the same,
> >>>>>>>>> which is usually how we roll. It's a regression in my books. We've got a
> >>>>>>>>> CI farm that's not very helpful in terms of dmesg logging right now
> >>>>>>>>> because of this.
> >>>>>>>>>
> >>>>>>>>> BR,
> >>>>>>>>> Jani.
> >>>>>>>>>
> >>>>>>>>>
> >>>>>>>> That doesn't sound good - so you are saying that prior to this change some
> >>>>>>>> of the drm debugs were default enabled. But now you have to manually enable
> >>>>>>>> them?
> >>>>>>>>
> >>>>>>>> Thanks,
> >>>>>>>>
> >>>>>>>> -Jason
> >>>>>>>
> >>>>>>> Im just seeing this now.
> >>>>>>> Any new details ?
> >>>>>> No. We just disabled it as BROKEN for now. I was just today thinking
> >>>>>> about sending that patch out if no solutin is forthcoming soon since
> >>>>>> we need this working before 6.1 is released.
> >>>>>>
> >>>>>> Pretty sure you should see the problem immediately with any driver
> >>>>>> (at least if it's built as a module, didn't try builtin). Or at least
> >>>>>> can't think what would make i915 any more special.
> >>>>>>
> >>>>> So, I should note -
> >>>>> 99% of my time & energy on this dyndbg + drm patchset
> >>>>> has been done using virtme,
> >>>>> so my world-view (and dev-hack-test env) has been smaller, simpler
> >>>>> maybe its been fatally simplistic.
> >>>>>
> >>>>> ive just rebuilt v6.0  (before the trouble)
> >>>>> and run it thru my virtual home box,
> >>>>> I didnt see any unfamiliar drm-debug output
> >>>>> that I might have inadvertently altered somehow
> >>>>>
> >>>>> I have some real HW I can put a reference kernel on,0
> >>>>> to look for the missing output, but its all gonna take some time,
> >>>>> esp to tighten up my dev-test-env
> >>>>>
> >>>>> in the meantime, there is:
> >>>>>
> >>>>> config DRM_USE_DYNAMIC_DEBUG
> >>>>> bool "use dynamic debug to implement drm.debug"
> >>>>> default y
> >>>>> depends on DRM
> >>>>> depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> >>>>> depends on JUMP_LABEL
> >>>>> help
> >>>>>    Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
> >>>>>    Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
> >>>>>    bytes per callsite, the .data costs can be substantial, and
> >>>>>    are therefore configurable.
> >>>>>
> >>>>> Does changing the default fix things for i915 dmesg ?
> >>>> I think we want to mark it BROKEN in addition to make sure no one
> >>> Ok, I get the distinction now.
> >>> youre spelling that
> >>>    depends on BROKEN
> >>>
> >>> I have a notional explanation, and a conflating commit:
> >>>
> >>> can you eliminate
> >>> git log -p ccc2b496324c13e917ef05f563626f4e7826bef1
> >>>
> >>> as the cause ?
> >> Reverting that doesn't help.
> >>
> > thanks for eliminating it.
> >
> >>> I do need to clarify, I dont know exactly what debug/logging output
> >>> is missing such that CI is failing
> >> CI isn't failing. But any logs it produces are 100% useless,
> >> as are any user reported logs.
> >>
> >> The debugs that are missing are anything not coming directly
> >> from drm.ko.
> >>
> >> The stuff that I see being printed by i915.ko are drm_info()
> >> and the drm_printer stuff from i915_welcome_messages(). That
> >> also implies that drm_debug_enabled(DRM_UT_DRIVER) does at
> >> least still work correctly.
> >>
> >> I suspect that the problem is just that the debug calls
> >> aren't getting patched in when a module loads. And fiddling
> >> with the modparam after the fact does trigger that somehow.
> >>
> > ok, heres the 'tape' of a virtme boot,
> > then modprobe going wrong.
> >
> > [    1.785873] dyndbg:   2 debug prints in module intel_rapl_msr
> > [    2.040598] virtme-init: udev is done
> > virtme-init: console is ttyS0
> >
> >> load drm driver
> > bash-5.2# modprobe i915
> >
> >> drm module is loaded 1st
> > [    6.549451] dyndbg: add-module: drm.302 sites
> > [    6.549991] dyndbg: class[0]: module:drm base:0 len:10 ty:0
> > [    6.550647] dyndbg:  0: 0 DRM_UT_CORE
> > [    6.551097] dyndbg:  1: 1 DRM_UT_DRIVER
> > [    6.551531] dyndbg:  2: 2 DRM_UT_KMS
> > [    6.551931] dyndbg:  3: 3 DRM_UT_PRIME
> > [    6.552402] dyndbg:  4: 4 DRM_UT_ATOMIC
> > [    6.552799] dyndbg:  5: 5 DRM_UT_VBL
> > [    6.553270] dyndbg:  6: 6 DRM_UT_STATE
> > [    6.553634] dyndbg:  7: 7 DRM_UT_LEASE
> > [    6.554043] dyndbg:  8: 8 DRM_UT_DP
> > [    6.554392] dyndbg:  9: 9 DRM_UT_DRMRES
> > [    6.554776] dyndbg: module:drm attached 1 classes
> > [    6.555241] dyndbg: 302 debug prints in module drm
> >
> >> here modprobe reads /etc/modprobe.d/drm-test.conf:
> > options drm dyndbg="class DRM_UT_CORE +p; class DRM_UT_DRIVER +p"
> > and dyndbg applies it
> 
> Hi,
> 
> I'm a bit confused with this. My understanding is that there
> is a 'regression' here from how this used to work. But the
> 'class' keyword is new - are we sure this is the command-line
> we are trying to fix?

The thing we need fixed is just the bog standard drm.debug=0xe etc.

-- 
Ville Syrjälä
Intel
Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation
Posted by jim.cromie@gmail.com 3 years, 5 months ago
On Tue, Nov 1, 2022 at 2:52 AM Ville Syrjälä
<ville.syrjala@linux.intel.com> wrote:
>
> On Mon, Oct 31, 2022 at 08:20:54PM -0400, Jason Baron wrote:
> >
> >
> > On 10/31/22 6:11 PM, jim.cromie@gmail.com wrote:
> > > On Mon, Oct 31, 2022 at 7:07 AM Ville Syrjälä
> > > <ville.syrjala@linux.intel.com> wrote:
> > >> On Sun, Oct 30, 2022 at 08:42:52AM -0600, jim.cromie@gmail.com wrote:
> > >>> On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
> > >>> <ville.syrjala@linux.intel.com> wrote:
> > >>>> On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@gmail.com wrote:
> > >>>>> On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
> > >>>>> <ville.syrjala@linux.intel.com> wrote:
> > >>>>>> On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@gmail.com wrote:
> > >>>>>>> On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@akamai.com> wrote:
> > >>>>>>>>
> > >>>>>>>>
> > >>>>>>>> On 10/21/22 05:18, Jani Nikula wrote:
> > >>>>>>>>> On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@linux.intel.com> wrote:
> > >>>>>>>>>> On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
> > >>>>>>>>>>> On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
> > >>>>>>>>>>>> hi Greg, Dan, Jason, DRM-folk,
> > >>>>>>>>>>>>
> > >>>>>>>>>>>> heres follow-up to V6:
> > >>>>>>>>>>>>    rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
> > >>>>>>>>>>>>    rework drm_debug_enabled{_raw,_instrumented,} per Dan.
> > >>>>>>>>>>>>
> > >>>>>>>>>>>> It excludes:
> > >>>>>>>>>>>>    nouveau parts (immature)
> > >>>>>>>>>>>>    tracefs parts (I missed --to=Steve on v6)
> > >>>>>>>>>>>>    split _ddebug_site and de-duplicate experiment (way unready)
> > >>>>>>>>>>>>
> > >>>>>>>>>>>> IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.
> > >>>>>>>>>>>>
> > >>>>>>>>>>>> If these are good to apply, I'll rebase and repost the rest separately.
> > >>>>>>>>>>> All now queued up, thanks.
> > >>>>>>>>>> This stuff broke i915 debugs. When I first load i915 no debug prints are
> > >>>>>>>>>> produced. If I then go fiddle around in /sys/module/drm/parameters/debug
> > >>>>>>>>>> the debug prints start to suddenly work.
> > >>>>>>>>> Wait what? I always assumed the default behaviour would stay the same,
> > >>>>>>>>> which is usually how we roll. It's a regression in my books. We've got a
> > >>>>>>>>> CI farm that's not very helpful in terms of dmesg logging right now
> > >>>>>>>>> because of this.
> > >>>>>>>>>
> > >>>>>>>>> BR,
> > >>>>>>>>> Jani.
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>> That doesn't sound good - so you are saying that prior to this change some
> > >>>>>>>> of the drm debugs were default enabled. But now you have to manually enable
> > >>>>>>>> them?
> > >>>>>>>>
> > >>>>>>>> Thanks,
> > >>>>>>>>
> > >>>>>>>> -Jason
> > >>>>>>>
> > >>>>>>> Im just seeing this now.
> > >>>>>>> Any new details ?
> > >>>>>> No. We just disabled it as BROKEN for now. I was just today thinking
> > >>>>>> about sending that patch out if no solutin is forthcoming soon since
> > >>>>>> we need this working before 6.1 is released.
> > >>>>>>
> > >>>>>> Pretty sure you should see the problem immediately with any driver
> > >>>>>> (at least if it's built as a module, didn't try builtin). Or at least
> > >>>>>> can't think what would make i915 any more special.
> > >>>>>>
> > >>>>> So, I should note -
> > >>>>> 99% of my time & energy on this dyndbg + drm patchset
> > >>>>> has been done using virtme,
> > >>>>> so my world-view (and dev-hack-test env) has been smaller, simpler
> > >>>>> maybe its been fatally simplistic.
> > >>>>>
> > >>>>> ive just rebuilt v6.0  (before the trouble)
> > >>>>> and run it thru my virtual home box,
> > >>>>> I didnt see any unfamiliar drm-debug output
> > >>>>> that I might have inadvertently altered somehow
> > >>>>>
> > >>>>> I have some real HW I can put a reference kernel on,0
> > >>>>> to look for the missing output, but its all gonna take some time,
> > >>>>> esp to tighten up my dev-test-env
> > >>>>>
> > >>>>> in the meantime, there is:
> > >>>>>
> > >>>>> config DRM_USE_DYNAMIC_DEBUG
> > >>>>> bool "use dynamic debug to implement drm.debug"
> > >>>>> default y
> > >>>>> depends on DRM
> > >>>>> depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
> > >>>>> depends on JUMP_LABEL
> > >>>>> help
> > >>>>>    Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
> > >>>>>    Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
> > >>>>>    bytes per callsite, the .data costs can be substantial, and
> > >>>>>    are therefore configurable.
> > >>>>>
> > >>>>> Does changing the default fix things for i915 dmesg ?
> > >>>> I think we want to mark it BROKEN in addition to make sure no one
> > >>> Ok, I get the distinction now.
> > >>> youre spelling that
> > >>>    depends on BROKEN
> > >>>
> > >>> I have a notional explanation, and a conflating commit:
> > >>>
> > >>> can you eliminate
> > >>> git log -p ccc2b496324c13e917ef05f563626f4e7826bef1
> > >>>
> > >>> as the cause ?
> > >> Reverting that doesn't help.
> > >>
> > > thanks for eliminating it.
> > >
> > >>> I do need to clarify, I dont know exactly what debug/logging output
> > >>> is missing such that CI is failing
> > >> CI isn't failing. But any logs it produces are 100% useless,
> > >> as are any user reported logs.
> > >>
> > >> The debugs that are missing are anything not coming directly
> > >> from drm.ko.
> > >>
> > >> The stuff that I see being printed by i915.ko are drm_info()
> > >> and the drm_printer stuff from i915_welcome_messages(). That
> > >> also implies that drm_debug_enabled(DRM_UT_DRIVER) does at
> > >> least still work correctly.
> > >>
> > >> I suspect that the problem is just that the debug calls
> > >> aren't getting patched in when a module loads. And fiddling
> > >> with the modparam after the fact does trigger that somehow.
> > >>
> > > ok, heres the 'tape' of a virtme boot,
> > > then modprobe going wrong.
> > >
> > > [    1.785873] dyndbg:   2 debug prints in module intel_rapl_msr
> > > [    2.040598] virtme-init: udev is done
> > > virtme-init: console is ttyS0
> > >
> > >> load drm driver
> > > bash-5.2# modprobe i915
> > >
> > >> drm module is loaded 1st
> > > [    6.549451] dyndbg: add-module: drm.302 sites
> > > [    6.549991] dyndbg: class[0]: module:drm base:0 len:10 ty:0
> > > [    6.550647] dyndbg:  0: 0 DRM_UT_CORE
> > > [    6.551097] dyndbg:  1: 1 DRM_UT_DRIVER
> > > [    6.551531] dyndbg:  2: 2 DRM_UT_KMS
> > > [    6.551931] dyndbg:  3: 3 DRM_UT_PRIME
> > > [    6.552402] dyndbg:  4: 4 DRM_UT_ATOMIC
> > > [    6.552799] dyndbg:  5: 5 DRM_UT_VBL
> > > [    6.553270] dyndbg:  6: 6 DRM_UT_STATE
> > > [    6.553634] dyndbg:  7: 7 DRM_UT_LEASE
> > > [    6.554043] dyndbg:  8: 8 DRM_UT_DP
> > > [    6.554392] dyndbg:  9: 9 DRM_UT_DRMRES
> > > [    6.554776] dyndbg: module:drm attached 1 classes
> > > [    6.555241] dyndbg: 302 debug prints in module drm
> > >
> > >> here modprobe reads /etc/modprobe.d/drm-test.conf:
> > > options drm dyndbg="class DRM_UT_CORE +p; class DRM_UT_DRIVER +p"
> > > and dyndbg applies it
> >
> > Hi,
> >
> > I'm a bit confused with this. My understanding is that there
> > is a 'regression' here from how this used to work. But the
> > 'class' keyword is new - are we sure this is the command-line
> > we are trying to fix?


the regression here is that previously, any late changes to drm.debug
are seen by all callers of drm_debug_enabled(), which checks the bits
when called.

Now, the change to drm.debug causes updates to currently loaded modules'
prdbgs.  But module loading of dependent modules is incomplete,
and those prdbgs are too late.


>
> The thing we need fixed is just the bog standard drm.debug=0xe etc.


my example was unfortunate, I repeated the test with
  options drm debug=0x1f

the results are the same, dyndbgs callback applies the class queries,
but the helper, driver modules arent yet loaded, so the class'd prdbgs
arent there to be enabled.

The Notional fix (Im working on it)

dyndbg gets static list of CLASSMAPS,

ddebug_attach_module_classes() can then distinguish the "owner"
of each classmap (the 1st module declaring it), from the subsequently
loaded modules (which reuse the same previously declared classmap)

as subsequent modules (say drm_kms_helper) refs the DRM_UT_* classmap
(just attached to drm module), ddebug_attach_module_classes() can
invoke the callback to reapply drm.debug to the newly loaded module.

or so I think.

> --
> Ville Syrjälä
> Intel