[PATCH 0/5] [GIT PULL] tracing/splice/ringbuffer: updates for tip

[PATCH 0/5] [GIT PULL] tracing/splice/ringbuffer: updates for tip

[Steven Rostedt]

Ingo,

I was doing a bit of tracing that was stressing the splice code
and I found lots of badness. Mostly, the second patch is the killer,
and should most likely go upstream ASAP. The ref counting on the
splice page is wrong and is never freed!

The rest are fixes to the read side. While debugging the memory leak
I pulled out my old logdev and used it to monitor what was happening
inside of ftrace (tracing the tracer). I did not like the amount
of copying that was happening in splice. This was mainly because
splice was faster than the writer (and this was with function tracer
running!). I added some enhancements to make the splice code
perform a little nicer.

Here's the logdev patch I was using to trace. As well as adding
my lfcnprint statements (similar to trace_printk).

  http://rostedt.homelinux.com/logdev/logdev-0.6.0-2.6.30-rc1.patch

Please pull the latest tip/tracing/ftrace-1 tree, which can be found at:

  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/tracing/ftrace-1


Steven Rostedt (5):
      tracing: convert ftrace_dump spinlocks to raw
      tracing: fix ref count in splice pages
      tracing: only add splice page if entries exist
      tracing: have splice only copy full pages
      ring-buffer: fix printk output

----
 kernel/trace/ring_buffer.c |    2 +-
 kernel/trace/trace.c       |   20 ++++++++++++++------
 2 files changed, 15 insertions(+), 7 deletions(-)
-- 

[PATCH 1/5] tracing: convert ftrace_dump spinlocks to raw

[Steven Rostedt]

[-- Attachment #1: 0001-tracing-convert-ftrace_dump-spinlocks-to-raw.patch --]
[-- Type: text/plain, Size: 1753 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

ftrace_dump is used for printing out the contents of the ftrace ring buffer
to the console on failure. Currently it uses a spinlock to synchronize
the output from multiple failures on different CPUs. This spin lock
currently is a normal spinlock and can cause issues with lockdep and
lock tracing.

This patch converts it to raw since it is for error handling only.
The lock is local to the ftrace_dump and is not used by any other
infrastructure.

[ Impact: prevent ftrace_dump from locking up by internal tracing ]

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |    9 ++++++---
 1 files changed, 6 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index b6183bc..5d704a4 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4114,7 +4114,8 @@ trace_printk_seq(struct trace_seq *s)
 
 static void __ftrace_dump(bool disable_tracing)
 {
-	static DEFINE_SPINLOCK(ftrace_dump_lock);
+	static raw_spinlock_t ftrace_dump_lock =
+		(raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
 	/* use static because iter can be a bit big for the stack */
 	static struct trace_iterator iter;
 	unsigned int old_userobj;
@@ -4123,7 +4124,8 @@ static void __ftrace_dump(bool disable_tracing)
 	int cnt = 0, cpu;
 
 	/* only one dump */
-	spin_lock_irqsave(&ftrace_dump_lock, flags);
+	local_irq_save(flags);
+	__raw_spin_lock(&ftrace_dump_lock);
 	if (dump_ran)
 		goto out;
 
@@ -4195,7 +4197,8 @@ static void __ftrace_dump(bool disable_tracing)
 	}
 
  out:
-	spin_unlock_irqrestore(&ftrace_dump_lock, flags);
+	__raw_spin_unlock(&ftrace_dump_lock);
+	local_irq_restore(flags);
 }
 
 /* By default: disable tracing after the dump */
-- 
1.6.2.1

-- 

Re: [PATCH 1/5] tracing: convert ftrace_dump spinlocks to raw

[Andrew Morton]

On Wed, 29 Apr 2009 00:48:15 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:

> +	local_irq_save(flags);
> +	__raw_spin_lock(&ftrace_dump_lock);

I'm counting twentyish instances of this.  Maybe it's time to give up
and implement raw_spin_lock_irqsave().

Re: [PATCH 1/5] tracing: convert ftrace_dump spinlocks to raw

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 00:48:15 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > +	local_irq_save(flags);
> > +	__raw_spin_lock(&ftrace_dump_lock);
> 
> I'm counting twentyish instances of this. [...]

there's 9 in the tracing code, two more in the rest of the kernel.

> [...] Maybe it's time to give up and implement 
> raw_spin_lock_irqsave().

There's a difference between:

	local_irq_save(flags);
	__raw_spin_lock(&ftrace_dump_lock);

and:

	raw_local_irq_save(flags);
	__raw_spin_lock(&ftrace_dump_lock);

raw_spin_lock_irqsave() would map to the latter logic-wise - but in 
the tracing code we want the former.

But the main reason is that using raw locks has its costs - it skips 
lockdep coverage, is preempt unsafe, etc. The APIs are not complete 
and intentionally so: they are minimal building blocks for the real 
APIs. Instrumentation goes deep in the guts of the kernel so using 
very low level primitives is justified there - but we dont want to 
make it _too_ easy to use a raw-anything locking facility.

	Ingo

[PATCH 2/5] tracing: fix ref count in splice pages

[Steven Rostedt]

[-- Attachment #1: 0002-tracing-fix-ref-count-in-splice-pages.patch --]
[-- Type: text/plain, Size: 866 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

The pages allocated for the splice binary buffer did not initialize
the ref count correctly. This caused pages not to be freed and causes
a drastic memory leak.

Thanks to logdev I was able to trace the tracer to find where the leak
was.

[ Impact: stop memory leak when using splice ]

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 5d704a4..9058240 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -3531,6 +3531,7 @@ tracing_buffers_splice_read(struct file *file, loff_t *ppos,
 		if (!ref)
 			break;
 
+		ref->ref = 1;
 		ref->buffer = info->tr->buffer;
 		ref->page = ring_buffer_alloc_read_page(ref->buffer);
 		if (!ref->page) {
-- 
1.6.2.1

-- 

[PATCH 3/5] tracing: only add splice page if entries exist

[Steven Rostedt]

[-- Attachment #1: 0003-tracing-only-add-splice-page-if-entries-exist.patch --]
[-- Type: text/plain, Size: 1608 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

The splice code allocates a page even when the ring buffer is empty.
It detects the ring buffer being empty when it it fails to copy
anything from the ring buffer into the page.

This patch adds a check to see if there is anything in the ring buffer
before allocating a page.

Thanks to logdev for letting me trace the tracer to find this.

[ Impact: speed up due to removing unnecessary allocation ]

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |    8 ++++++--
 1 files changed, 6 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 9058240..0aeb3b9 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -3508,7 +3508,7 @@ tracing_buffers_splice_read(struct file *file, loff_t *ppos,
 		.spd_release	= buffer_spd_release,
 	};
 	struct buffer_ref *ref;
-	int size, i;
+	int entries, size, i;
 	size_t ret;
 
 	if (*ppos & (PAGE_SIZE - 1)) {
@@ -3523,7 +3523,9 @@ tracing_buffers_splice_read(struct file *file, loff_t *ppos,
 		len &= PAGE_MASK;
 	}
 
-	for (i = 0; i < PIPE_BUFFERS && len; i++, len -= PAGE_SIZE) {
+	entries = ring_buffer_entries_cpu(info->tr->buffer, info->cpu);
+
+	for (i = 0; i < PIPE_BUFFERS && len && entries; i++, len -= PAGE_SIZE) {
 		struct page *page;
 		int r;
 
@@ -3564,6 +3566,8 @@ tracing_buffers_splice_read(struct file *file, loff_t *ppos,
 		spd.partial[i].private = (unsigned long)ref;
 		spd.nr_pages++;
 		*ppos += PAGE_SIZE;
+
+		entries = ring_buffer_entries_cpu(info->tr->buffer, info->cpu);
 	}
 
 	spd.nr_pages = i;
-- 
1.6.2.1

-- 

[PATCH 4/5] tracing: have splice only copy full pages

[Steven Rostedt]

[-- Attachment #1: 0004-tracing-have-splice-only-copy-full-pages.patch --]
[-- Type: text/plain, Size: 1547 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

Splice works with pages, it is much more effecient to use an entire
page than to copy bits over several pages.

Using logdev to trace the internals of the splice mechanism, I was
able to see that splice can be very aggressive. When tracing is
occurring, and the reader caught up to the writer, and the writer
is on the reader page, the reader will copy what is there into the
splice page. Splice may iterate over several pages and if the
writer is still writing to the page, the reader will keep copying
bits to new pages to pass to userspace.

This patch changes it to only pass data to userspace if the page
is full (the writer has left the page). This has a small side effect
that splice can not read a partial page, and must wait for the
page to fill. This should not be an issue. If tracing has stopped,
then a use of "read" will still read all of the page.

[ Impact: better performance for ring buffer splice code ]

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 0aeb3b9..f5427e0 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -3542,7 +3542,7 @@ tracing_buffers_splice_read(struct file *file, loff_t *ppos,
 		}
 
 		r = ring_buffer_read_page(ref->buffer, &ref->page,
-					  len, info->cpu, 0);
+					  len, info->cpu, 1);
 		if (r < 0) {
 			ring_buffer_free_read_page(ref->buffer,
 						   ref->page);
-- 
1.6.2.1

-- 

[PATCH 5/5] ring-buffer: fix printk output

[Steven Rostedt]

[-- Attachment #1: 0005-ring-buffer-fix-printk-output.patch --]
[-- Type: text/plain, Size: 864 bytes --]

From: Steven Rostedt <srostedt@redhat.com>

The warning output in trace_recursive_lock uses %d for a long when
it should be %ld.

[ Impact: fix compile warning ]

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 9692f10..f4cc590 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -1491,7 +1491,7 @@ static int trace_recursive_lock(void)
 	/* Disable all tracing before we do anything else */
 	tracing_off_permanent();
 
-	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
+	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
 		    "HC[%lu]:SC[%lu]:NMI[%lu]\n",
 		    current->trace_recursion,
 		    hardirq_count() >> HARDIRQ_SHIFT,
-- 
1.6.2.1

-- 

Re: [PATCH 5/5] ring-buffer: fix printk output

[Andrew Morton]

On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:

> -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"

hrmph.  I didn't know that printk_once() existed, and I should have
known.  I wonder how many other people don't know.

Should it use unlikely()?

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> 
> hrmph.  I didn't know that printk_once() existed, and I should 
> have known.  I wonder how many other people don't know.

Was posted to linux-next@vger.kernel.org.

> Should it use unlikely()?

Not really. Any printk_once() usage site is an 'unlikely' branch 
already in most cases. Double unlikely just spreads the instructions 
needlessly. The condition that _leads_ to a printk_once() should be 
an unlikely().

	Ingo

Re: [PATCH 5/5] ring-buffer: fix printk output

[Andrew Morton]

On Wed, 29 Apr 2009 07:43:59 +0200 Ingo Molnar <mingo@elte.hu> wrote:

> 
> * Andrew Morton <akpm@linux-foundation.org> wrote:
> 
> > On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> > 
> > > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> > 
> > hrmph.  I didn't know that printk_once() existed, and I should 
> > have known.  I wonder how many other people don't know.
> 
> Was posted to linux-next@vger.kernel.org.

Well no wonder I didn't know about it.

> > Should it use unlikely()?
> 
> Not really. Any printk_once() usage site is an 'unlikely' branch 
> already in most cases. Double unlikely just spreads the instructions 
> needlessly. The condition that _leads_ to a printk_once() should be 
> an unlikely().
> 

OK.

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 07:43:59 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> 
> > 
> > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > 
> > > On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> > > 
> > > > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > > > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> > > 
> > > hrmph.  I didn't know that printk_once() existed, and I should 
> > > have known.  I wonder how many other people don't know.
> > 
> > Was posted to linux-next@vger.kernel.org.
> 
> Well no wonder I didn't know about it.

I (too?) think it's counter-productive that the linux-next list is 
split out of lkml. I constantly fall into that trap: i get a 
bugreport against one of our trees, i see that there's vger in the 
Cc: list and mistake it for being Cc:-ed to lkml (all our trees are 
developed on lkml and most of the bugreports come Cc:-ed to lkml) 
but in reality it's Cc:-ed to linux-next which has a much smaller 
audience. (which audience apparently does not even include you)

If this email list fragmentation and the resoluting loss of 
information bothers you too then please ask Stephen to move 
linux-next mails to lkml (i've Cc:-ed Stephen) - it's not like it's 
actually something separate ... today's linux-next messages are 
tomorrow's lkml messages. Moving linux-next mails to lkml would 
nicely improve the S/N ratio on lkml.

	Ingo

Re: [PATCH 5/5] ring-buffer: fix printk output

[Andrew Morton]

On Wed, 29 Apr 2009 08:09:55 +0200 Ingo Molnar <mingo@elte.hu> wrote:

> 
> * Andrew Morton <akpm@linux-foundation.org> wrote:
> 
> > On Wed, 29 Apr 2009 07:43:59 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > 
> > > 
> > > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > > 
> > > > On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> > > > 
> > > > > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > > > > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> > > > 
> > > > hrmph.  I didn't know that printk_once() existed, and I should 
> > > > have known.  I wonder how many other people don't know.
> > > 
> > > Was posted to linux-next@vger.kernel.org.
> > 
> > Well no wonder I didn't know about it.
> 
> I (too?) think it's counter-productive that the linux-next list is 
> split out of lkml. I constantly fall into that trap: i get a 
> bugreport against one of our trees, i see that there's vger in the 
> Cc: list and mistake it for being Cc:-ed to lkml (all our trees are 
> developed on lkml and most of the bugreports come Cc:-ed to lkml) 
> but in reality it's Cc:-ed to linux-next which has a much smaller 
> audience. (which audience apparently does not even include you)
> 
> If this email list fragmentation and the resoluting loss of 
> information bothers you too then please ask Stephen to move 
> linux-next mails to lkml (i've Cc:-ed Stephen) - it's not like it's 
> actually something separate ... today's linux-next messages are 
> tomorrow's lkml messages. Moving linux-next mails to lkml would 
> nicely improve the S/N ratio on lkml.
> 

eh.  Just auto-add lkml to tipbot-commit emails?

printk_once() is racy on smp and preempt btw ;)

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 08:09:55 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> 
> > 
> > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > 
> > > On Wed, 29 Apr 2009 07:43:59 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > > 
> > > > 
> > > > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > > > 
> > > > > On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> > > > > 
> > > > > > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > > > > > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> > > > > 
> > > > > hrmph.  I didn't know that printk_once() existed, and I should 
> > > > > have known.  I wonder how many other people don't know.
> > > > 
> > > > Was posted to linux-next@vger.kernel.org.
> > > 
> > > Well no wonder I didn't know about it.
> > 
> > I (too?) think it's counter-productive that the linux-next list is 
> > split out of lkml. I constantly fall into that trap: i get a 
> > bugreport against one of our trees, i see that there's vger in the 
> > Cc: list and mistake it for being Cc:-ed to lkml (all our trees are 
> > developed on lkml and most of the bugreports come Cc:-ed to lkml) 
> > but in reality it's Cc:-ed to linux-next which has a much smaller 
> > audience. (which audience apparently does not even include you)
> > 
> > If this email list fragmentation and the resoluting loss of 
> > information bothers you too then please ask Stephen to move 
> > linux-next mails to lkml (i've Cc:-ed Stephen) - it's not like it's 
> > actually something separate ... today's linux-next messages are 
> > tomorrow's lkml messages. Moving linux-next mails to lkml would 
> > nicely improve the S/N ratio on lkml.
> > 
> 
> eh.  Just auto-add lkml to tipbot-commit emails?

Yeah - the tip-commits-bot already has such a feature and we are 
making use of it - but this commit predates it. So it was posted to 
linux-next and the tip-commits list.

My larger point remains, about possibly embedding linux-next into 
lkml. I couldnt think of a single linux-next mail that isnt relevant 
to lkml. It's all about commits that are destined for upstream in 
0-2.5 months.

> printk_once() is racy on smp and preempt btw ;)

Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
facility, not for normal kernel messages.

Do we want to complicate them with locking and preemption - or 
should we just concentrate on getting the "oh crap" message out to 
the syslog (before it's possibly too late to get anything out)?

I have no strong opinion about it - but i tend to like the simpler 
method most. printk + stack dumps themselves arent atomic to begin 
with.

	Ingo

Re: [PATCH 5/5] ring-buffer: fix printk output

[Andrew Morton]

On Wed, 29 Apr 2009 09:22:08 +0200 Ingo Molnar <mingo@elte.hu> wrote:

> 
> * Andrew Morton <akpm@linux-foundation.org> wrote:
> 
> > On Wed, 29 Apr 2009 08:09:55 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > 
> > > 
> > > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > > 
> > > > On Wed, 29 Apr 2009 07:43:59 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > > > 
> > > > > 
> > > > > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > > > > 
> > > > > > On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> > > > > > 
> > > > > > > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > > > > > > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> > > > > > 
> > > > > > hrmph.  I didn't know that printk_once() existed, and I should 
> > > > > > have known.  I wonder how many other people don't know.
> > > > > 
> > > > > Was posted to linux-next@vger.kernel.org.
> > > > 
> > > > Well no wonder I didn't know about it.
> > > 
> > > I (too?) think it's counter-productive that the linux-next list is 
> > > split out of lkml. I constantly fall into that trap: i get a 
> > > bugreport against one of our trees, i see that there's vger in the 
> > > Cc: list and mistake it for being Cc:-ed to lkml (all our trees are 
> > > developed on lkml and most of the bugreports come Cc:-ed to lkml) 
> > > but in reality it's Cc:-ed to linux-next which has a much smaller 
> > > audience. (which audience apparently does not even include you)
> > > 
> > > If this email list fragmentation and the resoluting loss of 
> > > information bothers you too then please ask Stephen to move 
> > > linux-next mails to lkml (i've Cc:-ed Stephen) - it's not like it's 
> > > actually something separate ... today's linux-next messages are 
> > > tomorrow's lkml messages. Moving linux-next mails to lkml would 
> > > nicely improve the S/N ratio on lkml.
> > > 
> > 
> > eh.  Just auto-add lkml to tipbot-commit emails?
> 
> Yeah - the tip-commits-bot already has such a feature and we are 
> making use of it - but this commit predates it. So it was posted to 
> linux-next and the tip-commits list.

there's a tip-commits list?

> My larger point remains, about possibly embedding linux-next into 
> lkml. I couldnt think of a single linux-next mail that isnt relevant 
> to lkml. It's all about commits that are destined for upstream in 
> 0-2.5 months.

Sure, I'd be OK with zapping the linux-next list.

> > printk_once() is racy on smp and preempt btw ;)
> 
> Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
> facility, not for normal kernel messages.
> 
> Do we want to complicate them with locking and preemption - or 
> should we just concentrate on getting the "oh crap" message out to 
> the syslog (before it's possibly too late to get anything out)?
> 
> I have no strong opinion about it - but i tend to like the simpler 
> method most. printk + stack dumps themselves arent atomic to begin 
> with.

Well, it's hardly likely to be a problem.  otoh, if two CPUs _do_ hit
the thing at the same time, the resulting output will be all messed up
and we'd really like to see it.

Easily fixed with test_and_set_bit()?

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 09:22:08 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> 
> > 
> > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > 
> > > On Wed, 29 Apr 2009 08:09:55 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > > 
> > > > 
> > > > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > > > 
> > > > > On Wed, 29 Apr 2009 07:43:59 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > > > > 
> > > > > > 
> > > > > > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > > > > > 
> > > > > > > On Wed, 29 Apr 2009 00:48:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> > > > > > > 
> > > > > > > > -	printk_once(KERN_WARNING "Tracing recursion: depth[%d]:"
> > > > > > > > +	printk_once(KERN_WARNING "Tracing recursion: depth[%ld]:"
> > > > > > > 
> > > > > > > hrmph.  I didn't know that printk_once() existed, and I should 
> > > > > > > have known.  I wonder how many other people don't know.
> > > > > > 
> > > > > > Was posted to linux-next@vger.kernel.org.
> > > > > 
> > > > > Well no wonder I didn't know about it.
> > > > 
> > > > I (too?) think it's counter-productive that the linux-next list is 
> > > > split out of lkml. I constantly fall into that trap: i get a 
> > > > bugreport against one of our trees, i see that there's vger in the 
> > > > Cc: list and mistake it for being Cc:-ed to lkml (all our trees are 
> > > > developed on lkml and most of the bugreports come Cc:-ed to lkml) 
> > > > but in reality it's Cc:-ed to linux-next which has a much smaller 
> > > > audience. (which audience apparently does not even include you)
> > > > 
> > > > If this email list fragmentation and the resoluting loss of 
> > > > information bothers you too then please ask Stephen to move 
> > > > linux-next mails to lkml (i've Cc:-ed Stephen) - it's not like it's 
> > > > actually something separate ... today's linux-next messages are 
> > > > tomorrow's lkml messages. Moving linux-next mails to lkml would 
> > > > nicely improve the S/N ratio on lkml.
> > > > 
> > > 
> > > eh.  Just auto-add lkml to tipbot-commit emails?
> > 
> > Yeah - the tip-commits-bot already has such a feature and we are 
> > making use of it - but this commit predates it. So it was posted 
> > to linux-next and the tip-commits list.
> 
> there's a tip-commits list?

has been for months, see:

   http://vger.kernel.org/vger-lists.html
   http://vger.kernel.org/vger-lists.html#linux-tip-commits

> > My larger point remains, about possibly embedding linux-next 
> > into lkml. I couldnt think of a single linux-next mail that isnt 
> > relevant to lkml. It's all about commits that are destined for 
> > upstream in 0-2.5 months.
> 
> Sure, I'd be OK with zapping the linux-next list.

Another, less drastic solution would be to keep it as an _alias_ 
list. All mails posted to it also go to lkml, but it would still be 
subscribe-able separately.

( This has come up before and this would be useful for a number of 
  other things - such as tracing/instrumentation. Someone who is 
  only interested in instrumentation related discussions could 
  subscribe to that list. )

> > > printk_once() is racy on smp and preempt btw ;)
> > 
> > Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
> > facility, not for normal kernel messages.
> > 
> > Do we want to complicate them with locking and preemption - or 
> > should we just concentrate on getting the "oh crap" message out 
> > to the syslog (before it's possibly too late to get anything 
> > out)?
> > 
> > I have no strong opinion about it - but i tend to like the 
> > simpler method most. printk + stack dumps themselves arent 
> > atomic to begin with.
> 
> Well, it's hardly likely to be a problem.  otoh, if two CPUs _do_ 
> hit the thing at the same time, the resulting output will be all 
> messed up and we'd really like to see it.
> 
> Easily fixed with test_and_set_bit()?

but if two CPUs hit it at once then the printk+stack-dump itself is 
already mixed up. So if we do any atomicity it should be done for 
all the print-once APIs. (note, lockdep does such message-atomicity 
already, in its own facility)

	Ingo

Re: [PATCH 5/5] ring-buffer: fix printk output

[Andrew Morton]

On Wed, 29 Apr 2009 11:56:25 +0200 Ingo Molnar <mingo@elte.hu> wrote:

> 
> > > My larger point remains, about possibly embedding linux-next 
> > > into lkml. I couldnt think of a single linux-next mail that isnt 
> > > relevant to lkml. It's all about commits that are destined for 
> > > upstream in 0-2.5 months.
> > 
> > Sure, I'd be OK with zapping the linux-next list.
> 
> Another, less drastic solution would be to keep it as an _alias_ 
> list. All mails posted to it also go to lkml, but it would still be 
> subscribe-able separately.

That would work, although I wonder about the potential for duplicates
turning up somewhere.

> ( This has come up before and this would be useful for a number of 
>   other things - such as tracing/instrumentation. Someone who is 
>   only interested in instrumentation related discussions could 
>   subscribe to that list. )
> 
> > > > printk_once() is racy on smp and preempt btw ;)
> > > 
> > > Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
> > > facility, not for normal kernel messages.
> > > 
> > > Do we want to complicate them with locking and preemption - or 
> > > should we just concentrate on getting the "oh crap" message out 
> > > to the syslog (before it's possibly too late to get anything 
> > > out)?
> > > 
> > > I have no strong opinion about it - but i tend to like the 
> > > simpler method most. printk + stack dumps themselves arent 
> > > atomic to begin with.
> > 
> > Well, it's hardly likely to be a problem.  otoh, if two CPUs _do_ 
> > hit the thing at the same time, the resulting output will be all 
> > messed up and we'd really like to see it.
> > 
> > Easily fixed with test_and_set_bit()?
> 
> but if two CPUs hit it at once then the printk+stack-dump itself is 
> already mixed up. So if we do any atomicity it should be done for 
> all the print-once APIs. (note, lockdep does such message-atomicity 
> already, in its own facility)

Confused.

<gets distracted by FW_BUG and friends.  ytf are they in kernel.h?>

#define printk_once(x...) ({				\
	static unsigned long __print_once;		\
							\
	if (!test_and_set_bit(0, &__print_once))	\
		printk(x);				\
})

How can	two CPUs do the printk(x)?

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 11:56:25 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> 
> > 
> > > > My larger point remains, about possibly embedding linux-next 
> > > > into lkml. I couldnt think of a single linux-next mail that isnt 
> > > > relevant to lkml. It's all about commits that are destined for 
> > > > upstream in 0-2.5 months.
> > > 
> > > Sure, I'd be OK with zapping the linux-next list.
> > 
> > Another, less drastic solution would be to keep it as an _alias_ 
> > list. All mails posted to it also go to lkml, but it would still be 
> > subscribe-able separately.
> 
> That would work, although I wonder about the potential for 
> duplicates turning up somewhere.

The potential for duplicates is inherent in Cc: lines to begin with.

> > ( This has come up before and this would be useful for a number of 
> >   other things - such as tracing/instrumentation. Someone who is 
> >   only interested in instrumentation related discussions could 
> >   subscribe to that list. )
> > 
> > > > > printk_once() is racy on smp and preempt btw ;)
> > > > 
> > > > Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
> > > > facility, not for normal kernel messages.
> > > > 
> > > > Do we want to complicate them with locking and preemption - or 
> > > > should we just concentrate on getting the "oh crap" message out 
> > > > to the syslog (before it's possibly too late to get anything 
> > > > out)?
> > > > 
> > > > I have no strong opinion about it - but i tend to like the 
> > > > simpler method most. printk + stack dumps themselves arent 
> > > > atomic to begin with.
> > > 
> > > Well, it's hardly likely to be a problem.  otoh, if two CPUs _do_ 
> > > hit the thing at the same time, the resulting output will be all 
> > > messed up and we'd really like to see it.
> > > 
> > > Easily fixed with test_and_set_bit()?
> > 
> > but if two CPUs hit it at once then the printk+stack-dump itself is 
> > already mixed up. So if we do any atomicity it should be done for 
> > all the print-once APIs. (note, lockdep does such message-atomicity 
> > already, in its own facility)
> 
> Confused.
> 
> <gets distracted by FW_BUG and friends.  ytf are they in kernel.h?>
> 
> #define printk_once(x...) ({				\
> 	static unsigned long __print_once;		\
> 							\

hm, this doubles the flag size on 32-bit kernels.

> 	if (!test_and_set_bit(0, &__print_once))	\
> 		printk(x);				\
> })
> 
> How can	two CPUs do the printk(x)?

they cannot. Did i say they do? What i said (or thought to have said 
;-) was that all the print-once APIs need similar treatment - or 
neither should.

	Ingo

Re: [PATCH 5/5] ring-buffer: fix printk output

[Andrew Morton]

On Wed, 29 Apr 2009 21:45:46 +0200
Ingo Molnar <mingo@elte.hu> wrote:

> 
> * Andrew Morton <akpm@linux-foundation.org> wrote:
> 
> > On Wed, 29 Apr 2009 11:56:25 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > 
> > > 
> > > > > My larger point remains, about possibly embedding linux-next 
> > > > > into lkml. I couldnt think of a single linux-next mail that isnt 
> > > > > relevant to lkml. It's all about commits that are destined for 
> > > > > upstream in 0-2.5 months.
> > > > 
> > > > Sure, I'd be OK with zapping the linux-next list.
> > > 
> > > Another, less drastic solution would be to keep it as an _alias_ 
> > > list. All mails posted to it also go to lkml, but it would still be 
> > > subscribe-able separately.
> > 
> > That would work, although I wonder about the potential for 
> > duplicates turning up somewhere.
> 
> The potential for duplicates is inherent in Cc: lines to begin with.

But if someone does reply-to-all to linux-next and linux-kernel, and
the linux-next email gets redirected to linux-kernel, badness might
happen.  Bearing in mind the screwiness of the mail clients whcih some
people use..

> > > ( This has come up before and this would be useful for a number of 
> > >   other things - such as tracing/instrumentation. Someone who is 
> > >   only interested in instrumentation related discussions could 
> > >   subscribe to that list. )
> > > 
> > > > > > printk_once() is racy on smp and preempt btw ;)
> > > > > 
> > > > > Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
> > > > > facility, not for normal kernel messages.
> > > > > 
> > > > > Do we want to complicate them with locking and preemption - or 
> > > > > should we just concentrate on getting the "oh crap" message out 
> > > > > to the syslog (before it's possibly too late to get anything 
> > > > > out)?
> > > > > 
> > > > > I have no strong opinion about it - but i tend to like the 
> > > > > simpler method most. printk + stack dumps themselves arent 
> > > > > atomic to begin with.
> > > > 
> > > > Well, it's hardly likely to be a problem.  otoh, if two CPUs _do_ 
> > > > hit the thing at the same time, the resulting output will be all 
> > > > messed up and we'd really like to see it.
> > > > 
> > > > Easily fixed with test_and_set_bit()?
> > > 
> > > but if two CPUs hit it at once then the printk+stack-dump itself is 
> > > already mixed up. So if we do any atomicity it should be done for 
> > > all the print-once APIs. (note, lockdep does such message-atomicity 
> > > already, in its own facility)
> > 
> > Confused.
> > 
> > <gets distracted by FW_BUG and friends.  ytf are they in kernel.h?>
> > 
> > #define printk_once(x...) ({				\
> > 	static unsigned long __print_once;		\
> > 							\
> 
> hm, this doubles the flag size on 32-bit kernels.

Well yeah.  I was wondering whether __print_once should be a char
anyway.  Will that hurt text size on any arch?  Will gcc dtrt with such
things?  It might go and 4-byte align the chars anwyay.

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Wed, 29 Apr 2009 21:45:46 +0200
> Ingo Molnar <mingo@elte.hu> wrote:
> 
> > 
> > * Andrew Morton <akpm@linux-foundation.org> wrote:
> > 
> > > On Wed, 29 Apr 2009 11:56:25 +0200 Ingo Molnar <mingo@elte.hu> wrote:
> > > 
> > > > 
> > > > > > My larger point remains, about possibly embedding linux-next 
> > > > > > into lkml. I couldnt think of a single linux-next mail that isnt 
> > > > > > relevant to lkml. It's all about commits that are destined for 
> > > > > > upstream in 0-2.5 months.
> > > > > 
> > > > > Sure, I'd be OK with zapping the linux-next list.
> > > > 
> > > > Another, less drastic solution would be to keep it as an _alias_ 
> > > > list. All mails posted to it also go to lkml, but it would still be 
> > > > subscribe-able separately.
> > > 
> > > That would work, although I wonder about the potential for 
> > > duplicates turning up somewhere.
> > 
> > The potential for duplicates is inherent in Cc: lines to begin with.
> 
> But if someone does reply-to-all to linux-next and linux-kernel, 
> and the linux-next email gets redirected to linux-kernel, badness 
> might happen.  Bearing in mind the screwiness of the mail clients 
> whcih some people use..

Hm, what badness would happen? Today, if i send a mail to linux-next 
and lkml, it shows up on both lists. If i'm subscribed to both, i 
get two mails - one from lkml and one from linux-next.

Auto-aliasing the lists means adding an implicit Cc: lkml to all 
mails that the linux-next list server gets. Two mails are generated 
- and if someone is subscribed to both lists, two mails are 
received. How would mail clients have a problem with that? It's 
already happening.

> > > > ( This has come up before and this would be useful for a number of 
> > > >   other things - such as tracing/instrumentation. Someone who is 
> > > >   only interested in instrumentation related discussions could 
> > > >   subscribe to that list. )
> > > > 
> > > > > > > printk_once() is racy on smp and preempt btw ;)
> > > > > > 
> > > > > > Like WARN_ONCE() and WARN_ON_ONCE(). It's really an "oh crap" 
> > > > > > facility, not for normal kernel messages.
> > > > > > 
> > > > > > Do we want to complicate them with locking and preemption - or 
> > > > > > should we just concentrate on getting the "oh crap" message out 
> > > > > > to the syslog (before it's possibly too late to get anything 
> > > > > > out)?
> > > > > > 
> > > > > > I have no strong opinion about it - but i tend to like the 
> > > > > > simpler method most. printk + stack dumps themselves arent 
> > > > > > atomic to begin with.
> > > > > 
> > > > > Well, it's hardly likely to be a problem.  otoh, if two CPUs _do_ 
> > > > > hit the thing at the same time, the resulting output will be all 
> > > > > messed up and we'd really like to see it.
> > > > > 
> > > > > Easily fixed with test_and_set_bit()?
> > > > 
> > > > but if two CPUs hit it at once then the printk+stack-dump itself is 
> > > > already mixed up. So if we do any atomicity it should be done for 
> > > > all the print-once APIs. (note, lockdep does such message-atomicity 
> > > > already, in its own facility)
> > > 
> > > Confused.
> > > 
> > > <gets distracted by FW_BUG and friends.  ytf are they in kernel.h?>
> > > 
> > > #define printk_once(x...) ({				\
> > > 	static unsigned long __print_once;		\
> > > 							\
> > 
> > hm, this doubles the flag size on 32-bit kernels.
> 
> Well yeah.  I was wondering whether __print_once should be a char 
> anyway.  Will that hurt text size on any arch?  Will gcc dtrt with 
> such things?  It might go and 4-byte align the chars anwyay.

a char would make sense - since they are all rare codepaths 
compression is important - and this should be done for the other 
_ONCE APIs as well.

gcc does the right thing and will compress adjacent char's - but the 
problem is that these char's are unlikely to be adjacent - te 
adjacent variables will likely be larger so the chars will take up 4 
or 8 bytes in practice.

So to achieve compression we'd have to put them into a separate data 
section and have a per arch linker script detail for that. Is that 
worth the trouble? How many flags are we talking about?

	Ingo

Re: [PATCH 5/5] ring-buffer: fix printk output

[Valdis.Kletnieks]

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

On Tue, 28 Apr 2009 23:20:00 PDT, Andrew Morton said:
> printk_once() is racy on smp and preempt btw ;)

Looks like at worst, it's prone to the usual printk racing, plus a possible
misfire causing it to print twice before shutting up?  Or is there something
I'm missing here?

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

Re: [PATCH 5/5] ring-buffer: fix printk output

[Ingo Molnar]

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

> On Tue, 28 Apr 2009 23:20:00 PDT, Andrew Morton said:
> > printk_once() is racy on smp and preempt btw ;)
> 
> Looks like at worst, it's prone to the usual printk racing, plus a 
> possible misfire causing it to print twice before shutting up?  Or 
> is there something I'm missing here?

Yeah, that's the worst-case scenario.

Still worth improving if we can do it without bloating the code or 
data.

[ If not, we can just assume the kernel is perfect and ignore all
  the printk_once() and WARN_ONCE() / WARN_ON_ONCE() callsites as
  obviously dead code ;-) ]

	Ingo

Re: [PATCH 0/5] [GIT PULL] tracing/splice/ringbuffer: updates for tip

[Ingo Molnar]

* Steven Rostedt <rostedt@goodmis.org> wrote:

> Ingo,
> 
> I was doing a bit of tracing that was stressing the splice code 
> and I found lots of badness. Mostly, the second patch is the 
> killer, and should most likely go upstream ASAP. The ref counting 
> on the splice page is wrong and is never freed!

ah, this probably explains what i reported some time ago: the 
ftrace-analyzer OOM hang. I've cherry-picked this into 
tracing/urgent as well.

> The rest are fixes to the read side. While debugging the memory 
> leak I pulled out my old logdev and used it to monitor what was 
> happening inside of ftrace (tracing the tracer). I did not like 
> the amount of copying that was happening in splice. This was 
> mainly because splice was faster than the writer (and this was 
> with function tracer running!). I added some enhancements to make 
> the splice code perform a little nicer.
> 
> Here's the logdev patch I was using to trace. As well as adding my 
> lfcnprint statements (similar to trace_printk).
> 
>   http://rostedt.homelinux.com/logdev/logdev-0.6.0-2.6.30-rc1.patch
> 
> Please pull the latest tip/tracing/ftrace-1 tree, which can be 
> found at:
> 
>   git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
> tip/tracing/ftrace-1
> 
> 
> Steven Rostedt (5):
>       tracing: convert ftrace_dump spinlocks to raw
>       tracing: fix ref count in splice pages
>       tracing: only add splice page if entries exist
>       tracing: have splice only copy full pages
>       ring-buffer: fix printk output
> 
> ----
>  kernel/trace/ring_buffer.c |    2 +-
>  kernel/trace/trace.c       |   20 ++++++++++++++------
>  2 files changed, 15 insertions(+), 7 deletions(-)

Pulled, thanks a lot Steve!

	Ingo