by Kees Cook

[permalink] [raw]

Subject: Re: [PATCH v2 5/7] ramoops: Split ftrace buffer space into per-CPU zones

On Thu, Nov 10, 2016 at 4:16 PM, Joel Fernandes <[email protected]> wrote:
> On Thu, Nov 10, 2016 at 4:13 PM, Kees Cook <[email protected]> wrote:
>> On Thu, Oct 20, 2016 at 12:34 AM, Joel Fernandes <[email protected]> wrote:
>>> If FTRACE_PER_CPU flag is passed to ramoops pdata, split the space into
>>> multiple zones depending on the number of CPUs.
>>>
>>> This speeds up the performance of function tracing by about 280% in my tests as
>>> we avoid the locking. The trade off being lesser space available per CPU. Let
>>> the ramoops user decide which option they want based on pdata flag.
>>>
>>> Signed-off-by: Joel Fernandes <[email protected]>
>>> ---
>>> fs/pstore/ram.c | 72 +++++++++++++++++++++++++++++++++++-----------
>>> include/linux/pstore_ram.h | 3 ++
>>> 2 files changed, 58 insertions(+), 17 deletions(-)
>>>
>>> diff --git a/fs/pstore/ram.c b/fs/pstore/ram.c
>>> index 5caa512..5e96f78 100644
>>> --- a/fs/pstore/ram.c
>>> +++ b/fs/pstore/ram.c
>>> @@ -87,7 +87,7 @@ MODULE_PARM_DESC(ramoops_ecc,
>>> struct ramoops_context {
>>> struct persistent_ram_zone **przs;
>>> struct persistent_ram_zone *cprz;
>>> - struct persistent_ram_zone *fprz;
>>> + struct persistent_ram_zone **fprzs;
>>> struct persistent_ram_zone *mprz;
>>> phys_addr_t phys_addr;
>>> unsigned long size;
>>> @@ -97,6 +97,7 @@ struct ramoops_context {
>>> size_t ftrace_size;
>>> size_t pmsg_size;
>>> int dump_oops;
>>> + int flags;
>>> struct persistent_ram_ecc_info ecc_info;
>>> unsigned int max_dump_cnt;
>>> unsigned int dump_write_cnt;
>>> @@ -219,9 +220,17 @@ static ssize_t ramoops_pstore_read(u64 *id, enum pstore_type_id *type,
>>> if (!prz_ok(prz))
>>> prz = ramoops_get_next_prz(&cxt->cprz, &cxt->console_read_cnt,
>>> 1, id, type, PSTORE_TYPE_CONSOLE, 0);
>>> - if (!prz_ok(prz))
>>> - prz = ramoops_get_next_prz(&cxt->fprz, &cxt->ftrace_read_cnt,
>>> - 1, id, type, PSTORE_TYPE_FTRACE, 0);
>>> + if (!prz_ok(prz)) {
>>> + int max = (cxt->flags & FTRACE_PER_CPU) ? nr_cpu_ids : 1;
>>> + while (cxt->ftrace_read_cnt < max && !prz) {
>>> + prz = ramoops_get_next_prz(cxt->fprzs,
>>> + &cxt->ftrace_read_cnt, max, id, type,
>>> + PSTORE_TYPE_FTRACE, 0);
>>> + if (!prz_ok(prz))
>>> + continue;
>>> + }
>>> + }
>>> +
>>> if (!prz_ok(prz))
>>> prz = ramoops_get_next_prz(&cxt->mprz, &cxt->pmsg_read_cnt,
>>> 1, id, type, PSTORE_TYPE_PMSG, 0);
>>> @@ -283,9 +292,23 @@ static int notrace ramoops_pstore_write_buf(enum pstore_type_id type,
>>> persistent_ram_write(cxt->cprz, buf, size, PSTORE_RAM_LOCK);
>>> return 0;
>>> } else if (type == PSTORE_TYPE_FTRACE) {
>>> - if (!cxt->fprz)
>>> + int zonenum, lock;
>>> +
>>> + if (!cxt->fprzs)
>>> return -ENOMEM;
>>> - persistent_ram_write(cxt->fprz, buf, size, PSTORE_RAM_LOCK);
>>> + /*
>>> + * If per-cpu buffers, don't lock. Otherwise there's only
>>> + * 1 zone for ftrace (zone 0) and all CPUs share it, so lock.
>>> + */
>>> + if (cxt->flags & FTRACE_PER_CPU) {
>>> + zonenum = smp_processor_id();
>>> + lock = PSTORE_RAM_NOLOCK;
>>> + } else {
>>> + zonenum = 0;
>>> + lock = PSTORE_RAM_LOCK;
>>> + }
>>> +
>>> + persistent_ram_write(cxt->fprzs[zonenum], buf, size, lock);
>>> return 0;
>>> } else if (type == PSTORE_TYPE_PMSG) {
>>> pr_warn_ratelimited("ramoops: warning: PMSG shouldn't call %s\n",
>>> @@ -352,6 +375,7 @@ static int ramoops_pstore_erase(enum pstore_type_id type, u64 id, int count,
>>> {
>>> struct ramoops_context *cxt = psi->data;
>>> struct persistent_ram_zone *prz;
>>> + int max;
>>>
>>> switch (type) {
>>> case PSTORE_TYPE_DMESG:
>>> @@ -363,7 +387,10 @@ static int ramoops_pstore_erase(enum pstore_type_id type, u64 id, int count,
>>> prz = cxt->cprz;
>>> break;
>>> case PSTORE_TYPE_FTRACE:
>>> - prz = cxt->fprz;
>>> + max = (cxt->flags & FTRACE_PER_CPU) ? nr_cpu_ids : 1;
>>> + if (id >= max)
>>> + return -EINVAL;
>>> + prz = cxt->fprzs[id];
>>> break;
>>> case PSTORE_TYPE_PMSG:
>>> prz = cxt->mprz;
>>> @@ -394,14 +421,23 @@ static void ramoops_free_przs(struct ramoops_context *cxt)
>>> {
>>> int i;
>>>
>>> - if (!cxt->przs)
>>> - return;
>>> + /* Free dump PRZs */
>>> + if (cxt->przs) {
>>> + for (i = 0; i < cxt->max_dump_cnt; i++)
>>> + persistent_ram_free(cxt->przs[i]);
>>>
>>> - for (i = 0; i < cxt->max_dump_cnt; i++)
>>> - persistent_ram_free(cxt->przs[i]);
>>> + kfree(cxt->przs);
>>> + cxt->max_dump_cnt = 0;
>>> + }
>>>
>>> - kfree(cxt->przs);
>>> - cxt->max_dump_cnt = 0;
>>> + /* Free ftrace PRZs */
>>> + if (cxt->fprzs) {
>>> + int nr = (cxt->flags & FTRACE_PER_CPU) ? nr_cpu_ids : 1;
>>> +
>>> + for (i = 0; i < nr; i++)
>>> + persistent_ram_free(cxt->fprzs[i]);
>>> + kfree(cxt->fprzs);
>>> + }
>>> }
>>>
>>> static int ramoops_init_przs(struct device *dev, struct ramoops_context *cxt,
>>> @@ -618,6 +654,7 @@ static int ramoops_probe(struct platform_device *pdev)
>>> cxt->ftrace_size = pdata->ftrace_size;
>>> cxt->pmsg_size = pdata->pmsg_size;
>>> cxt->dump_oops = pdata->dump_oops;
>>> + cxt->flags = pdata->flags;
>>> cxt->ecc_info = pdata->ecc_info;
>>>
>>> paddr = cxt->phys_addr;
>>> @@ -633,8 +670,9 @@ static int ramoops_probe(struct platform_device *pdev)
>>> if (err)
>>> goto fail_init_cprz;
>>>
>>> - err = ramoops_init_prz(dev, cxt, &cxt->fprz, &paddr, cxt->ftrace_size,
>>> - LINUX_VERSION_CODE);
>>> + err = ramoops_init_przs(dev, cxt, &cxt->fprzs, &paddr, cxt->ftrace_size,
>>> + (cxt->flags & FTRACE_PER_CPU) ? nr_cpu_ids : 1,
>>> + LINUX_VERSION_CODE);
>>> if (err)
>>> goto fail_init_fprz;
>>>
>>> @@ -698,7 +736,6 @@ fail_clear:
>>> cxt->pstore.bufsize = 0;
>>> persistent_ram_free(cxt->mprz);
>>> fail_init_mprz:
>>> - persistent_ram_free(cxt->fprz);
>>> fail_init_fprz:
>>> persistent_ram_free(cxt->cprz);
>>> fail_init_cprz:
>>> @@ -717,7 +754,6 @@ static int ramoops_remove(struct platform_device *pdev)
>>> cxt->pstore.bufsize = 0;
>>>
>>> persistent_ram_free(cxt->mprz);
>>> - persistent_ram_free(cxt->fprz);
>>> persistent_ram_free(cxt->cprz);
>>> ramoops_free_przs(cxt);
>>>
>>> @@ -759,6 +795,8 @@ static void ramoops_register_dummy(void)
>>> dummy_data->ftrace_size = ramoops_ftrace_size;
>>> dummy_data->pmsg_size = ramoops_pmsg_size;
>>> dummy_data->dump_oops = dump_oops;
>>> + dummy_data->flags = FTRACE_PER_CPU;
>>> +
>>> /*
>>> * For backwards compatibility ramoops.ecc=1 means 16 bytes ECC
>>> * (using 1 byte for ECC isn't much of use anyway).
>>> diff --git a/include/linux/pstore_ram.h b/include/linux/pstore_ram.h
>>> index 69f3487..122f78d 100644
>>> --- a/include/linux/pstore_ram.h
>>> +++ b/include/linux/pstore_ram.h
>>> @@ -86,6 +86,8 @@ ssize_t persistent_ram_ecc_string(struct persistent_ram_zone *prz,
>>> * @mem_address physical memory address to contain ramoops
>>> */
>>>
>>> +#define FTRACE_PER_CPU BIT(0)
>>> +
>>> struct ramoops_platform_data {
>>> unsigned long mem_size;
>>> phys_addr_t mem_address;
>>> @@ -95,6 +97,7 @@ struct ramoops_platform_data {
>>> unsigned long ftrace_size;
>>> unsigned long pmsg_size;
>>> int dump_oops;
>>> + int flags;
>>> struct persistent_ram_ecc_info ecc_info;
>>> };
>>>
>>> --
>>> 2.7.4
>>>
>>
>> Is there a case for not setting FTRACE_PER_CPU?
>
> Yes, if there are too many CPUs and only a few are in use, then the
> rest of the space allocated for the other CPUs not in use go waste. If
> the ram zone is begin enough though, then it still makes sense even
> for the many CPUs case.

Okay. In this case, let's make flags a u32, since int doesn't make
sense for flags. Also, with the addition of this in the platform data,
"flags" will need to be added to the EFI implementation
(ramoops_parse_dt() with a default of 0) and documentation
(Documentation/devicetree/bindings/reserved-memory/ramoops.txt).

-Kees

--
Kees Cook
Nexus Security

2016-11-11 18:29:16

by Kees Cook

[permalink] [raw]

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

On Thu, Nov 10, 2016 at 4:21 PM, Joel Fernandes <[email protected]> wrote:
> On Thu, Nov 10, 2016 at 4:15 PM, Kees Cook <[email protected]> wrote:
>> On Thu, Oct 20, 2016 at 12:34 AM, Joel Fernandes <[email protected]> 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 <[email protected]>
>>> ---
>>> 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.
>
> 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 <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
>>
>
> 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