[RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[Steven Rostedt]

trace_printk() is used to debug fast paths within the kernel. Places
that gets called in any context (interrupt or NMI) or thousands of
times a second. Something you do not want to do with a printk().

In order to make it completely lockless as it needs a temporary buffer
to handle some of the string formatting, a page is created per cpu for
every context (four per cpu; normal, softirq, irq, NMI).

Since trace_printk() should only be used for debugging purposes,
there's no reason to waste memory on these buffers on a production
system. That means, trace_printk() should never be used unless a
developer is debugging their kernel. There's macro magic to allocate
the buffers if trace_printk() is used anywhere in the kernel.

To help enforce that trace_printk() isn't used outside of development,
when it is used, a nasty banner is displayed on bootup (or when a module
is loaded that uses trace_printk() and the kernel core does not).

Here's the banner:

 ****************************************
 ** NOTICE NOTICE NOTICE NOTICE NOTICE **
 ** trace_printk() being used.         **
 ** Allocating extra memory for it     **
 ****************************************

Hmm, maybe I should add "Not for production use" to scare people even
more?

Not-yet-signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---

Ted,

I noticed that in fs/ext4/inline.c you use trace_printk() if
INLINE_DIR_DEBUG is defined. I'm assuming that this is not a production
setting and this banner should not affect you at all. Am I correct?

There's some other places that use it, but those are obviously debug
only.

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 0543169..068f453 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -1975,7 +1975,11 @@ void trace_printk_init_buffers(void)
 	if (alloc_percpu_trace_buffer())
 		return;
 
-	pr_info("ftrace: Allocated trace_printk buffers\n");
+	pr_warning("****************************************\n");
+	pr_warning("** NOTICE NOTICE NOTICE NOTICE NOTICE **\n");
+	pr_warning("** trace_printk() being used.         **\n");
+	pr_warning("** Allocating extra memory for it     **\n");
+	pr_warning("****************************************\n");
 
 	/* Expand the buffers to set size */
 	tracing_update_buffers();

Re: [RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[Peter Zijlstra]

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

On Wed, May 28, 2014 at 01:14:40PM -0400, Steven Rostedt wrote:
> 
> trace_printk() is used to debug fast paths within the kernel. Places
> that gets called in any context (interrupt or NMI) or thousands of
> times a second. Something you do not want to do with a printk().
> 
> In order to make it completely lockless as it needs a temporary buffer
> to handle some of the string formatting, a page is created per cpu for
> every context (four per cpu; normal, softirq, irq, NMI).
> 
> Since trace_printk() should only be used for debugging purposes,
> there's no reason to waste memory on these buffers on a production
> system. That means, trace_printk() should never be used unless a
> developer is debugging their kernel. There's macro magic to allocate
> the buffers if trace_printk() is used anywhere in the kernel.
> 
> To help enforce that trace_printk() isn't used outside of development,
> when it is used, a nasty banner is displayed on bootup (or when a module
> is loaded that uses trace_printk() and the kernel core does not).
> 
> Here's the banner:
> 
>  ****************************************
>  ** NOTICE NOTICE NOTICE NOTICE NOTICE **
>  ** trace_printk() being used.         **
>  ** Allocating extra memory for it     **
>  ****************************************
> 
> Hmm, maybe I should add "Not for production use" to scare people even
> more?

Does that really stop people from doing stupid? Wouldn't it be better to
make sure nobody merges a trace_printk() user in mainline? You can set
up a commit hook and check for +.*trace_printk or so.

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

Re: [RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[Borislav Petkov]

On Wed, May 28, 2014 at 01:14:40PM -0400, Steven Rostedt wrote:
> Here's the banner:
> 
>  ****************************************
>  ** NOTICE NOTICE NOTICE NOTICE NOTICE **
>  ** trace_printk() being used.         **
>  ** Allocating extra memory for it     **
>  ****************************************
> 
> Hmm, maybe I should add "Not for production use" to scare people even
> more?

Yes, and at least some swearing - this is the linux kernel for
chrissake. Or are you gone soft too?

-- 
Regards/Gruss,
    Boris.

Sent from a fat crate under my desk. Formatting is fine.
--

Re: [RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[Steven Rostedt]

On Wed, 28 May 2014 19:22:39 +0200
Peter Zijlstra <peterz@infradead.org> wrote:

> On Wed, May 28, 2014 at 01:14:40PM -0400, Steven Rostedt wrote:
> > 
> > trace_printk() is used to debug fast paths within the kernel. Places
> > that gets called in any context (interrupt or NMI) or thousands of
> > times a second. Something you do not want to do with a printk().
> > 
> > In order to make it completely lockless as it needs a temporary buffer
> > to handle some of the string formatting, a page is created per cpu for
> > every context (four per cpu; normal, softirq, irq, NMI).
> > 
> > Since trace_printk() should only be used for debugging purposes,
> > there's no reason to waste memory on these buffers on a production
> > system. That means, trace_printk() should never be used unless a
> > developer is debugging their kernel. There's macro magic to allocate
> > the buffers if trace_printk() is used anywhere in the kernel.
> > 
> > To help enforce that trace_printk() isn't used outside of development,
> > when it is used, a nasty banner is displayed on bootup (or when a module
> > is loaded that uses trace_printk() and the kernel core does not).
> > 
> > Here's the banner:
> > 
> >  ****************************************
> >  ** NOTICE NOTICE NOTICE NOTICE NOTICE **
> >  ** trace_printk() being used.         **
> >  ** Allocating extra memory for it     **
> >  ****************************************
> > 
> > Hmm, maybe I should add "Not for production use" to scare people even
> > more?
> 
> Does that really stop people from doing stupid? Wouldn't it be better to

Scary banners usually do. Perhaps this isn't scary enough.

> make sure nobody merges a trace_printk() user in mainline? You can set
> up a commit hook and check for +.*trace_printk or so.

Of course, but that requires me to monitory it. It may be too late when
I notice it.

Nothing prevents me from doing both :-)

-- Steve

Re: [RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[Steven Rostedt]

On Wed, 28 May 2014 19:26:18 +0200
Borislav Petkov <bp@alien8.de> wrote:

> On Wed, May 28, 2014 at 01:14:40PM -0400, Steven Rostedt wrote:
> > Here's the banner:
> > 
> >  ****************************************
> >  ** NOTICE NOTICE NOTICE NOTICE NOTICE **
> >  ** trace_printk() being used.         **
> >  ** Allocating extra memory for it     **
> >  ****************************************
> > 
> > Hmm, maybe I should add "Not for production use" to scare people even
> > more?
> 
> Yes, and at least some swearing - this is the linux kernel for
> chrissake. Or are you gone soft too?
> 

Going soft? Nah, you know me.  I never swear, so how could not swearing
cause me to go soft :-)


Perhaps a: 

  *********************************************************
  ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE    **
  **                                                     **
  ** trace_printk() being used.                          **
  ** Allocating extra memory for it                      **
  **                                                     **
  ** This means that this is a DEBUG kernel and it is    **
  ** unsafe for production use.                          **
  **                                                     **
  ** If you see this message and you are not debugging   **
  ** the kernel, report this immediately to your vendor! **
  **                                                     **
  ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE    **
  *********************************************************

Maybe that will work?

-- Steve

Re: [RFC][PATCH] tracing: Print nasty banner when trace_printk() is in use

[Olaf Titz]

>   *********************************************************
>   ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE    **

Is it really that bad to warrant this kind of warning? Not knowing
about the issue at all, I read from the original description that the
wastage is four pages of memory times number of CPU cores, which
shouldn't matter much except for small embedded systems.

Or does this something much scarier, like considerably slowing down
fast paths?

Olaf