diff options
Diffstat (limited to 'lib/dynamic_debug.c')
| -rw-r--r-- | lib/dynamic_debug.c | 805 |
1 files changed, 605 insertions, 200 deletions
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 8a16c2d498e9..6fba6423cc10 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -11,7 +11,7 @@ * Copyright (C) 2013 Du, Changbin <changbin.du@gmail.com> */ -#define pr_fmt(fmt) KBUILD_MODNAME ":%s: " fmt, __func__ +#define pr_fmt(fmt) "dyndbg: " fmt #include <linux/kernel.h> #include <linux/module.h> @@ -39,11 +39,13 @@ #include <rdma/ib_verbs.h> -extern struct _ddebug __start___verbose[]; -extern struct _ddebug __stop___verbose[]; +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; + struct list_head link, maps; const char *mod_name; unsigned int num_ddebugs; struct _ddebug *ddebugs; @@ -54,18 +56,26 @@ struct ddebug_query { const char *module; const char *function; const char *format; + const char *class_string; unsigned int first_lineno, last_lineno; }; struct ddebug_iter { struct ddebug_table *table; - unsigned int idx; + int idx; +}; + +struct flag_settings { + unsigned int flags; + unsigned int mask; }; static DEFINE_MUTEX(ddebug_lock); static LIST_HEAD(ddebug_tables); static int verbose; module_param(verbose, int, 0644); +MODULE_PARM_DESC(verbose, " dynamic_debug/control processing " + "( 0 = off (default), 1 = module add/rm, 2 = >control summary, 3 = parsing, 4 = per-site changes)"); /* Return the path relative to source root */ static inline const char *trim_prefix(const char *path) @@ -78,39 +88,45 @@ static inline const char *trim_prefix(const char *path) return path + skip; } -static struct { unsigned flag:8; char opt_char; } opt_array[] = { +static const struct { unsigned flag:8; char opt_char; } opt_array[] = { { _DPRINTK_FLAGS_PRINT, 'p' }, { _DPRINTK_FLAGS_INCL_MODNAME, 'm' }, { _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' }, + { _DPRINTK_FLAGS_INCL_SOURCENAME, 's' }, { _DPRINTK_FLAGS_INCL_LINENO, 'l' }, { _DPRINTK_FLAGS_INCL_TID, 't' }, { _DPRINTK_FLAGS_NONE, '_' }, }; +struct flagsbuf { char buf[ARRAY_SIZE(opt_array)+1]; }; + /* format a string into buf[] which describes the _ddebug's flags */ -static char *ddebug_describe_flags(struct _ddebug *dp, char *buf, - size_t maxlen) +static char *ddebug_describe_flags(unsigned int flags, struct flagsbuf *fb) { - char *p = buf; + char *p = fb->buf; int i; - BUG_ON(maxlen < 6); for (i = 0; i < ARRAY_SIZE(opt_array); ++i) - if (dp->flags & opt_array[i].flag) + if (flags & opt_array[i].flag) *p++ = opt_array[i].opt_char; - if (p == buf) + if (p == fb->buf) *p++ = '_'; *p = '\0'; - return buf; + return fb->buf; } -#define vpr_info(fmt, ...) \ +#define vnpr_info(lvl, fmt, ...) \ do { \ - if (verbose) \ + if (verbose >= lvl) \ pr_info(fmt, ##__VA_ARGS__); \ } while (0) +#define vpr_info(fmt, ...) vnpr_info(1, fmt, ##__VA_ARGS__) +#define v2pr_info(fmt, ...) vnpr_info(2, fmt, ##__VA_ARGS__) +#define v3pr_info(fmt, ...) vnpr_info(3, fmt, ##__VA_ARGS__) +#define v4pr_info(fmt, ...) vnpr_info(4, fmt, ##__VA_ARGS__) + static void vpr_info_dq(const struct ddebug_query *query, const char *msg) { /* trim any trailing newlines */ @@ -122,15 +138,33 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg) fmtlen--; } - vpr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u\n", - msg, - query->function ? query->function : "", - query->filename ? query->filename : "", - query->module ? query->module : "", - fmtlen, query->format ? 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 @@ -138,13 +172,15 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg) * logs the changes. Takes ddebug_lock. */ static int ddebug_change(const struct ddebug_query *query, - unsigned int flags, unsigned int mask) + struct flag_settings *modifiers) { int i; struct ddebug_table *dt; unsigned int newflags; unsigned int nfound = 0; - char flagbuf[10]; + struct flagsbuf fbuf, nbuf; + struct ddebug_class_map *map = NULL; + int __outvar valid_class; /* search for matching ddebugs */ mutex_lock(&ddebug_lock); @@ -155,9 +191,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) && @@ -173,9 +222,16 @@ static int ddebug_change(const struct ddebug_query *query, continue; /* match against the format */ - if (query->format && - !strstr(dp->format, query->format)) - continue; + if (query->format) { + if (*query->format == '^') { + char *p; + /* anchored search. match must be at beginning */ + p = strstr(dp->format, query->format+1); + if (p != dp->format) + continue; + } else if (!strstr(dp->format, query->format)) + continue; + } /* match against the line number range */ if (query->first_lineno && @@ -187,22 +243,23 @@ static int ddebug_change(const struct ddebug_query *query, nfound++; - newflags = (dp->flags & mask) | flags; + newflags = (dp->flags & modifiers->mask) | modifiers->flags; if (newflags == dp->flags) continue; #ifdef CONFIG_JUMP_LABEL if (dp->flags & _DPRINTK_FLAGS_PRINT) { - if (!(flags & _DPRINTK_FLAGS_PRINT)) + if (!(newflags & _DPRINTK_FLAGS_PRINT)) static_branch_disable(&dp->key.dd_key_true); - } else if (flags & _DPRINTK_FLAGS_PRINT) + } else if (newflags & _DPRINTK_FLAGS_PRINT) { 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; - vpr_info("changed %s:%d [%s]%s =%s\n", - trim_prefix(dp->filename), dp->lineno, - dt->mod_name, dp->function, - ddebug_describe_flags(dp, flagbuf, - sizeof(flagbuf))); } } mutex_unlock(&ddebug_lock); @@ -259,7 +316,7 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords) buf = end; } - if (verbose) { + if (verbose >= 3) { int i; pr_info("split into words:"); for (i = 0; i < nwords; i++) @@ -289,6 +346,41 @@ static inline int parse_lineno(const char *str, unsigned int *val) return 0; } +static int parse_linerange(struct ddebug_query *query, const char *first) +{ + char *last = strchr(first, '-'); + + if (query->first_lineno || query->last_lineno) { + pr_err("match-spec: line used 2x\n"); + return -EINVAL; + } + if (last) + *last++ = '\0'; + if (parse_lineno(first, &query->first_lineno) < 0) + return -EINVAL; + if (last) { + /* range <first>-<last> */ + if (parse_lineno(last, &query->last_lineno) < 0) + return -EINVAL; + + /* special case for last lineno not specified */ + if (query->last_lineno == 0) + query->last_lineno = UINT_MAX; + + if (query->last_lineno < query->first_lineno) { + pr_err("last-line:%d < 1st-line:%d\n", + query->last_lineno, + query->first_lineno); + return -EINVAL; + } + } else { + query->last_lineno = query->first_lineno; + } + v3pr_info("parsed line %d-%d\n", query->first_lineno, + query->last_lineno); + return 0; +} + static int check_set(const char **dest, char *src, char *name) { int rc = 0; @@ -322,66 +414,63 @@ static int ddebug_parse_query(char *words[], int nwords, { unsigned int i; int rc = 0; + char *fline; /* check we have an even number of words */ if (nwords % 2 != 0) { pr_err("expecting pairs of match-spec <value>\n"); return -EINVAL; } - memset(query, 0, sizeof(*query)); - - if (modname) - /* support $modname.dyndbg=<multiple queries> */ - query->module = modname; for (i = 0; i < nwords; i += 2) { - if (!strcmp(words[i], "func")) { - rc = check_set(&query->function, words[i+1], "func"); - } else if (!strcmp(words[i], "file")) { - rc = check_set(&query->filename, words[i+1], "file"); - } else if (!strcmp(words[i], "module")) { - rc = check_set(&query->module, words[i+1], "module"); - } else if (!strcmp(words[i], "format")) { - string_unescape_inplace(words[i+1], UNESCAPE_SPACE | - UNESCAPE_OCTAL | - UNESCAPE_SPECIAL); - rc = check_set(&query->format, words[i+1], "format"); - } else if (!strcmp(words[i], "line")) { - char *first = words[i+1]; - char *last = strchr(first, '-'); - if (query->first_lineno || query->last_lineno) { - pr_err("match-spec: line used 2x\n"); - return -EINVAL; - } - if (last) - *last++ = '\0'; - if (parse_lineno(first, &query->first_lineno) < 0) - return -EINVAL; - if (last) { - /* range <first>-<last> */ - if (parse_lineno(last, &query->last_lineno) < 0) - return -EINVAL; + char *keyword = words[i]; + char *arg = words[i+1]; - /* special case for last lineno not specified */ - if (query->last_lineno == 0) - query->last_lineno = UINT_MAX; + if (!strcmp(keyword, "func")) { + rc = check_set(&query->function, arg, "func"); + } else if (!strcmp(keyword, "file")) { + if (check_set(&query->filename, arg, "file")) + return -EINVAL; - if (query->last_lineno < query->first_lineno) { - pr_err("last-line:%d < 1st-line:%d\n", - query->last_lineno, - query->first_lineno); + /* tail :$info is function or line-range */ + fline = strchr(query->filename, ':'); + if (!fline) + continue; + *fline++ = '\0'; + if (isalpha(*fline) || *fline == '*' || *fline == '?') { + /* take as function name */ + if (check_set(&query->function, fline, "func")) return -EINVAL; - } } else { - query->last_lineno = query->first_lineno; + if (parse_linerange(query, fline)) + return -EINVAL; } + } else if (!strcmp(keyword, "module")) { + rc = check_set(&query->module, arg, "module"); + } else if (!strcmp(keyword, "format")) { + string_unescape_inplace(arg, UNESCAPE_SPACE | + UNESCAPE_OCTAL | + UNESCAPE_SPECIAL); + rc = check_set(&query->format, arg, "format"); + } 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", words[i]); + pr_err("unknown keyword \"%s\"\n", keyword); return -EINVAL; } 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; } @@ -392,11 +481,9 @@ static int ddebug_parse_query(char *words[], int nwords, * flags fields of matched _ddebug's. Returns 0 on success * or <0 on error. */ -static int ddebug_parse_flags(const char *str, unsigned int *flagsp, - unsigned int *maskp) +static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers) { - unsigned flags = 0; - int op = '=', i; + int op, i; switch (*str) { case '+': @@ -408,45 +495,45 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp, pr_err("bad flag-op %c, at start of %s\n", *str, str); return -EINVAL; } - vpr_info("op='%c'\n", op); + v3pr_info("op='%c'\n", op); for (; *str ; ++str) { for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) { if (*str == opt_array[i].opt_char) { - flags |= opt_array[i].flag; + modifiers->flags |= opt_array[i].flag; break; } } if (i < 0) { - pr_err("unknown flag '%c' in \"%s\"\n", *str, str); + pr_err("unknown flag '%c'\n", *str); return -EINVAL; } } - vpr_info("flags=0x%x\n", flags); + v3pr_info("flags=0x%x\n", modifiers->flags); - /* calculate final *flagsp, *maskp according to mask and op */ + /* calculate final flags, mask based upon op */ switch (op) { case '=': - *maskp = 0; - *flagsp = flags; + /* modifiers->flags already set */ + modifiers->mask = 0; break; case '+': - *maskp = ~0U; - *flagsp = flags; + modifiers->mask = ~0U; break; case '-': - *maskp = ~flags; - *flagsp = 0; + modifiers->mask = ~modifiers->flags; + modifiers->flags = 0; break; } - vpr_info("*flagsp=0x%x *maskp=0x%x\n", *flagsp, *maskp); + v3pr_info("*flagsp=0x%x *maskp=0x%x\n", modifiers->flags, modifiers->mask); + return 0; } static int ddebug_exec_query(char *query_string, const char *modname) { - unsigned int flags = 0, mask = 0; - struct ddebug_query query; + struct flag_settings modifiers = {}; + struct ddebug_query query = {}; #define MAXWORDS 9 int nwords, nfound; char *words[MAXWORDS]; @@ -457,7 +544,7 @@ static int ddebug_exec_query(char *query_string, const char *modname) return -EINVAL; } /* check flags 1st (last arg) so query is pairs of spec,val */ - if (ddebug_parse_flags(words[nwords-1], &flags, &mask)) { + if (ddebug_parse_flags(words[nwords-1], &modifiers)) { pr_err("flags parse failed\n"); return -EINVAL; } @@ -466,7 +553,7 @@ static int ddebug_exec_query(char *query_string, const char *modname) return -EINVAL; } /* actually go and implement the change */ - nfound = ddebug_change(&query, flags, mask); + nfound = ddebug_change(&query, &modifiers); vpr_info_dq(&query, nfound ? "applied" : "no-match"); return nfound; @@ -490,7 +577,7 @@ static int ddebug_exec_queries(char *query, const char *modname) if (!query || !*query || *query == '#') continue; - vpr_info("query %d: \"%s\"\n", i, query); + vpr_info("query %d: \"%s\" mod:%s\n", i, query, modname ?: "*"); rc = ddebug_exec_query(query, modname); if (rc < 0) { @@ -501,15 +588,228 @@ static int ddebug_exec_queries(char *query, const char *modname) } i++; } - vpr_info("processed %d queries, with %d matches, %d errs\n", - i, nfound, errs); + if (i) + v2pr_info("processed %d queries, with %d matches, %d errs\n", + i, nfound, errs); if (exitcode) return exitcode; return nfound; } -#define PREFIX_SIZE 64 +/* apply a new bitmap to the sys-knob's current bit-state */ +static int ddebug_apply_class_bitmap(const struct ddebug_class_param *dcp, + unsigned long *new_bits, unsigned long *old_bits) +{ +#define QUERY_SIZE 128 + char query[QUERY_SIZE]; + const struct ddebug_class_map *map = dcp->map; + int matches = 0; + int bi, ct; + + v2pr_info("apply: 0x%lx to: 0x%lx\n", *new_bits, *old_bits); + + for (bi = 0; bi < map->length; bi++) { + if (test_bit(bi, new_bits) == test_bit(bi, old_bits)) + continue; + + snprintf(query, QUERY_SIZE, "class %s %c%s", map->class_names[bi], + test_bit(bi, new_bits) ? '+' : '-', 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], *new_bits); + } + return matches; +} + +/* stub to later conditionally add "$module." prefix where not already done */ +#define KP_NAME(kp) kp->name + +#define CLASSMAP_BITMASK(width) ((1UL << (width)) - 1) + +/* accept comma-separated-list of [+-] classnames */ +static int param_set_dyndbg_classnames(const char *instr, const struct kernel_param *kp) +{ + const struct ddebug_class_param *dcp = kp->arg; + const struct ddebug_class_map *map = dcp->map; + unsigned long curr_bits, old_bits; + char *cl_str, *p, *tmp; + int cls_id, totct = 0; + bool wanted; + + cl_str = tmp = kstrdup(instr, GFP_KERNEL); + p = strchr(cl_str, '\n'); + if (p) + *p = '\0'; + + /* start with previously set state-bits, then modify */ + curr_bits = old_bits = *dcp->bits; + vpr_info("\"%s\" > %s:0x%lx\n", cl_str, KP_NAME(kp), curr_bits); + + for (; cl_str; cl_str = p) { + p = strchr(cl_str, ','); + if (p) + *p++ = '\0'; + + if (*cl_str == '-') { + wanted = false; + cl_str++; + } else { + wanted = true; + if (*cl_str == '+') + cl_str++; + } + cls_id = match_string(map->class_names, map->length, cl_str); + if (cls_id < 0) { + pr_err("%s unknown to %s\n", cl_str, KP_NAME(kp)); + continue; + } + + /* have one or more valid class_ids of one *_NAMES type */ + switch (map->map_type) { + case DD_CLASS_TYPE_DISJOINT_NAMES: + /* the +/- pertains to a single bit */ + if (test_bit(cls_id, &curr_bits) == wanted) { + v3pr_info("no change on %s\n", cl_str); + continue; + } + curr_bits ^= BIT(cls_id); + totct += ddebug_apply_class_bitmap(dcp, &curr_bits, dcp->bits); + *dcp->bits = curr_bits; + v2pr_info("%s: changed bit %d:%s\n", KP_NAME(kp), cls_id, + map->class_names[cls_id]); + break; + case DD_CLASS_TYPE_LEVEL_NAMES: + /* cls_id = N in 0..max. wanted +/- determines N or N-1 */ + old_bits = CLASSMAP_BITMASK(*dcp->lvl); + curr_bits = CLASSMAP_BITMASK(cls_id + (wanted ? 1 : 0 )); + + totct += ddebug_apply_class_bitmap(dcp, &curr_bits, &old_bits); + *dcp->lvl = (cls_id + (wanted ? 1 : 0)); + v2pr_info("%s: changed bit-%d: \"%s\" %lx->%lx\n", KP_NAME(kp), cls_id, + map->class_names[cls_id], old_bits, curr_bits); + break; + default: + pr_err("illegal map-type value %d\n", map->map_type); + } + } + kfree(tmp); + vpr_info("total matches: %d\n", totct); + return 0; +} + +/** + * param_set_dyndbg_classes - class FOO >control + * @instr: string echo>d to sysfs, input depends on map_type + * @kp: kp->arg has state: bits/lvl, map, map_type + * + * Enable/disable prdbgs by their class, as given in the arguments to + * DECLARE_DYNDBG_CLASSMAP. For LEVEL map-types, enforce relative + * levels by bitpos. + * + * Returns: 0 or <0 if error. + */ +int param_set_dyndbg_classes(const char *instr, const struct kernel_param *kp) +{ + const struct ddebug_class_param *dcp = kp->arg; + const struct ddebug_class_map *map = dcp->map; + unsigned long inrep, new_bits, old_bits; + int rc, totct = 0; + + switch (map->map_type) { + + case DD_CLASS_TYPE_DISJOINT_NAMES: + case DD_CLASS_TYPE_LEVEL_NAMES: + /* handle [+-]classnames list separately, we are done here */ + return param_set_dyndbg_classnames(instr, kp); + + case DD_CLASS_TYPE_DISJOINT_BITS: + case DD_CLASS_TYPE_LEVEL_NUM: + /* numeric input, accept and fall-thru */ + rc = kstrtoul(instr, 0, &inrep); + if (rc) { + pr_err("expecting numeric input: %s > %s\n", instr, KP_NAME(kp)); + return -EINVAL; + } + break; + default: + pr_err("%s: bad map type: %d\n", KP_NAME(kp), map->map_type); + return -EINVAL; + } + + /* only _BITS,_NUM (numeric) map-types get here */ + switch (map->map_type) { + case DD_CLASS_TYPE_DISJOINT_BITS: + /* 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(kp), inrep, CLASSMAP_BITMASK(map->length)); + inrep &= CLASSMAP_BITMASK(map->length); + } + v2pr_info("bits:%lx > %s\n", inrep, KP_NAME(kp)); + totct += ddebug_apply_class_bitmap(dcp, &inrep, dcp->bits); + *dcp->bits = inrep; + break; + case DD_CLASS_TYPE_LEVEL_NUM: + /* input is bitpos, of highest verbosity to be enabled */ + if (inrep > map->length) { + pr_warn("%s: level:%ld exceeds max:%d, clamping\n", + KP_NAME(kp), inrep, map->length); + inrep = map->length; + } + old_bits = CLASSMAP_BITMASK(*dcp->lvl); + new_bits = CLASSMAP_BITMASK(inrep); + v2pr_info("lvl:%ld bits:0x%lx > %s\n", inrep, new_bits, KP_NAME(kp)); + totct += ddebug_apply_class_bitmap(dcp, &new_bits, &old_bits); + *dcp->lvl = inrep; + break; + default: + pr_warn("%s: bad map type: %d\n", KP_NAME(kp), map->map_type); + } + vpr_info("%s: total matches: %d\n", KP_NAME(kp), 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 state, underlying prdbg state may have been + * altered by direct >control. Displays 0x for DISJOINT, 0-N for + * LEVEL Returns: #chars written or <0 on error + */ +int param_get_dyndbg_classes(char *buffer, const struct kernel_param *kp) +{ + const struct ddebug_class_param *dcp = kp->arg; + const struct ddebug_class_map *map = dcp->map; + + switch (map->map_type) { + + case DD_CLASS_TYPE_DISJOINT_NAMES: + case DD_CLASS_TYPE_DISJOINT_BITS: + return scnprintf(buffer, PAGE_SIZE, "0x%lx\n", *dcp->bits); + + case DD_CLASS_TYPE_LEVEL_NAMES: + case DD_CLASS_TYPE_LEVEL_NUM: + return scnprintf(buffer, PAGE_SIZE, "%d\n", *dcp->lvl); + 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 128 static int remaining(int wrote) { @@ -518,13 +818,11 @@ static int remaining(int wrote) return 0; } -static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf) +static char *__dynamic_emit_prefix(const struct _ddebug *desc, char *buf) { int pos_after_tid; int pos = 0; - *buf = '\0'; - if (desc->flags & _DPRINTK_FLAGS_INCL_TID) { if (in_interrupt()) pos += snprintf(buf + pos, remaining(pos), "<intr> "); @@ -539,6 +837,9 @@ static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf) if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME) pos += snprintf(buf + pos, remaining(pos), "%s:", desc->function); + if (desc->flags & _DPRINTK_FLAGS_INCL_SOURCENAME) + pos += snprintf(buf + pos, remaining(pos), "%s:", + trim_prefix(desc->filename)); if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO) pos += snprintf(buf + pos, remaining(pos), "%d:", desc->lineno); @@ -550,11 +851,18 @@ static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf) return buf; } +static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf) +{ + if (unlikely(desc->flags & _DPRINTK_FLAGS_INCL_ANY)) + return __dynamic_emit_prefix(desc, buf); + return buf; +} + void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...) { va_list args; struct va_format vaf; - char buf[PREFIX_SIZE]; + char buf[PREFIX_SIZE] = ""; BUG_ON(!descriptor); BUG_ON(!fmt); @@ -587,7 +895,7 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor, if (!dev) { printk(KERN_DEBUG "(NULL device *): %pV", &vaf); } else { - char buf[PREFIX_SIZE]; + char buf[PREFIX_SIZE] = ""; dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV", dynamic_emit_prefix(descriptor, buf), @@ -616,7 +924,7 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor, vaf.va = &args; if (dev && dev->dev.parent) { - char buf[PREFIX_SIZE]; + char buf[PREFIX_SIZE] = ""; dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent, "%s%s %s %s%s: %pV", @@ -652,7 +960,7 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor, vaf.va = &args; if (ibdev && ibdev->dev.parent) { - char buf[PREFIX_SIZE]; + char buf[PREFIX_SIZE] = ""; dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent, "%s%s %s %s: %pV", @@ -673,20 +981,17 @@ EXPORT_SYMBOL(__dynamic_ibdev_dbg); #endif -#define DDEBUG_STRING_SIZE 1024 -static __initdata char ddebug_setup_string[DDEBUG_STRING_SIZE]; - -static __init int ddebug_setup_query(char *str) +/* + * Install a noop handler to make dyndbg look like a normal kernel cli param. + * This avoids warnings about dyndbg being an unknown cli param when supplied + * by a user. + */ +static __init int dyndbg_setup(char *str) { - if (strlen(str) >= DDEBUG_STRING_SIZE) { - pr_warn("ddebug boot param string too large\n"); - return 0; - } - strlcpy(ddebug_setup_string, str, DDEBUG_STRING_SIZE); return 1; } -__setup("ddebug_query=", ddebug_setup_query); +__setup("dyndbg=", dyndbg_setup); /* * File_ops->write method for <debugfs>/dynamic_debug/control. Gathers the @@ -708,7 +1013,7 @@ static ssize_t ddebug_proc_write(struct file *file, const char __user *ubuf, tmpbuf = memdup_user_nul(ubuf, len); if (IS_ERR(tmpbuf)) return PTR_ERR(tmpbuf); - vpr_info("read %d bytes from userspace\n", (int)len); + v2pr_info("read %zu bytes from userspace\n", len); ret = ddebug_exec_queries(tmpbuf, NULL); kfree(tmpbuf); @@ -728,13 +1033,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]; } /* @@ -747,15 +1051,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]; } @@ -771,8 +1076,6 @@ static void *ddebug_proc_start(struct seq_file *m, loff_t *pos) struct _ddebug *dp; int n = *pos; - vpr_info("called m=%p *pos=%lld\n", m, (unsigned long long)*pos); - mutex_lock(&ddebug_lock); if (!n) @@ -795,9 +1098,6 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos) struct ddebug_iter *iter = m->private; struct _ddebug *dp; - vpr_info("called m=%p p=%p *pos=%lld\n", - m, p, (unsigned long long)*pos); - if (p == SEQ_START_TOKEN) dp = ddebug_iter_first(iter); else @@ -806,6 +1106,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 @@ -816,9 +1130,8 @@ static int ddebug_proc_show(struct seq_file *m, void *p) { struct ddebug_iter *iter = m->private; struct _ddebug *dp = p; - char flagsbuf[10]; - - vpr_info("called m=%p p=%p\n", m, p); + struct flagsbuf flags; + char const *class; if (p == SEQ_START_TOKEN) { seq_puts(m, @@ -829,9 +1142,18 @@ static int ddebug_proc_show(struct seq_file *m, void *p) seq_printf(m, "%s:%u [%s]%s =%s \"", trim_prefix(dp->filename), dp->lineno, iter->table->mod_name, dp->function, - ddebug_describe_flags(dp, flagsbuf, sizeof(flagsbuf))); - seq_escape(m, dp->format, "\t\r\n\""); - seq_puts(m, "\"\n"); + ddebug_describe_flags(dp->flags, &flags)); + seq_escape_str(m, dp->format, ESCAPE_SPACE, "\t\r\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; } @@ -842,7 +1164,6 @@ static int ddebug_proc_show(struct seq_file *m, void *p) */ static void ddebug_proc_stop(struct seq_file *m, void *p) { - vpr_info("called m=%p p=%p\n", m, p); mutex_unlock(&ddebug_lock); } @@ -853,16 +1174,8 @@ static const struct seq_operations ddebug_proc_seqops = { .stop = ddebug_proc_stop }; -/* - * File_ops->open method for <debugfs>/dynamic_debug/control. Does - * the seq_file setup dance, and also creates an iterator to walk the - * _ddebugs. Note that we create a seq_file always, even for O_WRONLY - * files where it's not needed, as doing so simplifies the ->release - * method. - */ static int ddebug_proc_open(struct inode *inode, struct file *file) { - vpr_info("called\n"); return seq_open_private(file, &ddebug_proc_seqops, sizeof(struct ddebug_iter)); } @@ -876,18 +1189,57 @@ static const struct file_operations ddebug_proc_fops = { .write = ddebug_proc_write }; +static const struct proc_ops proc_fops = { + .proc_open = ddebug_proc_open, + .proc_read = seq_read, + .proc_lseek = seq_lseek, + .proc_release = seq_release_private, + .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. */ -int ddebug_add_module(struct _ddebug *tab, unsigned int n, - const char *name) +static int ddebug_add_module(struct _ddebug_info *di, const char *modname) { struct ddebug_table *dt; + v3pr_info("add-module: %s.%d sites\n", modname, di->num_descs); + if (!di->num_descs) { + v3pr_info(" skip %s\n", modname); + return 0; + } + dt = kzalloc(sizeof(*dt), GFP_KERNEL); if (dt == NULL) { - pr_err("error adding module: %s\n", name); + pr_err("error adding module: %s\n", modname); return -ENOMEM; } /* @@ -896,15 +1248,21 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n, * member of struct module, which lives at least as long as * this struct ddebug_table. */ - dt->mod_name = name; - dt->num_ddebugs = n; - dt->ddebugs = tab; + dt->mod_name = modname; + dt->ddebugs = di->descs; + dt->num_ddebugs = di->num_descs; + + INIT_LIST_HEAD(&dt->link); + INIT_LIST_HEAD(&dt->maps); + + if (di->classes && di->num_classes) + ddebug_attach_module_classes(dt, di->classes, di->num_classes); mutex_lock(&ddebug_lock); list_add_tail(&dt->link, &ddebug_tables); mutex_unlock(&ddebug_lock); - vpr_info("%u debug prints in module %s\n", n, dt->mod_name); + vpr_info("%3u debug prints in module %s\n", di->num_descs, modname); return 0; } @@ -926,7 +1284,7 @@ static int ddebug_dyndbg_param_cb(char *param, char *val, ddebug_exec_queries((val ? val : "+p"), modname); - return 0; /* query failure shouldnt stop module load */ + return 0; /* query failure shouldn't stop module load */ } /* handle both dyndbg and $module.dyndbg params at boot */ @@ -954,17 +1312,17 @@ static void ddebug_table_free(struct ddebug_table *dt) kfree(dt); } +#ifdef CONFIG_MODULES + /* * Called in response to a module being unloaded. Removes * any ddebug_table's which point at the module. */ -int ddebug_remove_module(const char *mod_name) +static int ddebug_remove_module(const char *mod_name) { struct ddebug_table *dt, *nextdt; int ret = -ENOENT; - vpr_info("removing module \"%s\"\n", mod_name); - mutex_lock(&ddebug_lock); list_for_each_entry_safe(dt, nextdt, &ddebug_tables, link) { if (dt->mod_name == mod_name) { @@ -974,9 +1332,38 @@ int ddebug_remove_module(const char *mod_name) } } mutex_unlock(&ddebug_lock); + if (!ret) + v2pr_info("removed module \"%s\"\n", mod_name); return ret; } +static int ddebug_module_notify(struct notifier_block *self, unsigned long val, + void *data) +{ + struct module *mod = data; + int ret = 0; + + switch (val) { + case MODULE_STATE_COMING: + ret = ddebug_add_module(&mod->dyndbg_info, mod->name); + if (ret) + WARN(1, "Failed to allocate memory: dyndbg may not work properly.\n"); + break; + case MODULE_STATE_GOING: + ddebug_remove_module(mod->name); + break; + } + + return notifier_from_errno(ret); +} + +static struct notifier_block ddebug_module_nb = { + .notifier_call = ddebug_module_notify, + .priority = 0, /* dynamic debug depends on jump label */ +}; + +#endif /* CONFIG_MODULES */ + static void ddebug_remove_all_tables(void) { mutex_lock(&ddebug_lock); @@ -991,76 +1378,94 @@ static void ddebug_remove_all_tables(void) static __initdata int ddebug_init_success; -static int __init dynamic_debug_init_debugfs(void) +static int __init dynamic_debug_init_control(void) { - struct dentry *dir, *file; + struct proc_dir_entry *procfs_dir; + struct dentry *debugfs_dir; if (!ddebug_init_success) return -ENODEV; - dir = debugfs_create_dir("dynamic_debug", NULL); - if (!dir) - return -ENOMEM; - file = debugfs_create_file("control", 0644, dir, NULL, - &ddebug_proc_fops); - if (!file) { - debugfs_remove(dir); - return -ENOMEM; + /* Create the control file in debugfs if it is enabled */ + if (debugfs_initialized()) { + debugfs_dir = debugfs_create_dir("dynamic_debug", NULL); + debugfs_create_file("control", 0644, debugfs_dir, NULL, + &ddebug_proc_fops); } + + /* Also create the control file in procfs */ + procfs_dir = proc_mkdir("dynamic_debug", NULL); + if (procfs_dir) + proc_create("control", 0644, procfs_dir, &proc_fops); + return 0; } static int __init dynamic_debug_init(void) { - struct _ddebug *iter, *iter_start; - const char *modname = NULL; + struct _ddebug *iter, *iter_mod_start; + int ret, i, mod_sites, mod_ct; + const char *modname; char *cmdline; - int ret = 0; - int n = 0, entries = 0, modct = 0; - int verbose_bytes = 0; - if (__start___verbose == __stop___verbose) { - pr_warn("_ddebug table is empty in a CONFIG_DYNAMIC_DEBUG build\n"); - return 1; + struct _ddebug_info di = { + .descs = __start___dyndbg, + .classes = __start___dyndbg_classes, + .num_descs = __stop___dyndbg - __start___dyndbg, + .num_classes = __stop___dyndbg_classes - __start___dyndbg_classes, + }; + +#ifdef CONFIG_MODULES + ret = register_module_notifier(&ddebug_module_nb); + if (ret) { + pr_warn("Failed to register dynamic debug module notifier\n"); + return ret; + } +#endif /* CONFIG_MODULES */ + + if (&__start___dyndbg == &__stop___dyndbg) { + if (IS_ENABLED(CONFIG_DYNAMIC_DEBUG)) { + pr_warn("_ddebug table is empty in a CONFIG_DYNAMIC_DEBUG build\n"); + return 1; + } + pr_info("Ignore empty _ddebug table in a CONFIG_DYNAMIC_DEBUG_CORE build\n"); + ddebug_init_success = 1; + return 0; } - iter = __start___verbose; + + iter = iter_mod_start = __start___dyndbg; modname = iter->modname; - iter_start = iter; - for (; iter < __stop___verbose; iter++) { - entries++; - verbose_bytes += strlen(iter->modname) + strlen(iter->function) - + strlen(iter->filename) + strlen(iter->format); + i = mod_sites = mod_ct = 0; + + for (; iter < __stop___dyndbg; iter++, i++, mod_sites++) { if (strcmp(modname, iter->modname)) { - modct++; - ret = ddebug_add_module(iter_start, n, modname); + mod_ct++; + di.num_descs = mod_sites; + di.descs = iter_mod_start; + ret = ddebug_add_module(&di, modname); if (ret) goto out_err; - n = 0; + + mod_sites = 0; modname = iter->modname; - iter_start = iter; + iter_mod_start = iter; } - n++; } - ret = ddebug_add_module(iter_start, n, modname); + di.num_descs = mod_sites; + di.descs = iter_mod_start; + ret = ddebug_add_module(&di, modname); if (ret) goto out_err; ddebug_init_success = 1; - vpr_info("%d modules, %d entries and %d bytes in ddebug tables, %d bytes in (readonly) verbose section\n", - modct, entries, (int)(modct * sizeof(struct ddebug_table)), - verbose_bytes + (int)(__stop___verbose - __start___verbose)); - - /* apply ddebug_query boot param, dont unload tables on err */ - if (ddebug_setup_string[0] != '\0') { - pr_warn("ddebug_query param name is deprecated, change it to dyndbg\n"); - ret = ddebug_exec_queries(ddebug_setup_string, NULL); - if (ret < 0) - pr_warn("Invalid ddebug boot param %s\n", - ddebug_setup_string); - else - pr_info("%d changes by ddebug_query\n", ret); - } + vpr_info("%d prdebugs in %d modules, %d KiB in ddebug tables, %d kiB in __dyndbg section\n", + i, mod_ct, (int)((mod_ct * sizeof(struct ddebug_table)) >> 10), + (int)((i * sizeof(struct _ddebug)) >> 10)); + + if (di.num_classes) + v2pr_info(" %d builtin ddebug class-maps\n", di.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 @@ -1083,4 +1488,4 @@ out_err: early_initcall(dynamic_debug_init); /* Debugfs setup must be done later */ -fs_initcall(dynamic_debug_init_debugfs); +fs_initcall(dynamic_debug_init_control); |