2009-12-20 13:24:37

by Peter Zijlstra

[permalink] [raw]
Subject: sched: restore sanity

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);
}


2009-12-20 14:25:20

by Arjan van de Ven

[permalink] [raw]
Subject: Re: sched: restore sanity

On Sun, 20 Dec 2009 14:23:57 +0100
Peter Zijlstra <[email protected]> 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

2009-12-20 14:49:37

by Ingo Molnar

[permalink] [raw]
Subject: Re: sched: restore sanity


* Peter Zijlstra <[email protected]> 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

2009-12-20 14:52:20

by Peter Zijlstra

[permalink] [raw]
Subject: Re: sched: restore sanity

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.

2009-12-20 15:05:19

by San Mehat

[permalink] [raw]
Subject: Re: sched: restore sanity

On Sun, Dec 20, 2009 at 7:03 AM, San Mehat <[email protected]> wrote:
>
>
> On Sun, Dec 20, 2009 at 6:51 AM, Peter Zijlstra <[email protected]> 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 [email protected]
>> 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
> [email protected]



--
----------
San Mehat
Staff Software Engineer
Google Inc.
o: 650-253-7422
c: 408-382-1249
[email protected]

2009-12-20 15:20:15

by Peter Zijlstra

[permalink] [raw]
Subject: Re: sched: restore sanity

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.


2009-12-20 15:28:28

by Mike Galbraith

[permalink] [raw]
Subject: Re: sched: restore sanity

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

2009-12-20 15:37:06

by San Mehat

[permalink] [raw]
Subject: Re: sched: restore sanity

On Sun, Dec 20, 2009 at 7:19 AM, Peter Zijlstra <[email protected]> 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
[email protected]

2009-12-20 17:22:15

by Joe Perches

[permalink] [raw]
Subject: Re: sched: restore sanity

On Sun, 2009-12-20 at 15:49 +0100, Ingo Molnar wrote:
> * Peter Zijlstra <[email protected]> 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.

2009-12-20 17:22:28

by Joe Perches

[permalink] [raw]
Subject: Re: sched: restore sanity

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>?

2009-12-20 17:37:20

by Peter Zijlstra

[permalink] [raw]
Subject: Re: sched: restore sanity

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().

2009-12-20 17:37:46

by Ingo Molnar

[permalink] [raw]
Subject: Re: sched: restore sanity


* Joe Perches <[email protected]> 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

2009-12-20 17:50:36

by Ingo Molnar

[permalink] [raw]
Subject: Re: sched: restore sanity


* Peter Zijlstra <[email protected]> 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

2009-12-20 17:57:20

by Joe Perches

[permalink] [raw]
Subject: Re: sched: restore sanity

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.

2009-12-20 18:01:27

by Peter Zijlstra

[permalink] [raw]
Subject: [tip:sched/urgent] sched: Restore printk sanity

Commit-ID: 6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
Gitweb: http://git.kernel.org/tip/6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
Author: Peter Zijlstra <[email protected]>
AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
Committer: Ingo Molnar <[email protected]>
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 <[email protected]>
Acked-by: Mike Galbraith <[email protected]>
Cc: Joe Perches <[email protected]>
Cc: Linus Torvalds <[email protected]>
Cc: Andrew Morton <[email protected]>
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 <[email protected]>
--
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);
}

2009-12-20 18:07:29

by Peter Zijlstra

[permalink] [raw]
Subject: [tip:sched/urgent] sched: Restore printk sanity

Commit-ID: 3df0fc5b2e9d8092dcaeb5ae0b6753d85c851d66
Gitweb: http://git.kernel.org/tip/3df0fc5b2e9d8092dcaeb5ae0b6753d85c851d66
Author: Peter Zijlstra <[email protected]>
AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
Committer: Ingo Molnar <[email protected]>
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 <[email protected]>
Acked-by: Mike Galbraith <[email protected]>
Cc: Joe Perches <[email protected]>
Cc: Linus Torvalds <[email protected]>
Cc: Andrew Morton <[email protected]>
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 <[email protected]>
---
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);
}

2009-12-20 18:15:20

by Arjan van de Ven

[permalink] [raw]
Subject: Re: sched: restore sanity

On Sun, 20 Dec 2009 09:22:23 -0800
Joe Perches <[email protected]> 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

2009-12-20 18:21:53

by Joe Perches

[permalink] [raw]
Subject: Re: sched: restore sanity

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 <[email protected]> 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.

2009-12-20 18:55:07

by Joe Perches

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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.

2009-12-20 19:15:54

by Ingo Molnar

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity


* Joe Perches <[email protected]> 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

2009-12-20 19:44:18

by Joe Perches

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

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);

2009-12-20 20:12:22

by Ingo Molnar

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


* Joe Perches <[email protected]> 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 <[email protected]>

Ingo

2009-12-20 20:36:11

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

On Sun, Dec 20, 2009 at 19:00, tip-bot for Peter Zijlstra
<[email protected]> wrote:
> Commit-ID:  6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> Gitweb:     http://git.kernel.org/tip/6c9a74afc5d95321e33a727b3c563f3e7d6c4a5c
> Author:     Peter Zijlstra <[email protected]>
> AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
> Committer:  Ingo Molnar <[email protected]>
> 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 -- [email protected]

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

2009-12-20 22:13:26

by Theodore Ts'o

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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

2009-12-21 00:46:39

by Arjan van de Ven

[permalink] [raw]
Subject: Re: sched: restore sanity

On Sun, 20 Dec 2009 10:21:50 -0800
Joe Perches <[email protected]> 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 <[email protected]>
> > 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

2009-12-21 01:11:25

by Joe Perches

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

On Sun, 2009-12-20 at 17:12 -0500, [email protected] 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.

2009-12-21 01:20:12

by Joe Perches

[permalink] [raw]
Subject: Re: sched: restore sanity

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.

2009-12-21 20:41:45

by Valdis Klētnieks

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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?




Attachments:
(No filename) (227.00 B)

2009-12-22 10:11:31

by Al Viro

[permalink] [raw]
Subject: Re: sched: restore sanity

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

2009-12-25 13:27:06

by Pavel Machek

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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 <[email protected]>
> AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
> Committer: Ingo Molnar <[email protected]>
> 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

2009-12-25 18:39:54

by Joe Perches

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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.

2009-12-25 18:45:38

by Ingo Molnar

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity


* Pavel Machek <[email protected]> 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 <[email protected]>
> > AuthorDate: Sun, 20 Dec 2009 14:23:57 +0100
> > Committer: Ingo Molnar <[email protected]>
> > 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

2009-12-25 18:47:40

by Pavel Machek

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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

2009-12-27 00:49:34

by Valdis Klētnieks

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity

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


Attachments:
(No filename) (227.00 B)

2009-12-27 05:57:11

by Ingo Molnar

[permalink] [raw]
Subject: Re: [tip:sched/urgent] sched: Restore printk sanity


* [email protected] <[email protected]> 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