Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Joe Perches]

On Fri, 2007-08-03 at 17:05 +0200, Jean Delvare wrote: 
> Fine with me, but this first patch should still be correct per se.

Add new pr_<level> printk(KERN_<level> fmt "\n", ##arg) to kernel.h
pr_info and pr_debug are unchanged
Remove local pr_err #defines
Convert current uses of pr_err

Signed-off-by:  Joe Perches <joe@perches.com>

diff --git a/include/linux/kernel.h b/include/linux/kernel.h
index 4300bb4..6447072 100644
--- a/include/linux/kernel.h
+++ b/include/linux/kernel.h
@@ -229,20 +229,24 @@ extern void print_hex_dump_bytes(const char *prefix_str, int prefix_type,
 			void *buf, size_t len);
 #define hex_asc(x)	"0123456789abcdef"[x]
 
+#define pr_emerg(fmt, arg...)	printk(KERN_EMERG fmt "\n", ##arg)
+#define pr_alert(fmt, arg...)	printk(KERN_ALERT fmt "\n", ##arg)
+#define pr_crit(fmt, arg...)	printk(KERN_CRIT fmt "\n", ##arg)
+#define pr_err(fmt, arg...)	printk(KERN_ERR fmt "\n", ##arg)
+#define pr_warn(fmt, arg...)	printk(KERN_WARNING fmt "\n", ##arg)
+#define pr_notice(fmt, arg...)	printk(KERN_NOTICE fmt "\n", ##arg)
+#define pr_info(fmt, arg...)	printk(KERN_INFO fmt, ##arg)
+
 #ifdef DEBUG
 /* If you are writing a driver, please use dev_dbg instead */
-#define pr_debug(fmt,arg...) \
-	printk(KERN_DEBUG fmt,##arg)
+#define pr_debug(fmt, arg...)	printk(KERN_DEBUG fmt, ##arg)
 #else
-static inline int __attribute__ ((format (printf, 1, 2))) pr_debug(const char * fmt, ...)
+static inline int __attribute__ ((format (printf, 1, 2))) pr_debug(const char *fmt, ...)
 {
 	return 0;
 }
 #endif
 
-#define pr_info(fmt,arg...) \
-	printk(KERN_INFO fmt,##arg)
-
 /*
  *      Display an IP address in readable format.
  */
diff --git a/drivers/i2c/chips/menelaus.c b/drivers/i2c/chips/menelaus.c
index 48a7e2f..055a7b4 100644
--- a/drivers/i2c/chips/menelaus.c
+++ b/drivers/i2c/chips/menelaus.c
@@ -49,8 +49,7 @@
 #include <asm/arch/menelaus.h>
 
 #define DRIVER_NAME			"menelaus"
-
-#define pr_err(fmt, arg...)	printk(KERN_ERR DRIVER_NAME ": ", ## arg);
+#define PFX                             DRIVER_NAME ": "
 
 #define MENELAUS_I2C_ADDRESS		0x72
 
@@ -156,7 +155,7 @@ static int menelaus_write_reg(int reg, u8 value)
 	int val = i2c_smbus_write_byte_data(the_menelaus->client, reg, value);
 
 	if (val < 0) {
-		pr_err("write error");
+		pr_err(PFX "write error");
 		return val;
 	}
 
@@ -168,7 +167,7 @@ static int menelaus_read_reg(int reg)
 	int val = i2c_smbus_read_byte_data(the_menelaus->client, reg);
 
 	if (val < 0)
-		pr_err("read error");
+		pr_err(PFX "read error");
 
 	return val;
 }
@@ -1178,7 +1177,7 @@ static int menelaus_probe(struct i2c_client *client)
 	/* If a true probe check the device */
 	rev = menelaus_read_reg(MENELAUS_REV);
 	if (rev < 0) {
-		pr_err("device not found");
+		pr_err(PFX "device not found");
 		err = -ENODEV;
 		goto fail1;
 	}
@@ -1259,7 +1258,7 @@ static int __init menelaus_init(void)
 
 	res = i2c_add_driver(&menelaus_i2c_driver);
 	if (res < 0) {
-		pr_err("driver registration failed\n");
+		pr_err(PFX "driver registration failed");
 		return res;
 	}
 
diff --git a/drivers/net/spider_net.c b/drivers/net/spider_net.c
index 590b12c..ce0417c 100644
--- a/drivers/net/spider_net.c
+++ b/drivers/net/spider_net.c
@@ -1238,14 +1238,14 @@ spider_net_decode_one_descr(struct spider_net_card *card)
 	if (hwdescr->dmac_cmd_status & SPIDER_NET_DESCR_BAD_STATUS) {
 		dev_err(&card->netdev->dev, "bad status, cmd_status=x%08x\n",
 			       hwdescr->dmac_cmd_status);
-		pr_err("buf_addr=x%08x\n", hw_buf_addr);
-		pr_err("buf_size=x%08x\n", hwdescr->buf_size);
-		pr_err("next_descr_addr=x%08x\n", hwdescr->next_descr_addr);
-		pr_err("result_size=x%08x\n", hwdescr->result_size);
-		pr_err("valid_size=x%08x\n", hwdescr->valid_size);
-		pr_err("data_status=x%08x\n", hwdescr->data_status);
-		pr_err("data_error=x%08x\n", hwdescr->data_error);
-		pr_err("which=%ld\n", descr - card->rx_chain.ring);
+		pr_err("buf_addr=x%08x", hw_buf_addr);
+		pr_err("buf_size=x%08x", hwdescr->buf_size);
+		pr_err("next_descr_addr=x%08x", hwdescr->next_descr_addr);
+		pr_err("result_size=x%08x", hwdescr->result_size);
+		pr_err("valid_size=x%08x", hwdescr->valid_size);
+		pr_err("data_status=x%08x", hwdescr->data_status);
+		pr_err("data_error=x%08x", hwdescr->data_error);
+		pr_err("which=%ld", descr - card->rx_chain.ring);
 
 		card->spider_stats.rx_desc_error++;
 		goto bad_desc;
diff --git a/drivers/net/spider_net.h b/drivers/net/spider_net.h
index dbbdb8c..c67b11d 100644
--- a/drivers/net/spider_net.h
+++ b/drivers/net/spider_net.h
@@ -493,7 +493,4 @@ struct spider_net_card {
 	struct spider_net_descr darray[0];
 };
 
-#define pr_err(fmt,arg...) \
-	printk(KERN_ERR fmt ,##arg)
-
 #endif
diff --git a/drivers/video/omap/lcd_h3.c b/drivers/video/omap/lcd_h3.c
index 51807b4..c37b651 100644
--- a/drivers/video/omap/lcd_h3.c
+++ b/drivers/video/omap/lcd_h3.c
@@ -27,8 +27,7 @@
 #include <asm/arch/omapfb.h>
 
 #define MODULE_NAME	"omapfb-lcd_h3"
-
-#define pr_err(fmt, args...) printk(KERN_ERR MODULE_NAME ": " fmt, ## args)
+#define PFX MODULE_NAME ": "
 
 static int h3_panel_init(struct lcd_panel *panel, struct omapfb_device *fbdev)
 {
@@ -48,7 +47,7 @@ static int h3_panel_enable(struct lcd_panel *panel)
 	if (!r)
 		r = tps65010_set_gpio_out_value(GPIO2, HIGH);
 	if (r)
-		pr_err("Unable to turn on LCD panel\n");
+		pr_err(PFX "Unable to turn on LCD panel");
 
 	return r;
 }
@@ -62,7 +61,7 @@ static void h3_panel_disable(struct lcd_panel *panel)
 	if (!r)
 		tps65010_set_gpio_out_value(GPIO2, LOW);
 	if (r)
-		pr_err("Unable to turn off LCD panel\n");
+		pr_err(PFX "Unable to turn off LCD panel");
 }
 
 static unsigned long h3_panel_get_caps(struct lcd_panel *panel)
diff --git a/drivers/video/omap/lcd_inn1610.c b/drivers/video/omap/lcd_inn1610.c
index 95604ca..562a30e 100644
--- a/drivers/video/omap/lcd_inn1610.c
+++ b/drivers/video/omap/lcd_inn1610.c
@@ -26,8 +26,7 @@
 #include <asm/arch/omapfb.h>
 
 #define MODULE_NAME	"omapfb-lcd_h3"
-
-#define pr_err(fmt, args...) printk(KERN_ERR MODULE_NAME ": " fmt, ## args)
+#define PFX		MODULE_NAME ": "
 
 static int innovator1610_panel_init(struct lcd_panel *panel,
 				    struct omapfb_device *fbdev)
@@ -35,12 +34,12 @@ static int innovator1610_panel_init(struct lcd_panel *panel,
 	int r = 0;
 
 	if (omap_request_gpio(14)) {
-		pr_err("can't request GPIO 14\n");
+		pr_err(PFX "can't request GPIO 14");
 		r = -1;
 		goto exit;
 	}
 	if (omap_request_gpio(15)) {
-		pr_err("can't request GPIO 15\n");
+		pr_err(PFX "can't request GPIO 15");
 		omap_free_gpio(14);
 		r = -1;
 		goto exit;

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jan Engelhardt]

On Aug 3 2007 15:16, Joe Perches wrote:
>On Fri, 2007-08-03 at 17:05 +0200, Jean Delvare wrote: 
>> Fine with me, but this first patch should still be correct per se.
>
>Add new pr_<level> printk(KERN_<level> fmt "\n", ##arg) to kernel.h
>pr_info and pr_debug are unchanged
>Remove local pr_err #defines
>Convert current uses of pr_err
>
>Signed-off-by:  Joe Perches <joe@perches.com>
>
>diff --git a/include/linux/kernel.h b/include/linux/kernel.h
>index 4300bb4..6447072 100644
>--- a/include/linux/kernel.h
>+++ b/include/linux/kernel.h
>@@ -229,20 +229,24 @@ extern void print_hex_dump_bytes(const char *prefix_str, int prefix_type,
> 			void *buf, size_t len);
> #define hex_asc(x)	"0123456789abcdef"[x]
> 
>+#define pr_emerg(fmt, arg...)	printk(KERN_EMERG fmt "\n", ##arg)
>+#define pr_alert(fmt, arg...)	printk(KERN_ALERT fmt "\n", ##arg)
>+#define pr_crit(fmt, arg...)	printk(KERN_CRIT fmt "\n", ##arg)
>+#define pr_err(fmt, arg...)	printk(KERN_ERR fmt "\n", ##arg)
>+#define pr_warn(fmt, arg...)	printk(KERN_WARNING fmt "\n", ##arg)
>+#define pr_notice(fmt, arg...)	printk(KERN_NOTICE fmt "\n", ##arg)
>+#define pr_info(fmt, arg...)	printk(KERN_INFO fmt, ##arg)
>+

Ugh. What do we have printk for then? I do not like this.
For pr_debug() it makes sense because its semantics change with
-DDEBUG and -UDEBUG, but for these pr_()s it does not seem so.


> 	if (omap_request_gpio(15)) {
>-		pr_err("can't request GPIO 15\n");
>+		pr_err(PFX "can't request GPIO 15");
> 		omap_free_gpio(14);
> 		r = -1;
> 		goto exit;
>
>
>-
>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/
>

	Jan
-- 

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jean Delvare]

Hi Jan, Joe,

On 8/4/2007, "Jan Engelhardt" <jengelh@computergmbh.de> wrote:
>On Aug 3 2007 15:16, Joe Perches wrote:
>>On Fri, 2007-08-03 at 17:05 +0200, Jean Delvare wrote:
>>> Fine with me, but this first patch should still be correct per se.
>>
>>Add new pr_<level> printk(KERN_<level> fmt "\n", ##arg) to kernel.h
>>pr_info and pr_debug are unchanged
>>Remove local pr_err #defines
>>Convert current uses of pr_err
>>
>>Signed-off-by:  Joe Perches <joe@perches.com>
>>
>>diff --git a/include/linux/kernel.h b/include/linux/kernel.h
>>index 4300bb4..6447072 100644
>>--- a/include/linux/kernel.h
>>+++ b/include/linux/kernel.h
>>@@ -229,20 +229,24 @@ extern void print_hex_dump_bytes(const char *prefix_str, int prefix_type,
>> 			void *buf, size_t len);
>> #define hex_asc(x)	"0123456789abcdef"[x]
>>
>>+#define pr_emerg(fmt, arg...)	printk(KERN_EMERG fmt "\n", ##arg)
>>+#define pr_alert(fmt, arg...)	printk(KERN_ALERT fmt "\n", ##arg)
>>+#define pr_crit(fmt, arg...)	printk(KERN_CRIT fmt "\n", ##arg)
>>+#define pr_err(fmt, arg...)	printk(KERN_ERR fmt "\n", ##arg)
>>+#define pr_warn(fmt, arg...)	printk(KERN_WARNING fmt "\n", ##arg)
>>+#define pr_notice(fmt, arg...)	printk(KERN_NOTICE fmt "\n", ##arg)
>>+#define pr_info(fmt, arg...)	printk(KERN_INFO fmt, ##arg)
>>+
>
>Ugh. What do we have printk for then? I do not like this.
>For pr_debug() it makes sense because its semantics change with
>-DDEBUG and -UDEBUG, but for these pr_()s it does not seem so.

I think I agree with Jan here, I see no fundamental need for these
additional macros. But if they are really added, then they should follow
the same standard as pr_debug() and pr_info(), that is: no "\n" added
automatically. Otherwise this will become quite messy.

Thanks,
--
Jean Delvare

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Joe Perches]

On Sat, 2007-08-04 at 18:47 +0200, Jean Delvare wrote:
> On 8/4/2007, "Jan Engelhardt" <jengelh@computergmbh.de> wrote: 
> >Ugh. What do we have printk for then? I do not like this.
> >For pr_debug() it makes sense because its semantics change with
> >-DDEBUG and -UDEBUG, but for these pr_()s it does not seem so.
> I think I agree with Jan here, I see no fundamental need for these
> additional macros. But if they are really added, then they should follow
> the same standard as pr_debug() and pr_info(), that is: no "\n" added
> automatically. Otherwise this will become quite messy.

2 reasons:

This change will eventually isolate multiple line
printk messages and allow easier insertion of 

printk_block_start
printks
printk_block_end

so that multiple line messages are kept together
in the message logs.

and I've done tree-wide patches for single line

printk(KERN_\(emerg|alert|notice|crit\),

(about 2000) and fixed several dozen lines without \n
or things like "KERN_<level> /n msg"

Here's the perl script I used.

It's imperfect of course.  There are comments with
embedded semicolons where it fails, and #defines
aren't substituted too well.

if ($#ARGV < 2) {
    print "usage: KERN_<level> pr_<level> files...\n";
    exit;
}

for ($i=2; $i <= $#ARGV; $i++) {
    PrintkSearchReplace($ARGV[$i], $ARGV[0], $ARGV[1]);
}

sub PrintkSearchReplace{
    my($file, $search, $replace) = @_;

    my $orig = "";
    local($/);
    open(my $fh, $file) or die "File not found '$file'\n";
    $orig = <$fh>;
    close(my $fh);

    my $parts = $orig;
    my $whole = "";
    @segments = split(/\;/, $parts);
    foreach $line (@segments) {

	if ($whole ne "") {
	    $whole = $whole . "\;";
	}

	my $origline = $line;

	if ($line =~ m/\bprintk\s*\(\s*${search}\s*.*\".*\\n\s*\"/ms) {
	    
	    $line =~ s/\bprintk\s*\(\s*${search}\s*([^\"]*)\"/${replace}\(\1\"/ms;
	    $line =~ s/\\n\s*\"\s*/\"/ms;

	    print "${file}: changed:\n" . $origline . "\;" . "\nto:\n" . $line . "\;" . "\n" ;

	}
	$whole = $whole . $line;
    }

    if ($orig ne $whole) {
	open(my $fh, ">${file}") or die "Could not open '$file'\n";
	print $fh $whole;
	close(my $fh);
    }

}

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jan Engelhardt]

On Aug 7 2007 09:10, Joe Perches wrote:
>On Sat, 2007-08-04 at 18:47 +0200, Jean Delvare wrote:
>> On 8/4/2007, "Jan Engelhardt" <jengelh@computergmbh.de> wrote: 
>> >Ugh. What do we have printk for then? I do not like this.
>> >For pr_debug() it makes sense because its semantics change with
>> >-DDEBUG and -UDEBUG, but for these pr_()s it does not seem so.
>> I think I agree with Jan here, I see no fundamental need for these
>> additional macros. But if they are really added, then they should follow
>> the same standard as pr_debug() and pr_info(), that is: no "\n" added
>> automatically. Otherwise this will become quite messy.
>
>2 reasons:
>
>This change will eventually isolate multiple line
>printk messages and allow easier insertion of 
>
>printk_block_start
>printks
>printk_block_end
>
>so that multiple line messages are kept together in the message logs.

They are not kept together today, so I do not see how that will change.
Locking the printk buffer between _start and _end? No thanks, I don't
have overlapping messages that often.

Or what is it actually that you are trying to accomplish?


	Jan
-- 

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Andrew Morton]

On Fri, 03 Aug 2007 15:16:09 -0700
Joe Perches <joe@perches.com> wrote:

> On Fri, 2007-08-03 at 17:05 +0200, Jean Delvare wrote: 
> > Fine with me, but this first patch should still be correct per se.
> 
> Add new pr_<level> printk(KERN_<level> fmt "\n", ##arg) to kernel.h
> pr_info and pr_debug are unchanged
> Remove local pr_err #defines
> Convert current uses of pr_err

OK, I've lost the plot here.  If we have now converged on an
agreeable patch, please resend it?

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jean Delvare]

On Tue, 7 Aug 2007 13:19:49 -0700, Andrew Morton wrote:
> On Fri, 03 Aug 2007 15:16:09 -0700
> Joe Perches <joe@perches.com> wrote:
> 
> > On Fri, 2007-08-03 at 17:05 +0200, Jean Delvare wrote: 
> > > Fine with me, but this first patch should still be correct per se.
> > 
> > Add new pr_<level> printk(KERN_<level> fmt "\n", ##arg) to kernel.h
> > pr_info and pr_debug are unchanged
> > Remove local pr_err #defines
> > Convert current uses of pr_err
> 
> OK, I've lost the plot here.  If we have now converged on an
> agreeable patch, please resend it?

I don't think we have, no. It's not even clear what Joe is trying to
achieve.

-- 
Jean Delvare

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Joe Perches]

On Wed, 2007-08-08 at 22:02 +0200, Jean Delvare wrote:
> On Tue, 7 Aug 2007 13:19:49 -0700, Andrew Morton wrote:
> > On Fri, 03 Aug 2007 15:16:09 -0700
> > Joe Perches <joe@perches.com> wrote:
> > > Add new pr_<level> printk(KERN_<level> fmt "\n", ##arg) to kernel.h
> > > pr_info and pr_debug are unchanged
> > > Remove local pr_err #defines
> > > Convert current uses of pr_err
> > OK, I've lost the plot here.  If we have now converged on an
> > agreeable patch, please resend it?
> I don't think we have, no.
> It's not even clear what Joe is trying to achieve.

Goals in desired implementation sequence:

1 Standardization of pr_<level>
2 Correctness of single line uses of pr_<level>
3 Correctness of multiple line uses of printk(<level>)
4 Removal of local near equivalents of pr_<level>
5 Standardization of pr_<level> as single line only
6 Conversion of single line printk(KERN_<level> to pr_level
7 Standardize local #defines to enable/print pr_<level>
  __file__/__func__/__line__
8 Minimization/elimination of interleaved log messages

cheers, Joe

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jan Engelhardt]

On Aug 8 2007 13:31, Joe Perches wrote:
>Goals in desired implementation sequence:
>
>1 Standardization of pr_<level>
>2 Correctness of single line uses of pr_<level>
>3 Correctness of multiple line uses of printk(<level>)
>4 Removal of local near equivalents of pr_<level>
>5 Standardization of pr_<level> as single line only
>6 Conversion of single line printk(KERN_<level> to pr_level
>7 Standardize local #defines to enable/print pr_<level>
>  __file__/__func__/__line__

I fail to see what problem these are trying to fix. Please post some broken
code that would 'benefit' from pr_halleluja, and why printk(level ) could not
do the same.

>8 Minimization/elimination of interleaved log messages

This is a separate, and worthwhile, thing to do, yes.
And it can be done without deviating from the regular printk().


	Jan
-- 

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Joe Perches]

On Wed, 2007-08-08 at 22:39 +0200, Jan Engelhardt wrote:
> I fail to see what problem these are trying to fix. 

Any code that does the equivalent of printk(KERN_foo "\n message");

egrep -r "printk[[:space:]]*\([[:space:]]*KERN.*\\\n[A-JL-Za-jl-z[:space:]" --include=*.[ch] *

At least 61 instances right now.

> Please post some broken code that would 'benefit' from pr_halleluja,
> and why printk(level ) could not do the same.

"Could" most always leads to an interesting argument.

Future minimization of introduced error is a benefit
not an absolute.

Adding the ability to log higher priority KERN_<level>
without removing printk altogether for embedded systems
seems useful.  You could leave out say just KERN_INFO,
KERN_NOTICE and KERN_WARN levels.

Worth the churn is another question, though git seems to
allow most everyone to resync to tree wide changes pretty
easily.

If new pr_<level> defines aren't accepted, I suggest
removing the current ~200 uses of pr_info.

> >8 Minimization/elimination of interleaved log messages
> 
> This is a separate, and worthwhile, thing to do, yes.
> And it can be done without deviating from the regular printk().

I'm not sure how.  Maybe you have an idea you could share?

Maybe an external tool to reassemble complete messages from
prefixed {{cookie}} message logs would be fine for awhile.

Perhaps something like:

cookie = printk_block_start()
printk_block[s](cookie)
printk_block_end(cookie)?

where printk_block emits cookie when multiple cookies
are active.

cheers,  Joe

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jan Engelhardt]

On Aug 8 2007 14:36, Joe Perches wrote:
>On Wed, 2007-08-08 at 22:39 +0200, Jan Engelhardt wrote:
>> I fail to see what problem these are trying to fix. 
>
>Any code that does the equivalent of printk(KERN_foo "\n message");
>
>egrep -r "printk[[:space:]]*\([[:space:]]*KERN.*\\\n[A-JL-Za-jl-z[:space:]" --include=*.[ch] *
>
>At least 61 instances right now.

Eww. Well, let's look at some.
arch/i386/kernel/io_apic.c:line 1529

        printk("\n" KERN_DEBUG "printing local APIC contents on CPU#%d/%d:\n",
                smp_processor_id(), hard_smp_processor_id());

The \n seems unneeded, since print_local_APIC() is run on each cpu.
(see caller).


Then, there are also messages that are just a standalone \n
without even a debugging level. Not sure that is useful.

	# io_apic.c again, line 1601
	#
        printk(KERN_DEBUG "... APIC TDCR: %08x\n", v);  
        printk("\n");

So, well, let's pick one with KERN_DEBUG "\n....

fs/freevxfs/vxfs_bmap.c:line 169 (near "case VXFS_TYPED_DATA_DEV4")

                        printk(KERN_INFO "\n\nTYPED_DEV4 detected!\n");
                        printk(KERN_INFO "block: %Lu\tsize: %Ld\tdev: %d\n",
                               (unsigned long long) typ4->vd4_block,
                               (unsigned long long) typ4->vd4_size,
                               typ4->vd4_dev);

Seems normal. So it looks like your regex has some false positives.
(which nothing can be done about - the 61 must be hand-sorted)

Perhaps we're looking for this idiom:

	printk(KERN_WHATEVER "Doing foo...");
	for (as_long_as_there_is_work) {
		do_it();
		printk(KERN_WHATEVER ".");
	}
	printk(KERN_WHATEVER "\n");

Yes, that imo is horrible :) since code running on another cpu can printk in
the middle. Perhaps

	int i;
	for (as_long with ++i) {
		do_it();
		printk("something informative %d\n", i++);
	}

should be done _instead_. This would also address number 8:

>> >8 Minimization/elimination of interleaved log messages
>> 
>> This is a separate, and worthwhile, thing to do, yes.
>> And it can be done without deviating from the regular printk().
>
>I'm not sure how.  Maybe you have an idea you could share?

[My idea is above]

>Maybe an external tool to reassemble complete messages from
>prefixed {{cookie}} message logs would be fine for awhile.
>
>Perhaps something like:
>
>cookie = printk_block_start()
>printk_block[s](cookie)
>printk_block_end(cookie)?
>
>where printk_block emits cookie when multiple cookies
>are active.

How is this supposed to work? Are you suggesting that the printk buffer is
locked? I hope not. Cache output until a block is ended? No, I do not think
that helps either, because the   for(){printk(".");}  loops are meant to
give an indication _THAT_ something is happening (or not - e.g. lockup).
Now, if you hold the output of a printk block until it's _end()
counterpart is executed, the user does not get any output when the
machine locks up during the for loop.

Hence, better do a full printk (e.g. with newline) in each iteration.
And if possible sparingly. Booting in 9600 bps serial mode is going to
take longer the more output the kernel produces ;-)
Or just to not clutter dmesg too much.



And at the end of the day when this would be done -
what would we need pr_foo for?


	Jan
-- 

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Joe Perches]

On Wed, 2007-08-08 at 23:57 +0200, Jan Engelhardt wrote:
> fs/freevxfs/vxfs_bmap.c:line 169 (near "case VXFS_TYPED_DATA_DEV4")
> 
>                         printk(KERN_INFO "\n\nTYPED_DEV4 detected!\n");
> Seems normal.

The second output log line of the first printk isn't prefixed
with KERN_INFO.  It's output with log_level_unknown.

> So it looks like your regex has some false positives.
> (which nothing can be done about - the 61 must be hand-sorted)

Must have copy/pasted the wrong regex

$ egrep -r "printk[[:space:]]*\([[:space:]]*KERN.*\\\n[A-JL-Za-jl-z[:space:]]" --include=*.[ch] * | wc -l
61

> [My idea is above]

Any sequence of printks can be interleaved.  I don't see
how your suggestion changes that.

> >Maybe an external tool to reassemble complete messages from
> >prefixed {{cookie}} message logs would be fine for awhile.
> >
> >Perhaps something like:
> >
> >cookie = printk_block_start()
> >printk_block[s](cookie)
> >printk_block_end(cookie)?
> >
> >where printk_block emits cookie when multiple cookies
> >are active.
> 
> How is this supposed to work? Are you suggesting that the printk buffer is
> locked?

No, just another identifier placed into logs that allow messages
to be reassembled into something readable when multiple printk_block's
are active.

> Now, if you hold the output of a printk block until it's _end()
> counterpart is executed, the user does not get any output when the
> machine locks up during the for loop.

External tool scans logs.  No blocking or delay in output.

cheers,  Joe

Re: + remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[Jean Delvare]

Hi Joe,

On Wed, 08 Aug 2007 15:21:53 -0700, Joe Perches wrote:
> On Wed, 2007-08-08 at 23:57 +0200, Jan Engelhardt wrote:
> > fs/freevxfs/vxfs_bmap.c:line 169 (near "case VXFS_TYPED_DATA_DEV4")
> > 
> >                         printk(KERN_INFO "\n\nTYPED_DEV4 detected!\n");
> > Seems normal.
> 
> The second output log line of the first printk isn't prefixed
> with KERN_INFO.  It's output with log_level_unknown.

True. This simply means that the leading \n's shouldn't be there.
Pretty easy to fix.

> > So it looks like your regex has some false positives.
> > (which nothing can be done about - the 61 must be hand-sorted)
> 
> Must have copy/pasted the wrong regex
> 
> $ egrep -r "printk[[:space:]]*\([[:space:]]*KERN.*\\\n[A-JL-Za-jl-z[:space:]]" --include=*.[ch] * | wc -l
> 61
> 
> > [My idea is above]
> 
> Any sequence of printks can be interleaved.  I don't see
> how your suggestion changes that.
> 
> > >Maybe an external tool to reassemble complete messages from
> > >prefixed {{cookie}} message logs would be fine for awhile.
> > >
> > >Perhaps something like:
> > >
> > >cookie = printk_block_start()
> > >printk_block[s](cookie)
> > >printk_block_end(cookie)?
> > >
> > >where printk_block emits cookie when multiple cookies
> > >are active.
> > 
> > How is this supposed to work? Are you suggesting that the printk buffer is
> > locked?
> 
> No, just another identifier placed into logs that allow messages
> to be reassembled into something readable when multiple printk_block's
> are active.
> 
> > Now, if you hold the output of a printk block until it's _end()
> > counterpart is executed, the user does not get any output when the
> > machine locks up during the for loop.
> 
> External tool scans logs.  No blocking or delay in output.

Assuming that the related messages are prefixed in a similar way (as
dev_info and friends do), grouping them is already possible, and pretty
trivial: grep can select whatever you are interested in.

I'm not saying that your ideas are all bad. The ability to build a
kernel without the least interesting messages is valuable. Having a
more standard formatting for log messages is interesting as well,
although dev_info and friends already offer this to some extent. But
you have to realize that kernel logging must stay something very
simple, and that the first tool to read them is "dmesg" and not some
funky log scanner. So the current implementation can't be that far from
what we need.

Thanks,
-- 
Jean Delvare

+ remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch added to -mm tree

[akpm]

The patch titled
     Remove current defines and uses of pr_err, add pr_emerg, pr_alert, pr_crit, pr_err, pr_warn, pr_notice to include/linux/kernel.h
has been added to the -mm tree.  Its filename is
     remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch

*** Remember to use Documentation/SubmitChecklist when testing your code ***

See http://www.zip.com.au/~akpm/linux/patches/stuff/added-to-mm.txt to find
out what to do about this

------------------------------------------------------
Subject: Remove current defines and uses of pr_err, add pr_emerg, pr_alert, pr_crit, pr_err, pr_warn, pr_notice to include/linux/kernel.h
From: Joe Perches <joe@perches.com>

Remove current #define and uses of pr_err
Add pr_emerg, pr_alert, pr_crit, pr_err, pr_warn, pr_notice
	to include/linux/kernel.h

Signed-off-by: Joe Perches <joe@perches.com>
Cc: Jean Delvare <khali@linux-fr.org>
Cc: Jeff Garzik <jeff@garzik.org>
Cc: "Antonino A. Daplas" <adaplas@pol.net>
Cc: Greg KH <greg@kroah.com>
Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
---

 drivers/i2c/chips/menelaus.c     |   11 +++++------
 drivers/net/spider_net.c         |   17 +++++++++--------
 drivers/net/spider_net.h         |    3 ---
 drivers/video/omap/lcd_h3.c      |    7 +++----
 drivers/video/omap/lcd_inn1610.c |    7 +++----
 include/linux/kernel.h           |   16 ++++++++++------
 6 files changed, 30 insertions(+), 31 deletions(-)

diff -puN drivers/i2c/chips/menelaus.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg drivers/i2c/chips/menelaus.c
--- a/drivers/i2c/chips/menelaus.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg
+++ a/drivers/i2c/chips/menelaus.c
@@ -49,8 +49,7 @@
 #include <asm/arch/menelaus.h>
 
 #define DRIVER_NAME			"menelaus"
-
-#define pr_err(fmt, arg...)	printk(KERN_ERR DRIVER_NAME ": ", ## arg);
+#define PFX                             DRIVER_NAME ": "
 
 #define MENELAUS_I2C_ADDRESS		0x72
 
@@ -156,7 +155,7 @@ static int menelaus_write_reg(int reg, u
 	int val = i2c_smbus_write_byte_data(the_menelaus->client, reg, value);
 
 	if (val < 0) {
-		pr_err("write error");
+		printk(KERN_ERR PFX "write error\n");
 		return val;
 	}
 
@@ -168,7 +167,7 @@ static int menelaus_read_reg(int reg)
 	int val = i2c_smbus_read_byte_data(the_menelaus->client, reg);
 
 	if (val < 0)
-		pr_err("read error");
+		printk(KERN_ERR PFX "read error\n");
 
 	return val;
 }
@@ -1178,7 +1177,7 @@ static int menelaus_probe(struct i2c_cli
 	/* If a true probe check the device */
 	rev = menelaus_read_reg(MENELAUS_REV);
 	if (rev < 0) {
-		pr_err("device not found");
+		printk(KERN_ERR PFX "device not found\n");
 		err = -ENODEV;
 		goto fail1;
 	}
@@ -1259,7 +1258,7 @@ static int __init menelaus_init(void)
 
 	res = i2c_add_driver(&menelaus_i2c_driver);
 	if (res < 0) {
-		pr_err("driver registration failed\n");
+		printk(KERN_ERR PFX "driver registration failed\n");
 		return res;
 	}
 
diff -puN drivers/net/spider_net.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg drivers/net/spider_net.c
--- a/drivers/net/spider_net.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg
+++ a/drivers/net/spider_net.c
@@ -1238,14 +1238,15 @@ spider_net_decode_one_descr(struct spide
 	if (hwdescr->dmac_cmd_status & SPIDER_NET_DESCR_BAD_STATUS) {
 		dev_err(&card->netdev->dev, "bad status, cmd_status=x%08x\n",
 			       hwdescr->dmac_cmd_status);
-		pr_err("buf_addr=x%08x\n", hw_buf_addr);
-		pr_err("buf_size=x%08x\n", hwdescr->buf_size);
-		pr_err("next_descr_addr=x%08x\n", hwdescr->next_descr_addr);
-		pr_err("result_size=x%08x\n", hwdescr->result_size);
-		pr_err("valid_size=x%08x\n", hwdescr->valid_size);
-		pr_err("data_status=x%08x\n", hwdescr->data_status);
-		pr_err("data_error=x%08x\n", hwdescr->data_error);
-		pr_err("which=%ld\n", descr - card->rx_chain.ring);
+		printk(KERN_ERR "buf_addr=x%08x\n", hw_buf_addr);
+		printk(KERN_ERR "buf_size=x%08x\n", hwdescr->buf_size);
+		printk(KERN_ERR "next_descr_addr=x%08x\n",
+		       hwdescr->next_descr_addr);
+		printk(KERN_ERR "result_size=x%08x\n", hwdescr->result_size);
+		printk(KERN_ERR "valid_size=x%08x\n", hwdescr->valid_size);
+		printk(KERN_ERR "data_status=x%08x\n", hwdescr->data_status);
+		printk(KERN_ERR "data_error=x%08x\n", hwdescr->data_error);
+		printk(KERN_ERR "which=%ld\n", descr - card->rx_chain.ring);
 
 		card->spider_stats.rx_desc_error++;
 		goto bad_desc;
diff -puN drivers/net/spider_net.h~remove-current-defines-and-uses-of-pr_err-add-pr_emerg drivers/net/spider_net.h
--- a/drivers/net/spider_net.h~remove-current-defines-and-uses-of-pr_err-add-pr_emerg
+++ a/drivers/net/spider_net.h
@@ -493,7 +493,4 @@ struct spider_net_card {
 	struct spider_net_descr darray[0];
 };
 
-#define pr_err(fmt,arg...) \
-	printk(KERN_ERR fmt ,##arg)
-
 #endif
diff -puN drivers/video/omap/lcd_h3.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg drivers/video/omap/lcd_h3.c
--- a/drivers/video/omap/lcd_h3.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg
+++ a/drivers/video/omap/lcd_h3.c
@@ -27,8 +27,7 @@
 #include <asm/arch/omapfb.h>
 
 #define MODULE_NAME	"omapfb-lcd_h3"
-
-#define pr_err(fmt, args...) printk(KERN_ERR MODULE_NAME ": " fmt, ## args)
+#define PFX MODULE_NAME ": "
 
 static int h3_panel_init(struct lcd_panel *panel, struct omapfb_device *fbdev)
 {
@@ -48,7 +47,7 @@ static int h3_panel_enable(struct lcd_pa
 	if (!r)
 		r = tps65010_set_gpio_out_value(GPIO2, HIGH);
 	if (r)
-		pr_err("Unable to turn on LCD panel\n");
+		printk(KERN_ERR PFX "Unable to turn on LCD panel\n");
 
 	return r;
 }
@@ -62,7 +61,7 @@ static void h3_panel_disable(struct lcd_
 	if (!r)
 		tps65010_set_gpio_out_value(GPIO2, LOW);
 	if (r)
-		pr_err("Unable to turn off LCD panel\n");
+		printk(KERN_ERR PFX "Unable to turn off LCD panel\n");
 }
 
 static unsigned long h3_panel_get_caps(struct lcd_panel *panel)
diff -puN drivers/video/omap/lcd_inn1610.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg drivers/video/omap/lcd_inn1610.c
--- a/drivers/video/omap/lcd_inn1610.c~remove-current-defines-and-uses-of-pr_err-add-pr_emerg
+++ a/drivers/video/omap/lcd_inn1610.c
@@ -26,8 +26,7 @@
 #include <asm/arch/omapfb.h>
 
 #define MODULE_NAME	"omapfb-lcd_h3"
-
-#define pr_err(fmt, args...) printk(KERN_ERR MODULE_NAME ": " fmt, ## args)
+#define PFX		MODULE_NAME ": "
 
 static int innovator1610_panel_init(struct lcd_panel *panel,
 				    struct omapfb_device *fbdev)
@@ -35,12 +34,12 @@ static int innovator1610_panel_init(stru
 	int r = 0;
 
 	if (omap_request_gpio(14)) {
-		pr_err("can't request GPIO 14\n");
+		printk(KERN_ERR PFX "can't request GPIO 14\n");
 		r = -1;
 		goto exit;
 	}
 	if (omap_request_gpio(15)) {
-		pr_err("can't request GPIO 15\n");
+		printk(KERN_ERR PFX "can't request GPIO 15\n");
 		omap_free_gpio(14);
 		r = -1;
 		goto exit;
diff -puN include/linux/kernel.h~remove-current-defines-and-uses-of-pr_err-add-pr_emerg include/linux/kernel.h
--- a/include/linux/kernel.h~remove-current-defines-and-uses-of-pr_err-add-pr_emerg
+++ a/include/linux/kernel.h
@@ -241,20 +241,24 @@ extern void print_hex_dump_bytes(const c
 			void *buf, size_t len);
 #define hex_asc(x)	"0123456789abcdef"[x]
 
+#define pr_emerg(fmt, arg...)	printk(KERN_EMERG fmt, ##arg)
+#define pr_alert(fmt, arg...)	printk(KERN_ALERT fmt, ##arg)
+#define pr_crit(fmt, arg...)	printk(KERN_CRIT fmt, ##arg)
+#define pr_err(fmt, arg...)	printk(KERN_ERR fmt, ##arg)
+#define pr_warn(fmt, arg...)	printk(KERN_WARNING fmt, ##arg)
+#define pr_notice(fmt, arg...)	printk(KERN_NOTICE fmt, ##arg)
+#define pr_info(fmt, arg...)	printk(KERN_INFO fmt, ##arg)
+
 #ifdef DEBUG
 /* If you are writing a driver, please use dev_dbg instead */
-#define pr_debug(fmt,arg...) \
-	printk(KERN_DEBUG fmt,##arg)
+#define pr_debug(fmt,arg...)	printk(KERN_DEBUG fmt, ##arg)
 #else
-static inline int __attribute__ ((format (printf, 1, 2))) pr_debug(const char * fmt, ...)
+static inline int __attribute__ ((format (printf, 1, 2))) pr_debug(const char *fmt, ...)
 {
 	return 0;
 }
 #endif
 
-#define pr_info(fmt,arg...) \
-	printk(KERN_INFO fmt,##arg)
-
 /*
  *      Display an IP address in readable format.
  */
_

Patches currently in -mm which might be from joe@perches.com are

remove-current-defines-and-uses-of-pr_err-add-pr_emerg.patch