Jim Cromie
2022-Jul-18 06:37 UTC
[Nouveau] [PATCH v3 00/41] DYNDBG: opt-in class'd debug for modules, use in drm.
To: jbaron at akamai.com>,gregkh at linuxfounation.org CC: intel-gfx at lists.freedesktop.org,nouveau at lists.freedesktop.org,dri-devel at lists.freedesktop.org Add 'typed' "class FOO" support to dynamic-debug, where 'typed' means either DISJOINT (like drm debug categories), or VERBOSE (like nouveau debug-levels). Use it in DRM modules: core, helpers, and in drivers i915, amdgpu, nouveau. If a module is using class'd prdbgs (pr_debug_class, dev_dbg_class, or adapted drm_dbg_<category>) or similar in its code, it can "opt in" to allow dyndbg to manipulate those class'd prdebugs, by declaring in a c-file: DYNAMIC_DEBUG_CLASSMAP_TYPE(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, "DRM_UT_CORE", "DRM_UT_DRIVER", "DRM_UT_KMS", "DRM_UT_PRIME", "DRM_UT_ATOMIC", "DRM_UT_VBL", "DRM_UT_STATE", "DRM_UT_LEASE", "DRM_UT_DP", "DRM_UT_DRMRES"); // todo: stringify __va_args inside the macro By doing this, a module tells dyndbg that it: - is using class-ids [0..N] in prdbg callsites 0..N is also the numeric values of DRM_UT_CORE..DRM_UT_DRMRES - wants to refer to them by class-names [0..N] - is mapping those names to those class-ids - expects users to enable them via >control or >parameter/knob Then, a user can enable the prdbgs by their class: :#> echo class DRM_UT_KMS +p > /proc/dynamic_debug/control With another 3-line bitmap param declaration, wrapping that drm_debug_classes var in a module-param-cb: :#> echo 0x1 > /sys/module/drm/parameters/debug and optionally: :#> echo +DRM_UT_CORE,-DRM_UT_KMS \ > /sys/module/drm/parameters/debug_cats DYNAMIC_DEBUG gets: new .class_id:5 field in struct _ddebug (callsite record) big enough to represent drm_debug_category (after squeezing) defaults to 31 for all existing prdbgs classmaps (as declared in macro above) are in their own section, and are loaded by kernel/module, and handled by add_module, which attaches classmaps to their module's ddebug table. ddebug_change() handles class FOO queries by validating theyre known by each module in the loop, if unknown, the whole module is skipped, so no changes are possible w/o a good classname. Without class FOO in a query/command, only id=31 can be changed. This protects new class'd prdbgs from changes by old user queries. With this support, the module opt-in approach means that: - modules declare classnames they like, meaningful names, DRM_UT_* these are numbered [0..N] - modules call pr_debug_class(N, "fmt..",...) or drm_dbg(CAT, "fmt..",...) - same form. - class-id space, while limited:0-30, is private to each module - "class FOO" is only way to enable a class'd prdbg - unrelated modules use 0..N separately, for different purposes. - modules "share" classnames by separate decls (uses of macro) all drm modules reuse the above declaration. then they respond together to a >control 4 CLASS_TYPES are defined; they split behavior on 2 factors: 1. independent bits vs related:(X<Y) bits [0-N] 2. input form: number/hex vs CSV-list: [+-]CLASS_NAMES DD_CLASS_TYPE_DISJOINT independent bits, 0x1f input is clearest DD_CLASS_TYPE_VERBOSE (x<y), input is level, not bitvec DD_CLASS_TYPE_SYMBOLIC DISJOINT with csv-list of +-CLASS_NAMEs DD_CLASS_TYPE_LEVELS VERBOSE with csv-list of +-CLASS_NAMEs Splitting up behavior this way is safe, and flexible: - no bitmap-vs-level > sysknob ambiguity as was case when both were accepted on same knob - narrower interfaces uint is uint - can defer SYMBOLIC handling, but keep the enums. it has no users ... - can later add 2 more ENUMS allowing both inputs in separate VERBOSE & DISJOINT choices then authors choice if they want to accept mixed input - can enumerate "wierd" relations if needed DISJOINT|VERBOSE should cover everything I can forsee but theres room for DD_CLASS_TYPE_STOCHASTIC (over the garage) NB: DISJOINT v RELATED cover the space; there is no semi-related. The relation could differ from (x<y), but atm I can't think of another that makes any sensible distinction from VERBOSE. Quick review of debug logging: DRM is biggest use-case: 23 macros, issuing 10 exclusive categories of messages, from ~5100 callsites, across core (drm, _*helpers), and 3+ drivers (Im working amdgpu, i915, more recently nouveau). These mostly flow to drm_debug_enabled(category) for a print/no decision. nouveau has minimum direct use of the DRM.debug macros, but does use pr_debug (in VMM iirc), and drm_debug_enabled() in ~50 places via macros, and another ~50 iirc due to NOUVEAU_DEBUG_MMU=y What nouveau has most of is log-levels: there are ~800 uses of them; nvkm_(fatal|error|warn|info|debug|trace|spam), they all flow thru nvkm_printk_. Even excluding some levels as "always-on" and not appropriate for dyndbg's extra resources and complexity, theres ~450 callsites. A reported smattering of raw/adhoc debug code. all but unknown to me. Like any debug logging, they're mostly off, and should have close to 0-off-cost. This is what dyndbg (with/on jump-label) was made for. Bottom line: in order to unify more potential (drm,etc) use-cases, dyndbg needs to support both debug classification schemes: RELATED/VERBOSE and INDEPENDENT/DISJOINT. This is rev3. rev2 is here: https://lore.kernel.org/lkml/20220516225640.3102269-1-jim.cromie at gmail.com/ summary of diffs: - rebased on 5.19-rc6 to pick up kernel/module changes - tracfs bits now use __vstring, __vstr_assign, from S.Rostedt - 4 class-map-types - as outlined above now supports VERBOSE semantics, WIP nouveau integration. v2 became the DISJOINT use case Lots of API-ish surface area here *RFC* - class-maps now in section("__dyndbg_classes") class FOO queries are available at earlyboot / module-load drop (un)?register_classes() - test-dynamic-debug module tests the 4 CLASS-TYPES good place to bikeshed / paintshop the API - nouveau - start poking - WIP NV_PRINT -> dev_dbg (creates 632 prdbgs, but not class'd) VERBOSE classes declared to see how they "fit", unused yet. Summary: - plenty of new stuff here. - plenty of new API surface area. - exposes CLASSNAMES to user, via control, >symbolic-sysknob More on VERBOSE: dyndbg's class scheme is names-based, so even for VERBOSE with numeric input, there must be a "V0" name; a name with which to turn off "V1". And don't do 'pr_dbg_class(0,..)'. VERBOSE is an overlay on DISJOINT; the callback reads the input as a level, and computes and applies the bitmap to enforce it. Yes it wastes "V0" bit. That might matter if an author wanted many separate verbose-knobs with a few levels each, but that seems fairly unlikely. More importantly, it means that relative verbosity is not enforced at the >control input; IOW this is allowed: :#> echo class V1 -p > /proc/dynamic_debug/control :#> echo class V3 +p > /proc/dynamic_debug/control 2nd line doesn't undo 1st, as it would if changed via sysfs-knob: :#> echo 3 > /sys/module/drm/parameters/debug ISTM this is fine, the "relative" meaning is added at the interface, where it presents to a user. Doing otherwise means surgery to ddebug_change, which seems unnecessary given an option. CLASS NAMESPACE and DRM The class namespace is flat and wide, so "V1" is a poor choice, other than for demonstration (as in test_dynamic_debug module). If every module had a "V1", turning them all on would issue lots of unrelated noise. Instead, class DRM_UT_CORE has a name with a specific sub-system wide (ie multi-module) meaning, and can (and should) be responded to by all cooperating modules. For DRM, this means 4-5 duplicate uses of DEFINE_DYNDBG_CLASSMAP, from multiple drivers' "*_{drm,dev,main}.c" files; all of them agreeing on the classnames, map-type and base. Though repetitive, it is simple, and consistent with the "static struct foo = {INIT_expr}" pattern used in the macro. Initializing an extern sounded like a maze w/o cheese. For core, drm_print.c has an additional task; it defines and initializes the bitmap sysknob that converts bits to a query: static struct ddebug_classes_bitmap_param drm_debug_bitmap = { .bits = &__drm_debug, .flags = "p", .map = &drm_debug_classes, }; module_param_cb(debug, ¶m_ops_dyndbg_classes, &drm_debug_bitmap, 0600); then the callback converts bit-toggles on input into something like: :#> echo class DRM_UT_KMS +p > control which enables all drm_dbg_kms() callsites in all modules that declared that classname as known. NB: classmaps and classes_bitmap_params are different structs. this allows the former to be shared by 2 of latter, each toggling 'p' & 'T' flags, to control output to syslog or tracelog independently. NOUVEAU and multiple VERBOSE knobs ? One thing nouveau has that I havent yet grokked is 2|3 independent verbose levels, in {,cli,sub}->debug (see subdev.h). But Ive coded them as 2 more macro invocations; using bases 10, 15 to avoid/respect the 0-9 mapping of DRM.debug categories to those class-ids. With this, the drm subsystem uses 20/31 of its class-id range, perhaps 63 is better, despite the cumbersome 0x-64bit interface. Note that the sysfs-knobs do not expose the base/offset (its an inward-facing .class_id offset); each sysfs-knob gets its own 0..N bitmap, the base maps it to the 0..30 subrange allocated (manually, via the base arg to macro) for this class-map. anyway, heres how `modprobe nouveau` goes with dynamic_debug.verbose=3 [86512.693954] dyndbg: class[0]: module:nouveau base:15 len:5 ty:1 [86512.693958] dyndbg: 15: 0 NV_SUBDEV_DBG_OFF # aka V0 [86512.693959] dyndbg: 16: 1 NV_SUBDEV_DBG_INFO [86512.693960] dyndbg: 17: 2 NV_SUBDEV_DBG_DEBUG [86512.693960] dyndbg: 18: 3 NV_SUBDEV_DBG_TRACE [86512.693960] dyndbg: 19: 4 NV_SUBDEV_DBG_SPAM [86512.693961] dyndbg: class[1]: module:nouveau base:10 len:5 ty:1 [86512.693961] dyndbg: 10: 0 NV_CLI_DBG_OFF [86512.693962] dyndbg: 11: 1 NV_CLI_DBG_INFO [86512.693962] dyndbg: 12: 2 NV_CLI_DBG_DEBUG [86512.693963] dyndbg: 13: 3 NV_CLI_DBG_TRACE [86512.693963] dyndbg: 14: 4 NV_CLI_DBG_SPAM [86512.693963] dyndbg: class[2]: module:nouveau base:0 len:10 ty:0 [86512.693964] dyndbg: 0: 0 DRM_UT_CORE [86512.693964] dyndbg: 1: 1 DRM_UT_DRIVER [86512.693965] dyndbg: 2: 2 DRM_UT_KMS [86512.693965] dyndbg: 3: 3 DRM_UT_PRIME [86512.693965] dyndbg: 4: 4 DRM_UT_ATOMIC [86512.693966] dyndbg: 5: 5 DRM_UT_VBL [86512.693966] dyndbg: 6: 6 DRM_UT_STATE [86512.693966] dyndbg: 7: 7 DRM_UT_LEASE [86512.693967] dyndbg: 8: 8 DRM_UT_DP [86512.693967] dyndbg: 9: 9 DRM_UT_DRMRES [86512.693968] dyndbg: module:nouveau attached 3 classes [86512.693968] dyndbg: 632 debug prints in module nouveau They are not yet wired by class; the nv-printks are using dev_dbg for now, so they can be enabled with standard selections (module, func, etc). DYNDBG API I added __pr_debug_cls to make things testable, I wanted to keep it private/un-api, because drm already has drm_dbg_<cat>(cat, fmt..), and that seemed a pretty good model to follow: enums with strong names for class_id constants, and same names for classes. ie: __pr_debug_cls(DRM_UT_KMS, "Whats the Matter with KMS: %s\n", reason); But now nouveau probably wants/needs it, perhaps others too. pr_dbg_cls / dev_dbg_cls ? class or debug spelled out ? MORE TESTING with DRM & TRACEFS Most dev & testing has been on virtme, with test-dynamic-debug module doing an api-validation-demonstration. The test module proves multiple sysknobs, but cannot prove real multi-module sharing of the class-name space. The DRM.debug adaptation must (and does) do that. Now Im running on real gpu/drm hw; on both an amdgpu desktop, and this amdgpu+nouveau laptop. Its stable enough to type on, browse, build more kernels, etc. :#> uname -r 5.18.0-f2-00038-g61d300083196 :#> wc /proc/dynamic_debug/control 11554 95556 1442827 /proc/dynamic_debug/control :#> lsmod | grep drm drm_buddy 20480 1 i915 drm_ttm_helper 16384 2 amdgpu,nouveau ttm 86016 4 amdgpu,drm_ttm_helper,i915,nouveau drm_dp_helper 184320 3 amdgpu,i915,nouveau drm_kms_helper 208896 6 drm_dp_helper,amdgpu,i915,nouveau drm 655360 16 gpu_sched,drm_dp_helper,drm_kms_helper,drm_buddy,amdgpu,drm_ttm_helper,i915,ttm,nouveau cec 49152 2 drm_dp_helper,i915 I've never turned on DRM.debug in frustration (or curiousity until recently); I dunno what normal traffic looks like. So I wrote a script to toggle each category: on/off for 1 sec, so I could 'more' thru the output to see the partitioned streams. Different runs (of '10' sec of active tracing) produce between 330-3500 lines of logging, depending upon mousing/screen activity. Heres a bit of a many-window-select run: `wc trace` gives "size" of the category's stream. :#> trc_classes 12 /sys/kernel/tracing/trace doing class DRM_UT_CORE +/- T 1394 13941 141614 /sys/kernel/tracing/trace doing class DRM_UT_DRIVER +/- T 1396 13959 141816 /sys/kernel/tracing/trace doing class DRM_UT_KMS +/- T 1482 14521 148246 /sys/kernel/tracing/trace doing class DRM_UT_PRIME +/- T 1484 14539 148446 /sys/kernel/tracing/trace doing class DRM_UT_ATOMIC +/- T 2984 31658 396064 /sys/kernel/tracing/trace doing class DRM_UT_VBL +/- T 3411 37321 449848 /sys/kernel/tracing/trace doing class DRM_UT_STATE +/- T 3413 37339 450048 /sys/kernel/tracing/trace doing class DRM_UT_LEASE +/- T 3415 37357 450248 /sys/kernel/tracing/trace doing class DRM_UT_DP +/- T 3417 37375 450442 /sys/kernel/tracing/trace doing class DRM_UT_DRMRES +/- T 3419 37393 450644 /sys/kernel/tracing/trace and some mid-run output from a quiet run, with less repetition. bash-96790 [006] ..... 410237.432255: tracing_mark_write: doing class DRM_UT_DRIVER +T bash-96790 [006] ..... 410238.610319: tracing_mark_write: doing class DRM_UT_DRIVER -T bash-96790 [006] ..... 410239.776285: tracing_mark_write: doing class DRM_UT_KMS +T gnome-shell-2101 [003] ..... 410239.923029: drm_debug: [FB:98] kworker/u32:10-367584 [010] ..... 410239.924627: drm_debug: Allow idle optimizations (MALL): 0 kworker/u32:0-364714 [008] ..... 410239.935126: drm_debug: Allow idle optimizations (MALL): 1 gnome-shell-2101 [003] ..... 410240.527186: drm_debug: [FB:100] kworker/u32:0-364714 [008] ..... 410240.528686: drm_debug: Allow idle optimizations (MALL): 0 kworker/u32:10-367584 [010] ..... 410240.539378: drm_debug: Allow idle optimizations (MALL): 1 bash-96790 [006] ..... 410240.957921: tracing_mark_write: doing class DRM_UT_KMS -T bash-96790 [006] ..... 410242.199120: tracing_mark_write: doing class DRM_UT_PRIME +T bash-96790 [006] ..... 410243.301988: tracing_mark_write: doing class DRM_UT_PRIME -T bash-96790 [006] ..... 410244.416400: tracing_mark_write: doing class DRM_UT_ATOMIC +T gnome-shell-2101 [003] ..... 410244.653372: drm_devdbg: cat:4, (0xffff8f26c173de00:0000:06:00.0)[UNSAFE-MEMORY] Allocated atomic state 000000001f1e6cb6 gnome-shell-2101 [003] ..... 410244.653381: drm_devdbg: cat:4, (0xffff8f26c173de00:0000:06:00.0)[UNSAFE-MEMORY] Added [PLANE:55:plane-3] 00000000785ae904 state to 000000001f1e6cb6 gnome-shell-2101 [003] ..... 410244.653384: drm_devdbg: cat:4, (0xffff8f26c173de00:0000:06:00.0)[UNSAFE-MEMORY] Added [CRTC:67:crtc-0] 00000000b06ca618 state to 000000001f1e6cb6 gnome-shell-2101 [003] ..... 410244.653389: drm_devdbg: cat:4, (0xffff8f26c173de00:0000:06:00.0)[UNSAFE-MEMORY] Set [FB:98] for [PLANE:55:plane-3] state 00000000785ae904 gnome-shell-2101 [003] ..... 410244.653392: drm_devdbg: cat:4, (0xffff8f26c173de00:0000:06:00.0)[UNSAFE-MEMORY] checking 000000001f1e6cb6 gnome-shell-2101 [003] ..... 410244.653407: drm_devdbg: cat:4, (0xffff8f26c173de00:0000:06:00.0)[UNSAFE-MEMORY] committing 000000001f1e6cb6 nonblocking kworker/u32:0-364714 [010] ..... 410244.653729: drm_debug: amdgpu_crtc id:0 crtc_state_flags: enable:1, active:1, planes_changed:1, mode_changed:0,active_changed:0,connectors_changed:0 kworker/u32:0-364714 [010] ..... 410244.654642: drm_debug: plane: id=3 dcc_en=0 a few things to note in the trace output: . the event-name: drm_(debug|devdbg) is not very informative . drm_devdbg fmt has cat:%d, it could be the classname, but that should replace event-name, not supplement it. this pertains to drm_debug too. . drm_devdbg has lots of (dev-info), that could be optional on a new flag(s) If anyone wants to repeat the above with the patchset, the .rc file follows: events_3() { local a=$1 local b=$2 local c=$3 echo $a > /sys/kernel/tracing/events/dyndbg/enable # avoid drm_vblank*, its noisy echo $b > /sys/kernel/tracing/events/drm/drm_debug/enable echo $c > /sys/kernel/tracing/events/drm/drm_devdbg/enable } flags_class() { local flgs=$1; local cls=$2; echo class $cls $flgs > /proc/dynamic_debug/control } # turn on each DRM_UT_* for 1 second each. # kinda shows relative traffic of each category # separated into blocks to get flavor of each drm_classes() { local flgs=$1 [ -z $flgs ] && flgs="p" #echo > /sys/kernel/tracing/trace #wc /sys/kernel/tracing/trace for cls in DRM_UT_CORE DRM_UT_DRIVER DRM_UT_KMS DRM_UT_PRIME DRM_UT_ATOMIC \ DRM_UT_VBL DRM_UT_STATE DRM_UT_LEASE DRM_UT_DP \ DRM_UT_DRMRES; do echo -n doing class $cls " " echo doing class $cls +$flgs sleep .1 flags_class +$flgs $cls sleep 1 echo doing class $cls -$flgs sleep .1 flags_class -$flgs $cls sleep 1 #wc /sys/kernel/tracing/trace done } # like above but with T flag, and markers, trace/enable trc_classes() { local flgs=$1 [ -z $flgs ] && flgs="T" echo > /sys/kernel/tracing/trace wc -l /sys/kernel/tracing/trace events_3 1 1 1 for cls in DRM_UT_CORE DRM_UT_DRIVER DRM_UT_KMS DRM_UT_PRIME \ DRM_UT_ATOMIC \ DRM_UT_VBL DRM_UT_STATE DRM_UT_LEASE DRM_UT_DP \ DRM_UT_DRMRES; do echo -n doing class $cls +/- $flgs " " echo doing class $cls +$flgs > /sys/kernel/tracing/trace_marker sleep .1 flags_class +$flgs $cls sleep 1 echo doing class $cls -$flgs > /sys/kernel/tracing/trace_marker sleep .1 flags_class -$flgs $cls sleep 1 wc /sys/kernel/tracing/trace done events_3 0 0 0 } I ignored a few checkpatch warns, preferring source's spacing conventions. Jim Cromie (40): 1st, a group of "cleanups" dyndbg: fix static_branch manipulation dyndbg: fix module.dyndbg handling dyndbg: show both old and new in change-info dyndbg: reverse module walk in cat control dyndbg: reverse module.callsite walk in cat control dyndbg: use ESCAPE_SPACE for cat control dyndbg: let query-modname override actual module name dyndbg: add test_dynamic_debug module dyndbg: drop EXPORTed dynamic_debug_exec_queries class FOO support dyndbg: add class_id to pr_debug callsites dyndbg: add __pr_debug_cls for testing dyndbg: add DECLARE_DYNDBG_CLASSMAP kernel/module: add __dyndbg_classes section dyndbg: add ddebug_attach_module_classes dyndbg: validate class FOO by checking with module dyndbg: add drm.debug style bitmap support dyndbg: test DECLARE_DYNDBG_CLASSMAP, sysfs nodes doc-dyndbg: describe "class CLASS_NAME" query support doc-dyndbg: edit dynamic-debug-howto for brevity, audience drm.debug adaptation 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: add drm_dbg_driver to improve namespace symmetry drm-print: include dyndbg header indirectly drm_print: refine 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 nouveau: change nvkm_debug/trace to use dev_dbg POC Steven Rostedt (Google) (1): tracing/events: Add __vstring() and __assign_vstr() helper macros new tracefs events: dyndbg: add _DPRINTK_FLAGS_ENABLED dyndbg: add _DPRINTK_FLAGS_TRACE dyndbg: add write-events-to-tracefs code dyndbg: add 2 trace-events: drm_{,dev}debug dyndbg: add 2 more trace-events: pr_debug, dev_dbg dyndbg/drm: POC add tracebits sysfs-knob nouveau-VERBOSE integration: WIP/exploratory. nouveau: adapt NV_DEBUG, NV_ATOMIC to use DRM.debug nouveau-dyndbg: alter DEBUG, TRACE, SPAM levels to use dyndbg nouveau-dbg: add 2 verbose-classmaps for CLI, SUBDEV nouveau-dbg: fixup lost prdbgs nouveau-dyndbg: wip subdev refine, breaks on use .../admin-guide/dynamic-debug-howto.rst | 252 ++++---- MAINTAINERS | 2 + 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 | 83 ++- drivers/gpu/drm/i915/i915_params.c | 12 + .../gpu/drm/nouveau/include/nvkm/core/debug.h | 16 + .../drm/nouveau/include/nvkm/core/subdev.h | 17 +- drivers/gpu/drm/nouveau/nouveau_drm.c | 20 + drivers/gpu/drm/nouveau/nouveau_drv.h | 16 +- drivers/gpu/drm/nouveau/nvkm/core/subdev.c | 23 + include/asm-generic/vmlinux.lds.h | 3 + include/drm/drm_print.h | 85 ++- include/linux/dynamic_debug.h | 179 +++++- include/linux/trace_events.h | 18 + include/trace/events/drm.h | 54 ++ include/trace/events/dyndbg.h | 74 +++ include/trace/stages/stage1_struct_define.h | 3 + include/trace/stages/stage2_data_offsets.h | 3 + include/trace/stages/stage4_event_fields.h | 3 + include/trace/stages/stage5_get_offsets.h | 4 + include/trace/stages/stage6_event_callback.h | 7 + kernel/module/internal.h | 2 + kernel/module/main.c | 10 +- lib/Kconfig.debug | 10 + lib/Makefile | 1 + lib/dynamic_debug.c | 540 +++++++++++++++--- lib/test_dynamic_debug.c | 165 ++++++ 31 files changed, 1374 insertions(+), 282 deletions(-) create mode 100644 include/trace/events/drm.h create mode 100644 include/trace/events/dyndbg.h create mode 100644 lib/test_dynamic_debug.c -- 2.36.1
Jim Cromie
2022-Jul-18 06:37 UTC
[Nouveau] [PATCH v3 01/41] dyndbg: fix static_branch manipulation
In https://lore.kernel.org/lkml/20211209150910.GA23668 at axis.com/ Vincent's patch commented on, and worked around, a bug toggling static_branch's, when a 2nd PRINTK-ish flag was added. The bug results in a premature static_branch_disable when the 1st of 2 flags was disabled. The cited commit computed newflags, but then in the JUMP_LABEL block, failed to use that result, instead using just one of the terms in it. Using newflags instead made the code work properly. This is Vincents test-case, reduced. It needs the 2nd flag to demonstrate the bug, but it's explanatory here. pt_test() { echo 5 > /sys/module/dynamic_debug/verbose site="module tcp" # just one callsite echo " $site =_ " > /proc/dynamic_debug/control # clear it # A B ~A ~B for flg in +T +p "-T #broke here" -p; do echo " $site $flg " > /proc/dynamic_debug/control done; # A B ~B ~A for flg in +T +p "-p #broke here" -T; do echo " $site $flg " > /proc/dynamic_debug/control done } pt_test Fixes: 84da83a6ffc0 dyndbg: combine flags & mask into a struct, simplify with it CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> Acked-by: Jason Baron <jbaron at akamai.com> --- .drop @stable, no exposed bug. .add jbaron ack --- lib/dynamic_debug.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index dd7f56af9aed..a56c1286ffa4 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -211,10 +211,11 @@ static int ddebug_change(const struct ddebug_query *query, continue; #ifdef CONFIG_JUMP_LABEL if (dp->flags & _DPRINTK_FLAGS_PRINT) { - if (!(modifiers->flags & _DPRINTK_FLAGS_PRINT)) + if (!(newflags & _DPRINTK_FLAGS_PRINT)) static_branch_disable(&dp->key.dd_key_true); - } else if (modifiers->flags & _DPRINTK_FLAGS_PRINT) + } else if (newflags & _DPRINTK_FLAGS_PRINT) { static_branch_enable(&dp->key.dd_key_true); + } #endif dp->flags = newflags; v4pr_info("changed %s:%d [%s]%s =%s\n", -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 02/41] dyndbg: fix module.dyndbg handling
For CONFIG_DYNAMIC_DEBUG=N, the ddebug_dyndbg_module_param_cb() stub-fn is too permissive: bash-5.1# modprobe drm JUNKdyndbg bash-5.1# modprobe drm dyndbgJUNK [ 42.933220] dyndbg param is supported only in CONFIG_DYNAMIC_DEBUG builds [ 42.937484] ACPI: bus type drm_connector registered This caused no ill effects, because unknown parameters are either ignored by default (with an "unknown parameter" warning, see below), or ignored because dyndbg allows its no-effect use on non-dyndbg builds. But since the code has an explicit feedback message, it should be issued accurately. Fix with strcmp for exact param-name match. Reported-by: Rasmus Villemoes <linux at rasmusvillemoes.dk> Fixes: b48420c1d301 dynamic_debug: make dynamic-debug work for module initialization Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index dce631e678dd..f30b01aa9fa4 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -201,7 +201,7 @@ static inline int ddebug_remove_module(const char *mod) static inline int ddebug_dyndbg_module_param_cb(char *param, char *val, const char *modname) { - if (strstr(param, "dyndbg")) { + if (!strcmp(param, "dyndbg")) { /* avoid pr_warn(), which wants pr_fmt() fully defined */ printk(KERN_WARNING "dyndbg param is supported only in " "CONFIG_DYNAMIC_DEBUG builds\n"); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 03/41] dyndbg: show both old and new in change-info
print "old => new" flag values to the info("change") message. no functional change. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index a56c1286ffa4..8faf584f2f4b 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -156,7 +156,7 @@ static int ddebug_change(const struct ddebug_query *query, struct ddebug_table *dt; unsigned int newflags; unsigned int nfound = 0; - struct flagsbuf fbuf; + struct flagsbuf fbuf, nbuf; /* search for matching ddebugs */ mutex_lock(&ddebug_lock); @@ -217,11 +217,12 @@ static int ddebug_change(const struct ddebug_query *query, static_branch_enable(&dp->key.dd_key_true); } #endif + v4pr_info("changed %s:%d [%s]%s %s => %s\n", + trim_prefix(dp->filename), dp->lineno, + dt->mod_name, dp->function, + ddebug_describe_flags(dp->flags, &fbuf), + ddebug_describe_flags(newflags, &nbuf)); dp->flags = newflags; - v4pr_info("changed %s:%d [%s]%s =%s\n", - trim_prefix(dp->filename), dp->lineno, - dt->mod_name, dp->function, - ddebug_describe_flags(dp->flags, &fbuf)); } } mutex_unlock(&ddebug_lock); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 04/41] dyndbg: reverse module walk in cat control
/proc/dynamic_debug/control walks the prdbg catalog in "reverse", fix this by adding new ddebug_tables to tail of list. This puts init/main.c entries 1st, which looks intentional. no functional changes. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 8faf584f2f4b..7fb99492c16f 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -970,7 +970,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n, dt->ddebugs = tab; mutex_lock(&ddebug_lock); - list_add(&dt->link, &ddebug_tables); + list_add_tail(&dt->link, &ddebug_tables); mutex_unlock(&ddebug_lock); vpr_info("%3u debug prints in module %s\n", n, dt->mod_name); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 05/41] dyndbg: reverse module.callsite walk in cat control
Walk the module's vector of callsites backwards; ie N..0. This "corrects" the backwards appearance of a module's prdbg vector when walked 0..N. I think this is due to linker mechanics, which I'm inclined to treat as immutable, and the order is fixable in display. No functional changes. Combined with previous commit, which reversed tables-list, we get: :#> head -n7 /proc/dynamic_debug/control # filename:lineno [module]function flags format init/main.c:1179 [main]initcall_blacklist =_ "blacklisting initcall %s\012" init/main.c:1218 [main]initcall_blacklisted =_ "initcall %s blacklisted\012" init/main.c:1424 [main]run_init_process =_ " with arguments:\012" init/main.c:1426 [main]run_init_process =_ " %s\012" init/main.c:1427 [main]run_init_process =_ " with environment:\012" init/main.c:1429 [main]run_init_process =_ " %s\012" Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 7fb99492c16f..8ff11977b8bd 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -59,7 +59,7 @@ struct ddebug_query { struct ddebug_iter { struct ddebug_table *table; - unsigned int idx; + int idx; }; struct flag_settings { @@ -805,13 +805,12 @@ static struct _ddebug *ddebug_iter_first(struct ddebug_iter *iter) { if (list_empty(&ddebug_tables)) { iter->table = NULL; - iter->idx = 0; return NULL; } iter->table = list_entry(ddebug_tables.next, struct ddebug_table, link); - iter->idx = 0; - return &iter->table->ddebugs[iter->idx]; + iter->idx = iter->table->num_ddebugs; + return &iter->table->ddebugs[--iter->idx]; } /* @@ -824,15 +823,16 @@ static struct _ddebug *ddebug_iter_next(struct ddebug_iter *iter) { if (iter->table == NULL) return NULL; - if (++iter->idx == iter->table->num_ddebugs) { + if (--iter->idx < 0) { /* iterate to next table */ - iter->idx = 0; if (list_is_last(&iter->table->link, &ddebug_tables)) { iter->table = NULL; return NULL; } iter->table = list_entry(iter->table->link.next, struct ddebug_table, link); + iter->idx = iter->table->num_ddebugs; + --iter->idx; } return &iter->table->ddebugs[iter->idx]; } -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 06/41] dyndbg: use ESCAPE_SPACE for cat control
`cat control` currently does octal escape, so '\n' becomes "\012". Change this to display as "\n" instead, which reads much cleaner. :#> head -n7 /proc/dynamic_debug/control # filename:lineno [module]function flags format init/main.c:1179 [main]initcall_blacklist =_ "blacklisting initcall %s\n" init/main.c:1218 [main]initcall_blacklisted =_ "initcall %s blacklisted\n" init/main.c:1424 [main]run_init_process =_ " with arguments:\n" init/main.c:1426 [main]run_init_process =_ " %s\n" init/main.c:1427 [main]run_init_process =_ " with environment:\n" init/main.c:1429 [main]run_init_process =_ " %s\n" Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 8ff11977b8bd..e5cbe603000c 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -900,7 +900,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p) trim_prefix(dp->filename), dp->lineno, iter->table->mod_name, dp->function, ddebug_describe_flags(dp->flags, &flags)); - seq_escape(m, dp->format, "\t\r\n\""); + seq_escape_str(m, dp->format, ESCAPE_SPACE, "\t\r\n\""); seq_puts(m, "\"\n"); return 0; -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 07/41] dyndbg: let query-modname override actual module name
dyndbg's control-parser: ddebug_parse_query(), requires that search terms: module, func, file, lineno, are used only once in a query; a thing cannot be named both foo and bar. The cited commit added an overriding module modname, taken from the module loader, which is authoritative. So it set query.module 1st, which disallowed its use in the query-string. But now, its useful to allow a module-load to enable classes across a whole (or part of) a subsystem at once. # enable (dynamic-debug in) drm only modprobe drm dyndbg="class DRM_UT_CORE +p" # get drm_helper too modprobe drm dyndbg="class DRM_UT_CORE module drm* +p" # get everything that knows DRM_UT_CORE modprobe drm dyndbg="class DRM_UT_CORE module * +p" # also for boot-args: drm.dyndbg="class DRM_UT_CORE module * +p" So convert the override into a default, by filling it only when/after the query-string omitted the module. NB: the query class FOO handling is forthcoming. Fixes: 8e59b5cfb9a6 dynamic_debug: add modname arg to exec_query callchain Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index e5cbe603000c..5a849716220a 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -385,10 +385,6 @@ static int ddebug_parse_query(char *words[], int nwords, return -EINVAL; } - if (modname) - /* support $modname.dyndbg=<multiple queries> */ - query->module = modname; - for (i = 0; i < nwords; i += 2) { char *keyword = words[i]; char *arg = words[i+1]; @@ -429,6 +425,13 @@ static int ddebug_parse_query(char *words[], int nwords, if (rc) return rc; } + if (!query->module && modname) + /* + * support $modname.dyndbg=<multiple queries>, when + * not given in the query itself + */ + query->module = modname; + vpr_info_dq(query, "parsed"); return 0; } -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 08/41] dyndbg: add test_dynamic_debug module
Provide a simple module to allow testing DYNAMIC_DEBUG behavior. It calls do_prints() from module-init, and with a sysfs-node. dmesg -C dmesg -w & modprobe test_dynamic_debug dyndbg=+p echo 1 > /sys/module/dynamic_debug/parameters/verbose cat /sys/module/test_dynamic_debug/parameters/do_prints echo module test_dynamic_debug +mftl > /proc/dynamic_debug/control echo junk > /sys/module/test_dynamic_debug/parameters/do_prints Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- MAINTAINERS | 2 ++ lib/Kconfig.debug | 10 ++++++ lib/Makefile | 1 + lib/test_dynamic_debug.c | 70 ++++++++++++++++++++++++++++++++++++++++ 4 files changed, 83 insertions(+) create mode 100644 lib/test_dynamic_debug.c diff --git a/MAINTAINERS b/MAINTAINERS index f679152bdbad..663307268285 100644 --- a/MAINTAINERS +++ b/MAINTAINERS @@ -7094,6 +7094,8 @@ M: Jason Baron <jbaron at akamai.com> S: Maintained F: include/linux/dynamic_debug.h F: lib/dynamic_debug.c +M: Jim Cromie <jim.cromie at gmail.com> +F: lib/test_dynamic_debug.c DYNAMIC INTERRUPT MODERATION M: Tal Gilboa <talgi at nvidia.com> diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index 2e24db4bff19..ca5978e1d18a 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -2529,6 +2529,16 @@ config TEST_STATIC_KEYS If unsure, say N. +config TEST_DYNAMIC_DEBUG + tristate "Test DYNAMIC_DEBUG" + depends on DYNAMIC_DEBUG + help + This module registers a tracer callback to count enabled + pr_debugs in a 'do_debugging' function, then alters their + enablements, calls the function, and compares counts. + + If unsure, say N. + config TEST_KMOD tristate "kmod stress tester" depends on m diff --git a/lib/Makefile b/lib/Makefile index f99bf61f8bbc..9c316df868de 100644 --- a/lib/Makefile +++ b/lib/Makefile @@ -82,6 +82,7 @@ obj-$(CONFIG_TEST_SORT) += test_sort.o obj-$(CONFIG_TEST_USER_COPY) += test_user_copy.o obj-$(CONFIG_TEST_STATIC_KEYS) += test_static_keys.o obj-$(CONFIG_TEST_STATIC_KEYS) += test_static_key_base.o +obj-$(CONFIG_TEST_DYNAMIC_DEBUG) += test_dynamic_debug.o obj-$(CONFIG_TEST_PRINTF) += test_printf.o obj-$(CONFIG_TEST_SCANF) += test_scanf.o obj-$(CONFIG_TEST_BITMAP) += test_bitmap.o diff --git a/lib/test_dynamic_debug.c b/lib/test_dynamic_debug.c new file mode 100644 index 000000000000..ba3882ca3e48 --- /dev/null +++ b/lib/test_dynamic_debug.c @@ -0,0 +1,70 @@ +// SPDX-License-Identifier: GPL-2.0-only +/* + * Kernel module for testing dynamic_debug + * + * Authors: + * Jim Cromie <jim.cromie at gmail.com> + */ + +#define pr_fmt(fmt) "test_dd: " fmt + +#include <linux/module.h> + +static void do_prints(void); /* device under test */ + +/* run tests by reading or writing sysfs node */ + +static int param_set_do_prints(const char *instr, const struct kernel_param *kp) +{ + do_prints(); + return 0; +} + +static int param_get_do_prints(char *buffer, const struct kernel_param *kp) +{ + do_prints(); + return scnprintf(buffer, PAGE_SIZE, "did do_prints\n"); +} + +static const struct kernel_param_ops param_ops_do_prints = { + .set = param_set_do_prints, + .get = param_get_do_prints, +}; + +module_param_cb(do_prints, ¶m_ops_do_prints, NULL, 0600); + +static void do_alpha(void) +{ + pr_debug("do alpha\n"); +} +static void do_beta(void) +{ + pr_debug("do beta\n"); +} + +static void do_prints(void) +{ + do_alpha(); + do_beta(); +} + +static int __init test_dynamic_debug_init(void) +{ + pr_debug("init start\n"); + + do_prints(); + + pr_debug("init done\n"); + return 0; +} + +static void __exit test_dynamic_debug_exit(void) +{ + pr_debug("exiting\n"); +} + +module_init(test_dynamic_debug_init); +module_exit(test_dynamic_debug_exit); + +MODULE_AUTHOR("Jim Cromie <jim.cromie at gmail.com>"); +MODULE_LICENSE("GPL"); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 09/41] dyndbg: drop EXPORTed dynamic_debug_exec_queries
This exported fn is unused, and will not be needed. Lets dump it. The export was added to let drm control pr_debugs, as part of using them to avoid drm_debug_enabled overheads. But its better to just implement the drm.debug bitmap interface, then its available for everyone. Fixes: a2d375eda771 ("dyndbg: refine export, rename to dynamic_debug_exec_queries()") Fixes: 4c0d77828d4f ("dyndbg: export ddebug_exec_queries") Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 9 --------- lib/dynamic_debug.c | 29 ----------------------------- 2 files changed, 38 deletions(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index f30b01aa9fa4..8d9eec5f6d8b 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -55,9 +55,6 @@ struct _ddebug { #if defined(CONFIG_DYNAMIC_DEBUG_CORE) -/* exported for module authors to exercise >control */ -int dynamic_debug_exec_queries(const char *query, const char *modname); - int ddebug_add_module(struct _ddebug *tab, unsigned int n, const char *modname); extern int ddebug_remove_module(const char *mod_name); @@ -221,12 +218,6 @@ static inline int ddebug_dyndbg_module_param_cb(char *param, char *val, rowsize, groupsize, buf, len, ascii); \ } while (0) -static inline int dynamic_debug_exec_queries(const char *query, const char *modname) -{ - pr_warn("kernel not built with CONFIG_DYNAMIC_DEBUG_CORE\n"); - return 0; -} - #endif /* !CONFIG_DYNAMIC_DEBUG_CORE */ #endif diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 5a849716220a..e96dc216463b 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -558,35 +558,6 @@ static int ddebug_exec_queries(char *query, const char *modname) return nfound; } -/** - * dynamic_debug_exec_queries - select and change dynamic-debug prints - * @query: query-string described in admin-guide/dynamic-debug-howto - * @modname: string containing module name, usually &module.mod_name - * - * This uses the >/proc/dynamic_debug/control reader, allowing module - * authors to modify their dynamic-debug callsites. The modname is - * canonically struct module.mod_name, but can also be null or a - * module-wildcard, for example: "drm*". - */ -int dynamic_debug_exec_queries(const char *query, const char *modname) -{ - int rc; - char *qry; /* writable copy of query */ - - if (!query) { - pr_err("non-null query/command string expected\n"); - return -EINVAL; - } - qry = kstrndup(query, PAGE_SIZE, GFP_KERNEL); - if (!qry) - return -ENOMEM; - - rc = ddebug_exec_queries(qry, modname); - kfree(qry); - return rc; -} -EXPORT_SYMBOL_GPL(dynamic_debug_exec_queries); - #define PREFIX_SIZE 64 static int remaining(int wrote) -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 10/41] dyndbg: add class_id to pr_debug callsites
DRM issues ~10 exclusive categories of debug messages; to represent this directly in dyndbg, add a new field: struct _ddebug.class_id:5. This gives us 32 classes, which is a practical usability limit with a bitmap interface: #> echo 0x012345678 > /sys/module/drm/parameters/debug All existing callsites are initialized with _DPRINTK_CLASS_DFLT, which is 2^5-1. This reserves 0-30 for use in new categorized/class'd pr_debugs, which fits perfectly with natural enums (ints: 0..N). Then extend the init macro: DEFINE_DYNAMIC_DEBUG_METADATA() with _CLS(cls, ...), and redef old name using extended name. And extend the factory macro callchain with _cls() versions to provide the callsite.class_id, with old-names passing _DPRINTK_CLASS_DFLT. This sets us up to create class'd prdebug callsites (class'd callsites are those with .class_id != _DPRINTK_CLASS_DFLT). No behavior change. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 71 +++++++++++++++++++++++++++-------- 1 file changed, 55 insertions(+), 16 deletions(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 8d9eec5f6d8b..d1429812be2e 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -6,6 +6,8 @@ #include <linux/jump_label.h> #endif +#include <linux/build_bug.h> + /* * An instance of this structure is created in a special * ELF section at every dynamic debug callsite. At runtime, @@ -21,6 +23,9 @@ struct _ddebug { const char *filename; const char *format; unsigned int lineno:18; +#define CLS_BITS 5 + unsigned int class_id:CLS_BITS; +#define _DPRINTK_CLASS_DFLT ((1 << CLS_BITS) - 1) /* * The flags field controls the behaviour at the callsite. * The bits here are changed dynamically when the user @@ -84,7 +89,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, const struct ib_device *ibdev, const char *fmt, ...); -#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \ +#define DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, cls, fmt) \ static struct _ddebug __aligned(8) \ __section("__dyndbg") name = { \ .modname = KBUILD_MODNAME, \ @@ -93,8 +98,14 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, .format = (fmt), \ .lineno = __LINE__, \ .flags = _DPRINTK_FLAGS_DEFAULT, \ + .class_id = cls, \ _DPRINTK_KEY_INIT \ - } + }; \ + BUILD_BUG_ON_MSG(cls > _DPRINTK_CLASS_DFLT, \ + "classid value overflow") + +#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \ + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(name, _DPRINTK_CLASS_DFLT, fmt) #ifdef CONFIG_JUMP_LABEL @@ -125,17 +136,34 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, #endif /* CONFIG_JUMP_LABEL */ -#define __dynamic_func_call(id, fmt, func, ...) do { \ - DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \ - if (DYNAMIC_DEBUG_BRANCH(id)) \ - func(&id, ##__VA_ARGS__); \ -} while (0) - -#define __dynamic_func_call_no_desc(id, fmt, func, ...) do { \ - DEFINE_DYNAMIC_DEBUG_METADATA(id, fmt); \ +/* + * Factory macros: ($prefix)dynamic_func_call($suffix) + * + * Lower layer (with __ prefix) gets the callsite metadata, and wraps + * the func inside a debug-branch/static-key construct. Upper layer + * (with _ prefix) does the UNIQUE_ID once, so that lower can ref the + * name/label multiple times, and tie the elements together. + * Multiple flavors: + * (|_cls): adds in _DPRINT_CLASS_DFLT as needed + * (|_no_desc): former gets callsite descriptor as 1st arg (for prdbgs) + */ +#define __dynamic_func_call_cls(id, cls, fmt, func, ...) do { \ + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \ if (DYNAMIC_DEBUG_BRANCH(id)) \ - func(__VA_ARGS__); \ + func(&id, ##__VA_ARGS__); \ } while (0) +#define __dynamic_func_call(id, fmt, func, ...) \ + __dynamic_func_call_cls(id, _DPRINTK_CLASS_DFLT, fmt, \ + func, ##__VA_ARGS__) + +#define __dynamic_func_call_cls_no_desc(id, cls, fmt, func, ...) do { \ + DEFINE_DYNAMIC_DEBUG_METADATA_CLS(id, cls, fmt); \ + if (DYNAMIC_DEBUG_BRANCH(id)) \ + func(__VA_ARGS__); \ +} while (0) +#define __dynamic_func_call_no_desc(id, fmt, func, ...) \ + __dynamic_func_call_cls_no_desc(id, _DPRINTK_CLASS_DFLT, \ + fmt, func, ##__VA_ARGS__) /* * "Factory macro" for generating a call to func, guarded by a @@ -145,22 +173,33 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, * the varargs. Note that fmt is repeated in invocations of this * macro. */ +#define _dynamic_func_call_cls(cls, fmt, func, ...) \ + __dynamic_func_call_cls(__UNIQUE_ID(ddebug), cls, fmt, func, ##__VA_ARGS__) #define _dynamic_func_call(fmt, func, ...) \ - __dynamic_func_call(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__) + _dynamic_func_call_cls(_DPRINTK_CLASS_DFLT, fmt, func, ##__VA_ARGS__) + /* * A variant that does the same, except that the descriptor is not * passed as the first argument to the function; it is only called * with precisely the macro's varargs. */ -#define _dynamic_func_call_no_desc(fmt, func, ...) \ - __dynamic_func_call_no_desc(__UNIQUE_ID(ddebug), fmt, func, ##__VA_ARGS__) +#define _dynamic_func_call_cls_no_desc(cls, fmt, func, ...) \ + __dynamic_func_call_cls_no_desc(__UNIQUE_ID(ddebug), cls, fmt, \ + func, ##__VA_ARGS__) +#define _dynamic_func_call_no_desc(fmt, func, ...) \ + _dynamic_func_call_cls_no_desc(_DPRINTK_CLASS_DFLT, fmt, \ + func, ##__VA_ARGS__) + +#define dynamic_pr_debug_cls(cls, fmt, ...) \ + _dynamic_func_call_cls(cls, fmt, __dynamic_pr_debug, \ + pr_fmt(fmt), ##__VA_ARGS__) #define dynamic_pr_debug(fmt, ...) \ - _dynamic_func_call(fmt, __dynamic_pr_debug, \ + _dynamic_func_call(fmt, __dynamic_pr_debug, \ pr_fmt(fmt), ##__VA_ARGS__) #define dynamic_dev_dbg(dev, fmt, ...) \ - _dynamic_func_call(fmt,__dynamic_dev_dbg, \ + _dynamic_func_call(fmt, __dynamic_dev_dbg, \ dev, fmt, ##__VA_ARGS__) #define dynamic_netdev_dbg(dev, fmt, ...) \ -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 11/41] dyndbg: add __pr_debug_cls for testing
For selftest purposes, add __pr_debug_cls(class, fmt, ...) I didn't think we'd need to define this, since DRM effectively has it already in drm_dbg, drm_devdbg. But test_dynamic_debug needs it in order to demonstrate all the moving parts. Note the __ prefix; its not intended for general use, at least until a need emerges. ISTM the drm.debug model (macro wrappers inserting enum const 1st arg) is the baseline approach. NB: it does require a builtin-constant class, no __pr_debug_cls(i"",...) Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index d1429812be2e..0f7ad6cecf05 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -217,6 +217,13 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, KERN_DEBUG, prefix_str, prefix_type, \ rowsize, groupsize, buf, len, ascii) +/* for test only, generally expect drm.debug style macro wrappers */ +#define __pr_debug_cls(cls, fmt, ...) do { \ + BUILD_BUG_ON_MSG(!__builtin_constant_p(cls), \ + "expecting constant class int/enum"); \ + dynamic_pr_debug_cls(cls, fmt, ##__VA_ARGS__); \ + } while (0) + #else /* !CONFIG_DYNAMIC_DEBUG_CORE */ #include <linux/string.h> -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 12/41] dyndbg: add DECLARE_DYNDBG_CLASSMAP
DECLARE_DYNDBG_CLASSMAP lets modules declare a set of classnames, this opt-in authorizes dyndbg to allow enabling of prdbgs by their class: :#> echo class DRM_UT_KMS +p > /proc/dynamic_debug/control This is just the setup; following commits deliver. The macro declares and initializes a static struct ddebug_class_map: - maps approved class-names to class_ids used in module, by array order. forex: DRM_UT_* - class-name vals allow validation of "class FOO" queries using macro is opt-in - enum class_map_type - determines interface, behavior Each module has its own .class_id space, and only known class-names will be authorized for a manipulation. Only DRM stuff should know this: :#> echo class DRM_UT_CORE +p > control # across all modules pr_debugs (with default class_id) are still controllable as before. DECLARE_DYNDBG_CLASSMAP(_var, _maptype, _base, classes...) is:: _var: name of the static struct var. user passes to module_param_cb() if they want a sysfs node. (ive only done it this way). _maptype: this is hard-coded to DD_CLASS_TYPE_DISJOINT for now. _base: usually 0, it allows splitting 31 classes into subranges, so that multiple classes / sysfs-nodes can share the module's class-id space. classes: list of class_name strings, these are mapped to class-ids starting at _base. This class-names list must have a corresponding ENUM, with SYMBOLS that match the literals, and 1st enum val = _base. enum class_map_type has 4 values, on 2 factors:: - classes are disjoint/independent vs relative/x<y/verbosity. disjoint is basis, verbosity by overlay. - input NUMBERS vs [+-]CLASS_NAMES uints, ideally hex. vs +DRM_UT_CORE,-DRM_UT_KMS DD_CLASS_TYPE_DISJOINT: classes are separate, one per bit. expecting hex input. basis for others. DD_CLASS_TYPE_SYMBOLIC: input is a CSV of [+-]CLASS_NAMES, classes are independent, like DISJOINT DD_CLASS_TYPE_VERBOSE: input is numeric level, 0-N. 0 implies silence. use printk to break that. relative levels applied on bitmaps. DD_CLASS_TYPE_LEVELS: input is a CSV of [+-]CLASS_NAMES, names like: ERR,WARNING,NOTICE,INFO,DEBUG avoiding EMERG,ALERT,CRIT,ERR - no point. NOTES: The macro places the initialized struct ddebug_class_map into the __dyndbg_classes section. That draws a 'orphan' warning which we handle in next commit. The struct attributes are necessary: __aligned(8) stopped null-ptr derefs (why?), __used is needed by drm drivers, which declare class-maps, but don't also declare a sysfs-param, and thus dont ref the classmap; __used insures that the linkage is made, then the class-map is found at load-time. While its possible to handle both NAMES and NUMBERS in the same sys-interface, there is ambiguity to avoid, by disallowing them together. Later, if ambiguities are resolved, 2 new enums can permit both inputs, on verbose & independent types separately, and authors can select the interface they like. RFC: My plan is to implement LEVELS in the callbacks, outside of ddebug_exec_query(), which for simplicity will treat the CLASSES in the map as disjoint. This should handle most situations. The callbacks can see map-type, and apply ++/-- loops (or bitops) to force the relative meanings across the class-bitmap. That leaves 2 issues: 1. doing LEVELs in callbacks means that the native >control interface doesn't enforce the LEVELS relationship, so you could confusingly have V3 enabled, but V1 disabled. OTOH, the control iface already allows infinite variety in the underlying callsites, despite the veneer of uniformity suggested by the bitmap overlay, and LEVELS over that. 2. All dyndbg >control reduces to a query/command, includes +/-, which is at-root a kernel patching operation with +/- semantics. And the symbolic sys-node handling exposes it to the user: Consider whether these are/should-be 'exactly' the same: # force both 2 "half-duplex" relations echo +V3,-V4 > /sys/module/test_dynamic_debug/p_VX # should these both do the same ? echo +V3 > /sys/module/test_dynamic_debug/p_VX echo -V4 > /sys/module/test_dynamic_debug/p_VX IOW, half relations are suggested by the +/-, and enum control of individual behaviors leaves some room for this, especially wrt handling [+-]SYMBOLIC inputs from the user. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 55 +++++++++++++++++++++++++++++++++++ 1 file changed, 55 insertions(+) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 0f7ad6cecf05..84e97cd0e8c4 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -56,7 +56,62 @@ struct _ddebug { #endif } __attribute__((aligned(8))); +enum class_map_type { + DD_CLASS_TYPE_DISJOINT, + /** + * DD_CLASS_TYPE_DISJOINT: classes are independent, one per bit. + * expecting hex input. basis for others. + */ + DD_CLASS_TYPE_VERBOSE, + /** + * DD_CLASS_TYPE_VERBOSE: input is numeric level, 0-N. + * 0 should be silent, use printk to break that. + * (x<y) relationship on bitpos + */ + DD_CLASS_TYPE_SYMBOLIC, + /** + * DD_CLASS_TYPE_SYMBOLIC: input is a CSV of [+-]CLASS_NAMES, + * classes are independent, like DISJOINT + */ + DD_CLASS_TYPE_LEVELS, + /** + * DD_CLASS_TYPE_LEVELS: input is a CSV of [+-]CLASS_NAMES, + * intended for names like: ERR,WARNING,NOTICE,INFO,DEBUG + * avoid ? EMERG,ALERT,CRIT,ERR,WARNING ?? + */ +}; + +struct ddebug_class_map { + struct list_head link; + struct module *mod; + const char *mod_name; /* needed for builtins */ + const char **class_names; + const int length; + const int base; /* index of 1st .class_id, allows split/shared space */ + enum class_map_type map_type; +}; + +/** + * DECLARE_DYNDBG_CLASSMAP - declare classnames known by a module + * @_var: a struct ddebug_class_map, passed to module_param_cb + * @_type: enum class_map_type, chooses bits/verbose, numeric/symbolic + * @_base: offset of 1st class-name. splits .class_id space + * @classes: class-names used to control class'd prdbgs + */ +#define DECLARE_DYNDBG_CLASSMAP(_var, _maptype, _base, ...) \ + static const char *_var##_classnames[] = { __VA_ARGS__ }; \ + static struct ddebug_class_map __aligned(8) __used \ + __section("__dyndbg_classes") _var = { \ + .mod = THIS_MODULE, \ + .mod_name = KBUILD_MODNAME, \ + .base = _base, \ + .map_type = _maptype, \ + .length = NUM_TYPE_ARGS(char*, __VA_ARGS__), \ + .class_names = _var##_classnames, \ + } +#define NUM_TYPE_ARGS(eltype, ...) \ + (sizeof((eltype[]) {__VA_ARGS__}) / sizeof(eltype)) #if defined(CONFIG_DYNAMIC_DEBUG_CORE) -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 13/41] kernel/module: add __dyndbg_classes section
Like existing sections, particularly __dyndbg, this new one is an array/address and its length. In a close imitation of __dyndbg handling, these are defined, then passed around, as follows: vmlinux.lds.h: KEEP the new section, which also silences orphan section warning on loadable modules. Add (__start_/__stop_)__dyndbg_classes linker symbols for the c externs (below). kernel/module/internal.h: - add new fields for classes,length to struct load_info, kernel/module.c: - fill new fields in find_module_sections(), using section_objs() - extend callchain prototypes to pass classes, length load_module(): pass new info to dynamic_debug_setup() dynamic_debug_setup(): new params, pass through to ddebug_add_module() dynamic_debug.c: - add externs to the linker symbols. ddebug_add_module(): add params for classes, length. - It currently builds a debug_table, and *will* find and attach classes. dynamic_debug_init(): compute num_classes from linker symbols, and add new _start, num_classes params to ddebug_add_module() calls. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/asm-generic/vmlinux.lds.h | 3 +++ include/linux/dynamic_debug.h | 9 ++++++--- kernel/module/internal.h | 2 ++ kernel/module/main.c | 10 +++++++--- lib/dynamic_debug.c | 22 ++++++++++++++++------ 5 files changed, 34 insertions(+), 12 deletions(-) diff --git a/include/asm-generic/vmlinux.lds.h b/include/asm-generic/vmlinux.lds.h index 7515a465ec03..9b8bd5504ad9 100644 --- a/include/asm-generic/vmlinux.lds.h +++ b/include/asm-generic/vmlinux.lds.h @@ -345,6 +345,9 @@ *(__tracepoints) \ /* implement dynamic printk debug */ \ . = ALIGN(8); \ + __start___dyndbg_classes = .; \ + KEEP(*(__dyndbg_classes)) \ + __stop___dyndbg_classes = .; \ __start___dyndbg = .; \ KEEP(*(__dyndbg)) \ __stop___dyndbg = .; \ diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 84e97cd0e8c4..f57076e02767 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -115,8 +115,10 @@ struct ddebug_class_map { #if defined(CONFIG_DYNAMIC_DEBUG_CORE) -int ddebug_add_module(struct _ddebug *tab, unsigned int n, - const char *modname); +int ddebug_add_module(struct _ddebug *tab, unsigned int num_debugs, + struct ddebug_class_map *classes, unsigned int num_classes, + const char *modname); + extern int ddebug_remove_module(const char *mod_name); extern __printf(2, 3) void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...); @@ -285,7 +287,8 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, #include <linux/errno.h> #include <linux/printk.h> -static inline int ddebug_add_module(struct _ddebug *tab, unsigned int n, +static inline int ddebug_add_module(struct _ddebug *tab, unsigned int num_debugs, + struct ddebug_class_map *classes, unsigned int num_classes, const char *modname) { return 0; diff --git a/kernel/module/internal.h b/kernel/module/internal.h index bc5507ab8450..02601dfe452b 100644 --- a/kernel/module/internal.h +++ b/kernel/module/internal.h @@ -60,7 +60,9 @@ struct load_info { char *secstrings, *strtab; unsigned long symoffs, stroffs, init_typeoffs, core_typeoffs; struct _ddebug *debug; + struct ddebug_class_map *debug_classes; unsigned int num_debug; + unsigned int num_debug_classes; bool sig_ok; #ifdef CONFIG_KALLSYMS unsigned long mod_kallsyms_init_off; diff --git a/kernel/module/main.c b/kernel/module/main.c index fed58d30725d..0f8e888908df 100644 --- a/kernel/module/main.c +++ b/kernel/module/main.c @@ -1593,11 +1593,12 @@ static void free_modinfo(struct module *mod) } } -static void dynamic_debug_setup(struct module *mod, struct _ddebug *debug, unsigned int num) +static void dynamic_debug_setup(struct module *mod, struct _ddebug *debug, unsigned int num, + struct ddebug_class_map *classes, unsigned int num_classes) { if (!debug) return; - ddebug_add_module(debug, num, mod->name); + ddebug_add_module(debug, num, classes, num_classes, mod->name); } static void dynamic_debug_remove(struct module *mod, struct _ddebug *debug) @@ -2093,6 +2094,8 @@ static int find_module_sections(struct module *mod, struct load_info *info) if (section_addr(info, "__obsparm")) pr_warn("%s: Ignoring obsolete parameters\n", mod->name); + info->debug_classes = section_objs(info, "__dyndbg_classes", + sizeof(*info->debug_classes), &info->num_debug_classes); info->debug = section_objs(info, "__dyndbg", sizeof(*info->debug), &info->num_debug); @@ -2783,7 +2786,8 @@ static int load_module(struct load_info *info, const char __user *uargs, } init_build_id(mod, info); - dynamic_debug_setup(mod, info->debug, info->num_debug); + dynamic_debug_setup(mod, info->debug, info->num_debug, + info->debug_classes, info->num_debug_classes); /* Ftrace init must be called in the MODULE_STATE_UNFORMED state */ ftrace_module_init(mod); diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index e96dc216463b..b6d80ba25bf5 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -41,6 +41,8 @@ extern struct _ddebug __start___dyndbg[]; extern struct _ddebug __stop___dyndbg[]; +extern struct ddebug_class_map __start___dyndbg_classes[]; +extern struct ddebug_class_map __stop___dyndbg_classes[]; struct ddebug_table { struct list_head link; @@ -923,8 +925,9 @@ static const struct proc_ops proc_fops = { * Allocate a new ddebug_table for the given module * and add it to the global list. */ -int ddebug_add_module(struct _ddebug *tab, unsigned int n, - const char *name) +int ddebug_add_module(struct _ddebug *tab, unsigned int num_debugs, + struct ddebug_class_map *classes, unsigned int num_classes, + const char *name) { struct ddebug_table *dt; @@ -940,14 +943,14 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n, * this struct ddebug_table. */ dt->mod_name = name; - dt->num_ddebugs = n; + dt->num_ddebugs = num_debugs; dt->ddebugs = tab; mutex_lock(&ddebug_lock); list_add_tail(&dt->link, &ddebug_tables); mutex_unlock(&ddebug_lock); - vpr_info("%3u debug prints in module %s\n", n, dt->mod_name); + vpr_info("%3u debug prints in module %s\n", num_debugs, dt->mod_name); return 0; } @@ -1064,6 +1067,7 @@ static int __init dynamic_debug_init(void) char *cmdline; int ret = 0; int n = 0, entries = 0, modct = 0; + int num_classes = __stop___dyndbg_classes - __start___dyndbg_classes; if (&__start___dyndbg == &__stop___dyndbg) { if (IS_ENABLED(CONFIG_DYNAMIC_DEBUG)) { @@ -1081,7 +1085,9 @@ static int __init dynamic_debug_init(void) entries++; if (strcmp(modname, iter->modname)) { modct++; - ret = ddebug_add_module(iter_start, n, modname); + ret = ddebug_add_module(iter_start, n, + __start___dyndbg_classes, num_classes, + modname); if (ret) goto out_err; n = 0; @@ -1090,7 +1096,8 @@ static int __init dynamic_debug_init(void) } n++; } - ret = ddebug_add_module(iter_start, n, modname); + ret = ddebug_add_module(iter_start, n, + __start___dyndbg_classes, num_classes, modname); if (ret) goto out_err; @@ -1099,6 +1106,9 @@ static int __init dynamic_debug_init(void) entries, modct, (int)((modct * sizeof(struct ddebug_table)) >> 10), (int)((entries * sizeof(struct _ddebug)) >> 10)); + if (num_classes) + v2pr_info(" %d builtin ddebug class-maps\n", num_classes); + /* now that ddebug tables are loaded, process all boot args * again to find and activate queries given in dyndbg params. * While this has already been done for known boot params, it -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 14/41] dyndbg: add ddebug_attach_module_classes
Add ddebug_attach_module_classes(), call it from ddebug_add_module(). It scans the classes/section its given, finds records where the module-name matches the module being added, and adds them to the module's maps list. No locking here, since the record isn't yet linked into the ddebug_tables list. It is called indirectly from 2 sources: - from load_module(), where it scans the module's __dyndbg_classes section, which contains DYNAMIC_DEBUG_CLASSES definitions from just the module. - from dynamic_debug_init(), where all DYNAMIC_DEBUG_CLASSES definitions of each builtin module have been packed together. This is why ddebug_attach_module_classes() checks module-name. RFC: Its (highly) likely that builtin classes will be ordered by module name (just like prdbg descriptors are in the __dyndbg section). So the list can be replaced by a vector (ptr + length), which will work for loaded modules too. This would imitate whats currently done for the _ddebug descriptors. That said, converting to vector,len is close to pointless; a small minority of modules will ever define a class-map, and almost all of them will have only 1 or 2 class-maps, so theres only a couple dozen pointers to save. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 34 +++++++++++++++++++++++++++++++++- 1 file changed, 33 insertions(+), 1 deletion(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index b6d80ba25bf5..e29730686cfb 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -45,7 +45,7 @@ extern struct ddebug_class_map __start___dyndbg_classes[]; extern struct ddebug_class_map __stop___dyndbg_classes[]; struct ddebug_table { - struct list_head link; + struct list_head link, maps; const char *mod_name; unsigned int num_ddebugs; struct _ddebug *ddebugs; @@ -921,6 +921,32 @@ 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) +{ + struct ddebug_class_map *cm; + int i, j, ct = 0; + + for (cm = classes, i = 0; i < 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 (ct) + vpr_info("module:%s attached %d classes\n", dt->mod_name, ct); +} + /* * Allocate a new ddebug_table for the given module * and add it to the global list. @@ -946,6 +972,12 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int num_debugs, dt->num_ddebugs = num_debugs; dt->ddebugs = tab; + INIT_LIST_HEAD(&dt->link); + INIT_LIST_HEAD(&dt->maps); + + if (classes && num_classes) + ddebug_attach_module_classes(dt, classes, num_classes); + mutex_lock(&ddebug_lock); list_add_tail(&dt->link, &ddebug_tables); mutex_unlock(&ddebug_lock); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 15/41] dyndbg: validate class FOO by checking with module
Add module-to-class validation: #> echo class DRM_UT_KMS +p > /proc/dynamic_debug/control If a query has "class FOO", then ddebug_find_valid_class(), called from ddebug_change(), requires that FOO is known to module X, otherwize the query is skipped entirely for X. This protects each module's class-space, other than the default:31. The authors' choice of FOO is highly selective, giving isolation and/or coordinated sharing of FOOs. For example, only DRM modules should know and respond to DRM_UT_KMS. So this, combined with module's opt-in declaration of known classes, effectively privatizes the .class_id space for each module (or coordinated set of modules). Notes: For all "class FOO" queries, ddebug_find_valid_class() is called, it returns the map matching the query, and sets valid_class via an *outvar). If no "class FOO" is supplied, valid_class = _CLASS_DFLT. This insures that legacy queries do not trample on new class'd callsites, as they get added. Also add a new column to control-file output, displaying non-default class-name (when found) or the "unknown _id:", if it has not been (correctly) declared with one of the declarator macros. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/dynamic_debug.c | 76 ++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 68 insertions(+), 8 deletions(-) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index e29730686cfb..4c27bbe5187e 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -56,6 +56,7 @@ struct ddebug_query { const char *module; const char *function; const char *format; + const char *class_string; unsigned int first_lineno, last_lineno; }; @@ -136,15 +137,33 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg) fmtlen--; } - v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u\n", - msg, - query->function ?: "", - query->filename ?: "", - query->module ?: "", - fmtlen, query->format ?: "", - query->first_lineno, query->last_lineno); + v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%s\n", + msg, + query->function ?: "", + query->filename ?: "", + query->module ?: "", + fmtlen, query->format ?: "", + query->first_lineno, query->last_lineno, query->class_string); } +static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table const *dt, + const char *class_string, int *class_id) +{ + struct ddebug_class_map *map; + int idx; + + list_for_each_entry(map, &dt->maps, link) { + idx = match_string(map->class_names, map->length, class_string); + if (idx >= 0) { + *class_id = idx + map->base; + return map; + } + } + *class_id = -ENOENT; + 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 @@ -159,6 +178,8 @@ static int ddebug_change(const struct ddebug_query *query, unsigned int newflags; unsigned int nfound = 0; struct flagsbuf fbuf, nbuf; + struct ddebug_class_map *map = NULL; + int __outvar valid_class; /* search for matching ddebugs */ mutex_lock(&ddebug_lock); @@ -169,9 +190,22 @@ static int ddebug_change(const struct ddebug_query *query, !match_wildcard(query->module, dt->mod_name)) continue; + if (query->class_string) { + map = ddebug_find_valid_class(dt, query->class_string, &valid_class); + if (!map) + continue; + } else { + /* constrain query, do not touch class'd callsites */ + valid_class = _DPRINTK_CLASS_DFLT; + } + for (i = 0; i < dt->num_ddebugs; i++) { struct _ddebug *dp = &dt->ddebugs[i]; + /* match site against query-class */ + if (dp->class_id != valid_class) + continue; + /* match against the source filename */ if (query->filename && !match_wildcard(query->filename, dp->filename) && @@ -420,6 +454,8 @@ static int ddebug_parse_query(char *words[], int nwords, } else if (!strcmp(keyword, "line")) { if (parse_linerange(query, arg)) return -EINVAL; + } else if (!strcmp(keyword, "class")) { + rc = check_set(&query->class_string, arg, "class"); } else { pr_err("unknown keyword \"%s\"\n", keyword); return -EINVAL; @@ -854,6 +890,20 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos) return dp; } +#define class_in_range(class_id, map) \ + (class_id >= map->base && class_id < map->base + map->length) + +static const char *ddebug_class_name(struct ddebug_iter *iter, struct _ddebug *dp) +{ + struct ddebug_class_map *map; + + list_for_each_entry(map, &iter->table->maps, link) + if (class_in_range(dp->class_id, map)) + return map->class_names[dp->class_id - map->base]; + + return NULL; +} + /* * Seq_ops show method. Called several times within a read() * call from userspace, with ddebug_lock held. Formats the @@ -865,6 +915,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p) struct ddebug_iter *iter = m->private; struct _ddebug *dp = p; struct flagsbuf flags; + char const *class; if (p == SEQ_START_TOKEN) { seq_puts(m, @@ -877,7 +928,16 @@ static int ddebug_proc_show(struct seq_file *m, void *p) iter->table->mod_name, dp->function, ddebug_describe_flags(dp->flags, &flags)); seq_escape_str(m, dp->format, ESCAPE_SPACE, "\t\r\n\""); - seq_puts(m, "\"\n"); + seq_puts(m, "\""); + + if (dp->class_id != _DPRINTK_CLASS_DFLT) { + class = ddebug_class_name(iter, dp); + if (class) + seq_printf(m, " class:%s", class); + else + seq_printf(m, " class unknown, _id:%d", dp->class_id); + } + seq_puts(m, "\n"); return 0; } -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 16/41] dyndbg: add drm.debug style bitmap support
Add kernel_param_ops and callbacks to apply a class-map to a sysfs-node, which then can control classes defined in that class-map. This supports uses like: echo 0x3 > /sys/module/drm/parameters/debug IE add these: - int param_set_dyndbg_classes() - int param_get_dyndbg_classes() - struct kernel_param_ops param_ops_dyndbg_classes Following the model of kernel/params.c STANDARD_PARAM_DEFS, these are non-static and exported. This might be unnecessary here. get/set use an augmented kernel_param; the arg refs a new struct ddebug_classes_bitmap_param, initialized by DYNAMIC_DEBUG_CLASSBITS macro, which contains: BITS: a pointer to the user module's ulong holding the bits/state. By ref'g the client's bit-state _var, we coordinate with existing code (such as drm_debug_enabled) which uses the _var, so it works unchanged, even as the foundation is switched out underneath it.. Using a ulong allows use of BIT() etc. FLAGS: dyndbg.flags toggled by changes to bitmap. Usually just "p". MAP: a pointer to struct ddebug_classes_map, which maps those class-names to .class_ids 0..N that the module is using. This class-map is declared & initialized by DEFINE_DYNDBG_CLASSMAP. map-type: add support here for DD_CLASS_DISJOINT, DD_CLASS_VERBOSE. These 2 class-types both expect an integer; _DISJOINT treats input like a bit-vector (ala drm.debug), and sets each bit accordingly. _VERBOSE treats input like a bit-pos:N, then sets bits(0..N)=1, and bits(N+1..max)=0. This applies (bit<N) semantics on top of disjoint bits. cases DD_CLASS_SYMBOLIC, DD_CLASS_LEVELS are included for the complete picture, with commented out call to a following commit. NOTES: this now includes SYMBOLIC/LEVELS support, too tedious to keep separate thru all the tweaking. get-param undoes the bit-pos -> bitmap transform that set-param does on VERBOSE inputs, this gives the read-what-was-written property. _VERBOSE is overlay on _DISJOINT: verbose-maps still need class-names, even though theyre not usable at the sysfs interface (unlike with _SYMBOLIC/_LEVELS). - It must have a "V0" name, something below "V1" to turn "V1" off. __pr_debug_cls(V0,..) is printk, don't do that. - "class names" is required at the >control interface. - relative levels are not enforced at >control IOW this is possible, and maybe confusing: echo class V3 +p > control echo class V1 -p > control IMO thats ok, relative verbosity is an interface property. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- . drop kp->mod->name as unneeded (build-dependent) <lkp> --- include/linux/dynamic_debug.h | 18 ++++ lib/dynamic_debug.c | 193 ++++++++++++++++++++++++++++++++++ 2 files changed, 211 insertions(+) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index f57076e02767..b50bdd5c8184 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -113,6 +113,12 @@ struct ddebug_class_map { #define NUM_TYPE_ARGS(eltype, ...) \ (sizeof((eltype[]) {__VA_ARGS__}) / sizeof(eltype)) +struct ddebug_classes_bitmap_param { + unsigned long *bits; + char flags[8]; + const struct ddebug_class_map *map; +}; + #if defined(CONFIG_DYNAMIC_DEBUG_CORE) int ddebug_add_module(struct _ddebug *tab, unsigned int num_debugs, @@ -274,6 +280,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, KERN_DEBUG, prefix_str, prefix_type, \ rowsize, groupsize, buf, len, ascii) +struct kernel_param; +int param_set_dyndbg_classes(const char *instr, const struct kernel_param *kp); +int param_get_dyndbg_classes(char *buffer, const struct kernel_param *kp); + /* for test only, generally expect drm.debug style macro wrappers */ #define __pr_debug_cls(cls, fmt, ...) do { \ BUILD_BUG_ON_MSG(!__builtin_constant_p(cls), \ @@ -322,6 +332,14 @@ static inline int ddebug_dyndbg_module_param_cb(char *param, char *val, rowsize, groupsize, buf, len, ascii); \ } while (0) +struct kernel_param; +static inline int param_set_dyndbg_classes(const char *instr, const struct kernel_param *kp) +{ return 0; } +static inline int param_get_dyndbg_classes(char *buffer, const struct kernel_param *kp) +{ return 0; } + #endif /* !CONFIG_DYNAMIC_DEBUG_CORE */ +extern const struct kernel_param_ops param_ops_dyndbg_classes; + #endif diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 4c27bbe5187e..dd27dc514aa3 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -596,6 +596,199 @@ static int ddebug_exec_queries(char *query, const char *modname) return nfound; } +static int ddebug_apply_class_bitmap(const struct ddebug_classes_bitmap_param *dcp, + unsigned long inbits) +{ +#define QUERY_SIZE 128 + char query[QUERY_SIZE]; + const struct ddebug_class_map *map = dcp->map; + int matches = 0; + int bi, ct; + + v2pr_info("in: 0x%lx on: 0x%lx\n", inbits, *dcp->bits); + + for (bi = 0; bi < map->length; bi++) { + if (test_bit(bi, &inbits) == test_bit(bi, dcp->bits)) + continue; + + snprintf(query, QUERY_SIZE, "class %s %c%s", map->class_names[bi], + test_bit(bi, &inbits) ? '+' : '-', dcp->flags); + + ct = ddebug_exec_queries(query, NULL); + matches += ct; + + v2pr_info("bit_%d: %d matches on class: %s -> 0x%lx\n", bi, + ct, map->class_names[bi], inbits); + } + return matches; +} + +/* support for [+-] symbolic-name boolean list */ +static int param_set_dyndbg_class_strings(const char *instr, const struct kernel_param *kp) +{ + const struct ddebug_classes_bitmap_param *dcp = kp->arg; + const struct ddebug_class_map *map = dcp->map; + unsigned long inbits; + int idx, totct = 0; + bool wanted; + char *cls, *p; + + cls = kstrdup(instr, GFP_KERNEL); + p = strchr(cls, '\n'); + if (p) + *p = '\0'; + + vpr_info("\"%s\" > %s\n", cls, kp->name); + inbits = *dcp->bits; + + for (; cls; cls = p) { + p = strchr(cls, ','); + if (p) + *p++ = '\0'; + + if (*cls == '-') { + wanted = false; + cls++; + } else { + wanted = true; + if (*cls == '+') + cls++; + } + idx = match_string(map->class_names, map->length, cls); + if (idx < 0) { + pr_err("%s unknown to %s\n", cls, kp->name); + continue; + } + + switch (map->map_type) { + case DD_CLASS_TYPE_SYMBOLIC: + if (test_bit(idx, &inbits) == wanted) { + v3pr_info("no change on %s\n", cls); + continue; + } + inbits ^= BIT(idx); + break; + case DD_CLASS_TYPE_LEVELS: + /* bitmask must respect classmap ranges, this does not */ + inbits = (1 << (idx + wanted)); + break; + default: + pr_err("illegal map-type value %d\n", map->map_type); + } + v2pr_info("%s: bit %d: %s\n", kp->name, idx, map->class_names[idx]); + totct += ddebug_apply_class_bitmap(dcp, inbits); + } + kfree(cls); + *dcp->bits = inbits; + vpr_info("total matches: %d\n", totct); + return 0; +} + +#define CLASSMAP_BITMASK(width) ((1UL << (width)) - 1) + +/** + * param_set_dyndbg_classes - bits => categories >control setter + * @instr: string echo>d to sysfs + * @kp: kp->arg has state: bits, map + * + * Enable/disable prdbgs by their "category", as given in the + * arguments to DYNAMIC_DEBUG_CLASSES. + * + * Returns: 0 or <0 if error. + */ +int param_set_dyndbg_classes(const char *instr, const struct kernel_param *kp) +{ + const struct ddebug_classes_bitmap_param *dcp = kp->arg; + const struct ddebug_class_map *map = dcp->map; + unsigned long inrep; + int rc, totct = 0; + + switch (map->map_type) { + + case DD_CLASS_TYPE_SYMBOLIC: + case DD_CLASS_TYPE_LEVELS: + /* CSV list of [+-]classnames */ + return param_set_dyndbg_class_strings(instr, kp); + + case DD_CLASS_TYPE_DISJOINT: + case DD_CLASS_TYPE_VERBOSE: + /* numeric input */ + rc = kstrtoul(instr, 0, &inrep); + if (rc) { + pr_err("expecting numeric input: %s > %s\n", instr, kp->name); + return -EINVAL; + } + break; + default: + pr_err("%s: bad map type: %d\n", kp->name, map->map_type); + return -EINVAL; + } + + switch (map->map_type) { + case DD_CLASS_TYPE_DISJOINT: + /* expect bits. mask and warn if too many */ + if (inrep & ~CLASSMAP_BITMASK(map->length)) { + pr_warn("%s: input: 0x%lx exceeds mask: 0x%lx, masking\n", + kp->name, inrep, CLASSMAP_BITMASK(map->length)); + inrep &= CLASSMAP_BITMASK(map->length); + } + break; + case DD_CLASS_TYPE_VERBOSE: + /* input is bitpos, of highest verbosity enabled */ + if (inrep > map->length) { + pr_warn("%s: verbosity:%ld exceeds range:%d, clamping\n", + kp->name, inrep, map->length); + inrep = map->length; + } + v2pr_info("VERBOSE: %ld > %s\n", inrep, kp->name); + inrep = CLASSMAP_BITMASK(inrep + 1); + break; + default: + pr_warn("%s: bad map type: %d\n", kp->name, map->map_type); + } + totct += ddebug_apply_class_bitmap(dcp, inrep); + *dcp->bits = inrep; + + vpr_info("%s: total matches: %d\n", kp->name, totct); + return 0; +} +EXPORT_SYMBOL(param_set_dyndbg_classes); + +/** + * param_get_dyndbg_classes - classes reader + * @buffer: string description of controlled bits -> classes + * @kp: kp->arg has state: bits, map + * + * Reads last written bits, underlying prdbg state may have changed since. + * Returns: #chars written or <0 on error + */ +int param_get_dyndbg_classes(char *buffer, const struct kernel_param *kp) +{ + const struct ddebug_classes_bitmap_param *dcp = kp->arg; + const struct ddebug_class_map *map = dcp->map; + unsigned long val = *dcp->bits; + + switch (map->map_type) { + case DD_CLASS_TYPE_SYMBOLIC: + case DD_CLASS_TYPE_DISJOINT: + case DD_CLASS_TYPE_LEVELS: + return scnprintf(buffer, PAGE_SIZE, "0x%lx\n", val); + case DD_CLASS_TYPE_VERBOSE: + /* convert internal bits to a level */ + return scnprintf(buffer, PAGE_SIZE, "%lu\n", + find_first_zero_bit(&val, map->length) - 1); + default: + return -1; + } +} +EXPORT_SYMBOL(param_get_dyndbg_classes); + +const struct kernel_param_ops param_ops_dyndbg_classes = { + .set = param_set_dyndbg_classes, + .get = param_get_dyndbg_classes, +}; +EXPORT_SYMBOL(param_ops_dyndbg_classes); + #define PREFIX_SIZE 64 static int remaining(int wrote) -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 17/41] dyndbg: test DECLARE_DYNDBG_CLASSMAP, sysfs nodes
Demonstrate use of DECLARE_DYNDBG_CLASSMAP macro, and expose them as sysfs-nodes for testing. For each of the 4 class-map-types: - declare a class-map of that type, - declare the enum corresponding to those class-names - share _base across 0..30 range - add a __pr_debug_cls() call for each class-name - declare 2 sysnodes for each class-map for 'p' flag, and future 'T' flag These declarations create the following sysfs parameter interface: :> pwd /sys/module/test_dynamic_debug/parameters :> ls T_disjoint T_levels T_symbolic T_verbosity do_prints p_disjoint p_levels p_symbolic p_verbosity NOTES: The local wrapper macro is an api candidate, but there are already too many parameters. OTOH, maybe related enum should be in there too, since it has _base inter-dependencies. The T_* params control the (future) T flag on the same class'd pr_debug callsites as their p* counterparts. Using them will fail, until the dyndbg-trace patches are added in. :#> echo 1 > T_disjoint [ 28.792489] dyndbg: disjoint: 0x1 > test_dynamic_debug.T_D2 [ 28.793848] dyndbg: query 0: "class D2_CORE +T" mod:* [ 28.795086] dyndbg: split into words: "class" "D2_CORE" "+T" [ 28.796467] dyndbg: op='+' [ 28.797148] dyndbg: unknown flag 'T' [ 28.798021] dyndbg: flags parse failed [ 28.798947] dyndbg: processed 1 queries, with 0 matches, 1 errs [ 28.800378] dyndbg: bit_0: -22 matches on class: D2_CORE -> 0x1 [ 28.801959] dyndbg: test_dynamic_debug.T_D2: updated 0x0 -> 0x1 [ 28.803974] dyndbg: total matches: -22 Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- lib/test_dynamic_debug.c | 125 ++++++++++++++++++++++++++++++++++----- 1 file changed, 110 insertions(+), 15 deletions(-) diff --git a/lib/test_dynamic_debug.c b/lib/test_dynamic_debug.c index ba3882ca3e48..eac85e4e996a 100644 --- a/lib/test_dynamic_debug.c +++ b/lib/test_dynamic_debug.c @@ -10,57 +10,152 @@ #include <linux/module.h> -static void do_prints(void); /* device under test */ - -/* run tests by reading or writing sysfs node */ +/* run tests by reading or writing sysfs node: do_prints */ +static void do_prints(void); /* device under test */ static int param_set_do_prints(const char *instr, const struct kernel_param *kp) { do_prints(); return 0; } - static int param_get_do_prints(char *buffer, const struct kernel_param *kp) { do_prints(); return scnprintf(buffer, PAGE_SIZE, "did do_prints\n"); } - static const struct kernel_param_ops param_ops_do_prints = { .set = param_set_do_prints, .get = param_get_do_prints, }; - module_param_cb(do_prints, ¶m_ops_do_prints, NULL, 0600); -static void do_alpha(void) +/* + * 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-30 class_id space !! + * (build-bug-on tips welcome) + * Additionally, here: + * - tie together sysname, mapname, bitsname, flagsname + */ +#define DD_SYS_WRAP(_model, _flags) \ + static unsigned long bits_##_model; \ + static struct ddebug_classes_bitmap_param _flags##_model = { \ + .bits = &bits_##_model, \ + .flags = #_flags, \ + .map = &map_##_model, \ + }; \ + module_param_cb(_flags##_##_model, ¶m_ops_dyndbg_classes, &_flags##_model, 0600) + +/* numeric input, independent bits */ +enum cat_disjoint { + D2_CORE = 0, + D2_DRIVER, + D2_KMS, + D2_PRIME, + D2_ATOMIC, + D2_VBL, + D2_STATE, + D2_LEASE, + D2_DP, + D2_DRMRES }; +DECLARE_DYNDBG_CLASSMAP(map_disjoint, DD_CLASS_TYPE_DISJOINT, 0, + "D2_CORE", + "D2_DRIVER", + "D2_KMS", + "D2_PRIME", + "D2_ATOMIC", + "D2_VBL", + "D2_STATE", + "D2_LEASE", + "D2_DP", + "D2_DRMRES"); +DD_SYS_WRAP(disjoint, p); +DD_SYS_WRAP(disjoint, T); + +/* symbolic input, independent bits */ +enum cat_symbolic { LOW = 11, MID, HI }; +DECLARE_DYNDBG_CLASSMAP(map_symbolic, DD_CLASS_TYPE_SYMBOLIC, 10, + "LOW", "MID", "HI"); +DD_SYS_WRAP(symbolic, p); +DD_SYS_WRAP(symbolic, T); + +/* numeric verbosity, V2 > V1 related */ +enum cat_verbosity { V0 = 14, V1, V2, V3, V4, V5, V6, V7 }; +DECLARE_DYNDBG_CLASSMAP(map_verbosity, DD_CLASS_TYPE_VERBOSE, 14, + "V0", "V1", "V2", "V3", "V4", "V5", "V6", "V7"); +DD_SYS_WRAP(verbosity, p); +DD_SYS_WRAP(verbosity, T); + +/* symbolic verbosity */ +enum cat_levels { L0 = 22, L1, L2, L3, L4, L5, L6, L7 }; +DECLARE_DYNDBG_CLASSMAP(map_levels, DD_CLASS_TYPE_LEVELS, 22, + "L0", "L1", "L2", "L3", "L4", "L5", "L6", "L7"); +DD_SYS_WRAP(levels, p); +DD_SYS_WRAP(levels, T); + +/* stand-in for all pr_debug etc */ +#define prdbg(SYM) __pr_debug_cls(SYM, #SYM " msg\n") + +static void do_cats(void) { - pr_debug("do alpha\n"); + pr_debug("doing categories\n"); + + prdbg(LOW); + prdbg(MID); + prdbg(HI); + + prdbg(D2_CORE); + prdbg(D2_DRIVER); + prdbg(D2_KMS); + prdbg(D2_PRIME); + prdbg(D2_ATOMIC); + prdbg(D2_VBL); + prdbg(D2_STATE); + prdbg(D2_LEASE); + prdbg(D2_DP); + prdbg(D2_DRMRES); } -static void do_beta(void) + +static void do_levels(void) { - pr_debug("do beta\n"); + pr_debug("doing levels\n"); + + prdbg(V1); + prdbg(V2); + prdbg(V3); + prdbg(V4); + prdbg(V5); + prdbg(V6); + prdbg(V7); + + prdbg(L1); + prdbg(L2); + prdbg(L3); + prdbg(L4); + prdbg(L5); + prdbg(L6); + prdbg(L7); } static void do_prints(void) { - do_alpha(); - do_beta(); + do_cats(); + do_levels(); } static int __init test_dynamic_debug_init(void) { pr_debug("init start\n"); - do_prints(); - pr_debug("init done\n"); return 0; } static void __exit test_dynamic_debug_exit(void) { - pr_debug("exiting\n"); + pr_debug("exited\n"); } module_init(test_dynamic_debug_init); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 18/41] doc-dyndbg: describe "class CLASS_NAME" query support
Add an explanation of the new "class CLASS_NAME" syntax and meaning, noting that the module determines if CLASS_NAME applies to it. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- Documentation/admin-guide/dynamic-debug-howto.rst | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst index a89cfa083155..d8954ab05c7b 100644 --- a/Documentation/admin-guide/dynamic-debug-howto.rst +++ b/Documentation/admin-guide/dynamic-debug-howto.rst @@ -35,6 +35,7 @@ Dynamic debug has even more useful features: - line number (including ranges of line numbers) - module name - format string + - class name (as known/declared by each module) * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control`` which can be read to display the complete list of known debug @@ -142,6 +143,7 @@ against. Possible keywords are::: 'file' string | 'module' string | 'format' string | + 'class' string | 'line' line-range line-range ::= lineno | @@ -203,6 +205,15 @@ format format "nfsd: SETATTR" // a neater way to match a format with whitespace format 'nfsd: SETATTR' // yet another way to match a format with whitespace +class + The given class_name is validated against each module, which may + have declared a list of known class_names. If the class_name is + found for a module, callsite & class matching and adjustment + proceeds. Examples:: + + class DRM_UT_KMS # a DRM.debug category + class JUNK # silent non-match + line The given line number or range of line numbers is compared against the line number of each ``pr_debug()`` callsite. A single -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 19/41] doc-dyndbg: edit dynamic-debug-howto for brevity, audience
Rework/modernize docs: - use /proc/dynamic_debug/control in examples its *always* there (when dyndbg is config'd), even when <debugfs> is not. drop <debugfs> talk, its a distraction here. - read before write. Viewing before Controlling. control file as Catalog. - focus on use by a system administrator add an alias to make examples more readable drop grep-101 lessons, admins know this. - use init/main.c as 1st example, thread it thru doc where useful. everybodys kernel boots, runs these. - add *prdbg* api section to the bottom of the file, its for developers more than admins. move list of api functions there. - simplify - drop extra words, phrases, sentences. - add "decorator" flags line to unify "prefix", trim fmlt descriptions CC: linux-doc at vger.kernel.org Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- .../admin-guide/dynamic-debug-howto.rst | 238 +++++++++--------- 1 file changed, 120 insertions(+), 118 deletions(-) diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst index d8954ab05c7b..cdf1da69e43c 100644 --- a/Documentation/admin-guide/dynamic-debug-howto.rst +++ b/Documentation/admin-guide/dynamic-debug-howto.rst @@ -5,30 +5,19 @@ Dynamic debug Introduction =========== -This document describes how to use the dynamic debug (dyndbg) feature. +Dynamic debug allows you to dynamically enable/disable kernel +debug-print code to obtain additional kernel information. -Dynamic debug is designed to allow you to dynamically enable/disable -kernel code to obtain additional kernel information. Currently, if -``CONFIG_DYNAMIC_DEBUG`` is set, then all ``pr_debug()``/``dev_dbg()`` and -``print_hex_dump_debug()``/``print_hex_dump_bytes()`` calls can be dynamically -enabled per-callsite. +If ``/proc/dynamic_debug/control`` exists, your kernel has dynamic debug. +You'll need root access (sudo su) to use this. -If you do not want to enable dynamic debug globally (i.e. in some embedded -system), you may set ``CONFIG_DYNAMIC_DEBUG_CORE`` as basic support of dynamic -debug and add ``ccflags := -DDYNAMIC_DEBUG_MODULE`` into the Makefile of any -modules which you'd like to dynamically debug later. - -If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is just -shortcut for ``print_hex_dump(KERN_DEBUG)``. - -For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is -its ``prefix_str`` argument, if it is constant string; or ``hexdump`` -in case ``prefix_str`` is built dynamically. +Dynamic debug provides: -Dynamic debug has even more useful features: + * a Catalog of all *prdbgs* in your kernel. + ``cat /proc/dynamic_debug/control`` to see them. - * Simple query language allows turning on and off debugging - statements by matching any combination of 0 or 1 of: + * a Simple query/command language to alter *prdbgs* by selecting on + any combination of 0 or 1 of: - source filename - function name @@ -37,107 +26,88 @@ Dynamic debug has even more useful features: - format string - class name (as known/declared by each module) - * Provides a debugfs control file: ``<debugfs>/dynamic_debug/control`` - which can be read to display the complete list of known debug - statements, to help guide you - -Controlling dynamic debug Behaviour -==================================- -The behaviour of ``pr_debug()``/``dev_dbg()`` are controlled via writing to a -control file in the 'debugfs' filesystem. Thus, you must first mount -the debugfs filesystem, in order to make use of this feature. -Subsequently, we refer to the control file as: -``<debugfs>/dynamic_debug/control``. For example, if you want to enable -printing from source file ``svcsock.c``, line 1603 you simply do:: - - nullarbor:~ # echo 'file svcsock.c line 1603 +p' > - <debugfs>/dynamic_debug/control - -If you make a mistake with the syntax, the write will fail thus:: - - nullarbor:~ # echo 'file svcsock.c wtf 1 +p' > - <debugfs>/dynamic_debug/control - -bash: echo: write error: Invalid argument - -Note, for systems without 'debugfs' enabled, the control file can be -found in ``/proc/dynamic_debug/control``. - Viewing Dynamic Debug Behaviour ============================== -You can view the currently configured behaviour of all the debug -statements via:: +You can view the currently configured behaviour in the *prdbg* catalog: - nullarbor:~ # cat <debugfs>/dynamic_debug/control + :#> head -n7 /proc/dynamic_debug/control # filename:lineno [module]function flags format - net/sunrpc/svc_rdma.c:323 [svcxprt_rdma]svc_rdma_cleanup =_ "SVCRDMA Module Removed, deregister RPC RDMA transport\012" - net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init =_ "\011max_inline : %d\012" - net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init =_ "\011sq_depth : %d\012" - net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests : %d\012" - ... + init/main.c:1179 [main]initcall_blacklist =_ "blacklisting initcall %s\012 + init/main.c:1218 [main]initcall_blacklisted =_ "initcall %s blacklisted\012" + init/main.c:1424 [main]run_init_process =_ " with arguments:\012" + init/main.c:1426 [main]run_init_process =_ " %s\012" + init/main.c:1427 [main]run_init_process =_ " with environment:\012" + init/main.c:1429 [main]run_init_process =_ " %s\012" +The 3rd space-delimited column shows the current flags, preceded by +a ``=`` for easy use with grep/cut. ``=p`` shows enabled callsites. -You can also apply standard Unix text manipulation filters to this -data, e.g.:: +Controlling dynamic debug Behaviour +================================== - nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control | wc -l - 62 +The behaviour of *prdbg* sites are controlled by writing +query/commands to the control file. Example:: - nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l - 42 + # grease the interface + :#> alias ddcmd='echo $* > /proc/dynamic_debug/control' -The third column shows the currently enabled flags for each debug -statement callsite (see below for definitions of the flags). The -default value, with no flags enabled, is ``=_``. So you can view all -the debug statement callsites with any non-default flags:: + :#> ddcmd '-p; module main func run* +p' + :#> grep =p /proc/dynamic_debug/control + init/main.c:1424 [main]run_init_process =p " with arguments:\012" + init/main.c:1426 [main]run_init_process =p " %s\012" + init/main.c:1427 [main]run_init_process =p " with environment:\012" + init/main.c:1429 [main]run_init_process =p " %s\012" - nullarbor:~ # awk '$3 != "=_"' <debugfs>/dynamic_debug/control - # filename:lineno [module]function flags format - net/sunrpc/svcsock.c:1603 [sunrpc]svc_send p "svc_process: st_sendto returned %d\012" +Error messages go to console/syslog: + + :#> ddcmd mode foo +p + dyndbg: unknown keyword "mode" + dyndbg: query parse failed + bash: echo: write error: Invalid argument + +If debugfs is also enabled and mounted, ``dynamic_debug/control`` is +also under the mount-dir, typically ``/sys/kernel/debug/``. Command Language Reference ========================= -At the lexical level, a command comprises a sequence of words separated +At the basic lexical level, a command is a sequence of words separated by spaces or tabs. So these are all equivalent:: - nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > - <debugfs>/dynamic_debug/control - nullarbor:~ # echo -n ' file svcsock.c line 1603 +p ' > - <debugfs>/dynamic_debug/control - nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > - <debugfs>/dynamic_debug/control + :#> ddcmd file svcsock.c line 1603 +p + :#> ddcmd "file svcsock.c line 1603 +p" + :#> ddcmd ' file svcsock.c line 1603 +p ' Command submissions are bounded by a write() system call. Multiple commands can be written together, separated by ``;`` or ``\n``:: - ~# echo "func pnpacpi_get_resources +p; func pnp_assign_mem +p" \ - > <debugfs>/dynamic_debug/control + :#> ddcmd "func pnpacpi_get_resources +p; func pnp_assign_mem +p" + :#> ddcmd <<"EOC" + func pnpacpi_get_resources +p + func pnp_assign_mem +p + EOC + :#> cat query-batch-file > /proc/dynamic_debug/control -If your query set is big, you can batch them too:: +You can also use wildcards in each query term. The match rule supports +``*`` (matches zero or more characters) and ``?`` (matches exactly one +character). For example, you can match all usb drivers:: - ~# cat query-batch-file > <debugfs>/dynamic_debug/control + :#> ddcmd file "drivers/usb/*" +p # "" to suppress shell expansion -Another way is to use wildcards. The match rule supports ``*`` (matches -zero or more characters) and ``?`` (matches exactly one character). For -example, you can match all usb drivers:: - - ~# echo "file drivers/usb/* +p" > <debugfs>/dynamic_debug/control - -At the syntactical level, a command comprises a sequence of match -specifications, followed by a flags change specification:: +Syntactically, a command is pairs of keyword values, followed by a +flags change or setting:: command ::= match-spec* flags-spec -The match-spec's are used to choose a subset of the known pr_debug() -callsites to which to apply the flags-spec. Think of them as a query -with implicit ANDs between each pair. Note that an empty list of -match-specs will select all debug statement callsites. +The match-spec's select *prdbgs* from the catalog, upon which to apply +the flags-spec, all constraints are ANDed together. An absent keyword +is the same as keyword "*". + -A match specification comprises a keyword, which controls the -attribute of the callsite to be compared, and a value to compare -against. Possible keywords are::: +A match specification is a keyword, which selects the attribute of +the callsite to be compared, and a value to compare against. Possible +keywords are::: match-spec ::= 'func' string | 'file' string | @@ -213,6 +183,7 @@ class class DRM_UT_KMS # a DRM.debug category class JUNK # silent non-match + // class TLD_* # NOTICE: no wildcard in class names line The given line number or range of line numbers is compared @@ -239,17 +210,16 @@ of the characters:: The flags are:: p enables the pr_debug() callsite. - f Include the function name in the printed message - l Include line number in the printed message - m Include module name in the printed message - t Include thread ID in messages not generated from interrupt context - _ No flags are set. (Or'd with others on input) + _ enables no flags. -For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only ``p`` flag -have meaning, other flags ignored. + Decorator flags add to the message-prefix, in order: + t Include thread ID, or <intr> + m Include module name + f Include the function name + l Include line number -For display, the flags are preceded by ``=`` -(mnemonic: what the flags are currently equal to). +For ``print_hex_dump_debug()`` and ``print_hex_dump_bytes()``, only +the ``p`` flag has meaning, other flags are ignored. Note the regexp ``^[-+=][flmpt_]+$`` matches a flags specification. To clear all flags at once, use ``=_`` or ``-flmpt``. @@ -324,7 +294,7 @@ For ``CONFIG_DYNAMIC_DEBUG`` kernels, any settings given at boot-time (or enabled by ``-DDEBUG`` flag during compilation) can be disabled later via the debugfs interface if the debug messages are no longer needed:: - echo "module module_name -p" > <debugfs>/dynamic_debug/control + echo "module module_name -p" > /proc/dynamic_debug/control Examples =======@@ -332,37 +302,31 @@ Examples :: // enable the message at line 1603 of file svcsock.c - nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' > - <debugfs>/dynamic_debug/control + :#> ddcmd 'file svcsock.c line 1603 +p' // enable all the messages in file svcsock.c - nullarbor:~ # echo -n 'file svcsock.c +p' > - <debugfs>/dynamic_debug/control + :#> ddcmd 'file svcsock.c +p' // enable all the messages in the NFS server module - nullarbor:~ # echo -n 'module nfsd +p' > - <debugfs>/dynamic_debug/control + :#> ddcmd 'module nfsd +p' // enable all 12 messages in the function svc_process() - nullarbor:~ # echo -n 'func svc_process +p' > - <debugfs>/dynamic_debug/control + :#> ddcmd 'func svc_process +p' // disable all 12 messages in the function svc_process() - nullarbor:~ # echo -n 'func svc_process -p' > - <debugfs>/dynamic_debug/control + :#> ddcmd 'func svc_process -p' // enable messages for NFS calls READ, READLINK, READDIR and READDIR+. - nullarbor:~ # echo -n 'format "nfsd: READ" +p' > - <debugfs>/dynamic_debug/control + :#> ddcmd 'format "nfsd: READ" +p' // enable messages in files of which the paths include string "usb" - nullarbor:~ # echo -n 'file *usb* +p' > <debugfs>/dynamic_debug/control + :#> ddcmd 'file *usb* +p' > /proc/dynamic_debug/control // enable all messages - nullarbor:~ # echo -n '+p' > <debugfs>/dynamic_debug/control + :#> ddcmd '+p' > /proc/dynamic_debug/control // add module, function to all enabled messages - nullarbor:~ # echo -n '+mf' > <debugfs>/dynamic_debug/control + :#> ddcmd '+mf' > /proc/dynamic_debug/control // boot-args example, with newlines and comments for readability Kernel command line: ... @@ -375,3 +339,41 @@ Examples dyndbg="file init/* +p #cmt ; func parse_one +p" // enable pr_debugs in 2 functions in a module loaded later pc87360.dyndbg="func pc87360_init_device +p; func pc87360_find +p" + +Kernel Configuration +===================+ +Dynamic Debug is enabled via kernel config items: + + CONFIG_DYNAMIC_DEBUG=y # build catalog, enables CORE + CONFIG_DYNAMIC_DEBUG_CORE=y # enable mechanics only, skip catalog + +Fedora's distro-kernel has both, and has 7250 *prdbgs*. Each callsite +record uses 56 bytes, so the impact on memory is non-trivial. + +If you do not want to enable dynamic debug globally (i.e. in some embedded +system), you may set ``CONFIG_DYNAMIC_DEBUG_CORE`` as basic support of dynamic +debug and add ``ccflags := -DDYNAMIC_DEBUG_MODULE`` into the Makefile of any +modules which you'd like to dynamically debug later. + + +Kernel *prdbg* API +=================+ +The following functions are cataloged and controllable when dynamic +debug is enabled:: + + pr_debug() + dev_dbg() + print_hex_dump_debug() + print_hex_dump_bytes() + +Otherwise, they are off by default; ``ccflags += -DDEBUG`` or +``#define DEBUG`` in a source file will enable them appropriately. + +If ``CONFIG_DYNAMIC_DEBUG`` is not set, ``print_hex_dump_debug()`` is +just a shortcut for ``print_hex_dump(KERN_DEBUG)``. + +For ``print_hex_dump_debug()``/``print_hex_dump_bytes()``, format string is +its ``prefix_str`` argument, if it is constant string; or ``hexdump`` +in case ``prefix_str`` is built dynamically. -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 20/41] drm_print: condense enum drm_debug_category
enum drm_debug_category has 10 categories, but is initialized with bitmasks which require 10 bits of underlying storage. By using natural enumeration, and moving the BIT(cat) into drm_debug_enabled(), the enum fits in 4 bits, allowing the category to be represented directly in pr_debug callsites, via the ddebug.class_id field. While this slightly pessimizes the bit-test in drm_debug_enabled(), using dyndbg with JUMP_LABEL will avoid the function entirely. NOTE: this change forecloses the possibility of doing: drm_dbg(DRM_UT_CORE|DRM_UT_KMS, "weird 2-cat experiment") but thats already strongly implied by the use of the enum itself; its not a normal enum if it can be 2 values simultaneously. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/drm/drm_print.h | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 22fabdeed297..b3b470440e46 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -279,49 +279,49 @@ enum drm_debug_category { * @DRM_UT_CORE: Used in the generic drm code: drm_ioctl.c, drm_mm.c, * drm_memory.c, ... */ - DRM_UT_CORE = 0x01, + DRM_UT_CORE, /** * @DRM_UT_DRIVER: Used in the vendor specific part of the driver: i915, * radeon, ... macro. */ - DRM_UT_DRIVER = 0x02, + DRM_UT_DRIVER, /** * @DRM_UT_KMS: Used in the modesetting code. */ - DRM_UT_KMS = 0x04, + DRM_UT_KMS, /** * @DRM_UT_PRIME: Used in the prime code. */ - DRM_UT_PRIME = 0x08, + DRM_UT_PRIME, /** * @DRM_UT_ATOMIC: Used in the atomic code. */ - DRM_UT_ATOMIC = 0x10, + DRM_UT_ATOMIC, /** * @DRM_UT_VBL: Used for verbose debug message in the vblank code. */ - DRM_UT_VBL = 0x20, + DRM_UT_VBL, /** * @DRM_UT_STATE: Used for verbose atomic state debugging. */ - DRM_UT_STATE = 0x40, + DRM_UT_STATE, /** * @DRM_UT_LEASE: Used in the lease code. */ - DRM_UT_LEASE = 0x80, + DRM_UT_LEASE, /** * @DRM_UT_DP: Used in the DP code. */ - DRM_UT_DP = 0x100, + DRM_UT_DP, /** * @DRM_UT_DRMRES: Used in the drm managed resources code. */ - DRM_UT_DRMRES = 0x200, + DRM_UT_DRMRES }; static inline bool drm_debug_enabled(enum drm_debug_category category) { - return unlikely(__drm_debug & category); + return unlikely(__drm_debug & BIT(category)); } /* -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 21/41] drm: POC drm on dyndbg - use in core, 2 helpers, 3 drivers.
Use DECLARE_DYNDBG_CLASSMAP across DRM: - in .c files, since macro defines/initializes a record - in drivers, $mod_{drv,drm,param}.c ie where param setup is done (since a class-bitmap is a param) - in drm/drm_print.c, since thats where it adds the class-bitmap, and replaces module_param_named. - in drm_*_helper modules: dp/drm_dp - 1st item in makefile target drivers/gpu/drm/drm_crtc_helper.c - random pick iirc. Since these modules all use identical class-maps (ie: names and .class_id's) they all will respond together to class FOO changes: :#> echo class DRM_UT_KMS +p > /proc/dynamic_debug/control ttm and video have 2,8 callsites each, I havent looked. NOTES: DRM's enum drm_debug_category values need to sync with the index of their respective class-names here. Then .class_id == category, and dyndbg's class FOO mechanisms will enable drm_dbg(DRM_UT_KMS, ...). Though DRM needs consistent categories across all modules, thats not generally needed; modules X and Y could define FOO differently (ie different corresponding .class_id), changes are made according to each module's private class-map. No callsites are actually selected here, since none are class'd yet. change __drm_debug from int to long, so BIT() is usable on it. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- 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 | 27 +++++++++++++++++++++++-- drivers/gpu/drm/i915/i915_params.c | 12 +++++++++++ drivers/gpu/drm/nouveau/nouveau_drm.c | 13 ++++++++++++ include/drm/drm_print.h | 3 ++- 7 files changed, 92 insertions(+), 3 deletions(-) diff --git a/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c b/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c index 8890300766a5..ba96d33137b6 100644 --- a/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c +++ b/drivers/gpu/drm/amd/amdgpu/amdgpu_drv.c @@ -38,6 +38,8 @@ #include <linux/mmu_notifier.h> #include <linux/suspend.h> #include <linux/cc_platform.h> +#include <linux/fb.h> +#include <linux/dynamic_debug.h> #include "amdgpu.h" #include "amdgpu_irq.h" @@ -183,6 +185,18 @@ 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, 0, + "DRM_UT_CORE", + "DRM_UT_DRIVER", + "DRM_UT_KMS", + "DRM_UT_PRIME", + "DRM_UT_ATOMIC", + "DRM_UT_VBL", + "DRM_UT_STATE", + "DRM_UT_LEASE", + "DRM_UT_DP", + "DRM_UT_DRMRES"); + struct amdgpu_mgpu_info mgpu_info = { .mutex = __MUTEX_INITIALIZER(mgpu_info.mutex), .delayed_reset_work = __DELAYED_WORK_INITIALIZER( diff --git a/drivers/gpu/drm/display/drm_dp_helper.c b/drivers/gpu/drm/display/drm_dp_helper.c index e7c22c2ca90c..eb7aef22e7fd 100644 --- a/drivers/gpu/drm/display/drm_dp_helper.c +++ b/drivers/gpu/drm/display/drm_dp_helper.c @@ -29,6 +29,7 @@ #include <linux/sched.h> #include <linux/seq_file.h> #include <linux/string_helpers.h> +#include <linux/dynamic_debug.h> #include <drm/display/drm_dp_helper.h> #include <drm/display/drm_dp_mst_helper.h> @@ -38,6 +39,18 @@ #include "drm_dp_helper_internal.h" +DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, + "DRM_UT_CORE", + "DRM_UT_DRIVER", + "DRM_UT_KMS", + "DRM_UT_PRIME", + "DRM_UT_ATOMIC", + "DRM_UT_VBL", + "DRM_UT_STATE", + "DRM_UT_LEASE", + "DRM_UT_DP", + "DRM_UT_DRMRES"); + struct dp_aux_backlight { struct backlight_device *base; struct drm_dp_aux *aux; diff --git a/drivers/gpu/drm/drm_crtc_helper.c b/drivers/gpu/drm/drm_crtc_helper.c index b632825654a9..80f2cf807dae 100644 --- a/drivers/gpu/drm/drm_crtc_helper.c +++ b/drivers/gpu/drm/drm_crtc_helper.c @@ -32,6 +32,7 @@ #include <linux/export.h> #include <linux/kernel.h> #include <linux/moduleparam.h> +#include <linux/dynamic_debug.h> #include <drm/drm_atomic.h> #include <drm/drm_atomic_helper.h> @@ -50,6 +51,18 @@ #include "drm_crtc_helper_internal.h" +DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, + "DRM_UT_CORE", + "DRM_UT_DRIVER", + "DRM_UT_KMS", + "DRM_UT_PRIME", + "DRM_UT_ATOMIC", + "DRM_UT_VBL", + "DRM_UT_STATE", + "DRM_UT_LEASE", + "DRM_UT_DP", + "DRM_UT_DRMRES"); + /** * DOC: overview * diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index f783d4963d4b..44be95fac164 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -40,7 +40,7 @@ * __drm_debug: Enable debug output. * Bitmask of DRM_UT_x. See include/drm/drm_print.h for details. */ -unsigned int __drm_debug; +unsigned long __drm_debug; EXPORT_SYMBOL(__drm_debug); MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" @@ -52,7 +52,30 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" "\t\tBit 8 (0x100) will enable DP messages (displayport code)"); -module_param_named(debug, __drm_debug, int, 0600); + +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) +module_param_named(debug, __drm_debug, ulong, 0600); +#else +/* classnames must match vals of enum drm_debug_category */ +DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, + "DRM_UT_CORE", + "DRM_UT_DRIVER", + "DRM_UT_KMS", + "DRM_UT_PRIME", + "DRM_UT_ATOMIC", + "DRM_UT_VBL", + "DRM_UT_STATE", + "DRM_UT_LEASE", + "DRM_UT_DP", + "DRM_UT_DRMRES"); + +static struct ddebug_classes_bitmap_param drm_debug_bitmap = { + .bits = &__drm_debug, + .flags = "p", + .map = &drm_debug_classes, +}; +module_param_cb(debug, ¶m_ops_dyndbg_classes, &drm_debug_bitmap, 0600); +#endif void __drm_puts_coredump(struct drm_printer *p, const char *str) { diff --git a/drivers/gpu/drm/i915/i915_params.c b/drivers/gpu/drm/i915/i915_params.c index 701fbc98afa0..b0ce128e245a 100644 --- a/drivers/gpu/drm/i915/i915_params.c +++ b/drivers/gpu/drm/i915/i915_params.c @@ -29,6 +29,18 @@ #include "i915_params.h" #include "i915_drv.h" +DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, + "DRM_UT_CORE", + "DRM_UT_DRIVER", + "DRM_UT_KMS", + "DRM_UT_PRIME", + "DRM_UT_ATOMIC", + "DRM_UT_VBL", + "DRM_UT_STATE", + "DRM_UT_LEASE", + "DRM_UT_DP", + "DRM_UT_DRMRES"); + #define i915_param_named(name, T, perm, desc) \ module_param_named(name, i915_modparams.name, T, perm); \ MODULE_PARM_DESC(name, desc) diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c b/drivers/gpu/drm/nouveau/nouveau_drm.c index 561309d447e0..76e3a8d50b01 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drm.c +++ b/drivers/gpu/drm/nouveau/nouveau_drm.c @@ -28,6 +28,7 @@ #include <linux/pm_runtime.h> #include <linux/vga_switcheroo.h> #include <linux/mmu_notifier.h> +#include <linux/dynamic_debug.h> #include <drm/drm_aperture.h> #include <drm/drm_crtc_helper.h> @@ -70,6 +71,18 @@ #include "nouveau_svm.h" #include "nouveau_dmem.h" +DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, + "DRM_UT_CORE", + "DRM_UT_DRIVER", + "DRM_UT_KMS", + "DRM_UT_PRIME", + "DRM_UT_ATOMIC", + "DRM_UT_VBL", + "DRM_UT_STATE", + "DRM_UT_LEASE", + "DRM_UT_DP", + "DRM_UT_DRMRES"); + MODULE_PARM_DESC(config, "option string to pass to driver core"); static char *nouveau_config; module_param_named(config, nouveau_config, charp, 0400); diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index b3b470440e46..668273e36c2c 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -35,7 +35,7 @@ #include <drm/drm.h> /* Do *not* use outside of drm_print.[ch]! */ -extern unsigned int __drm_debug; +extern unsigned long __drm_debug; /** * DOC: print @@ -275,6 +275,7 @@ static inline struct drm_printer drm_err_printer(const char *prefix) * */ enum drm_debug_category { + /* These names must match those in DYNAMIC_DEBUG_CLASSBITS */ /** * @DRM_UT_CORE: Used in the generic drm code: drm_ioctl.c, drm_mm.c, * drm_memory.c, ... -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 22/41] drm_print: interpose drm_*dbg with forwarding macros
change drm_dev_dbg & drm_dbg to macros, which forward to the renamed functions (with __ prefix added). Those functions sit below the categorized layer of macros implementing the DRM debug.category API, and implement most of it. These are good places to insert dynamic-debug jump-label mechanics, which will allow DRM to avoid the runtime cost of drm_debug_enabled(). no functional changes. memory cost baseline: (unchanged) bash-5.1# drms_load [ 9.220389] dyndbg: 1 debug prints in module drm [ 9.224426] ACPI: bus type drm_connector registered [ 9.302192] dyndbg: 2 debug prints in module ttm [ 9.305033] dyndbg: 8 debug prints in module video [ 9.627563] dyndbg: 127 debug prints in module i915 [ 9.721505] AMD-Vi: AMD IOMMUv2 functionality not available on this system - This is not a bug. [ 10.091345] dyndbg: 2196 debug prints in module amdgpu [ 10.106589] [drm] amdgpu kernel modesetting enabled. [ 10.107270] amdgpu: CRAT table not found [ 10.107926] amdgpu: Virtual CRAT table created for CPU [ 10.108398] amdgpu: Topology: Add CPU node [ 10.168507] dyndbg: 3 debug prints in module wmi [ 10.329587] dyndbg: 3 debug prints in module nouveau Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 10 +++++----- include/drm/drm_print.h | 9 +++++++-- 2 files changed, 12 insertions(+), 7 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 44be95fac164..21b416af0be2 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -279,8 +279,8 @@ void drm_dev_printk(const struct device *dev, const char *level, } EXPORT_SYMBOL(drm_dev_printk); -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...) +void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, + const char *format, ...) { struct va_format vaf; va_list args; @@ -301,9 +301,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, va_end(args); } -EXPORT_SYMBOL(drm_dev_dbg); +EXPORT_SYMBOL(__drm_dev_dbg); -void __drm_dbg(enum drm_debug_category category, const char *format, ...) +void ___drm_dbg(enum drm_debug_category category, const char *format, ...) { struct va_format vaf; va_list args; @@ -320,7 +320,7 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...) va_end(args); } -EXPORT_SYMBOL(__drm_dbg); +EXPORT_SYMBOL(___drm_dbg); void __drm_err(const char *format, ...) { diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 668273e36c2c..c429c258c957 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -335,7 +335,7 @@ __printf(3, 4) void drm_dev_printk(const struct device *dev, const char *level, const char *format, ...); __printf(3, 4) -void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, +void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, const char *format, ...); /** @@ -384,6 +384,9 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, } \ }) +#define drm_dev_dbg(dev, cat, fmt, ...) \ + __drm_dev_dbg(dev, cat, fmt, ##__VA_ARGS__) + /** * DRM_DEV_DEBUG() - Debug output for generic drm code * @@ -485,10 +488,12 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, */ __printf(2, 3) -void __drm_dbg(enum drm_debug_category category, const char *format, ...); +void ___drm_dbg(enum drm_debug_category category, const char *format, ...); __printf(1, 2) void __drm_err(const char *format, ...); +#define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__) + /* Macros to make printk easier */ #define _DRM_PRINTK(once, level, fmt, ...) \ -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 23/41] drm_print: wrap drm_*_dbg in dyndbg descriptor factory macro
For CONFIG_DRM_USE_DYNAMIC_DEBUG=y, wrap __drm_dbg() & __drm_dev_dbg() in one of dyndbg's Factory macros: _dynamic_func_call_no_desc(). This adds the callsite descriptor into the code, and an entry for each into /proc/dynamic_debug/control. #> echo class DRM_UT_ATOMIC +p > /proc/dynamic_debug/control CONFIG_DRM_USE_DYNAMIC_DEBUG=y/n is configurable because of the .data footprint cost of per-callsite control; 56 bytes/site * ~2k for i915, ~4k callsites for amdgpu. This is large enough that a kernel builder might not want it. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/Kconfig | 12 ++++++++++++ drivers/gpu/drm/Makefile | 2 ++ include/drm/drm_print.h | 12 ++++++++++++ 3 files changed, 26 insertions(+) diff --git a/drivers/gpu/drm/Kconfig b/drivers/gpu/drm/Kconfig index e88c497fa010..bb1fa20a8eb2 100644 --- a/drivers/gpu/drm/Kconfig +++ b/drivers/gpu/drm/Kconfig @@ -50,6 +50,18 @@ config DRM_DEBUG_MM If in doubt, say "N". +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. + config DRM_DEBUG_SELFTEST tristate "kselftests for DRM" depends on DRM diff --git a/drivers/gpu/drm/Makefile b/drivers/gpu/drm/Makefile index 15fe3163f822..272de137d207 100644 --- a/drivers/gpu/drm/Makefile +++ b/drivers/gpu/drm/Makefile @@ -3,6 +3,8 @@ # Makefile for the drm device driver. This driver provides support for the # Direct Rendering Infrastructure (DRI) in XFree86 4.1.0 and higher. +CFLAGS-$(CONFIG_DRM_USE_DYNAMIC_DEBUG) += -DDYNAMIC_DEBUG_MODULE + drm-y := drm_aperture.o drm_auth.o drm_cache.o \ drm_file.o drm_gem.o drm_ioctl.o \ drm_drv.o \ diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index c429c258c957..2d2cef76b5c1 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -384,8 +384,14 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, } \ }) +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) #define drm_dev_dbg(dev, cat, fmt, ...) \ __drm_dev_dbg(dev, cat, fmt, ##__VA_ARGS__) +#else +#define drm_dev_dbg(dev, cat, fmt, ...) \ + _dynamic_func_call_no_desc(fmt, __drm_dev_dbg, \ + dev, cat, fmt, ##__VA_ARGS__) +#endif /** * DRM_DEV_DEBUG() - Debug output for generic drm code @@ -492,7 +498,13 @@ void ___drm_dbg(enum drm_debug_category category, const char *format, ...); __printf(1, 2) void __drm_err(const char *format, ...); +#if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) #define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__) +#else +#define __drm_dbg(cat, fmt, ...) \ + _dynamic_func_call_no_desc(fmt, ___drm_dbg, \ + cat, fmt, ##__VA_ARGS__) +#endif /* Macros to make printk easier */ -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 24/39] drm-print: include dyndbg header indirectly
lkp robot told me: >> drivers/gpu/drm/drm_ioc32.c:989:2: error: call to undeclared function '_dynamic_func_call_cls'; ISO C99 and later do not support implicit function declarations [-Wimplicit-function-declaration] DRM_DEBUG("comm=\"%s\", pid=%d, dev=0x%lx, auth=%d, %s\n", Since that macro is defined in drm_print.h, include <dynamic_debug.h> there too, so that any uses have the definitions of all the macros in the callchain. This is done as a separate patch mostly to see how lkp sorts it; I'll probably squash it with HEAD~1 Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/drm/drm_print.h | 1 + 1 file changed, 1 insertion(+) diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 2d2cef76b5c1..f8bb3e7158c6 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -31,6 +31,7 @@ #include <linux/seq_file.h> #include <linux/device.h> #include <linux/debugfs.h> +#include <linux/dynamic_debug.h> #include <drm/drm.h> -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 24/41] drm-print: add drm_dbg_driver to improve namespace symmetry
drm_print defines all of these: drm_dbg_{core,kms,prime,atomic,vbl,lease,_dp,_drmres} but not drm_dbg_driver itself, since it was the original drm_dbg. To improve namespace symmetry, change the drm_dbg defn to drm_dbg_driver, and redef grandfathered name to symmetric one. This will help with nouveau, which uses its own stack of macros to construct calls to dev_info, dev_dbg, etc, for which adaptation means drm_dbg_##driver constructs. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/drm/drm_print.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 2d2cef76b5c1..3aa5e9ea26f4 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -467,7 +467,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, #define drm_dbg_core(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__) -#define drm_dbg(drm, fmt, ...) \ +#define drm_dbg_driver(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__) #define drm_dbg_kms(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__) @@ -486,6 +486,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, #define drm_dbg_drmres(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__) +#define drm_dbg(drm, fmt, ...) drm_dbg_driver(drm, fmt, ##__VA_ARGS__) /* * printk based logging -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 25/41] drm-print: include dyndbg header indirectly
lkp robot told me: >> drivers/gpu/drm/drm_ioc32.c:989:2: error: call to undeclared function '_dynamic_func_call_cls'; ISO C99 and later do not support implicit function declarations [-Wimplicit-function-declaration] DRM_DEBUG("comm=\"%s\", pid=%d, dev=0x%lx, auth=%d, %s\n", Since that macro is defined in drm_print.h, include <dynamic_debug.h> there too, so that any uses have the definitions of all the macros in the callchain. This is done as a separate patch mostly to see how lkp sorts it; I'll probably squash it with HEAD~1 Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/drm/drm_print.h | 1 + 1 file changed, 1 insertion(+) diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 3aa5e9ea26f4..dfdd81c3287c 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -31,6 +31,7 @@ #include <linux/seq_file.h> #include <linux/device.h> #include <linux/debugfs.h> +#include <linux/dynamic_debug.h> #include <drm/drm.h> -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 25/39] drm_print: refine drm_debug_enabled for jump-label
In order to use dynamic-debug's jump-label optimization in drm-debug, its clarifying to refine drm_debug_enabled into 3 uses: 1. drm_debug_enabled - legacy, public 2. __drm_debug_enabled - optimized for dyndbg jump-label enablement. 3. _drm_debug_enabled - pr_debug instrumented, observable 1. The legacy version always checks the bits. 2. is privileged, for use by __drm_dbg(), __drm_dev_dbg(), which do an early return unless the category is enabled. For dyndbg builds, debug callsites are selectively "pre-enabled", so __drm_debug_enabled() short-circuits to true there. Remaining callers of 1 may be able to use 2, case by case. 3. is 1st wrapped in a macro, with a pr_debug, which reports each usage in /proc/dynamic_debug/control, making it observable in the logs. The macro lets the pr_debug see the real caller, not an inline function. When plugged into 1, 3 identified ~10 remaining callers of the function, leading to the follow-on cleanup patch, and would allow activating the pr_debugs, estimating the callrate, and the potential savings by using the wrapper macro. It is unused ATM, but it fills out the picture. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 4 ++-- include/drm/drm_print.h | 28 ++++++++++++++++++++++++++++ 2 files changed, 30 insertions(+), 2 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 21b416af0be2..effb95b3c2bf 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -285,7 +285,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, struct va_format vaf; va_list args; - if (!drm_debug_enabled(category)) + if (!__drm_debug_enabled(category)) return; va_start(args, format); @@ -308,7 +308,7 @@ void ___drm_dbg(enum drm_debug_category category, const char *format, ...) struct va_format vaf; va_list args; - if (!drm_debug_enabled(category)) + if (!__drm_debug_enabled(category)) return; va_start(args, format); diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index f8bb3e7158c6..3c16b00b6d21 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -321,11 +321,39 @@ enum drm_debug_category { DRM_UT_DRMRES }; +/* + * 3 name flavors of drm_debug_enabled: + * drm_debug_enabled - public/legacy, always checks bits + * _drm_debug_enabled - instrumented to observe call-rates, est overheads. + * __drm_debug_enabled - privileged - knows jump-label state, can short-circuit + */ static inline bool drm_debug_enabled(enum drm_debug_category category) { return unlikely(__drm_debug & BIT(category)); } +/* + * Wrap fn in macro, so that the pr_debug sees the actual caller, not + * the inline fn. Using this name creates a callsite entry / control + * point in /proc/dynamic_debug/control. + */ +#define _drm_debug_enabled(category) \ + ({ \ + pr_debug("todo: maybe avoid via dyndbg\n"); \ + drm_debug_enabled(category); \ + }) + +#if defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) +/* + * dyndbg is wrapping the drm.debug API, so as to avoid the runtime + * bit-test overheads of drm_debug_enabled() in those api calls. + * In this case, executed callsites are known enabled, so true. + */ +#define __drm_debug_enabled(category) true +#else +#define __drm_debug_enabled(category) drm_debug_enabled(category) +#endif + /* * struct device based logging * -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 26/39] 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 at gmail.com> --- drivers/gpu/drm/drm_print.c | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index effb95b3c2bf..e0de79a22255 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -23,8 +23,6 @@ * Rob Clark <robdclark at gmail.com> */ -#define DEBUG /* for pr_debug() */ - #include <linux/stdarg.h> #include <linux/io.h> @@ -185,7 +183,8 @@ EXPORT_SYMBOL(__drm_printfn_info); void __drm_printfn_debug(struct drm_printer *p, struct va_format *vaf) { - pr_debug("%s %pV", p->prefix, vaf); + /* pr_debug callsite decorations are unhelpful here */ + printk(KERN_DEBUG "%s %pV", p->prefix, vaf); } EXPORT_SYMBOL(__drm_printfn_debug); -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 26/41] drm_print: refine drm_debug_enabled for jump-label
In order to use dynamic-debug's jump-label optimization in drm-debug, its clarifying to refine drm_debug_enabled into 3 uses: 1. drm_debug_enabled - legacy, public 2. __drm_debug_enabled - optimized for dyndbg jump-label enablement. 3. _drm_debug_enabled - pr_debug instrumented, observable 1. The legacy version always checks the bits. 2. is privileged, for use by __drm_dbg(), __drm_dev_dbg(), which do an early return unless the category is enabled. For dyndbg builds, debug callsites are selectively "pre-enabled", so __drm_debug_enabled() short-circuits to true there. Remaining callers of 1 may be able to use 2, case by case. 3. is 1st wrapped in a macro, with a pr_debug, which reports each usage in /proc/dynamic_debug/control, making it observable in the logs. The macro lets the pr_debug see the real caller, not an inline function. When plugged into 1, 3 identified ~10 remaining callers of the function, leading to the follow-on cleanup patch, and would allow activating the pr_debugs, estimating the callrate, and the potential savings by using the wrapper macro. It is unused ATM, but it fills out the picture. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 4 ++-- include/drm/drm_print.h | 28 ++++++++++++++++++++++++++++ 2 files changed, 30 insertions(+), 2 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 21b416af0be2..effb95b3c2bf 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -285,7 +285,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, struct va_format vaf; va_list args; - if (!drm_debug_enabled(category)) + if (!__drm_debug_enabled(category)) return; va_start(args, format); @@ -308,7 +308,7 @@ void ___drm_dbg(enum drm_debug_category category, const char *format, ...) struct va_format vaf; va_list args; - if (!drm_debug_enabled(category)) + if (!__drm_debug_enabled(category)) return; va_start(args, format); diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index dfdd81c3287c..7631b5fb669e 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -321,11 +321,39 @@ enum drm_debug_category { DRM_UT_DRMRES }; +/* + * 3 name flavors of drm_debug_enabled: + * drm_debug_enabled - public/legacy, always checks bits + * _drm_debug_enabled - instrumented to observe call-rates, est overheads. + * __drm_debug_enabled - privileged - knows jump-label state, can short-circuit + */ static inline bool drm_debug_enabled(enum drm_debug_category category) { return unlikely(__drm_debug & BIT(category)); } +/* + * Wrap fn in macro, so that the pr_debug sees the actual caller, not + * the inline fn. Using this name creates a callsite entry / control + * point in /proc/dynamic_debug/control. + */ +#define _drm_debug_enabled(category) \ + ({ \ + pr_debug("todo: maybe avoid via dyndbg\n"); \ + drm_debug_enabled(category); \ + }) + +#if defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) +/* + * dyndbg is wrapping the drm.debug API, so as to avoid the runtime + * bit-test overheads of drm_debug_enabled() in those api calls. + * In this case, executed callsites are known enabled, so true. + */ +#define __drm_debug_enabled(category) true +#else +#define __drm_debug_enabled(category) drm_debug_enabled(category) +#endif + /* * struct device based logging * -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 27/39] drm_print: add _ddebug descriptor to drm_*dbg prototypes
upgrade the callchain to drm_dbg() and drm_dev_dbg(); add a struct _ddebug ptr parameter to them, and supply that additional param by replacing the '_no_desc' flavor of dyndbg Factory macro currently used with the flavor that supplies the descriptor. NOTES: The descriptor gives these fns access to the decorator flags, but does none of the dynamic-prefixing done by __dynamic_emit_prefix(). DRM already has conventions for logging/messaging; just tossing optional decorations on top may not help. Instead, existing flags (or new ones) can be used to make current conventions optional. For CONFIG_DRM_USE_DYNAMIC_DEBUG=N, just pass null. Note: desc->class_id is redundant with category parameter, but its availability is dependent on desc. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 8 +++++--- include/drm/drm_print.h | 23 ++++++++++++----------- 2 files changed, 17 insertions(+), 14 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index e0de79a22255..92f3f45e410c 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -29,6 +29,7 @@ #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> +#include <linux/dynamic_debug.h> #include <drm/drm.h> #include <drm/drm_drv.h> @@ -278,8 +279,8 @@ void drm_dev_printk(const struct device *dev, const char *level, } EXPORT_SYMBOL(drm_dev_printk); -void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...) +void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, + enum drm_debug_category category, const char *format, ...) { struct va_format vaf; va_list args; @@ -287,6 +288,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, if (!__drm_debug_enabled(category)) return; + /* we know we are printing for either syslog, tracefs, or both */ va_start(args, format); vaf.fmt = format; vaf.va = &args; @@ -302,7 +304,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, } EXPORT_SYMBOL(__drm_dev_dbg); -void ___drm_dbg(enum drm_debug_category category, const char *format, ...) +void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const char *format, ...) { struct va_format vaf; va_list args; diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 3c16b00b6d21..2879a2f84381 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -363,9 +363,10 @@ static inline bool drm_debug_enabled(enum drm_debug_category category) __printf(3, 4) void drm_dev_printk(const struct device *dev, const char *level, const char *format, ...); -__printf(3, 4) -void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...); +struct _ddebug; +__printf(4, 5) +void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, + enum drm_debug_category category, const char *format, ...); /** * DRM_DEV_ERROR() - Error output. @@ -415,11 +416,11 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, #if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) #define drm_dev_dbg(dev, cat, fmt, ...) \ - __drm_dev_dbg(dev, cat, fmt, ##__VA_ARGS__) + __drm_dev_dbg(NULL, dev, cat, fmt, ##__VA_ARGS__) #else #define drm_dev_dbg(dev, cat, fmt, ...) \ - _dynamic_func_call_no_desc(fmt, __drm_dev_dbg, \ - dev, cat, fmt, ##__VA_ARGS__) + _dynamic_func_call_cls(cat, fmt, __drm_dev_dbg, \ + dev, cat, fmt, ##__VA_ARGS__) #endif /** @@ -522,17 +523,17 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, * Prefer drm_device based logging over device or prink based logging. */ -__printf(2, 3) -void ___drm_dbg(enum drm_debug_category category, const char *format, ...); +__printf(3, 4) +void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const char *format, ...); __printf(1, 2) void __drm_err(const char *format, ...); #if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) -#define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__) +#define __drm_dbg(fmt, ...) ___drm_dbg(NULL, fmt, ##__VA_ARGS__) #else #define __drm_dbg(cat, fmt, ...) \ - _dynamic_func_call_no_desc(fmt, ___drm_dbg, \ - cat, fmt, ##__VA_ARGS__) + _dynamic_func_call_cls(cat, fmt, ___drm_dbg, \ + cat, fmt, ##__VA_ARGS__) #endif /* Macros to make printk easier */ -- 2.36.1
Jim Cromie
2022-Jul-18 06:38 UTC
[Nouveau] [PATCH v3 27/41] 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 at gmail.com> --- drivers/gpu/drm/drm_print.c | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index effb95b3c2bf..e0de79a22255 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -23,8 +23,6 @@ * Rob Clark <robdclark at gmail.com> */ -#define DEBUG /* for pr_debug() */ - #include <linux/stdarg.h> #include <linux/io.h> @@ -185,7 +183,8 @@ EXPORT_SYMBOL(__drm_printfn_info); void __drm_printfn_debug(struct drm_printer *p, struct va_format *vaf) { - pr_debug("%s %pV", p->prefix, vaf); + /* pr_debug callsite decorations are unhelpful here */ + printk(KERN_DEBUG "%s %pV", p->prefix, vaf); } EXPORT_SYMBOL(__drm_printfn_debug); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 28/39] nouveau: change nvkm_debug/trace to use dev_dbg POC
These 2 macros formerly used dev_info, and they still check subdev->debug to gate the printing. So dyndbg control is redundant ATM (and possibly confusing, since its off by default). prdbg count is up from 3, or from 65 (with VMM_DEBUG here) [ 7.765379] dyndbg: 516 debug prints in module nouveau Its possible to control error, warn, info callsites too, but they're usually on, and the .data overheads on ~450 more callsites (56 bytes each) would just be wasted. $ for l in fatal error warn info debug trace spam; do echo $l; ack nvkm_$l drivers/gpu |wc; done fatal 3 19 335 error 289 1956 30651 warn 84 513 8860 info 14 88 1502 debug 387 2339 40844 trace 31 219 3368 spam 1 7 123 bash-5.1# echo $(( 516-65-387-31-1 )) 32 Thats approximate; not accounting #defines and doc/comment mentions. NOTE: this patch changes the log-level of the macro-issued messages from KERN_INFO to KERN_DEBUG. Adding a .kern_lvl field to struct _ddebug could fix that. RFC: dyndbg & subdev->debug Separate class-maps for each subdev are possible; except for the coordinated use of _base, each is independent, including choice of DISJOINT or LEVELS, as long as class-names don't conflict. So theres some flexibility. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index 96113c8bee8c..065d07ccea87 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -59,8 +59,8 @@ void nvkm_subdev_intr(struct nvkm_subdev *); #define nvkm_error(s,f,a...) nvkm_printk((s), ERROR, err, f, ##a) #define nvkm_warn(s,f,a...) nvkm_printk((s), WARN, notice, f, ##a) #define nvkm_info(s,f,a...) nvkm_printk((s), INFO, info, f, ##a) -#define nvkm_debug(s,f,a...) nvkm_printk((s), DEBUG, info, f, ##a) -#define nvkm_trace(s,f,a...) nvkm_printk((s), TRACE, info, f, ##a) +#define nvkm_debug(s,f,a...) nvkm_printk((s), DEBUG, dbg, f, ##a) +#define nvkm_trace(s,f,a...) nvkm_printk((s), TRACE, dbg, f, ##a) #define nvkm_spam(s,f,a...) nvkm_printk((s), SPAM, dbg, f, ##a) #define nvkm_error_ratelimited(s,f,a...) nvkm_printk((s), ERROR, err_ratelimited, f, ##a) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 28/41] drm_print: add _ddebug descriptor to drm_*dbg prototypes
upgrade the callchain to drm_dbg() and drm_dev_dbg(); add a struct _ddebug ptr parameter to them, and supply that additional param by replacing the '_no_desc' flavor of dyndbg Factory macro currently used with the flavor that supplies the descriptor. NOTES: The descriptor gives these fns access to the decorator flags, but does none of the dynamic-prefixing done by __dynamic_emit_prefix(). DRM already has conventions for logging/messaging; just tossing optional decorations on top may not help. Instead, existing flags (or new ones) can be used to make current conventions optional. For CONFIG_DRM_USE_DYNAMIC_DEBUG=N, just pass null. Note: desc->class_id is redundant with category parameter, but its availability is dependent on desc. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 8 +++++--- include/drm/drm_print.h | 23 ++++++++++++----------- 2 files changed, 17 insertions(+), 14 deletions(-) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index e0de79a22255..92f3f45e410c 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -29,6 +29,7 @@ #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> +#include <linux/dynamic_debug.h> #include <drm/drm.h> #include <drm/drm_drv.h> @@ -278,8 +279,8 @@ void drm_dev_printk(const struct device *dev, const char *level, } EXPORT_SYMBOL(drm_dev_printk); -void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...) +void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, + enum drm_debug_category category, const char *format, ...) { struct va_format vaf; va_list args; @@ -287,6 +288,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, if (!__drm_debug_enabled(category)) return; + /* we know we are printing for either syslog, tracefs, or both */ va_start(args, format); vaf.fmt = format; vaf.va = &args; @@ -302,7 +304,7 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, } EXPORT_SYMBOL(__drm_dev_dbg); -void ___drm_dbg(enum drm_debug_category category, const char *format, ...) +void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const char *format, ...) { struct va_format vaf; va_list args; diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 7631b5fb669e..46f14cfb401e 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -363,9 +363,10 @@ static inline bool drm_debug_enabled(enum drm_debug_category category) __printf(3, 4) void drm_dev_printk(const struct device *dev, const char *level, const char *format, ...); -__printf(3, 4) -void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, - const char *format, ...); +struct _ddebug; +__printf(4, 5) +void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, + enum drm_debug_category category, const char *format, ...); /** * DRM_DEV_ERROR() - Error output. @@ -415,11 +416,11 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, #if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) #define drm_dev_dbg(dev, cat, fmt, ...) \ - __drm_dev_dbg(dev, cat, fmt, ##__VA_ARGS__) + __drm_dev_dbg(NULL, dev, cat, fmt, ##__VA_ARGS__) #else #define drm_dev_dbg(dev, cat, fmt, ...) \ - _dynamic_func_call_no_desc(fmt, __drm_dev_dbg, \ - dev, cat, fmt, ##__VA_ARGS__) + _dynamic_func_call_cls(cat, fmt, __drm_dev_dbg, \ + dev, cat, fmt, ##__VA_ARGS__) #endif /** @@ -523,17 +524,17 @@ void __drm_dev_dbg(const struct device *dev, enum drm_debug_category category, * Prefer drm_device based logging over device or prink based logging. */ -__printf(2, 3) -void ___drm_dbg(enum drm_debug_category category, const char *format, ...); +__printf(3, 4) +void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const char *format, ...); __printf(1, 2) void __drm_err(const char *format, ...); #if !defined(CONFIG_DRM_USE_DYNAMIC_DEBUG) -#define __drm_dbg(fmt, ...) ___drm_dbg(fmt, ##__VA_ARGS__) +#define __drm_dbg(fmt, ...) ___drm_dbg(NULL, fmt, ##__VA_ARGS__) #else #define __drm_dbg(cat, fmt, ...) \ - _dynamic_func_call_no_desc(fmt, ___drm_dbg, \ - cat, fmt, ##__VA_ARGS__) + _dynamic_func_call_cls(cat, fmt, ___drm_dbg, \ + cat, fmt, ##__VA_ARGS__) #endif /* Macros to make printk easier */ -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 29/39] dyndbg: add _DPRINTK_FLAGS_ENABLED
Distinguish the condition: _DPRINTK_FLAGS_ENABLED from the bit: _DPRINTK_FLAGS_PRINT, and re-define former in terms of latter, in preparation to add a 2nd bit: _DPRINTK_FLAGS_TRACE Update JUMP_LABEL code block to check _DPRINTK_FLAGS_ENABLED symbol. Also add a 'K' to get new symbol _DPRINTK_FLAGS_PRINTK, in order to break any stale uses. CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 10 ++++++---- lib/dynamic_debug.c | 8 ++++---- 2 files changed, 10 insertions(+), 8 deletions(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index b50bdd5c8184..38cfdd5c0bdc 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -32,7 +32,7 @@ struct _ddebug { * writes commands to <debugfs>/dynamic_debug/control */ #define _DPRINTK_FLAGS_NONE 0 -#define _DPRINTK_FLAGS_PRINT (1<<0) /* printk() a message using the format */ +#define _DPRINTK_FLAGS_PRINTK (1 << 0) /* printk() a message using the format */ #define _DPRINTK_FLAGS_INCL_MODNAME (1<<1) #define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<2) #define _DPRINTK_FLAGS_INCL_LINENO (1<<3) @@ -42,8 +42,10 @@ struct _ddebug { (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\ _DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID) +#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK + #if defined DEBUG -#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT +#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK #else #define _DPRINTK_FLAGS_DEFAULT 0 #endif @@ -191,10 +193,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, #ifdef DEBUG #define DYNAMIC_DEBUG_BRANCH(descriptor) \ - likely(descriptor.flags & _DPRINTK_FLAGS_PRINT) + likely(descriptor.flags & _DPRINTK_FLAGS_ENABLED) #else #define DYNAMIC_DEBUG_BRANCH(descriptor) \ - unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT) + unlikely(descriptor.flags & _DPRINTK_FLAGS_ENABLED) #endif #endif /* CONFIG_JUMP_LABEL */ diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index dd27dc514aa3..2a46c642373a 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -89,7 +89,7 @@ static inline const char *trim_prefix(const char *path) } static struct { unsigned flag:8; char opt_char; } opt_array[] = { - { _DPRINTK_FLAGS_PRINT, 'p' }, + { _DPRINTK_FLAGS_PRINTK, 'p' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, @@ -246,10 +246,10 @@ static int ddebug_change(const struct ddebug_query *query, if (newflags == dp->flags) continue; #ifdef CONFIG_JUMP_LABEL - if (dp->flags & _DPRINTK_FLAGS_PRINT) { - if (!(newflags & _DPRINTK_FLAGS_PRINT)) + if (dp->flags & _DPRINTK_FLAGS_ENABLED) { + if (!(newflags & _DPRINTK_FLAGS_ENABLED)) static_branch_disable(&dp->key.dd_key_true); - } else if (newflags & _DPRINTK_FLAGS_PRINT) { + } else if (newflags & _DPRINTK_FLAGS_ENABLED) { static_branch_enable(&dp->key.dd_key_true); } #endif -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 29/41] nouveau: change nvkm_debug/trace to use dev_dbg POC
These 2 macros formerly used dev_info, and they still check subdev->debug to gate the printing. So dyndbg control is redundant ATM (and possibly confusing, since its off by default). prdbg count is up from 3, or from 65 (with VMM_DEBUG here) [ 7.765379] dyndbg: 516 debug prints in module nouveau Its possible to control error, warn, info callsites too, but they're usually on, and the .data overheads on ~450 more callsites (56 bytes each) would just be wasted. $ for l in fatal error warn info debug trace spam; do echo $l; ack nvkm_$l drivers/gpu |wc; done fatal 3 19 335 error 289 1956 30651 warn 84 513 8860 info 14 88 1502 debug 387 2339 40844 trace 31 219 3368 spam 1 7 123 bash-5.1# echo $(( 516-65-387-31-1 )) 32 Thats approximate; not accounting #defines and doc/comment mentions. NOTE: this patch changes the log-level of the macro-issued messages from KERN_INFO to KERN_DEBUG. Adding a .kern_lvl field to struct _ddebug could fix that. RFC: dyndbg & subdev->debug Separate class-maps for each subdev are possible; except for the coordinated use of _base, each is independent, including choice of DISJOINT or LEVELS, as long as class-names don't conflict. So theres some flexibility. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index 96113c8bee8c..065d07ccea87 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -59,8 +59,8 @@ void nvkm_subdev_intr(struct nvkm_subdev *); #define nvkm_error(s,f,a...) nvkm_printk((s), ERROR, err, f, ##a) #define nvkm_warn(s,f,a...) nvkm_printk((s), WARN, notice, f, ##a) #define nvkm_info(s,f,a...) nvkm_printk((s), INFO, info, f, ##a) -#define nvkm_debug(s,f,a...) nvkm_printk((s), DEBUG, info, f, ##a) -#define nvkm_trace(s,f,a...) nvkm_printk((s), TRACE, info, f, ##a) +#define nvkm_debug(s,f,a...) nvkm_printk((s), DEBUG, dbg, f, ##a) +#define nvkm_trace(s,f,a...) nvkm_printk((s), TRACE, dbg, f, ##a) #define nvkm_spam(s,f,a...) nvkm_printk((s), SPAM, dbg, f, ##a) #define nvkm_error_ratelimited(s,f,a...) nvkm_printk((s), ERROR, err_ratelimited, f, ##a) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 30/39] dyndbg: add _DPRINTK_FLAGS_TRACE
add new flag, and OR it into _DPRINTK_FLAGS_ENABLED definition CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 38cfdd5c0bdc..0752e6c21c6e 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -42,7 +42,9 @@ struct _ddebug { (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\ _DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID) -#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK +#define _DPRINTK_FLAGS_TRACE (1 << 5) +#define _DPRINTK_FLAGS_ENABLED (_DPRINTK_FLAGS_PRINTK | \ + _DPRINTK_FLAGS_TRACE) #if defined DEBUG #define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 30/41] tracing/events: Add __vstring() and __assign_vstr() helper macros
From: "Steven Rostedt (Google)" <rostedt at goodmis.org> There's several places that open code the following logic: TP_STRUCT__entry(__dynamic_array(char, msg, MSG_MAX)), TP_fast_assign(vsnprintf(__get_str(msg), MSG_MAX, vaf->fmt, *vaf->va);) To load a string created by variable array va_list. The main issue with this approach is that "MSG_MAX" usage in the __dynamic_array() portion. That actually just reserves the MSG_MAX in the event, and even wastes space because there's dynamic meta data also saved in the event to denote the offset and size of the dynamic array. It would have been better to just use a static __array() field. Instead, create __vstring() and __assign_vstr() that work like __string and __assign_str() but instead of taking a destination string to copy, take a format string and a va_list pointer and fill in the values. It uses the helper: #define __trace_event_vstr_len(fmt, va) \ ({ \ va_list __ap; \ int __ret; \ \ va_copy(__ap, *(va)); \ __ret = vsnprintf(NULL, 0, fmt, __ap); \ va_end(__ap); \ \ min(__ret, TRACE_EVENT_STR_MAX); \ }) To figure out the length to store the string. It may be slightly slower as it needs to run the vsnprintf() twice, but it now saves space on the ring buffer. Link: https://lkml.kernel.org/r/20220705224749.053570613 at goodmis.org Cc: Dennis Dalessandro <dennis.dalessandro at cornelisnetworks.com> Cc: Ingo Molnar <mingo at kernel.org> Cc: Andrew Morton <akpm at linux-foundation.org> Cc: Jason Gunthorpe <jgg at ziepe.ca> Cc: Leon Romanovsky <leon at kernel.org> Cc: Kalle Valo <kvalo at kernel.org> Cc: "David S. Miller" <davem at davemloft.net> Cc: Eric Dumazet <edumazet at google.com> Cc: Jakub Kicinski <kuba at kernel.org> Cc: Paolo Abeni <pabeni at redhat.com> Cc: Arend van Spriel <aspriel at gmail.com> Cc: Franky Lin <franky.lin at broadcom.com> Cc: Hante Meuleman <hante.meuleman at broadcom.com> Cc: Gregory Greenman <gregory.greenman at intel.com> Cc: Peter Chen <peter.chen at kernel.org> Cc: Greg Kroah-Hartman <gregkh at linuxfoundation.org> Cc: Mathias Nyman <mathias.nyman at intel.com> Cc: Chunfeng Yun <chunfeng.yun at mediatek.com> Cc: Bin Liu <b-liu at ti.com> Cc: Marek Lindner <mareklindner at neomailbox.ch> Cc: Simon Wunderlich <sw at simonwunderlich.de> Cc: Antonio Quartulli <a at unstable.cc> Cc: Sven Eckelmann <sven at narfation.org> Cc: Johannes Berg <johannes at sipsolutions.net> Cc: Jim Cromie <jim.cromie at gmail.com> Signed-off-by: Steven Rostedt (Google) <rostedt at goodmis.org> --- include/linux/trace_events.h | 18 ++++++++++++++++++ include/trace/stages/stage1_struct_define.h | 3 +++ include/trace/stages/stage2_data_offsets.h | 3 +++ include/trace/stages/stage4_event_fields.h | 3 +++ include/trace/stages/stage5_get_offsets.h | 4 ++++ include/trace/stages/stage6_event_callback.h | 7 +++++++ 6 files changed, 38 insertions(+) diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index e6e95a9f07a5..b18759a673c6 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -916,6 +916,24 @@ perf_trace_buf_submit(void *raw_data, int size, int rctx, u16 type, #endif +#define TRACE_EVENT_STR_MAX 512 + +/* + * gcc warns that you can not use a va_list in an inlined + * function. But lets me make it into a macro :-/ + */ +#define __trace_event_vstr_len(fmt, va) \ +({ \ + va_list __ap; \ + int __ret; \ + \ + va_copy(__ap, *(va)); \ + __ret = vsnprintf(NULL, 0, fmt, __ap) + 1; \ + va_end(__ap); \ + \ + min(__ret, TRACE_EVENT_STR_MAX); \ +}) + #endif /* _LINUX_TRACE_EVENT_H */ /* diff --git a/include/trace/stages/stage1_struct_define.h b/include/trace/stages/stage1_struct_define.h index a16783419687..1b7bab60434c 100644 --- a/include/trace/stages/stage1_struct_define.h +++ b/include/trace/stages/stage1_struct_define.h @@ -26,6 +26,9 @@ #undef __string_len #define __string_len(item, src, len) __dynamic_array(char, item, -1) +#undef __vstring +#define __vstring(item, fmt, ap) __dynamic_array(char, item, -1) + #undef __bitmask #define __bitmask(item, nr_bits) __dynamic_array(char, item, -1) diff --git a/include/trace/stages/stage2_data_offsets.h b/include/trace/stages/stage2_data_offsets.h index 42fd1e8813ec..1b7a8f764fdd 100644 --- a/include/trace/stages/stage2_data_offsets.h +++ b/include/trace/stages/stage2_data_offsets.h @@ -32,6 +32,9 @@ #undef __string_len #define __string_len(item, src, len) __dynamic_array(char, item, -1) +#undef __vstring +#define __vstring(item, fmt, ap) __dynamic_array(char, item, -1) + #undef __bitmask #define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1) diff --git a/include/trace/stages/stage4_event_fields.h b/include/trace/stages/stage4_event_fields.h index e80cdc397a43..c3790ec7a453 100644 --- a/include/trace/stages/stage4_event_fields.h +++ b/include/trace/stages/stage4_event_fields.h @@ -38,6 +38,9 @@ #undef __string_len #define __string_len(item, src, len) __dynamic_array(char, item, -1) +#undef __vstring +#define __vstring(item, fmt, ap) __dynamic_array(char, item, -1) + #undef __bitmask #define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1) diff --git a/include/trace/stages/stage5_get_offsets.h b/include/trace/stages/stage5_get_offsets.h index 7ee5931300e6..fba4c24ed9e6 100644 --- a/include/trace/stages/stage5_get_offsets.h +++ b/include/trace/stages/stage5_get_offsets.h @@ -39,6 +39,10 @@ #undef __string_len #define __string_len(item, src, len) __dynamic_array(char, item, (len) + 1) +#undef __vstring +#define __vstring(item, fmt, ap) __dynamic_array(char, item, \ + __trace_event_vstr_len(fmt, ap)) + #undef __rel_dynamic_array #define __rel_dynamic_array(type, item, len) \ __item_length = (len) * sizeof(type); \ diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index e1724f73594b..0f51f6b3ab70 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -24,6 +24,9 @@ #undef __string_len #define __string_len(item, src, len) __dynamic_array(char, item, -1) +#undef __vstring +#define __vstring(item, fmt, ap) __dynamic_array(char, item, -1) + #undef __assign_str #define __assign_str(dst, src) \ strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)"); @@ -35,6 +38,10 @@ __get_str(dst)[len] = '\0'; \ } while(0) +#undef __assign_vstr +#define __assign_vstr(dst, fmt, va) \ + vsnprintf(__get_str(dst), TRACE_EVENT_STR_MAX, fmt, *(va)) + #undef __bitmask #define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 32/39] dyndbg: 4 new trace-events: pr_debug, dev_dbg, drm_{, dev}debug
ddebug_trace() currently issues a single printk:console event. Replace that, adding include/trace/events/dyndbg.h, which defines 2 new events: - dyndbg:prdbg - from trace_prdbg() - if !dev - dyndbg:devdbg - from trace_devdbg() - if !!dev This links the legacy pr_debug API to tracefs, via dyndbg, allowing pr_debug()s etc to add just a little more user-context to the trace-logs, and then at users option, less syslog. The 2 new trace_*() calls accept their caller's args respectively, keeping the available info w/o alteration; we can't improve on transparency. The args: 1- struct _ddebug *descriptor, giving tracefs all of dyndbg's info. 2- struct device *dev, used by trace_devdbg(), if !!dev The trace_*() calls need the descriptor arg, the callchain prototypes above them are extended to provide it. The existing category param in this callchain is partially redundant; when descriptor is available, it has the class_id. dev_dbg(desc, dev...), if dev is true, issues a trace_devdbg(), otherwise trace_prdbg(). This way we dont consume buffer space storing nulls. Otherwise the events are equivalent. Also add include/trace/events/drm.h, to create 2 events for use in drm_dbg() and drm_devdbg(), and call them. This recapitulates the changes described above, connecting 3-10K drm.debug callsites to tracefs. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 25 ++++++++---- include/trace/events/drm.h | 68 ++++++++++++++++++++++++++++++++ include/trace/events/dyndbg.h | 74 +++++++++++++++++++++++++++++++++++ lib/dynamic_debug.c | 73 +++++++++++++++++----------------- 4 files changed, 197 insertions(+), 43 deletions(-) create mode 100644 include/trace/events/drm.h create mode 100644 include/trace/events/dyndbg.h diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 92f3f45e410c..9fb0b8e40dca 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -35,6 +35,9 @@ #include <drm/drm_drv.h> #include <drm/drm_print.h> +#define CREATE_TRACE_POINTS +#include <trace/events/drm.h> + /* * __drm_debug: Enable debug output. * Bitmask of DRM_UT_x. See include/drm/drm_print.h for details. @@ -293,13 +296,19 @@ void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, vaf.fmt = format; vaf.va = &args; - if (dev) - dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); - else - printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); - + if (dev) { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) + dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf); + if (desc->flags & _DPRINTK_FLAGS_TRACE) + trace_drm_devdbg(dev, category, &vaf); + } else { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf); + if (desc->flags & _DPRINTK_FLAGS_TRACE) + trace_drm_debug(category, &vaf); + } va_end(args); } EXPORT_SYMBOL(__drm_dev_dbg); @@ -319,6 +328,8 @@ void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const ch printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", __builtin_return_address(0), &vaf); + trace_drm_debug(category, &vaf); + va_end(args); } EXPORT_SYMBOL(___drm_dbg); diff --git a/include/trace/events/drm.h b/include/trace/events/drm.h new file mode 100644 index 000000000000..6de80dd68620 --- /dev/null +++ b/include/trace/events/drm.h @@ -0,0 +1,68 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM drm + +#if !defined(_TRACE_DRM_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_DRM_H + +#include <linux/tracepoint.h> + +/* drm_debug() was called, pass its args */ +TRACE_EVENT(drm_debug, + TP_PROTO(int drm_debug_category, struct va_format *vaf), + + TP_ARGS(drm_debug_category, vaf), + + TP_STRUCT__entry( + __field(int, drm_debug_category) + __dynamic_array(char, msg, 256) + ), + + TP_fast_assign( + int len; + + __entry->drm_debug_category = drm_debug_category; + vsnprintf(__get_str(msg), 256, vaf->fmt, *vaf->va); + + len = strlen(__get_str(msg)); + if (len > 0 && (__get_str(msg)[len - 1] == '\n')) + len -= 1; + __get_str(msg)[len] = 0; + ), + + TP_printk("%s", __get_str(msg)) +); + +/* drm_devdbg() was called, pass its args, preserving order */ +TRACE_EVENT(drm_devdbg, + TP_PROTO(const struct device *dev, int drm_debug_category, struct va_format *vaf), + + TP_ARGS(dev, drm_debug_category, vaf), + + TP_STRUCT__entry( + __field(const struct device*, dev) + __field(int, drm_debug_category) + __dynamic_array(char, msg, 256) + ), + + TP_fast_assign( + int len; + + __entry->drm_debug_category = drm_debug_category; + __entry->dev = dev; + vsnprintf(__get_str(msg), 256, vaf->fmt, *vaf->va); + + len = strlen(__get_str(msg)); + if (len > 0 && (__get_str(msg)[len - 1] == '\n')) + len -= 1; + __get_str(msg)[len] = 0; + ), + + TP_printk("cat:%d, %s %s", __entry->drm_debug_category, + dev_name(__entry->dev), __get_str(msg)) +); + +#endif /* _TRACE_DRM_H */ + +/* This part must be outside protection */ +#include <trace/define_trace.h> diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h new file mode 100644 index 000000000000..e19fcb56566c --- /dev/null +++ b/include/trace/events/dyndbg.h @@ -0,0 +1,74 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM dyndbg + +#if !defined(_TRACE_DYNDBG_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_DYNDBG_H + +#include <linux/tracepoint.h> + +/* capture pr_debug() callsite descriptor and message */ +TRACE_EVENT(prdbg, + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len), + + TP_ARGS(desc, text, len), + + TP_STRUCT__entry( + __field(const struct _ddebug *, desc) + __dynamic_array(char, msg, len + 1) + ), + + TP_fast_assign( + __entry->desc = desc; + /* + * Each trace entry is printed in a new line. + * If the msg finishes with '\n', cut it off + * to avoid blank lines in the trace. + */ + if (len > 0 && (text[len - 1] == '\n')) + len -= 1; + + memcpy(__get_str(msg), text, len); + __get_str(msg)[len] = 0; + ), + + TP_printk("%s.%s %s", __entry->desc->modname, + __entry->desc->function, __get_str(msg)) +); + +/* capture dev_dbg() callsite descriptor, device, and message */ +TRACE_EVENT(devdbg, + TP_PROTO(const struct _ddebug *desc, const struct device *dev, + const char *text, size_t len), + + TP_ARGS(desc, dev, text, len), + + TP_STRUCT__entry( + __field(const struct _ddebug *, desc) + __field(const struct device *, dev) + __dynamic_array(char, msg, len + 1) + ), + + TP_fast_assign( + __entry->desc = desc; + __entry->dev = (struct device *) dev; + /* + * Each trace entry is printed in a new line. + * If the msg finishes with '\n', cut it off + * to avoid blank lines in the trace. + */ + if (len > 0 && (text[len - 1] == '\n')) + len -= 1; + + memcpy(__get_str(msg), text, len); + __get_str(msg)[len] = 0; + ), + + TP_printk("%s.%s %s", __entry->desc->modname, + __entry->desc->function, __get_str(msg)) +); + +#endif /* _TRACE_DYNDBG_H */ + +/* This part must be outside protection */ +#include <trace/define_trace.h> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 66f12b9127c7..e000d037cb2e 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -36,7 +36,9 @@ #include <linux/sched.h> #include <linux/device.h> #include <linux/netdevice.h> -#include <trace/events/printk.h> + +#define CREATE_TRACE_POINTS +#include <trace/events/dyndbg.h> #include <rdma/ib_verbs.h> @@ -855,7 +857,9 @@ struct ddebug_trace_bufs { static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs); static DEFINE_PER_CPU(int, ddebug_trace_reserve); -static void ddebug_trace(const char *fmt, va_list args) +__printf(3, 0) +static void ddebug_trace(struct _ddebug *desc, const struct device *dev, + const char *fmt, va_list args) { struct ddebug_trace_buf *buf; int bufidx; @@ -874,7 +878,11 @@ static void ddebug_trace(const char *fmt, va_list args) buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx; len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args); - trace_console(buf->buf, len); + + if (!dev) + trace_prdbg(desc, buf->buf, len); + else + trace_devdbg(desc, dev, buf->buf, len); out: /* As above. */ @@ -884,9 +892,9 @@ static void ddebug_trace(const char *fmt, va_list args) } __printf(2, 3) -static void ddebug_printk(unsigned int flags, const char *fmt, ...) +static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...) { - if (flags & _DPRINTK_FLAGS_TRACE) { + if (desc->flags & _DPRINTK_FLAGS_TRACE) { va_list args; va_start(args, fmt); @@ -894,11 +902,11 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...) * All callers include the KERN_DEBUG prefix to keep the * vprintk case simple; strip it out for tracing. */ - ddebug_trace(fmt + strlen(KERN_DEBUG), args); + ddebug_trace(desc, NULL, fmt + strlen(KERN_DEBUG), args); va_end(args); } - if (flags & _DPRINTK_FLAGS_PRINTK) { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) { va_list args; va_start(args, fmt); @@ -908,19 +916,19 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...) } __printf(3, 4) -static void ddebug_dev_printk(unsigned int flags, const struct device *dev, +static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev, const char *fmt, ...) { - if (flags & _DPRINTK_FLAGS_TRACE) { + if (desc->flags & _DPRINTK_FLAGS_TRACE) { va_list args; va_start(args, fmt); - ddebug_trace(fmt, args); + ddebug_trace(desc, dev, fmt, args); va_end(args); } - if (flags & _DPRINTK_FLAGS_PRINTK) { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) { va_list args; va_start(args, fmt); @@ -943,7 +951,7 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) vaf.fmt = fmt; vaf.va = &args; - ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV", + ddebug_printk(descriptor, KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf); va_end(args); @@ -954,7 +962,6 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, const struct device *dev, const char *fmt, ...) { struct va_format vaf; - unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -964,15 +971,14 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; - flags = descriptor->flags; if (!dev) { - ddebug_printk(flags, KERN_DEBUG "(NULL device *): %pV", - &vaf); + ddebug_printk(descriptor, KERN_DEBUG "(NULL device *): %pV", + &vaf); } else { char buf[PREFIX_SIZE] = ""; - ddebug_dev_printk(flags, dev, "%s%s %s: %pV", + ddebug_dev_printk(descriptor, dev, "%s%s %s: %pV", dynamic_emit_prefix(descriptor, buf), dev_driver_string(dev), dev_name(dev), &vaf); @@ -988,7 +994,6 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, const struct net_device *dev, const char *fmt, ...) { struct va_format vaf; - unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -998,24 +1003,22 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; - flags = descriptor->flags; if (dev && dev->dev.parent) { char buf[PREFIX_SIZE] = ""; - ddebug_dev_printk(flags, dev->dev.parent, - "%s%s %s %s%s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev->dev.parent), - dev_name(dev->dev.parent), - netdev_name(dev), netdev_reg_state(dev), - &vaf); + ddebug_dev_printk(descriptor, dev->dev.parent, + "%s%s %s %s%s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev->dev.parent), + dev_name(dev->dev.parent), + netdev_name(dev), netdev_reg_state(dev), + &vaf); } else if (dev) { - ddebug_printk(flags, KERN_DEBUG "%s%s: %pV", - netdev_name(dev), netdev_reg_state(dev), &vaf); + ddebug_dev_printk(descriptor, &dev->dev, KERN_DEBUG "%s%s: %pV", + netdev_name(dev), netdev_reg_state(dev), &vaf); } else { - ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV", - &vaf); + ddebug_printk(descriptor, KERN_DEBUG "(NULL net_device): %pV", &vaf); } va_end(args); @@ -1031,18 +1034,16 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, { struct va_format vaf; va_list args; - unsigned int flags; va_start(args, fmt); vaf.fmt = fmt; vaf.va = &args; - flags = descriptor->flags; if (ibdev && ibdev->dev.parent) { char buf[PREFIX_SIZE] = ""; - ddebug_dev_printk(flags, ibdev->dev.parent, + ddebug_dev_printk(descriptor, ibdev->dev.parent, "%s%s %s %s: %pV", dynamic_emit_prefix(descriptor, buf), dev_driver_string(ibdev->dev.parent), @@ -1050,10 +1051,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, dev_name(&ibdev->dev), &vaf); } else if (ibdev) { - ddebug_printk(flags, KERN_DEBUG "%s: %pV", - dev_name(&ibdev->dev), &vaf); + ddebug_dev_printk(descriptor, &ibdev->dev, KERN_DEBUG "%s: %pV", + dev_name(&ibdev->dev), &vaf); } else { - ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf); + ddebug_printk(descriptor, KERN_DEBUG "(NULL ip_device): %pV", &vaf); } va_end(args); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 31/41] dyndbg: add _DPRINTK_FLAGS_ENABLED
Distinguish the condition: _DPRINTK_FLAGS_ENABLED from the bit: _DPRINTK_FLAGS_PRINT, and re-define former in terms of latter, in preparation to add a 2nd bit: _DPRINTK_FLAGS_TRACE Update JUMP_LABEL code block to check _DPRINTK_FLAGS_ENABLED symbol. Also add a 'K' to get new symbol _DPRINTK_FLAGS_PRINTK, in order to break any stale uses. CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 10 ++++++---- lib/dynamic_debug.c | 8 ++++---- 2 files changed, 10 insertions(+), 8 deletions(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index b50bdd5c8184..38cfdd5c0bdc 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -32,7 +32,7 @@ struct _ddebug { * writes commands to <debugfs>/dynamic_debug/control */ #define _DPRINTK_FLAGS_NONE 0 -#define _DPRINTK_FLAGS_PRINT (1<<0) /* printk() a message using the format */ +#define _DPRINTK_FLAGS_PRINTK (1 << 0) /* printk() a message using the format */ #define _DPRINTK_FLAGS_INCL_MODNAME (1<<1) #define _DPRINTK_FLAGS_INCL_FUNCNAME (1<<2) #define _DPRINTK_FLAGS_INCL_LINENO (1<<3) @@ -42,8 +42,10 @@ struct _ddebug { (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\ _DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID) +#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK + #if defined DEBUG -#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT +#define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK #else #define _DPRINTK_FLAGS_DEFAULT 0 #endif @@ -191,10 +193,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, #ifdef DEBUG #define DYNAMIC_DEBUG_BRANCH(descriptor) \ - likely(descriptor.flags & _DPRINTK_FLAGS_PRINT) + likely(descriptor.flags & _DPRINTK_FLAGS_ENABLED) #else #define DYNAMIC_DEBUG_BRANCH(descriptor) \ - unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT) + unlikely(descriptor.flags & _DPRINTK_FLAGS_ENABLED) #endif #endif /* CONFIG_JUMP_LABEL */ diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index dd27dc514aa3..2a46c642373a 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -89,7 +89,7 @@ static inline const char *trim_prefix(const char *path) } static struct { unsigned flag:8; char opt_char; } opt_array[] = { - { _DPRINTK_FLAGS_PRINT, 'p' }, + { _DPRINTK_FLAGS_PRINTK, 'p' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, @@ -246,10 +246,10 @@ static int ddebug_change(const struct ddebug_query *query, if (newflags == dp->flags) continue; #ifdef CONFIG_JUMP_LABEL - if (dp->flags & _DPRINTK_FLAGS_PRINT) { - if (!(newflags & _DPRINTK_FLAGS_PRINT)) + if (dp->flags & _DPRINTK_FLAGS_ENABLED) { + if (!(newflags & _DPRINTK_FLAGS_ENABLED)) static_branch_disable(&dp->key.dd_key_true); - } else if (newflags & _DPRINTK_FLAGS_PRINT) { + } else if (newflags & _DPRINTK_FLAGS_ENABLED) { static_branch_enable(&dp->key.dd_key_true); } #endif -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 31/39] dyndbg: add write-events-to-tracefs code
adds: ddebug_trace() uses trace_console() temporarily to issue printk:console event uses internal-ish __ftrace_trace_stack code: 4-context buffer stack, barriers per Steve Rostedt call it from new funcs: ddebug_printk() - print to both syslog/tracefs ddebug_dev_printk() - dev-print to both syslog/tracefs These handle both _DPRINTK_FLAGS_PRINTK and _DPRINTK_FLAGS_TRACE cases, allowing to vsnprintf the message once and use it for both, skipping past the KERN_DEBUG character for tracing. Finally, adjust the callers: __ddebug_{pr_debug,{,net,ib}dev_dbg}, replacing printk and dev_printk with the new funcs above. The _DPRINTK_FLAGS_TRACE flag character is 'T', so the following finds all callsites enabled for tracing: grep -P =p?T /proc/dynamic_debug/control This patch,~1,~2 are basically copies of: https://lore.kernel.org/lkml/20200825153338.17061-1-vincent.whitchurch at axis.com/ with a few differences: - s/dynamic_/ddebug_/ on Vincent's additions - __printf attrs on the _printk funcs - reuses trace_console() event, not adding a new "printk:dyndbg" event. next patch replaces this with 2 new events CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- .../admin-guide/dynamic-debug-howto.rst | 5 +- lib/dynamic_debug.c | 156 +++++++++++++++--- 2 files changed, 133 insertions(+), 28 deletions(-) diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst index cdf1da69e43c..103e79269bac 100644 --- a/Documentation/admin-guide/dynamic-debug-howto.rst +++ b/Documentation/admin-guide/dynamic-debug-howto.rst @@ -209,8 +209,9 @@ of the characters:: The flags are:: - p enables the pr_debug() callsite. - _ enables no flags. + p callsite prints to syslog + T callsite issues a dyndbg:* trace-event + _ enables no flags Decorator flags add to the message-prefix, in order: t Include thread ID, or <intr> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 2a46c642373a..66f12b9127c7 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -36,6 +36,7 @@ #include <linux/sched.h> #include <linux/device.h> #include <linux/netdevice.h> +#include <trace/events/printk.h> #include <rdma/ib_verbs.h> @@ -90,6 +91,7 @@ static inline const char *trim_prefix(const char *path) static struct { unsigned flag:8; char opt_char; } opt_array[] = { { _DPRINTK_FLAGS_PRINTK, 'p' }, + { _DPRINTK_FLAGS_TRACE, 'T' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, @@ -835,6 +837,98 @@ static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf) return buf; } +/* + * This code is heavily based on __ftrace_trace_stack(). + * + * Allow 4 levels of nesting: normal, softirq, irq, NMI. + */ +#define DYNAMIC_TRACE_NESTING 4 + +struct ddebug_trace_buf { + char buf[256]; +}; + +struct ddebug_trace_bufs { + struct ddebug_trace_buf bufs[DYNAMIC_TRACE_NESTING]; +}; + +static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs); +static DEFINE_PER_CPU(int, ddebug_trace_reserve); + +static void ddebug_trace(const char *fmt, va_list args) +{ + struct ddebug_trace_buf *buf; + int bufidx; + int len; + + preempt_disable_notrace(); + + bufidx = __this_cpu_inc_return(ddebug_trace_reserve) - 1; + + if (WARN_ON_ONCE(bufidx > DYNAMIC_TRACE_NESTING)) + goto out; + + /* For the same reasons as in __ftrace_trace_stack(). */ + barrier(); + + buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx; + + len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args); + trace_console(buf->buf, len); + +out: + /* As above. */ + barrier(); + __this_cpu_dec(ddebug_trace_reserve); + preempt_enable_notrace(); +} + +__printf(2, 3) +static void ddebug_printk(unsigned int flags, const char *fmt, ...) +{ + if (flags & _DPRINTK_FLAGS_TRACE) { + va_list args; + + va_start(args, fmt); + /* + * All callers include the KERN_DEBUG prefix to keep the + * vprintk case simple; strip it out for tracing. + */ + ddebug_trace(fmt + strlen(KERN_DEBUG), args); + va_end(args); + } + + if (flags & _DPRINTK_FLAGS_PRINTK) { + va_list args; + + va_start(args, fmt); + vprintk(fmt, args); + va_end(args); + } +} + +__printf(3, 4) +static void ddebug_dev_printk(unsigned int flags, const struct device *dev, + const char *fmt, ...) +{ + + if (flags & _DPRINTK_FLAGS_TRACE) { + va_list args; + + va_start(args, fmt); + ddebug_trace(fmt, args); + va_end(args); + } + + if (flags & _DPRINTK_FLAGS_PRINTK) { + va_list args; + + va_start(args, fmt); + dev_vprintk_emit(LOGLEVEL_DEBUG, dev, fmt, args); + va_end(args); + } +} + void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) { va_list args; @@ -849,16 +943,18 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) vaf.fmt = fmt; vaf.va = &args; - printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf); + ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV", + dynamic_emit_prefix(descriptor, buf), &vaf); va_end(args); } EXPORT_SYMBOL(__dynamic_pr_debug); void __dynamic_dev_dbg(struct _ddebug *descriptor, - const struct device *dev, const char *fmt, ...) + const struct device *dev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -868,16 +964,18 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (!dev) { - printk(KERN_DEBUG "(NULL device *): %pV", &vaf); + ddebug_printk(flags, KERN_DEBUG "(NULL device *): %pV", + &vaf); } else { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev), dev_name(dev), - &vaf); + ddebug_dev_printk(flags, dev, "%s%s %s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev), dev_name(dev), + &vaf); } va_end(args); @@ -890,6 +988,7 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, const struct net_device *dev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -899,22 +998,24 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (dev && dev->dev.parent) { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent, - "%s%s %s %s%s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev->dev.parent), - dev_name(dev->dev.parent), - netdev_name(dev), netdev_reg_state(dev), - &vaf); + ddebug_dev_printk(flags, dev->dev.parent, + "%s%s %s %s%s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev->dev.parent), + dev_name(dev->dev.parent), + netdev_name(dev), netdev_reg_state(dev), + &vaf); } else if (dev) { - printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev), - netdev_reg_state(dev), &vaf); + ddebug_printk(flags, KERN_DEBUG "%s%s: %pV", + netdev_name(dev), netdev_reg_state(dev), &vaf); } else { - printk(KERN_DEBUG "(NULL net_device): %pV", &vaf); + ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV", + &vaf); } va_end(args); @@ -930,26 +1031,29 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, { struct va_format vaf; va_list args; + unsigned int flags; va_start(args, fmt); vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (ibdev && ibdev->dev.parent) { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent, - "%s%s %s %s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(ibdev->dev.parent), - dev_name(ibdev->dev.parent), - dev_name(&ibdev->dev), - &vaf); + ddebug_dev_printk(flags, ibdev->dev.parent, + "%s%s %s %s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(ibdev->dev.parent), + dev_name(ibdev->dev.parent), + dev_name(&ibdev->dev), + &vaf); } else if (ibdev) { - printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf); + ddebug_printk(flags, KERN_DEBUG "%s: %pV", + dev_name(&ibdev->dev), &vaf); } else { - printk(KERN_DEBUG "(NULL ib_device): %pV", &vaf); + ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf); } va_end(args); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 32/41] dyndbg: add _DPRINTK_FLAGS_TRACE
add new flag, and OR it into _DPRINTK_FLAGS_ENABLED definition CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/linux/dynamic_debug.h | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h index 38cfdd5c0bdc..0752e6c21c6e 100644 --- a/include/linux/dynamic_debug.h +++ b/include/linux/dynamic_debug.h @@ -42,7 +42,9 @@ struct _ddebug { (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\ _DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID) -#define _DPRINTK_FLAGS_ENABLED _DPRINTK_FLAGS_PRINTK +#define _DPRINTK_FLAGS_TRACE (1 << 5) +#define _DPRINTK_FLAGS_ENABLED (_DPRINTK_FLAGS_PRINTK | \ + _DPRINTK_FLAGS_TRACE) #if defined DEBUG #define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINTK -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 33/41] dyndbg: add write-events-to-tracefs code
1st, internals: adds: ddebug_trace() uses trace_console() temporarily to issue printk:console event uses internal-ish __ftrace_trace_stack code: 4-context buffer stack, barriers per Steve Rostedt call it from new mid-layer funcs: ddebug_printk() - ddebug_trace or vprintk (to syslog) ddebug_dev_printk() - ddebug_trace or dev_printk_emit These handle both _DPRINTK_FLAGS_PRINTK and _DPRINTK_FLAGS_TRACE cases, allowing to vsnprintf the message once and use it for both, skipping past the KERN_DEBUG prefix for tracing. Finally, adjust the top-layer: __dynamic_{pr_debug,{,net,ib}dev_dbg), replacing printk/dev_printk_emit with ddebug_printk/ddebug_dev_printk. Interface additions: new 'T' flag decl in opt_array. existing code handles it like others. document the new flag. To enable drm.debug ATOMIC messages to tracefs: :#> echo class DRM_UT_ATOMIC +T > /proc/dynamic_debug/control NB: This patch,~1,~2 are basically direct copies of: https://lore.kernel.org/lkml/20200825153338.17061-1-vincent.whitchurch at axis.com/ with a few differences: - s/dynamic_/ddebug_/ on Vincent's additions, tighter naming. - __printf attrs on the _printk funcs. - reuses trace_console() event, not adding a new "printk:dyndbg" event. later patches differentiate to new events. - a flags arg remains unchanged, adapt later to *descriptor. CC: vincent.whitchurch at axis.com Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- .../admin-guide/dynamic-debug-howto.rst | 5 +- lib/dynamic_debug.c | 156 +++++++++++++++--- 2 files changed, 133 insertions(+), 28 deletions(-) diff --git a/Documentation/admin-guide/dynamic-debug-howto.rst b/Documentation/admin-guide/dynamic-debug-howto.rst index cdf1da69e43c..103e79269bac 100644 --- a/Documentation/admin-guide/dynamic-debug-howto.rst +++ b/Documentation/admin-guide/dynamic-debug-howto.rst @@ -209,8 +209,9 @@ of the characters:: The flags are:: - p enables the pr_debug() callsite. - _ enables no flags. + p callsite prints to syslog + T callsite issues a dyndbg:* trace-event + _ enables no flags Decorator flags add to the message-prefix, in order: t Include thread ID, or <intr> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 2a46c642373a..66f12b9127c7 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -36,6 +36,7 @@ #include <linux/sched.h> #include <linux/device.h> #include <linux/netdevice.h> +#include <trace/events/printk.h> #include <rdma/ib_verbs.h> @@ -90,6 +91,7 @@ static inline const char *trim_prefix(const char *path) static struct { unsigned flag:8; char opt_char; } opt_array[] = { { _DPRINTK_FLAGS_PRINTK, 'p' }, + { _DPRINTK_FLAGS_TRACE, 'T' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, @@ -835,6 +837,98 @@ static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf) return buf; } +/* + * This code is heavily based on __ftrace_trace_stack(). + * + * Allow 4 levels of nesting: normal, softirq, irq, NMI. + */ +#define DYNAMIC_TRACE_NESTING 4 + +struct ddebug_trace_buf { + char buf[256]; +}; + +struct ddebug_trace_bufs { + struct ddebug_trace_buf bufs[DYNAMIC_TRACE_NESTING]; +}; + +static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs); +static DEFINE_PER_CPU(int, ddebug_trace_reserve); + +static void ddebug_trace(const char *fmt, va_list args) +{ + struct ddebug_trace_buf *buf; + int bufidx; + int len; + + preempt_disable_notrace(); + + bufidx = __this_cpu_inc_return(ddebug_trace_reserve) - 1; + + if (WARN_ON_ONCE(bufidx > DYNAMIC_TRACE_NESTING)) + goto out; + + /* For the same reasons as in __ftrace_trace_stack(). */ + barrier(); + + buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx; + + len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args); + trace_console(buf->buf, len); + +out: + /* As above. */ + barrier(); + __this_cpu_dec(ddebug_trace_reserve); + preempt_enable_notrace(); +} + +__printf(2, 3) +static void ddebug_printk(unsigned int flags, const char *fmt, ...) +{ + if (flags & _DPRINTK_FLAGS_TRACE) { + va_list args; + + va_start(args, fmt); + /* + * All callers include the KERN_DEBUG prefix to keep the + * vprintk case simple; strip it out for tracing. + */ + ddebug_trace(fmt + strlen(KERN_DEBUG), args); + va_end(args); + } + + if (flags & _DPRINTK_FLAGS_PRINTK) { + va_list args; + + va_start(args, fmt); + vprintk(fmt, args); + va_end(args); + } +} + +__printf(3, 4) +static void ddebug_dev_printk(unsigned int flags, const struct device *dev, + const char *fmt, ...) +{ + + if (flags & _DPRINTK_FLAGS_TRACE) { + va_list args; + + va_start(args, fmt); + ddebug_trace(fmt, args); + va_end(args); + } + + if (flags & _DPRINTK_FLAGS_PRINTK) { + va_list args; + + va_start(args, fmt); + dev_vprintk_emit(LOGLEVEL_DEBUG, dev, fmt, args); + va_end(args); + } +} + void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) { va_list args; @@ -849,16 +943,18 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) vaf.fmt = fmt; vaf.va = &args; - printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf); + ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV", + dynamic_emit_prefix(descriptor, buf), &vaf); va_end(args); } EXPORT_SYMBOL(__dynamic_pr_debug); void __dynamic_dev_dbg(struct _ddebug *descriptor, - const struct device *dev, const char *fmt, ...) + const struct device *dev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -868,16 +964,18 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (!dev) { - printk(KERN_DEBUG "(NULL device *): %pV", &vaf); + ddebug_printk(flags, KERN_DEBUG "(NULL device *): %pV", + &vaf); } else { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev), dev_name(dev), - &vaf); + ddebug_dev_printk(flags, dev, "%s%s %s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev), dev_name(dev), + &vaf); } va_end(args); @@ -890,6 +988,7 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, const struct net_device *dev, const char *fmt, ...) { struct va_format vaf; + unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -899,22 +998,24 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (dev && dev->dev.parent) { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent, - "%s%s %s %s%s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev->dev.parent), - dev_name(dev->dev.parent), - netdev_name(dev), netdev_reg_state(dev), - &vaf); + ddebug_dev_printk(flags, dev->dev.parent, + "%s%s %s %s%s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev->dev.parent), + dev_name(dev->dev.parent), + netdev_name(dev), netdev_reg_state(dev), + &vaf); } else if (dev) { - printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev), - netdev_reg_state(dev), &vaf); + ddebug_printk(flags, KERN_DEBUG "%s%s: %pV", + netdev_name(dev), netdev_reg_state(dev), &vaf); } else { - printk(KERN_DEBUG "(NULL net_device): %pV", &vaf); + ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV", + &vaf); } va_end(args); @@ -930,26 +1031,29 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, { struct va_format vaf; va_list args; + unsigned int flags; va_start(args, fmt); vaf.fmt = fmt; vaf.va = &args; + flags = descriptor->flags; if (ibdev && ibdev->dev.parent) { char buf[PREFIX_SIZE] = ""; - dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent, - "%s%s %s %s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(ibdev->dev.parent), - dev_name(ibdev->dev.parent), - dev_name(&ibdev->dev), - &vaf); + ddebug_dev_printk(flags, ibdev->dev.parent, + "%s%s %s %s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(ibdev->dev.parent), + dev_name(ibdev->dev.parent), + dev_name(&ibdev->dev), + &vaf); } else if (ibdev) { - printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf); + ddebug_printk(flags, KERN_DEBUG "%s: %pV", + dev_name(&ibdev->dev), &vaf); } else { - printk(KERN_DEBUG "(NULL ib_device): %pV", &vaf); + ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf); } va_end(args); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 33/39] dyndbg/drm: POC add tracebits sysfs-knob
clone DRM.debug interface to DRM.tracebits: ie map bits to drm-debug-categories, except this interface enables messages to tracefs, not to syslog. 1- we reuse the class-map added previously. this reflects the single source of both syslog/trace events 2- add a 2nd struct ddebug_classes_bitmap_param refs 1, reusing it. flags = "T", to enable trace-events on this callsite. 3- module_param_cb([2]) - does the sysfs part Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 9fb0b8e40dca..47a41d96beea 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -45,6 +45,9 @@ unsigned long __drm_debug; EXPORT_SYMBOL(__drm_debug); +unsigned long __drm_trace; +EXPORT_SYMBOL(__drm_trace); + MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" "\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" "\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" @@ -77,6 +80,13 @@ static struct ddebug_classes_bitmap_param drm_debug_bitmap = { .map = &drm_debug_classes, }; module_param_cb(debug, ¶m_ops_dyndbg_classes, &drm_debug_bitmap, 0600); + +static struct ddebug_classes_bitmap_param drm_trace_bitmap = { + .bits = &__drm_trace, + .flags = "T", + .map = &drm_debug_classes, +}; +module_param_cb(tracecats, ¶m_ops_dyndbg_classes, &drm_trace_bitmap, 0600); #endif void __drm_puts_coredump(struct drm_printer *p, const char *str) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 34/39] drm-print: add drm_dbg_driver, improve namespace symmetry
drm_print defines all of these: drm_dbg_{core,kms,prime,atomic,vbl,lease,_dp,_drmres} but not drm_dbg_driver itself, which was the original drm_dbg. To improve namespace symmetry, change the drm_dbg defn to drm_dbg_driver, and redef grandfathered name to symmetric one. This may help with nouveau, which uses its own stack of macros to construct calls to dev_info, dev_dbg, etc, for which adaptation might mean drm_dbg_##driver constructs. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/drm/drm_print.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 2879a2f84381..46f14cfb401e 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -497,7 +497,7 @@ void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, #define drm_dbg_core(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_CORE, fmt, ##__VA_ARGS__) -#define drm_dbg(drm, fmt, ...) \ +#define drm_dbg_driver(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRIVER, fmt, ##__VA_ARGS__) #define drm_dbg_kms(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_KMS, fmt, ##__VA_ARGS__) @@ -516,6 +516,7 @@ void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, #define drm_dbg_drmres(drm, fmt, ...) \ drm_dev_dbg((drm) ? (drm)->dev : NULL, DRM_UT_DRMRES, fmt, ##__VA_ARGS__) +#define drm_dbg(drm, fmt, ...) drm_dbg_driver(drm, fmt, ##__VA_ARGS__) /* * printk based logging -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 34/41] dyndbg: add 2 trace-events: drm_{, dev}debug
Add include/trace/events/drm.h, with 2 new events: drm_debug() & drm_devdbg(), and call them from drm_dbg() & drm_dev_dbg(). This is easy, cuz the callers already build the vaf that the callee wants. This allows the 3-5k drm.debug/on-dyndbg callsites to independently (re-)direct messages to tracefs, not just syslog. ISTM this is good; debug traffic can be sent (just) to the tool where it can be best used. Over time, I'd expect to see less traffic to syslog. NOTE: The message formats for the 2 events are both sub-optimal. (both have event-name too) drm_devdbg: TP_printk("cat:%d, %s %s", __entry->drm_debug_category, "cat:%d" should be "%s", but the classnames arent really in-scope here. Maybe the events-decl-header should be under drm somewhere, so that class-names are available. It would also be nice to replace the event-name with the classname, as the names are highly client centric. drm_dbg: TP_printk("%s", __get_str(msg)) same as above. NB: The existing category param in this callchain is partially redundant; when descriptor is available, it has the callsite's class_id. If later, CONFIG_DRM_USE_DYNAMIC_DEBUG:=y (hardwired), then category can be dropped here, since the descriptor will always be available. Also, if combined with header-move (or maybe its expanding inclusion by lib/dynamic_debug), we could add the optional flags prefix, by exposing dynamic_emit_prefix. And perhaps this could be done only in TP_printk, to save work while writing to the ring-buffer. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 25 ++++++++++++----- include/trace/events/drm.h | 54 +++++++++++++++++++++++++++++++++++++ 2 files changed, 72 insertions(+), 7 deletions(-) create mode 100644 include/trace/events/drm.h diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 92f3f45e410c..9fb0b8e40dca 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -35,6 +35,9 @@ #include <drm/drm_drv.h> #include <drm/drm_print.h> +#define CREATE_TRACE_POINTS +#include <trace/events/drm.h> + /* * __drm_debug: Enable debug output. * Bitmask of DRM_UT_x. See include/drm/drm_print.h for details. @@ -293,13 +296,19 @@ void __drm_dev_dbg(struct _ddebug *desc, const struct device *dev, vaf.fmt = format; vaf.va = &args; - if (dev) - dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); - else - printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); - + if (dev) { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) + dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf); + if (desc->flags & _DPRINTK_FLAGS_TRACE) + trace_drm_devdbg(dev, category, &vaf); + } else { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf); + if (desc->flags & _DPRINTK_FLAGS_TRACE) + trace_drm_debug(category, &vaf); + } va_end(args); } EXPORT_SYMBOL(__drm_dev_dbg); @@ -319,6 +328,8 @@ void ___drm_dbg(struct _ddebug *desc, enum drm_debug_category category, const ch printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", __builtin_return_address(0), &vaf); + trace_drm_debug(category, &vaf); + va_end(args); } EXPORT_SYMBOL(___drm_dbg); diff --git a/include/trace/events/drm.h b/include/trace/events/drm.h new file mode 100644 index 000000000000..589fa1e1f2c2 --- /dev/null +++ b/include/trace/events/drm.h @@ -0,0 +1,54 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM drm + +#if !defined(_TRACE_DRM_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_DRM_H + +#include <linux/tracepoint.h> + +/* drm_debug() was called, pass its args */ +TRACE_EVENT(drm_debug, + TP_PROTO(int drm_debug_category, struct va_format *vaf), + + TP_ARGS(drm_debug_category, vaf), + + TP_STRUCT__entry( + __field(int, drm_debug_category) + __vstring(msg, vaf->fmt, vaf->va) + ), + + TP_fast_assign( + __entry->drm_debug_category = drm_debug_category; + __assign_vstr(msg, vaf->fmt, vaf->va); + ), + + TP_printk("%s", __get_str(msg)) +); + +/* drm_devdbg() was called, pass its args, preserving order */ +TRACE_EVENT(drm_devdbg, + TP_PROTO(const struct device *dev, int drm_debug_category, struct va_format *vaf), + + TP_ARGS(dev, drm_debug_category, vaf), + + TP_STRUCT__entry( + __field(const struct device*, dev) + __field(int, drm_debug_category) + __vstring(msg, vaf->fmt, vaf->va) + ), + + TP_fast_assign( + __entry->drm_debug_category = drm_debug_category; + __entry->dev = dev; + __assign_vstr(msg, vaf->fmt, vaf->va); + ), + + TP_printk("cat:%d, %s %s", __entry->drm_debug_category, + dev_name(__entry->dev), __get_str(msg)) +); + +#endif /* _TRACE_DRM_H */ + +/* This part must be outside protection */ +#include <trace/define_trace.h> -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 35/41] dyndbg: add 2 more trace-events: pr_debug, dev_dbg
ddebug_trace() currently issues a single printk:console event. Replace that, adding include/trace/events/dyndbg.h, which defines 2 new events: - dyndbg:prdbg - from trace_prdbg() - if !dev - dyndbg:devdbg - from trace_devdbg() - if !!dev This links the legacy pr_debug API to tracefs, via dyndbg, allowing pr_debug()s etc to add just a little more user-context to the trace-logs, and then at users option, less syslog. The 2 new trace_*() calls accept their caller's args respectively, keeping the available info w/o alteration; we can't improve on full disclosure. The args: 1- struct _ddebug *descriptor, giving tracefs all of dyndbg's info. this replaces flags, which is in desc 2- struct device *dev, used by trace_devdbg(), if !!dev The trace_*() calls need the descriptor arg, the prototypes of the callchain above them are extended to provide it. dev_dbg(desc, dev...), if dev is true, issues a trace_devdbg(), otherwise trace_prdbg(). This way we don't consume buffer space storing nulls. Otherwise the events are equivalent. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- include/trace/events/dyndbg.h | 74 +++++++++++++++++++++++++++++++++++ lib/dynamic_debug.c | 73 +++++++++++++++++----------------- 2 files changed, 111 insertions(+), 36 deletions(-) create mode 100644 include/trace/events/dyndbg.h diff --git a/include/trace/events/dyndbg.h b/include/trace/events/dyndbg.h new file mode 100644 index 000000000000..e19fcb56566c --- /dev/null +++ b/include/trace/events/dyndbg.h @@ -0,0 +1,74 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM dyndbg + +#if !defined(_TRACE_DYNDBG_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_DYNDBG_H + +#include <linux/tracepoint.h> + +/* capture pr_debug() callsite descriptor and message */ +TRACE_EVENT(prdbg, + TP_PROTO(const struct _ddebug *desc, const char *text, size_t len), + + TP_ARGS(desc, text, len), + + TP_STRUCT__entry( + __field(const struct _ddebug *, desc) + __dynamic_array(char, msg, len + 1) + ), + + TP_fast_assign( + __entry->desc = desc; + /* + * Each trace entry is printed in a new line. + * If the msg finishes with '\n', cut it off + * to avoid blank lines in the trace. + */ + if (len > 0 && (text[len - 1] == '\n')) + len -= 1; + + memcpy(__get_str(msg), text, len); + __get_str(msg)[len] = 0; + ), + + TP_printk("%s.%s %s", __entry->desc->modname, + __entry->desc->function, __get_str(msg)) +); + +/* capture dev_dbg() callsite descriptor, device, and message */ +TRACE_EVENT(devdbg, + TP_PROTO(const struct _ddebug *desc, const struct device *dev, + const char *text, size_t len), + + TP_ARGS(desc, dev, text, len), + + TP_STRUCT__entry( + __field(const struct _ddebug *, desc) + __field(const struct device *, dev) + __dynamic_array(char, msg, len + 1) + ), + + TP_fast_assign( + __entry->desc = desc; + __entry->dev = (struct device *) dev; + /* + * Each trace entry is printed in a new line. + * If the msg finishes with '\n', cut it off + * to avoid blank lines in the trace. + */ + if (len > 0 && (text[len - 1] == '\n')) + len -= 1; + + memcpy(__get_str(msg), text, len); + __get_str(msg)[len] = 0; + ), + + TP_printk("%s.%s %s", __entry->desc->modname, + __entry->desc->function, __get_str(msg)) +); + +#endif /* _TRACE_DYNDBG_H */ + +/* This part must be outside protection */ +#include <trace/define_trace.h> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 66f12b9127c7..e000d037cb2e 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -36,7 +36,9 @@ #include <linux/sched.h> #include <linux/device.h> #include <linux/netdevice.h> -#include <trace/events/printk.h> + +#define CREATE_TRACE_POINTS +#include <trace/events/dyndbg.h> #include <rdma/ib_verbs.h> @@ -855,7 +857,9 @@ struct ddebug_trace_bufs { static DEFINE_PER_CPU(struct ddebug_trace_bufs, ddebug_trace_bufs); static DEFINE_PER_CPU(int, ddebug_trace_reserve); -static void ddebug_trace(const char *fmt, va_list args) +__printf(3, 0) +static void ddebug_trace(struct _ddebug *desc, const struct device *dev, + const char *fmt, va_list args) { struct ddebug_trace_buf *buf; int bufidx; @@ -874,7 +878,11 @@ static void ddebug_trace(const char *fmt, va_list args) buf = this_cpu_ptr(ddebug_trace_bufs.bufs) + bufidx; len = vscnprintf(buf->buf, sizeof(buf->buf), fmt, args); - trace_console(buf->buf, len); + + if (!dev) + trace_prdbg(desc, buf->buf, len); + else + trace_devdbg(desc, dev, buf->buf, len); out: /* As above. */ @@ -884,9 +892,9 @@ static void ddebug_trace(const char *fmt, va_list args) } __printf(2, 3) -static void ddebug_printk(unsigned int flags, const char *fmt, ...) +static void ddebug_printk(struct _ddebug *desc, const char *fmt, ...) { - if (flags & _DPRINTK_FLAGS_TRACE) { + if (desc->flags & _DPRINTK_FLAGS_TRACE) { va_list args; va_start(args, fmt); @@ -894,11 +902,11 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...) * All callers include the KERN_DEBUG prefix to keep the * vprintk case simple; strip it out for tracing. */ - ddebug_trace(fmt + strlen(KERN_DEBUG), args); + ddebug_trace(desc, NULL, fmt + strlen(KERN_DEBUG), args); va_end(args); } - if (flags & _DPRINTK_FLAGS_PRINTK) { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) { va_list args; va_start(args, fmt); @@ -908,19 +916,19 @@ static void ddebug_printk(unsigned int flags, const char *fmt, ...) } __printf(3, 4) -static void ddebug_dev_printk(unsigned int flags, const struct device *dev, +static void ddebug_dev_printk(struct _ddebug *desc, const struct device *dev, const char *fmt, ...) { - if (flags & _DPRINTK_FLAGS_TRACE) { + if (desc->flags & _DPRINTK_FLAGS_TRACE) { va_list args; va_start(args, fmt); - ddebug_trace(fmt, args); + ddebug_trace(desc, dev, fmt, args); va_end(args); } - if (flags & _DPRINTK_FLAGS_PRINTK) { + if (desc->flags & _DPRINTK_FLAGS_PRINTK) { va_list args; va_start(args, fmt); @@ -943,7 +951,7 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) vaf.fmt = fmt; vaf.va = &args; - ddebug_printk(descriptor->flags, KERN_DEBUG "%s%pV", + ddebug_printk(descriptor, KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf); va_end(args); @@ -954,7 +962,6 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, const struct device *dev, const char *fmt, ...) { struct va_format vaf; - unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -964,15 +971,14 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; - flags = descriptor->flags; if (!dev) { - ddebug_printk(flags, KERN_DEBUG "(NULL device *): %pV", - &vaf); + ddebug_printk(descriptor, KERN_DEBUG "(NULL device *): %pV", + &vaf); } else { char buf[PREFIX_SIZE] = ""; - ddebug_dev_printk(flags, dev, "%s%s %s: %pV", + ddebug_dev_printk(descriptor, dev, "%s%s %s: %pV", dynamic_emit_prefix(descriptor, buf), dev_driver_string(dev), dev_name(dev), &vaf); @@ -988,7 +994,6 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, const struct net_device *dev, const char *fmt, ...) { struct va_format vaf; - unsigned int flags; va_list args; BUG_ON(!descriptor); @@ -998,24 +1003,22 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, vaf.fmt = fmt; vaf.va = &args; - flags = descriptor->flags; if (dev && dev->dev.parent) { char buf[PREFIX_SIZE] = ""; - ddebug_dev_printk(flags, dev->dev.parent, - "%s%s %s %s%s: %pV", - dynamic_emit_prefix(descriptor, buf), - dev_driver_string(dev->dev.parent), - dev_name(dev->dev.parent), - netdev_name(dev), netdev_reg_state(dev), - &vaf); + ddebug_dev_printk(descriptor, dev->dev.parent, + "%s%s %s %s%s: %pV", + dynamic_emit_prefix(descriptor, buf), + dev_driver_string(dev->dev.parent), + dev_name(dev->dev.parent), + netdev_name(dev), netdev_reg_state(dev), + &vaf); } else if (dev) { - ddebug_printk(flags, KERN_DEBUG "%s%s: %pV", - netdev_name(dev), netdev_reg_state(dev), &vaf); + ddebug_dev_printk(descriptor, &dev->dev, KERN_DEBUG "%s%s: %pV", + netdev_name(dev), netdev_reg_state(dev), &vaf); } else { - ddebug_printk(flags, KERN_DEBUG "(NULL net_device): %pV", - &vaf); + ddebug_printk(descriptor, KERN_DEBUG "(NULL net_device): %pV", &vaf); } va_end(args); @@ -1031,18 +1034,16 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, { struct va_format vaf; va_list args; - unsigned int flags; va_start(args, fmt); vaf.fmt = fmt; vaf.va = &args; - flags = descriptor->flags; if (ibdev && ibdev->dev.parent) { char buf[PREFIX_SIZE] = ""; - ddebug_dev_printk(flags, ibdev->dev.parent, + ddebug_dev_printk(descriptor, ibdev->dev.parent, "%s%s %s %s: %pV", dynamic_emit_prefix(descriptor, buf), dev_driver_string(ibdev->dev.parent), @@ -1050,10 +1051,10 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, dev_name(&ibdev->dev), &vaf); } else if (ibdev) { - ddebug_printk(flags, KERN_DEBUG "%s: %pV", - dev_name(&ibdev->dev), &vaf); + ddebug_dev_printk(descriptor, &ibdev->dev, KERN_DEBUG "%s: %pV", + dev_name(&ibdev->dev), &vaf); } else { - ddebug_printk(flags, KERN_DEBUG "(NULL ip_device): %pV", &vaf); + ddebug_printk(descriptor, KERN_DEBUG "(NULL ip_device): %pV", &vaf); } va_end(args); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 35/39] nouveau: adapt NV_DEBUG, NV_ATOMIC to use DRM.debug
These 2 macros used drm_debug_enabled() on DRM_UT_{DRIVER,ATOMIC} respectively, replace those with drm_dbg_##cat invocations. this results in new class'd prdbg callsites: :#> grep nouveau /proc/dynamic_debug/control | grep class | wc 116 1130 15584 :#> grep nouveau /proc/dynamic_debug/control | grep class | grep DRIVER | wc 74 704 9709 :#> grep nouveau /proc/dynamic_debug/control | grep class | grep ATOMIC | wc 31 307 4237 :#> grep nouveau /proc/dynamic_debug/control | grep class | grep KMS | wc 11 119 1638 the KMS entries are due to existing uses of drm_dbg_kms(). Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/nouveau_drv.h | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/drivers/gpu/drm/nouveau/nouveau_drv.h b/drivers/gpu/drm/nouveau/nouveau_drv.h index b2a970aa9bf4..f266cd6b0405 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drv.h +++ b/drivers/gpu/drm/nouveau/nouveau_drv.h @@ -39,6 +39,7 @@ */ #include <linux/notifier.h> +#include <linux/dynamic_debug.h> #include <nvif/client.h> #include <nvif/device.h> @@ -264,13 +265,16 @@ void nouveau_drm_device_remove(struct drm_device *dev); #define NV_WARN(drm,f,a...) NV_PRINTK(warn, &(drm)->client, f, ##a) #define NV_INFO(drm,f,a...) NV_PRINTK(info, &(drm)->client, f, ##a) -#define NV_DEBUG(drm,f,a...) do { \ - if (drm_debug_enabled(DRM_UT_DRIVER)) \ - NV_PRINTK(info, &(drm)->client, f, ##a); \ +#define NV_DRMDBG(cat,c,f,a...) do { \ + struct nouveau_cli *_cli = (c); \ + drm_dbg_##cat(_cli->drm->dev, "%s: "f, _cli->name, ##a); \ } while(0) -#define NV_ATOMIC(drm,f,a...) do { \ - if (drm_debug_enabled(DRM_UT_ATOMIC)) \ - NV_PRINTK(info, &(drm)->client, f, ##a); \ + +#define NV_DEBUG(drm,f,a...) do { \ + NV_DRMDBG(driver, &(drm)->client, f, ##a); \ +} while(0) +#define NV_ATOMIC(drm,f,a...) do { \ + NV_DRMDBG(atomic, &(drm)->client, f, ##a); \ } while(0) #define NV_PRINTK_ONCE(l,c,f,a...) NV_PRINTK(l##_once,c,f, ##a) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 36/41] dyndbg/drm: POC add tracebits sysfs-knob
clone DRM.debug interface to DRM.tracebits: ie declare __drm_trace, map its bits to drm-debug-categories, except this interface enables messages to tracefs, not to syslog. 1- we reuse the drm_debug_classes class-map added previously. this reflects the single source of both syslog/trace events and is why structs classmap and bitmap-param are separate. 2- add a 2nd struct ddebug_classes_bitmap_param refs 1, reusing it. flags = "T", to enable trace-events on this callsite. 3- module_param_cb([2]) - does the sysfs part Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/drm_print.c | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 9fb0b8e40dca..47a41d96beea 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -45,6 +45,9 @@ unsigned long __drm_debug; EXPORT_SYMBOL(__drm_debug); +unsigned long __drm_trace; +EXPORT_SYMBOL(__drm_trace); + MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" "\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" "\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" @@ -77,6 +80,13 @@ static struct ddebug_classes_bitmap_param drm_debug_bitmap = { .map = &drm_debug_classes, }; module_param_cb(debug, ¶m_ops_dyndbg_classes, &drm_debug_bitmap, 0600); + +static struct ddebug_classes_bitmap_param drm_trace_bitmap = { + .bits = &__drm_trace, + .flags = "T", + .map = &drm_debug_classes, +}; +module_param_cb(tracecats, ¶m_ops_dyndbg_classes, &drm_trace_bitmap, 0600); #endif void __drm_puts_coredump(struct drm_printer *p, const char *str) -- 2.36.1
clone the nvkm_printk,_,__ macro ladder into nvkm_drmdbg,_,__. And alter debug, trace, spam macros to use the renamed ladder. This *sets-up* (not done yet) to remove the _subdev->debug >= (l) condition, once the bitmap-param is wired up correctly, and figured into dyndbg's jump-label enablement. starting with: static struct ddebug_classes_bitmap_param drm_trace_bitmap = { .bits = &__drm_trace, .flags = "T", .map = &drm_trace_classes, }; module_param_cb(tracecats, ¶m_ops_dyndbg_classes, &drm_trace_bitmap, 0600); The missing part might be re-setting the .bits field to ref _subdev->debug, while respecting the _subdev's lifecycle. no functional changes. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index 065d07ccea87..b9c2afab321f 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -59,9 +59,17 @@ void nvkm_subdev_intr(struct nvkm_subdev *); #define nvkm_error(s,f,a...) nvkm_printk((s), ERROR, err, f, ##a) #define nvkm_warn(s,f,a...) nvkm_printk((s), WARN, notice, f, ##a) #define nvkm_info(s,f,a...) nvkm_printk((s), INFO, info, f, ##a) -#define nvkm_debug(s,f,a...) nvkm_printk((s), DEBUG, dbg, f, ##a) -#define nvkm_trace(s,f,a...) nvkm_printk((s), TRACE, dbg, f, ##a) -#define nvkm_spam(s,f,a...) nvkm_printk((s), SPAM, dbg, f, ##a) + +#define nvkm_drmdbg__(s,l,p,f,a...) do { \ + const struct nvkm_subdev *_subdev = (s); \ + if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ + dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ +} while(0) +#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_DBG_##l, dbg, f, ##a) +#define nvkm_debug(s,f,a...) nvkm_drmdbg_((s), DEBUG, f, ##a) +#define nvkm_trace(s,f,a...) nvkm_drmdbg_((s), TRACE, f, ##a) +#define nvkm_spam(s,f,a...) nvkm_drmdbg_((s), SPAM, f, ##a) #define nvkm_error_ratelimited(s,f,a...) nvkm_printk((s), ERROR, err_ratelimited, f, ##a) + #endif -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 37/41] nouveau: adapt NV_DEBUG, NV_ATOMIC to use DRM.debug
These 2 macros used drm_debug_enabled() on DRM_UT_{DRIVER,ATOMIC} respectively, replace those with drm_dbg_##cat invocations. this results in new class'd prdbg callsites: :#> grep nouveau /proc/dynamic_debug/control | grep class | wc 116 1130 15584 :#> grep nouveau /proc/dynamic_debug/control | grep class | grep DRIVER | wc 74 704 9709 :#> grep nouveau /proc/dynamic_debug/control | grep class | grep ATOMIC | wc 31 307 4237 :#> grep nouveau /proc/dynamic_debug/control | grep class | grep KMS | wc 11 119 1638 the KMS entries are due to existing uses of drm_dbg_kms(). Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/nouveau_drv.h | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/drivers/gpu/drm/nouveau/nouveau_drv.h b/drivers/gpu/drm/nouveau/nouveau_drv.h index b2a970aa9bf4..f266cd6b0405 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drv.h +++ b/drivers/gpu/drm/nouveau/nouveau_drv.h @@ -39,6 +39,7 @@ */ #include <linux/notifier.h> +#include <linux/dynamic_debug.h> #include <nvif/client.h> #include <nvif/device.h> @@ -264,13 +265,16 @@ void nouveau_drm_device_remove(struct drm_device *dev); #define NV_WARN(drm,f,a...) NV_PRINTK(warn, &(drm)->client, f, ##a) #define NV_INFO(drm,f,a...) NV_PRINTK(info, &(drm)->client, f, ##a) -#define NV_DEBUG(drm,f,a...) do { \ - if (drm_debug_enabled(DRM_UT_DRIVER)) \ - NV_PRINTK(info, &(drm)->client, f, ##a); \ +#define NV_DRMDBG(cat,c,f,a...) do { \ + struct nouveau_cli *_cli = (c); \ + drm_dbg_##cat(_cli->drm->dev, "%s: "f, _cli->name, ##a); \ } while(0) -#define NV_ATOMIC(drm,f,a...) do { \ - if (drm_debug_enabled(DRM_UT_ATOMIC)) \ - NV_PRINTK(info, &(drm)->client, f, ##a); \ + +#define NV_DEBUG(drm,f,a...) do { \ + NV_DRMDBG(driver, &(drm)->client, f, ##a); \ +} while(0) +#define NV_ATOMIC(drm,f,a...) do { \ + NV_DRMDBG(atomic, &(drm)->client, f, ##a); \ } while(0) #define NV_PRINTK_ONCE(l,c,f,a...) NV_PRINTK(l##_once,c,f, ##a) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 37/39] nouveau-dbg: add 2 verbose-classmaps for CLI, SUBDEV
nouveau has additional debug variables to consider: drivers/gpu/drm/nouveau/include/nvkm/core/device.h 131: if (_device->debug >= (l)) \ drivers/gpu/drm/nouveau/include/nvkm/core/client.h 39: if (_client->debug >= NV_DBG_##l) \ drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h 54: if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ This is another baby-step, that seems not to break, so lets get a snapshot. whats done here: In nouveau_drm.c, do DECLARE_DYNDBG_CLASSMAP(verbose-type) 2x more, right after the drm DECLARE, for cli and subdev. Adjust base for each, to share the 0..30 classid-space. These declare class-names: NV_CLI_DBG_* NV_SUBDEV_DBG_* accordingly. Note: class-name-space is flat and wide, so super-generic names like INFO should be prefixed; who could predict what a generic V3 does across all modules. s should be included adjusting the base to avoid each other, and the 0-10 already mapped to drm-debug-categorys (just above this addition). In nvkm/core/debug.h, add enums to match the names, with initial values to match the bases. In nvkm/core/subdev.h, alter (recently added) nvkm_drmdbg_() to use NV_SUBDEV_DBG_* instead of NV_DBG_*. NB: in both classmaps, Ive left FATAL..WARN out, they're not really optional the way INFO..SPAM are; dyndbg shouldn't be able to turn them off. bash-5.1# modprobe nouveau [ 966.107833] dyndbg: 3 debug prints in module wmi [ 966.342188] dyndbg: class[0]: module:nouveau base:15 len:5 ty:1 [ 966.342873] dyndbg: 15: 0 NV_SUBDEV_DBG_OFF [ 966.343352] dyndbg: 16: 1 NV_SUBDEV_DBG_INFO [ 966.343912] dyndbg: 17: 2 NV_SUBDEV_DBG_DEBUG [ 966.344443] dyndbg: 18: 3 NV_SUBDEV_DBG_TRACE [ 966.344938] dyndbg: 19: 4 NV_SUBDEV_DBG_SPAM [ 966.345402] dyndbg: class[1]: module:nouveau base:10 len:5 ty:1 [ 966.346011] dyndbg: 10: 0 NV_CLI_DBG_OFF [ 966.346477] dyndbg: 11: 1 NV_CLI_DBG_INFO [ 966.346989] dyndbg: 12: 2 NV_CLI_DBG_DEBUG [ 966.347442] dyndbg: 13: 3 NV_CLI_DBG_TRACE [ 966.347875] dyndbg: 14: 4 NV_CLI_DBG_SPAM [ 966.348284] dyndbg: class[2]: module:nouveau base:0 len:10 ty:0 [ 966.348888] dyndbg: 0: 0 DRM_UT_CORE [ 966.349310] dyndbg: 1: 1 DRM_UT_DRIVER [ 966.349694] dyndbg: 2: 2 DRM_UT_KMS [ 966.350083] dyndbg: 3: 3 DRM_UT_PRIME [ 966.350482] dyndbg: 4: 4 DRM_UT_ATOMIC [ 966.351016] dyndbg: 5: 5 DRM_UT_VBL [ 966.351475] dyndbg: 6: 6 DRM_UT_STATE [ 966.351899] dyndbg: 7: 7 DRM_UT_LEASE [ 966.352309] dyndbg: 8: 8 DRM_UT_DP [ 966.352678] dyndbg: 9: 9 DRM_UT_DRMRES [ 966.353104] dyndbg: module:nouveau attached 3 classes [ 966.353759] dyndbg: 119 debug prints in module nouveau NOTE: it was 632 with previous commit, switching NV_DEBUG to use NV_SUBDEV_DBG_DEBUG instead of NV_DBG_DEBUG may be the cause. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- .../gpu/drm/nouveau/include/nvkm/core/debug.h | 16 ++++++++++++++++ .../gpu/drm/nouveau/include/nvkm/core/subdev.h | 3 ++- drivers/gpu/drm/nouveau/nouveau_drm.c | 14 ++++++++++++++ 3 files changed, 32 insertions(+), 1 deletion(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h b/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h index b4a9c7d991ca..6a155a23a3d1 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h @@ -9,4 +9,20 @@ #define NV_DBG_TRACE 5 #define NV_DBG_PARANOIA 6 #define NV_DBG_SPAM 7 + +enum nv_cli_dbg_verbose { + NV_CLI_DBG_OFF = 10, + NV_CLI_DBG_INFO, + NV_CLI_DBG_DEBUG, + NV_CLI_DBG_TRACE, + NV_CLI_DBG_SPAM +}; +enum nv_subdev_dbg_verbose { + NV_SUBDEV_DBG_OFF = 15, + NV_SUBDEV_DBG_INFO, + NV_SUBDEV_DBG_DEBUG, + NV_SUBDEV_DBG_TRACE, + NV_SUBDEV_DBG_SPAM +}; + #endif diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index b9c2afab321f..bf9c69f4fc3e 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -2,6 +2,7 @@ #ifndef __NVKM_SUBDEV_H__ #define __NVKM_SUBDEV_H__ #include <core/device.h> +#include <core/debug.h> enum nvkm_subdev_type { #define NVKM_LAYOUT_ONCE(t,s,p,...) t, @@ -65,7 +66,7 @@ void nvkm_subdev_intr(struct nvkm_subdev *); if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ } while(0) -#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_DBG_##l, dbg, f, ##a) +#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_SUBDEV_DBG_##l, dbg, f, ##a) #define nvkm_debug(s,f,a...) nvkm_drmdbg_((s), DEBUG, f, ##a) #define nvkm_trace(s,f,a...) nvkm_drmdbg_((s), TRACE, f, ##a) #define nvkm_spam(s,f,a...) nvkm_drmdbg_((s), SPAM, f, ##a) diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c b/drivers/gpu/drm/nouveau/nouveau_drm.c index 76e3a8d50b01..85b63b527877 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drm.c +++ b/drivers/gpu/drm/nouveau/nouveau_drm.c @@ -83,6 +83,20 @@ DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, "DRM_UT_DP", "DRM_UT_DRMRES"); +DECLARE_DYNDBG_CLASSMAP(nv_cli_debug_verbose, DD_CLASS_TYPE_VERBOSE, 10, + "NV_CLI_DBG_OFF", + "NV_CLI_DBG_INFO", + "NV_CLI_DBG_DEBUG", + "NV_CLI_DBG_TRACE", + "NV_CLI_DBG_SPAM"); + +DECLARE_DYNDBG_CLASSMAP(nv_subdev_debug_verbose, DD_CLASS_TYPE_VERBOSE, 15, + "NV_SUBDEV_DBG_OFF", + "NV_SUBDEV_DBG_INFO", + "NV_SUBDEV_DBG_DEBUG", + "NV_SUBDEV_DBG_TRACE", + "NV_SUBDEV_DBG_SPAM"); + MODULE_PARM_DESC(config, "option string to pass to driver core"); static char *nouveau_config; module_param_named(config, nouveau_config, charp, 0400); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 38/39] nouveau-dbg: fixup lost prdbgs
Undo the 1-line change that reduced count of prdbgs from 632 to 119. ie: s/NV_SUBDEV_DBG_##l/NV_DBG_##l/ So heres what happened: new symbol is 15 (or 10), and fails this macro test, so gets compiled out, and the dev_dbg is excluded. if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ I could hack this, by doing (l + base), but base is pretty distant. OTOH, the whole CONFIG_NOUVEAU_DEBUG check could be reworked; given that trace is minumum recommended, theres not that many callsites elided (SPAM only iirc) at compile-time, and dyndbg means keeping them has "zero" run=cost (and 56 bytes per). So this config item doesnt do much when DRM_USE_DYNAMIC_DEBUG=y. So this is a useful place to stop and look around, try to guess which trail to take.. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index bf9c69f4fc3e..d5f6ca05d5fa 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -66,7 +66,7 @@ void nvkm_subdev_intr(struct nvkm_subdev *); if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ } while(0) -#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_SUBDEV_DBG_##l, dbg, f, ##a) +#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_DBG_##l, dbg, f, ##a) #define nvkm_debug(s,f,a...) nvkm_drmdbg_((s), DEBUG, f, ##a) #define nvkm_trace(s,f,a...) nvkm_drmdbg_((s), TRACE, f, ##a) #define nvkm_spam(s,f,a...) nvkm_drmdbg_((s), SPAM, f, ##a) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 38/41] nouveau-dyndbg: alter DEBUG, TRACE, SPAM levels to use dyndbg
clone the nvkm_printk,_,__ macro ladder into nvkm_drmdbg,_,__. And alter debug, trace, spam macros to use the renamed ladder. This *sets-up* to remove the _subdev->debug >= (l) condition from the __ macro, once the bitmap-param is wired up correctly (pointing at the right state-bit-vector), and figured into dyndbg's jump-label enablement. Also, with DYNDBG=y, sites will be off, until enabled by >control, or by #define DEBUG at compile time. Starting with this as a model: static struct ddebug_classes_bitmap_param drm_trace_bitmap = { .bits = &__drm_trace, .flags = "T", .map = &drm_trace_classes, }; module_param_cb(tracecats, ¶m_ops_dyndbg_classes, &drm_trace_bitmap,.. We basically need to clone that, but ref a different .bits: .bits = &_subdev->debug, while respecting the _subdev's lifecycle. hints welcomed. no functional changes. (other than dyndbg's default-off) Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index 065d07ccea87..b9c2afab321f 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -59,9 +59,17 @@ void nvkm_subdev_intr(struct nvkm_subdev *); #define nvkm_error(s,f,a...) nvkm_printk((s), ERROR, err, f, ##a) #define nvkm_warn(s,f,a...) nvkm_printk((s), WARN, notice, f, ##a) #define nvkm_info(s,f,a...) nvkm_printk((s), INFO, info, f, ##a) -#define nvkm_debug(s,f,a...) nvkm_printk((s), DEBUG, dbg, f, ##a) -#define nvkm_trace(s,f,a...) nvkm_printk((s), TRACE, dbg, f, ##a) -#define nvkm_spam(s,f,a...) nvkm_printk((s), SPAM, dbg, f, ##a) + +#define nvkm_drmdbg__(s,l,p,f,a...) do { \ + const struct nvkm_subdev *_subdev = (s); \ + if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ + dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ +} while(0) +#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_DBG_##l, dbg, f, ##a) +#define nvkm_debug(s,f,a...) nvkm_drmdbg_((s), DEBUG, f, ##a) +#define nvkm_trace(s,f,a...) nvkm_drmdbg_((s), TRACE, f, ##a) +#define nvkm_spam(s,f,a...) nvkm_drmdbg_((s), SPAM, f, ##a) #define nvkm_error_ratelimited(s,f,a...) nvkm_printk((s), ERROR, err_ratelimited, f, ##a) + #endif -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 39/41] nouveau-dbg: add 2 verbose-classmaps for CLI, SUBDEV
nouveau has additional debug variables to consider: drivers/gpu/drm/nouveau/include/nvkm/core/device.h 131: if (_device->debug >= (l)) \ drivers/gpu/drm/nouveau/include/nvkm/core/client.h 39: if (_client->debug >= NV_DBG_##l) \ drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h 54: if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ This is another baby-step, that seems not to break, so lets get a snapshot. whats done here: In nouveau_drm.c, declare class-names: NV_CLI_DBG_* NV_SUBDEV_DBG_* by calling DECLARE_DYNDBG_CLASSMAP(verbose-type) 2x more, right after the drm DECLARE, for cli and subdev. Adjust base to 10,15, to avoid 0-10 allocated subsystem-wide for drm.debug. This shares the 0..30 classid-space. In nvkm/core/debug.h, add enums to match the names, with initial values to match the bases. In nvkm/core/subdev.h, alter (recently added) nvkm_drmdbg_() to use NV_SUBDEV_DBG_* instead of NV_DBG_*. Note: this is undone next, because base != CONFIG_NOUVEAU_DEBUG. NOTES: class-name-space is flat and wide, so super-generic names like INFO should be prefixed; who could predict what a generic "V1" does across all modules. A sub-system prefix, such as "DRM_UT_" could be considered a working shorthand for module "foo,bar,buzz" (which wouldnt work), but it adds a layer of authors-judgment in the classifications. In both classmaps, Ive left FATAL..WARN out, they're not really optional the way INFO..SPAM are; even if they were defaulted to on, dyndbg shouldn't be able to turn them off. bash-5.1# modprobe nouveau [ 966.107833] dyndbg: 3 debug prints in module wmi [ 966.342188] dyndbg: class[0]: module:nouveau base:15 len:5 ty:1 [ 966.342873] dyndbg: 15: 0 NV_SUBDEV_DBG_OFF [ 966.343352] dyndbg: 16: 1 NV_SUBDEV_DBG_INFO [ 966.343912] dyndbg: 17: 2 NV_SUBDEV_DBG_DEBUG [ 966.344443] dyndbg: 18: 3 NV_SUBDEV_DBG_TRACE [ 966.344938] dyndbg: 19: 4 NV_SUBDEV_DBG_SPAM [ 966.345402] dyndbg: class[1]: module:nouveau base:10 len:5 ty:1 [ 966.346011] dyndbg: 10: 0 NV_CLI_DBG_OFF [ 966.346477] dyndbg: 11: 1 NV_CLI_DBG_INFO [ 966.346989] dyndbg: 12: 2 NV_CLI_DBG_DEBUG [ 966.347442] dyndbg: 13: 3 NV_CLI_DBG_TRACE [ 966.347875] dyndbg: 14: 4 NV_CLI_DBG_SPAM [ 966.348284] dyndbg: class[2]: module:nouveau base:0 len:10 ty:0 [ 966.348888] dyndbg: 0: 0 DRM_UT_CORE [ 966.349310] dyndbg: 1: 1 DRM_UT_DRIVER [ 966.349694] dyndbg: 2: 2 DRM_UT_KMS [ 966.350083] dyndbg: 3: 3 DRM_UT_PRIME [ 966.350482] dyndbg: 4: 4 DRM_UT_ATOMIC [ 966.351016] dyndbg: 5: 5 DRM_UT_VBL [ 966.351475] dyndbg: 6: 6 DRM_UT_STATE [ 966.351899] dyndbg: 7: 7 DRM_UT_LEASE [ 966.352309] dyndbg: 8: 8 DRM_UT_DP [ 966.352678] dyndbg: 9: 9 DRM_UT_DRMRES [ 966.353104] dyndbg: module:nouveau attached 3 classes [ 966.353759] dyndbg: 119 debug prints in module nouveau NOTE: it was 632 with previous commit, switching NV_DEBUG to use NV_SUBDEV_DBG_DEBUG instead of NV_DBG_DEBUG is the cause. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- .../gpu/drm/nouveau/include/nvkm/core/debug.h | 16 ++++++++++++++++ .../gpu/drm/nouveau/include/nvkm/core/subdev.h | 3 ++- drivers/gpu/drm/nouveau/nouveau_drm.c | 14 ++++++++++++++ 3 files changed, 32 insertions(+), 1 deletion(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h b/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h index b4a9c7d991ca..6a155a23a3d1 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/debug.h @@ -9,4 +9,20 @@ #define NV_DBG_TRACE 5 #define NV_DBG_PARANOIA 6 #define NV_DBG_SPAM 7 + +enum nv_cli_dbg_verbose { + NV_CLI_DBG_OFF = 10, + NV_CLI_DBG_INFO, + NV_CLI_DBG_DEBUG, + NV_CLI_DBG_TRACE, + NV_CLI_DBG_SPAM +}; +enum nv_subdev_dbg_verbose { + NV_SUBDEV_DBG_OFF = 15, + NV_SUBDEV_DBG_INFO, + NV_SUBDEV_DBG_DEBUG, + NV_SUBDEV_DBG_TRACE, + NV_SUBDEV_DBG_SPAM +}; + #endif diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index b9c2afab321f..bf9c69f4fc3e 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -2,6 +2,7 @@ #ifndef __NVKM_SUBDEV_H__ #define __NVKM_SUBDEV_H__ #include <core/device.h> +#include <core/debug.h> enum nvkm_subdev_type { #define NVKM_LAYOUT_ONCE(t,s,p,...) t, @@ -65,7 +66,7 @@ void nvkm_subdev_intr(struct nvkm_subdev *); if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ } while(0) -#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_DBG_##l, dbg, f, ##a) +#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_SUBDEV_DBG_##l, dbg, f, ##a) #define nvkm_debug(s,f,a...) nvkm_drmdbg_((s), DEBUG, f, ##a) #define nvkm_trace(s,f,a...) nvkm_drmdbg_((s), TRACE, f, ##a) #define nvkm_spam(s,f,a...) nvkm_drmdbg_((s), SPAM, f, ##a) diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c b/drivers/gpu/drm/nouveau/nouveau_drm.c index 76e3a8d50b01..85b63b527877 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drm.c +++ b/drivers/gpu/drm/nouveau/nouveau_drm.c @@ -83,6 +83,20 @@ DECLARE_DYNDBG_CLASSMAP(drm_debug_classes, DD_CLASS_TYPE_DISJOINT, 0, "DRM_UT_DP", "DRM_UT_DRMRES"); +DECLARE_DYNDBG_CLASSMAP(nv_cli_debug_verbose, DD_CLASS_TYPE_VERBOSE, 10, + "NV_CLI_DBG_OFF", + "NV_CLI_DBG_INFO", + "NV_CLI_DBG_DEBUG", + "NV_CLI_DBG_TRACE", + "NV_CLI_DBG_SPAM"); + +DECLARE_DYNDBG_CLASSMAP(nv_subdev_debug_verbose, DD_CLASS_TYPE_VERBOSE, 15, + "NV_SUBDEV_DBG_OFF", + "NV_SUBDEV_DBG_INFO", + "NV_SUBDEV_DBG_DEBUG", + "NV_SUBDEV_DBG_TRACE", + "NV_SUBDEV_DBG_SPAM"); + MODULE_PARM_DESC(config, "option string to pass to driver core"); static char *nouveau_config; module_param_named(config, nouveau_config, charp, 0400); -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 39/39] wip subdev refine breaks on use
--- .../drm/nouveau/include/nvkm/core/subdev.h | 2 +- drivers/gpu/drm/nouveau/nouveau_drm.c | 7 ------ drivers/gpu/drm/nouveau/nvkm/core/subdev.c | 23 +++++++++++++++++++ 3 files changed, 24 insertions(+), 8 deletions(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index d5f6ca05d5fa..05807403fdd6 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -19,7 +19,7 @@ struct nvkm_subdev { enum nvkm_subdev_type type; int inst; char name[16]; - u32 debug; + unsigned long debug; struct list_head head; void **pself; diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c b/drivers/gpu/drm/nouveau/nouveau_drm.c index 85b63b527877..d45c71ffc09e 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drm.c +++ b/drivers/gpu/drm/nouveau/nouveau_drm.c @@ -90,13 +90,6 @@ DECLARE_DYNDBG_CLASSMAP(nv_cli_debug_verbose, DD_CLASS_TYPE_VERBOSE, 10, "NV_CLI_DBG_TRACE", "NV_CLI_DBG_SPAM"); -DECLARE_DYNDBG_CLASSMAP(nv_subdev_debug_verbose, DD_CLASS_TYPE_VERBOSE, 15, - "NV_SUBDEV_DBG_OFF", - "NV_SUBDEV_DBG_INFO", - "NV_SUBDEV_DBG_DEBUG", - "NV_SUBDEV_DBG_TRACE", - "NV_SUBDEV_DBG_SPAM"); - MODULE_PARM_DESC(config, "option string to pass to driver core"); static char *nouveau_config; module_param_named(config, nouveau_config, charp, 0400); diff --git a/drivers/gpu/drm/nouveau/nvkm/core/subdev.c b/drivers/gpu/drm/nouveau/nvkm/core/subdev.c index a74b7acb6832..227871c3a749 100644 --- a/drivers/gpu/drm/nouveau/nvkm/core/subdev.c +++ b/drivers/gpu/drm/nouveau/nvkm/core/subdev.c @@ -26,6 +26,27 @@ #include <core/option.h> #include <subdev/mc.h> +#include <linux/dynamic_debug.h> +#include <linux/module.h> + +#define DEBUG + +DECLARE_DYNDBG_CLASSMAP(nv_subdev_debug_verbose, DD_CLASS_TYPE_VERBOSE, 15, + "NV_SUBDEV_DBG_OFF", + "NV_SUBDEV_DBG_INFO", + "NV_SUBDEV_DBG_DEBUG", + "NV_SUBDEV_DBG_TRACE", + "NV_SUBDEV_DBG_SPAM"); + +static struct ddebug_classes_bitmap_param nv_subdev_verbose = { + .bits = NULL, // wants &_subdev->debug + .flags = "p", + .map = &nv_subdev_debug_verbose, +}; +module_param_cb(debug_subdev, ¶m_ops_dyndbg_classes, &nv_subdev_verbose, 0600); + + + const char * nvkm_subdev_type[NVKM_SUBDEV_NR] = { #define NVKM_LAYOUT_ONCE(type,data,ptr,...) [type] = #ptr, @@ -180,6 +201,8 @@ nvkm_subdev_ctor(const struct nvkm_subdev_func *func, struct nvkm_device *device else strscpy(subdev->name, nvkm_subdev_type[type], sizeof(subdev->name)); subdev->debug = nvkm_dbgopt(device->dbgopt, subdev->name); + nv_subdev_verbose.bits = &subdev->debug; + pr_debug("updated bitmap: %px\n", &nv_subdev_verbose.bits); list_add_tail(&subdev->head, &device->subdev); } -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 40/41] nouveau-dbg: fixup lost prdbgs
Undo the 1-line change that reduced count of prdbgs from 632 to 119. ie: s/NV_SUBDEV_DBG_##l/NV_DBG_##l/ So heres what happened: new symbol is 15 (or 10), and fails this macro test, so gets compiled out, and the dev_dbg is excluded. if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ I could hack this, by hardcoding in (l + #base), but base is pretty distant to just toss into the macro. At least, the base-ref should be a macro(&classmap) properly exposing it. OTOH, the whole CONFIG_NOUVEAU_DEBUG check could be reworked; given that trace is minumum recommended, theres not that many callsites elided (SPAM only iirc) at compile-time, and dyndbg means keeping them has "zero" run=cost (and 56 bytes per). So this config item doesnt do much when DRM_USE_DYNAMIC_DEBUG=y. So this is a useful place to stop and take another look around, try to guess which trail to take.. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index bf9c69f4fc3e..d5f6ca05d5fa 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -66,7 +66,7 @@ void nvkm_subdev_intr(struct nvkm_subdev *); if (CONFIG_NOUVEAU_DEBUG >= (l) && _subdev->debug >= (l)) \ dev_dbg(_subdev->device->dev, "%s: "f, _subdev->name, ##a); \ } while(0) -#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_SUBDEV_DBG_##l, dbg, f, ##a) +#define nvkm_drmdbg_(s,l,f,a...) nvkm_drmdbg__((s), NV_DBG_##l, dbg, f, ##a) #define nvkm_debug(s,f,a...) nvkm_drmdbg_((s), DEBUG, f, ##a) #define nvkm_trace(s,f,a...) nvkm_drmdbg_((s), TRACE, f, ##a) #define nvkm_spam(s,f,a...) nvkm_drmdbg_((s), SPAM, f, ##a) -- 2.36.1
Jim Cromie
2022-Jul-18 06:39 UTC
[Nouveau] [PATCH v3 41/41] nouveau-dyndbg: wip subdev refine, breaks on use
Change nvkm_subdev.debug to a ulong, so dyndbg can maybe use it. Move macro decl from nv-drm.c to subdev.c, and add a struct ddebug_classes_bitmap_param and a module_param_cb() that creates the sysfs-knob. Finally, in nvkm_subdev_ctor(), *attempt* to set dyndbg's pointer to the debug address, so that dyndbg can observe the underlying debug value, and make enable/disable decisions based upon it. But Im not getting the ctor called, so the ptr is NULL when refd. Signed-off-by: Jim Cromie <jim.cromie at gmail.com> --- .../drm/nouveau/include/nvkm/core/subdev.h | 2 +- drivers/gpu/drm/nouveau/nouveau_drm.c | 7 ------ drivers/gpu/drm/nouveau/nvkm/core/subdev.c | 23 +++++++++++++++++++ 3 files changed, 24 insertions(+), 8 deletions(-) diff --git a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h index d5f6ca05d5fa..05807403fdd6 100644 --- a/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h +++ b/drivers/gpu/drm/nouveau/include/nvkm/core/subdev.h @@ -19,7 +19,7 @@ struct nvkm_subdev { enum nvkm_subdev_type type; int inst; char name[16]; - u32 debug; + unsigned long debug; struct list_head head; void **pself; diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c b/drivers/gpu/drm/nouveau/nouveau_drm.c index 85b63b527877..d45c71ffc09e 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drm.c +++ b/drivers/gpu/drm/nouveau/nouveau_drm.c @@ -90,13 +90,6 @@ DECLARE_DYNDBG_CLASSMAP(nv_cli_debug_verbose, DD_CLASS_TYPE_VERBOSE, 10, "NV_CLI_DBG_TRACE", "NV_CLI_DBG_SPAM"); -DECLARE_DYNDBG_CLASSMAP(nv_subdev_debug_verbose, DD_CLASS_TYPE_VERBOSE, 15, - "NV_SUBDEV_DBG_OFF", - "NV_SUBDEV_DBG_INFO", - "NV_SUBDEV_DBG_DEBUG", - "NV_SUBDEV_DBG_TRACE", - "NV_SUBDEV_DBG_SPAM"); - MODULE_PARM_DESC(config, "option string to pass to driver core"); static char *nouveau_config; module_param_named(config, nouveau_config, charp, 0400); diff --git a/drivers/gpu/drm/nouveau/nvkm/core/subdev.c b/drivers/gpu/drm/nouveau/nvkm/core/subdev.c index a74b7acb6832..227871c3a749 100644 --- a/drivers/gpu/drm/nouveau/nvkm/core/subdev.c +++ b/drivers/gpu/drm/nouveau/nvkm/core/subdev.c @@ -26,6 +26,27 @@ #include <core/option.h> #include <subdev/mc.h> +#include <linux/dynamic_debug.h> +#include <linux/module.h> + +#define DEBUG + +DECLARE_DYNDBG_CLASSMAP(nv_subdev_debug_verbose, DD_CLASS_TYPE_VERBOSE, 15, + "NV_SUBDEV_DBG_OFF", + "NV_SUBDEV_DBG_INFO", + "NV_SUBDEV_DBG_DEBUG", + "NV_SUBDEV_DBG_TRACE", + "NV_SUBDEV_DBG_SPAM"); + +static struct ddebug_classes_bitmap_param nv_subdev_verbose = { + .bits = NULL, // wants &_subdev->debug + .flags = "p", + .map = &nv_subdev_debug_verbose, +}; +module_param_cb(debug_subdev, ¶m_ops_dyndbg_classes, &nv_subdev_verbose, 0600); + + + const char * nvkm_subdev_type[NVKM_SUBDEV_NR] = { #define NVKM_LAYOUT_ONCE(type,data,ptr,...) [type] = #ptr, @@ -180,6 +201,8 @@ nvkm_subdev_ctor(const struct nvkm_subdev_func *func, struct nvkm_device *device else strscpy(subdev->name, nvkm_subdev_type[type], sizeof(subdev->name)); subdev->debug = nvkm_dbgopt(device->dbgopt, subdev->name); + nv_subdev_verbose.bits = &subdev->debug; + pr_debug("updated bitmap: %px\n", &nv_subdev_verbose.bits); list_add_tail(&subdev->head, &device->subdev); } -- 2.36.1