Re: [PATCH v2 6/7] pstore: Add support to store timestamp counter in ftrace records

[Kees Cook]

On Thu, Oct 20, 2016 at 12:34 AM, Joel Fernandes <joelaf@xxxxxxxxxx> wrote:
> In preparation for merging the per CPU buffers into one buffer when we retrieve
> the pstore ftrace data, we store the timestamp as a counter in the ftrace
> pstore record.  We store the CPU number as well if !PSTORE_CPU_IN_IP, in this
> case we shift the counter and may lose ordering there but we preserve the same
> record size. The timestamp counter is also racy, and not doing any locking or
> synchronization here results in the benefit of lower overhead. Since we don't
> care much here for exact ordering of function traces across CPUs, we don't
> synchronize and may lose some counter updates but I'm ok with that.
>
> Using trace_clock() results in much lower performance so avoid using it since
> we don't want accuracy in timestamp and need a rough ordering to perform merge.
>
> Signed-off-by: Joel Fernandes <joelaf@xxxxxxxxxx>
> ---
>  fs/pstore/ftrace.c     |  3 +++
>  fs/pstore/inode.c      |  7 ++---
>  fs/pstore/internal.h   | 34 -------------------------
>  include/linux/pstore.h | 69 ++++++++++++++++++++++++++++++++++++++++++++++++++
>  4 files changed, 76 insertions(+), 37 deletions(-)
>
> diff --git a/fs/pstore/ftrace.c b/fs/pstore/ftrace.c
> index d488770..1c6cf86 100644
> --- a/fs/pstore/ftrace.c
> +++ b/fs/pstore/ftrace.c
> @@ -27,6 +27,8 @@
>  #include <asm/barrier.h>
>  #include "internal.h"
>
> +static u64 pstore_ftrace_stamp;

I think the race described in the commit message deserves a comment here.

> +
>  static void notrace pstore_ftrace_call(unsigned long ip,
>                                        unsigned long parent_ip,
>                                        struct ftrace_ops *op,
> @@ -42,6 +44,7 @@ static void notrace pstore_ftrace_call(unsigned long ip,
>
>         rec.ip = ip;
>         rec.parent_ip = parent_ip;
> +       pstore_ftrace_write_timestamp(&rec, pstore_ftrace_stamp++);
>         pstore_ftrace_encode_cpu(&rec, raw_smp_processor_id());
>         psinfo->write_buf(PSTORE_TYPE_FTRACE, 0, NULL, 0, (void *)&rec,
>                           0, sizeof(rec), psinfo);
> diff --git a/fs/pstore/inode.c b/fs/pstore/inode.c
> index ec9ddef..fcc5d1a 100644
> --- a/fs/pstore/inode.c
> +++ b/fs/pstore/inode.c
> @@ -107,9 +107,10 @@ static int pstore_ftrace_seq_show(struct seq_file *s, void *v)
>         struct pstore_ftrace_seq_data *data = v;
>         struct pstore_ftrace_record *rec = (void *)(ps->data + data->off);
>
> -       seq_printf(s, "%d %08lx  %08lx  %pf <- %pF\n",
> -               pstore_ftrace_decode_cpu(rec), rec->ip, rec->parent_ip,
> -               (void *)rec->ip, (void *)rec->parent_ip);
> +       seq_printf(s, "CPU:%d ts:%llu %08lx  %08lx  %pf <- %pF\n",
> +                  pstore_ftrace_decode_cpu(rec), pstore_ftrace_read_timestamp(rec),
> +                  rec->ip, rec->parent_ip, (void *)rec->ip,
> +                  (void *)rec->parent_ip);
>
>         return 0;
>  }
> diff --git a/fs/pstore/internal.h b/fs/pstore/internal.h
> index e38a22b..da416e6 100644
> --- a/fs/pstore/internal.h
> +++ b/fs/pstore/internal.h
> @@ -5,40 +5,6 @@
>  #include <linux/time.h>
>  #include <linux/pstore.h>
>
> -#if NR_CPUS <= 2 && defined(CONFIG_ARM_THUMB)
> -#define PSTORE_CPU_IN_IP 0x1
> -#elif NR_CPUS <= 4 && defined(CONFIG_ARM)
> -#define PSTORE_CPU_IN_IP 0x3
> -#endif
> -
> -struct pstore_ftrace_record {
> -       unsigned long ip;
> -       unsigned long parent_ip;
> -#ifndef PSTORE_CPU_IN_IP
> -       unsigned int cpu;
> -#endif
> -};
> -
> -static inline void
> -pstore_ftrace_encode_cpu(struct pstore_ftrace_record *rec, unsigned int cpu)
> -{
> -#ifndef PSTORE_CPU_IN_IP
> -       rec->cpu = cpu;
> -#else
> -       rec->ip |= cpu;
> -#endif
> -}
> -
> -static inline unsigned int
> -pstore_ftrace_decode_cpu(struct pstore_ftrace_record *rec)
> -{
> -#ifndef PSTORE_CPU_IN_IP
> -       return rec->cpu;
> -#else
> -       return rec->ip & PSTORE_CPU_IN_IP;
> -#endif
> -}
> -
>  #ifdef CONFIG_PSTORE_FTRACE
>  extern void pstore_register_ftrace(void);
>  extern void pstore_unregister_ftrace(void);
> diff --git a/include/linux/pstore.h b/include/linux/pstore.h
> index 92013cc..4e7fc3c 100644
> --- a/include/linux/pstore.h
> +++ b/include/linux/pstore.h
> @@ -89,4 +89,73 @@ extern int pstore_register(struct pstore_info *);
>  extern void pstore_unregister(struct pstore_info *);
>  extern bool pstore_cannot_block_path(enum kmsg_dump_reason reason);
>
> +struct pstore_ftrace_record {
> +       unsigned long ip;
> +       unsigned long parent_ip;
> +       u64 ts;
> +};
> +
> +/*
> + * ftrace related stuff: Both backends and frontends need these so expose them
> + */
> +
> +#if NR_CPUS <= 2 && defined(CONFIG_ARM_THUMB)
> +#define PSTORE_CPU_IN_IP 0x1
> +#elif NR_CPUS <= 4 && defined(CONFIG_ARM)
> +#define PSTORE_CPU_IN_IP 0x3
> +#endif
> +
> +#define TS_CPU_SHIFT 8
> +#define TS_CPU_MASK (BIT(TS_CPU_SHIFT) - 1)
> +
> +/*
> + * If CPU number can be stored in IP, store it there
> + * else store it in the time stamp.
> + */
> +#ifdef PSTORE_CPU_IN_IP
> +static inline void
> +pstore_ftrace_encode_cpu(struct pstore_ftrace_record *rec, unsigned int cpu)
> +{
> +       rec->ip |= cpu;
> +}
> +
> +static inline unsigned int
> +pstore_ftrace_decode_cpu(struct pstore_ftrace_record *rec)
> +{
> +       return rec->ip & PSTORE_CPU_IN_IP;
> +}
> +
> +static inline u64 pstore_ftrace_read_timestamp(struct pstore_ftrace_record *rec)
> +{
> +       return rec->ts;
> +}
> +
> +static inline void pstore_ftrace_write_timestamp(struct pstore_ftrace_record *rec, u64 val)
> +{
> +       rec->ts = val;
> +}
> +#else
> +static inline void
> +pstore_ftrace_encode_cpu(struct pstore_ftrace_record *rec, unsigned int cpu)
> +{
> +       rec->ts &= ~(TS_CPU_MASK);
> +       rec->ts |= cpu;
> +}
> +
> +static inline unsigned int
> +pstore_ftrace_decode_cpu(struct pstore_ftrace_record *rec)
> +{
> +       return rec->ts & TS_CPU_MASK;
> +}
> +
> +static inline u64 pstore_ftrace_read_timestamp(struct pstore_ftrace_record *rec)
> +{
> +       return rec->ts >> TS_CPU_SHIFT;
> +}
> +
> +static inline void pstore_ftrace_write_timestamp(struct pstore_ftrace_record *rec, u64 val)
> +{
> +       rec->ts = (rec->ts & TS_CPU_MASK) | (val << TS_CPU_SHIFT);
> +}
> +#endif
>  #endif /*_LINUX_PSTORE_H*/
> --
> 2.7.4
>

Should these ftrace helpers live somewhere else? It seems really
specific to ftrace, not pstore?

-Kees

-- 
Kees Cook
Nexus Security