pstore/ftrace: Convert to its own enable/disable debugfs knob

With this patch we no longer reuse function tracer infrastructure, now
we register our own tracer back-end via a debugfs knob.

It's a bit more code, but that is the only downside. On the bright side we
have:

- Ability to make persistent_ram module removable (when needed, we can
  move ftrace_ops struct into a module). Note that persistent_ram is still
  not removable for other reasons, but with this patch it's just one
  thing less to worry about;

- Pstore part is more isolated from the generic function tracer. We tried
  it already by registering our own tracer in available_tracers, but that
  way we're loosing ability to see the traces while we record them to
  pstore. This solution is somewhere in the middle: we only register
  "internal ftracer" back-end, but not the "front-end";

- When only pstore tracing enabled, the kernel will only write to the
  pstore buffer, omitting function tracer buffer (which, of course, still
  can be enabled via 'echo function > current_tracer').

Suggested-by: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Anton Vorontsov <anton.vorontsov@linaro.org>
---

On Tue, Jul 17, 2012 at 05:38:22PM -0400, Steven Rostedt wrote:
[...]
> > > Note, it's safe to use if the trace_ops (or anything the callback calls)
> > > is a module. That's because it detects the trace_ops is not kernel core
> > > code and will place a wrapper around it that allows the function tracing
> > > to by synced with module unload. You still need to unregister the
> > > trace_ops before unloading the module, or you can have a crash that way.
> > 
> > Hehe. Like this? http://lkml.org/lkml/2012/5/26/80 :-D
> > 
> > So, do you want something like this, but combinded: we don't register
> > another tracer, but register our own ftrace_ops? This sounds doable.
> 
> Yeah, the combined. That is, don't make a tracer out of it. Use another
> mechanism to enable the tracing and not as a tracer
> in /debug/tracing/available_tracers. We can probably set up events for
> you too, but at a later time.

OK, here it is. How does it look?

 Documentation/ramoops.txt      |    4 +-
 fs/pstore/Kconfig              |    1 +
 fs/pstore/ftrace.c             |   94 +++++++++++++++++++++++++++++++++++++++-
 fs/pstore/internal.h           |    6 +++
 fs/pstore/platform.c           |    1 +
 include/linux/pstore.h         |    8 ----
 kernel/trace/trace_functions.c |   15 +------
 7 files changed, 103 insertions(+), 26 deletions(-)

On Tue, Jul 17, 2012 at 08:47:22PM -0700, Anton Vorontsov wrote:
[...]
> -void notrace pstore_ftrace_call(unsigned long ip, unsigned long parent_ip)
> +static void notrace pstore_ftrace_call(unsigned long ip,
> +				       unsigned long parent_ip)
>  {
> +	unsigned long flags;
>  	struct pstore_ftrace_record rec = {};
>  
> +	if (unlikely(!ftrace_enabled))
> +		return;
>  	if (unlikely(oops_in_progress))
>  		return;
>  
> +	local_irq_save(flags);
> +
>  	rec.ip = ip;
>  	rec.parent_ip = parent_ip;
>  	pstore_ftrace_encode_cpu(&rec, raw_smp_processor_id());
>  	psinfo->write_buf(PSTORE_TYPE_FTRACE, 0, NULL, 0, (void *)&rec,
>  			  sizeof(rec), psinfo);

Btw, here we might be running w/o recurse protection, and that helped
to find a bug in the persistent ram module.

The bug was quite subtle: it only happened if pstore tracing was
enabled before any other tracers. And it magically disappeared
otherwise.

This is because ftrace_ops_list_func() does its own recurse protection,
but ftrace_ops_list_func() is only used when there are more than
one 'struct ops' registered, otherwise ->func is called directly.

Of course, if I specify FL_GLOBAL/FL_CONTROL flag for the tracer,
then it will not try to call the func directly. But then there is
a question: do we really want to set these flags if we yet don't
want removable modules?

Or, setting at least FL_CONTROL would be a good idea anyway, since
it will then react to ftrace_function_local_{enable,disable}()?

Thanks,

On Tue, 2012-07-17 at 20:47 -0700, Anton Vorontsov wrote:

> diff --git a/Documentation/ramoops.txt b/Documentation/ramoops.txt
> index 197ad59..69b3cac 100644
> --- a/Documentation/ramoops.txt
> +++ b/Documentation/ramoops.txt
> @@ -102,9 +102,7 @@ related hangs. The functions call chain log is stored in a "ftrace-ramoops"
>  file. Here is an example of usage:
>  
>   # mount -t debugfs debugfs /sys/kernel/debug/
> - # cd /sys/kernel/debug/tracing
> - # echo function > current_tracer
> - # echo 1 > options/func_pstore
> + # echo 1 > /sys/kernel/debug/pstore/record_ftrace
>   # reboot -f
>   [...]
>   # mount -t pstore pstore /mnt/
> diff --git a/fs/pstore/Kconfig b/fs/pstore/Kconfig
> index d39bb5c..ca71db6 100644
> --- a/fs/pstore/Kconfig
> +++ b/fs/pstore/Kconfig
> @@ -23,6 +23,7 @@ config PSTORE_FTRACE
>  	bool "Persistent function tracer"
>  	depends on PSTORE
>  	depends on FUNCTION_TRACER
> +	depends on DEBUG_FS
>  	help
>  	  With this option kernel traces function calls into a persistent
>  	  ram buffer that can be decoded and dumped after reboot through
> diff --git a/fs/pstore/ftrace.c b/fs/pstore/ftrace.c
> index a130d48..824be81 100644
> --- a/fs/pstore/ftrace.c
> +++ b/fs/pstore/ftrace.c
> @@ -17,19 +17,111 @@
>  #include <linux/percpu.h>
>  #include <linux/smp.h>
>  #include <linux/atomic.h>
> +#include <linux/types.h>
> +#include <linux/mutex.h>
> +#include <linux/ftrace.h>
> +#include <linux/fs.h>
> +#include <linux/debugfs.h>
> +#include <linux/err.h>
>  #include <asm/barrier.h>
>  #include "internal.h"
>  
> -void notrace pstore_ftrace_call(unsigned long ip, unsigned long parent_ip)
> +static void notrace pstore_ftrace_call(unsigned long ip,
> +				       unsigned long parent_ip)
>  {
> +	unsigned long flags;
>  	struct pstore_ftrace_record rec = {};
>  
> +	if (unlikely(!ftrace_enabled))
> +		return;

You don't need this check. The ftrace_enabled is internal to ftrace and
the users shouldn't care. If we disable ftrace, the callback shouldn't
be executed. If it is, that's our fault ;-)


>  	if (unlikely(oops_in_progress))
>  		return;
>  
> +	local_irq_save(flags);
> +
>  	rec.ip = ip;
>  	rec.parent_ip = parent_ip;
>  	pstore_ftrace_encode_cpu(&rec, raw_smp_processor_id());
>  	psinfo->write_buf(PSTORE_TYPE_FTRACE, 0, NULL, 0, (void *)&rec,
>  			  sizeof(rec), psinfo);
> +
> +	local_irq_restore(flags);
> +}
> +
> +static struct ftrace_ops pstore_ftrace_ops __read_mostly = {
> +	.func	= pstore_ftrace_call,
> +};
> +
> +static DEFINE_MUTEX(pstore_ftrace_lock);
> +static bool pstore_ftrace_enabled;
> +
> +static ssize_t pstore_ftrace_knob_write(struct file *f, const char __user *buf,
> +					size_t count, loff_t *ppos)
> +{
> +	u8 on;
> +	int err;
> +
> +	err = kstrtou8_from_user(buf, count, 2, &on);
> +	if (err)
> +		return err;
> +
> +	mutex_lock(&pstore_ftrace_lock);
> +
> +	if (!on ^ pstore_ftrace_enabled)
> +		goto out;
> +	pstore_ftrace_enabled = on;
> +
> +	if (on)
> +		register_ftrace_function(&pstore_ftrace_ops);

You might want to check the return value of this.

-- Steve

> +	else
> +		unregister_ftrace_function(&pstore_ftrace_ops);
> +out:
> +	mutex_unlock(&pstore_ftrace_lock);
> +
> +	return count;
> +}
> +
> +static ssize_t pstore_ftrace_knob_read(struct file *f, char __user *buf,
> +				       size_t count, loff_t *ppos)
> +{
> +	char val[] = { '0' + pstore_ftrace_enabled, '\n' };
> +
> +	return simple_read_from_buffer(buf, count, ppos, val, sizeof(val));
> +}
> +
> +static const struct file_operations pstore_knob_fops = {
> +	.open	= simple_open,
> +	.read	= pstore_ftrace_knob_read,
> +	.write	= pstore_ftrace_knob_write,
> +};
> +
> +void pstore_register_ftrace(void)
> +{
> +	struct dentry *dir;
> +	struct dentry *file;
> +	int err;
> +
> +	if (!psinfo->write_buf)
> +		return;
> +
> +	dir = debugfs_create_dir("pstore", NULL);
> +	if (IS_ERR_OR_NULL(dir)) {
> +		err = PTR_ERR(dir);
> +		pr_err("%s: unable to create pstore debugfs: %d\n",
> +		       __func__, err);
> +		return;
> +	}
> +
> +	file = debugfs_create_file("record_ftrace", 0600, dir, NULL,
> +				   &pstore_knob_fops);
> +	if (IS_ERR_OR_NULL(file)) {
> +		err = PTR_ERR(file);
> +		pr_err("%s: unable to create pstore/ftrace file: %d\n",
> +		       __func__, err);
> +		goto err_file;
> +	}
> +
> +	return;
> +err_file:
> +	debugfs_remove(dir);
>  }

On Wed, 2012-07-18 at 00:26 -0700, Anton Vorontsov wrote:
> On Tue, Jul 17, 2012 at 08:47:22PM -0700, Anton Vorontsov wrote:
> [...]
> > -void notrace pstore_ftrace_call(unsigned long ip, unsigned long parent_ip)
> > +static void notrace pstore_ftrace_call(unsigned long ip,
> > +				       unsigned long parent_ip)
> >  {
> > +	unsigned long flags;
> >  	struct pstore_ftrace_record rec = {};
> >  
> > +	if (unlikely(!ftrace_enabled))
> > +		return;
> >  	if (unlikely(oops_in_progress))
> >  		return;
> >  
> > +	local_irq_save(flags);
> > +
> >  	rec.ip = ip;
> >  	rec.parent_ip = parent_ip;
> >  	pstore_ftrace_encode_cpu(&rec, raw_smp_processor_id());
> >  	psinfo->write_buf(PSTORE_TYPE_FTRACE, 0, NULL, 0, (void *)&rec,
> >  			  sizeof(rec), psinfo);
> 
> Btw, here we might be running w/o recurse protection, and that helped
> to find a bug in the persistent ram module.
> 
> The bug was quite subtle: it only happened if pstore tracing was
> enabled before any other tracers. And it magically disappeared
> otherwise.
> 
> This is because ftrace_ops_list_func() does its own recurse protection,
> but ftrace_ops_list_func() is only used when there are more than
> one 'struct ops' registered, otherwise ->func is called directly.
> 
> Of course, if I specify FL_GLOBAL/FL_CONTROL flag for the tracer,
> then it will not try to call the func directly. But then there is
> a question: do we really want to set these flags if we yet don't
> want removable modules?
> 
> Or, setting at least FL_CONTROL would be a good idea anyway, since
> it will then react to ftrace_function_local_{enable,disable}()?

I have a patch to fix this already. It's part of my kprobe/ftrace work.

The patch has been published here:

 https://lkml.org/lkml/2012/7/11/476

I'm hoping to get this ready for 3.6. Thus, don't worry about adding
recursion protection. ftrace should do that for you.

Thanks!

-- Steve

On 07/17/12 20:47, Anton Vorontsov wrote:
> +
> +	file = debugfs_create_file("record_ftrace", 0600, dir, NULL,
> +				   &pstore_knob_fops);
> +	if (IS_ERR_OR_NULL(file)) {
> +		err = PTR_ERR(file);
> +		pr_err("%s: unable to create pstore/ftrace file: %d\n",
> +		       __func__, err);
> +		goto err_file;
> +	}

debugfs only returns NULL on failure.

On Wed, Jul 18, 2012 at 10:12:44AM -0700, Stephen Boyd wrote:
> On 07/17/12 20:47, Anton Vorontsov wrote:
> > +
> > +	file = debugfs_create_file("record_ftrace", 0600, dir, NULL,
> > +				   &pstore_knob_fops);
> > +	if (IS_ERR_OR_NULL(file)) {
> > +		err = PTR_ERR(file);
> > +		pr_err("%s: unable to create pstore/ftrace file: %d\n",
> > +		       __func__, err);
> > +		goto err_file;
> > +	}
> 
> debugfs only returns NULL on failure.

Well, techincally, with DEBUG_FS=y, yes. (And we have dependency on
it.)

But see include/linux/debugfs.h for DEBUG_FS=n case:

static inline struct dentry *debugfs_create_file(const char *name, umode_t mode,
                                        struct dentry *parent, void *data,
                                        const struct file_operations *fops)
{
        return ERR_PTR(-ENODEV);
}

So, I think it is fine to check for IS_ERR_OR_NULL(), although today
it's always NULL for our case, true.

Thanks,

On 07/18/12 11:50, Anton Vorontsov wrote:
> On Wed, Jul 18, 2012 at 10:12:44AM -0700, Stephen Boyd wrote:
>> On 07/17/12 20:47, Anton Vorontsov wrote:
>>> +
>>> +	file = debugfs_create_file("record_ftrace", 0600, dir, NULL,
>>> +				   &pstore_knob_fops);
>>> +	if (IS_ERR_OR_NULL(file)) {
>>> +		err = PTR_ERR(file);
>>> +		pr_err("%s: unable to create pstore/ftrace file: %d\n",
>>> +		       __func__, err);
>>> +		goto err_file;
>>> +	}
>> debugfs only returns NULL on failure.
> Well, techincally, with DEBUG_FS=y, yes. (And we have dependency on
> it.)
>
> But see include/linux/debugfs.h for DEBUG_FS=n case:
>
> static inline struct dentry *debugfs_create_file(const char *name, umode_t mode,
>                                         struct dentry *parent, void *data,
>                                         const struct file_operations *fops)
> {
>         return ERR_PTR(-ENODEV);
> }
>
> So, I think it is fine to check for IS_ERR_OR_NULL(), although today
> it's always NULL for our case, true.

What does PTR_ERR(NULL) mean then? It will always print "unable to
create pstore/ftrace file: 0"?