dynamic_debug: Add print_hex_dump_bytes/debug support and cleanups
Subsystems (4)
cover dynamic_debug: Add print_hex_dump_bytes/debug support and cleanups
Hi Greg,
Here's a collection of the latest dyanmic debug patches that I have pending.
Thanks,
-Jason
Jim Cromie (1):
dynamic_debug: add pr_errs before -EINVALs
Joe Perches (1):
dynamic_debug: Fix vpr_<foo> logging styles
Vladimir Kondratiev (1):
dynamic_debug: dynamic hex dump
Documentation/dynamic-debug-howto.txt | 15 +++- include/linux/dynamic_debug.h | 11 ++ include/linux/printk.h | 17 ++++ lib/dynamic_debug.c | 165 +++++++++++++++++++-------------- lib/hexdump.c | 4 +- 5 files changed, 141 insertions(+), 71 deletions(-)
PATCH 1/3 dynamic_debug: Fix vpr_<foo> logging styles
From: Joe Perches <[email protected]>
vpr_info_dq should be a function and vpr_info should have a do {} while (0)
Add missing newlines to pr_<level>s.
Miscellaneous neatening too.
braces, coalescing formats, alignments, etc...
--- lib/dynamic_debug.c | 118 +++++++++++++++++++++++++++------------------------ 1 files changed, 62 insertions(+), 56 deletions(-)
lib/dynamic_debug.c +62 -56
@@ -59,7 +59,7 @@ struct ddebug_iter {static DEFINE_MUTEX (ddebug_lock);static LIST_HEAD (ddebug_tables); -static int verbose =0 ; +static int verbose;module_param (verbose, int,0644 );/* Return the last part of a pathname */
@@ -107,24 +107,32 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,return buf; } -#define vpr_info (fmt, ...) \ - if (verbose) do { pr_info(fmt, ##__VA_ARGS__); } while (0) - -#define vpr_info_dq (q, msg) \ +#define vpr_info (fmt, ...) \ do { \ -/* trim last char off format print */ \ -vpr_info ("%s: func=\"%s\" file=\"%s\" " \ -"module=\"%s\" format=\"%.*s\" " \ -"lineno=%u-%u" , \ - msg, \ - q->function ? q->function :"" , \ - q->filename ? q->filename :"" , \ - q->module ? q->module :"" , \ - (int )(q->format ?strlen (q->format) -1 :0 ), \ - q->format ? q->format :"" , \ - q->first_lineno, q->last_lineno); \ + if (verbose) \ + pr_info(fmt, ##__VA_ARGS__); \ } while (0) +static void vpr_info_dq (const struct ddebug_query *query,const char *msg) +{ +/* trim any trailing newlines */ +int fmtlen =0 ; + +if (query->format) { + fmtlen =strlen (query->format); +while (fmtlen && query->format[fmtlen -1 ] =='\n' ) + 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); +} +/* * Search the tables for _ddebug's which match the given `query' and * apply the `flags' and `mask' to them. Returns number of matching
@@ -148,7 +156,7 @@ static int ddebug_change(const struct ddebug_query *query,if (query->module &&strcmp (query->module, dt->mod_name))continue ; -for (i =0 ; i < dt->num_ddebugs ; i++) { +for (i =0 ; i < dt->num_ddebugs; i++) {struct _ddebug *dp = &dt->ddebugs[i];/* match against the source filename */
@@ -183,10 +191,10 @@ static int ddebug_change(const struct ddebug_query *query,continue ; 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))); +trim_prefix (dp->filename), dp->lineno, + dt->mod_name, dp->function, +ddebug_describe_flags (dp, flagbuf, +sizeof (flagbuf))); } }mutex_unlock (&ddebug_lock);
@@ -220,12 +228,12 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords)/* find `end' of word, whitespace separated or quoted */ if (*buf =='"' || *buf =='\'' ) {int quote = *buf++; -for (end = buf ; *end && *end != quote ; end++) +for (end = buf; *end && *end != quote; end++) ;if (!*end)return -EINVAL ;/* unclosed quote */ }else { -for (end = buf ; *end && !isspace (*end) ; end++) +for (end = buf; *end && !isspace (*end); end++) ;BUG_ON (end == buf); }
@@ -242,7 +250,7 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords)if (verbose) {int i;pr_info ("split into words:" ); -for (i =0 ; i < nwords ; i++) +for (i =0 ; i < nwords; i++)pr_cont (" \"%s\"" , words[i]);pr_cont ("\n" ); }
@@ -293,11 +301,11 @@ static char *unescape(char *str) in +=2 ;continue ; }else if (isodigit (in[1 ]) && -isodigit (in[2 ]) && -isodigit (in[3 ])) { - *out++ = ((in[1 ] -'0' )<<6 ) | - ((in[2 ] -'0' )<<3 ) | - (in[3 ] -'0' ); +isodigit (in[2 ]) && +isodigit (in[3 ])) { + *out++ = (((in[1 ] -'0' ) <<6 ) | + ((in[2 ] -'0' ) <<3 ) | + (in[3 ] -'0' )); in +=4 ;continue ; }
@@ -315,8 +323,8 @@ static int check_set(const char **dest, char *src, char *name)if (*dest) { rc = -EINVAL ; -pr_err ("match-spec:%s val:%s overridden by %s" , - name, *dest, src); +pr_err ("match-spec:%s val:%s overridden by %s\n" , + name, *dest, src); } *dest = src;return rc;
@@ -352,17 +360,17 @@ static int ddebug_parse_query(char *words[], int nwords,/* support $modname.dyndbg=<multiple queries> */ query->module = modname; -for (i =0 ; i < nwords ; i +=2 ) { -if (!strcmp (words[i],"func" )) +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" )) + }else if (!strcmp (words[i],"file" )) { rc =check_set (&query->filename, words[i+1 ],"file" ); -else if (!strcmp (words[i],"module" )) + }else if (!strcmp (words[i],"module" )) { rc =check_set (&query->module, words[i+1 ],"module" ); -else if (!strcmp (words[i],"format" )) + }else if (!strcmp (words[i],"format" )) { rc =check_set (&query->format,unescape (words[i+1 ]), -"format" ); -else if (!strcmp (words[i],"line" )) { +"format" ); + }else if (!strcmp (words[i],"line" )) {char *first = words[i+1 ];char *last =strchr (first,'-' );if (query->first_lineno || query->last_lineno) {
@@ -417,7 +425,7 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp, }vpr_info ("op='%c'\n" , op); -for ( ; *str ; ++str) { +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;
@@ -466,7 +474,7 @@ static int ddebug_exec_query(char *query_string, const char *modname)/* actually go and implement the change */ nfound =ddebug_change (&query, flags, mask); -vpr_info_dq ((&query), (nfound) ?"applied" :"no-match" ); +vpr_info_dq (&query, nfound ?"applied" :"no-match" );return nfound; }
@@ -495,8 +503,9 @@ static int ddebug_exec_queries(char *query, const char *modname)if (rc <0 ) { errs++; exitcode = rc; - }else + }else { nfound += rc; + } i++; } vpr_info("processed %d queries, with %d matches, %d errs\n",
@@ -772,7 +781,7 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)struct _ddebug *dp;vpr_info ("called m=%p p=%p *pos=%lld\n" , - m, p, (unsigned long long )*pos); + m, p, (unsigned long long )*pos);if (p ==SEQ_START_TOKEN ) dp =ddebug_iter_first (iter);
@@ -798,14 +807,14 @@ static int ddebug_proc_show(struct seq_file *m, void *p)if (p ==SEQ_START_TOKEN ) {seq_puts (m, -"# filename:lineno [module]function flags format\n" ); +"# filename:lineno [module]function flags format\n" );return 0 ; }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))); +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" );
@@ -852,7 +861,7 @@ static int ddebug_proc_open(struct inode *inode, struct file *file)kfree (iter);return err; } - ((struct seq_file *) file->private_data)->private = iter; + ((struct seq_file *)file->private_data)->private = iter;return 0 ; }
@@ -1009,8 +1018,7 @@ static int __init dynamic_debug_init(void)int verbose_bytes =0 ;if (__start___verbose == __stop___verbose) { -pr_warn ("_ddebug table is empty in a " -"CONFIG_DYNAMIC_DEBUG build" ); +pr_warn ("_ddebug table is empty in a CONFIG_DYNAMIC_DEBUG build\n" );return 1 ; } iter = __start___verbose;
@@ -1037,18 +1045,16 @@ static int __init dynamic_debug_init(void) 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)); +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" ); +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" , +pr_warn ("Invalid ddebug boot param %s\n" , ddebug_setup_string);else pr_info ("%d changes by ddebug_query\n" , ret);
Signature · 1 line
1.7.1
PATCH 2/3 dynamic_debug: dynamic hex dump
In reply to Jason BaronFrom: Vladimir Kondratiev <[email protected]>
Introduce print_hex_dump_debug() that can be dynamically controlled, similar to pr_debug.
Also, make print_hex_dump_bytes() dynamically controlled
Implement only 'p' flag (_DPRINTK_FLAGS_PRINT) to keep it simple since hex dump prints multiple lines and long prefix would impact readability.
To provide line/file etc. information, use pr_debug or similar before/after print_hex_dump_debug()
--- Documentation/dynamic-debug-howto.txt | 15 +++++++++++++-- include/linux/dynamic_debug.h | 11 +++++++++++ include/linux/printk.h | 17 +++++++++++++++++ lib/hexdump.c | 4 +++- 4 files changed, 44 insertions(+), 3 deletions(-)
Documentation/dynamic-debug-howto.txt +13 -2
@@ -6,8 +6,16 @@ This document describes how to use the dynamic debug (dyndbg) feature. 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() calls can -be dynamically enabled per-callsite. +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 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 build dynamically. Dynamic debug has even more useful features:
@@ -202,6 +210,9 @@ The flags are: t Include thread ID in messages not generated from interrupt context _ No flags are set. (Or'd with others on input) +For print_hex_dump_debug() and print_hex_dump_bytes(), only 'p' flag +have meaning, other flags ignored. + For display, the flags are preceded by '=' (mnemonic: what the flags are currently equal to).
include/linux/dynamic_debug.h +11 -0
@@ -95,6 +95,17 @@ do { \ ##__VA_ARGS__); \ } while (0) +#define dynamic_hex_dump (prefix_str, prefix_type, rowsize, \ + groupsize, buf, len, ascii) \ +do { \ + DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, \ + __builtin_constant_p(prefix_str) ? prefix_str : "hexdump");\ + if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT)) \ + print_hex_dump(KERN_DEBUG, prefix_str, \ + prefix_type, rowsize, groupsize, \ + buf, len, ascii); \ +} while (0) +#else #include <linux/string.h>
include/linux/printk.h +17 -0
@@ -321,8 +321,13 @@ extern void hex_dump_to_buffer(const void *buf, size_t len,extern void print_hex_dump (const char *level,const char *prefix_str,int prefix_type,int rowsize,int groupsize,const void *buf,size_t len,bool ascii); +#if defined(CONFIG_DYNAMIC_DEBUG ) +#define print_hex_dump_bytes (prefix_str, prefix_type, buf, len) \ + dynamic_hex_dump(prefix_str, prefix_type, 16, 1, buf, len, true) +#else extern void print_hex_dump_bytes (const char *prefix_str,int prefix_type,const void *buf,size_t len); +#endif /* defined(CONFIG_DYNAMIC_DEBUG) */ #else static inline void print_hex_dump(const char *level, const char *prefix_str, int prefix_type, int rowsize, int groupsize,
@@ -336,4 +341,16 @@ static inline void print_hex_dump_bytes(const char *prefix_str, int prefix_type,#endif +#if defined(CONFIG_DYNAMIC_DEBUG ) +#define print_hex_dump_debug (prefix_str, prefix_type, rowsize, \ + groupsize, buf, len, ascii) \ + dynamic_hex_dump(prefix_str, prefix_type, rowsize, \ + groupsize, buf, len, ascii) +#else +#define print_hex_dump_debug (prefix_str, prefix_type, rowsize, \ + groupsize, buf, len, ascii) \ + print_hex_dump(KERN_DEBUG, prefix_str, prefix_type, rowsize, \ + groupsize, buf, len, ascii) +#endif /* defined(CONFIG_DYNAMIC_DEBUG) */ +#endif
lib/hexdump.c +3 -1
@@ -227,6 +227,7 @@ void print_hex_dump(const char *level, const char *prefix_str, int prefix_type, }EXPORT_SYMBOL (print_hex_dump); +#if !defined(CONFIG_DYNAMIC_DEBUG )/** * print_hex_dump_bytes - shorthand form of print_hex_dump() with default params * @prefix_str: string to prefix each line with;
@@ -246,4 +247,5 @@ void print_hex_dump_bytes(const char *prefix_str, int prefix_type, buf, len, true); }EXPORT_SYMBOL (print_hex_dump_bytes); -#endif +#endif /* !defined(CONFIG_DYNAMIC_DEBUG) */ +#endif /* defined(CONFIG_PRINTK) */
Signature · 1 line
1.7.1
PATCH 3/3 dynamic_debug: add pr_errs before -EINVALs
In reply to Jason BaronFrom: Jim Cromie <[email protected]>
Ma noted that dynamic-debug is silent about many query errors, so add pr_err()s to explain those errors, and tweak a few others. Also parse flags 1st, so that match-spec errs are slightly clearer.
--- lib/dynamic_debug.c | 47 +++++++++++++++++++++++++++++++++++------------ 1 files changed, 35 insertions(+), 12 deletions(-)
lib/dynamic_debug.c +35 -12
@@ -230,8 +230,10 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords)int quote = *buf++;for (end = buf; *end && *end != quote; end++) ; -if (!*end) +if (!*end) { +pr_err ("unclosed quote: %s\n" , buf);return -EINVAL ;/* unclosed quote */ + } }else {for (end = buf; *end && !isspace (*end); end++) ;
@@ -239,8 +241,10 @@ static int ddebug_tokenize(char *buf, char *words[], int maxwords) }/* `buf' is start of word, `end' is one past its end */ -if (nwords == maxwords) +if (nwords == maxwords) { +pr_err ("too many words, legal max <=%d\n" , maxwords);return -EINVAL ;/* ran out of words[] before bytes */ + }if (*end) *end++ ='\0' ;/* terminate the word */ words[nwords++] = buf;
@@ -272,7 +276,11 @@ static inline int parse_lineno(const char *str, unsigned int *val)return 0 ; } *val =simple_strtoul (str, &end,10 ); -return end ==NULL || end == str || *end !='\0' ? -EINVAL :0 ; +if (end ==NULL || end == str || *end !='\0' ) { +pr_err ("bad line-number: %s\n" , str); +return -EINVAL ; + } +return 0 ; }/*
@@ -352,8 +360,10 @@ static int ddebug_parse_query(char *words[], int nwords,int rc;/* check we have an even number of words */ -if (nwords %2 !=0 ) +if (nwords %2 !=0 ) { +pr_err ("expecting pairs of match-spec <value>\n" );return -EINVAL ; + }memset (query,0 ,sizeof (*query));if (modname)
@@ -374,18 +384,22 @@ static int ddebug_parse_query(char *words[], int nwords,char *first = words[i+1 ];char *last =strchr (first,'-' );if (query->first_lineno || query->last_lineno) { -pr_err ("match-spec:line given 2 times\n" ); +pr_err ("match-spec: line used 2x\n" );return -EINVAL ; }if (last) *last++ ='\0' ; -if (parse_lineno (first, &query->first_lineno) <0 ) +if (parse_lineno (first, &query->first_lineno) <0 ) { +pr_err ("line-number is <0\n" );return -EINVAL ; + }if (last) {/* range <first>-<last> */ if (parse_lineno (last, &query->last_lineno) < query->first_lineno) { -pr_err ("last-line < 1st-line\n" ); +pr_err ("last-line:%d < 1st-line:%d\n" , + query->last_lineno, + query->first_lineno);return -EINVAL ; } }else {
@@ -421,6 +435,7 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp, op = *str++;break ;default : +pr_err ("bad flag-op %c, at start of %s\n" , *str, str);return -EINVAL ; }vpr_info ("op='%c'\n" , op);
@@ -432,8 +447,10 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,break ; } } -if (i <0 ) +if (i <0 ) { +pr_err ("unknown flag '%c' in \"%s\"\n" , *str, str);return -EINVAL ; + } }vpr_info ("flags=0x%x\n" , flags);
@@ -465,13 +482,19 @@ static int ddebug_exec_query(char *query_string, const char *modname)char *words[MAXWORDS ]; nwords =ddebug_tokenize (query_string, words,MAXWORDS ); -if (nwords <=0 ) +if (nwords <=0 ) { +pr_err ("tokenize failed\n" );return -EINVAL ; -if (ddebug_parse_query (words, nwords-1 , &query, modname)) + } +/* check flags 1st (last arg) so query is pairs of spec,val */ +if (ddebug_parse_flags (words[nwords-1 ], &flags, &mask)) { +pr_err ("flags parse failed\n" );return -EINVAL ; -if (ddebug_parse_flags (words[nwords-1 ], &flags, &mask)) + } +if (ddebug_parse_query (words, nwords-1 , &query, modname)) { +pr_err ("query parse failed\n" );return -EINVAL ; - + }/* actually go and implement the change */ nfound =ddebug_change (&query, flags, mask);vpr_info_dq (&query, nfound ?"applied" :"no-match" );
Signature · 1 line
1.7.1
Quoted 2 lines · Jason Baron
Here's a collection of the latest dynamic debug patches that I have pending.
Any update on the jump table support?
Quoted 6 lines · Joe Perches
Quoted 2 lines · Jason Baron
Here's a collection of the latest dynamic debug patches that I have pending.
Any update on the jump table support?
I have patches that implement the support, although they are a bit hacky due to header dependencies. However, the main reason I didn't post them yet is that the 'data' section increases quite a bit due to the increased table size (text section is reduced, since we are saving instructions). On x86_64, the the upper 32-bits of each table entry are always '0xffffffff', so the table could be reduced by a factor of 2. Although, I haven't figured out a simple way of doing so. Perhaps, the 'data' section bloat is ok, due to the runtime savings, though. I can dig out the % increase data.
While we're on new features, I think it would be nice to have the ability to enable the core dynamic debug library - lib/dynamic_debug.c, independently from the debug statements that use it. So, having CONFIG_DYNAMIC_DEBUG would just configure the infrastructure bits, and something such as CONFIG_DYNAMIC_DEBUG_PRINTK could enable pr_debug() and friends. In that way subsystems that want to use dynamic output can be enabled/disabled independently. So they could do:
#ifdef CONFIG_DRIVER_FOO_DEBUG
#define drv_foo_debug() dev_dbg()
#else
#define drv_foo_debug() {}
where CONFIG_DRIVER_FOO_DEBUG would enable CONFIG_DYNAMIC_DEBUG.
Thanks,
-Jason