Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756947AbcKKS3Q (ORCPT ); Fri, 11 Nov 2016 13:29:16 -0500 Received: from mail-wm0-f50.google.com ([74.125.82.50]:35659 "EHLO mail-wm0-f50.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756886AbcKKS3O (ORCPT ); Fri, 11 Nov 2016 13:29:14 -0500 MIME-Version: 1.0 In-Reply-To: References: <1476948846-15006-1-git-send-email-joelaf@google.com> <1476948846-15006-7-git-send-email-joelaf@google.com> From: Kees Cook Date: Fri, 11 Nov 2016 10:29:06 -0800 X-Google-Sender-Auth: xmF262gcE5LHr_fEVLWoKEhVWVQ Message-ID: Subject: Re: [PATCH v2 6/7] pstore: Add support to store timestamp counter in ftrace records To: Joel Fernandes Cc: LKML , Anton Vorontsov , Colin Cross , Tony Luck Content-Type: text/plain; charset=UTF-8 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 7322 Lines: 212 On Thu, Nov 10, 2016 at 4:21 PM, Joel Fernandes wrote: > On Thu, Nov 10, 2016 at 4:15 PM, Kees Cook wrote: >> On Thu, Oct 20, 2016 at 12:34 AM, Joel Fernandes 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 >>> --- >>> 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 >>> #include "internal.h" >>> >>> +static u64 pstore_ftrace_stamp; >> >> I think the race described in the commit message deserves a comment here. > > Sure, I can add that. > >>> + >>> 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 >>> #include >>> >>> -#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 >> > > Actually the time stamp and CPU information is not specific to low > level ftrace hooks. Ftrace just provides the hooks into the function > calls, its upto the user to store this information how they want. So > the pstore ftrace helpers should be included in the pstore header IMO. Okay, gotcha. Thanks! -Kees -- Kees Cook Nexus Security