sched: restore sanity

sched: restore sanity

[Peter Zijlstra]

Revert the braindead pr_* crap.

it's dumb and causes stupid "sched: " strings all over the place.

---
 kernel/sched.c          |   89 ++++++++++++++++++++++++++---------------------
 kernel/sched_idletask.c |    2 +-
 2 files changed, 50 insertions(+), 41 deletions(-)

diff --git a/kernel/sched.c b/kernel/sched.c
index 720df10..7ffde2a 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -26,8 +26,6 @@
  *              Thomas Gleixner, Mike Kravetz
  */
 
-#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
-
 #include <linux/mm.h>
 #include <linux/module.h>
 #include <linux/nmi.h>
@@ -5375,8 +5373,8 @@ static noinline void __schedule_bug(struct task_struct *prev)
 {
 	struct pt_regs *regs = get_irq_regs();
 
-	pr_err("BUG: scheduling while atomic: %s/%d/0x%08x\n",
-	       prev->comm, prev->pid, preempt_count());
+	printk(KERN_ERR "BUG: scheduling while atomic: %s/%d/0x%08x\n",
+		prev->comm, prev->pid, preempt_count());
 
 	debug_show_held_locks(prev);
 	print_modules();
@@ -6940,23 +6938,23 @@ void sched_show_task(struct task_struct *p)
 	unsigned state;
 
 	state = p->state ? __ffs(p->state) + 1 : 0;
-	pr_info("%-13.13s %c", p->comm,
+	printk(KERN_INFO "%-13.13s %c", p->comm,
 		state < sizeof(stat_nam) - 1 ? stat_nam[state] : '?');
 #if BITS_PER_LONG == 32
 	if (state == TASK_RUNNING)
-		pr_cont(" running  ");
+		printk(KERN_CONT " running  ");
 	else
-		pr_cont(" %08lx ", thread_saved_pc(p));
+		printk(KERN_CONT " %08lx ", thread_saved_pc(p));
 #else
 	if (state == TASK_RUNNING)
-		pr_cont("  running task    ");
+		printk(KERN_CONT "  running task    ");
 	else
-		pr_cont(" %016lx ", thread_saved_pc(p));
+		printk(KERN_CONT " %016lx ", thread_saved_pc(p));
 #endif
 #ifdef CONFIG_DEBUG_STACK_USAGE
 	free = stack_not_used(p);
 #endif
-	pr_cont("%5lu %5d %6d 0x%08lx\n", free,
+	printk(KERN_CONT "%5lu %5d %6d 0x%08lx\n", free,
 		task_pid_nr(p), task_pid_nr(p->real_parent),
 		(unsigned long)task_thread_info(p)->flags);
 
@@ -6968,9 +6966,11 @@ void show_state_filter(unsigned long state_filter)
 	struct task_struct *g, *p;
 
 #if BITS_PER_LONG == 32
-	pr_info("  task                PC stack   pid father\n");
+	printk(KERN_INFO
+		"  task                PC stack   pid father\n");
 #else
-	pr_info("  task                        PC stack   pid father\n");
+	printk(KERN_INFO
+		"  task                        PC stack   pid father\n");
 #endif
 	read_lock(&tasklist_lock);
 	do_each_thread(g, p) {
@@ -7828,44 +7828,48 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
 	printk(KERN_DEBUG "%*s domain %d: ", level, "", level);
 
 	if (!(sd->flags & SD_LOAD_BALANCE)) {
-		pr_cont("does not load-balance\n");
+		printk("does not load-balance\n");
 		if (sd->parent)
-			pr_err("ERROR: !SD_LOAD_BALANCE domain has parent\n");
+			printk(KERN_ERR "ERROR: !SD_LOAD_BALANCE domain"
+					" has parent");
 		return -1;
 	}
 
-	pr_cont("span %s level %s\n", str, sd->name);
+	printk(KERN_CONT "span %s level %s\n", str, sd->name);
 
 	if (!cpumask_test_cpu(cpu, sched_domain_span(sd))) {
-		pr_err("ERROR: domain->span does not contain CPU%d\n", cpu);
+		printk(KERN_ERR "ERROR: domain->span does not contain "
+				"CPU%d\n", cpu);
 	}
 	if (!cpumask_test_cpu(cpu, sched_group_cpus(group))) {
-		pr_err("ERROR: domain->groups does not contain CPU%d\n", cpu);
+		printk(KERN_ERR "ERROR: domain->groups does not contain"
+				" CPU%d\n", cpu);
 	}
 
 	printk(KERN_DEBUG "%*s groups:", level + 1, "");
 	do {
 		if (!group) {
-			pr_cont("\n");
-			pr_err("ERROR: group is NULL\n");
+			printk("\n");
+			printk(KERN_ERR "ERROR: group is NULL\n");
 			break;
 		}
 
 		if (!group->cpu_power) {
-			pr_cont("\n");
-			pr_err("ERROR: domain->cpu_power not set\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: domain->cpu_power not "
+					"set\n");
 			break;
 		}
 
 		if (!cpumask_weight(sched_group_cpus(group))) {
-			pr_cont("\n");
-			pr_err("ERROR: empty group\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: empty group\n");
 			break;
 		}
 
 		if (cpumask_intersects(groupmask, sched_group_cpus(group))) {
-			pr_cont("\n");
-			pr_err("ERROR: repeated CPUs\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: repeated CPUs\n");
 			break;
 		}
 
@@ -7873,21 +7877,23 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
 
 		cpulist_scnprintf(str, sizeof(str), sched_group_cpus(group));
 
-		pr_cont(" %s", str);
+		printk(KERN_CONT " %s", str);
 		if (group->cpu_power != SCHED_LOAD_SCALE) {
-			pr_cont(" (cpu_power = %d)", group->cpu_power);
+			printk(KERN_CONT " (cpu_power = %d)",
+				group->cpu_power);
 		}
 
 		group = group->next;
 	} while (group != sd->groups);
-	pr_cont("\n");
+	printk(KERN_CONT "\n");
 
 	if (!cpumask_equal(sched_domain_span(sd), groupmask))
-		pr_err("ERROR: groups don't span domain->span\n");
+		printk(KERN_ERR "ERROR: groups don't span domain->span\n");
 
 	if (sd->parent &&
 	    !cpumask_subset(groupmask, sched_domain_span(sd->parent)))
-		pr_err("ERROR: parent span is not a superset of domain->span\n");
+		printk(KERN_ERR "ERROR: parent span is not a superset "
+			"of domain->span\n");
 	return 0;
 }
 
@@ -8443,7 +8449,8 @@ static int build_numa_sched_groups(struct s_data *d,
 	sg = kmalloc_node(sizeof(struct sched_group) + cpumask_size(),
 			  GFP_KERNEL, num);
 	if (!sg) {
-		pr_warning("Can not alloc domain group for node %d\n", num);
+		printk(KERN_WARNING "Can not alloc domain group for node %d\n",
+		       num);
 		return -ENOMEM;
 	}
 	d->sched_group_nodes[num] = sg;
@@ -8472,8 +8479,8 @@ static int build_numa_sched_groups(struct s_data *d,
 		sg = kmalloc_node(sizeof(struct sched_group) + cpumask_size(),
 				  GFP_KERNEL, num);
 		if (!sg) {
-			pr_warning("Can not alloc domain group for node %d\n",
-				   j);
+			printk(KERN_WARNING
+			       "Can not alloc domain group for node %d\n", j);
 			return -ENOMEM;
 		}
 		sg->cpu_power = 0;
@@ -8701,7 +8708,7 @@ static enum s_alloc __visit_domain_allocation_hell(struct s_data *d,
 	d->sched_group_nodes = kcalloc(nr_node_ids,
 				      sizeof(struct sched_group *), GFP_KERNEL);
 	if (!d->sched_group_nodes) {
-		pr_warning("Can not alloc sched group node list\n");
+		printk(KERN_WARNING "Can not alloc sched group node list\n");
 		return sa_notcovered;
 	}
 	sched_group_nodes_bycpu[cpumask_first(cpu_map)] = d->sched_group_nodes;
@@ -8718,7 +8725,7 @@ static enum s_alloc __visit_domain_allocation_hell(struct s_data *d,
 		return sa_send_covered;
 	d->rd = alloc_rootdomain();
 	if (!d->rd) {
-		pr_warning("Cannot alloc root domain\n");
+		printk(KERN_WARNING "Cannot alloc root domain\n");
 		return sa_tmpmask;
 	}
 	return sa_rootdomain;
@@ -9700,11 +9707,13 @@ void __might_sleep(char *file, int line, int preempt_offset)
 		return;
 	prev_jiffy = jiffies;
 
-	pr_err("BUG: sleeping function called from invalid context at %s:%d\n",
-	       file, line);
-	pr_err("in_atomic(): %d, irqs_disabled(): %d, pid: %d, name: %s\n",
-	       in_atomic(), irqs_disabled(),
-	       current->pid, current->comm);
+	printk(KERN_ERR
+		"BUG: sleeping function called from invalid context at %s:%d\n",
+			file, line);
+	printk(KERN_ERR
+		"in_atomic(): %d, irqs_disabled(): %d, pid: %d, name: %s\n",
+			in_atomic(), irqs_disabled(),
+			current->pid, current->comm);
 
 	debug_show_held_locks(current);
 	if (irqs_disabled())
diff --git a/kernel/sched_idletask.c b/kernel/sched_idletask.c
index 21b969a..5f93b57 100644
--- a/kernel/sched_idletask.c
+++ b/kernel/sched_idletask.c
@@ -35,7 +35,7 @@ static void
 dequeue_task_idle(struct rq *rq, struct task_struct *p, int sleep)
 {
 	raw_spin_unlock_irq(&rq->lock);
-	pr_err("bad: scheduling from the idle thread!\n");
+	printk(KERN_ERR "bad: scheduling from the idle thread!\n");
 	dump_stack();
 	raw_spin_lock_irq(&rq->lock);
 }

Re: sched: restore sanity

[Arjan van de Ven]

On Sun, 20 Dec 2009 14:23:57 +0100
Peter Zijlstra <peterz@infradead.org> wrote:

> Revert the braindead pr_* crap.
> 
> it's dumb and causes stupid "sched: " strings all over the place.

yes please; this also broke kerneloops.org parsing ;)


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

Re: sched: restore sanity

[Ingo Molnar]

* Peter Zijlstra <peterz@infradead.org> wrote:

> Revert the braindead pr_* crap.
> 
> it's dumb and causes stupid "sched: " strings all over the place.
> 
> ---
>  kernel/sched.c          |   89 ++++++++++++++++++++++++++---------------------
>  kernel/sched_idletask.c |    2 +-
>  2 files changed, 50 insertions(+), 41 deletions(-)
> 
> diff --git a/kernel/sched.c b/kernel/sched.c
> index 720df10..7ffde2a 100644
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -26,8 +26,6 @@
>   *              Thomas Gleixner, Mike Kravetz
>   */
>  
> -#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
> -
>  #include <linux/mm.h>
>  #include <linux/module.h>
>  #include <linux/nmi.h>

that's all that we need to remove i suspect, to get rid of the stupid 
prefixes.

	Ingo

Re: sched: restore sanity

[Peter Zijlstra]

On Sun, 2009-12-20 at 15:49 +0100, Ingo Molnar wrote:
>  
> > -#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt

> that's all that we need to remove i suspect, to get rid of the stupid 
> prefixes.

Probably, but the rest is just as annoying, pr_* is crap.

Re: sched: restore sanity

[San Mehat]

On Sun, Dec 20, 2009 at 7:03 AM, San Mehat <san@google.com> wrote:
>
>
> On Sun, Dec 20, 2009 at 6:51 AM, Peter Zijlstra <peterz@infradead.org> wrote:
>>
>> On Sun, 2009-12-20 at 15:49 +0100, Ingo Molnar wrote:
>> >
>> > > -#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
>>
>> > that's all that we need to remove i suspect, to get rid of the stupid
>> > prefixes.
>>
>> Probably, but the rest is just as annoying, pr_* is crap.
>>
>

Oh? Out of curiosity whats wrong with it?

Apologies for the html broken-ness in my last.

> -san
>
>>
>> --
>> 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/
>
>
>
> --
> ----------
> San Mehat
> Staff Software Engineer
> Google Inc.
> o: 650-253-7422
> c: 408-382-1249
> san@google.com



--
----------
San Mehat
Staff Software Engineer
Google Inc.
o: 650-253-7422
c: 408-382-1249
san@google.com

Re: sched: restore sanity

[Peter Zijlstra]

On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> >> Probably, but the rest is just as annoying, pr_* is crap.

> Oh? Out of curiosity whats wrong with it?

That's what should be asked of printk().

And as long as we're not going to depricate printk() -- any attempt
thereof will meet with fierce resistance from yours truly -- its all a
futile exercise at best, and breaking scripts habits and patches at
worst.

I might be strange, but if I want to print something in C I write
print[fk]() and be done with it, there's no reason what so ever to
introduce fancy wankery for this.

We try to stick to ANSI-C as much as possible, we've got
kalloc,kfree,strcmp,strnlen and all the other 'regular' C bits,
deviating from that serves no purpose but seed confusion.

If driver folks feel the need for dumb-ass wrappers because they can't
write printk() then maybe, otoh if they can't do that, then wtf are they
doing writing drivers anyway.

But I feel this has no place in the core kernel at all, esp when its
getting in the way of things without offering a single benefit.

Re: sched: restore sanity

[Mike Galbraith]

On Sun, 2009-12-20 at 16:19 +0100, Peter Zijlstra wrote:
> On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> > >> Probably, but the rest is just as annoying, pr_* is crap.
> 
> > Oh? Out of curiosity whats wrong with it?
> 
> That's what should be asked of printk().
> 
> And as long as we're not going to depricate printk() -- any attempt
> thereof will meet with fierce resistance from yours truly -- its all a
> futile exercise at best, and breaking scripts habits and patches at
> worst.
> 
> I might be strange, but if I want to print something in C I write
> print[fk]() and be done with it, there's no reason what so ever to
> introduce fancy wankery for this.
> 
> We try to stick to ANSI-C as much as possible, we've got
> kalloc,kfree,strcmp,strnlen and all the other 'regular' C bits,
> deviating from that serves no purpose but seed confusion.
> 
> If driver folks feel the need for dumb-ass wrappers because they can't
> write printk() then maybe, otoh if they can't do that, then wtf are they
> doing writing drivers anyway.
> 
> But I feel this has no place in the core kernel at all, esp when its
> getting in the way of things without offering a single benefit.

FWIW, I agree.

You can have my printk when you pry it from my cold dead fingers ;-)

	-Mike

Re: sched: restore sanity

[San Mehat]

On Sun, Dec 20, 2009 at 7:19 AM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
>> >> Probably, but the rest is just as annoying, pr_* is crap.
>
>> Oh? Out of curiosity whats wrong with it?
>
> That's what should be asked of printk().
>
> And as long as we're not going to depricate printk() -- any attempt
> thereof will meet with fierce resistance from yours truly -- its all a
> futile exercise at best, and breaking scripts habits and patches at
> worst.
>
> I might be strange, but if I want to print something in C I write
> print[fk]() and be done with it, there's no reason what so ever to
> introduce fancy wankery for this.
>
> We try to stick to ANSI-C as much as possible, we've got
> kalloc,kfree,strcmp,strnlen and all the other 'regular' C bits,
> deviating from that serves no purpose but seed confusion.
>

Fair enough, thanks for the clarification.

-san

> If driver folks feel the need for dumb-ass wrappers because they can't
> write printk() then maybe, otoh if they can't do that, then wtf are they
> doing writing drivers anyway.
>
> But I feel this has no place in the core kernel at all, esp when its
> getting in the way of things without offering a single benefit.
>
>
>
>



-- 
----------
San Mehat
Staff Software Engineer
Google Inc.
o: 650-253-7422
c: 408-382-1249
san@google.com

Re: sched: restore sanity

[Joe Perches]

On Sun, 2009-12-20 at 16:19 +0100, Peter Zijlstra wrote:
> On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> > >> Probably, but the rest is just as annoying, pr_* is crap.
> > Oh? Out of curiosity whats wrong with it?
> That's what should be asked of printk().

pr_<level> offers some things printk cannot:

o standardization, eliminates frequent missing KERN_ levels
  and missing/typo/misspelled module prefixes  
o visually shorter, fewer chars used, less 80 char wrapping
o finer grained ability to eliminate unnecessary messages
  for embedded systems
o standardized mechanism to prefix messages with module/function
o eventual code reduction via use of a singleton instead of
  duplicated module/function names
o eventual dynamic_debug styled control of prefix by
  module/function

There are quite of number of arbitrarily named module wrapper
macros and functions that build on printk.

Standardizing them around a fewer number of prefixes would
ease grepping for logging.

A standardized logging function to filter messages by
bitmask or level could also be useful. 

> We try to stick to ANSI-C as much as possible, we've got
> kalloc,kfree,strcmp,strnlen and all the other 'regular' C bits,
> deviating from that serves no purpose but seed confusion.

There is a lot of kernel code that isn't 'regular' C.

Nothing in pr_<level> is not ANSI-C, it just builds on printk.

> But I feel this has no place in the core kernel at all, esp when its
> getting in the way of things without offering a single benefit.

What are the negatives of using pr_<level>?

Re: sched: restore sanity

[Peter Zijlstra]

On Sun, 2009-12-20 at 09:22 -0800, Joe Perches wrote:
> On Sun, 2009-12-20 at 16:19 +0100, Peter Zijlstra wrote:
> > On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> > > >> Probably, but the rest is just as annoying, pr_* is crap.
> > > Oh? Out of curiosity whats wrong with it?
> > That's what should be asked of printk().
> 
> pr_<level> offers some things printk cannot:
> 
> o standardization, eliminates frequent missing KERN_ levels
>   and missing/typo/misspelled module prefixes  

There's other ways of fixing that, one way is to make it a proper
function argument, like:

printk(char level, char *fmt, ...);

Which is something we have precedent for too in fprintf() and syslog().

> o visually shorter, fewer chars used, less 80 char wrapping

Fuck me senseless, visually less obvious too.

> o finer grained ability to eliminate unnecessary messages
>   for embedded systems

How is that not possible with another solution.

> o standardized mechanism to prefix messages with module/function

Who fucking gives a shit, that is the very thing that made me send the
revert.

> o eventual code reduction via use of a singleton instead of
>   duplicated module/function names

text reduction?

> o eventual dynamic_debug styled control of prefix by
>   module/function

Feh, who cares, printk output simply shouldn't be frequent enough to
need filtering, there's much better solutions for that.

> There are quite of number of arbitrarily named module wrapper
> macros and functions that build on printk.

Then remove them all..

Are you really arguing to fully deprecate printk()? If not this is all
going to be useless since I'll simply keep using printk().

Re: sched: restore sanity

[Ingo Molnar]

* Peter Zijlstra <peterz@infradead.org> wrote:

> On Sun, 2009-12-20 at 09:22 -0800, Joe Perches wrote:
> > On Sun, 2009-12-20 at 16:19 +0100, Peter Zijlstra wrote:
> > > On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> > > > >> Probably, but the rest is just as annoying, pr_* is crap.
> > > > Oh? Out of curiosity whats wrong with it?
> > > That's what should be asked of printk().
> > 
> > pr_<level> offers some things printk cannot:
> > 
> > o standardization, eliminates frequent missing KERN_ levels
> >   and missing/typo/misspelled module prefixes  
> 
> There's other ways of fixing that, one way is to make it a proper
> function argument, like:
> 
> printk(char level, char *fmt, ...);
> 
> Which is something we have precedent for too in fprintf() and syslog().
> 
> > o visually shorter, fewer chars used, less 80 char wrapping
> 
> Fuck me senseless, visually less obvious too.
> 
> > o finer grained ability to eliminate unnecessary messages
> >   for embedded systems
> 
> How is that not possible with another solution.
> 
> > o standardized mechanism to prefix messages with module/function
> 
> Who fucking gives a shit, that is the very thing that made me send the
> revert.
> 
> > o eventual code reduction via use of a singleton instead of
> >   duplicated module/function names
> 
> text reduction?
> 
> > o eventual dynamic_debug styled control of prefix by
> >   module/function
> 
> Feh, who cares, printk output simply shouldn't be frequent enough to
> need filtering, there's much better solutions for that.
> 
> > There are quite of number of arbitrarily named module wrapper
> > macros and functions that build on printk.
> 
> Then remove them all..
> 
> Are you really arguing to fully deprecate printk()? If not this is all
> going to be useless since I'll simply keep using printk().

I dont mind that strongly but you (and Mike) objecting to it so forcefully 
clearly tips the balance against the pr_*() lines in sched.c so i've queued up 
your revert in the scheduler tree.

( I've Cc:-ed Linus and Andrew, in case they care one way or another. )

Thanks,

	Ingo

Re: sched: restore sanity

[Joe Perches]

On Sun, 2009-12-20 at 18:36 +0100, Peter Zijlstra wrote:
> On Sun, 2009-12-20 at 09:22 -0800, Joe Perches wrote:
> > On Sun, 2009-12-20 at 16:19 +0100, Peter Zijlstra wrote:
> > > On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> > > > >> Probably, but the rest is just as annoying, pr_* is crap.
> > > > Oh? Out of curiosity whats wrong with it?
> > > That's what should be asked of printk().
> > pr_<level> offers some things printk cannot:
> > o standardization, eliminates frequent missing KERN_ levels
> >   and missing/typo/misspelled module prefixes  
> printk(char level, char *fmt, ...);

A change that's not possible without breaking the build of
one rather large body of code.

> Which is something we have precedent for too in fprintf() and syslog().

Huh?  Did that break builds?

> > o finer grained ability to eliminate unnecessary messages
> >   for embedded systems
> How is that not possible with another solution.

printk is not selective.  printk always compiles all
messages, pr_debug eliminates to nothing without DEBUG.
Similar mechanisms are possible for arbitrary pr_<level>.

> > o standardized mechanism to prefix messages with module/function
> Who fucking gives a shit

Apparently the people that prefix.

There are an awful lot of printks with __func__ or
embedded typed function names that I think are senseless.

I think it'd be much more sensible to have some
per module_printk_flags field that controlled whether
or not module/function/line was emitted.

I'm trying to get rid of them slowly and generically.

> > o eventual code reduction via use of a singleton instead of
> >   duplicated module/function names
> text reduction?

Yes.

> > o eventual dynamic_debug styled control of prefix by
> >   module/function
> Feh, who cares, printk output simply shouldn't be frequent enough to
> need filtering, there's much better solutions for that.

You could name those solutions.

> > There are quite of number of arbitrarily named module wrapper
> > macros and functions that build on printk.
> Then remove them all..
> Are you really arguing to fully deprecate printk()?

I think pr_<level> is a better use.
It's too early to deprecate printk though.

> If not this is all
> going to be useless since I'll simply keep using printk().

I didn't suggest you shouldn't.  Use what works for you.

Re: sched: restore sanity

[Ingo Molnar]

* Joe Perches <joe@perches.com> wrote:

> On Sun, 2009-12-20 at 16:19 +0100, Peter Zijlstra wrote:
> > On Sun, 2009-12-20 at 07:05 -0800, San Mehat wrote:
> > > >> Probably, but the rest is just as annoying, pr_* is crap.
> > > Oh? Out of curiosity whats wrong with it?
> > That's what should be asked of printk().
> 
> pr_<level> offers some things printk cannot:
> 
> o standardization, eliminates frequent missing KERN_ levels
>   and missing/typo/misspelled module prefixes  
> o visually shorter, fewer chars used, less 80 char wrapping
> o finer grained ability to eliminate unnecessary messages
>   for embedded systems
> o standardized mechanism to prefix messages with module/function
> o eventual code reduction via use of a singleton instead of
>   duplicated module/function names
> o eventual dynamic_debug styled control of prefix by
>   module/function

These are pretty marginal advantages - borderline not worth the resulting 
churn. But borderline good patch is still a good patch in my book so i applied 
it. Btw., i wish you mixed with real kernel code too instead of going down the 
Bunk path. That would reduce such friction substantially IMO - people would 
see that you are willing to do (and capable of doing) the harder stuff too.

Thanks,

	Ingo

Re: sched: restore sanity

[Arjan van de Ven]

On Sun, 20 Dec 2009 09:22:23 -0800
Joe Perches <joe@perches.com> wrote:

> What are the negatives of using pr_<level>?

pr_ is really just for "I am a driver and want a single line message
out in a standardized format".
Nothing wrong with that.

But here you are changing fundamental kernel outputs in the style of an
oops message. Multiline, complex and machine parsed things...


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

Re: sched: restore sanity

[Joe Perches]

On Sun, 2009-12-20 at 19:17 +0100, Arjan van de Ven wrote:
> On Sun, 20 Dec 2009 09:22:23 -0800 Joe Perches <joe@perches.com> wrote:
> > What are the negatives of using pr_<level>?
> pr_ is really just for "I am a driver and want a single line message
> out in a standardized format".
> Nothing wrong with that.
> 
> But here you are changing fundamental kernel outputs in the style of an
> oops message. Multiline, complex and machine parsed things...

The prefixing was trivial to change.
No other output was modified.

I believe kernel log output is specifically _not_ guaranteed
and should not be so guaranteed to remain stable across
versions.

Re: sched: restore sanity

[Arjan van de Ven]

On Sun, 20 Dec 2009 10:21:50 -0800
Joe Perches <joe@perches.com> wrote:

> On Sun, 2009-12-20 at 19:17 +0100, Arjan van de Ven wrote:
> > On Sun, 20 Dec 2009 09:22:23 -0800 Joe Perches <joe@perches.com>
> > wrote:
> > > What are the negatives of using pr_<level>?
> > pr_ is really just for "I am a driver and want a single line message
> > out in a standardized format".
> > Nothing wrong with that.
> > 
> > But here you are changing fundamental kernel outputs in the style
> > of an oops message. Multiline, complex and machine parsed things...
> 
> The prefixing was trivial to change.
> No other output was modified.

but you still have a "multiline message" (the atomic schedule oops like
dump) that now is half printk half pr_*... where pr_ is just a silly
wrapper around printk now that the prefixing etc is gone.

> 
> I believe kernel log output is specifically _not_ guaranteed
> and should not be so guaranteed to remain stable across
> versions.

changing it gratuitously is bad though. There *are* scripts out there
parsing oopses. Yes they change as kernels change, but changing
the output of oopses for silly reasons is just hostile 

> 
> 


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

Re: sched: restore sanity

[Joe Perches]

On Mon, 2009-12-21 at 01:48 +0100, Arjan van de Ven wrote:
> but you still have a "multiline message" (the atomic schedule oops like
> dump) that now is half printk half pr_*... where pr_ is just a silly
> wrapper around printk now that the prefixing etc is gone.

Nope.  That's what pr_cont does.

There could be some extension that does a better job
of avoiding multiple process message interleaving.

> > I believe kernel log output is specifically _not_ guaranteed
> > and should not be so guaranteed to remain stable across
> > versions.
> 
> changing it gratuitously is bad though. There *are* scripts out there
> parsing oopses. Yes they change as kernels change, but changing
> the output of oopses for silly reasons is just hostile 

Yup.  sched should have not had pr_fmt defined.
oh well.

Re: sched: restore sanity

[Al Viro]

On Sun, Dec 20, 2009 at 09:22:23AM -0800, Joe Perches wrote:

> pr_<level> offers some things printk cannot:
> 
> o standardization, eliminates frequent missing KERN_ levels
>   and missing/typo/misspelled module prefixes  
> o visually shorter, fewer chars used, less 80 char wrapping
> o finer grained ability to eliminate unnecessary messages
>   for embedded systems
> o standardized mechanism to prefix messages with module/function
> o eventual code reduction via use of a singleton instead of
>   duplicated module/function names
> o eventual dynamic_debug styled control of prefix by
>   module/function

o leveraging the synergy between make-work job and commit count masturbation

Re: sched: restore sanity

[Joe Perches]

On Sun, 2009-12-20 at 15:49 +0100, Ingo Molnar wrote:
> * Peter Zijlstra <peterz@infradead.org> wrote:
> > Revert the braindead pr_* crap.
> > it's dumb and causes stupid "sched: " strings all over the place.
> > -#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
> > -
> >  #include <linux/mm.h>
> >  #include <linux/module.h>
> >  #include <linux/nmi.h>
> 
> that's all that we need to remove i suspect, to get rid of the stupid 
> prefixes.

True.

[tip:sched/urgent] sched: Restore printk sanity

[tip-bot for Peter Zijlstra]

Commit-ID:  6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
Gitweb:     http://git.kernel.org/tip/6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
Author:     Peter Zijlstra <peterz@infradead.org>
AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
Committer:  Ingo Molnar <mingo@elte.hu>
CommitDate: Sun, 20 Dec 2009 18:45:57 +0100

sched: Restore printk sanity

Revert the braindead pr_* crap. (Commit 663997d "sched: Use
pr_fmt() and pr_<level>()")

It's dumb and causes stupid "sched: " strings all over the place.

Signed-off-by: Peter Zijlstra <peterz@infradead.org>
Acked-by: Mike Galbraith <efault@gmx.de>
Cc: Joe Perches <joe@perches.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
LKML-Reference: <1261315437.4314.6.camel@laptop>
[ i dont mind the pr_*() patterns that much - but Peter dislikes them with a vengence. ]
Signed-off-by: Ingo Molnar <mingo@elte.hu>
--
 kernel/sched.c          |   89 ++++++++++++++++++++++++++----------------------
 kernel/sched_idletask.c |    2 -
 2 files changed, 50 insertions(+), 41 deletions(-)
---
 kernel/sched.c          |   89 ++++++++++++++++++++++++++---------------------
 kernel/sched_idletask.c |    2 +-
 2 files changed, 50 insertions(+), 41 deletions(-)

diff --git a/kernel/sched.c b/kernel/sched.c
index 720df10..7ffde2a 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -26,8 +26,6 @@
  *              Thomas Gleixner, Mike Kravetz
  */
 
-#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
-
 #include <linux/mm.h>
 #include <linux/module.h>
 #include <linux/nmi.h>
@@ -5375,8 +5373,8 @@ static noinline void __schedule_bug(struct task_struct *prev)
 {
 	struct pt_regs *regs = get_irq_regs();
 
-	pr_err("BUG: scheduling while atomic: %s/%d/0x%08x\n",
-	       prev->comm, prev->pid, preempt_count());
+	printk(KERN_ERR "BUG: scheduling while atomic: %s/%d/0x%08x\n",
+		prev->comm, prev->pid, preempt_count());
 
 	debug_show_held_locks(prev);
 	print_modules();
@@ -6940,23 +6938,23 @@ void sched_show_task(struct task_struct *p)
 	unsigned state;
 
 	state = p->state ? __ffs(p->state) + 1 : 0;
-	pr_info("%-13.13s %c", p->comm,
+	printk(KERN_INFO "%-13.13s %c", p->comm,
 		state < sizeof(stat_nam) - 1 ? stat_nam[state] : '?');
 #if BITS_PER_LONG == 32
 	if (state == TASK_RUNNING)
-		pr_cont(" running  ");
+		printk(KERN_CONT " running  ");
 	else
-		pr_cont(" %08lx ", thread_saved_pc(p));
+		printk(KERN_CONT " %08lx ", thread_saved_pc(p));
 #else
 	if (state == TASK_RUNNING)
-		pr_cont("  running task    ");
+		printk(KERN_CONT "  running task    ");
 	else
-		pr_cont(" %016lx ", thread_saved_pc(p));
+		printk(KERN_CONT " %016lx ", thread_saved_pc(p));
 #endif
 #ifdef CONFIG_DEBUG_STACK_USAGE
 	free = stack_not_used(p);
 #endif
-	pr_cont("%5lu %5d %6d 0x%08lx\n", free,
+	printk(KERN_CONT "%5lu %5d %6d 0x%08lx\n", free,
 		task_pid_nr(p), task_pid_nr(p->real_parent),
 		(unsigned long)task_thread_info(p)->flags);
 
@@ -6968,9 +6966,11 @@ void show_state_filter(unsigned long state_filter)
 	struct task_struct *g, *p;
 
 #if BITS_PER_LONG == 32
-	pr_info("  task                PC stack   pid father\n");
+	printk(KERN_INFO
+		"  task                PC stack   pid father\n");
 #else
-	pr_info("  task                        PC stack   pid father\n");
+	printk(KERN_INFO
+		"  task                        PC stack   pid father\n");
 #endif
 	read_lock(&tasklist_lock);
 	do_each_thread(g, p) {
@@ -7828,44 +7828,48 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
 	printk(KERN_DEBUG "%*s domain %d: ", level, "", level);
 
 	if (!(sd->flags & SD_LOAD_BALANCE)) {
-		pr_cont("does not load-balance\n");
+		printk("does not load-balance\n");
 		if (sd->parent)
-			pr_err("ERROR: !SD_LOAD_BALANCE domain has parent\n");
+			printk(KERN_ERR "ERROR: !SD_LOAD_BALANCE domain"
+					" has parent");
 		return -1;
 	}
 
-	pr_cont("span %s level %s\n", str, sd->name);
+	printk(KERN_CONT "span %s level %s\n", str, sd->name);
 
 	if (!cpumask_test_cpu(cpu, sched_domain_span(sd))) {
-		pr_err("ERROR: domain->span does not contain CPU%d\n", cpu);
+		printk(KERN_ERR "ERROR: domain->span does not contain "
+				"CPU%d\n", cpu);
 	}
 	if (!cpumask_test_cpu(cpu, sched_group_cpus(group))) {
-		pr_err("ERROR: domain->groups does not contain CPU%d\n", cpu);
+		printk(KERN_ERR "ERROR: domain->groups does not contain"
+				" CPU%d\n", cpu);
 	}
 
 	printk(KERN_DEBUG "%*s groups:", level + 1, "");
 	do {
 		if (!group) {
-			pr_cont("\n");
-			pr_err("ERROR: group is NULL\n");
+			printk("\n");
+			printk(KERN_ERR "ERROR: group is NULL\n");
 			break;
 		}
 
 		if (!group->cpu_power) {
-			pr_cont("\n");
-			pr_err("ERROR: domain->cpu_power not set\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: domain->cpu_power not "
+					"set\n");
 			break;
 		}
 
 		if (!cpumask_weight(sched_group_cpus(group))) {
-			pr_cont("\n");
-			pr_err("ERROR: empty group\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: empty group\n");
 			break;
 		}
 
 		if (cpumask_intersects(groupmask, sched_group_cpus(group))) {
-			pr_cont("\n");
-			pr_err("ERROR: repeated CPUs\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: repeated CPUs\n");
 			break;
 		}
 
@@ -7873,21 +7877,23 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
 
 		cpulist_scnprintf(str, sizeof(str), sched_group_cpus(group));
 
-		pr_cont(" %s", str);
+		printk(KERN_CONT " %s", str);
 		if (group->cpu_power != SCHED_LOAD_SCALE) {
-			pr_cont(" (cpu_power = %d)", group->cpu_power);
+			printk(KERN_CONT " (cpu_power = %d)",
+				group->cpu_power);
 		}
 
 		group = group->next;
 	} while (group != sd->groups);
-	pr_cont("\n");
+	printk(KERN_CONT "\n");
 
 	if (!cpumask_equal(sched_domain_span(sd), groupmask))
-		pr_err("ERROR: groups don't span domain->span\n");
+		printk(KERN_ERR "ERROR: groups don't span domain->span\n");
 
 	if (sd->parent &&
 	    !cpumask_subset(groupmask, sched_domain_span(sd->parent)))
-		pr_err("ERROR: parent span is not a superset of domain->span\n");
+		printk(KERN_ERR "ERROR: parent span is not a superset "
+			"of domain->span\n");
 	return 0;
 }
 
@@ -8443,7 +8449,8 @@ static int build_numa_sched_groups(struct s_data *d,
 	sg = kmalloc_node(sizeof(struct sched_group) + cpumask_size(),
 			  GFP_KERNEL, num);
 	if (!sg) {
-		pr_warning("Can not alloc domain group for node %d\n", num);
+		printk(KERN_WARNING "Can not alloc domain group for node %d\n",
+		       num);
 		return -ENOMEM;
 	}
 	d->sched_group_nodes[num] = sg;
@@ -8472,8 +8479,8 @@ static int build_numa_sched_groups(struct s_data *d,
 		sg = kmalloc_node(sizeof(struct sched_group) + cpumask_size(),
 				  GFP_KERNEL, num);
 		if (!sg) {
-			pr_warning("Can not alloc domain group for node %d\n",
-				   j);
+			printk(KERN_WARNING
+			       "Can not alloc domain group for node %d\n", j);
 			return -ENOMEM;
 		}
 		sg->cpu_power = 0;
@@ -8701,7 +8708,7 @@ static enum s_alloc __visit_domain_allocation_hell(struct s_data *d,
 	d->sched_group_nodes = kcalloc(nr_node_ids,
 				      sizeof(struct sched_group *), GFP_KERNEL);
 	if (!d->sched_group_nodes) {
-		pr_warning("Can not alloc sched group node list\n");
+		printk(KERN_WARNING "Can not alloc sched group node list\n");
 		return sa_notcovered;
 	}
 	sched_group_nodes_bycpu[cpumask_first(cpu_map)] = d->sched_group_nodes;
@@ -8718,7 +8725,7 @@ static enum s_alloc __visit_domain_allocation_hell(struct s_data *d,
 		return sa_send_covered;
 	d->rd = alloc_rootdomain();
 	if (!d->rd) {
-		pr_warning("Cannot alloc root domain\n");
+		printk(KERN_WARNING "Cannot alloc root domain\n");
 		return sa_tmpmask;
 	}
 	return sa_rootdomain;
@@ -9700,11 +9707,13 @@ void __might_sleep(char *file, int line, int preempt_offset)
 		return;
 	prev_jiffy = jiffies;
 
-	pr_err("BUG: sleeping function called from invalid context at %s:%d\n",
-	       file, line);
-	pr_err("in_atomic(): %d, irqs_disabled(): %d, pid: %d, name: %s\n",
-	       in_atomic(), irqs_disabled(),
-	       current->pid, current->comm);
+	printk(KERN_ERR
+		"BUG: sleeping function called from invalid context at %s:%d\n",
+			file, line);
+	printk(KERN_ERR
+		"in_atomic(): %d, irqs_disabled(): %d, pid: %d, name: %s\n",
+			in_atomic(), irqs_disabled(),
+			current->pid, current->comm);
 
 	debug_show_held_locks(current);
 	if (irqs_disabled())
diff --git a/kernel/sched_idletask.c b/kernel/sched_idletask.c
index 21b969a..5f93b57 100644
--- a/kernel/sched_idletask.c
+++ b/kernel/sched_idletask.c
@@ -35,7 +35,7 @@ static void
 dequeue_task_idle(struct rq *rq, struct task_struct *p, int sleep)
 {
 	raw_spin_unlock_irq(&rq->lock);
-	pr_err("bad: scheduling from the idle thread!\n");
+	printk(KERN_ERR "bad: scheduling from the idle thread!\n");
 	dump_stack();
 	raw_spin_lock_irq(&rq->lock);
 }

Re: [tip:sched/urgent] sched: Restore printk sanity

[Geert Uytterhoeven]

On Sun, Dec 20, 2009 at 19:00, tip-bot for Peter Zijlstra
<peterz@infradead.org> wrote:
> Commit-ID:  6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> Gitweb:     http://git.kernel.org/tip/6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> Author:     Peter Zijlstra <peterz@infradead.org>
> AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
> Committer:  Ingo Molnar <mingo@elte.hu>
> CommitDate: Sun, 20 Dec 2009 18:45:57 +0100
>
> sched: Restore printk sanity
>
> Revert the braindead pr_* crap. (Commit 663997d "sched: Use
> pr_fmt() and pr_<level>()")
>
> It's dumb and causes stupid "sched: " strings all over the place.

Isn't it sufficient to just remove the `#define pr_fmt(fmt) ...' line?

Gr{oetje,eeting}s,

						Geert (pr_* fan)

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
							    -- Linus Torvalds

Re: [tip:sched/urgent] sched: Restore printk sanity

[Valdis.Kletnieks]

[-- Attachment #1: Type: text/plain, Size: 447 bytes --]

On Sun, 20 Dec 2009 18:00:38 GMT, tip-bot for Peter Zijlstra said:
> Commit-ID:  6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c

> @@ -7828,44 +7828,48 @@ static int sched_domain_debug_one(struct sched_domain
 *sd, int cpu, int level,
>  	printk(KERN_DEBUG "%*s domain %d: ", level, "", level);
>  
>  	if (!(sd->flags & SD_LOAD_BALANCE)) {
> -		pr_cont("does not load-balance\n");
> +		printk("does not load-balance\n");

printk(KERN_CONT  perhaps?




[-- Attachment #2: Type: application/pgp-signature, Size: 227 bytes --]

Re: [tip:sched/urgent] sched: Restore printk sanity

[Pavel Machek]

On Sun 2009-12-20 18:00:38, tip-bot for Peter Zijlstra wrote:
> Commit-ID:  6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> Gitweb:     http://git.kernel.org/tip/6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> Author:     Peter Zijlstra <peterz@infradead.org>
> AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
> Committer:  Ingo Molnar <mingo@elte.hu>
> CommitDate: Sun, 20 Dec 2009 18:45:57 +0100
> 
> sched: Restore printk sanity
> 
> Revert the braindead pr_* crap. (Commit 663997d "sched: Use
> pr_fmt() and pr_<level>()")
> 
> It's dumb and causes stupid "sched: " strings all over the place.

It seems rest of kernel is moving towards pr_*. just removing the
"sched:" would be better for consistency.

Or alternatively... deprecate pr_*?
									Pavel

-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

Re: [tip:sched/urgent] sched: Restore printk sanity

[Ingo Molnar]

* Pavel Machek <pavel@ucw.cz> wrote:

> On Sun 2009-12-20 18:00:38, tip-bot for Peter Zijlstra wrote:
> > Commit-ID:  6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> > Gitweb:     http://git.kernel.org/tip/6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> > Author:     Peter Zijlstra <peterz@infradead.org>
> > AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
> > Committer:  Ingo Molnar <mingo@elte.hu>
> > CommitDate: Sun, 20 Dec 2009 18:45:57 +0100
> > 
> > sched: Restore printk sanity
> > 
> > Revert the braindead pr_* crap. (Commit 663997d "sched: Use
> > pr_fmt() and pr_<level>()")
> > 
> > It's dumb and causes stupid "sched: " strings all over the place.
> 
> It seems rest of kernel is moving towards pr_*. [...]

Git stats do not agree with you:

 - for every pr_*() line in the kernel source code there's more than 6
   printk's:

     $ git grep '\<pr_' | wc -l
     10861
     $ git grep '\<printk' | wc -l
     61126

 - in the last stable kernel, v2.6.32, still more new printk()s were 
   introduced than pr_*() lines:

     $ git log -p v2.6.31..v2.6.32 | grep '^+.*\<pr_' | wc -l
     2016
     $ git log -p v2.6.31..v2.6.32 | grep '^+.*\<printk' | wc -l
     3531

An estimated completion of the 'conversion' to pr_*() to be in infinite number 
of years.

> [...] just removing the "sched:" would be better for consistency.
> 
> Or alternatively... deprecate pr_*?

Or alternatively, my favorite: let people who write the code use whichever 
variant they prefer.

	Ingo

Re: [tip:sched/urgent] sched: Restore printk sanity

[Valdis.Kletnieks]

[-- Attachment #1: Type: text/plain, Size: 1760 bytes --]

On Fri, 25 Dec 2009 19:45:14 +0100, Ingo Molnar said:

>  - in the last stable kernel, v2.6.32, still more new printk()s were 
>    introduced than pr_*() lines:
> 
>      $ git log -p v2.6.31..v2.6.32 | grep '^+.*\<pr_' | wc -l
>      2016
>      $ git log -p v2.6.31..v2.6.32 | grep '^+.*\<printk' | wc -l
>      3531

Ahem. That's not introduced, that's 'added or modified'.

% git log -p v2.6.31..v2.6.32 | grep -C 5 '^+.*\<pr_' | head
-        * In case of failure continue with no timer. */
+       /* Test if the external timer can be actually used.
+        * In case of failure continue without timer. */
        if (unlikely((stmmac_open_ext_timer(dev, priv->tm)) < 0)) {
-               pr_warning("stmmaceth: cannot attach the HW timer\n");
+               pr_warning("stmmaceth: cannot attach the external timer.\n");
                tmrate = 0;
                priv->tm->freq = 0;
                priv->tm->timer_start = stmmac_no_timer_started;
                priv->tm->timer_stop = stmmac_no_timer_stopped;

Meanwhile, the fact that there's only about a 2-to-1 difference in patches when
there's a 6-to-1 difference in existing code tells me that proportionally,
there is *more* activity with pr_foo variants than printk.

printk:  3531 hits in 61126 uses = 5.7% churn
pr_foo: 2016 hits in 10861 uses = 18.5% churn

The numbers need much deeper analysis to make any sort of real statistical
conclusion here...

> 
> An estimated completion of the 'conversion' to pr_*() to be in infinite numbe
r 
> of years.
> 
> > [...] just removing the "sched:" would be better for consistency.
> > 
> > Or alternatively... deprecate pr_*?
> 
> Or alternatively, my favorite: let people who write the code use whichever 
> variant they prefer.
> 
> 	Ingo


[-- Attachment #2: Type: application/pgp-signature, Size: 227 bytes --]

Re: [tip:sched/urgent] sched: Restore printk sanity

[Ingo Molnar]

* Valdis.Kletnieks@vt.edu <Valdis.Kletnieks@vt.edu> wrote:

> On Fri, 25 Dec 2009 19:45:14 +0100, Ingo Molnar said:
> 
> >  - in the last stable kernel, v2.6.32, still more new printk()s were 
> >    introduced than pr_*() lines:
> > 
> >      $ git log -p v2.6.31..v2.6.32 | grep '^+.*\<pr_' | wc -l
> >      2016
> >      $ git log -p v2.6.31..v2.6.32 | grep '^+.*\<printk' | wc -l
> >      3531
> 
> Ahem. That's not introduced, that's 'added or modified'.

'introduced or modified', yes. In those 5500 lines less than ~20% are 
'modifications' (the rest is newly introduced).

> % git log -p v2.6.31..v2.6.32 | grep -C 5 '^+.*\<pr_' | head
> -        * In case of failure continue with no timer. */
> +       /* Test if the external timer can be actually used.
> +        * In case of failure continue without timer. */
>         if (unlikely((stmmac_open_ext_timer(dev, priv->tm)) < 0)) {
> -               pr_warning("stmmaceth: cannot attach the HW timer\n");
> +               pr_warning("stmmaceth: cannot attach the external timer.\n");
>                 tmrate = 0;
>                 priv->tm->freq = 0;
>                 priv->tm->timer_start = stmmac_no_timer_started;
>                 priv->tm->timer_stop = stmmac_no_timer_stopped;
> 
> Meanwhile, the fact that there's only about a 2-to-1 difference in patches 
> when there's a 6-to-1 difference in existing code tells me that 
> proportionally, there is *more* activity with pr_foo variants than printk.

Yet there's more printks in the kernel than a cycle ago, so without the trend 
changing, we've got an infinite supply of future 'conversion' patches.

> printk:  3531 hits in 61126 uses = 5.7% churn
> pr_foo: 2016 hits in 10861 uses = 18.5% churn

Peter's complaint was precisely that there's a lot of 'churn' for pr_*().

> The numbers need much deeper analysis to make any sort of real statistical 
> conclusion here...

If you are convinced that there's something else going on as well feel free to 
do deeper analysis. So, until some contrary numbers are posted i stay by my 
main conclusions.

Thanks,

	Ingo

Re: [tip:sched/urgent] sched: Restore printk sanity

[Joe Perches]

On Fri, 2009-12-25 at 17:00 +0100, Peter Zijlstra wrote:
> On Fri, 2009-12-25 at 14:26 +0100, Pavel Machek wrote:
> > Or alternatively... deprecate pr_*?
> Seems like a fine idea, here's the patch.
> Happy X-mas ;
> git grep -l "\<pr_" | grep -v "kernel\.h" | while read file; 
> do 
> 	sed -i -e 's/pr_emerg(/printk(KERN_EMERG /g' 	\
> 	    -e 's/pr_alert(/printk(KERN_ALERT /g'	\

A lump of coal for you.

1.3 megabytes?

The sed script doesn't match the patch.

Where pr_fmt is defined, the translations are not correct
and need the additional pr_fmt provided format and args.

Re: [tip:sched/urgent] sched: Restore printk sanity

[Pavel Machek]

On Fri 2009-12-25 17:00:19, Peter Zijlstra wrote:
> On Fri, 2009-12-25 at 14:26 +0100, Pavel Machek wrote:
> 
> > Or alternatively... deprecate pr_*?
> 
> Seems like a fine idea, here's the patch.

Actually... I guess I'd slightly prefer the opposite patch. printk()
has a place for quick hacks, but...

pr_err() 

is way shorter 

printk(KERN_ERR )

and forces you to specify log level. 
									Pavel

-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

[tip:sched/urgent] sched: Restore printk sanity

[tip-bot for Peter Zijlstra]

Commit-ID:  3df0fc5b2e9d8092dcaeb5ae0b6753d85c851d66
Gitweb:     http://git.kernel.org/tip/3df0fc5b2e9d8092dcaeb5ae0b6753d85c851d66
Author:     Peter Zijlstra <peterz@infradead.org>
AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
Committer:  Ingo Molnar <mingo@elte.hu>
CommitDate: Sun, 20 Dec 2009 19:05:02 +0100

sched: Restore printk sanity

Revert the braindead pr_* crap. (Commit 663997d "sched: Use
pr_fmt() and pr_<level>()")

It's dumb and causes stupid "sched: " strings all over the place.

Signed-off-by: Peter Zijlstra <peterz@infradead.org>
Acked-by: Mike Galbraith <efault@gmx.de>
Cc: Joe Perches <joe@perches.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
LKML-Reference: <1261315437.4314.6.camel@laptop>
[ i dont mind the pr_*() patterns that much - but Peter dislikes them with a vengence. ]
[ - v2: remove spurious diffstat from changelog :-/ ]
Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 kernel/sched.c          |   89 ++++++++++++++++++++++++++---------------------
 kernel/sched_idletask.c |    2 +-
 2 files changed, 50 insertions(+), 41 deletions(-)

diff --git a/kernel/sched.c b/kernel/sched.c
index 720df10..7ffde2a 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -26,8 +26,6 @@
  *              Thomas Gleixner, Mike Kravetz
  */
 
-#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
-
 #include <linux/mm.h>
 #include <linux/module.h>
 #include <linux/nmi.h>
@@ -5375,8 +5373,8 @@ static noinline void __schedule_bug(struct task_struct *prev)
 {
 	struct pt_regs *regs = get_irq_regs();
 
-	pr_err("BUG: scheduling while atomic: %s/%d/0x%08x\n",
-	       prev->comm, prev->pid, preempt_count());
+	printk(KERN_ERR "BUG: scheduling while atomic: %s/%d/0x%08x\n",
+		prev->comm, prev->pid, preempt_count());
 
 	debug_show_held_locks(prev);
 	print_modules();
@@ -6940,23 +6938,23 @@ void sched_show_task(struct task_struct *p)
 	unsigned state;
 
 	state = p->state ? __ffs(p->state) + 1 : 0;
-	pr_info("%-13.13s %c", p->comm,
+	printk(KERN_INFO "%-13.13s %c", p->comm,
 		state < sizeof(stat_nam) - 1 ? stat_nam[state] : '?');
 #if BITS_PER_LONG == 32
 	if (state == TASK_RUNNING)
-		pr_cont(" running  ");
+		printk(KERN_CONT " running  ");
 	else
-		pr_cont(" %08lx ", thread_saved_pc(p));
+		printk(KERN_CONT " %08lx ", thread_saved_pc(p));
 #else
 	if (state == TASK_RUNNING)
-		pr_cont("  running task    ");
+		printk(KERN_CONT "  running task    ");
 	else
-		pr_cont(" %016lx ", thread_saved_pc(p));
+		printk(KERN_CONT " %016lx ", thread_saved_pc(p));
 #endif
 #ifdef CONFIG_DEBUG_STACK_USAGE
 	free = stack_not_used(p);
 #endif
-	pr_cont("%5lu %5d %6d 0x%08lx\n", free,
+	printk(KERN_CONT "%5lu %5d %6d 0x%08lx\n", free,
 		task_pid_nr(p), task_pid_nr(p->real_parent),
 		(unsigned long)task_thread_info(p)->flags);
 
@@ -6968,9 +6966,11 @@ void show_state_filter(unsigned long state_filter)
 	struct task_struct *g, *p;
 
 #if BITS_PER_LONG == 32
-	pr_info("  task                PC stack   pid father\n");
+	printk(KERN_INFO
+		"  task                PC stack   pid father\n");
 #else
-	pr_info("  task                        PC stack   pid father\n");
+	printk(KERN_INFO
+		"  task                        PC stack   pid father\n");
 #endif
 	read_lock(&tasklist_lock);
 	do_each_thread(g, p) {
@@ -7828,44 +7828,48 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
 	printk(KERN_DEBUG "%*s domain %d: ", level, "", level);
 
 	if (!(sd->flags & SD_LOAD_BALANCE)) {
-		pr_cont("does not load-balance\n");
+		printk("does not load-balance\n");
 		if (sd->parent)
-			pr_err("ERROR: !SD_LOAD_BALANCE domain has parent\n");
+			printk(KERN_ERR "ERROR: !SD_LOAD_BALANCE domain"
+					" has parent");
 		return -1;
 	}
 
-	pr_cont("span %s level %s\n", str, sd->name);
+	printk(KERN_CONT "span %s level %s\n", str, sd->name);
 
 	if (!cpumask_test_cpu(cpu, sched_domain_span(sd))) {
-		pr_err("ERROR: domain->span does not contain CPU%d\n", cpu);
+		printk(KERN_ERR "ERROR: domain->span does not contain "
+				"CPU%d\n", cpu);
 	}
 	if (!cpumask_test_cpu(cpu, sched_group_cpus(group))) {
-		pr_err("ERROR: domain->groups does not contain CPU%d\n", cpu);
+		printk(KERN_ERR "ERROR: domain->groups does not contain"
+				" CPU%d\n", cpu);
 	}
 
 	printk(KERN_DEBUG "%*s groups:", level + 1, "");
 	do {
 		if (!group) {
-			pr_cont("\n");
-			pr_err("ERROR: group is NULL\n");
+			printk("\n");
+			printk(KERN_ERR "ERROR: group is NULL\n");
 			break;
 		}
 
 		if (!group->cpu_power) {
-			pr_cont("\n");
-			pr_err("ERROR: domain->cpu_power not set\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: domain->cpu_power not "
+					"set\n");
 			break;
 		}
 
 		if (!cpumask_weight(sched_group_cpus(group))) {
-			pr_cont("\n");
-			pr_err("ERROR: empty group\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: empty group\n");
 			break;
 		}
 
 		if (cpumask_intersects(groupmask, sched_group_cpus(group))) {
-			pr_cont("\n");
-			pr_err("ERROR: repeated CPUs\n");
+			printk(KERN_CONT "\n");
+			printk(KERN_ERR "ERROR: repeated CPUs\n");
 			break;
 		}
 
@@ -7873,21 +7877,23 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
 
 		cpulist_scnprintf(str, sizeof(str), sched_group_cpus(group));
 
-		pr_cont(" %s", str);
+		printk(KERN_CONT " %s", str);
 		if (group->cpu_power != SCHED_LOAD_SCALE) {
-			pr_cont(" (cpu_power = %d)", group->cpu_power);
+			printk(KERN_CONT " (cpu_power = %d)",
+				group->cpu_power);
 		}
 
 		group = group->next;
 	} while (group != sd->groups);
-	pr_cont("\n");
+	printk(KERN_CONT "\n");
 
 	if (!cpumask_equal(sched_domain_span(sd), groupmask))
-		pr_err("ERROR: groups don't span domain->span\n");
+		printk(KERN_ERR "ERROR: groups don't span domain->span\n");
 
 	if (sd->parent &&
 	    !cpumask_subset(groupmask, sched_domain_span(sd->parent)))
-		pr_err("ERROR: parent span is not a superset of domain->span\n");
+		printk(KERN_ERR "ERROR: parent span is not a superset "
+			"of domain->span\n");
 	return 0;
 }
 
@@ -8443,7 +8449,8 @@ static int build_numa_sched_groups(struct s_data *d,
 	sg = kmalloc_node(sizeof(struct sched_group) + cpumask_size(),
 			  GFP_KERNEL, num);
 	if (!sg) {
-		pr_warning("Can not alloc domain group for node %d\n", num);
+		printk(KERN_WARNING "Can not alloc domain group for node %d\n",
+		       num);
 		return -ENOMEM;
 	}
 	d->sched_group_nodes[num] = sg;
@@ -8472,8 +8479,8 @@ static int build_numa_sched_groups(struct s_data *d,
 		sg = kmalloc_node(sizeof(struct sched_group) + cpumask_size(),
 				  GFP_KERNEL, num);
 		if (!sg) {
-			pr_warning("Can not alloc domain group for node %d\n",
-				   j);
+			printk(KERN_WARNING
+			       "Can not alloc domain group for node %d\n", j);
 			return -ENOMEM;
 		}
 		sg->cpu_power = 0;
@@ -8701,7 +8708,7 @@ static enum s_alloc __visit_domain_allocation_hell(struct s_data *d,
 	d->sched_group_nodes = kcalloc(nr_node_ids,
 				      sizeof(struct sched_group *), GFP_KERNEL);
 	if (!d->sched_group_nodes) {
-		pr_warning("Can not alloc sched group node list\n");
+		printk(KERN_WARNING "Can not alloc sched group node list\n");
 		return sa_notcovered;
 	}
 	sched_group_nodes_bycpu[cpumask_first(cpu_map)] = d->sched_group_nodes;
@@ -8718,7 +8725,7 @@ static enum s_alloc __visit_domain_allocation_hell(struct s_data *d,
 		return sa_send_covered;
 	d->rd = alloc_rootdomain();
 	if (!d->rd) {
-		pr_warning("Cannot alloc root domain\n");
+		printk(KERN_WARNING "Cannot alloc root domain\n");
 		return sa_tmpmask;
 	}
 	return sa_rootdomain;
@@ -9700,11 +9707,13 @@ void __might_sleep(char *file, int line, int preempt_offset)
 		return;
 	prev_jiffy = jiffies;
 
-	pr_err("BUG: sleeping function called from invalid context at %s:%d\n",
-	       file, line);
-	pr_err("in_atomic(): %d, irqs_disabled(): %d, pid: %d, name: %s\n",
-	       in_atomic(), irqs_disabled(),
-	       current->pid, current->comm);
+	printk(KERN_ERR
+		"BUG: sleeping function called from invalid context at %s:%d\n",
+			file, line);
+	printk(KERN_ERR
+		"in_atomic(): %d, irqs_disabled(): %d, pid: %d, name: %s\n",
+			in_atomic(), irqs_disabled(),
+			current->pid, current->comm);
 
 	debug_show_held_locks(current);
 	if (irqs_disabled())
diff --git a/kernel/sched_idletask.c b/kernel/sched_idletask.c
index 21b969a..5f93b57 100644
--- a/kernel/sched_idletask.c
+++ b/kernel/sched_idletask.c
@@ -35,7 +35,7 @@ static void
 dequeue_task_idle(struct rq *rq, struct task_struct *p, int sleep)
 {
 	raw_spin_unlock_irq(&rq->lock);
-	pr_err("bad: scheduling from the idle thread!\n");
+	printk(KERN_ERR "bad: scheduling from the idle thread!\n");
 	dump_stack();
 	raw_spin_lock_irq(&rq->lock);
 }

Re: [tip:sched/urgent] sched: Restore printk sanity

[Joe Perches]

On Sun, 2009-12-20 at 18:06 +0000, tip-bot for Peter Zijlstra wrote:
> diff --git a/kernel/sched.c b/kernel/sched.c
> index 720df10..7ffde2a 100644
> --- a/kernel/sched.c
> +++ b/kernel/sched.c
> @@ -7828,44 +7828,48 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
>  	printk(KERN_DEBUG "%*s domain %d: ", level, "", level);
>  
>  	if (!(sd->flags & SD_LOAD_BALANCE)) {
> -		pr_cont("does not load-balance\n");
> +		printk("does not load-balance\n");
>  		if (sd->parent)
> -			pr_err("ERROR: !SD_LOAD_BALANCE domain has parent\n");
> +			printk(KERN_ERR "ERROR: !SD_LOAD_BALANCE domain"
> +					" has parent");

Missing a trailing \n.

Re: [tip:sched/urgent] sched: Restore printk sanity

[Ingo Molnar]

* Joe Perches <joe@perches.com> wrote:

> On Sun, 2009-12-20 at 18:06 +0000, tip-bot for Peter Zijlstra wrote:
> > diff --git a/kernel/sched.c b/kernel/sched.c
> > index 720df10..7ffde2a 100644
> > --- a/kernel/sched.c
> > +++ b/kernel/sched.c
> > @@ -7828,44 +7828,48 @@ static int sched_domain_debug_one(struct sched_domain *sd, int cpu, int level,
> >  	printk(KERN_DEBUG "%*s domain %d: ", level, "", level);
> >  
> >  	if (!(sd->flags & SD_LOAD_BALANCE)) {
> > -		pr_cont("does not load-balance\n");
> > +		printk("does not load-balance\n");
> >  		if (sd->parent)
> > -			pr_err("ERROR: !SD_LOAD_BALANCE domain has parent\n");
> > +			printk(KERN_ERR "ERROR: !SD_LOAD_BALANCE domain"
> > +					" has parent");
> 
> Missing a trailing \n.

It's also needlessly broken mid-string. Checkpatch should warn about printk 
lines that end with a '"', those are almost always a sign of some ill-advised 
break-the-string artifact.

	Ingo

[PATCH] scripts/checkpatch.pl: Add WARN on printk format split on multiple lines

[Joe Perches]

On Sun, 2009-12-20 at 20:15 +0100, Ingo Molnar wrote:
> Checkpatch should warn about printk 
> lines that end with a '"', those are almost always a sign of some ill-advised 
> break-the-string artifact.

Perhaps something like this:

diff from Andy Whitcroft's testing script,
where logFunctions is defined.
http://www.kernel.org/pub/linux/kernel/people/apw/checkpatch/checkpatch.pl-testing

--- a/scripts/checkpatch.pl-testing	2009-12-20 11:35:28.000000000 -0800
+++ b/scripts/checkpatch.pl-testing	2009-12-20 11:35:46.000000000 -0800
@@ -1398,6 +1398,11 @@
 			WARN("line over 80 characters\n" . $herecurr);
 		}
 
+#Logging function format split over multiple lines
+		if ($line =~ /^\+\s*$logFunctions.*"\s*$/) {
+			WARN("Don't split logging function format\n" . $herecurr);
+		}
+
 # check for adding lines without a newline.
 		if ($line =~ /^\+/ && defined $lines[$linenr] && $lines[$linenr] =~ /^\\ No newline at end of file/) {
 			WARN("adding a line without newline at end of file\n" . $herecurr);

Re: [PATCH] scripts/checkpatch.pl: Add WARN on printk format split on multiple lines

[Ingo Molnar]

* Joe Perches <joe@perches.com> wrote:

> On Sun, 2009-12-20 at 20:15 +0100, Ingo Molnar wrote:
> > Checkpatch should warn about printk 
> > lines that end with a '"', those are almost always a sign of some ill-advised 
> > break-the-string artifact.
> 
> Perhaps something like this:
> 
> diff from Andy Whitcroft's testing script,
> where logFunctions is defined.
> http://www.kernel.org/pub/linux/kernel/people/apw/checkpatch/checkpatch.pl-testing
> 
> --- a/scripts/checkpatch.pl-testing	2009-12-20 11:35:28.000000000 -0800
> +++ b/scripts/checkpatch.pl-testing	2009-12-20 11:35:46.000000000 -0800
> @@ -1398,6 +1398,11 @@
>  			WARN("line over 80 characters\n" . $herecurr);
>  		}
>  
> +#Logging function format split over multiple lines
> +		if ($line =~ /^\+\s*$logFunctions.*"\s*$/) {
> +			WARN("Don't split logging function format\n" . $herecurr);
> +		}
> +

Havent tested it but this check would be lovely to have.

Acked-by: Ingo Molnar <mingo@elte.hu>

	Ingo

Re: [tip:sched/urgent] sched: Restore printk sanity

[tytso]

On Sun, Dec 20, 2009 at 08:15:31PM +0100, Ingo Molnar wrote:
> 
> It's also needlessly broken mid-string. Checkpatch should warn about printk 
> lines that end with a '"', those are almost always a sign of some ill-advised 
> break-the-string artifact.

Ironic, given that for a long time checkpatch strongly encouraged
people to do this with its "line too long" complaint.  Maybe all
printk's should be exempted from this, or at least if it's the format
string which is breaking whatever the magic boundary happens to be?

Even if we up the limit to 106, or 132, or whatever, I can imagine
situations where it will be *impossible* to shut up checkpatch.
Either it will bitch and moan about the line being too long, or it
will bitch and moan that a format string has been broken across
multiple lines.  :-(

					- Ted

Re: [tip:sched/urgent] sched: Restore printk sanity

[Joe Perches]

On Sun, 2009-12-20 at 17:12 -0500, tytso@mit.edu wrote:
> Maybe all
> printk's should be exempted from this, or at least if it's the format
> string which is breaking whatever the magic boundary happens to be?

If ever Andy Whitcroft gets 'round to releasing the
latest checkpatch from testing, the formats of
logging functions are exempted from long line checks.