[patch 00/25] dynamic_debug: multiple, pending queries in boot-arg

[patch 00/25] dynamic_debug: multiple, pending queries in boot-arg

[Jim Cromie]

This patchset extends dynamic-debug facility to allow
use of pr_debug() within a loadable module's module_init()
function.  Query/rules can be given on the boot-line,
and are saved to a pending list if they cannot be applied
immediately.  Later, when the module is being loaded, the
pending list is scanned, and matching rules are applied.
Thus pr_debug() calls in the module's initialization function
are active when it is invoked.

Changes since rev1:

- rebased on top of Jasons & Joes patchset
- fixed accidental unescape removal, noted by Bart
- trim src-path patch checks for matching prefix before trimming
 should now work for out-of-tree modules.
- undid verbose newline-strip in exec-queries - Bart
- verbose param 644, not 744 - Bart, Greg
- whitespace - Bart
- added 'a' flag - Jason, Bart
- drop pending_max - Bart

Changes since rev2:

1. lock around all list-work, pending-ct

In response to Bart's locking-bug observation, I hoisted locks up to
callers, so theyd protect all list, pending-ct manipulation.  This
means longer hold-times, but less locking/unlocking.  Left as separate
patch for now, partly cuz having pr_info's under lock gave me some
heartburn.  That said, lockdep didnt complain.  I think I got the
interim patches correct too.

2. filter-flags

Ive extended flags spec to have <match-flags>* <op> <new-flags>*
IE, matching /[pmflta]*[+-=][pmflta]*/

match-flags (optional) allows a query/rule to be more selective, which
increases the utility of otherwise unconstrained rules.  So the
following query matches all call-sites that are already enabled,
adding the TID flag.

$> echo " p+t " > <dbgfs>/dynamic_debug/control

3. 'a' pending query modification, removal

Real purpose of 2 was to allow modification or deletion of currently
pending queries:

$> echo "module foo +ap" > <debugfs>/dynamic_debug/control
$> echo "module foo +apt" > <debugfs>/dynamic_debug/control
$> echo "module foo ap=_" > <debugfs>/dynamic_debug/control

1st command adds a pending query on module foo
2nd command modifies it by adding a TID flag
3rd command deletes the pending query by setting flags to 0

Note that 2,3 have exact match on the query-spec, the match-flags in 3
specify flags required to match against the pending query; the 't'
flag added in 2 is not required, but allowed.

With explicit deletion of pending rules, I removed the tacit
delete-on-apply behavior.

4. $> cat <dbfs>/dynamic_debug/pending

This displays currently pending queries, simplifying their deletion.
Its not correct right now; it iterates over set, but repeats

5.  Fuller multi-command input

writes to control-file are parsed on '\n' as well as ';',
and '#' are recognized as comments.  
With this, the following works.

root@voyage:~# cat debugfs-file

  # blank lines ok
  module dynamic_debug +p              ; # turn on self-debugging
  # these are quite noisy when grepping
  # $DEBUGFS/dynamic_debug/{control,pending}
    # silence them (also, leading spaces allowed in comments)
  func ddebug_proc_show -p
  func ddebug_proc_next -p     ; # trailing comments need cmd terminator
  func pending_proc_show -p    ;
  func pending_proc_next -p

root@voyage:~# cat debugfs-file > /dbgfs/dynamic_debug/control
split into words: "module" "dynamic_debug" "+p"
changed $srcroot/lib/dynamic_debug.c:223 [dynamic_debug]ddebug_change =p
changed $srcroot/lib/dynamic_debug.c:576 [dynamic_debug]ddebug_save_pending =p
....

Here-docs work too, but shell interferes with comments.


Notes:

1. echo " +p " > /dbg/dynamic_debug/control

The above felt a little radical, but it isnt really; it works on
mainline.  Therefore one part of the Doc is slightly misleading (last
sentence):

 The match-spec's are used to choose a subset of the known dprintk()
 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 is possible, but is not very useful because it will not
 match any debug statement callsites.

2. this runs 2 separate writes.

printf "module nsc_gpio +p\n module pc8736x_gpio +p\npc8736x_gpio +p\n" \
      > /dbg/dynamic_debug/control

This form of command is seen by kernel as 2 separate writes, so the
form is not usable in boot-line in mainline; it breaks the debug
facility (see patch 6).  Using ';' to separate multiple commands does
work on boot-line.

thanks
Jim Cromie

1-11 are straightforward, I think ready to go.
12-25 are the core feature addition, and have bigger implications.  
I think theyre mostly solid, but they probably warrant more scrutiny.
25 needs some help.

0001-dynamic_debug-add-pending-flag-a-to-make-pending-que.patch
0002-dynamic_debug-change-verbosity-at-runtime.patch
0003-dynamic_debug-use-pr_debug-instead-of-pr_info.patch
0004-dynamic_debug-replace-strcpy-with-strlcpy-in-ddebug_.patch
0005-dynamic_debug-trim-source-path-prefix-from-dynamic_d.patch
0006-dynamic_debug-process-multiple-commands-on-a-line.patch
0007-dynamic_debug-enlarge-command-query-write-buffer.patch
0008-dynamic_debug-warn-when-1-of-each-type-of-match-spec.patch
0009-dynamic_debug-pr_err-call-should-not-depend-upon-ver.patch
0010-dynamic_debug-dont-kill-entire-facility-on-error-par.patch
0011-dynamic_debug-factor-show_ddebug_query-out-of-ddebug.patch
0012-dynamic_debug-save-non-matching-queries-to-pending-l.patch
0013-dynamic_debug-apply_pending_queries-from-ddebug_add_.patch
0014-dynamic_debug-refactor-query_matches_callsite-out-of.patch
0015-dynamic_debug-remove-explicit-foo-NULL-checks.patch
0016-dynamic_debug-require-a-flag-to-explicitly-mark-pend.patch
0017-dynamic_debug-hoist-locking-in-ddebug_change-to-call.patch
0018-dynamic_debug-describe_flags-with-pmflta_.patch
0019-dynamic_debug-add-flags-filtering-to-flags-spec.patch
0020-dynamic_debug-remove-pending-query-when-flags-zeroed.patch
0021-dynamic_debug-shrink-struct-pending-query-to-size-ac.patch
0022-dynamic_debug-call-ddebug_add_module-on-dynamic_debu.patch
0023-dynamic_debug-document-pending-queries-flags-filter-.patch
0024-dynamic_debug-add-Documentation-example-for-query-cm.patch
0025-dynamic_debug-drop-pr_fmt-from-dynamic_pr_debug.patch
0026-dynamic_debug-add-DBGFS-dynamic_debug-pending.patch

[PATCH 01/25] dynamic_debug: add pending flag 'a' to make pending queries explicit

[Jim Cromie]

this just adds flag to header, so it can be rebased to the front of
the patchset, so that rebuilds within the set are faster.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 include/linux/dynamic_debug.h |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index bc75472..8f46a5d 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -26,6 +26,7 @@ struct _ddebug {
 #define _DPRINTK_FLAGS_INCL_FUNCNAME	(1<<2)
 #define _DPRINTK_FLAGS_INCL_LINENO	(1<<3)
 #define _DPRINTK_FLAGS_INCL_TID		(1<<4)
+#define _DPRINTK_FLAGS_APPEND   (1<<5)  /* add query to pending list */
 #define _DPRINTK_FLAGS_DEFAULT 0
 	unsigned int flags:8;
 	char enabled;
-- 
1.7.4.1

[PATCH 02/25] dynamic_debug: change verbosity at runtime

[Jim Cromie]

allow changing dynamic_debug verbosity at boot-time,
with: dynamic_debug.verbose=1
or at runtime with:
root@voyage:~# echo 1 > /sys/module/dynamic_debug/parameters/verbose

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 1f11978..af6f1ae 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -61,6 +61,7 @@ struct ddebug_iter {
 static DEFINE_MUTEX(ddebug_lock);
 static LIST_HEAD(ddebug_tables);
 static int verbose = 0;
+module_param(verbose, int, 0644);
 
 /* Return the last part of a pathname */
 static inline const char *basename(const char *path)
-- 
1.7.4.1

[PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jim Cromie]

Replace almost all occurrences of "if (verbose) pr_info()" with
pr_debug(), and get full control of output at each callsite.
Leave a few sites unaltered:

1st also uses pr_cont(), and theres no pr_debug_cont().
2nd is in ddebug_add_module(), which is called during arch_init,
too early for callsite to be enabled when called.

3rd, pr_debug doesnt work in dynamic_debug_init(), its too early.
Also move the print ddebug_setup_string prior to parsing, since
afterwards it's been chopped up with '\0's, and only 1st word is seen.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   66 ++++++++++++++++++++-------------------------------
 1 files changed, 26 insertions(+), 40 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index af6f1ae..a7161db 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -157,18 +157,17 @@ static void ddebug_change(const struct ddebug_query *query,
 				dp->enabled = 1;
 			else
 				dp->enabled = 0;
-			if (verbose)
-				pr_info("changed %s:%d [%s]%s %s\n",
-					dp->filename, dp->lineno,
-					dt->mod_name, dp->function,
-					ddebug_describe_flags(dp, flagbuf,
-							sizeof(flagbuf)));
+			pr_debug("changed %s:%d [%s]%s %s\n",
+				dp->filename, dp->lineno,
+				dt->mod_name, dp->function,
+				ddebug_describe_flags(dp, flagbuf,
+						sizeof(flagbuf)));
 		}
 	}
 	mutex_unlock(&ddebug_lock);
 
-	if (!nfound && verbose)
-		pr_info("no matches for query\n");
+	if (!nfound)
+		pr_debug("no matches for query\n");
 }
 
 /*
@@ -333,12 +332,11 @@ static int ddebug_parse_query(char *words[], int nwords,
 		}
 	}
 
-	if (verbose)
-		pr_info("q->function=\"%s\" q->filename=\"%s\" "
-			"q->module=\"%s\" q->format=\"%s\" q->lineno=%u-%u\n",
-			query->function, query->filename,
-			query->module, query->format, query->first_lineno,
-			query->last_lineno);
+	pr_debug("q->function=\"%s\" q->filename=\"%s\" "
+		"q->module=\"%s\" q->format=\"%s\" q->lineno=%u-%u\n",
+		query->function, query->filename,
+		query->module, query->format, query->first_lineno,
+		query->last_lineno);
 
 	return 0;
 }
@@ -364,8 +362,7 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 	default:
 		return -EINVAL;
 	}
-	if (verbose)
-		pr_info("op='%c'\n", op);
+	pr_debug("op='%c'\n", op);
 
 	for ( ; *str ; ++str) {
 		for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
@@ -379,8 +376,7 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 	}
 	if (flags == 0)
 		return -EINVAL;
-	if (verbose)
-		pr_info("flags=0x%x\n", flags);
+	pr_debug("flags=0x%x\n", flags);
 
 	/* calculate final *flagsp, *maskp according to mask and op */
 	switch (op) {
@@ -397,8 +393,7 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 		*flagsp = 0;
 		break;
 	}
-	if (verbose)
-		pr_info("*flagsp=0x%x *maskp=0x%x\n", *flagsp, *maskp);
+	pr_debug("*flagsp=0x%x *maskp=0x%x\n", *flagsp, *maskp);
 	return 0;
 }
 
@@ -542,8 +537,7 @@ static ssize_t ddebug_proc_write(struct file *file, const char __user *ubuf,
 	if (copy_from_user(tmpbuf, ubuf, len))
 		return -EFAULT;
 	tmpbuf[len] = '\0';
-	if (verbose)
-		pr_info("read %d bytes from userspace\n", (int)len);
+	pr_debug("read %d bytes from userspace\n", (int)len);
 
 	ret = ddebug_exec_query(tmpbuf);
 	if (ret)
@@ -605,8 +599,7 @@ static void *ddebug_proc_start(struct seq_file *m, loff_t *pos)
 	struct _ddebug *dp;
 	int n = *pos;
 
-	if (verbose)
-		pr_info("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);
+	pr_debug("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);
 
 	mutex_lock(&ddebug_lock);
 
@@ -630,9 +623,8 @@ static void *ddebug_proc_next(struct seq_file *m, void *p, loff_t *pos)
 	struct ddebug_iter *iter = m->private;
 	struct _ddebug *dp;
 
-	if (verbose)
-		pr_info("called m=%p p=%p *pos=%lld\n",
-			m, p, (unsigned long long)*pos);
+	pr_debug("called m=%p p=%p *pos=%lld\n",
+		m, p, (unsigned long long)*pos);
 
 	if (p == SEQ_START_TOKEN)
 		dp = ddebug_iter_first(iter);
@@ -654,8 +646,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 	struct _ddebug *dp = p;
 	char flagsbuf[8];
 
-	if (verbose)
-		pr_info("called m=%p p=%p\n", m, p);
+	pr_debug("called m=%p p=%p\n", m, p);
 
 	if (p == SEQ_START_TOKEN) {
 		seq_puts(m,
@@ -679,8 +670,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
  */
 static void ddebug_proc_stop(struct seq_file *m, void *p)
 {
-	if (verbose)
-		pr_info("called m=%p p=%p\n", m, p);
+	pr_debug("called m=%p p=%p\n", m, p);
 	mutex_unlock(&ddebug_lock);
 }
 
@@ -702,8 +692,7 @@ static int ddebug_proc_open(struct inode *inode, struct file *file)
 	struct ddebug_iter *iter;
 	int err;
 
-	if (verbose)
-		pr_info("called\n");
+	pr_debug("called\n");
 
 	iter = kzalloc(sizeof(*iter), GFP_KERNEL);
 	if (iter == NULL)
@@ -775,8 +764,7 @@ int ddebug_remove_module(const char *mod_name)
 	struct ddebug_table *dt, *nextdt;
 	int ret = -ENOENT;
 
-	if (verbose)
-		pr_info("removing module \"%s\"\n", mod_name);
+	pr_debug("removing module \"%s\"\n", mod_name);
 
 	mutex_lock(&ddebug_lock);
 	list_for_each_entry_safe(dt, nextdt, &ddebug_tables, link) {
@@ -850,13 +838,11 @@ static int __init dynamic_debug_init(void)
 
 	/* ddebug_query boot param got passed -> set it up */
 	if (ddebug_setup_string[0] != '\0') {
+		pr_info("ddebug initializing with string \"%s\"",
+			ddebug_setup_string);
 		ret = ddebug_exec_query(ddebug_setup_string);
 		if (ret)
-			pr_warn("Invalid ddebug boot param %s",
-				ddebug_setup_string);
-		else
-			pr_info("ddebug initialized with string %s",
-				ddebug_setup_string);
+			pr_warn("invalid ddebug_query\n");
 	}
 
 out_free:
-- 
1.7.4.1

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Bart Van Assche]

On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> Replace almost all occurrences of "if (verbose) pr_info()" with
> pr_debug(), and get full control of output at each callsite.
> Leave a few sites unaltered:
>
> 1st also uses pr_cont(), and theres no pr_debug_cont().
> 2nd is in ddebug_add_module(), which is called during arch_init,
> too early for callsite to be enabled when called.
>
> 3rd, pr_debug doesnt work in dynamic_debug_init(), its too early.
> Also move the print ddebug_setup_string prior to parsing, since
> afterwards it's been chopped up with '\0's, and only 1st word is seen.
>
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  lib/dynamic_debug.c |   66 ++++++++++++++++++++-------------------------------
>  1 files changed, 26 insertions(+), 40 deletions(-)
>
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index af6f1ae..a7161db 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -157,18 +157,17 @@ static void ddebug_change(const struct ddebug_query *query,
>                                dp->enabled = 1;
>                        else
>                                dp->enabled = 0;
> -                       if (verbose)
> -                               pr_info("changed %s:%d [%s]%s %s\n",
> -                                       dp->filename, dp->lineno,
> -                                       dt->mod_name, dp->function,
> -                                       ddebug_describe_flags(dp, flagbuf,
> -                                                       sizeof(flagbuf)));
> +                       pr_debug("changed %s:%d [%s]%s %s\n",
> +                               dp->filename, dp->lineno,
> +                               dt->mod_name, dp->function,
> +                               ddebug_describe_flags(dp, flagbuf,
> +                                               sizeof(flagbuf)));

Changing pr_info() into pr_debug() inside the dynamic_debug
implementation seems like a really bad idea to me. Such changes make
it hard to find out via source code reading whether or not there is a
risk that invoking one of these pr_debug() macros will cause infinite
recursion.

Bart.

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jim Cromie]

On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> Replace almost all occurrences of "if (verbose) pr_info()" with
>> pr_debug(), and get full control of output at each callsite.
>> Leave a few sites unaltered:
>>
>> 1st also uses pr_cont(), and theres no pr_debug_cont().
>> 2nd is in ddebug_add_module(), which is called during arch_init,
>> too early for callsite to be enabled when called.
>>
>> 3rd, pr_debug doesnt work in dynamic_debug_init(), its too early.
>> Also move the print ddebug_setup_string prior to parsing, since
>> afterwards it's been chopped up with '\0's, and only 1st word is seen.
>>

>
> Changing pr_info() into pr_debug() inside the dynamic_debug
> implementation seems like a really bad idea to me. Such changes make
> it hard to find out via source code reading whether or not there is a
> risk that invoking one of these pr_debug() macros will cause infinite
> recursion.
>
> Bart.
>

By inspection, all the pr_debug-ish code macros down to

 430int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
 431{
 432        va_list args

which uses raw printk, KERN_DEBUG, KERN_CONT only.
This is the "print-path" that Jason mentioned.

IOW, this is more like "eating your own dogfood" than "eating your own tail"

WRT earlier discussion (Joe, Jason):

> I think these should be pr_debug.
> I know you're only using the current style.
>
> Jason, any reason these can not be converted?
>

it should be ok, although we have to be careful not to use them in the
printing path, since that will cause a recursion.

Also, if there is an issue with the dynamic debug code, it makes it more
of a pain to debug :)


All conversions were to flag-management code
The conversion was painless, and just worked,
except for init code, where I used pr_info.

wrt "pain to debug", Id suggest that "eating your own dogfood"
provides an early test, especially when combined with following
to enable the selftest at boot.

    ddebug_query="module dynamic_debug +p ; module dynamic_debug line
815-940 =_"

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Bart Van Assche]

On Wed, Jul 27, 2011 at 11:34 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
>> Changing pr_info() into pr_debug() inside the dynamic_debug
>> implementation seems like a really bad idea to me. Such changes make
>> it hard to find out via source code reading whether or not there is a
>> risk that invoking one of these pr_debug() macros will cause infinite
>> recursion.
>
> WRT earlier discussion (Joe, Jason):
>
>> I think these should be pr_debug.
>> I know you're only using the current style.
>>
>> Jason, any reason these can not be converted?
>
> it should be ok, although we have to be careful not to use them in the
> printing path, since that will cause a recursion.
>
> Also, if there is an issue with the dynamic debug code, it makes it more
> of a pain to debug :)

With this approach enabling all debug printing in the dynamic_debug
implementation requires both echoing into .../dynamic_debug/control
and setting the "verbose" module parameter. That's not something I
would call "elegant", but after all, I'm not the dynamic debug
maintainer ...

Bart.

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jason Baron]

On Thu, Jul 28, 2011 at 11:18:56AM +0200, Bart Van Assche wrote:
> On Wed, Jul 27, 2011 at 11:34 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> > On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> >> Changing pr_info() into pr_debug() inside the dynamic_debug
> >> implementation seems like a really bad idea to me. Such changes make
> >> it hard to find out via source code reading whether or not there is a
> >> risk that invoking one of these pr_debug() macros will cause infinite
> >> recursion.
> >
> > WRT earlier discussion (Joe, Jason):
> >
> >> I think these should be pr_debug.
> >> I know you're only using the current style.
> >>
> >> Jason, any reason these can not be converted?
> >
> > it should be ok, although we have to be careful not to use them in the
> > printing path, since that will cause a recursion.
> >
> > Also, if there is an issue with the dynamic debug code, it makes it more
> > of a pain to debug :)
> 
> With this approach enabling all debug printing in the dynamic_debug
> implementation requires both echoing into .../dynamic_debug/control
> and setting the "verbose" module parameter. That's not something I
> would call "elegant", but after all, I'm not the dynamic debug
> maintainer ...
> 
> Bart.

we certainly don't want to make ppl do both. why is the verbose param
still required?

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jim Cromie]

On Thu, Jul 28, 2011 at 12:24 PM, Jason Baron <jbaron@redhat.com> wrote:
> On Thu, Jul 28, 2011 at 11:18:56AM +0200, Bart Van Assche wrote:
>> On Wed, Jul 27, 2011 at 11:34 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> > On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
>> >> Changing pr_info() into pr_debug() inside the dynamic_debug
>> >> implementation seems like a really bad idea to me. Such changes make
>> >> it hard to find out via source code reading whether or not there is a
>> >> risk that invoking one of these pr_debug() macros will cause infinite
>> >> recursion.
>> >
>> > WRT earlier discussion (Joe, Jason):
>> >
>> >> I think these should be pr_debug.
>> >> I know you're only using the current style.
>> >>
>> >> Jason, any reason these can not be converted?
>> >
>> > it should be ok, although we have to be careful not to use them in the
>> > printing path, since that will cause a recursion.
>> >
>> > Also, if there is an issue with the dynamic debug code, it makes it more
>> > of a pain to debug :)
>>
>> With this approach enabling all debug printing in the dynamic_debug
>> implementation requires both echoing into .../dynamic_debug/control
>> and setting the "verbose" module parameter. That's not something I
>> would call "elegant", but after all, I'm not the dynamic debug
>> maintainer ...
>>
>> Bart.
>
> we certainly don't want to make ppl do both. why is the verbose param
> still required?
>

Its needed to selectively enable pr_info()s,
which I use cuz they happen too early for pr_debug() to be enabled.

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jason Baron]

On Thu, Jul 28, 2011 at 03:15:35PM -0600, Jim Cromie wrote:
> On Thu, Jul 28, 2011 at 12:24 PM, Jason Baron <jbaron@redhat.com> wrote:
> > On Thu, Jul 28, 2011 at 11:18:56AM +0200, Bart Van Assche wrote:
> >> On Wed, Jul 27, 2011 at 11:34 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> >> > On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> >> >> Changing pr_info() into pr_debug() inside the dynamic_debug
> >> >> implementation seems like a really bad idea to me. Such changes make
> >> >> it hard to find out via source code reading whether or not there is a
> >> >> risk that invoking one of these pr_debug() macros will cause infinite
> >> >> recursion.
> >> >
> >> > WRT earlier discussion (Joe, Jason):
> >> >
> >> >> I think these should be pr_debug.
> >> >> I know you're only using the current style.
> >> >>
> >> >> Jason, any reason these can not be converted?
> >> >
> >> > it should be ok, although we have to be careful not to use them in the
> >> > printing path, since that will cause a recursion.
> >> >
> >> > Also, if there is an issue with the dynamic debug code, it makes it more
> >> > of a pain to debug :)
> >>
> >> With this approach enabling all debug printing in the dynamic_debug
> >> implementation requires both echoing into .../dynamic_debug/control
> >> and setting the "verbose" module parameter. That's not something I
> >> would call "elegant", but after all, I'm not the dynamic debug
> >> maintainer ...
> >>
> >> Bart.
> >
> > we certainly don't want to make ppl do both. why is the verbose param
> > still required?
> >
> 
> Its needed to selectively enable pr_info()s,
> which I use cuz they happen too early for pr_debug() to be enabled.

ok, then I would suggest we just stay with the verbose flag, since we
don't want make ppl jump through two hoops, and as a bonus we avoid any
potential recursive issue.

thanks,

-Jason

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jim Cromie]

On Wed, Aug 3, 2011 at 12:27 PM, Jason Baron <jbaron@redhat.com> wrote:
> On Thu, Jul 28, 2011 at 03:15:35PM -0600, Jim Cromie wrote:
>> On Thu, Jul 28, 2011 at 12:24 PM, Jason Baron <jbaron@redhat.com> wrote:
>> > On Thu, Jul 28, 2011 at 11:18:56AM +0200, Bart Van Assche wrote:
>> >> On Wed, Jul 27, 2011 at 11:34 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> >> > On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
>> >> >> Changing pr_info() into pr_debug() inside the dynamic_debug
>> >> >> implementation seems like a really bad idea to me. Such changes make
>> >> >> it hard to find out via source code reading whether or not there is a
>> >> >> risk that invoking one of these pr_debug() macros will cause infinite
>> >> >> recursion.
>> >> >
>> >> > WRT earlier discussion (Joe, Jason):
>> >> >
>> >> >> I think these should be pr_debug.
>> >> >> I know you're only using the current style.
>> >> >>
>> >> >> Jason, any reason these can not be converted?
>> >> >
>> >> > it should be ok, although we have to be careful not to use them in the
>> >> > printing path, since that will cause a recursion.
>> >> >
>> >> > Also, if there is an issue with the dynamic debug code, it makes it more
>> >> > of a pain to debug :)
>> >>
>> >> With this approach enabling all debug printing in the dynamic_debug
>> >> implementation requires both echoing into .../dynamic_debug/control
>> >> and setting the "verbose" module parameter. That's not something I
>> >> would call "elegant", but after all, I'm not the dynamic debug
>> >> maintainer ...
>> >>
>> >> Bart.
>> >
>> > we certainly don't want to make ppl do both. why is the verbose param
>> > still required?
>> >
>>
>> Its needed to selectively enable pr_info()s,
>> which I use cuz they happen too early for pr_debug() to be enabled.

ie: during init.  ddebug_add_module happens for everything in the
_ddebug table, and THEN ddebug_query is parsed and executed,
which enables the callsites.
I could parse 1st, and put them on pending-list, but then all parsing
is done before the callsites are enabled, defeating the purpose.

>
> ok, then I would suggest we just stay with the verbose flag, since we
> don't want make ppl jump through two hoops, and as a bonus we avoid any
> potential recursive issue.
>
> thanks,
>
> -Jason
>


alright, I can live with that, but Id like to note the loss of selectivity
in the verbose-only approach before capitulating:

the pr_info()s in _proc_ routines are quite noisy when enabled.

in my current config, which has 537 callsites,
enabling all those pr_debug()s unselectively, ie:

Kernel command line: ... ddebug_query="module dynamic_debug +pflt; "
loglevel=8 dynamic_debug.verbose=1

and doing : ~# cat /dbg/dynamic_debug/control
logs 836 lines like
[2573] ddebug_proc_next:866: called m=c6f99a40 p=c88955d0 *pos=427
[2573] ddebug_proc_show:888: called m=c6f99a40 p=c88955e8

Not completely overwhelming perhaps, but nice to silence.

Before switching to pr_debug, I had changed those proc pr_infos to:
if (verbose >= 10)
    pr_info(...)

that quiets things nicely, and is knowable via modinfo,
is that addition acceptable ?

BTW, are you aiming for tip tree ?

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jason Baron]

On Wed, Aug 03, 2011 at 01:52:33PM -0600, Jim Cromie wrote:
> On Wed, Aug 3, 2011 at 12:27 PM, Jason Baron <jbaron@redhat.com> wrote:
> > On Thu, Jul 28, 2011 at 03:15:35PM -0600, Jim Cromie wrote:
> >> On Thu, Jul 28, 2011 at 12:24 PM, Jason Baron <jbaron@redhat.com> wrote:
> >> > On Thu, Jul 28, 2011 at 11:18:56AM +0200, Bart Van Assche wrote:
> >> >> On Wed, Jul 27, 2011 at 11:34 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> >> >> > On Tue, Jul 26, 2011 at 1:08 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> >> >> >> Changing pr_info() into pr_debug() inside the dynamic_debug
> >> >> >> implementation seems like a really bad idea to me. Such changes make
> >> >> >> it hard to find out via source code reading whether or not there is a
> >> >> >> risk that invoking one of these pr_debug() macros will cause infinite
> >> >> >> recursion.
> >> >> >
> >> >> > WRT earlier discussion (Joe, Jason):
> >> >> >
> >> >> >> I think these should be pr_debug.
> >> >> >> I know you're only using the current style.
> >> >> >>
> >> >> >> Jason, any reason these can not be converted?
> >> >> >
> >> >> > it should be ok, although we have to be careful not to use them in the
> >> >> > printing path, since that will cause a recursion.
> >> >> >
> >> >> > Also, if there is an issue with the dynamic debug code, it makes it more
> >> >> > of a pain to debug :)
> >> >>
> >> >> With this approach enabling all debug printing in the dynamic_debug
> >> >> implementation requires both echoing into .../dynamic_debug/control
> >> >> and setting the "verbose" module parameter. That's not something I
> >> >> would call "elegant", but after all, I'm not the dynamic debug
> >> >> maintainer ...
> >> >>
> >> >> Bart.
> >> >
> >> > we certainly don't want to make ppl do both. why is the verbose param
> >> > still required?
> >> >
> >>
> >> Its needed to selectively enable pr_info()s,
> >> which I use cuz they happen too early for pr_debug() to be enabled.
> 
> ie: during init.  ddebug_add_module happens for everything in the
> _ddebug table, and THEN ddebug_query is parsed and executed,
> which enables the callsites.
> I could parse 1st, and put them on pending-list, but then all parsing
> is done before the callsites are enabled, defeating the purpose.
> 
> >
> > ok, then I would suggest we just stay with the verbose flag, since we
> > don't want make ppl jump through two hoops, and as a bonus we avoid any
> > potential recursive issue.
> >
> > thanks,
> >
> > -Jason
> >
> 
> 
> alright, I can live with that, but Id like to note the loss of selectivity
> in the verbose-only approach before capitulating:
> 
> the pr_info()s in _proc_ routines are quite noisy when enabled.
> 
> in my current config, which has 537 callsites,
> enabling all those pr_debug()s unselectively, ie:
> 
> Kernel command line: ... ddebug_query="module dynamic_debug +pflt; "
> loglevel=8 dynamic_debug.verbose=1
> 
> and doing : ~# cat /dbg/dynamic_debug/control
> logs 836 lines like
> [2573] ddebug_proc_next:866: called m=c6f99a40 p=c88955d0 *pos=427
> [2573] ddebug_proc_show:888: called m=c6f99a40 p=c88955e8
> 
> Not completely overwhelming perhaps, but nice to silence.
> 
> Before switching to pr_debug, I had changed those proc pr_infos to:
> if (verbose >= 10)
>     pr_info(...)
> 
> that quiets things nicely, and is knowable via modinfo,
> is that addition acceptable ?
> 

why do you have '10' here, isn't it just, if (verbose) ? 

> BTW, are you aiming for tip tree ?

The dynamic debug patches have been going in via Greg KH's device
tree. Now that the merge window has closed, I going to re-send the patch
series that I had pending. You can then send your series on top of that,
if you'd like.

Thanks,

-Jason

Re: [PATCH 03/25] dynamic_debug: use pr_debug instead of pr_info

[Jim Cromie]

On Wed, Aug 10, 2011 at 11:14 AM, Jason Baron <jbaron@redhat.com> wrote:

trimmed

>>
>> alright, I can live with that, but Id like to note the loss of selectivity
>> in the verbose-only approach before capitulating:
>>
>> the pr_info()s in _proc_ routines are quite noisy when enabled.
>>
>> in my current config, which has 537 callsites,
>> enabling all those pr_debug()s unselectively, ie:
>>
>> Kernel command line: ... ddebug_query="module dynamic_debug +pflt; "
>> loglevel=8 dynamic_debug.verbose=1
>>
>> and doing : ~# cat /dbg/dynamic_debug/control
>> logs 836 lines like
>> [2573] ddebug_proc_next:866: called m=c6f99a40 p=c88955d0 *pos=427
>> [2573] ddebug_proc_show:888: called m=c6f99a40 p=c88955e8
>>
>> Not completely overwhelming perhaps, but nice to silence.
>>
>> Before switching to pr_debug, I had changed those proc pr_infos to:
>> if (verbose >= 10)
>>     pr_info(...)
>>
>> that quiets things nicely, and is knowable via modinfo,
>> is that addition acceptable ?
>>
>
> why do you have '10' here, isn't it just, if (verbose) ?

Because the ddebug_proc_show and ddebug_proc_next routines
are called a lot (~500 times each on my build) when looking at control file.
For my needs, there wasnt much info in them..

As to the number, I wanted to leave space for other increments
of verbosity, and I couldnt resist an homage to Spinal Tap:
    This verbosity goes to eleven !

If you'd prefer, I can switch to a flags/mask approach,
or drop back to pure boolean.


>
>> BTW, are you aiming for tip tree ?
>
> The dynamic debug patches have been going in via Greg KH's device
> tree. Now that the merge window has closed, I going to re-send the patch
> series that I had pending. You can then send your series on top of that,
> if you'd like.
>

Sure, that works.  Ill watch for it.
Mine is 'ready' subject to changes in your series, and pushback.

> Thanks,
>
> -Jason
>

[PATCH 04/25] dynamic_debug: replace strcpy with strlcpy, in ddebug_setup_query()

[Jim Cromie]

replace strcpy with strlcpy, and add define for the size constant.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    7 ++++---
 1 files changed, 4 insertions(+), 3 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index a7161db..887940d 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -506,14 +506,15 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 }
 EXPORT_SYMBOL(__dynamic_netdev_dbg);
 
-static __initdata char ddebug_setup_string[1024];
+#define BOOT_QUERY_SZ 1024
+static __initdata char ddebug_setup_string[BOOT_QUERY_SZ];
 static __init int ddebug_setup_query(char *str)
 {
-	if (strlen(str) >= 1024) {
+	if (strlen(str) >= BOOT_QUERY_SZ) {
 		pr_warn("ddebug boot param string too large\n");
 		return 0;
 	}
-	strcpy(ddebug_setup_string, str);
+	strlcpy(ddebug_setup_string, str, BOOT_QUERY_SZ);
 	return 1;
 }
 
-- 
1.7.4.1

[PATCH 05/25] dynamic_debug: trim source-path prefix from dynamic_debug/control

[Jim Cromie]

Check for a common source-path prefix, and skip past it, to print a
path thats relative to kernel source's root-dir.  For in-tree modules,
this makes the control file easier to read without a wide screen.

For example:
  kernel/freezer.c:128 [freezer]cancel_freezing - "  clean up: %s\012"

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    6 +++++-
 1 files changed, 5 insertions(+), 1 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 887940d..76f80dc 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -646,6 +646,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 	struct ddebug_iter *iter = m->private;
 	struct _ddebug *dp = p;
 	char flagsbuf[8];
+	int skip = strlen(__FILE__) - strlen("lib/dynamic_debug.c");
 
 	pr_debug("called m=%p p=%p\n", m, p);
 
@@ -655,8 +656,11 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 		return 0;
 	}
 
+	if (strncmp(dp->filename, __FILE__, skip))
+		skip = 0; /* prefix mismatch, don't skip */
+
 	seq_printf(m, "%s:%u [%s]%s %s \"",
-		   dp->filename, dp->lineno,
+		   dp->filename + skip, dp->lineno,
 		   iter->table->mod_name, dp->function,
 		   ddebug_describe_flags(dp, flagsbuf, sizeof(flagsbuf)));
 	seq_escape(m, dp->format, "\t\r\n\"");
-- 
1.7.4.1

[PATCH 06/25] dynamic_debug: process multiple commands on a line

[Jim Cromie]

Process multiple commands per line, separated by ';' or '\n'.
All commands are processed, independent of errors, allowing individual
commands to fail, for example when a module is not installed.  Errors
are counted, and last error code is returned.

With this, extensive command sets can be given on the boot-line.

Splitting on '\n' allows "cat cmd-file > /dbg/dynamic_debug/control"
where cmd-file contains multiple queries, one per line.  Empty commands
are skipped, allowing ";\n\n" to not count as errors.

Splitting on '\n' prevents its use in a format-spec, but thats not very
useful anyway, searching for meaningful and selective substrings is typical.

Also allow comment lines, starting with '#', with optional leading whitespace.
Trailing comments are allowed, if preceded by ';' which terminates
the command on the line.  For example:

root@voyage:~# cat debugfs-file

  # blank lines ok
  module dynamic_debug +p		; # turn on self-debugging
  # these are quite noisy when grepping
  # $DEBUGFS/dynamic_debug/{control,pending}
    # silence them (also, leading spaces allowed in comments)
  func ddebug_proc_show -p
  func ddebug_proc_next -p	; # trailing comments need cmd terminator
  func pending_proc_show -p	; # TB added later.  gives error, harmless.
  func pending_proc_next -p

root@voyage:~# cat debugfs-file > /dbg/dynamic_debug/control
split into words: "module" "dynamic_debug" "+p"
changed $srcpath/lib/dynamic_debug.c:223 [dynamic_debug]ddebug_change =p
changed $srcpath/lib/dynamic_debug.c:576 [dynamic_debug]ddebug_save_pending =p
...
nfound 23 on func="" file="" module="dynamic_debug" format="" lineno=0-0
query 1: "func ddebug_proc_show -p	"
split into words: "func" "ddebug_proc_show" "-p"
parsed func="ddebug_proc_show" file="" module="" format="" lineno=0-0
filter=0x0 op='-' flags=0x1 *flagsp=0x0 *maskp=0xfffffffe
changed $srcpath/lib/dynamic_debug.c:881 [dynamic_debug]ddebug_proc_show =_
nfound 1 on func="ddebug_proc_show" file="" module="" format="" lineno=0-0
query 2: "func ddebug_proc_next -p"
...

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   32 ++++++++++++++++++++++++++++++--
 1 files changed, 30 insertions(+), 2 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 76f80dc..2539517 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -418,6 +418,34 @@ static int ddebug_exec_query(char *query_string)
 	return 0;
 }
 
+/* handle multiple queries, continue on error, return last error */
+static int ddebug_exec_queries(char *query)
+{
+	char *split;
+	int i, errs = 0, exitcode = 0, rc;
+
+	for (i = 0; query; query = split) {
+		split = strpbrk(query, ";\n");
+		if (split)
+			*split++ = '\0';
+
+		query = skip_spaces(query);
+		if (!*query || *query == '#')
+			continue;
+		pr_debug("query %d: \"%s\"\n", i, query);
+
+		rc = ddebug_exec_query(query);
+		if (rc) {
+			errs++;
+			exitcode = rc;
+		}
+		i++;
+	}
+	pr_debug("processed %d queries, with %d errs\n", i, errs);
+
+	return exitcode;
+}
+
 #define PREFIX_SIZE 64
 #define LEFT(wrote) ((PREFIX_SIZE - wrote) > 0) ? (PREFIX_SIZE - wrote) : 0
 
@@ -540,7 +568,7 @@ static ssize_t ddebug_proc_write(struct file *file, const char __user *ubuf,
 	tmpbuf[len] = '\0';
 	pr_debug("read %d bytes from userspace\n", (int)len);
 
-	ret = ddebug_exec_query(tmpbuf);
+	ret = ddebug_exec_queries(tmpbuf);
 	if (ret)
 		return ret;
 
@@ -845,7 +873,7 @@ static int __init dynamic_debug_init(void)
 	if (ddebug_setup_string[0] != '\0') {
 		pr_info("ddebug initializing with string \"%s\"",
 			ddebug_setup_string);
-		ret = ddebug_exec_query(ddebug_setup_string);
+		ret = ddebug_exec_queries(ddebug_setup_string);
 		if (ret)
 			pr_warn("invalid ddebug_query\n");
 	}
-- 
1.7.4.1

[PATCH 07/25] dynamic_debug: enlarge command/query write buffer

[Jim Cromie]

Current write buffer is 256 bytes, on stack.  Allocate it off heap,
to fit the size passed by user.   This makes it play nicely with:

 $> cat debug-queries-file > /dbg/dynamic_debug/control

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   13 ++++++++-----
 1 files changed, 8 insertions(+), 5 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 2539517..8ce941a 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -555,20 +555,23 @@ __setup("ddebug_query=", ddebug_setup_query);
 static ssize_t ddebug_proc_write(struct file *file, const char __user *ubuf,
 				  size_t len, loff_t *offp)
 {
-	char tmpbuf[256];
+	char *tmpbuf;
 	int ret;
 
 	if (len == 0)
 		return 0;
-	/* we don't check *offp -- multiple writes() are allowed */
-	if (len > sizeof(tmpbuf)-1)
-		return -E2BIG;
-	if (copy_from_user(tmpbuf, ubuf, len))
+	tmpbuf = kmalloc(len, GFP_KERNEL);
+	if (!tmpbuf)
+		return -ENOMEM;
+	if (copy_from_user(tmpbuf, ubuf, len)) {
+		kfree(tmpbuf);
 		return -EFAULT;
+	}
 	tmpbuf[len] = '\0';
 	pr_debug("read %d bytes from userspace\n", (int)len);
 
 	ret = ddebug_exec_queries(tmpbuf);
+	kfree(tmpbuf);
 	if (ret)
 		return ret;
 
-- 
1.7.4.1

[PATCH 08/25] dynamic_debug: warn when >1 of each type of match-spec is given

[Jim Cromie]

Issue warning when a match-spec is given multiple times in a rule.
Previous code kept last one, but was silent about it.  Docs imply only
one is allowed by saying match-specs are ANDed together, given that
module M cannot match both A and B.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   20 ++++++++++++++++----
 1 files changed, 16 insertions(+), 4 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 8ce941a..6746439 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -280,6 +280,14 @@ static char *unescape(char *str)
 	return str;
 }
 
+static inline void check_set(const char **dest, char *src, char *name)
+{
+	if (*dest)
+		pr_warn("match-spec:%s val:%s overridden by %s",
+			name, *dest, src);
+	*dest = src;
+}
+
 /*
  * Parse words[] as a ddebug query specification, which is a series
  * of (keyword, value) pairs chosen from these possibilities:
@@ -291,6 +299,9 @@ static char *unescape(char *str)
  * format <escaped-string-to-find-in-format>
  * line <lineno>
  * line <first-lineno>-<last-lineno> // where either may be empty
+ *
+ * only 1 pair of each type is expected, subsequent ones elicit a
+ * warning, and override the setting.
  */
 static int ddebug_parse_query(char *words[], int nwords,
 			       struct ddebug_query *query)
@@ -304,13 +315,14 @@ static int ddebug_parse_query(char *words[], int nwords,
 
 	for (i = 0 ; i < nwords ; i += 2) {
 		if (!strcmp(words[i], "func"))
-			query->function = words[i+1];
+			check_set(&query->function, words[i+1], "func");
 		else if (!strcmp(words[i], "file"))
-			query->filename = words[i+1];
+			check_set(&query->filename, words[i+1], "file");
 		else if (!strcmp(words[i], "module"))
-			query->module = words[i+1];
+			check_set(&query->module, words[i+1], "module");
 		else if (!strcmp(words[i], "format"))
-			query->format = unescape(words[i+1]);
+			check_set(&query->format, unescape(words[i+1]),
+				"format");
 		else if (!strcmp(words[i], "line")) {
 			char *first = words[i+1];
 			char *last = strchr(first, '-');
-- 
1.7.4.1

[PATCH 09/25] dynamic_debug: pr_err() call should not depend upon verbosity

[Jim Cromie]

issue keyword/parsing errors even w/o verbose set;
uncover otherwize mysterious non-functionality.
Also convert to pr_err(), which supplies __func__ via pr_fmt.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    3 +--
 1 files changed, 1 insertions(+), 2 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 6746439..c6d38b4 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -338,8 +338,7 @@ static int ddebug_parse_query(char *words[], int nwords,
 				query->last_lineno = query->first_lineno;
 			}
 		} else {
-			if (verbose)
-				pr_err("unknown keyword \"%s\"\n", words[i]);
+			pr_err("unknown keyword \"%s\"\n", words[i]);
 			return -EINVAL;
 		}
 	}
-- 
1.7.4.1

[PATCH 10/25] dynamic_debug: dont kill entire facility on error parsing ddebug_query

[Jim Cromie]

Currently, a parsing error on ddebug_query results in effective loss
of the facility; all tables are removed, and the init-call returns error.
This is way too severe, especially when an innocent quoting error can
be the cause:

Kernel command line: ... ddebug_query='file char_dev.c +p'
yields:

ddebug_exec_queries: query 0: "'file"
query before parse <'file>
ddebug_exec_queries: processed 1 queries, with 1 errs
Invalid ddebug boot param 'file

Fix this by zeroing return-code for query parse errors before
returning from dynamic_debug_init().

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    4 +++-
 1 files changed, 3 insertions(+), 1 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c6d38b4..1ced79e 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -888,8 +888,10 @@ static int __init dynamic_debug_init(void)
 		pr_info("ddebug initializing with string \"%s\"",
 			ddebug_setup_string);
 		ret = ddebug_exec_queries(ddebug_setup_string);
-		if (ret)
+		if (ret) {
+			ret = 0; /* make this non-fatal */
 			pr_warn("invalid ddebug_query\n");
+		}
 	}
 
 out_free:
-- 
1.7.4.1

[PATCH 11/25] dynamic_debug: factor show_ddebug_query out of ddebug_parse_query

[Jim Cromie]

Factor show_ddebug_query out of ddebug_parse_query.  Also change
the printed labels to agree with the query-spec keywords accepted in
the control file; file, func.  Pass "" when string is null,
to avoid "(null)" output from sprintf.

Code uses sprintf into a large buffer, kallocd and freed from
ddebug_exec_queries.  function has 1 caller now, will add more later.
Will also reuse the buffer and function for show_pending_query().
This is in lieu of char *p=kasprintf; free(p) everywhere the
function will be used.  TBD.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   30 ++++++++++++++++++++++++------
 1 files changed, 24 insertions(+), 6 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 1ced79e..5774a6f 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -96,6 +96,21 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
 	return buf;
 }
 
+static char *prbuf_query;
+
+static char *show_ddebug_query(const struct ddebug_query *q)
+{
+	char *p = kasprintf(GFP_KERNEL,
+			"func=\"%s\" file=\"%s\" "
+			"module=\"%s\" format=\"%s\" lineno=%u-%u",
+			q->function ? q->function : "",
+			q->filename ? q->filename : "",
+			q->module ? q->module : "",
+			q->format ? q->format : "",
+			q->first_lineno, q->last_lineno);
+	return p;
+}
+
 /*
  * Search the tables for _ddebug's which match the given
  * `query' and apply the `flags' and `mask' to them.  Tells
@@ -307,6 +322,7 @@ static int ddebug_parse_query(char *words[], int nwords,
 			       struct ddebug_query *query)
 {
 	unsigned int i;
+	char *qstr;
 
 	/* check we have an even number of words */
 	if (nwords % 2 != 0)
@@ -342,12 +358,9 @@ static int ddebug_parse_query(char *words[], int nwords,
 			return -EINVAL;
 		}
 	}
-
-	pr_debug("q->function=\"%s\" q->filename=\"%s\" "
-		"q->module=\"%s\" q->format=\"%s\" q->lineno=%u-%u\n",
-		query->function, query->filename,
-		query->module, query->format, query->first_lineno,
-		query->last_lineno);
+	qstr = show_ddebug_query(query);
+	pr_debug("parsed %s\n", qstr);
+	kfree(qstr);
 
 	return 0;
 }
@@ -435,6 +448,10 @@ static int ddebug_exec_queries(char *query)
 	char *split;
 	int i, errs = 0, exitcode = 0, rc;
 
+	prbuf_query = kmalloc(1024, GFP_KERNEL);
+	if (prbuf_query == NULL)
+		return -ENOMEM;
+
 	for (i = 0; query; query = split) {
 		split = strpbrk(query, ";\n");
 		if (split)
@@ -452,6 +469,7 @@ static int ddebug_exec_queries(char *query)
 		}
 		i++;
 	}
+	kfree(prbuf_query);
 	pr_debug("processed %d queries, with %d errs\n", i, errs);
 
 	return exitcode;
-- 
1.7.4.1

Re: [PATCH 11/25] dynamic_debug: factor show_ddebug_query out of ddebug_parse_query

[Bart Van Assche]

On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> +static char *prbuf_query;

Please drop this.

Thanks,

Bart.

Re: [PATCH 11/25] dynamic_debug: factor show_ddebug_query out of ddebug_parse_query

[Bart Van Assche]

On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> @@ -435,6 +448,10 @@ static int ddebug_exec_queries(char *query)
>        char *split;
>        int i, errs = 0, exitcode = 0, rc;
>
> +       prbuf_query = kmalloc(1024, GFP_KERNEL);
> +       if (prbuf_query == NULL)
> +               return -ENOMEM;
> +
>        for (i = 0; query; query = split) {
>                split = strpbrk(query, ";\n");
>                if (split)
> @@ -452,6 +469,7 @@ static int ddebug_exec_queries(char *query)
>                }
>                i++;
>        }
> +       kfree(prbuf_query);

The above changes invoke memory allocation and deallocation. But the
allocated buffer isn't used anywhere - neither in this patch nor in
any later patch ???

Bart.

Re: [PATCH 11/25] dynamic_debug: factor show_ddebug_query out of ddebug_parse_query

[Jim Cromie]

On Tue, Jul 26, 2011 at 1:15 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> @@ -435,6 +448,10 @@ static int ddebug_exec_queries(char *query)
>>        char *split;
>>        int i, errs = 0, exitcode = 0, rc;
>>
>> +       prbuf_query = kmalloc(1024, GFP_KERNEL);
>> +       if (prbuf_query == NULL)
>> +               return -ENOMEM;
>> +
>>        for (i = 0; query; query = split) {
>>                split = strpbrk(query, ";\n");
>>                if (split)
>> @@ -452,6 +469,7 @@ static int ddebug_exec_queries(char *query)
>>                }
>>                i++;
>>        }
>> +       kfree(prbuf_query);
>
> The above changes invoke memory allocation and deallocation. But the
> allocated buffer isn't used anywhere - neither in this patch nor in
> any later patch ???
>
> Bart.
>


nope, that was a vestige of code before rework to use kasprintf.
now excised.

thanks.

[PATCH 12/25] dynamic_debug: save non-matching queries to pending-list for later application.

[Jim Cromie]

When a query/rule doesnt match against current callsites, call
save_pending(new function) to copy the query off the stack, into
a (new) struct pending_query, and add to pending_queries (new) list.
Alter ddebug_change to return number of matches found for query/rule.

Patch adds: /sys/module/dynamic_debug/parameters/
  verbose - rw, added previously, here for completeness
  pending_ct - ro, shows current count of pending queries

With this and previous patches, queries submitted (on the boot-line
for example) which do not match (because module is not built-in,
and thus not present yet) are added to pending_queries.

Clear pending list in ddebug_remove_all_tables().  Note that latter is
currently only used for init-error path, its not called during cleanup.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |  108 +++++++++++++++++++++++++++++++++++++++++++++++---
 1 files changed, 101 insertions(+), 7 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 5774a6f..4135bf5 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -53,6 +53,16 @@ struct ddebug_query {
 	unsigned int first_lineno, last_lineno;
 };
 
+struct pending_query {
+	struct list_head link;
+	struct ddebug_query query;
+	char filename[100];
+	char module[30];
+	char function[50];
+	char format[200];
+	unsigned int flags, mask;
+};
+
 struct ddebug_iter {
 	struct ddebug_table *table;
 	unsigned int idx;
@@ -63,6 +73,11 @@ static LIST_HEAD(ddebug_tables);
 static int verbose = 0;
 module_param(verbose, int, 0644);
 
+/* legal but inapplicable queries, save and test against new modules */
+static LIST_HEAD(pending_queries);
+static int pending_ct;
+module_param(pending_ct, int, 0444);
+
 /* Return the last part of a pathname */
 static inline const char *basename(const char *path)
 {
@@ -111,14 +126,31 @@ static char *show_ddebug_query(const struct ddebug_query *q)
 	return p;
 }
 
+static char *show_pending_query(struct pending_query *pq)
+{
+	struct ddebug_query *q = &pq->query;
+
+	char *p = kasprintf(GFP_KERNEL,
+			"func=\"%s\" file=\"%s\" "
+			"module=\"%s\" format=\"%s\" lineno=%u-%u"
+			" flags=0x%x mask=0x%x",
+			q->function ? q->function : "",
+			q->filename ? q->filename : "",
+			q->module ? q->module : "",
+			q->format ? q->format : "",
+			q->first_lineno, q->last_lineno,
+			pq->flags, pq->mask);
+	return p;
+}
+
 /*
  * Search the tables for _ddebug's which match the given
  * `query' and apply the `flags' and `mask' to them.  Tells
  * the user which ddebug's were changed, or whether none
  * were matched.
  */
-static void ddebug_change(const struct ddebug_query *query,
-			   unsigned int flags, unsigned int mask)
+static int ddebug_change(const struct ddebug_query *query,
+			unsigned int flags, unsigned int mask)
 {
 	int i;
 	struct ddebug_table *dt;
@@ -181,8 +213,7 @@ static void ddebug_change(const struct ddebug_query *query,
 	}
 	mutex_unlock(&ddebug_lock);
 
-	if (!nfound)
-		pr_debug("no matches for query\n");
+	return nfound;
 }
 
 /*
@@ -421,13 +452,58 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 	return 0;
 }
 
+/* copy query off stack, save flags & mask, and store in pending-list */
+static int ddebug_save_pending(struct ddebug_query *query,
+				unsigned int flags, unsigned int mask)
+{
+	struct pending_query *pq;
+	char *qstr;
+
+	qstr = show_ddebug_query(query);
+	pr_debug("add to pending: %s\n", qstr);
+	kfree(qstr);
+
+	pq = kzalloc(sizeof(struct pending_query), GFP_KERNEL);
+	if (pq == NULL)
+		return -ENOMEM;
+
+	/* copy non-null match-specs into allocd mem, update pointers */
+	if (query->module) {
+		strlcpy(pq->module, query->module, sizeof(pq->module));
+		pq->query.module = pq->module;
+	}
+	if (query->function) {
+		strlcpy(pq->function, query->function, sizeof(pq->function));
+		pq->query.function = pq->function;
+	}
+	if (query->filename) {
+		strlcpy(pq->filename, query->filename, sizeof(pq->filename));
+		pq->query.filename = pq->filename;
+	}
+	if (query->format) {
+		strlcpy(pq->format, query->format, sizeof(pq->format));
+		pq->query.format = pq->format;
+	}
+	pq->flags = flags;
+	pq->mask = mask;
+
+	mutex_lock(&ddebug_lock);
+	list_add(&pq->link, &pending_queries);
+	pending_ct++;
+	mutex_unlock(&ddebug_lock);
+
+	pr_debug("query saved as pending %d\n", pending_ct);
+	return 0;
+}
+
 static int ddebug_exec_query(char *query_string)
 {
 	unsigned int flags = 0, mask = 0;
 	struct ddebug_query query;
 #define MAXWORDS 9
 	int nwords;
-	char *words[MAXWORDS];
+	char *words[MAXWORDS], *qstr;
+	int nfound, rc = 0;
 
 	nwords = ddebug_tokenize(query_string, words, MAXWORDS);
 	if (nwords <= 0)
@@ -438,8 +514,17 @@ static int ddebug_exec_query(char *query_string)
 		return -EINVAL;
 
 	/* actually go and implement the change */
-	ddebug_change(&query, flags, mask);
-	return 0;
+	nfound = ddebug_change(&query, flags, mask);
+	qstr = show_ddebug_query(&query);
+	pr_debug("nfound %d on %s\n", nfound, qstr);
+	if (!nfound) {
+		if (flags & _DPRINTK_FLAGS_APPEND)
+			rc = ddebug_save_pending(&query, flags, mask);
+		else
+			pr_warn("no match on: %s\n", qstr);
+	}
+	kfree(qstr);
+	return rc;
 }
 
 /* handle multiple queries, continue on error, return last error */
@@ -845,6 +930,8 @@ EXPORT_SYMBOL_GPL(ddebug_remove_module);
 
 static void ddebug_remove_all_tables(void)
 {
+	struct pending_query *pq, *pqnext;
+
 	mutex_lock(&ddebug_lock);
 	while (!list_empty(&ddebug_tables)) {
 		struct ddebug_table *dt = list_entry(ddebug_tables.next,
@@ -852,6 +939,13 @@ static void ddebug_remove_all_tables(void)
 						      link);
 		ddebug_table_free(dt);
 	}
+	list_for_each_entry_safe(pq, pqnext, &pending_queries, link) {
+		char *qstr = show_pending_query(pq);
+		pr_debug("delete pending: %s\n", qstr);
+		kfree(qstr);
+		list_del_init(&pq->link);
+		kfree(pq);
+	}
 	mutex_unlock(&ddebug_lock);
 }
 
-- 
1.7.4.1

[PATCH 13/25] dynamic_debug: apply_pending_queries() from ddebug_add_module()

[Jim Cromie]

When a module is loaded, ddebug_add_module calls apply_pending_queries
to scan pending_queries list and call ddebug_change to apply them.
Pending queries remain on the list after they're applied, so they
persist through modprobe-rmmod cycles during debugging.

With this change, the loaded module's pr_debugs are enabled when
its module_init is invoked, which is not possible otherwize.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   16 ++++++++++++++++
 1 files changed, 16 insertions(+), 0 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 4135bf5..7e4f919 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -866,6 +866,21 @@ static const struct file_operations ddebug_proc_fops = {
 	.write = ddebug_proc_write
 };
 
+/* apply matching queries in pending-queries list */
+static void apply_pending_queries(struct ddebug_table *dt)
+{
+	struct pending_query *pq, *pqnext;
+	int nfound;
+	char *qstr;
+
+	list_for_each_entry_safe(pq, pqnext, &pending_queries, link) {
+		nfound = ddebug_change(&pq->query, pq->flags, pq->mask);
+		qstr = show_pending_query(pq);
+		pr_debug("%s: %s\n", (nfound) ? "applied" : "no-match", qstr);
+		kfree(qstr);
+	}
+}
+
 /*
  * Allocate a new ddebug_table for the given module
  * and add it to the global list.
@@ -890,6 +905,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
 
 	mutex_lock(&ddebug_lock);
 	list_add_tail(&dt->link, &ddebug_tables);
+	apply_pending_queries(dt);
 	mutex_unlock(&ddebug_lock);
 
 	if (verbose)
-- 
1.7.4.1

[PATCH 14/25] dynamic_debug: refactor query_matches_callsite out of ddebug_change

[Jim Cromie]

This makes no behavioral change, its just a code-move.  Originally
done cuz it looked momentarily to be useful in the query-vs-query
check needed soon.

If this function is reused, note that it excludes check of the module;
that is done once for the table, this code refactors the test inside
the loop over the module's ddebug callsites.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   52 +++++++++++++++++++++++++++++---------------------
 1 files changed, 30 insertions(+), 22 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 7e4f919..c0a5d20 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -143,6 +143,35 @@ static char *show_pending_query(struct pending_query *pq)
 	return p;
 }
 
+static bool query_matches_callsite(struct _ddebug *dp,
+				const struct ddebug_query *query)
+{
+	/* match against the source filename */
+	if (query->filename != NULL &&
+		strcmp(query->filename, dp->filename) &&
+		strcmp(query->filename, basename(dp->filename)))
+		return false;
+
+	/* match against the function */
+	if (query->function != NULL &&
+		strcmp(query->function, dp->function))
+		return false;
+
+	/* match against the format */
+	if (query->format != NULL &&
+		strstr(dp->format, query->format) == NULL)
+		return false;
+
+	/* match against the line number range */
+	if (query->first_lineno && dp->lineno < query->first_lineno)
+		return false;
+
+	if (query->last_lineno && dp->lineno > query->last_lineno)
+		return false;
+
+	return true;
+}
+
 /*
  * Search the tables for _ddebug's which match the given
  * `query' and apply the `flags' and `mask' to them.  Tells
@@ -170,28 +199,7 @@ static int ddebug_change(const struct ddebug_query *query,
 		for (i = 0 ; i < dt->num_ddebugs ; i++) {
 			struct _ddebug *dp = &dt->ddebugs[i];
 
-			/* match against the source filename */
-			if (query->filename != NULL &&
-			    strcmp(query->filename, dp->filename) &&
-			    strcmp(query->filename, basename(dp->filename)))
-				continue;
-
-			/* match against the function */
-			if (query->function != NULL &&
-			    strcmp(query->function, dp->function))
-				continue;
-
-			/* match against the format */
-			if (query->format != NULL &&
-			    strstr(dp->format, query->format) == NULL)
-				continue;
-
-			/* match against the line number range */
-			if (query->first_lineno &&
-			    dp->lineno < query->first_lineno)
-				continue;
-			if (query->last_lineno &&
-			    dp->lineno > query->last_lineno)
+			if (!query_matches_callsite(dp, query))
 				continue;
 
 			nfound++;
-- 
1.7.4.1

[PATCH 15/25] dynamic_debug: remove explicit foo != NULL checks.

[Jim Cromie]

Reduce != NULL relational tests to their 0/1 equivalents.
Done separately to preserve code-move character of previous patch.
No generated code difference.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    8 +++-----
 1 files changed, 3 insertions(+), 5 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c0a5d20..0c25ba0 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -147,19 +147,17 @@ static bool query_matches_callsite(struct _ddebug *dp,
 				const struct ddebug_query *query)
 {
 	/* match against the source filename */
-	if (query->filename != NULL &&
+	if (query->filename &&
 		strcmp(query->filename, dp->filename) &&
 		strcmp(query->filename, basename(dp->filename)))
 		return false;
 
 	/* match against the function */
-	if (query->function != NULL &&
-		strcmp(query->function, dp->function))
+	if (query->function && strcmp(query->function, dp->function))
 		return false;
 
 	/* match against the format */
-	if (query->format != NULL &&
-		strstr(dp->format, query->format) == NULL)
+	if (query->format && !strstr(dp->format, query->format))
 		return false;
 
 	/* match against the line number range */
-- 
1.7.4.1

[PATCH 16/25] dynamic_debug: require 'a' flag to explicitly mark pending queries

[Jim Cromie]

Require that user mark pending queries explicitly, otherwise warn
that they do not apply.  Note that pending rules are still applied
by default, and are only added to pending-list if they do not apply,
and bear the flag.

Add queries_match() to test newly submitted pending query against
those already on the pending list, and either update the flags
or add the new query

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   42 ++++++++++++++++++++++++++++++++++++++++--
 1 files changed, 40 insertions(+), 2 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 0c25ba0..05773c8 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -91,6 +91,7 @@ static struct { unsigned flag:8; char opt_char; } opt_array[] = {
 	{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
 	{ _DPRINTK_FLAGS_INCL_LINENO, 'l' },
 	{ _DPRINTK_FLAGS_INCL_TID, 't' },
+	{ _DPRINTK_FLAGS_APPEND, 'a' },
 };
 
 /* format a string into buf[] which describes the _ddebug's flags */
@@ -458,13 +459,50 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 	return 0;
 }
 
-/* copy query off stack, save flags & mask, and store in pending-list */
+static bool queries_match(struct ddebug_query *q1, struct ddebug_query *q2)
+{
+	if (!q1->module ^ !q2->module ||
+		!q1->filename ^ !q2->filename ||
+		!q1->function ^ !q2->function ||
+		!q1->format ^ !q2->format)
+		return false;  /* a match-spec set/unset state differs */
+
+	if (q1->last_lineno != q2->last_lineno ||
+		q1->first_lineno != q2->first_lineno)
+		return false;
+
+	if ((q1->module && strcmp(q1->module, q2->module)) ||
+		(q1->filename && strcmp(q1->filename, q2->filename)) ||
+		(q1->function && strcmp(q1->function, q2->function)) ||
+		(q1->format && strcmp(q1->format, q2->format)))
+		return false;
+
+	return true;
+}
+
+/* copy query off stack, save flags & mask, and store or update in
+   pending-list.  Called with ddebug_lock held.
+ */
 static int ddebug_save_pending(struct ddebug_query *query,
 				unsigned int flags, unsigned int mask)
 {
-	struct pending_query *pq;
+	struct pending_query *pq, *pqnext;
 	char *qstr;
 
+	list_for_each_entry_safe(pq, pqnext, &pending_queries, link) {
+		if (queries_match(query, &pq->query)) {
+			/* query already in list, update flags */
+			if (pq->flags != flags)
+				pq->flags = flags;
+			if (pq->mask != mask)
+				pq->mask = mask;
+			qstr = show_pending_query(pq);
+			pr_debug("already pending, updated it: %s\n", qstr);
+			kfree(qstr);
+			return 0;
+		}
+	}
+
 	qstr = show_ddebug_query(query);
 	pr_debug("add to pending: %s\n", qstr);
 	kfree(qstr);
-- 
1.7.4.1

Re: [PATCH 16/25] dynamic_debug: require 'a' flag to explicitly mark pending queries

[Bart Van Assche]

On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> +       if (!q1->module ^ !q2->module ||
> +               !q1->filename ^ !q2->filename ||
> +               !q1->function ^ !q2->function ||
> +               !q1->format ^ !q2->format)
> +               return false;  /* a match-spec set/unset state differs */

I'd suggest to use "!=" here instead of "^" when testing booleans for
inequality. At least for me that would make the above code easier to
read.

Bart.

Re: [PATCH 16/25] dynamic_debug: require 'a' flag to explicitly mark pending queries

[Jim Cromie]

On Tue, Jul 26, 2011 at 1:26 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> +       if (!q1->module ^ !q2->module ||
>> +               !q1->filename ^ !q2->filename ||
>> +               !q1->function ^ !q2->function ||
>> +               !q1->format ^ !q2->format)
>> +               return false;  /* a match-spec set/unset state differs */
>
> I'd suggest to use "!=" here instead of "^" when testing booleans for
> inequality. At least for me that would make the above code easier to
> read.
>
> Bart.
>

yes. ^ is esoteric compared to !=
my github tree updated accordingly,
git://github.com/jimc/linux-2.6.git  dyndbg-next

[PATCH 17/25] dynamic_debug: hoist locking in ddebug_change to callers

[Jim Cromie]

Hoist locking out of ddebug_change() and ddebug_save_pending()
into ddebug_exec_query().

ddebug_add_module() also calls ddebug_change() via apply_pending_queries(),
move that call inside the critical section protecting list_add_tail()

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   11 ++++-------
 1 files changed, 4 insertions(+), 7 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 05773c8..396ffb4 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -175,7 +175,7 @@ static bool query_matches_callsite(struct _ddebug *dp,
  * Search the tables for _ddebug's which match the given
  * `query' and apply the `flags' and `mask' to them.  Tells
  * the user which ddebug's were changed, or whether none
- * were matched.
+ * were matched.  Called with ddebug_lock held.
  */
 static int ddebug_change(const struct ddebug_query *query,
 			unsigned int flags, unsigned int mask)
@@ -187,7 +187,6 @@ static int ddebug_change(const struct ddebug_query *query,
 	char flagbuf[8];
 
 	/* search for matching ddebugs */
-	mutex_lock(&ddebug_lock);
 	list_for_each_entry(dt, &ddebug_tables, link) {
 
 		/* match against the module name */
@@ -218,8 +217,6 @@ static int ddebug_change(const struct ddebug_query *query,
 						sizeof(flagbuf)));
 		}
 	}
-	mutex_unlock(&ddebug_lock);
-
 	return nfound;
 }
 
@@ -531,10 +528,8 @@ static int ddebug_save_pending(struct ddebug_query *query,
 	pq->flags = flags;
 	pq->mask = mask;
 
-	mutex_lock(&ddebug_lock);
 	list_add(&pq->link, &pending_queries);
 	pending_ct++;
-	mutex_unlock(&ddebug_lock);
 
 	pr_debug("query saved as pending %d\n", pending_ct);
 	return 0;
@@ -558,6 +553,7 @@ static int ddebug_exec_query(char *query_string)
 		return -EINVAL;
 
 	/* actually go and implement the change */
+	mutex_lock(&ddebug_lock);
 	nfound = ddebug_change(&query, flags, mask);
 	qstr = show_ddebug_query(&query);
 	pr_debug("nfound %d on %s\n", nfound, qstr);
@@ -568,6 +564,7 @@ static int ddebug_exec_query(char *query_string)
 			pr_warn("no match on: %s\n", qstr);
 	}
 	kfree(qstr);
+	mutex_unlock(&ddebug_lock);
 	return rc;
 }
 
@@ -910,7 +907,7 @@ static const struct file_operations ddebug_proc_fops = {
 	.write = ddebug_proc_write
 };
 
-/* apply matching queries in pending-queries list */
+/* apply matching queries in pending-queries list. Called with lock held */
 static void apply_pending_queries(struct ddebug_table *dt)
 {
 	struct pending_query *pq, *pqnext;
-- 
1.7.4.1

[PATCH 18/25] dynamic_debug: describe_flags with '=[pmflta_]*'

[Jim Cromie]

Change describe_flags() to emit '=[pmflta_]+' for current callsite
flags, or just '=_' when they're disabled.  Having '=' in output
allows a more selective grep expression, in contrast '-' may appear
in filenames, line-ranges, and format-strings.  '=' also has better
mnemonics, saying; "the current setting are equal to <flags>".

The default allows grep "=_" <dbgfs>/dynamic_debug/control
to see disabled callsites while avoiding the many occurrences of " = "
seen in format strings.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |    6 ++++--
 1 files changed, 4 insertions(+), 2 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 396ffb4..37f9748 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -92,6 +92,7 @@ static struct { unsigned flag:8; char opt_char; } opt_array[] = {
 	{ _DPRINTK_FLAGS_INCL_LINENO, 'l' },
 	{ _DPRINTK_FLAGS_INCL_TID, 't' },
 	{ _DPRINTK_FLAGS_APPEND, 'a' },
+	{ _DPRINTK_FLAGS_DEFAULT, '_' },
 };
 
 /* format a string into buf[] which describes the _ddebug's flags */
@@ -102,11 +103,12 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
 	int i;
 
 	BUG_ON(maxlen < 4);
+	*p++ = '=';
 	for (i = 0; i < ARRAY_SIZE(opt_array); ++i)
 		if (dp->flags & opt_array[i].flag)
 			*p++ = opt_array[i].opt_char;
-	if (p == buf)
-		*p++ = '-';
+	if (*(p-1) == '=')
+		*p++ = '_';
 	*p = '\0';
 
 	return buf;
-- 
1.7.4.1

Re: [PATCH 18/25] dynamic_debug: describe_flags with '=[pmflta_]*'

[Bart Van Assche]

On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> Change describe_flags() to emit '=[pmflta_]+' for current callsite
> flags, or just '=_' when they're disabled.  Having '=' in output
> allows a more selective grep expression, in contrast '-' may appear
> in filenames, line-ranges, and format-strings.  '=' also has better
> mnemonics, saying; "the current setting are equal to <flags>".
>
> The default allows grep "=_" <dbgfs>/dynamic_debug/control
> to see disabled callsites while avoiding the many occurrences of " = "
> seen in format strings.
>
> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
> ---
>  lib/dynamic_debug.c |    6 ++++--
>  1 files changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index 396ffb4..37f9748 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -92,6 +92,7 @@ static struct { unsigned flag:8; char opt_char; } opt_array[] = {
>        { _DPRINTK_FLAGS_INCL_LINENO, 'l' },
>        { _DPRINTK_FLAGS_INCL_TID, 't' },
>        { _DPRINTK_FLAGS_APPEND, 'a' },
> +       { _DPRINTK_FLAGS_DEFAULT, '_' },
>  };
>
>  /* format a string into buf[] which describes the _ddebug's flags */
> @@ -102,11 +103,12 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
>        int i;
>
>        BUG_ON(maxlen < 4);
> +       *p++ = '=';
>        for (i = 0; i < ARRAY_SIZE(opt_array); ++i)
>                if (dp->flags & opt_array[i].flag)
>                        *p++ = opt_array[i].opt_char;
> -       if (p == buf)
> -               *p++ = '-';
> +       if (*(p-1) == '=')
> +               *p++ = '_';
>        *p = '\0';
>
>        return buf;

The "BUG_ON(maxlen < 4)" tests whether a buffer overflow can occur
before starting to write in the buffer. Since the above code affects
the number of characters that can be written in the output buffer,
shouldn't that statement be updated or replaced ?

Bart.

Re: [PATCH 18/25] dynamic_debug: describe_flags with '=[pmflta_]*'

[Jim Cromie]

On Tue, Jul 26, 2011 at 1:37 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> Change describe_flags() to emit '=[pmflta_]+' for current callsite
>> flags, or just '=_' when they're disabled.  Having '=' in output
>> allows a more selective grep expression, in contrast '-' may appear
>> in filenames, line-ranges, and format-strings.  '=' also has better
>> mnemonics, saying; "the current setting are equal to <flags>".
>>
>> The default allows grep "=_" <dbgfs>/dynamic_debug/control
>> to see disabled callsites while avoiding the many occurrences of " = "
>> seen in format strings.
>>
>> Signed-off-by: Jim Cromie <jim.cromie@gmail.com>

>> @@ -102,11 +103,12 @@ static char *ddebug_describe_flags(struct _ddebug *dp, char *buf,
>>        int i;
>>
>>        BUG_ON(maxlen < 4);
>> +       *p++ = '=';
>>        for (i = 0; i < ARRAY_SIZE(opt_array); ++i)

>
> The "BUG_ON(maxlen < 4)" tests whether a buffer overflow can occur
> before starting to write in the buffer. Since the above code affects
> the number of characters that can be written in the output buffer,
> shouldn't that statement be updated or replaced ?
>
> Bart.
>

Ack.
Ive just enlarged buffer and check to 10.
strictly, only 9 is needed, but Im feeling generous.

thanks for the close reading.

updated git://github.com/jimc/linux-2.6.git  dyndbg-next

[PATCH 19/25] dynamic_debug: add flags filtering to flags spec

[Jim Cromie]

Change definition of flags spec to [pmflta_]*[-+=][pmflta_]*
The flags preceding the op are optional filter-flags; if provided,
they add an additional constraint to call-site matching done
by ddebug_change; call-sites which do not have all specified flags
are skipped (additional flags are allowed).

This allows query/rules like "p+t" to turn on TID logging for all
currently enabled call-sites, while leaving the others alone.
This will also allow filtering on pending rules (with 'a' flag),
which will support removal of pending rules.

Also allow 0 flags byte, so that active rules can be completely
reset by writing "p=" or "p=_".

Patch factors flag-scanning into ddebug_parse_flag_settings(),
and uses it for both filter-flags and new flags, and adds pr_err()
where useful.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   81 ++++++++++++++++++++++++++++++++-------------------
 1 files changed, 51 insertions(+), 30 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 37f9748..275cf30 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -180,7 +180,8 @@ static bool query_matches_callsite(struct _ddebug *dp,
  * were matched.  Called with ddebug_lock held.
  */
 static int ddebug_change(const struct ddebug_query *query,
-			unsigned int flags, unsigned int mask)
+			unsigned int flags, unsigned int mask,
+			unsigned int filter)
 {
 	int i;
 	struct ddebug_table *dt;
@@ -202,6 +203,9 @@ static int ddebug_change(const struct ddebug_query *query,
 			if (!query_matches_callsite(dp, query))
 				continue;
 
+			if (filter && (dp->flags & filter) != filter)
+				continue;
+
 			nfound++;
 
 			newflags = (dp->flags & mask) | flags;
@@ -402,28 +406,9 @@ static int ddebug_parse_query(char *words[], int nwords,
 	return 0;
 }
 
-/*
- * Parse `str' as a flags specification, format [-+=][p]+.
- * Sets up *maskp and *flagsp to be used when changing the
- * 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_flag_settings(const char *str)
 {
-	unsigned flags = 0;
-	int op = '=', i;
-
-	switch (*str) {
-	case '+':
-	case '-':
-	case '=':
-		op = *str++;
-		break;
-	default:
-		return -EINVAL;
-	}
-	pr_debug("op='%c'\n", op);
+	int i, flags = 0;
 
 	for ( ; *str ; ++str) {
 		for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
@@ -432,12 +417,46 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 				break;
 			}
 		}
-		if (i < 0)
+		if (i < 0 && *str) {
+			pr_err("unknown flag: %c\n", *str);
 			return -EINVAL;
+		}
 	}
-	if (flags == 0)
+	return flags;
+}
+
+/*
+ * Parse `str' as a flags filter and specification, with format
+ * [ptlmfa]*[-+=][ptlmfa]+.  Sets up *maskp, *flagsp and *filterp to
+ * be used when changing the 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, unsigned int *filterp)
+{
+	int flags, filter;
+	int op = '=';
+	char *s = strpbrk(str, "+-=");
+
+	if (!s) {
+		pr_err("flags spec missing op, expecting [+-=]\n");
 		return -EINVAL;
-	pr_debug("flags=0x%x\n", flags);
+	} else {
+		op = *s;
+		*s++ = '\0';
+	}
+	filter = ddebug_parse_flag_settings(str);
+	if (filter < 0) {
+		pr_err("flags_filter=0x%x\n", filter);
+		return -EINVAL;
+	}
+	*filterp = filter;
+
+	flags = ddebug_parse_flag_settings(s);
+	if (flags < 0) {
+		pr_err("flags=0x%x\n", flags);
+		return -EINVAL;
+	}
 
 	/* calculate final *flagsp, *maskp according to mask and op */
 	switch (op) {
@@ -454,7 +473,9 @@ static int ddebug_parse_flags(const char *str, unsigned int *flagsp,
 		*flagsp = 0;
 		break;
 	}
-	pr_debug("*flagsp=0x%x *maskp=0x%x\n", *flagsp, *maskp);
+	pr_debug("filter=0x%x op='%c' flags=0x%x *flagsp=0x%x *maskp=0x%x\n",
+		filter, op, flags, *flagsp, *maskp);
+
 	return 0;
 }
 
@@ -539,7 +560,7 @@ static int ddebug_save_pending(struct ddebug_query *query,
 
 static int ddebug_exec_query(char *query_string)
 {
-	unsigned int flags = 0, mask = 0;
+	unsigned int flags = 0, mask = 0, filter = 0;
 	struct ddebug_query query;
 #define MAXWORDS 9
 	int nwords;
@@ -551,12 +572,12 @@ static int ddebug_exec_query(char *query_string)
 		return -EINVAL;
 	if (ddebug_parse_query(words, nwords-1, &query))
 		return -EINVAL;
-	if (ddebug_parse_flags(words[nwords-1], &flags, &mask))
+	if (ddebug_parse_flags(words[nwords-1], &flags, &mask, &filter))
 		return -EINVAL;
 
 	/* actually go and implement the change */
 	mutex_lock(&ddebug_lock);
-	nfound = ddebug_change(&query, flags, mask);
+	nfound = ddebug_change(&query, flags, mask, filter);
 	qstr = show_ddebug_query(&query);
 	pr_debug("nfound %d on %s\n", nfound, qstr);
 	if (!nfound) {
@@ -917,7 +938,7 @@ static void apply_pending_queries(struct ddebug_table *dt)
 	char *qstr;
 
 	list_for_each_entry_safe(pq, pqnext, &pending_queries, link) {
-		nfound = ddebug_change(&pq->query, pq->flags, pq->mask);
+		nfound = ddebug_change(&pq->query, pq->flags, pq->mask, 0);
 		qstr = show_pending_query(pq);
 		pr_debug("%s: %s\n", (nfound) ? "applied" : "no-match", qstr);
 		kfree(qstr);
-- 
1.7.4.1

[PATCH 20/25] dynamic_debug: remove pending query when flags zeroed

[Jim Cromie]

When a pending-query is resubmitted with zeroed flags, remove it
from pending-queries list.  The submission must have identical
match-specs, and like the original query, must have 'a' in the
filter-flags.  If other filter-flags are given, they must match
the query to be removed, but filter can be underspecified; "p"
will match against "pt".

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   15 +++++++++++++--
 1 files changed, 13 insertions(+), 2 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 275cf30..8f56092 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -511,7 +511,17 @@ static int ddebug_save_pending(struct ddebug_query *query,
 
 	list_for_each_entry_safe(pq, pqnext, &pending_queries, link) {
 		if (queries_match(query, &pq->query)) {
-			/* query already in list, update flags */
+			/* query already in list */
+			if (!flags) {
+				/* zeroed flags, remove query */
+				qstr = show_pending_query(pq);
+				pr_debug("delete pending: %s\n", qstr);
+				kfree(qstr);
+				list_del_init(&pq->link);
+				kfree(pq);
+				pending_ct--;
+				return 0;
+			}
 			if (pq->flags != flags)
 				pq->flags = flags;
 			if (pq->mask != mask)
@@ -581,7 +591,8 @@ static int ddebug_exec_query(char *query_string)
 	qstr = show_ddebug_query(&query);
 	pr_debug("nfound %d on %s\n", nfound, qstr);
 	if (!nfound) {
-		if (flags & _DPRINTK_FLAGS_APPEND)
+		if (flags & _DPRINTK_FLAGS_APPEND ||
+			filter & _DPRINTK_FLAGS_APPEND)
 			rc = ddebug_save_pending(&query, flags, mask);
 		else
 			pr_warn("no match on: %s\n", qstr);
-- 
1.7.4.1

[PATCH 21/25] dynamic_debug: shrink struct pending query to size actually needed

[Jim Cromie]

Remove struct pending_query's fixed sized char arrays; function,
filename, module, format, and replace them with a 0-sized charbuf.
Before the struct is allocd, determine the size needed to store
the 4 strings into the charbuf.  Then copy the strings off the stack,
and update the field ptrs in the embedded struct ddebug_query to point
into the charbuf.  This change uses strcpy instead of strlcpy, since
we know that the charbuf is big enough to hold the 4 strings.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   37 ++++++++++++++++++++++---------------
 1 files changed, 22 insertions(+), 15 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 8f56092..5ec8165 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -56,11 +56,8 @@ struct ddebug_query {
 struct pending_query {
 	struct list_head link;
 	struct ddebug_query query;
-	char filename[100];
-	char module[30];
-	char function[50];
-	char format[200];
 	unsigned int flags, mask;
+	char buf[0];
 };
 
 struct ddebug_iter {
@@ -507,7 +504,8 @@ static int ddebug_save_pending(struct ddebug_query *query,
 				unsigned int flags, unsigned int mask)
 {
 	struct pending_query *pq, *pqnext;
-	char *qstr;
+	char *qstr, *bp;
+	size_t buflen;
 
 	list_for_each_entry_safe(pq, pqnext, &pending_queries, link) {
 		if (queries_match(query, &pq->query)) {
@@ -537,26 +535,33 @@ static int ddebug_save_pending(struct ddebug_query *query,
 	pr_debug("add to pending: %s\n", qstr);
 	kfree(qstr);
 
-	pq = kzalloc(sizeof(struct pending_query), GFP_KERNEL);
+	buflen = (query->module ? strlen(query->module) : 0)
+		+ (query->function ? strlen(query->function) : 0)
+		+ (query->filename ? strlen(query->filename) : 0)
+		+ (query->format ? strlen(query->format) : 0)
+		+ 4; /* for \0's */
+
+	pq = kzalloc(sizeof(struct pending_query) + buflen, GFP_KERNEL);
 	if (pq == NULL)
 		return -ENOMEM;
 
 	/* copy non-null match-specs into allocd mem, update pointers */
+	bp = pq->buf;
 	if (query->module) {
-		strlcpy(pq->module, query->module, sizeof(pq->module));
-		pq->query.module = pq->module;
+		pq->query.module = strcpy(bp, query->module);
+		bp += strlen(bp) + 1;
 	}
 	if (query->function) {
-		strlcpy(pq->function, query->function, sizeof(pq->function));
-		pq->query.function = pq->function;
+		pq->query.function = strcpy(bp, query->function);
+		bp += strlen(bp) + 1;
 	}
 	if (query->filename) {
-		strlcpy(pq->filename, query->filename, sizeof(pq->filename));
-		pq->query.filename = pq->filename;
+		pq->query.filename = strcpy(bp, query->filename);
+		bp += strlen(bp) + 1;
 	}
 	if (query->format) {
-		strlcpy(pq->format, query->format, sizeof(pq->format));
-		pq->query.format = pq->format;
+		pq->query.format = strcpy(bp, query->format);
+		bp += strlen(bp) + 1;
 	}
 	pq->flags = flags;
 	pq->mask = mask;
@@ -564,7 +569,9 @@ static int ddebug_save_pending(struct ddebug_query *query,
 	list_add(&pq->link, &pending_queries);
 	pending_ct++;
 
-	pr_debug("query saved as pending %d\n", pending_ct);
+	pr_debug("query saved as pending %d, in %d+%d bytes\n",
+		pending_ct, sizeof(struct pending_query), buflen);
+
 	return 0;
 }
 
-- 
1.7.4.1

Re: [PATCH 21/25] dynamic_debug: shrink struct pending query to size actually needed

[Bart Van Assche]

On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
> -       pr_debug("query saved as pending %d\n", pending_ct);
> +       pr_debug("query saved as pending %d, in %d+%d bytes\n",
> +               pending_ct, sizeof(struct pending_query), buflen);

The proper format specifier for size_t is %zd, not %d. Does this mean
that this code has not yet been compiled on a 64-bit system ?

Bart.

Re: [PATCH 21/25] dynamic_debug: shrink struct pending query to size actually needed

[Jim Cromie]

On Tue, Jul 26, 2011 at 1:32 AM, Bart Van Assche <bvanassche@acm.org> wrote:
> On Mon, Jul 25, 2011 at 11:42 PM, Jim Cromie <jim.cromie@gmail.com> wrote:
>> -       pr_debug("query saved as pending %d\n", pending_ct);
>> +       pr_debug("query saved as pending %d, in %d+%d bytes\n",
>> +               pending_ct, sizeof(struct pending_query), buflen);
>
> The proper format specifier for size_t is %zd, not %d. Does this mean
> that this code has not yet been compiled on a 64-bit system ?
>
> Bart.
>

this patch hadnt been compiled on 64,
it has been now, and updated to my github repo,
not resending it or others now, awaiting further comments.

[PATCH 22/25] dynamic_debug: call ddebug_add_module() on dynamic_debug first.

[Jim Cromie]

In dynamic_debug_init(), find the dynamic-debug entries in the debug
section, and call ddebug_add_module on those entries 1st, before
doing all the others.  Doing this activates debug callsites in
dynamic_debug before the functions they're part of are used to
process other modules, making them useful for debugging debug
queries on those modules.  Without this, the debuggability of
queries depends upon whether the module is before or after
dynamic-debug in the __verbose data, ie link order.

Finding the dynamic-debug entries effectively splits the __verbose
data in 2; 1st we mark the found spot and process mark to end
(which starts with dynamic-debug entries), then process start to mark.
Refactor the block-finding code into dynamic_debug_init_helper(),
then call it on the 2 halves of the __verbose data.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |   53 ++++++++++++++++++++++++++++++++++++--------------
 1 files changed, 38 insertions(+), 15 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 5ec8165..6dbefb7 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1068,29 +1068,52 @@ static int __init dynamic_debug_init_debugfs(void)
 	return 0;
 }
 
+static int __init dynamic_debug_init_helper(struct _ddebug *start,
+					struct _ddebug *end)
+{
+	struct _ddebug *iter, *block;
+	const char *modname = start->modname;
+	int ret, n = 0;
+
+	for (block = iter = start; iter < end; iter++) {
+		if (strcmp(modname, iter->modname)) {
+			ret = ddebug_add_module(block, n, modname);
+			if (ret)
+				return ret;
+			n = 0;
+			modname = iter->modname;
+			block = iter;
+		}
+		n++;
+	}
+	return ddebug_add_module(block, n, modname);
+}
+
 static int __init dynamic_debug_init(void)
 {
-	struct _ddebug *iter, *iter_start;
+	struct _ddebug *iter;
 	const char *modname = NULL;
 	int ret = 0;
-	int n = 0;
 
 	if (__start___verbose != __stop___verbose) {
+		/* find and process dynamic_debug entries 1st
+		   this might allow activating ddebug_add_module callsites
+		   prior to their use processing other modules. TBI
+		*/
 		iter = __start___verbose;
 		modname = iter->modname;
-		iter_start = iter;
-		for (; iter < __stop___verbose; iter++) {
-			if (strcmp(modname, iter->modname)) {
-				ret = ddebug_add_module(iter_start, n, modname);
-				if (ret)
-					goto out_free;
-				n = 0;
-				modname = iter->modname;
-				iter_start = iter;
-			}
-			n++;
-		}
-		ret = ddebug_add_module(iter_start, n, modname);
+
+		for (; iter < __stop___verbose; iter++)
+			if (!strcmp("dynamic_debug", iter->modname))
+				break;
+
+		ret = dynamic_debug_init_helper(iter, __stop___verbose);
+		if (ret)
+			goto out_free;
+
+		ret = dynamic_debug_init_helper(__start___verbose, iter);
+		if (ret)
+			goto out_free;
 	}
 
 	/* ddebug_query boot param got passed -> set it up */
-- 
1.7.4.1

[PATCH 23/25] dynamic_debug: document pending queries, flags-filter, multiple queries

[Jim Cromie]

Add section on pending-queries.  Rework flags description to include
flags-filter, rearrange docs into 3 parts for the 3 components of
the flags-spec.  Reflow some paragraphs.

Add example of a command-file which enables dynamic-debugging on
the dynamic debugging facility itself.  Example also shows commenting,
describes constraints.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 Documentation/dynamic-debug-howto.txt |  221 ++++++++++++++++++++++-----------
 1 files changed, 147 insertions(+), 74 deletions(-)

diff --git a/Documentation/dynamic-debug-howto.txt b/Documentation/dynamic-debug-howto.txt
index f959909..c1a4f42 100644
--- a/Documentation/dynamic-debug-howto.txt
+++ b/Documentation/dynamic-debug-howto.txt
@@ -4,15 +4,15 @@ Introduction
 
 This document describes how to use the dynamic debug (ddebug) 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.
+Dynamic debug is designed to allow you to dynamically enable/disable
+kernel code to obtain additional kernel information.  If kernel is
+built with CONFIG_DYNAMIC_DEBUG=y, then all pr_debug()/dev_dbg() calls
+can be dynamically enabled per-callsite.
 
 Dynamic debug has even more useful features:
 
- * Simple query language allows turning on and off debugging statements by
-   matching any combination of:
+ * Simple query language allows turning on and off debugging
+   statements by matching any combination of:
 
    - source filename
    - function name
@@ -20,25 +20,32 @@ Dynamic debug has even more useful features:
    - module name
    - format string
 
- * 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
+ * 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()s 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:
+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.
 
-nullarbor:~ # echo 'file svcsock.c line 1603 +p' >
-				<debugfs>/dynamic_debug/control
+# a simple helper shell-function, to shorten examples
+function dbg_query() {
+	 echo "$*" > $DEBUGFS/dynamic_debug/control
+}
+
+For example, if you want to enable
+printing from source file 'svcsock.c', line 1603 you simply do:
+
+nullarbor:~ # dbg_query file svcsock.c line 1603 +p
 
 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
+nullarbor:~ # dbg_query 'file svcsock.c wtf 1 +p'
 -bash: echo: write error: Invalid argument
 
 Viewing Dynamic Debug Behaviour
@@ -47,32 +54,33 @@ Viewing Dynamic Debug Behaviour
 You can view the currently configured behaviour of all the debug statements
 via:
 
-nullarbor:~ # cat <debugfs>/dynamic_debug/control
+nullarbor:~ # cat $DEBUGFS/dynamic_debug/control
 # filename:lineno [module]function flags format
-/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:323 [svcxprt_rdma]svc_rdma_cleanup - "SVCRDMA Module Removed, deregister RPC RDMA transport\012"
-/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init - "\011max_inline       : %d\012"
-/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init - "\011sq_depth         : %d\012"
-/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init - "\011max_requests     : %d\012"
+/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:323 [svcxprt_rdma]svc_rdma_cleanup =_ "SVCRDMA Module Removed, deregister RPC RDMA transport\012"
+/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:341 [svcxprt_rdma]svc_rdma_init =_ "\011max_inline       : %d\012"
+/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:340 [svcxprt_rdma]svc_rdma_init =_ "\011sq_depth         : %d\012"
+/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svc_rdma.c:338 [svcxprt_rdma]svc_rdma_init =_ "\011max_requests     : %d\012"
 ...
 
 
 You can also apply standard Unix text manipulation filters to this
 data, e.g.
 
-nullarbor:~ # grep -i rdma <debugfs>/dynamic_debug/control  | wc -l
+nullarbor:~ # grep -i rdma $DEBUGFS/dynamic_debug/control  | wc -l
 62
 
-nullarbor:~ # grep -i tcp <debugfs>/dynamic_debug/control | wc -l
+nullarbor:~ # grep -i tcp $DEBUGFS/dynamic_debug/control | wc -l
 42
 
-Note in particular that the third column shows the enabled behaviour
-flags for each debug statement callsite (see below for definitions of the
-flags).  The default value, no extra behaviour enabled, is "-".  So
-you can view all the debug statement callsites with any non-default flags:
+The third column shows the current flag settings for each debug
+statement callsite (menmonic: what they equal to, see below for
+definitions of the flags).  The default value, no extra behaviour
+enabled, is "=_".  So you can view all the debug statement callsites
+with any non-default flags:
 
-nullarbor:~ # awk '$3 != "-"' <debugfs>/dynamic_debug/control
+nullarbor:~ # grep -v "=_" $DEBUGFS/dynamic_debug/control
 # filename:lineno [module]function flags format
-/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c:1603 [sunrpc]svc_send p "svc_process: st_sendto returned %d\012"
+/usr/src/packages/BUILD/sgi-enhancednfs-1.4/default/net/sunrpc/svcsock.c:1603 [sunrpc]svc_send =p "svc_process: st_sendto returned %d\012"
 
 
 Command Language Reference
@@ -84,16 +92,31 @@ separators and do *not* end a command or allow multiple commands to
 be done together.  So these are all equivalent:
 
 nullarbor:~ # echo -c 'file svcsock.c line 1603 +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 nullarbor:~ # echo -c '  file   svcsock.c     line  1603 +p  ' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 nullarbor:~ # echo -c 'file svcsock.c\nline 1603 +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
+
+Commands are bounded by a write() system call.  Subject to this limit
+(or 1024 for boot-line parameter) you can send multiple commands,
+separated by ';' or '\n'
+
+foo:~ # echo "module nsc_gpio +p ; module pc8736x_gpio +p ; " \
+      > $DEBUGFS/dynamic_debug/control
 
-Commands are bounded by a write() system call.  If you want to do
-multiple commands you need to do a separate "echo" for each, like:
+foo:~ # cat queries
+  module nsc_gpio +p ;
+  module pc8736x_gpio +p
+foo:~ # cat queries > $DEBUGFS/dynamic_debug/control
+
+Multiple commands are processed independently, this allows you to send
+commands which may fail, for example if a module is not present.  The
+last failing command returns its error.
+
+Or you can do an "echo" for each, like:
 
 nullarbor:~ # echo 'file svcsock.c line 1603 +p' > /proc/dprintk ;\
 > echo 'file svcsock.c line 1563 +p' > /proc/dprintk
@@ -110,11 +133,12 @@ specifications, followed by a flags change specification.
 
 command ::= match-spec* flags-spec
 
-The match-spec's are used to choose a subset of the known dprintk()
+The match-specs are used to choose a subset of the known dprintk()
 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 is possible, but is not very useful because it will not
-match any debug statement callsites.
+with implicit ANDs between each pair.  This means that multiple specs
+of a given type are nonsense; a module cannot match A and B
+simultaneously.  Note that an empty list of match-specs matches all
+callsites.
 
 A match specification comprises a keyword, which controls the attribute
 of the callsite to be compared, and a value to compare against.  Possible
@@ -125,6 +149,7 @@ match-spec ::= 'func' string |
 	       'module' string |
 	       'format' string |
 	       'line' line-range
+Note: no wildcards or regexs are accepted
 
 line-range ::= lineno |
 	       '-'lineno |
@@ -190,36 +215,55 @@ line
     line -1605	    // the 1605 lines from line 1 to line 1605
     line 1600-	    // all lines from line 1600 to the end of the file
 
-The flags specification comprises a change operation followed
-by one or more flag characters.  The change operation is one
-of the characters:
-
--
-    remove the given flags
+The flags specification matches the regexp: ^[flmpta_]*[-+=][flmpta_]*$
+and has 3 parts:
 
-+
-    add the given flags
+flags filter (optional):
+    Constrains matching to thoses callsite with given flags set,
+    allows altering currently enabled callsites.
+      #> dbg_query pm+t		# add t to enabled sites which have m
+      #> dbg_query p+t		# add t to all enabled sites, both m and !m
+      #> dbg_query tmf-p	# disable sites with 'tmf'
+      #> dbg_query tmf+p	# re-enable those disabled sites
 
-=
-    set the flags to the given flags
+flags change operation:
+    '-' remove the given flags
+    '+' add the given flags
+    '=' set the flags to the given flags
 
 The flags are:
-
-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
-p
-    Causes a printk() message to be emitted to dmesg
-t
-    Include thread ID in messages not generated from interrupt context
-
-Note the regexp ^[-+=][flmpt]+$ matches a flags specification.
-Note also that there is no convenient syntax to remove all
-the flags at once, you need to use "-flmpt".
-
+  '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
+  'p'  Causes a printk() message to be emitted to dmesg
+  't'  Include thread ID in messages not generated from interrupt context
+  'a'  Add query to pending queries if not directly applicable
+  '_'  default/null flag.
+       Primarily for display, so grep "=_" can avoid " = " in format strings.
+       Also usable (but not required) to clear all flags.
+
+Pending queries
+===============
+
+Queries submitted with 'a' are added to a pending list IFF they don't
+match against current callsites.  This allows you to add queries for
+modules before they're loaded, which enables pr_debug()s used in
+initialization.  To better support module debugging, pending queries
+remain on the list through modprobe-rmmod cycles.  To remove a pending query, resubmit it with zeroed flags:
+
+#> dbg_query module foo +apt	# original pending query
+#> dbg_query module foo a=	# zero pending query to remove
+#> dbg_query module foo a-a	# also zeros, removes
+#> dbg_query module foo a-ap	# zeros already 0-flag, removes
+
+There are a few subtleties; removing or altering a pending query
+requires an exact match on the query-spec, but not on the flags
+filter.  So 2nd query does not clear 1st.
+
+#> dbg_query module foo line 100-200 +ap
+#> dbg_query module foo ap=
+
+TBR. some issues remain..
 
 Debug messages during boot process
 ==================================
@@ -232,37 +276,66 @@ QUERY follows the syntax described above, but must not exceed 1023
 characters. The enablement of debug messages is done as an arch_initcall.
 Thus you can enable debug messages in all code processed after this
 arch_initcall via this boot parameter.
-On an x86 system for example ACPI enablement is a subsys_initcall and
-ddebug_query="file ec.c +p"
+
+On an x86 system for example ACPI enablement is a subsys_initcall, so
+  ddebug_query="file ec.c +p"
 will show early Embedded Controller transactions during ACPI setup if
 your machine (typically a laptop) has an Embedded Controller.
 PCI (or other devices) initialization also is a hot candidate for using
 this boot parameter for debugging purposes.
 
-
 Examples
 ========
 
 // enable the message at line 1603 of file svcsock.c
 nullarbor:~ # echo -n 'file svcsock.c line 1603 +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 
 // enable all the messages in file svcsock.c
 nullarbor:~ # echo -n 'file svcsock.c +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 
 // enable all the messages in the NFS server module
 nullarbor:~ # echo -n 'module nfsd +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 
 // enable all 12 messages in the function svc_process()
 nullarbor:~ # echo -n 'func svc_process +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 
 // disable all 12 messages in the function svc_process()
 nullarbor:~ # echo -n 'func svc_process -p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
 
 // enable messages for NFS calls READ, READLINK, READDIR and READDIR+.
 nullarbor:~ # echo -n 'format "nfsd: READ" +p' >
-				<debugfs>/dynamic_debug/control
+				$DEBUGFS/dynamic_debug/control
+
+// enable dynamic-debugging on dynamic-debugging facility
+root@voyage:~# cat debugfs-file
+
+  # blank lines ok
+  module dynamic_debug +p		; # turn on self-debugging
+  # these are quite noisy when grepping
+  # $DEBUGFS/dynamic_debug/{control,pending}
+    # silence them (also, leading spaces allowed in comments)
+  func ddebug_proc_show -p
+  func ddebug_proc_next -p	; # trailing comments need cmd terminator
+  func pending_proc_show -p
+  func pending_proc_next -p
+
+root@voyage:~# cat debugfs-file > /dbg/dynamic_debug/control
+split into words: "module" "dynamic_debug" "+p"
+changed $srcroot/lib/dynamic_debug.c:223 [dynamic_debug]ddebug_change =p
+changed $srcroot/lib/dynamic_debug.c:576 [dynamic_debug]ddebug_save_pending =p
+....
+nfound 23 on func="" file="" module="dynamic_debug" format="" lineno=0-0
+query 1: "func ddebug_proc_show -p	"
+split into words: "func" "ddebug_proc_show" "-p"
+parsed func="ddebug_proc_show" file="" module="" format="" lineno=0-0
+filter=0x0 op='-' flags=0x1 *flagsp=0x0 *maskp=0xfffffffe
+changed $srcroot/lib/dynamic_debug.c:881 [dynamic_debug]ddebug_proc_show =_
+nfound 1 on func="ddebug_proc_show" file="" module="" format="" lineno=0-0
+query 2: "func ddebug_proc_next -p"
+...
+
-- 
1.7.4.1

[PATCH 24/25] dynamic_debug: drop pr_fmt() from dynamic_pr_debug

[Jim Cromie]

dynamic_pr_debug can add module, function, file, and line selectively,
theres no need to also add them via macro.  Moreover, adding them
via the macro, which is useful for pr_info and friends, causes
pr_debug to double-print those fields added by the flag-settings.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 include/linux/dynamic_debug.h |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 8f46a5d..6fd10ab 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -65,7 +65,7 @@ extern int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 #define dynamic_pr_debug(fmt, ...) do {					\
 	DYNAMIC_DEBUG_METADATA(fmt);					\
 	if (unlikely(descriptor.enabled))				\
-		__dynamic_pr_debug(&descriptor, pr_fmt(fmt), ##__VA_ARGS__);\
+		__dynamic_pr_debug(&descriptor, fmt, ##__VA_ARGS__);	\
 	} while (0)
 
 #define dynamic_dev_dbg(dev, fmt, ...) do {				\
-- 
1.7.4.1

Re: [PATCH 24/25] dynamic_debug: drop pr_fmt() from dynamic_pr_debug

[Joe Perches]

On Mon, 2011-07-25 at 15:42 -0600, Jim Cromie wrote:
> dynamic_pr_debug can add module, function, file, and line selectively,
> theres no need to also add them via macro.  Moreover, adding them
> via the macro, which is useful for pr_info and friends, causes
> pr_debug to double-print those fields added by the flag-settings.
[]
> diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
[]
> @@ -65,7 +65,7 @@ extern int __dynamic_netdev_dbg(struct _ddebug *descriptor,
>  #define dynamic_pr_debug(fmt, ...) do {					\
>  	DYNAMIC_DEBUG_METADATA(fmt);					\
>  	if (unlikely(descriptor.enabled))				\
> -		__dynamic_pr_debug(&descriptor, pr_fmt(fmt), ##__VA_ARGS__);\
> +		__dynamic_pr_debug(&descriptor, fmt, ##__VA_ARGS__);	\

For me, NAK.

I think this isn't a good idea for now.
Maybe in a year or two after all the #define pr_fmt(foo)
are sorted out better.

This is a #define, that is used by all uses of pr_fmt/pr_debug.

This will have problems with uses of pr_fmt that are not
using KBUILD_MODNAME like all uses of:

#define pr_fmt(fmt) KMSG_COMPONENT ": " fmt

and those that use a specific fixed  string like:

#define pr_fmt(fmt) "foo: " fmt

Re: [PATCH 24/25] dynamic_debug: drop pr_fmt() from dynamic_pr_debug

[Joe Perches]

On Mon, 2011-07-25 at 15:42 -0600, Jim Cromie wrote:
> dynamic_pr_debug can add module, function, file, and line selectively,
> theres no need to also add them via macro.  Moreover, adding them
> via the macro, which is useful for pr_info and friends, causes
> pr_debug to double-print those fields added by the flag-settings.
[]
> -		__dynamic_pr_debug(&descriptor, pr_fmt(fmt), ##__VA_ARGS__);\
> +		__dynamic_pr_debug(&descriptor, fmt, ##__VA_ARGS__);	\

Hey Jim.

Thinking about a bit more, maybe it's possible to use
another test to see if the current pr_fmt is:

#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt

and not add pr_fmt when appropriate.

I tried this once.  I recall it worked without adding any
new string dependencies.   It did depend on __builtin_strcmp.

+#define _first_macro_arg(arg1, args...) arg1
+#define first_macro_arg(arg1, args...) _first_macro_arg(arg1)
+
+#define define_kernel_printk_level(level, fmt, ...)                    \
+do {                                                                   \
+       if (__builtin_strcmp(first_macro_arg(pr_fmt(fmt)),              \
+                            KBUILD_MODNAME ": " fmt))                  \
+               printk(level pr_fmt(fmt), ##__VA_ARGS__);               \
+       else                                                            \
+               printk(level fmt, ##__VA_ARGS__);                       \
+} while (0)

Re: [PATCH 24/25] dynamic_debug: drop pr_fmt() from dynamic_pr_debug

[Jim Cromie]

On Mon, Jul 25, 2011 at 9:45 PM, Joe Perches <joe@perches.com> wrote:
> On Mon, 2011-07-25 at 15:42 -0600, Jim Cromie wrote:
>> dynamic_pr_debug can add module, function, file, and line selectively,
>> theres no need to also add them via macro.  Moreover, adding them
>> via the macro, which is useful for pr_info and friends, causes
>> pr_debug to double-print those fields added by the flag-settings.
> []
>> -             __dynamic_pr_debug(&descriptor, pr_fmt(fmt), ##__VA_ARGS__);\
>> +             __dynamic_pr_debug(&descriptor, fmt, ##__VA_ARGS__);    \
>
> Hey Jim.
>
> Thinking about a bit more, maybe it's possible to use
> another test to see if the current pr_fmt is:
>
> #define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
>
> and not add pr_fmt when appropriate.
>
> I tried this once.  I recall it worked without adding any
> new string dependencies.   It did depend on __builtin_strcmp.
>
> +#define _first_macro_arg(arg1, args...) arg1
> +#define first_macro_arg(arg1, args...) _first_macro_arg(arg1)
> +
> +#define define_kernel_printk_level(level, fmt, ...)                    \
> +do {                                                                   \
> +       if (__builtin_strcmp(first_macro_arg(pr_fmt(fmt)),              \
> +                            KBUILD_MODNAME ": " fmt))                  \
> +               printk(level pr_fmt(fmt), ##__VA_ARGS__);               \
> +       else                                                            \
> +               printk(level fmt, ##__VA_ARGS__);                       \
> +} while (0)
>
>
>
>

hi Joe,

In case it wasnt clear, the idea was to leave pr_fmt as is for use
with pr_info, etc.
Providing another, separate macro for the purpose would seem most
straightforward:

#define pr_dbg_fmt ( fmt )   fmt

>> -             __dynamic_pr_debug(&descriptor, pr_fmt(fmt), ##__VA_ARGS__);\
>> +             __dynamic_pr_debug(&descriptor, pr_dbg_fmt(fmt), ##__VA_ARGS__);    \

would this address your concerns ?

It doesnt allow arbitrary insertion of extra punctuation, etc between
file, func, module, line, nor rearrange the ordering, but thats
probably overkill.

[PATCH 25/25] dynamic_debug: add $DBGFS/dynamic_debug/pending

[Jim Cromie]

add pending file so user can see queries that are pending.
This needs work - it currently loops through all pending queries,
but doesnt terminate - it starts over at the beginning.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c |  169 ++++++++++++++++++++++++++++++++++++++++++++++++++-
 1 files changed, 168 insertions(+), 1 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 6dbefb7..0f0bc61 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -65,6 +65,10 @@ struct ddebug_iter {
 	unsigned int idx;
 };
 
+struct pending_iter {
+	struct pending_query *elem;
+};
+
 static DEFINE_MUTEX(ddebug_lock);
 static LIST_HEAD(ddebug_tables);
 static int verbose = 0;
@@ -948,6 +952,162 @@ static const struct file_operations ddebug_proc_fops = {
 	.write = ddebug_proc_write
 };
 
+/*
+ * Set the iterator to point to the first pending_query object
+ * and return a pointer to that first object.  Returns
+ * NULL if there are no pending_querys at all.
+ */
+static struct pending_query *pending_iter_first(struct pending_iter *iter)
+{
+	if (list_empty(&pending_queries))
+		return NULL;
+	iter->elem = list_entry(pending_queries.next,
+				 struct pending_query, link);
+	return iter->elem;
+}
+
+/*
+ * Advance the iterator to point to the next pending_query
+ * object from the one the iterator currently points at,
+ * and returns a pointer to the new pending_query.  Returns
+ * NULL if the iterator has seen all the pending_querys.
+ */
+static struct pending_query *pending_iter_next(struct pending_iter *iter)
+{
+	if (iter->elem == NULL)
+		return NULL;
+	if (list_is_last(&iter->elem->link, &pending_queries)) {
+		iter->elem = NULL;
+		return NULL;
+	}
+	iter->elem = list_entry(iter->elem->link.next,
+				struct pending_query, link);
+	return iter->elem;
+}
+
+/*
+ * Seq_ops start method.  Called at the start of every
+ * read() call from userspace.  Takes the pending_lock and
+ * seeks the seq_file's iterator to the given position.
+ */
+static void *pending_proc_start(struct seq_file *m, loff_t *pos)
+{
+	struct pending_iter *iter = m->private;
+	struct pending_query *pq;
+	int n = *pos;
+
+	pr_debug("called m=%p *pos=%lld\n", m, (unsigned long long)*pos);
+
+	mutex_lock(&ddebug_lock);
+
+	if (!n)
+		return SEQ_START_TOKEN;
+	if (n < 0)
+		return NULL;
+	pq = pending_iter_first(iter);
+	/*while (pq != NULL && --n > 0)
+		pq = pending_iter_next(iter);
+	*/
+	return pq;
+}
+
+/*
+ * Seq_ops next method.  Called several times within a read()
+ * call from userspace, with pending_lock held.  Walks to the
+ * next pending_query object with a special case for the header line.
+ */
+static void *pending_proc_next(struct seq_file *m, void *p, loff_t *pos)
+{
+	struct pending_iter *iter = m->private;
+	struct pending_query *pq;
+
+	pr_debug("called m=%p p=%p *pos=%lld\n",
+		m, p, (unsigned long long)*pos);
+
+	if (p == SEQ_START_TOKEN)
+		pq = pending_iter_first(iter);
+	else
+		pq = pending_iter_next(iter);
+	++*pos;
+	return pq;
+}
+
+/*
+ * Seq_ops show method.  Called several times within a read()
+ * call from userspace, with pending_lock held.  Formats the
+ * current pending_query as a single human-readable line, with a
+ * special case for the header line.
+ */
+static int pending_proc_show(struct seq_file *m, void *p)
+{
+	struct pending_iter *iter = m->private;
+	struct pending_query *pq = p;
+	char *qstr;
+
+	pr_debug("called m=%p p=%p\n", m, p);
+
+	if (p == SEQ_START_TOKEN) {
+		seq_puts(m, "# file module func line flags\n");
+		return 0;
+	}
+
+	seq_printf(m, "%s\n", qstr = show_pending_query(iter->elem));
+	kfree(qstr);
+	return 0;
+}
+
+/*
+ * Seq_ops stop method.  Called at the end of each read()
+ * call from userspace.  Drops pending_lock.
+ */
+static void pending_proc_stop(struct seq_file *m, void *p)
+{
+	pr_debug("called m=%p p=%p\n", m, p);
+	mutex_unlock(&ddebug_lock);
+}
+
+static const struct seq_operations pending_proc_seqops = {
+	.start = pending_proc_start,
+	.next = pending_proc_next,
+	.show = pending_proc_show,
+	.stop = pending_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 pending_querys.
+ * 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 pending_proc_open(struct inode *inode, struct file *file)
+{
+	struct pending_iter *iter;
+	int err;
+
+	if (verbose)
+		pr_info("called\n");
+
+	iter = kzalloc(sizeof(*iter), GFP_KERNEL);
+	if (iter == NULL)
+		return -ENOMEM;
+
+	err = seq_open(file, &pending_proc_seqops);
+	if (err) {
+		kfree(iter);
+		return err;
+	}
+	((struct seq_file *) file->private_data)->private = iter;
+	return 0;
+}
+
+static const struct file_operations pending_proc_fops = {
+	.owner = THIS_MODULE,
+	.open = pending_proc_open,
+	.read = seq_read,
+	.llseek = seq_lseek,
+	.release = seq_release_private,
+};
+
 /* apply matching queries in pending-queries list. Called with lock held */
 static void apply_pending_queries(struct ddebug_table *dt)
 {
@@ -1051,7 +1211,7 @@ static __initdata int ddebug_init_success;
 
 static int __init dynamic_debug_init_debugfs(void)
 {
-	struct dentry *dir, *file;
+	struct dentry *dir, *file, *file2;
 
 	if (!ddebug_init_success)
 		return -ENODEV;
@@ -1065,6 +1225,13 @@ static int __init dynamic_debug_init_debugfs(void)
 		debugfs_remove(dir);
 		return -ENOMEM;
 	}
+	file2 = debugfs_create_file("pending", 0444, dir, NULL,
+					&pending_proc_fops);
+	if (!file2) {
+		debugfs_remove(file);
+		debugfs_remove(dir);
+		return -ENOMEM;
+	}
 	return 0;
 }
 
-- 
1.7.4.1