Re: [RFC PATCH v2 00/27] DRM.debug on DYNAMIC_DEBUG, add trace events
On Mon, Jun 06, 2022 at 08:59:36AM -0600, jim.cro...@gmail.com wrote: > On Wed, May 25, 2022 at 9:02 AM Daniel Vetter wrote: > > > On Mon, May 16, 2022 at 04:56:13PM -0600, Jim Cromie wrote: > > > DRM.debug API is 23 macros, issuing 10 exclusive categories of debug > > > messages. By rough count, they are used 5140 times in the kernel. > > > These all call drm_dbg or drm_devdbg, which call drm_debug_enabled(), > > > which checks bits in global __drm_debug. Some of these are page-flips > > > and vblanks, and get called often. > > > > > > DYNAMIC_DEBUG (with CONFIG_JUMP_LABEL) is built to avoid this kind of > > > work, with NOOPd jump/callsites. > > > > > > This patchset is RFC because: > > > - it touches 2.5 subsystems: dyndbg, drm, tracefs (new events) > > > - dyndbg class support is built for drm, needs it for validation > > > - new api, used by drm > > > - big memory impact, with 5100 new pr-debug callsites. > > > - drm class bikeshedding opportunities > > > - others, names etc. > > > > Thanks a lot for keeping on pushing this! > > > > > > > > DYNAMIC_DEBUG: > > > > > > > > > RFC: > > > > > > dynamic_debug_register_classes() cannot act early enough to be in > > > effect at module-load. So this will not work as you'd reasonably > > > expect: > > > > > > modprobe test_dynamic_debug dyndbg='+pfm; class FOO +pfmlt' > > > > > > The 1st query:+pfm will be enabled during load, but in the 2nd query, > > > "class FOO" will be unknown at load time. Early class enablement > > > would be nice. DYNAMIC_DEBUG_CLASSES is a static initializer, which > > > is certainly early enough, but Im missing a trick, suggestions? > > > > So maybe I'm just totally overloading this work here so feel free to > > ignore or postpone, but: Could we do the dynamic_debug_register_classes() > > automatically at module load as a new special section? And then throw in a > > bit of kbuild so that in a given subsystem every driver gets the same > > class names by default and everything would just work, without having to > > sprinkle calls to dynamic_debug_register_classes() all over the place? > > > > This is now done; Ive added __dyndbg_classes section. > load_module() now grabs it from the .ko > and ddebug_add_module() attaches it to the module's ddebug_table record. > for builtins, dynamic_debug_init feeds the builtin class-maps to > ddebug_add_module > > bash-5.1# modprobe test_dynamic_debug dyndbg="class FOO +p" > [ 88.374722] dyndbg: class[0]: nm:test_dynamic_debug base:20 len:7 ty:1 > [ 88.375158] dyndbg: 0: EMERG > [ 88.375345] dyndbg: 1: DANGER > [ 88.375540] dyndbg: 2: ERROR > [ 88.375726] dyndbg: 3: WARNING > [ 88.375930] dyndbg: 4: NOTICE > [ 88.376130] dyndbg: 5: INFO > [ 88.376310] dyndbg: 6: DEBUG > [ 88.376499] dyndbg: class[1]: nm:test_dynamic_debug base:12 len:3 ty:1 > [ 88.376903] dyndbg: 0: ONE > [ 88.377079] dyndbg: 1: TWO > [ 88.377253] dyndbg: 2: THREE > [ 88.377441] dyndbg: class[2]: nm:test_dynamic_debug base:8 len:3 ty:0 > [ 88.377837] dyndbg: 0: bing > [ 88.378022] dyndbg: 1: bong > [ 88.378203] dyndbg: 2: boom > [ 88.378387] dyndbg: class[3]: nm:test_dynamic_debug base:4 len:3 ty:0 > [ 88.378800] dyndbg: 0: Foo > [ 88.378986] dyndbg: 1: Bar > [ 88.379167] dyndbg: 2: Buzz > [ 88.379348] dyndbg: class[4]: nm:test_dynamic_debug base:0 len:3 ty:0 > [ 88.379757] dyndbg: 0: FOO > [ 88.379938] dyndbg: 1: BAR > [ 88.380136] dyndbg: 2: BUZZ > [ 88.380410] dyndbg: module:test_dynamic_debug attached 5 classes > [ 88.380881] dyndbg: 24 debug prints in module test_dynamic_debug > [ 88.381315] dyndbg: module: test_dynamic_debug dyndbg="class FOO +p" > [ 88.381714] dyndbg: query 0: "class FOO +p" mod:test_dynamic_debug > [ 88.382109] dyndbg: split into words: "class" "FOO" "+p" > [ 88.382445] dyndbg: op='+' > [ 88.382616] dyndbg: flags=0x1 > [ 88.382802] dyndbg: *flagsp=0x1 *maskp=0x > [ 88.383101] dyndbg: parsed: func="" file="" module="test_dynamic_debug" > format="" lineno=0-0 class=FOO > [ 88.383740] dyndbg: applied: func="" file="" module="test_dynamic_debug" > format="" lineno=0-0 class=FOO > [ 88.384324] dyndbg: processed 1 queries, with 2 matches, 0 errs > bash-5.1# > > so its working at module-load time. Awesome! > > For the entire class approach, did you spot another subsystem that could > > benefit from this and maybe make a more solid case that this is something > > good? > > > > I had been working on the premise that ~4k drm*dbg callsites was a good > case. Oh I'm happy with just drm, but occasionally we've done stuff in drm that the wider kernel community found a bit silly. So bit more acks/validation from outside the dri-devel echo chamber would be great, whatever form it is. > verbosity-levels - with x missing. > > the next revision adds something, which "kinda works". > But I think I'll rip it out, and do this simpler approach instead: > > implement a verbose/levels param & callback, which
Re: [RFC PATCH v2 00/27] DRM.debug on DYNAMIC_DEBUG, add trace events
On Wed, May 25, 2022 at 9:02 AM Daniel Vetter wrote: > On Mon, May 16, 2022 at 04:56:13PM -0600, Jim Cromie wrote: > > DRM.debug API is 23 macros, issuing 10 exclusive categories of debug > > messages. By rough count, they are used 5140 times in the kernel. > > These all call drm_dbg or drm_devdbg, which call drm_debug_enabled(), > > which checks bits in global __drm_debug. Some of these are page-flips > > and vblanks, and get called often. > > > > DYNAMIC_DEBUG (with CONFIG_JUMP_LABEL) is built to avoid this kind of > > work, with NOOPd jump/callsites. > > > > This patchset is RFC because: > > - it touches 2.5 subsystems: dyndbg, drm, tracefs (new events) > > - dyndbg class support is built for drm, needs it for validation > > - new api, used by drm > > - big memory impact, with 5100 new pr-debug callsites. > > - drm class bikeshedding opportunities > > - others, names etc. > > Thanks a lot for keeping on pushing this! > > > > DYNAMIC_DEBUG: > > > > RFC: > > > > dynamic_debug_register_classes() cannot act early enough to be in > > effect at module-load. So this will not work as you'd reasonably > > expect: > > > > modprobe test_dynamic_debug dyndbg='+pfm; class FOO +pfmlt' > > > > The 1st query:+pfm will be enabled during load, but in the 2nd query, > > "class FOO" will be unknown at load time. Early class enablement > > would be nice. DYNAMIC_DEBUG_CLASSES is a static initializer, which > > is certainly early enough, but Im missing a trick, suggestions? > > So maybe I'm just totally overloading this work here so feel free to > ignore or postpone, but: Could we do the dynamic_debug_register_classes() > automatically at module load as a new special section? And then throw in a > bit of kbuild so that in a given subsystem every driver gets the same > class names by default and everything would just work, without having to > sprinkle calls to dynamic_debug_register_classes() all over the place? > This is now done; Ive added __dyndbg_classes section. load_module() now grabs it from the .ko and ddebug_add_module() attaches it to the module's ddebug_table record. for builtins, dynamic_debug_init feeds the builtin class-maps to ddebug_add_module bash-5.1# modprobe test_dynamic_debug dyndbg="class FOO +p" [ 88.374722] dyndbg: class[0]: nm:test_dynamic_debug base:20 len:7 ty:1 [ 88.375158] dyndbg: 0: EMERG [ 88.375345] dyndbg: 1: DANGER [ 88.375540] dyndbg: 2: ERROR [ 88.375726] dyndbg: 3: WARNING [ 88.375930] dyndbg: 4: NOTICE [ 88.376130] dyndbg: 5: INFO [ 88.376310] dyndbg: 6: DEBUG [ 88.376499] dyndbg: class[1]: nm:test_dynamic_debug base:12 len:3 ty:1 [ 88.376903] dyndbg: 0: ONE [ 88.377079] dyndbg: 1: TWO [ 88.377253] dyndbg: 2: THREE [ 88.377441] dyndbg: class[2]: nm:test_dynamic_debug base:8 len:3 ty:0 [ 88.377837] dyndbg: 0: bing [ 88.378022] dyndbg: 1: bong [ 88.378203] dyndbg: 2: boom [ 88.378387] dyndbg: class[3]: nm:test_dynamic_debug base:4 len:3 ty:0 [ 88.378800] dyndbg: 0: Foo [ 88.378986] dyndbg: 1: Bar [ 88.379167] dyndbg: 2: Buzz [ 88.379348] dyndbg: class[4]: nm:test_dynamic_debug base:0 len:3 ty:0 [ 88.379757] dyndbg: 0: FOO [ 88.379938] dyndbg: 1: BAR [ 88.380136] dyndbg: 2: BUZZ [ 88.380410] dyndbg: module:test_dynamic_debug attached 5 classes [ 88.380881] dyndbg: 24 debug prints in module test_dynamic_debug [ 88.381315] dyndbg: module: test_dynamic_debug dyndbg="class FOO +p" [ 88.381714] dyndbg: query 0: "class FOO +p" mod:test_dynamic_debug [ 88.382109] dyndbg: split into words: "class" "FOO" "+p" [ 88.382445] dyndbg: op='+' [ 88.382616] dyndbg: flags=0x1 [ 88.382802] dyndbg: *flagsp=0x1 *maskp=0x [ 88.383101] dyndbg: parsed: func="" file="" module="test_dynamic_debug" format="" lineno=0-0 class=FOO [ 88.383740] dyndbg: applied: func="" file="" module="test_dynamic_debug" format="" lineno=0-0 class=FOO [ 88.384324] dyndbg: processed 1 queries, with 2 matches, 0 errs bash-5.1# so its working at module-load time. > For the entire class approach, did you spot another subsystem that could > benefit from this and maybe make a more solid case that this is something > good? > I had been working on the premise that ~4k drm*dbg callsites was a good case. verbosity-levels - with x /sys/module/foo/parameters/debug_verbosity and effectively does echo < /proc/dynamic_debug/control module foo class V1 +p module foo class V2 +p module foo class V3 +p module foo class V4 -p module foo class V5 -p module foo class V6 -p module foo class V7 -p module foo class V8 -p EOQRY since only real +/-p changes incur kernel-patching costs, the remaining overheads are minimal. > RFC for DRM: > > - decoration flags "fmlt" do not work on drm_*dbg(). > (drm_*dbg() dont use pr_debug, they *become* one flavor of them) > this could (should?) be added, and maybe tailored for drm. > some of the device prefixes are very long, a "d" flag could optionalize them. I'm lost what the fmlt decoration
Re: [RFC PATCH v2 00/27] DRM.debug on DYNAMIC_DEBUG, add trace events
On Mon, May 16, 2022 at 04:56:13PM -0600, Jim Cromie wrote: > DRM.debug API is 23 macros, issuing 10 exclusive categories of debug > messages. By rough count, they are used 5140 times in the kernel. > These all call drm_dbg or drm_devdbg, which call drm_debug_enabled(), > which checks bits in global __drm_debug. Some of these are page-flips > and vblanks, and get called often. > > DYNAMIC_DEBUG (with CONFIG_JUMP_LABEL) is built to avoid this kind of > work, with NOOPd jump/callsites. > > This patchset is RFC because: > - it touches 2.5 subsystems: dyndbg, drm, tracefs (new events) > - dyndbg class support is built for drm, needs it for validation > - new api, used by drm > - big memory impact, with 5100 new pr-debug callsites. > - drm class bikeshedding opportunities > - others, names etc. Thanks a lot for keeping on pushing this! > > DYNAMIC_DEBUG: > > Adapt to directly represent 32 exclusive classes / categories. > All existing users get _CLASS_DFLT:31, reserving 0-30 for opt-in. > > dynamic_debug_register_classes(): Tells dyndbg that caller/client is > using .class_id's 0..N, and wants them exposed and manipulatable with > names: DRM_UT_KMS etc. > > Client invokes DYNAMIC_DEBUG_CLASSES to define the name->id map, > then registers it during its initialization. > > Then, when a dyndbg command-query has "class FOO": > > echo class DRM_UT_KMS +p > /proc/dynamic_debug/control > > ddebug_change() will 1st ddebug_validate_classname() for each module, > using its registered class-maps; only modules which know DRM_UT_KMS > will get those callsite adjustments. This "protects" each module's > class-id space, unlike "class 4" query syntax. > > Add bitmap support for: > echo 0x02 > /sys/module/drm/parameters/debug > > Add symbolic bitmap, because we have the class-names: > echo +DRM_UT_KMS,+DRM_UT_ATOMIC > /sys/module/drm/parameters/debug > > Add test_dynamic_debug, to prove out the API. > > which is (used 3x to prove class-id ranges): > - DYNAMIC_DEBUG_CLASSES(var, ... [3 class-name-literals each]) > - dynamic_debug_register_classes(var) > - dynamic_debug_unregister_classes(var) > also (6x): > +module_param_cb(, _ops_dyndbg_classes, > /[pt][123]_bitmap/, 0600); > > Bits 0,1,2 of each of the 6 bitmaps control the 3 named classes in > each of 3 groups, toggling their p,T bits respectively. > > RFC: > > dynamic_debug_register_classes() cannot act early enough to be in > effect at module-load. So this will not work as you'd reasonably > expect: > > modprobe test_dynamic_debug dyndbg='+pfm; class FOO +pfmlt' > > The 1st query:+pfm will be enabled during load, but in the 2nd query, > "class FOO" will be unknown at load time. Early class enablement > would be nice. DYNAMIC_DEBUG_CLASSES is a static initializer, which > is certainly early enough, but Im missing a trick, suggestions? So maybe I'm just totally overloading this work here so feel free to ignore or postpone, but: Could we do the dynamic_debug_register_classes() automatically at module load as a new special section? And then throw in a bit of kbuild so that in a given subsystem every driver gets the same class names by default and everything would just work, without having to sprinkle calls to dynamic_debug_register_classes() all over the place? That kbuild magic could then also insert all the boilerplate to make the module options work, or maybe you could push that all into the module loader and it would add these special options on its own (yay for more consistency across subsystems)? Also I think with that the early class stuff should be possible to fix, since you can make sure that the classes are all there (in the module loader code) before anything else gets done. A bit a special case but oh well. For the entire class approach, did you spot another subsystem that could benefit from this and maybe make a more solid case that this is something good? > Wildcarding on classname is possible, maybe useful: > >echo +DRM_UT_\* > /sys/module/drm/parameters/debug > > If contemplated in earnest, it should consider the difference between > "DRM_*" and "*_KMS", wrt observing across class hierarchies, as well > as decide whether that echo means 1st match, or all matching names. > > __pr_debug_cls(cls, fmt,...) is just for testing, drm doesnt need it. > > > DRM adaptation: > > Basically, these patches add another layer of macro indirection, which > by CONFIG_DRM_USE_DYNAMIC_DEBUG=y, wraps drm_*dbg() in dyndbg's callsite > Factory macro, and adds the new descriptor arg to the funcs. > > With these patches, drm.debugs appear as controllable *pr-dbg* callsites: > > [ 11.804352] dyndbg: register_classes: drm > [ 11.920715] dyndbg: 234 debug prints in module drm_kms_helper > [ 11.932135] dyndbg: 2 debug prints in module ttm > [ 11.936119] dyndbg: 8 debug prints in module video > [ 12.537543] dyndbg: 1756 debug prints in module i915 > [ 12.555045] dyndbg: register_classes: i915 > [ 12.666727]
[RFC PATCH v2 00/27] DRM.debug on DYNAMIC_DEBUG, add trace events
DRM.debug API is 23 macros, issuing 10 exclusive categories of debug messages. By rough count, they are used 5140 times in the kernel. These all call drm_dbg or drm_devdbg, which call drm_debug_enabled(), which checks bits in global __drm_debug. Some of these are page-flips and vblanks, and get called often. DYNAMIC_DEBUG (with CONFIG_JUMP_LABEL) is built to avoid this kind of work, with NOOPd jump/callsites. This patchset is RFC because: - it touches 2.5 subsystems: dyndbg, drm, tracefs (new events) - dyndbg class support is built for drm, needs it for validation - new api, used by drm - big memory impact, with 5100 new pr-debug callsites. - drm class bikeshedding opportunities - others, names etc. DYNAMIC_DEBUG: Adapt to directly represent 32 exclusive classes / categories. All existing users get _CLASS_DFLT:31, reserving 0-30 for opt-in. dynamic_debug_register_classes(): Tells dyndbg that caller/client is using .class_id's 0..N, and wants them exposed and manipulatable with names: DRM_UT_KMS etc. Client invokes DYNAMIC_DEBUG_CLASSES to define the name->id map, then registers it during its initialization. Then, when a dyndbg command-query has "class FOO": echo class DRM_UT_KMS +p > /proc/dynamic_debug/control ddebug_change() will 1st ddebug_validate_classname() for each module, using its registered class-maps; only modules which know DRM_UT_KMS will get those callsite adjustments. This "protects" each module's class-id space, unlike "class 4" query syntax. Add bitmap support for: echo 0x02 > /sys/module/drm/parameters/debug Add symbolic bitmap, because we have the class-names: echo +DRM_UT_KMS,+DRM_UT_ATOMIC > /sys/module/drm/parameters/debug Add test_dynamic_debug, to prove out the API. which is (used 3x to prove class-id ranges): - DYNAMIC_DEBUG_CLASSES(var, ... [3 class-name-literals each]) - dynamic_debug_register_classes(var) - dynamic_debug_unregister_classes(var) also (6x): +module_param_cb(, _ops_dyndbg_classes, /[pt][123]_bitmap/, 0600); Bits 0,1,2 of each of the 6 bitmaps control the 3 named classes in each of 3 groups, toggling their p,T bits respectively. RFC: dynamic_debug_register_classes() cannot act early enough to be in effect at module-load. So this will not work as you'd reasonably expect: modprobe test_dynamic_debug dyndbg='+pfm; class FOO +pfmlt' The 1st query:+pfm will be enabled during load, but in the 2nd query, "class FOO" will be unknown at load time. Early class enablement would be nice. DYNAMIC_DEBUG_CLASSES is a static initializer, which is certainly early enough, but Im missing a trick, suggestions? Wildcarding on classname is possible, maybe useful: echo +DRM_UT_\* > /sys/module/drm/parameters/debug If contemplated in earnest, it should consider the difference between "DRM_*" and "*_KMS", wrt observing across class hierarchies, as well as decide whether that echo means 1st match, or all matching names. __pr_debug_cls(cls, fmt,...) is just for testing, drm doesnt need it. DRM adaptation: Basically, these patches add another layer of macro indirection, which by CONFIG_DRM_USE_DYNAMIC_DEBUG=y, wraps drm_*dbg() in dyndbg's callsite Factory macro, and adds the new descriptor arg to the funcs. With these patches, drm.debugs appear as controllable *pr-dbg* callsites: [ 11.804352] dyndbg: register_classes: drm [ 11.920715] dyndbg: 234 debug prints in module drm_kms_helper [ 11.932135] dyndbg: 2 debug prints in module ttm [ 11.936119] dyndbg: 8 debug prints in module video [ 12.537543] dyndbg: 1756 debug prints in module i915 [ 12.555045] dyndbg: register_classes: i915 [ 12.666727] AMD-Vi: AMD IOMMUv2 functionality not available on this .. [ 13.735310] dyndbg: 3859 debug prints in module amdgpu amdgpu's large count includes: 582 direct uses/mentions of pr_debug 43 defns of DC_LOG_*, which use either pr_debug or DRM_DEBUG_* ~1000 uses of DC_LOG_* 1116 uses of dml_print in drivers/gpu/drm/amd 15 drm_dbg_\\w+ drivers/gpu/drm/amd 273 DRM_DEBUG_\\w+ drivers/gpu/drm/amd i915 has: 1072 drm_dbg_\\w+ drivers/gpu/drm/i915/ | wc -l 200 DRM_DEBUG_\\w+ drivers/gpu/drm/i915/ 46 pr_debug drivers/gpu/drm/i915/ 144 gvt_dbg_\\w+ drivers/gpu/drm/i915/gvt, using pr_debug This impacts the data footprint, so everything new/drm is dependent on DRM_USE_DYNAMIC_DEBUG=y. RFC for DRM: - decoration flags "fmlt" do not work on drm_*dbg(). (drm_*dbg() dont use pr_debug, they *become* one flavor of them) this could (should?) be added, and maybe tailored for drm. some of the device prefixes are very long, a "d" flag could optionalize them. - api use needs review wrt drm life-cycle. enum drm_debug_category and DYNAMIC_DEBUG_CLASSES could be together? - class-names could stand review, perhaps extension "drm:core:" etc have appeared (maybe just from me) or a "plan" to look at it later - i915 & amdgpu have pr_debugs (DC_LOG_*, gvt_dbg_*) that have class-ish prefixes that are
