linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Jason Baron <jbaron@redhat.com>
To: Bart Van Assche <bvanassche@acm.org>
Cc: gregkh@suse.de, joe@perches.com, jim.cromie@gmail.com,
	linux-kernel@vger.kernel.org
Subject: Re: [PATCH 3/4 re-post] dynamic_debug: use a single printk() to emit msgs
Date: Thu, 25 Aug 2011 14:19:01 -0400	[thread overview]
Message-ID: <20110825181901.GA2448@redhat.com> (raw)
In-Reply-To: <CAO+b5-q0dVQUVLgo3VosAjNWHYNCf=xv8_qcCjBfYuhVh9RT9Q@mail.gmail.com>

On Thu, Aug 25, 2011 at 07:42:19PM +0200, Bart Van Assche wrote:
> On Thu, Aug 25, 2011 at 7:34 PM, Jason Baron <jbaron@redhat.com> wrote:
> > -static int dynamic_emit_prefix(const struct _ddebug *descriptor)
> > +#define PREFIX_SIZE 64
> > +#define LEFT(wrote) ((PREFIX_SIZE - wrote) > 0) ? (PREFIX_SIZE - wrote) : 0
> > +
> > +static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
> >  {
> > -       char tid[sizeof(int) + sizeof(int)/2 + 4];
> > -       char lineno[sizeof(int) + sizeof(int)/2];
> > +       int pos = 0;
> >
> > -       if (descriptor->flags & _DPRINTK_FLAGS_INCL_TID) {
> > +       pos += snprintf(buf + pos, LEFT(pos), "%s", KERN_DEBUG);
> > +       if (desc->flags & _DPRINTK_FLAGS_INCL_TID) {
> >                if (in_interrupt())
> > -                       snprintf(tid, sizeof(tid), "%s", "<intr> ");
> > +                       pos += snprintf(buf + pos, LEFT(pos), "%s ",
> > +                                               "<intr>");
> >                else
> > -                       snprintf(tid, sizeof(tid), "[%d] ",
> > -                                task_pid_vnr(current));
> > -       } else {
> > -               tid[0] = 0;
> > +                       pos += snprintf(buf + pos, LEFT(pos), "[%d] ",
> > +                                               task_pid_vnr(current));
> >        }
> > +       if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)
> > +               pos += snprintf(buf + pos, LEFT(pos), "%s:", desc->modname);
> > +       if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
> > +               pos += snprintf(buf + pos, LEFT(pos), "%s:", desc->function);
> > +       if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
> > +               pos += snprintf(buf + pos, LEFT(pos), "%d ", desc->lineno);
> >
> > -       if (descriptor->flags & _DPRINTK_FLAGS_INCL_LINENO)
> > -               snprintf(lineno, sizeof(lineno), "%d", descriptor->lineno);
> > -       else
> > -               lineno[0] = 0;
> > -
> > -       return printk(KERN_DEBUG "%s%s%s%s%s%s",
> > -                     tid,
> > -                     (descriptor->flags & _DPRINTK_FLAGS_INCL_MODNAME) ?
> > -                     descriptor->modname : "",
> > -                     (descriptor->flags & _DPRINTK_FLAGS_INCL_MODNAME) ?
> > -                     ":" : "",
> > -                     (descriptor->flags & _DPRINTK_FLAGS_INCL_FUNCNAME) ?
> > -                     descriptor->function : "",
> > -                     (descriptor->flags & _DPRINTK_FLAGS_INCL_FUNCNAME) ?
> > -                     ":" : "",
> > -                     lineno);
> > +       return buf;
> >  }
> 
> Shouldn't the new implementation guarantee that buf[] is
> '\0'-terminated if pos >= PREFIX_SIZE ?
> 
> Bart.

Yes, good catch. Here is a re-post.

thanks,

-Jason

We were using KERN_CONT to combine msgs with their prefix. However,
KERN_CONT is not smp safe, in the sense that it can interleave messages.
This interleaving can result in printks coming out at the wrong loglevel.
With the high frequency of printks, that dynamic debug can produce, this
is not desirable.

Thus, make dynamic_emit_prefix(), fill a char buf[64], instead
of doing a printk directly. If we enable printing out of
function, module, line, or pid info, they are placed in this
64 byte buffer. In my testing 64 bytes was enough size to fulfill
all requests. Even if its not, we can match up the printk itself
to see where its from, so to me this is no big deal.

Signed-off-by: Jason Baron <jbaron@redhat.com>
---
 lib/dynamic_debug.c |   69 ++++++++++++++++++++++----------------------------
 1 files changed, 30 insertions(+), 39 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 198d2af..f5def31 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -422,52 +422,49 @@ static int ddebug_exec_query(char *query_string)
 	return 0;
 }
 
-static int dynamic_emit_prefix(const struct _ddebug *descriptor)
+#define PREFIX_SIZE 64
+#define LEFT(wrote) ((PREFIX_SIZE - wrote) > 0) ? (PREFIX_SIZE - wrote) : 0
+
+static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
 {
-	char tid[sizeof(int) + sizeof(int)/2 + 4];
-	char lineno[sizeof(int) + sizeof(int)/2];
+	int pos = 0;
 
-	if (descriptor->flags & _DPRINTK_FLAGS_INCL_TID) {
+	pos += snprintf(buf + pos, LEFT(pos), "%s", KERN_DEBUG);
+	if (desc->flags & _DPRINTK_FLAGS_INCL_TID) {
 		if (in_interrupt())
-			snprintf(tid, sizeof(tid), "%s", "<intr> ");
+			pos += snprintf(buf + pos, LEFT(pos), "%s ",
+						"<intr>");
 		else
-			snprintf(tid, sizeof(tid), "[%d] ",
-				 task_pid_vnr(current));
-	} else {
-		tid[0] = 0;
+			pos += snprintf(buf + pos, LEFT(pos), "[%d] ",
+						task_pid_vnr(current));
 	}
+	if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)
+		pos += snprintf(buf + pos, LEFT(pos), "%s:", desc->modname);
+	if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
+		pos += snprintf(buf + pos, LEFT(pos), "%s:", desc->function);
+	if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
+		pos += snprintf(buf + pos, LEFT(pos), "%d ", desc->lineno);
 
-	if (descriptor->flags & _DPRINTK_FLAGS_INCL_LINENO)
-		snprintf(lineno, sizeof(lineno), "%d", descriptor->lineno);
-	else
-		lineno[0] = 0;
-
-	return printk(KERN_DEBUG "%s%s%s%s%s%s",
-		      tid,
-		      (descriptor->flags & _DPRINTK_FLAGS_INCL_MODNAME) ?
-		      descriptor->modname : "",
-		      (descriptor->flags & _DPRINTK_FLAGS_INCL_MODNAME) ?
-		      ":" : "",
-		      (descriptor->flags & _DPRINTK_FLAGS_INCL_FUNCNAME) ?
-		      descriptor->function : "",
-		      (descriptor->flags & _DPRINTK_FLAGS_INCL_FUNCNAME) ?
-		      ":" : "",
-		      lineno);
+	if (pos >= PREFIX_SIZE)
+		buf[PREFIX_SIZE - 1] = '\0';
+
+	return buf;
 }
 
 int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
 {
 	va_list args;
 	int res;
+	struct va_format vaf;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
-
-	res = dynamic_emit_prefix(descriptor);
-	res += vprintk(fmt, args);
-
+	vaf.fmt = fmt;
+	vaf.va = &args;
+	res = printk("%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);
 	va_end(args);
 
 	return res;
@@ -480,18 +477,15 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
-
 	vaf.fmt = fmt;
 	vaf.va = &args;
-
-	res = dynamic_emit_prefix(descriptor);
-	res += __dev_printk(KERN_CONT, dev, &vaf);
-
+	res = __dev_printk(dynamic_emit_prefix(descriptor, buf), dev, &vaf);
 	va_end(args);
 
 	return res;
@@ -504,18 +498,15 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
-
 	vaf.fmt = fmt;
 	vaf.va = &args;
-
-	res = dynamic_emit_prefix(descriptor);
-	res += __netdev_printk(KERN_CONT, dev, &vaf);
-
+	res = __netdev_printk(dynamic_emit_prefix(descriptor, buf), dev, &vaf);
 	va_end(args);
 
 	return res;
-- 
1.7.5.4


  reply	other threads:[~2011-08-25 18:19 UTC|newest]

Thread overview: 16+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2011-08-25 17:34 [PATCH 0/4] dynamic debug: cleanups + compile fix Jason Baron
2011-08-25 17:34 ` [PATCH 1/4] dynamic_debug: consolidate repetitive struct _ddebug descriptor definitions Jason Baron
2011-08-26 10:46   ` Bart Van Assche
2011-08-25 17:34 ` [PATCH 2/4] dynamic_debug: remove num_enabled accounting Jason Baron
2011-08-25 17:34 ` [PATCH 3/4] dynamic_debug: use a single printk() to emit msgs Jason Baron
2011-08-25 17:42   ` Bart Van Assche
2011-08-25 18:19     ` Jason Baron [this message]
2011-08-26 21:47   ` Jim Cromie
2011-08-29 19:14     ` Jason Baron
2011-08-25 17:34 ` [PATCH 4/4] dynamic_debug: fix undefined reference to `__netdev_printk' Jason Baron
2011-08-26 18:29 ` [PATCH 0/4] dynamic debug: cleanups + compile fix Greg KH
2011-08-26 18:47   ` Jason Baron
2011-08-26 19:04     ` Greg KH
2011-08-26 22:14       ` Joe Perches
2011-08-26 22:18         ` Greg KH
2011-08-26 22:22           ` Joe Perches

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20110825181901.GA2448@redhat.com \
    --to=jbaron@redhat.com \
    --cc=bvanassche@acm.org \
    --cc=gregkh@suse.de \
    --cc=jim.cromie@gmail.com \
    --cc=joe@perches.com \
    --cc=linux-kernel@vger.kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).