Sorry for the top post. I've been wanting to do this as well for some time. It's quite useful. I am out of office this week and away from work machine. I will take a look at your patches next week once I'm back at work. Thanks. Best, J On Sun, Sep 16, 2018, 12:08 AM Sai Prakash Ranjan < saiprakash.ranjan@codeaurora.org> wrote: > On 9/9/2018 1:57 AM, Sai Prakash Ranjan wrote: > > Currently pstore has function trace support which can be > > used to get the function call chain with limited data. > > Event tracing has extra data which is useful to debug wide > > variety of issues and is heavily used across the kernel. > > > > Adding this support to pstore can be very helpful to debug > > different subsystems since almost all of them have trace > > events already available. And also it is useful to debug > > unknown resets or crashes since we can get lot more info > > from event tracing by viewing the last occurred events. > > > > High frequency tracepoints such as sched and irq has also > > been tested. This implementation is similar to "tp_printk" > > command line feature of ftrace by Steven. > > > > For example, sample pstore output of tracing sched events > > after reboot: > > > > # mount -t pstore pstore /sys/fs/pstore/ > > # tail /sys/fs/pstore/event-ramoops-0 > > sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 > prev_state=S ==> next_comm=rcu_preempt next_pid=10 next_prio=120 > > sched_switch: prev_comm=rcu_preempt prev_pid=10 prev_prio=120 > prev_state=R+ ==> next_comm=swapper/1 next_pid=0 next_prio=120 > > sched_waking: comm=rcu_sched pid=11 prio=120 target_cpu=002 > > sched_wakeup: comm=rcu_sched pid=11 prio=120 target_cpu=002 > > sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 > prev_state=S ==> next_comm=rcu_sched next_pid=11 next_prio=120 > > sched_switch: prev_comm=rcu_sched prev_pid=11 prev_prio=120 > prev_state=R+ ==> next_comm=swapper/2 next_pid=0 next_prio=120 > > sched_waking: comm=reboot pid=1867 prio=120 target_cpu=000 > > sched_wakeup: comm=reboot pid=1867 prio=120 target_cpu=000 > > sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 > prev_state=S ==> next_comm=reboot next_pid=1867 next_prio=120 > > > > Signed-off-by: Sai Prakash Ranjan > > --- > > fs/pstore/Kconfig | 2 +- > > fs/pstore/ftrace.c | 55 ++++++++++++++++++++++++++++++++++++++ > > fs/pstore/inode.c | 4 +++ > > fs/pstore/ram.c | 44 +++++++++++++++++++++++++++--- > > include/linux/pstore.h | 2 ++ > > include/linux/pstore_ram.h | 1 + > > 6 files changed, 104 insertions(+), 4 deletions(-) > > > > diff --git a/fs/pstore/Kconfig b/fs/pstore/Kconfig > > index 503086f7f7c1..6fe087b13a51 100644 > > --- a/fs/pstore/Kconfig > > +++ b/fs/pstore/Kconfig > > @@ -126,7 +126,7 @@ config PSTORE_PMSG > > > > config PSTORE_FTRACE > > bool "Persistent function tracer" > > - depends on PSTORE > > + depends on PSTORE && PSTORE!=m > > depends on FUNCTION_TRACER > > depends on DEBUG_FS > > help > > diff --git a/fs/pstore/ftrace.c b/fs/pstore/ftrace.c > > index 06aab07b6bb7..d47dc93ac098 100644 > > --- a/fs/pstore/ftrace.c > > +++ b/fs/pstore/ftrace.c > > @@ -24,6 +24,8 @@ > > #include > > #include > > #include > > +#include > > +#include > > #include > > #include "internal.h" > > > > @@ -62,6 +64,59 @@ static struct ftrace_ops pstore_ftrace_ops > __read_mostly = { > > .func = pstore_ftrace_call, > > }; > > > > +void notrace pstore_event_call(struct trace_event_buffer *fbuffer) > > +{ > > + struct trace_iterator *iter; > > + struct trace_seq *s; > > + struct trace_event_call *event_call; > > + struct pstore_record record; > > + struct trace_event *event; > > + struct seq_buf *seq; > > + unsigned long flags; > > + > > + if (!psinfo) > > + return; > > + > > + if (unlikely(oops_in_progress)) > > + return; > > + > > + pstore_record_init(&record, psinfo); > > + record.type = PSTORE_TYPE_EVENT; > > + > > + iter = kmalloc(sizeof(*iter), GFP_KERNEL); > > + if (!iter) > > + return; > > + > > + event_call = fbuffer->trace_file->event_call; > > + if (!event_call || !event_call->event.funcs || > > + !event_call->event.funcs->trace) > > + goto fail_event; > > + > > + event = &fbuffer->trace_file->event_call->event; > > + > > + spin_lock_irqsave(&psinfo->buf_lock, flags); > > + > > + trace_seq_init(&iter->seq); > > + iter->ent = fbuffer->entry; > > + event_call->event.funcs->trace(iter, 0, event); > > + trace_seq_putc(&iter->seq, 0); > > + > > + if (seq->size > psinfo->bufsize) > > + seq->size = psinfo->bufsize; > > + > > + s = &iter->seq; > > + seq = &s->seq; > > + > > + record.buf = (char *)(seq->buffer); > > + record.size = seq->len; > > + psinfo->write(&record); > > + > > + spin_unlock_irqrestore(&psinfo->buf_lock, flags); > > + > > +fail_event: > > + kfree(iter); > > +} > > + > > static DEFINE_MUTEX(pstore_ftrace_lock); > > static bool pstore_ftrace_enabled; > > > > diff --git a/fs/pstore/inode.c b/fs/pstore/inode.c > > index 5fcb845b9fec..f099152abbbd 100644 > > --- a/fs/pstore/inode.c > > +++ b/fs/pstore/inode.c > > @@ -345,6 +345,10 @@ int pstore_mkfile(struct dentry *root, struct > pstore_record *record) > > scnprintf(name, sizeof(name), "console-%s-%llu", > > record->psi->name, record->id); > > break; > > + case PSTORE_TYPE_EVENT: > > + scnprintf(name, sizeof(name), "event-%s-%llu", > > + record->psi->name, record->id); > > + break; > > case PSTORE_TYPE_FTRACE: > > scnprintf(name, sizeof(name), "ftrace-%s-%llu", > > record->psi->name, record->id); > > diff --git a/fs/pstore/ram.c b/fs/pstore/ram.c > > index bbd1e357c23d..f60d41c0309e 100644 > > --- a/fs/pstore/ram.c > > +++ b/fs/pstore/ram.c > > @@ -48,6 +48,10 @@ static ulong ramoops_console_size = MIN_MEM_SIZE; > > module_param_named(console_size, ramoops_console_size, ulong, 0400); > > MODULE_PARM_DESC(console_size, "size of kernel console log"); > > > > +static ulong ramoops_event_size = MIN_MEM_SIZE; > > +module_param_named(event_size, ramoops_event_size, ulong, 0400); > > +MODULE_PARM_DESC(event_size, "size of event log"); > > + > > static ulong ramoops_ftrace_size = MIN_MEM_SIZE; > > module_param_named(ftrace_size, ramoops_ftrace_size, ulong, 0400); > > MODULE_PARM_DESC(ftrace_size, "size of ftrace log"); > > @@ -86,6 +90,7 @@ MODULE_PARM_DESC(ramoops_ecc, > > struct ramoops_context { > > struct persistent_ram_zone **dprzs; /* Oops dump zones */ > > struct persistent_ram_zone *cprz; /* Console zone */ > > + struct persistent_ram_zone *eprz; /* Event zone */ > > struct persistent_ram_zone **fprzs; /* Ftrace zones */ > > struct persistent_ram_zone *mprz; /* PMSG zone */ > > phys_addr_t phys_addr; > > @@ -93,6 +98,7 @@ struct ramoops_context { > > unsigned int memtype; > > size_t record_size; > > size_t console_size; > > + size_t event_size; > > size_t ftrace_size; > > size_t pmsg_size; > > int dump_oops; > > @@ -103,6 +109,7 @@ struct ramoops_context { > > /* _read_cnt need clear on ramoops_pstore_open */ > > unsigned int dump_read_cnt; > > unsigned int console_read_cnt; > > + unsigned int event_read_cnt; > > unsigned int max_ftrace_cnt; > > unsigned int ftrace_read_cnt; > > unsigned int pmsg_read_cnt; > > @@ -118,6 +125,7 @@ static int ramoops_pstore_open(struct pstore_info > *psi) > > > > cxt->dump_read_cnt = 0; > > cxt->console_read_cnt = 0; > > + cxt->event_read_cnt = 0; > > cxt->ftrace_read_cnt = 0; > > cxt->pmsg_read_cnt = 0; > > return 0; > > @@ -277,6 +285,11 @@ static ssize_t ramoops_pstore_read(struct > pstore_record *record) > > 1, &record->id, &record->type, > > PSTORE_TYPE_CONSOLE, 0); > > > > + if (!prz_ok(prz)) > > + prz = ramoops_get_next_prz(&cxt->eprz, > &cxt->event_read_cnt, > > + 1, &record->id, &record->type, > > + PSTORE_TYPE_EVENT, 0); > > + > > if (!prz_ok(prz)) > > prz = ramoops_get_next_prz(&cxt->mprz, &cxt->pmsg_read_cnt, > > 1, &record->id, &record->type, > > @@ -385,6 +398,11 @@ static int notrace ramoops_pstore_write(struct > pstore_record *record) > > return -ENOMEM; > > persistent_ram_write(cxt->cprz, record->buf, record->size); > > return 0; > > + } else if (record->type == PSTORE_TYPE_EVENT) { > > + if (!cxt->eprz) > > + return -ENOMEM; > > + persistent_ram_write(cxt->eprz, record->buf, record->size); > > + return 0; > > } else if (record->type == PSTORE_TYPE_FTRACE) { > > int zonenum; > > > > @@ -475,6 +493,9 @@ static int ramoops_pstore_erase(struct pstore_record > *record) > > case PSTORE_TYPE_CONSOLE: > > prz = cxt->cprz; > > break; > > + case PSTORE_TYPE_EVENT: > > + prz = cxt->eprz; > > + break; > > case PSTORE_TYPE_FTRACE: > > if (record->id >= cxt->max_ftrace_cnt) > > return -EINVAL; > > @@ -699,6 +720,7 @@ static int ramoops_parse_dt(struct platform_device > *pdev, > > > > parse_size("record-size", pdata->record_size); > > parse_size("console-size", pdata->console_size); > > + parse_size("event-size", pdata->event_size); > > parse_size("ftrace-size", pdata->ftrace_size); > > parse_size("pmsg-size", pdata->pmsg_size); > > parse_size("ecc-size", pdata->ecc_info.ecc_size); > > @@ -747,7 +769,8 @@ static int ramoops_probe(struct platform_device > *pdev) > > } > > > > if (!pdata->mem_size || (!pdata->record_size && > !pdata->console_size && > > - !pdata->ftrace_size && !pdata->pmsg_size)) { > > + !pdata->event_size && !pdata->ftrace_size && > > + !pdata->pmsg_size)) { > > pr_err("The memory size and the record/console size must > be " > > "non-zero\n"); > > goto fail_out; > > @@ -757,6 +780,8 @@ static int ramoops_probe(struct platform_device > *pdev) > > pdata->record_size = > rounddown_pow_of_two(pdata->record_size); > > if (pdata->console_size && !is_power_of_2(pdata->console_size)) > > pdata->console_size = > rounddown_pow_of_two(pdata->console_size); > > + if (pdata->event_size && !is_power_of_2(pdata->event_size)) > > + pdata->event_size = > rounddown_pow_of_two(pdata->event_size); > > if (pdata->ftrace_size && !is_power_of_2(pdata->ftrace_size)) > > pdata->ftrace_size = > rounddown_pow_of_two(pdata->ftrace_size); > > if (pdata->pmsg_size && !is_power_of_2(pdata->pmsg_size)) > > @@ -767,6 +792,7 @@ static int ramoops_probe(struct platform_device > *pdev) > > cxt->memtype = pdata->mem_type; > > cxt->record_size = pdata->record_size; > > cxt->console_size = pdata->console_size; > > + cxt->event_size = pdata->event_size; > > cxt->ftrace_size = pdata->ftrace_size; > > cxt->pmsg_size = pdata->pmsg_size; > > cxt->dump_oops = pdata->dump_oops; > > @@ -775,8 +801,8 @@ static int ramoops_probe(struct platform_device > *pdev) > > > > paddr = cxt->phys_addr; > > > > - dump_mem_sz = cxt->size - cxt->console_size - cxt->ftrace_size > > - - cxt->pmsg_size; > > + dump_mem_sz = cxt->size - cxt->console_size - cxt->event_size > > + - cxt->ftrace_size - cxt->pmsg_size; > > err = ramoops_init_przs("dump", dev, cxt, &cxt->dprzs, &paddr, > > dump_mem_sz, cxt->record_size, > > &cxt->max_dump_cnt, 0, 0); > > @@ -788,6 +814,11 @@ static int ramoops_probe(struct platform_device > *pdev) > > if (err) > > goto fail_init_cprz; > > > > + err = ramoops_init_prz("event", dev, cxt, &cxt->eprz, &paddr, > > + cxt->event_size, 0); > > + if (err) > > + goto fail_init_eprz; > > + > > cxt->max_ftrace_cnt = (cxt->flags & RAMOOPS_FLAG_FTRACE_PER_CPU) > > ? nr_cpu_ids > > : 1; > > @@ -825,6 +856,8 @@ static int ramoops_probe(struct platform_device > *pdev) > > cxt->pstore.flags = PSTORE_FLAGS_DMESG; > > if (cxt->console_size) > > cxt->pstore.flags |= PSTORE_FLAGS_CONSOLE; > > + if (cxt->event_size) > > + cxt->pstore.flags |= PSTORE_FLAGS_EVENT; > > if (cxt->ftrace_size) > > cxt->pstore.flags |= PSTORE_FLAGS_FTRACE; > > if (cxt->pmsg_size) > > @@ -845,6 +878,7 @@ static int ramoops_probe(struct platform_device > *pdev) > > record_size = pdata->record_size; > > dump_oops = pdata->dump_oops; > > ramoops_console_size = pdata->console_size; > > + ramoops_event_size = pdata->event_size; > > ramoops_pmsg_size = pdata->pmsg_size; > > ramoops_ftrace_size = pdata->ftrace_size; > > > > @@ -858,6 +892,8 @@ static int ramoops_probe(struct platform_device > *pdev) > > kfree(cxt->pstore.buf); > > fail_clear: > > cxt->pstore.bufsize = 0; > > + persistent_ram_free(cxt->eprz); > > +fail_init_eprz: > > persistent_ram_free(cxt->mprz); > > fail_init_mprz: > > fail_init_fprz: > > @@ -877,6 +913,7 @@ static int ramoops_remove(struct platform_device > *pdev) > > kfree(cxt->pstore.buf); > > cxt->pstore.bufsize = 0; > > > > + persistent_ram_free(cxt->eprz); > > persistent_ram_free(cxt->mprz); > > persistent_ram_free(cxt->cprz); > > ramoops_free_przs(cxt); > > @@ -916,6 +953,7 @@ static void ramoops_register_dummy(void) > > dummy_data->mem_type = mem_type; > > dummy_data->record_size = record_size; > > dummy_data->console_size = ramoops_console_size; > > + dummy_data->event_size = ramoops_event_size; > > dummy_data->ftrace_size = ramoops_ftrace_size; > > dummy_data->pmsg_size = ramoops_pmsg_size; > > dummy_data->dump_oops = dump_oops; > > diff --git a/include/linux/pstore.h b/include/linux/pstore.h > > index a15bc4d48752..c31bb9567b4a 100644 > > --- a/include/linux/pstore.h > > +++ b/include/linux/pstore.h > > @@ -44,6 +44,7 @@ enum pstore_type_id { > > PSTORE_TYPE_PPC_COMMON = 6, > > PSTORE_TYPE_PMSG = 7, > > PSTORE_TYPE_PPC_OPAL = 8, > > + PSTORE_TYPE_EVENT = 9, > > PSTORE_TYPE_UNKNOWN = 255 > > }; > > > > @@ -193,6 +194,7 @@ struct pstore_info { > > #define PSTORE_FLAGS_CONSOLE (1 << 1) > > #define PSTORE_FLAGS_FTRACE (1 << 2) > > #define PSTORE_FLAGS_PMSG (1 << 3) > > +#define PSTORE_FLAGS_EVENT (1 << 4) > > > > extern int pstore_register(struct pstore_info *); > > extern void pstore_unregister(struct pstore_info *); > > diff --git a/include/linux/pstore_ram.h b/include/linux/pstore_ram.h > > index e6d226464838..f01055c6cc40 100644 > > --- a/include/linux/pstore_ram.h > > +++ b/include/linux/pstore_ram.h > > @@ -95,6 +95,7 @@ struct ramoops_platform_data { > > unsigned int mem_type; > > unsigned long record_size; > > unsigned long console_size; > > + unsigned long event_size; > > unsigned long ftrace_size; > > unsigned long pmsg_size; > > int dump_oops; > > > > Hi, > > Anyone here? >