kernel/linux.git/lib/dynamic_debug.c, branch linux-6.0.y

dyndbg: drop EXPORTed dynamic_debug_exec_queries

2022-10-21T10:38:44+00:00

[ Upstream commit e26ef3af964acfea311403126acee8c56c89e26b ] 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") Acked-by: Jason Baron Acked-by: Daniel Vetter Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20220904214134.408619-10-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman Signed-off-by: Sasha Levin

dyndbg: let query-modname override actual module name

2022-10-21T10:38:44+00:00

[ Upstream commit e75ef56f74965f426dd819a41336b640ffdd8fbc ] 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 Acked-by: Jason Baron Acked-by: Daniel Vetter Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20220904214134.408619-8-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman Signed-off-by: Sasha Levin

dyndbg: fix static_branch manipulation

2022-10-21T10:38:44+00:00

[ Upstream commit ee879be38bc87f8cedc79ae2742958db6533ca59 ] In https://lore.kernel.org/lkml/20211209150910.GA23668@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@axis.com Acked-by: Jason Baron Acked-by: Daniel Vetter Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20220904214134.408619-2-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman Signed-off-by: Sasha Levin

dyndbg: refine verbosity 1-4 summary-detail

2021-10-21T11:01:25+00:00

adjust current v*pr_info() calls to fit an overview..detail scheme: 1- module level activity: add/remove, etc 2- command ingest, splitting, summary of effects. per >control write 3- command parsing: op, flags, search terms 4- per-site change msg can yield ~3k x 2 logs per echo "+p;-p" > command. Summarize these 4 levels in MODULE_PARM_DESC, and update verbose=3 in Doc. 2- is new, to isolate a problem where a stress-test script (which feeds ~4kb multi-command strings) would produce short writes, truncating last command and causing parsing errors, which confused test results. The script fix was to use syswrite, to deliver full proper commands. 4- gets per-callsite "changed:" pr-infos, which are very noisy during stress tests, and formerly obscured v1-3 messages, and overwhelmed the static-key workload being tested. The verbose parameter has previously seen adjustment: commit 481c0e33f1e7 ("dyndbg: refine debug verbosity; 1 is basic, 2 more chatty") The script driving these adjustments is: !/usr/bin/perl -w =for Doc 1st purpose was to benchmark the effect of wildcard queries on query performance; if wildcards are risk free cheap enough, we can deploy them in the (floating) format search. 1st finding: wildcards take 2x as long to process. 2nd purpose was to benchmark real static-key changes VS simple flag changes. Found ~100x decrease for the hard work. The script maximizes workload per >control by packing it a ~4kb string of "+p; -p;" commands; this uncovered some broken stuff. The 85th query failed, and appears to be truncated, so is gramatically incorrect. Its either an error here, or in the kernel. Its not happening atm, retest. Plot thickens: fail only happens doing +-p, not +-mf, likely load dependent. Error remains consistent. Looks like a short write, longer on writer than kernel-reader. Try syswrite on handle to control this. That fixed short write. =cut use Getopt::Std; getopts('vN:k:', \my %opts) or die <', $ctrl) or die "cant open $ctrl for writing: $!\n"; sub vx { my $arg = shift; my $cmd = "echo $arg > /sys/module/dynamic_debug/parameters/verbose"; system($cmd); warn("vx problem: rc:$? err:$! qry: $cmd\n") if ($?); } sub qryOK { my $qry = shift; print "syntax test: <\n$qry>\n" if $opts{v}; my $bytes = syswrite $CTL, $qry; printf "short read: $bytes / %d\n", length $qry if $bytes < length $qry; if ($?) { warn "rc:$? err:$! qry: $qry\n"; return 0; } return 1; } sub build_queries { my ($cmd, $flags, $ct) = @_; # build experiment and reference queries my $cycle = " $cmd +$flags # on ; $cmd -$flags # off \n"; my $ref = " +$flags ; -$flags \n"; my $len = length $cycle; my $max = int(4096 / $len); # break/fit to buffer size $ct |= $max; print "qry: ct:$max x << \n$cycle >>\n"; return unless qryOK($ref); return unless qryOK($cycle); my $wild = $cycle x $ct; my $empty = $ref x $ct; printf "len: %d, %d\n", length $wild, length $empty; return { trial => $wild, ref => $empty, probe => $cycle, zero => $ref, count => $ct, max => $max }; } my $query_set = build_queries(' file "*" module "*" func "*" ', "mf"); qryOK($query_set->{zero}); qryOK($query_set->{probe}); qryOK($query_set->{ref}); qryOK($query_set->{trial}); use Benchmark; sub dobatch { my ($cmd, $flags, $reps, $ct) = @_; $reps ||= $opts{N}; my $qs = build_queries($cmd, $flags, $ct); timethese($reps, { wildcards => sub { syswrite $CTL, $qs->{trial}; }, no_search => sub { syswrite $CTL, $qs->{ref}; } } ); } sub bench_static_key_toggle { vx 0; dobatch(' file "*" module "*" func "*" ', "mf"); dobatch(' file "*" module "*" func "*" ', "p"); } sub bench_verbose_levels { for my $i (0..4) { vx $i; dobatch(' file "*" module "*" func "*" ', "mf"); } } bench_static_key_toggle(); __END__ Heres how the test-script runs: :: verbose=3 parsing info [ 48.401646] dyndbg: query 95: "file "*" module "*" func "*" -mf # off " mod:* [ 48.402040] dyndbg: split into words: "file" "*" "module" "*" "func" "*" "-mf" [ 48.402456] dyndbg: op='-' [ 48.402615] dyndbg: flags=0x6 [ 48.402779] dyndbg: *flagsp=0x0 *maskp=0xfffffff9 [ 48.403033] dyndbg: parsed: func="*" file="*" module="*" format="" lineno=0-0 [ 48.403674] dyndbg: applied: func="*" file="*" module="*" format="" lineno=0-0 :: verbose=2 >control summary. ~300k site matches/changes per 4kb command [ 48.404063] dyndbg: processed 96 queries, with 296160 matches, 0 errs :: 2 queries against each other, no-search vs all-wildcard-search qry: ct:48 x << file "*" module "*" func "*" +mf # on ; file "*" module "*" func "*" -mf # off >> len: 4080, 576 Benchmark: timing 10 iterations of no_search, wildcards... no_search: 0 wallclock secs ( 0.00 usr + 0.03 sys = 0.03 CPU) @ 333.33/s (n=10) (warning: too few iterations for a reliable count) wildcards: 0 wallclock secs ( 0.00 usr + 0.09 sys = 0.09 CPU) @ 111.11/s (n=10) (warning: too few iterations for a reliable count) :: 2 queries, both doing real work / changing stati-key states. qry: ct:49 x << file "*" module "*" func "*" +p # on ; file "*" module "*" func "*" -p # off >> len: 4067, 490 Benchmark: timing 10 iterations of no_search, wildcards... no_search: 20 wallclock secs ( 0.00 usr + 20.36 sys = 20.36 CPU) @ 0.49/s (n=10) wildcards: 21 wallclock secs ( 0.00 usr + 21.08 sys = 21.08 CPU) @ 0.47/s (n=10) bash-5.1# Thats 150k static-key-toggles / sec ~600x slower than simple flags on qemu --smp 3 run Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20211019210746.185307-1-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman

dyndbg: fix spurious vNpr_info change

2021-10-15T08:02:29+00:00

The cited commit inadvertently altered the verbose level of a vpr_info, restore it to original. Fixes: 216a0fc40897 ("dyndbg: show module in vpr-info in dd-exec-queries") Signed-off-By: Jim Cromie Link: https://lore.kernel.org/r/20211014223614.1952171-1-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman

dyndbg: no vpr-info on empty queries

2021-10-14T08:59:14+00:00

when `echo $cmd > control` contains multiple queries, extra query separators (;\n) can parse as empty statements. This is normal, and a vpr-info on an empty command is just noise. Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20211013220726.1280565-4-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman

dyndbg: vpr-info on remove-module complete, not starting

2021-10-14T08:59:10+00:00

On qemu --smp 3 runs, remove-module can get called 3 times. So don't print on entry; instead print "removed" after entry is found and removed, so just once. Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20211013220726.1280565-3-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman

dyndbg: Remove support for ddebug_query param

2021-10-14T08:48:56+00:00

This param has been deprecated for a very long time now, let's rip it out. Signed-off-by: Andrew Halaney Signed-off-by: Jason Baron Link: https://lore.kernel.org/r/1634139622-20667-3-git-send-email-jbaron@akamai.com Signed-off-by: Greg Kroah-Hartman

dyndbg: make dyndbg a known cli param

2021-10-14T08:48:56+00:00

Right now dyndbg shows up as an unknown parameter if used on boot: Unknown command line parameters: dyndbg=+p That's because it is unknown, it doesn't sit in the __param section, so the processing done to warn users supplying an unknown parameter doesn't think it is legitimate. Install a dummy handler to register it. dynamic debug needs to search the whole command line for modules listed that are currently builtin, so there's no real work to be done in this callback. Fixes: 86d1919a4fb0 ("init: print out unknown kernel parameters") Tested-by: Jim Cromie Signed-off-by: Andrew Halaney Signed-off-by: Jason Baron Link: https://lore.kernel.org/r/1634139622-20667-2-git-send-email-jbaron@akamai.com Signed-off-by: Greg Kroah-Hartman

dyndbg: show module in vpr-info in dd-exec-queries

2021-10-13T13:21:26+00:00

dynamic_debug_exec_queries() accepts a separate module arg (so it can support $module.dyndbg boot arg), display that in the vpr-info for a more useful user-debug context. Signed-off-by: Jim Cromie Link: https://lore.kernel.org/r/20211012183310.1016678-2-jim.cromie@gmail.com Signed-off-by: Greg Kroah-Hartman