[PATCH 27/38] Rearrange buffer formatting in printk()

[PATCH 27/38] Rearrange buffer formatting in printk()

[Hannes Reinecke]

Move buffer formatting to the start of the function as it
doesn't require to be done under any locks.
No functional change, required by the next patch.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: LKML <linux-kernel@vger.kernel.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 kernel/printk/printk.c | 21 ++++++++++-----------
 1 file changed, 10 insertions(+), 11 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1ce7706..d13675e 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1633,8 +1633,18 @@ asmlinkage int vprintk_emit(int facility, int level,
 	if (level == SCHED_MESSAGE_LOGLEVEL) {
 		level = -1;
 		in_sched = true;
+
+		/*
+		 * The printf needs to come first; we need the syslog
+		 * prefix which might be passed-in as a parameter.
+		 */
+		text_len = scnprintf(text, sizeof(textbuf),
+				     KERN_WARNING "[sched_delayed] ");
 	}
 
+	text_len += vscnprintf(text + text_len,
+			       sizeof(textbuf) - text_len, fmt, args);
+
 	boot_delay_msec(level);
 	printk_delay();
 
@@ -1676,17 +1686,6 @@ asmlinkage int vprintk_emit(int facility, int level,
 					 strlen(recursion_msg));
 	}
 
-	/*
-	 * The printf needs to come first; we need the syslog
-	 * prefix which might be passed-in as a parameter.
-	 */
-	if (in_sched)
-		text_len = scnprintf(text, sizeof(textbuf),
-				     KERN_WARNING "[sched_delayed] ");
-
-	text_len += vscnprintf(text + text_len,
-			       sizeof(textbuf) - text_len, fmt, args);
-
 	/* mark and strip a trailing newline */
 	if (text_len && text[text_len-1] == '\n') {
 		text_len--;
-- 
1.8.5.2

[PATCH 28/38] Externalize string buffer for printk

[Hannes Reinecke]

This patch splits off the actual logging from vprintk_emit()
into printk_emit_string(), with vprintk_emit() just being a
simple wrapper for formatting the message into a
static buffer.

With that the caller can pass in a local buffer for
printk_emit_string() without increasing the overall stack size.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: LKML <linux-kernel@vger.kernel.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 include/linux/printk.h |  5 +++++
 kernel/printk/printk.c | 36 ++++++++++++++++++++++++------------
 2 files changed, 29 insertions(+), 12 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index d78125f..9639900 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -130,6 +130,11 @@ int vprintk_emit(int facility, int level,
 		 const char *dict, size_t dictlen,
 		 const char *fmt, va_list args);
 
+asmlinkage
+int printk_emit_string(int facility, int level,
+		       const char *dict, size_t dictlen,
+		       char *textbuf, size_t text_len);
+
 asmlinkage __printf(1, 0)
 int vprintk(const char *fmt, va_list args);
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d13675e..303a1fe 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1618,22 +1618,11 @@ asmlinkage int vprintk_emit(int facility, int level,
 			    const char *dict, size_t dictlen,
 			    const char *fmt, va_list args)
 {
-	static int recursion_bug;
 	static char textbuf[LOG_LINE_MAX];
 	char *text = textbuf;
 	size_t text_len = 0;
-	enum log_flags lflags = 0;
-	unsigned long flags;
-	int this_cpu;
-	int printed_len = 0;
-	bool in_sched = false;
-	/* cpu currently holding logbuf_lock in this function */
-	static volatile unsigned int logbuf_cpu = UINT_MAX;
 
 	if (level == SCHED_MESSAGE_LOGLEVEL) {
-		level = -1;
-		in_sched = true;
-
 		/*
 		 * The printf needs to come first; we need the syslog
 		 * prefix which might be passed-in as a parameter.
@@ -1644,6 +1633,24 @@ asmlinkage int vprintk_emit(int facility, int level,
 
 	text_len += vscnprintf(text + text_len,
 			       sizeof(textbuf) - text_len, fmt, args);
+	return printk_emit_string(facility, level, dict, dictlen,
+				  textbuf, text_len);
+}
+EXPORT_SYMBOL(vprintk_emit);
+
+asmlinkage int printk_emit_string(int facility, int level,
+				  const char *dict, size_t dictlen,
+				  char *textbuf, size_t text_len)
+{
+	static int recursion_bug;
+	char *text = textbuf;
+	enum log_flags lflags = 0;
+	unsigned long flags;
+	int this_cpu;
+	int printed_len = 0;
+	bool in_sched = false;
+	/* cpu currently holding logbuf_lock in this function */
+	static volatile unsigned int logbuf_cpu = UINT_MAX;
 
 	boot_delay_msec(level);
 	printk_delay();
@@ -1652,6 +1659,11 @@ asmlinkage int vprintk_emit(int facility, int level,
 	local_irq_save(flags);
 	this_cpu = smp_processor_id();
 
+	if (level == SCHED_MESSAGE_LOGLEVEL) {
+		level = -1;
+		in_sched = true;
+	}
+
 	/*
 	 * Ouch, printk recursed into itself!
 	 */
@@ -1789,7 +1801,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 
 	return printed_len;
 }
-EXPORT_SYMBOL(vprintk_emit);
+EXPORT_SYMBOL(printk_emit_string);
 
 asmlinkage int vprintk(const char *fmt, va_list args)
 {
-- 
1.8.5.2

[PATCH 29/38] Introduce dev_printk_string() and dev_printk_header()

[Hannes Reinecke]

Introducing dev_printk_string() and dev_printk_header() to allow
using an external buffer for printing via dev_printk().

Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: LKML <linux-kernel@vger.kernel.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/base/core.c    | 24 ++++++++++++++++++++++++
 include/linux/device.h | 12 ++++++++++++
 2 files changed, 36 insertions(+)

diff --git a/drivers/base/core.c b/drivers/base/core.c
index 20da3ad..e8aecf0 100644
--- a/drivers/base/core.c
+++ b/drivers/base/core.c
@@ -2041,6 +2041,19 @@ create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 	return pos;
 }
 
+int dev_printk_string(int level, const struct device *dev,
+		      char *msg, size_t msg_len)
+{
+	char hdr[128];
+	size_t hdrlen;
+
+	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
+
+	return printk_emit_string(0, level, hdrlen ? hdr : NULL, hdrlen,
+				  msg, msg_len);
+}
+EXPORT_SYMBOL(dev_printk_string);
+
 int dev_vprintk_emit(int level, const struct device *dev,
 		     const char *fmt, va_list args)
 {
@@ -2068,6 +2081,17 @@ int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
 }
 EXPORT_SYMBOL(dev_printk_emit);
 
+int dev_printk_header(char *buf, size_t buf_len, const struct device *dev)
+{
+	size_t off = 0;
+
+	if (dev)
+		off = scnprintf(buf, buf_len, "%s %s: ",
+				dev_driver_string(dev), dev_name(dev));
+	return off;
+}
+EXPORT_SYMBOL(dev_printk_header);
+
 static int __dev_printk(const char *level, const struct device *dev,
 			struct va_format *vaf)
 {
diff --git a/include/linux/device.h b/include/linux/device.h
index 43d183a..47f3b62 100644
--- a/include/linux/device.h
+++ b/include/linux/device.h
@@ -1025,6 +1025,9 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
+int dev_printk_string(int level, const struct device *dev,
+		      char *msg, size_t msg_len);
+int dev_printk_header(char *buf, size_t buf_len, const struct device *dev);
 extern __printf(3, 0)
 int dev_vprintk_emit(int level, const struct device *dev,
 		     const char *fmt, va_list args);
@@ -1051,6 +1054,15 @@ int _dev_info(const struct device *dev, const char *fmt, ...);
 
 #else
 
+static inline
+int dev_printk_string(int level, const struct device *dev,
+		      char *msg, size_t msg_len)
+{ return 0; }
+
+static inline
+int dev_printk_header(char *buf, size_t buf_len, const struct device *dev)
+{ return 0; }
+
 static inline __printf(3, 0)
 int dev_vprintk_emit(int level, const struct device *dev,
 		     const char *fmt, va_list args)
-- 
1.8.5.2

[PATCH 33/38] libata: use __scsi_print_command()

[Hannes Reinecke]

libata already uses an internal buffer, so we should be using
__scsi_print_command() here.

Cc: Tejun Heo <tj@kernel.org>
Cc: linux-ide@vger.kernel.org
Cc: LKML <linux-kernel@vger.kernel.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/ata/libata-eh.c | 12 ++++--------
 1 file changed, 4 insertions(+), 8 deletions(-)

diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index dad83df..74c5652 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -2509,15 +2509,11 @@ static void ata_eh_link_report(struct ata_link *link)
 
 		if (ata_is_atapi(qc->tf.protocol)) {
 			if (qc->scsicmd)
-				scsi_print_command(qc->scsicmd);
+				__scsi_print_command(cdb_buf, sizeof(cdb_buf),
+						     qc->scsicmd->cmnd);
 			else
-				snprintf(cdb_buf, sizeof(cdb_buf),
-				 "cdb %02x %02x %02x %02x %02x %02x %02x %02x  "
-				 "%02x %02x %02x %02x %02x %02x %02x %02x\n         ",
-				 cdb[0], cdb[1], cdb[2], cdb[3],
-				 cdb[4], cdb[5], cdb[6], cdb[7],
-				 cdb[8], cdb[9], cdb[10], cdb[11],
-				 cdb[12], cdb[13], cdb[14], cdb[15]);
+				__scsi_print_command(cdb_buf, sizeof(cdb_buf),
+						     (unsigned char *)cdb);
 		} else {
 			const char *descr = ata_get_cmd_descript(cmd->command);
 			if (descr)
-- 
1.8.5.2

Re: [PATCH 33/38] libata: use __scsi_print_command()

[Tejun Heo]

On Mon, Sep 29, 2014 at 01:59:02PM +0200, Hannes Reinecke wrote:
> libata already uses an internal buffer, so we should be using
> __scsi_print_command() here.
> 
> Cc: Tejun Heo <tj@kernel.org>
> Cc: linux-ide@vger.kernel.org
> Cc: LKML <linux-kernel@vger.kernel.org>
> Signed-off-by: Hannes Reinecke <hare@suse.de>

Applied to libata/for-3.18.

Thanks.

-- 
tejun

Re: [PATCH 33/38] libata: use __scsi_print_command()

[Hannes Reinecke]

On 09/29/2014 04:06 PM, Tejun Heo wrote:
> On Mon, Sep 29, 2014 at 01:59:02PM +0200, Hannes Reinecke wrote:
>> libata already uses an internal buffer, so we should be using
>> __scsi_print_command() here.
>>
>> Cc: Tejun Heo <tj@kernel.org>
>> Cc: linux-ide@vger.kernel.org
>> Cc: LKML <linux-kernel@vger.kernel.org>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
> 
> Applied to libata/for-3.18.
> 
> Thanks.
> 
Errm.
Nice that you did, but it sort of relies for patches 01-32 to be
applied previously.
I'd rather apply your Signed-off-by: to the patch and have it
routed through the SCSI tree; that way we're sure it'll only be
applied if the previous patches are in.

Can you please pull it from libata to avoid build issues?

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)

Re: [PATCH 33/38] libata: use __scsi_print_command()

[Tejun Heo]

On Mon, Sep 29, 2014 at 04:10:30PM +0200, Hannes Reinecke wrote:
> On 09/29/2014 04:06 PM, Tejun Heo wrote:
> > On Mon, Sep 29, 2014 at 01:59:02PM +0200, Hannes Reinecke wrote:
> >> libata already uses an internal buffer, so we should be using
> >> __scsi_print_command() here.
> >>
> >> Cc: Tejun Heo <tj@kernel.org>
> >> Cc: linux-ide@vger.kernel.org
> >> Cc: LKML <linux-kernel@vger.kernel.org>
> >> Signed-off-by: Hannes Reinecke <hare@suse.de>
> > 
> > Applied to libata/for-3.18.
> > 
> > Thanks.
> > 
> Errm.
> Nice that you did, but it sort of relies for patches 01-32 to be
> applied previously.
> I'd rather apply your Signed-off-by: to the patch and have it
> routed through the SCSI tree; that way we're sure it'll only be
> applied if the previous patches are in.
> 
> Can you please pull it from libata to avoid build issues?

Ah, okay, pulled it.  Please feel free to add

 Acked-by: Tejun Heo <tj@kernel.org>

Thanks.

-- 
tejun

Re: [PATCH 29/38] Introduce dev_printk_string() and dev_printk_header()

[Greg Kroah-Hartman]

On Mon, Sep 29, 2014 at 01:58:58PM +0200, Hannes Reinecke wrote:
> Introducing dev_printk_string() and dev_printk_header() to allow
> using an external buffer for printing via dev_printk().
> 
> Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Cc: LKML <linux-kernel@vger.kernel.org>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  drivers/base/core.c    | 24 ++++++++++++++++++++++++
>  include/linux/device.h | 12 ++++++++++++
>  2 files changed, 36 insertions(+)

I don't understand, what are you trying to do with this?  I don't see
any follow-on patches that use this, nor can I find a 00/38 patch for
this series...

thanks,

greg k-h

Re: [PATCH 29/38] Introduce dev_printk_string() and dev_printk_header()

[Hannes Reinecke]

On 09/29/2014 06:58 PM, Greg Kroah-Hartman wrote:
> On Mon, Sep 29, 2014 at 01:58:58PM +0200, Hannes Reinecke wrote:
>> Introducing dev_printk_string() and dev_printk_header() to allow
>> using an external buffer for printing via dev_printk().
>>
>> Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
>> Cc: Steven Rostedt <rostedt@goodmis.org>
>> Cc: LKML <linux-kernel@vger.kernel.org>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
>> ---
>>   drivers/base/core.c    | 24 ++++++++++++++++++++++++
>>   include/linux/device.h | 12 ++++++++++++
>>   2 files changed, 36 insertions(+)
>
> I don't understand, what are you trying to do with this?  I don't see
> any follow-on patches that use this, nor can I find a 00/38 patch for
> this series...
>
Well, I've copied lkml only for the generic interface changes.
The main bulk of patches have been posted to linux-scsi.
But it seems I should have posted all of them to lkml, too.

As I'll have to redo the patchset anyway as Steven Rostedt isn't so sure 
about his seq_buf patches I'll be posting the next series to
both, lkml and linux-scsi.

Or do you prefer to keep the printk() patches as a separate patchset and 
have the scsi fixes on top of that?

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)

Re: [PATCH 27/38] Rearrange buffer formatting in printk()

[Petr Mladek]

On Mon 29-09-14 13:58:56, Hannes Reinecke wrote:
> Move buffer formatting to the start of the function as it
> doesn't require to be done under any locks.
> No functional change, required by the next patch.
> 
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Cc: LKML <linux-kernel@vger.kernel.org>

printk stuff is maintained by Andrew in mm tree, so adding him into CC.

> Signed-off-by: Hannes Reinecke <hare@suse.de>

Reviewed-by: Petr Mladek <pmladek@suse.cz>

I do not see any obvious problem. Just note that
[sched_delayed] has already been removed in -mm tree. You might
want to base this patch on top of the commit 460d73c35ffa17979422290
("printk: git rid of [sched_delayed] message for printk_deferred")
from linux-next.

Best Regards,
Petr

> ---
>  kernel/printk/printk.c | 21 ++++++++++-----------
>  1 file changed, 10 insertions(+), 11 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1ce7706..d13675e 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1633,8 +1633,18 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	if (level == SCHED_MESSAGE_LOGLEVEL) {
>  		level = -1;
>  		in_sched = true;
> +
> +		/*
> +		 * The printf needs to come first; we need the syslog
> +		 * prefix which might be passed-in as a parameter.
> +		 */
> +		text_len = scnprintf(text, sizeof(textbuf),
> +				     KERN_WARNING "[sched_delayed] ");
>  	}
>  
> +	text_len += vscnprintf(text + text_len,
> +			       sizeof(textbuf) - text_len, fmt, args);
> +
>  	boot_delay_msec(level);
>  	printk_delay();
>  
> @@ -1676,17 +1686,6 @@ asmlinkage int vprintk_emit(int facility, int level,
>  					 strlen(recursion_msg));
>  	}
>  
> -	/*
> -	 * The printf needs to come first; we need the syslog
> -	 * prefix which might be passed-in as a parameter.
> -	 */
> -	if (in_sched)
> -		text_len = scnprintf(text, sizeof(textbuf),
> -				     KERN_WARNING "[sched_delayed] ");
> -
> -	text_len += vscnprintf(text + text_len,
> -			       sizeof(textbuf) - text_len, fmt, args);
> -
>  	/* mark and strip a trailing newline */
>  	if (text_len && text[text_len-1] == '\n') {
>  		text_len--;
> -- 
> 1.8.5.2
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: [PATCH 28/38] Externalize string buffer for printk

[Petr Mladek]

On Mon 29-09-14 13:58:57, Hannes Reinecke wrote:
> This patch splits off the actual logging from vprintk_emit()
> into printk_emit_string(), with vprintk_emit() just being a
> simple wrapper for formatting the message into a
> static buffer.
> 
> With that the caller can pass in a local buffer for
> printk_emit_string() without increasing the overall stack size.
> 
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Cc: LKML <linux-kernel@vger.kernel.org>

Adding Andrew into CC here as well.

There is one potential problem, see below.

> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  include/linux/printk.h |  5 +++++
>  kernel/printk/printk.c | 36 ++++++++++++++++++++++++------------
>  2 files changed, 29 insertions(+), 12 deletions(-)
> 
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index d78125f..9639900 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -130,6 +130,11 @@ int vprintk_emit(int facility, int level,
>  		 const char *dict, size_t dictlen,
>  		 const char *fmt, va_list args);
>  
> +asmlinkage
> +int printk_emit_string(int facility, int level,
> +		       const char *dict, size_t dictlen,
> +		       char *textbuf, size_t text_len);
> +
>  asmlinkage __printf(1, 0)
>  int vprintk(const char *fmt, va_list args);
>  
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index d13675e..303a1fe 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1618,22 +1618,11 @@ asmlinkage int vprintk_emit(int facility, int level,
>  			    const char *dict, size_t dictlen,
>  			    const char *fmt, va_list args)
>  {
> -	static int recursion_bug;
>  	static char textbuf[LOG_LINE_MAX];
>
>  	char *text = textbuf;
>  	size_t text_len = 0;
> -	enum log_flags lflags = 0;
> -	unsigned long flags;
> -	int this_cpu;
> -	int printed_len = 0;
> -	bool in_sched = false;
> -	/* cpu currently holding logbuf_lock in this function */
> -	static volatile unsigned int logbuf_cpu = UINT_MAX;
>  
>  	if (level == SCHED_MESSAGE_LOGLEVEL) {
> -		level = -1;
> -		in_sched = true;
> -
>  		/*
>  		 * The printf needs to come first; we need the syslog
>  		 * prefix which might be passed-in as a parameter.
> @@ -1644,6 +1633,24 @@ asmlinkage int vprintk_emit(int facility, int level,
>  
>  	text_len += vscnprintf(text + text_len,
>  			       sizeof(textbuf) - text_len, fmt, args);
> +	return printk_emit_string(facility, level, dict, dictlen,
> +				  textbuf, text_len);
> +}
> +EXPORT_SYMBOL(vprintk_emit);
> +
> +asmlinkage int printk_emit_string(int facility, int level,
> +				  const char *dict, size_t dictlen,
> +				  char *textbuf, size_t text_len)
> +{
> +	static int recursion_bug;
> +	char *text = textbuf;
> +	enum log_flags lflags = 0;
> +	unsigned long flags;
> +	int this_cpu;
> +	int printed_len = 0;
> +	bool in_sched = false;
> +	/* cpu currently holding logbuf_lock in this function */
> +	static volatile unsigned int logbuf_cpu = UINT_MAX;

We should make sure that text_len is lower or equal LOG_LINE_MAX.

I am afraid that printk() code is not able to process longer
lines. For example, syslog_print() does:

       text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);

Then it calls msg_print_text() that works with entire messages. So,
any longer message would freeze syslog_print() because it would newer
fit into the buffer.

I guess that there are more locations like this.

Maybe, we should make LOG_LINE_MAX public, so it could be used on the
other location either to allocate the buffer or to check the size.

Best Regards,
Petr
  
>  	boot_delay_msec(level);
>  	printk_delay();
> @@ -1652,6 +1659,11 @@ asmlinkage int vprintk_emit(int facility, int level,
>  	local_irq_save(flags);
>  	this_cpu = smp_processor_id();
>  
> +	if (level == SCHED_MESSAGE_LOGLEVEL) {
> +		level = -1;
> +		in_sched = true;
> +	}
> +
>  	/*
>  	 * Ouch, printk recursed into itself!
>  	 */
> @@ -1789,7 +1801,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>  
>  	return printed_len;
>  }
> -EXPORT_SYMBOL(vprintk_emit);
> +EXPORT_SYMBOL(printk_emit_string);
>  
>  asmlinkage int vprintk(const char *fmt, va_list args)
>  {
> -- 
> 1.8.5.2
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: [PATCH 28/38] Externalize string buffer for printk

[Hannes Reinecke]

On 09/30/2014 06:39 PM, Petr Mladek wrote:
> On Mon 29-09-14 13:58:57, Hannes Reinecke wrote:
>> This patch splits off the actual logging from vprintk_emit()
>> into printk_emit_string(), with vprintk_emit() just being a
>> simple wrapper for formatting the message into a
>> static buffer.
>>
>> With that the caller can pass in a local buffer for
>> printk_emit_string() without increasing the overall stack size.
>>
>> Cc: Steven Rostedt <rostedt@goodmis.org>
>> Cc: LKML <linux-kernel@vger.kernel.org>
>
> Adding Andrew into CC here as well.
>
> There is one potential problem, see below.
>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
>> ---
>>   include/linux/printk.h |  5 +++++
>>   kernel/printk/printk.c | 36 ++++++++++++++++++++++++------------
>>   2 files changed, 29 insertions(+), 12 deletions(-)
>>
>> diff --git a/include/linux/printk.h b/include/linux/printk.h
>> index d78125f..9639900 100644
>> --- a/include/linux/printk.h
>> +++ b/include/linux/printk.h
>> @@ -130,6 +130,11 @@ int vprintk_emit(int facility, int level,
>>   		 const char *dict, size_t dictlen,
>>   		 const char *fmt, va_list args);
>>
>> +asmlinkage
>> +int printk_emit_string(int facility, int level,
>> +		       const char *dict, size_t dictlen,
>> +		       char *textbuf, size_t text_len);
>> +
>>   asmlinkage __printf(1, 0)
>>   int vprintk(const char *fmt, va_list args);
>>
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index d13675e..303a1fe 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -1618,22 +1618,11 @@ asmlinkage int vprintk_emit(int facility, int level,
>>   			    const char *dict, size_t dictlen,
>>   			    const char *fmt, va_list args)
>>   {
>> -	static int recursion_bug;
>>   	static char textbuf[LOG_LINE_MAX];
>>
>>   	char *text = textbuf;
>>   	size_t text_len = 0;
>> -	enum log_flags lflags = 0;
>> -	unsigned long flags;
>> -	int this_cpu;
>> -	int printed_len = 0;
>> -	bool in_sched = false;
>> -	/* cpu currently holding logbuf_lock in this function */
>> -	static volatile unsigned int logbuf_cpu = UINT_MAX;
>>
>>   	if (level == SCHED_MESSAGE_LOGLEVEL) {
>> -		level = -1;
>> -		in_sched = true;
>> -
>>   		/*
>>   		 * The printf needs to come first; we need the syslog
>>   		 * prefix which might be passed-in as a parameter.
>> @@ -1644,6 +1633,24 @@ asmlinkage int vprintk_emit(int facility, int level,
>>
>>   	text_len += vscnprintf(text + text_len,
>>   			       sizeof(textbuf) - text_len, fmt, args);
>> +	return printk_emit_string(facility, level, dict, dictlen,
>> +				  textbuf, text_len);
>> +}
>> +EXPORT_SYMBOL(vprintk_emit);
>> +
>> +asmlinkage int printk_emit_string(int facility, int level,
>> +				  const char *dict, size_t dictlen,
>> +				  char *textbuf, size_t text_len)
>> +{
>> +	static int recursion_bug;
>> +	char *text = textbuf;
>> +	enum log_flags lflags = 0;
>> +	unsigned long flags;
>> +	int this_cpu;
>> +	int printed_len = 0;
>> +	bool in_sched = false;
>> +	/* cpu currently holding logbuf_lock in this function */
>> +	static volatile unsigned int logbuf_cpu = UINT_MAX;
>
> We should make sure that text_len is lower or equal LOG_LINE_MAX.
>
> I am afraid that printk() code is not able to process longer
> lines. For example, syslog_print() does:
>
>         text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
>
> Then it calls msg_print_text() that works with entire messages. So,
> any longer message would freeze syslog_print() because it would newer
> fit into the buffer.
>
Ah. Okay, I haven't thought about this. But yes, you are right.

> I guess that there are more locations like this.
>
> Maybe, we should make LOG_LINE_MAX public, so it could be used on the
> other location either to allocate the buffer or to check the size.
>
Well, for starters we should be truncating the buffer to LOG_LINE_MAX in 
printk_emit_string().
And document that it will only handle messages up to that length.

I'll be posting an updated patchset.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)

Re: [PATCH 27/38] Rearrange buffer formatting in printk()

[Petr Mladek]

On Tue 30-09-14 18:16:20, Petr Mladek wrote:
> On Mon 29-09-14 13:58:56, Hannes Reinecke wrote:
> > Move buffer formatting to the start of the function as it
> > doesn't require to be done under any locks.
> > No functional change, required by the next patch.
> > 
> > Cc: Steven Rostedt <rostedt@goodmis.org>
> > Cc: LKML <linux-kernel@vger.kernel.org>
> 
> printk stuff is maintained by Andrew in mm tree, so adding him into CC.
> 
> > Signed-off-by: Hannes Reinecke <hare@suse.de>
> 
> Reviewed-by: Petr Mladek <pmladek@suse.cz>

I have just realized that textbuf[LOG_LINE_MAX] is a static variable.
It means that it must be used under the lock and this patch is wrong.
I want to take back the Reviewed-by and instead do

Nacked->by: Petr Mladek <pmladek@suse.cz>

also it means that it does not take the extra space on the stack
and you probably does not need the two patches at all.

Best Regards,
Petr
 
> I do not see any obvious problem. Just note that
> [sched_delayed] has already been removed in -mm tree. You might
> want to base this patch on top of the commit 460d73c35ffa17979422290
> ("printk: git rid of [sched_delayed] message for printk_deferred")
> from linux-next.
> 
> Best Regards,
> Petr
> 
> > ---
> >  kernel/printk/printk.c | 21 ++++++++++-----------
> >  1 file changed, 10 insertions(+), 11 deletions(-)
> > 
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 1ce7706..d13675e 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -1633,8 +1633,18 @@ asmlinkage int vprintk_emit(int facility, int level,
> >  	if (level == SCHED_MESSAGE_LOGLEVEL) {
> >  		level = -1;
> >  		in_sched = true;
> > +
> > +		/*
> > +		 * The printf needs to come first; we need the syslog
> > +		 * prefix which might be passed-in as a parameter.
> > +		 */
> > +		text_len = scnprintf(text, sizeof(textbuf),
> > +				     KERN_WARNING "[sched_delayed] ");
> >  	}
> >  
> > +	text_len += vscnprintf(text + text_len,
> > +			       sizeof(textbuf) - text_len, fmt, args);
> > +
> >  	boot_delay_msec(level);
> >  	printk_delay();
> >  
> > @@ -1676,17 +1686,6 @@ asmlinkage int vprintk_emit(int facility, int level,
> >  					 strlen(recursion_msg));
> >  	}
> >  
> > -	/*
> > -	 * The printf needs to come first; we need the syslog
> > -	 * prefix which might be passed-in as a parameter.
> > -	 */
> > -	if (in_sched)
> > -		text_len = scnprintf(text, sizeof(textbuf),
> > -				     KERN_WARNING "[sched_delayed] ");
> > -
> > -	text_len += vscnprintf(text + text_len,
> > -			       sizeof(textbuf) - text_len, fmt, args);
> > -
> >  	/* mark and strip a trailing newline */
> >  	if (text_len && text[text_len-1] == '\n') {
> >  		text_len--;
> > -- 
> > 1.8.5.2
> > 
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> > the body of a message to majordomo@vger.kernel.org
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> > Please read the FAQ at  http://www.tux.org/lkml/
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/