public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* [PATCH 1/1] rcutorture: fixes for printing message buffer
@ 2014-07-11 20:30 Pranith Kumar
  2014-07-11 20:37 ` Joe Perches
  0 siblings, 1 reply; 6+ messages in thread
From: Pranith Kumar @ 2014-07-11 20:30 UTC (permalink / raw)
  To: Josh Triplett, Paul E. McKenney, Steven Rostedt,
	Mathieu Desnoyers, Lai Jiangshan, Iulia Manda, open list
  Cc: Joe Perches

Use snprintf() instead of sprintf() for writing to the message buffer.
Also use vmalloc() for the allocation of the message buffer. Since pr_alert() is
limited to print LOG_LINE_MAX characters at a time, we print the buffer in a
loop one line at a time.

I tested this using the parse-torture.sh script as follows:

$ dmesg | grep torture > log.txt
$ bash parse-torture.sh log.txt test
$

There were no warnings which means that parsing went fine.

Signed-off-by: Pranith Kumar <bobby.prani@gmail.com>
cc: Joe Perches <joe@perches.com>
Link: https://lkml.org/lkml/2014/6/18/604
---
 include/linux/torture.h |  2 +-
 kernel/rcu/rcutorture.c | 95 +++++++++++++++++++++++++++++++------------------
 kernel/torture.c        |  7 ++--
 3 files changed, 66 insertions(+), 38 deletions(-)

diff --git a/include/linux/torture.h b/include/linux/torture.h
index 5ca58fc..1e47ec7 100644
--- a/include/linux/torture.h
+++ b/include/linux/torture.h
@@ -51,7 +51,7 @@
 
 /* Definitions for online/offline exerciser. */
 int torture_onoff_init(long ooholdoff, long oointerval);
-char *torture_onoff_stats(char *page);
+int torture_onoff_stats(char *page, int size);
 bool torture_onoff_failures(void);
 
 /* Low-rider random number generator. */
diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
index 5ec0452..ab2cfbd 100644
--- a/kernel/rcu/rcutorture.c
+++ b/kernel/rcu/rcutorture.c
@@ -242,7 +242,7 @@ struct rcu_torture_ops {
 	void (*call)(struct rcu_head *head, void (*func)(struct rcu_head *rcu));
 	void (*cb_barrier)(void);
 	void (*fqs)(void);
-	void (*stats)(char *page);
+	int (*stats)(char *page, int size);
 	int irq_capable;
 	int can_boost;
 	const char *name;
@@ -525,21 +525,23 @@ static void srcu_torture_barrier(void)
 	srcu_barrier(&srcu_ctl);
 }
 
-static void srcu_torture_stats(char *page)
+static int srcu_torture_stats(char *page, int size)
 {
-	int cpu;
+	int cpu, used;
 	int idx = srcu_ctl.completed & 0x1;
 
-	page += sprintf(page, "%s%s per-CPU(idx=%d):",
+	used = snprintf(page, size, "%s%s per-CPU(idx=%d):",
 		       torture_type, TORTURE_FLAG, idx);
 	for_each_possible_cpu(cpu) {
 		long c0, c1;
 
 		c0 = (long)per_cpu_ptr(srcu_ctl.per_cpu_ref, cpu)->c[!idx];
 		c1 = (long)per_cpu_ptr(srcu_ctl.per_cpu_ref, cpu)->c[idx];
-		page += sprintf(page, " %d(%ld,%ld)", cpu, c0, c1);
+		used += snprintf(page + used, size - used,
+				" %d(%ld,%ld)", cpu, c0, c1);
 	}
-	sprintf(page, "\n");
+	used += snprintf(page + used, size - used, "\n");
+	return used;
 }
 
 static void srcu_torture_synchronize_expedited(void)
@@ -1033,10 +1035,10 @@ rcu_torture_reader(void *arg)
 /*
  * Create an RCU-torture statistics message in the specified buffer.
  */
-static void
-rcu_torture_printk(char *page)
+static int
+rcu_torture_printk(char *page, int size)
 {
-	int cpu;
+	int cpu, used = 0;
 	int i;
 	long pipesummary[RCU_TORTURE_PIPE_LEN + 1] = { 0 };
 	long batchsummary[RCU_TORTURE_PIPE_LEN + 1] = { 0 };
@@ -1052,8 +1054,9 @@ rcu_torture_printk(char *page)
 		if (pipesummary[i] != 0)
 			break;
 	}
-	page += sprintf(page, "%s%s ", torture_type, TORTURE_FLAG);
-	page += sprintf(page,
+	used += snprintf(page + used, size - used,
+			"%s%s ", torture_type, TORTURE_FLAG);
+	used += snprintf(page + used, size - used,
 		       "rtc: %p ver: %lu tfle: %d rta: %d rtaf: %d rtf: %d ",
 		       rcu_torture_current,
 		       rcu_torture_current_version,
@@ -1061,46 +1064,54 @@ rcu_torture_printk(char *page)
 		       atomic_read(&n_rcu_torture_alloc),
 		       atomic_read(&n_rcu_torture_alloc_fail),
 		       atomic_read(&n_rcu_torture_free));
-	page += sprintf(page, "rtmbe: %d rtbke: %ld rtbre: %ld ",
+	used += snprintf(page + used, size - used,
+		       "rtmbe: %d rtbke: %ld rtbre: %ld ",
 		       atomic_read(&n_rcu_torture_mberror),
 		       n_rcu_torture_boost_ktrerror,
 		       n_rcu_torture_boost_rterror);
-	page += sprintf(page, "rtbf: %ld rtb: %ld nt: %ld ",
+	used += snprintf(page + used, size - used,
+		       "rtbf: %ld rtb: %ld nt: %ld ",
 		       n_rcu_torture_boost_failure,
 		       n_rcu_torture_boosts,
 		       n_rcu_torture_timers);
-	page = torture_onoff_stats(page);
-	page += sprintf(page, "barrier: %ld/%ld:%ld",
+	used += torture_onoff_stats(page + used, size - used);
+	used += snprintf(page + used, size - used,
+		       "barrier: %ld/%ld:%ld",
 		       n_barrier_successes,
 		       n_barrier_attempts,
 		       n_rcu_torture_barrier_error);
-	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
+	used += snprintf(page + used, size - used,
+			"\n%s%s ", torture_type, TORTURE_FLAG);
 	if (atomic_read(&n_rcu_torture_mberror) != 0 ||
 	    n_rcu_torture_barrier_error != 0 ||
 	    n_rcu_torture_boost_ktrerror != 0 ||
 	    n_rcu_torture_boost_rterror != 0 ||
 	    n_rcu_torture_boost_failure != 0 ||
 	    i > 1) {
-		page += sprintf(page, "!!! ");
+		used += snprintf(page + used, size - used, "!!! ");
 		atomic_inc(&n_rcu_torture_error);
 		WARN_ON_ONCE(1);
 	}
-	page += sprintf(page, "Reader Pipe: ");
+	used += snprintf(page + used, size - used, "Reader Pipe: ");
 	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++)
-		page += sprintf(page, " %ld", pipesummary[i]);
-	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
-	page += sprintf(page, "Reader Batch: ");
+		used += snprintf(page + used, size - used,
+				" %ld", pipesummary[i]);
+	used += snprintf(page + used, size - used,
+			"\n%s%s ", torture_type, TORTURE_FLAG);
+	used += snprintf(page + used, size - used, "Reader Batch: ");
 	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++)
-		page += sprintf(page, " %ld", batchsummary[i]);
-	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
-	page += sprintf(page, "Free-Block Circulation: ");
+		used += snprintf(page + used, size - used,
+				" %ld", batchsummary[i]);
+	used += snprintf(page + used, size - used,
+			"\n%s%s ", torture_type, TORTURE_FLAG);
+	used += snprintf(page + used, size - used, "Free-Block Circulation: ");
 	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++) {
-		page += sprintf(page, " %d",
+		used += snprintf(page + used, size - used, " %d",
 			       atomic_read(&rcu_torture_wcount[i]));
 	}
-	page += sprintf(page, "\n");
+	used += snprintf(page + used, size - used, "\n");
 	if (cur_ops->stats)
-		cur_ops->stats(page);
+		used += cur_ops->stats(page + used, size - used);
 	if (rtcv_snap == rcu_torture_current_version &&
 	    rcu_torture_current != NULL) {
 		int __maybe_unused flags;
@@ -1109,7 +1120,7 @@ rcu_torture_printk(char *page)
 
 		rcutorture_get_gp_data(cur_ops->ttype,
 				       &flags, &gpnum, &completed);
-		page += sprintf(page,
+		used += snprintf(page + used, size - used,
 				"??? Writer stall state %d g%lu c%lu f%#x\n",
 				rcu_torture_writer_state,
 				gpnum, completed, flags);
@@ -1117,6 +1128,8 @@ rcu_torture_printk(char *page)
 		rcutorture_trace_dump();
 	}
 	rtcv_snap = rcu_torture_current_version;
+
+	return used;
 }
 
 /*
@@ -1130,17 +1143,31 @@ rcu_torture_printk(char *page)
 static void
 rcu_torture_stats_print(void)
 {
-	int size = nr_cpu_ids * 200 + 8192;
-	char *buf;
+	int size = nr_cpu_ids * 200 + 8192, used, marker;
+	char *buf, *tmpbuf, c;
 
-	buf = kmalloc(size, GFP_KERNEL);
+	buf = vmalloc(size);
 	if (!buf) {
 		pr_err("rcu-torture: Out of memory, need: %d", size);
 		return;
 	}
-	rcu_torture_printk(buf);
-	pr_alert("%s", buf);
-	kfree(buf);
+	used = rcu_torture_printk(buf, size);
+
+	tmpbuf = buf;
+
+	/* printk() can print only LOG_LINE_MAX chars at a time
+	 * so print the buffer in a loop, one line at a time
+	 */
+	while (used > 0) {
+		marker = strcspn(tmpbuf, "\n") + 1;
+		c = tmpbuf[marker];
+		tmpbuf[marker] = '\0';
+		pr_alert("%s", tmpbuf);
+		tmpbuf[marker] = c;
+		used   -= marker;
+		tmpbuf += marker;
+	}
+	vfree(buf);
 }
 
 /*
diff --git a/kernel/torture.c b/kernel/torture.c
index d600af2..83de502 100644
--- a/kernel/torture.c
+++ b/kernel/torture.c
@@ -211,10 +211,11 @@ EXPORT_SYMBOL_GPL(torture_onoff_cleanup);
 /*
  * Print online/offline testing statistics.
  */
-char *torture_onoff_stats(char *page)
+int torture_onoff_stats(char *page, int size)
 {
+	int used = 0;
 #ifdef CONFIG_HOTPLUG_CPU
-	page += sprintf(page,
+	used = snprintf(page, size,
 		       "onoff: %ld/%ld:%ld/%ld %d,%d:%d,%d %lu:%lu (HZ=%d) ",
 		       n_online_successes, n_online_attempts,
 		       n_offline_successes, n_offline_attempts,
@@ -222,7 +223,7 @@ char *torture_onoff_stats(char *page)
 		       min_offline, max_offline,
 		       sum_online, sum_offline, HZ);
 #endif /* #ifdef CONFIG_HOTPLUG_CPU */
-	return page;
+	return used;
 }
 EXPORT_SYMBOL_GPL(torture_onoff_stats);
 
-- 
1.9.1


^ permalink raw reply related	[flat|nested] 6+ messages in thread

* Re: [PATCH 1/1] rcutorture: fixes for printing message buffer
  2014-07-11 20:30 [PATCH 1/1] rcutorture: fixes for printing message buffer Pranith Kumar
@ 2014-07-11 20:37 ` Joe Perches
  2014-07-11 21:09   ` Pranith Kumar
  2014-07-14 13:26   ` Pranith Kumar
  0 siblings, 2 replies; 6+ messages in thread
From: Joe Perches @ 2014-07-11 20:37 UTC (permalink / raw)
  To: Pranith Kumar
  Cc: Josh Triplett, Paul E. McKenney, Steven Rostedt,
	Mathieu Desnoyers, Lai Jiangshan, Iulia Manda, open list

On Fri, 2014-07-11 at 16:30 -0400, Pranith Kumar wrote:
> Use snprintf() instead of sprintf() for writing to the message buffer.
> Also use vmalloc() for the allocation of the message buffer. Since pr_alert() is
> limited to print LOG_LINE_MAX characters at a time, we print the buffer in a
> loop one line at a time.
> 
> I tested this using the parse-torture.sh script as follows:

Did you see the patch I sent you?
https://lkml.org/lkml/2014/6/20/604

It doesn't need a vmalloc.
What is wrong with that approach?



^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [PATCH 1/1] rcutorture: fixes for printing message buffer
  2014-07-11 20:37 ` Joe Perches
@ 2014-07-11 21:09   ` Pranith Kumar
  2014-07-11 21:14     ` Joe Perches
  2014-07-14 13:26   ` Pranith Kumar
  1 sibling, 1 reply; 6+ messages in thread
From: Pranith Kumar @ 2014-07-11 21:09 UTC (permalink / raw)
  To: Joe Perches
  Cc: Josh Triplett, Paul E. McKenney, Steven Rostedt,
	Mathieu Desnoyers, Lai Jiangshan, Iulia Manda, open list

On Fri, Jul 11, 2014 at 4:37 PM, Joe Perches <joe@perches.com> wrote:
> On Fri, 2014-07-11 at 16:30 -0400, Pranith Kumar wrote:
>> Use snprintf() instead of sprintf() for writing to the message buffer.
>> Also use vmalloc() for the allocation of the message buffer. Since pr_alert() is
>> limited to print LOG_LINE_MAX characters at a time, we print the buffer in a
>> loop one line at a time.
>>
>> I tested this using the parse-torture.sh script as follows:
>
> Did you see the patch I sent you?
> https://lkml.org/lkml/2014/6/20/604
>
> It doesn't need a vmalloc.
> What is wrong with that approach?
>
>

I was trying to stay as close to the original code as possible by
using a buffer instead of using pr_alert/pr_cont throughout the code.

I see nothing wrong with what you proposed, but I like having one
pr_alert instead of lots sprinkled. Also avoiding vmalloc/vfree using
your approach seems like a win.

I will let Paul decide.

-- 
Pranith

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [PATCH 1/1] rcutorture: fixes for printing message buffer
  2014-07-11 21:09   ` Pranith Kumar
@ 2014-07-11 21:14     ` Joe Perches
  0 siblings, 0 replies; 6+ messages in thread
From: Joe Perches @ 2014-07-11 21:14 UTC (permalink / raw)
  To: Pranith Kumar
  Cc: Josh Triplett, Paul E. McKenney, Steven Rostedt,
	Mathieu Desnoyers, Lai Jiangshan, Iulia Manda, open list

On Fri, 2014-07-11 at 17:09 -0400, Pranith Kumar wrote:
> On Fri, Jul 11, 2014 at 4:37 PM, Joe Perches <joe@perches.com> wrote:
> > On Fri, 2014-07-11 at 16:30 -0400, Pranith Kumar wrote:
> >> Use snprintf() instead of sprintf() for writing to the message buffer.
> >> Also use vmalloc() for the allocation of the message buffer. Since pr_alert() is
> >> limited to print LOG_LINE_MAX characters at a time, we print the buffer in a
> >> loop one line at a time.
[]
> > Did you see the patch I sent you?
> > https://lkml.org/lkml/2014/6/20/604
> >
> > It doesn't need a vmalloc.
> > What is wrong with that approach?
[]
> I see nothing wrong with what you proposed, but I like having one
> pr_alert instead of lots sprinkled. Also avoiding vmalloc/vfree using
> your approach seems like a win.

Using any alloc an an intermediate buffer for logging
messages is very unusual.



^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [PATCH 1/1] rcutorture: fixes for printing message buffer
  2014-07-11 20:37 ` Joe Perches
  2014-07-11 21:09   ` Pranith Kumar
@ 2014-07-14 13:26   ` Pranith Kumar
  2014-08-13 21:17     ` Paul E. McKenney
  1 sibling, 1 reply; 6+ messages in thread
From: Pranith Kumar @ 2014-07-14 13:26 UTC (permalink / raw)
  To: Joe Perches
  Cc: Josh Triplett, Paul E. McKenney, Steven Rostedt,
	Mathieu Desnoyers, Lai Jiangshan, Iulia Manda, open list

On 07/11/2014 04:37 PM, Joe Perches wrote:
> On Fri, 2014-07-11 at 16:30 -0400, Pranith Kumar wrote:
>> Use snprintf() instead of sprintf() for writing to the message buffer.
>> Also use vmalloc() for the allocation of the message buffer. Since pr_alert() is
>> limited to print LOG_LINE_MAX characters at a time, we print the buffer in a
>> loop one line at a time.
>>
>> I tested this using the parse-torture.sh script as follows:
> 
> Did you see the patch I sent you?
> https://lkml.org/lkml/2014/6/20/604
> 
> It doesn't need a vmalloc.
> What is wrong with that approach?
> 
> 

Hi Paul,

Please find an alternative patch as suggested by Joe.


>From 0a3050d5ac910cb5f488e0a0dfe44cde06af1259 Mon Sep 17 00:00:00 2001
From: Pranith Kumar <bobby.prani@gmail.com>
Date: Mon, 14 Jul 2014 09:16:15 -0400
Subject: [PATCH 1/1] rcu: Use pr_alert/pr_cont for printing logs

User pr_alert/pr_cont for printing the logs from rcutorture module directly
instead of writing it to a buffer and then printing it. This allows us from not
having to allocate such buffers. Also remove a resulting empty function.

I tested this using the parse-torture.sh script as follows:

$ dmesg | grep torture > log.txt
$ bash parse-torture.sh log.txt test
$

There were no warnings which means that parsing went fine.

Signed-off-by: Joe Percesh <joe@perches.com>
Signed-off-by: Pranith Kumar <bobby.prani@gmail.com>
---
 include/linux/torture.h |   2 +-
 kernel/rcu/rcutorture.c | 127 +++++++++++++++++++++---------------------------
 kernel/torture.c        |  16 +++---
 3 files changed, 64 insertions(+), 81 deletions(-)

diff --git a/include/linux/torture.h b/include/linux/torture.h
index 5ca58fc..fec46f8 100644
--- a/include/linux/torture.h
+++ b/include/linux/torture.h
@@ -51,7 +51,7 @@
 
 /* Definitions for online/offline exerciser. */
 int torture_onoff_init(long ooholdoff, long oointerval);
-char *torture_onoff_stats(char *page);
+void torture_onoff_stats(void);
 bool torture_onoff_failures(void);
 
 /* Low-rider random number generator. */
diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
index 5ec0452..3e35f1b 100644
--- a/kernel/rcu/rcutorture.c
+++ b/kernel/rcu/rcutorture.c
@@ -242,7 +242,7 @@ struct rcu_torture_ops {
 	void (*call)(struct rcu_head *head, void (*func)(struct rcu_head *rcu));
 	void (*cb_barrier)(void);
 	void (*fqs)(void);
-	void (*stats)(char *page);
+	void (*stats)(void);
 	int irq_capable;
 	int can_boost;
 	const char *name;
@@ -525,21 +525,21 @@ static void srcu_torture_barrier(void)
 	srcu_barrier(&srcu_ctl);
 }
 
-static void srcu_torture_stats(char *page)
+static void srcu_torture_stats(void)
 {
 	int cpu;
 	int idx = srcu_ctl.completed & 0x1;
 
-	page += sprintf(page, "%s%s per-CPU(idx=%d):",
-		       torture_type, TORTURE_FLAG, idx);
+	pr_alert("%s%s per-CPU(idx=%d):",
+		 torture_type, TORTURE_FLAG, idx);
 	for_each_possible_cpu(cpu) {
 		long c0, c1;
 
 		c0 = (long)per_cpu_ptr(srcu_ctl.per_cpu_ref, cpu)->c[!idx];
 		c1 = (long)per_cpu_ptr(srcu_ctl.per_cpu_ref, cpu)->c[idx];
-		page += sprintf(page, " %d(%ld,%ld)", cpu, c0, c1);
+		pr_cont(" %d(%ld,%ld)", cpu, c0, c1);
 	}
-	sprintf(page, "\n");
+	pr_cont("\n");
 }
 
 static void srcu_torture_synchronize_expedited(void)
@@ -1031,10 +1031,15 @@ rcu_torture_reader(void *arg)
 }
 
 /*
- * Create an RCU-torture statistics message in the specified buffer.
+ * Print torture statistics.  Caller must ensure that there is only
+ * one call to this function at a given time!!!  This is normally
+ * accomplished by relying on the module system to only have one copy
+ * of the module loaded, and then by giving the rcu_torture_stats
+ * kthread full control (or the init/cleanup functions when rcu_torture_stats
+ * thread is not running).
  */
 static void
-rcu_torture_printk(char *page)
+rcu_torture_stats_print(void)
 {
 	int cpu;
 	int i;
@@ -1052,55 +1057,60 @@ rcu_torture_printk(char *page)
 		if (pipesummary[i] != 0)
 			break;
 	}
-	page += sprintf(page, "%s%s ", torture_type, TORTURE_FLAG);
-	page += sprintf(page,
-		       "rtc: %p ver: %lu tfle: %d rta: %d rtaf: %d rtf: %d ",
-		       rcu_torture_current,
-		       rcu_torture_current_version,
-		       list_empty(&rcu_torture_freelist),
-		       atomic_read(&n_rcu_torture_alloc),
-		       atomic_read(&n_rcu_torture_alloc_fail),
-		       atomic_read(&n_rcu_torture_free));
-	page += sprintf(page, "rtmbe: %d rtbke: %ld rtbre: %ld ",
-		       atomic_read(&n_rcu_torture_mberror),
-		       n_rcu_torture_boost_ktrerror,
-		       n_rcu_torture_boost_rterror);
-	page += sprintf(page, "rtbf: %ld rtb: %ld nt: %ld ",
-		       n_rcu_torture_boost_failure,
-		       n_rcu_torture_boosts,
-		       n_rcu_torture_timers);
-	page = torture_onoff_stats(page);
-	page += sprintf(page, "barrier: %ld/%ld:%ld",
-		       n_barrier_successes,
-		       n_barrier_attempts,
-		       n_rcu_torture_barrier_error);
-	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
+
+	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
+	pr_cont("rtc: %p ver: %lu tfle: %d rta: %d rtaf: %d rtf: %d ",
+		rcu_torture_current,
+		rcu_torture_current_version,
+		list_empty(&rcu_torture_freelist),
+		atomic_read(&n_rcu_torture_alloc),
+		atomic_read(&n_rcu_torture_alloc_fail),
+		atomic_read(&n_rcu_torture_free));
+	pr_cont("rtmbe: %d rtbke: %ld rtbre: %ld ",
+		atomic_read(&n_rcu_torture_mberror),
+		n_rcu_torture_boost_ktrerror,
+		n_rcu_torture_boost_rterror);
+	pr_cont("rtbf: %ld rtb: %ld nt: %ld ",
+		n_rcu_torture_boost_failure,
+		n_rcu_torture_boosts,
+		n_rcu_torture_timers);
+	torture_onoff_stats();
+	pr_cont("barrier: %ld/%ld:%ld\n",
+		n_barrier_successes,
+		n_barrier_attempts,
+		n_rcu_torture_barrier_error);
+
+	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
 	if (atomic_read(&n_rcu_torture_mberror) != 0 ||
 	    n_rcu_torture_barrier_error != 0 ||
 	    n_rcu_torture_boost_ktrerror != 0 ||
 	    n_rcu_torture_boost_rterror != 0 ||
 	    n_rcu_torture_boost_failure != 0 ||
 	    i > 1) {
-		page += sprintf(page, "!!! ");
+		pr_cont("%s", "!!! ");
 		atomic_inc(&n_rcu_torture_error);
 		WARN_ON_ONCE(1);
 	}
-	page += sprintf(page, "Reader Pipe: ");
+	pr_cont("Reader Pipe: ");
 	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++)
-		page += sprintf(page, " %ld", pipesummary[i]);
-	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
-	page += sprintf(page, "Reader Batch: ");
+		pr_cont(" %ld", pipesummary[i]);
+	pr_cont("\n");
+
+	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
+	pr_cont("Reader Batch: ");
 	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++)
-		page += sprintf(page, " %ld", batchsummary[i]);
-	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
-	page += sprintf(page, "Free-Block Circulation: ");
+		pr_cont(" %ld", batchsummary[i]);
+	pr_cont("\n");
+
+	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
+	pr_cont("Free-Block Circulation: ");
 	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++) {
-		page += sprintf(page, " %d",
-			       atomic_read(&rcu_torture_wcount[i]));
+		pr_cont(" %d", atomic_read(&rcu_torture_wcount[i]));
 	}
-	page += sprintf(page, "\n");
+	pr_cont("\n");
+
 	if (cur_ops->stats)
-		cur_ops->stats(page);
+		cur_ops->stats();
 	if (rtcv_snap == rcu_torture_current_version &&
 	    rcu_torture_current != NULL) {
 		int __maybe_unused flags;
@@ -1109,10 +1119,9 @@ rcu_torture_printk(char *page)
 
 		rcutorture_get_gp_data(cur_ops->ttype,
 				       &flags, &gpnum, &completed);
-		page += sprintf(page,
-				"??? Writer stall state %d g%lu c%lu f%#x\n",
-				rcu_torture_writer_state,
-				gpnum, completed, flags);
+		pr_alert("??? Writer stall state %d g%lu c%lu f%#x\n",
+			 rcu_torture_writer_state,
+			 gpnum, completed, flags);
 		show_rcu_gp_kthreads();
 		rcutorture_trace_dump();
 	}
@@ -1120,30 +1129,6 @@ rcu_torture_printk(char *page)
 }
 
 /*
- * Print torture statistics.  Caller must ensure that there is only
- * one call to this function at a given time!!!  This is normally
- * accomplished by relying on the module system to only have one copy
- * of the module loaded, and then by giving the rcu_torture_stats
- * kthread full control (or the init/cleanup functions when rcu_torture_stats
- * thread is not running).
- */
-static void
-rcu_torture_stats_print(void)
-{
-	int size = nr_cpu_ids * 200 + 8192;
-	char *buf;
-
-	buf = kmalloc(size, GFP_KERNEL);
-	if (!buf) {
-		pr_err("rcu-torture: Out of memory, need: %d", size);
-		return;
-	}
-	rcu_torture_printk(buf);
-	pr_alert("%s", buf);
-	kfree(buf);
-}
-
-/*
  * Periodically prints torture statistics, if periodic statistics printing
  * was specified via the stat_interval module parameter.
  */
diff --git a/kernel/torture.c b/kernel/torture.c
index d600af2..ede8b25 100644
--- a/kernel/torture.c
+++ b/kernel/torture.c
@@ -211,18 +211,16 @@ EXPORT_SYMBOL_GPL(torture_onoff_cleanup);
 /*
  * Print online/offline testing statistics.
  */
-char *torture_onoff_stats(char *page)
+void torture_onoff_stats(void)
 {
 #ifdef CONFIG_HOTPLUG_CPU
-	page += sprintf(page,
-		       "onoff: %ld/%ld:%ld/%ld %d,%d:%d,%d %lu:%lu (HZ=%d) ",
-		       n_online_successes, n_online_attempts,
-		       n_offline_successes, n_offline_attempts,
-		       min_online, max_online,
-		       min_offline, max_offline,
-		       sum_online, sum_offline, HZ);
+	pr_cont("onoff: %ld/%ld:%ld/%ld %d,%d:%d,%d %lu:%lu (HZ=%d) ",
+		n_online_successes, n_online_attempts,
+		n_offline_successes, n_offline_attempts,
+		min_online, max_online,
+		min_offline, max_offline,
+		sum_online, sum_offline, HZ);
 #endif /* #ifdef CONFIG_HOTPLUG_CPU */
-	return page;
 }
 EXPORT_SYMBOL_GPL(torture_onoff_stats);
 
-- 
2.0.1


^ permalink raw reply related	[flat|nested] 6+ messages in thread

* Re: [PATCH 1/1] rcutorture: fixes for printing message buffer
  2014-07-14 13:26   ` Pranith Kumar
@ 2014-08-13 21:17     ` Paul E. McKenney
  0 siblings, 0 replies; 6+ messages in thread
From: Paul E. McKenney @ 2014-08-13 21:17 UTC (permalink / raw)
  To: Pranith Kumar
  Cc: Joe Perches, Josh Triplett, Steven Rostedt, Mathieu Desnoyers,
	Lai Jiangshan, Iulia Manda, open list

On Mon, Jul 14, 2014 at 09:26:32AM -0400, Pranith Kumar wrote:
> On 07/11/2014 04:37 PM, Joe Perches wrote:
> > On Fri, 2014-07-11 at 16:30 -0400, Pranith Kumar wrote:
> >> Use snprintf() instead of sprintf() for writing to the message buffer.
> >> Also use vmalloc() for the allocation of the message buffer. Since pr_alert() is
> >> limited to print LOG_LINE_MAX characters at a time, we print the buffer in a
> >> loop one line at a time.
> >>
> >> I tested this using the parse-torture.sh script as follows:
> > 
> > Did you see the patch I sent you?
> > https://lkml.org/lkml/2014/6/20/604
> > 
> > It doesn't need a vmalloc.
> > What is wrong with that approach?
> > 
> > 
> 
> Hi Paul,
> 
> Please find an alternative patch as suggested by Joe.

Queued for 3.18, thank you both!

							Thanx, Paul

> >From 0a3050d5ac910cb5f488e0a0dfe44cde06af1259 Mon Sep 17 00:00:00 2001
> From: Pranith Kumar <bobby.prani@gmail.com>
> Date: Mon, 14 Jul 2014 09:16:15 -0400
> Subject: [PATCH 1/1] rcu: Use pr_alert/pr_cont for printing logs
> 
> User pr_alert/pr_cont for printing the logs from rcutorture module directly
> instead of writing it to a buffer and then printing it. This allows us from not
> having to allocate such buffers. Also remove a resulting empty function.
> 
> I tested this using the parse-torture.sh script as follows:
> 
> $ dmesg | grep torture > log.txt
> $ bash parse-torture.sh log.txt test
> $
> 
> There were no warnings which means that parsing went fine.
> 
> Signed-off-by: Joe Percesh <joe@perches.com>
> Signed-off-by: Pranith Kumar <bobby.prani@gmail.com>
> ---
>  include/linux/torture.h |   2 +-
>  kernel/rcu/rcutorture.c | 127 +++++++++++++++++++++---------------------------
>  kernel/torture.c        |  16 +++---
>  3 files changed, 64 insertions(+), 81 deletions(-)
> 
> diff --git a/include/linux/torture.h b/include/linux/torture.h
> index 5ca58fc..fec46f8 100644
> --- a/include/linux/torture.h
> +++ b/include/linux/torture.h
> @@ -51,7 +51,7 @@
> 
>  /* Definitions for online/offline exerciser. */
>  int torture_onoff_init(long ooholdoff, long oointerval);
> -char *torture_onoff_stats(char *page);
> +void torture_onoff_stats(void);
>  bool torture_onoff_failures(void);
> 
>  /* Low-rider random number generator. */
> diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
> index 5ec0452..3e35f1b 100644
> --- a/kernel/rcu/rcutorture.c
> +++ b/kernel/rcu/rcutorture.c
> @@ -242,7 +242,7 @@ struct rcu_torture_ops {
>  	void (*call)(struct rcu_head *head, void (*func)(struct rcu_head *rcu));
>  	void (*cb_barrier)(void);
>  	void (*fqs)(void);
> -	void (*stats)(char *page);
> +	void (*stats)(void);
>  	int irq_capable;
>  	int can_boost;
>  	const char *name;
> @@ -525,21 +525,21 @@ static void srcu_torture_barrier(void)
>  	srcu_barrier(&srcu_ctl);
>  }
> 
> -static void srcu_torture_stats(char *page)
> +static void srcu_torture_stats(void)
>  {
>  	int cpu;
>  	int idx = srcu_ctl.completed & 0x1;
> 
> -	page += sprintf(page, "%s%s per-CPU(idx=%d):",
> -		       torture_type, TORTURE_FLAG, idx);
> +	pr_alert("%s%s per-CPU(idx=%d):",
> +		 torture_type, TORTURE_FLAG, idx);
>  	for_each_possible_cpu(cpu) {
>  		long c0, c1;
> 
>  		c0 = (long)per_cpu_ptr(srcu_ctl.per_cpu_ref, cpu)->c[!idx];
>  		c1 = (long)per_cpu_ptr(srcu_ctl.per_cpu_ref, cpu)->c[idx];
> -		page += sprintf(page, " %d(%ld,%ld)", cpu, c0, c1);
> +		pr_cont(" %d(%ld,%ld)", cpu, c0, c1);
>  	}
> -	sprintf(page, "\n");
> +	pr_cont("\n");
>  }
> 
>  static void srcu_torture_synchronize_expedited(void)
> @@ -1031,10 +1031,15 @@ rcu_torture_reader(void *arg)
>  }
> 
>  /*
> - * Create an RCU-torture statistics message in the specified buffer.
> + * Print torture statistics.  Caller must ensure that there is only
> + * one call to this function at a given time!!!  This is normally
> + * accomplished by relying on the module system to only have one copy
> + * of the module loaded, and then by giving the rcu_torture_stats
> + * kthread full control (or the init/cleanup functions when rcu_torture_stats
> + * thread is not running).
>   */
>  static void
> -rcu_torture_printk(char *page)
> +rcu_torture_stats_print(void)
>  {
>  	int cpu;
>  	int i;
> @@ -1052,55 +1057,60 @@ rcu_torture_printk(char *page)
>  		if (pipesummary[i] != 0)
>  			break;
>  	}
> -	page += sprintf(page, "%s%s ", torture_type, TORTURE_FLAG);
> -	page += sprintf(page,
> -		       "rtc: %p ver: %lu tfle: %d rta: %d rtaf: %d rtf: %d ",
> -		       rcu_torture_current,
> -		       rcu_torture_current_version,
> -		       list_empty(&rcu_torture_freelist),
> -		       atomic_read(&n_rcu_torture_alloc),
> -		       atomic_read(&n_rcu_torture_alloc_fail),
> -		       atomic_read(&n_rcu_torture_free));
> -	page += sprintf(page, "rtmbe: %d rtbke: %ld rtbre: %ld ",
> -		       atomic_read(&n_rcu_torture_mberror),
> -		       n_rcu_torture_boost_ktrerror,
> -		       n_rcu_torture_boost_rterror);
> -	page += sprintf(page, "rtbf: %ld rtb: %ld nt: %ld ",
> -		       n_rcu_torture_boost_failure,
> -		       n_rcu_torture_boosts,
> -		       n_rcu_torture_timers);
> -	page = torture_onoff_stats(page);
> -	page += sprintf(page, "barrier: %ld/%ld:%ld",
> -		       n_barrier_successes,
> -		       n_barrier_attempts,
> -		       n_rcu_torture_barrier_error);
> -	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
> +
> +	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
> +	pr_cont("rtc: %p ver: %lu tfle: %d rta: %d rtaf: %d rtf: %d ",
> +		rcu_torture_current,
> +		rcu_torture_current_version,
> +		list_empty(&rcu_torture_freelist),
> +		atomic_read(&n_rcu_torture_alloc),
> +		atomic_read(&n_rcu_torture_alloc_fail),
> +		atomic_read(&n_rcu_torture_free));
> +	pr_cont("rtmbe: %d rtbke: %ld rtbre: %ld ",
> +		atomic_read(&n_rcu_torture_mberror),
> +		n_rcu_torture_boost_ktrerror,
> +		n_rcu_torture_boost_rterror);
> +	pr_cont("rtbf: %ld rtb: %ld nt: %ld ",
> +		n_rcu_torture_boost_failure,
> +		n_rcu_torture_boosts,
> +		n_rcu_torture_timers);
> +	torture_onoff_stats();
> +	pr_cont("barrier: %ld/%ld:%ld\n",
> +		n_barrier_successes,
> +		n_barrier_attempts,
> +		n_rcu_torture_barrier_error);
> +
> +	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
>  	if (atomic_read(&n_rcu_torture_mberror) != 0 ||
>  	    n_rcu_torture_barrier_error != 0 ||
>  	    n_rcu_torture_boost_ktrerror != 0 ||
>  	    n_rcu_torture_boost_rterror != 0 ||
>  	    n_rcu_torture_boost_failure != 0 ||
>  	    i > 1) {
> -		page += sprintf(page, "!!! ");
> +		pr_cont("%s", "!!! ");
>  		atomic_inc(&n_rcu_torture_error);
>  		WARN_ON_ONCE(1);
>  	}
> -	page += sprintf(page, "Reader Pipe: ");
> +	pr_cont("Reader Pipe: ");
>  	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++)
> -		page += sprintf(page, " %ld", pipesummary[i]);
> -	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
> -	page += sprintf(page, "Reader Batch: ");
> +		pr_cont(" %ld", pipesummary[i]);
> +	pr_cont("\n");
> +
> +	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
> +	pr_cont("Reader Batch: ");
>  	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++)
> -		page += sprintf(page, " %ld", batchsummary[i]);
> -	page += sprintf(page, "\n%s%s ", torture_type, TORTURE_FLAG);
> -	page += sprintf(page, "Free-Block Circulation: ");
> +		pr_cont(" %ld", batchsummary[i]);
> +	pr_cont("\n");
> +
> +	pr_alert("%s%s ", torture_type, TORTURE_FLAG);
> +	pr_cont("Free-Block Circulation: ");
>  	for (i = 0; i < RCU_TORTURE_PIPE_LEN + 1; i++) {
> -		page += sprintf(page, " %d",
> -			       atomic_read(&rcu_torture_wcount[i]));
> +		pr_cont(" %d", atomic_read(&rcu_torture_wcount[i]));
>  	}
> -	page += sprintf(page, "\n");
> +	pr_cont("\n");
> +
>  	if (cur_ops->stats)
> -		cur_ops->stats(page);
> +		cur_ops->stats();
>  	if (rtcv_snap == rcu_torture_current_version &&
>  	    rcu_torture_current != NULL) {
>  		int __maybe_unused flags;
> @@ -1109,10 +1119,9 @@ rcu_torture_printk(char *page)
> 
>  		rcutorture_get_gp_data(cur_ops->ttype,
>  				       &flags, &gpnum, &completed);
> -		page += sprintf(page,
> -				"??? Writer stall state %d g%lu c%lu f%#x\n",
> -				rcu_torture_writer_state,
> -				gpnum, completed, flags);
> +		pr_alert("??? Writer stall state %d g%lu c%lu f%#x\n",
> +			 rcu_torture_writer_state,
> +			 gpnum, completed, flags);
>  		show_rcu_gp_kthreads();
>  		rcutorture_trace_dump();
>  	}
> @@ -1120,30 +1129,6 @@ rcu_torture_printk(char *page)
>  }
> 
>  /*
> - * Print torture statistics.  Caller must ensure that there is only
> - * one call to this function at a given time!!!  This is normally
> - * accomplished by relying on the module system to only have one copy
> - * of the module loaded, and then by giving the rcu_torture_stats
> - * kthread full control (or the init/cleanup functions when rcu_torture_stats
> - * thread is not running).
> - */
> -static void
> -rcu_torture_stats_print(void)
> -{
> -	int size = nr_cpu_ids * 200 + 8192;
> -	char *buf;
> -
> -	buf = kmalloc(size, GFP_KERNEL);
> -	if (!buf) {
> -		pr_err("rcu-torture: Out of memory, need: %d", size);
> -		return;
> -	}
> -	rcu_torture_printk(buf);
> -	pr_alert("%s", buf);
> -	kfree(buf);
> -}
> -
> -/*
>   * Periodically prints torture statistics, if periodic statistics printing
>   * was specified via the stat_interval module parameter.
>   */
> diff --git a/kernel/torture.c b/kernel/torture.c
> index d600af2..ede8b25 100644
> --- a/kernel/torture.c
> +++ b/kernel/torture.c
> @@ -211,18 +211,16 @@ EXPORT_SYMBOL_GPL(torture_onoff_cleanup);
>  /*
>   * Print online/offline testing statistics.
>   */
> -char *torture_onoff_stats(char *page)
> +void torture_onoff_stats(void)
>  {
>  #ifdef CONFIG_HOTPLUG_CPU
> -	page += sprintf(page,
> -		       "onoff: %ld/%ld:%ld/%ld %d,%d:%d,%d %lu:%lu (HZ=%d) ",
> -		       n_online_successes, n_online_attempts,
> -		       n_offline_successes, n_offline_attempts,
> -		       min_online, max_online,
> -		       min_offline, max_offline,
> -		       sum_online, sum_offline, HZ);
> +	pr_cont("onoff: %ld/%ld:%ld/%ld %d,%d:%d,%d %lu:%lu (HZ=%d) ",
> +		n_online_successes, n_online_attempts,
> +		n_offline_successes, n_offline_attempts,
> +		min_online, max_online,
> +		min_offline, max_offline,
> +		sum_online, sum_offline, HZ);
>  #endif /* #ifdef CONFIG_HOTPLUG_CPU */
> -	return page;
>  }
>  EXPORT_SYMBOL_GPL(torture_onoff_stats);
> 
> -- 
> 2.0.1
> 


^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2014-08-13 21:17 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-07-11 20:30 [PATCH 1/1] rcutorture: fixes for printing message buffer Pranith Kumar
2014-07-11 20:37 ` Joe Perches
2014-07-11 21:09   ` Pranith Kumar
2014-07-11 21:14     ` Joe Perches
2014-07-14 13:26   ` Pranith Kumar
2014-08-13 21:17     ` Paul E. McKenney

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox