Re: [PATCH 3/6] tracing: Add tp_pstore cmdline to have tracepoints go to pstore
From: Sai Prakash Ranjan <hidden>
Date: 2018-10-08 14:16:32
Also in:
linux-arm-kernel, linux-arm-msm, lkml
On 9/26/2018 3:16 PM, Sai Prakash Ranjan wrote:
On 9/26/2018 2:55 AM, Joel Fernandes wrote:quoted
On Sat, Sep 8, 2018 at 1:28 PM Sai Prakash Ranjan [off-list ref] wrote:quoted
Add the kernel command line tp_pstore option that will have tracepoints go to persistent ram buffer as well as to the trace buffer for further debugging. This is similar to tp_printk cmdline option of ftrace. Pstore support for event tracing is already added and we enable logging to pstore only if cmdline is specified. Passing "tp_pstore" will activate logging to pstore. To turn it off, the sysctl /proc/sys/kernel/tracepoint_pstore can have '0' echoed into it. Note, this only works if the cmdline option is used. Echoing 1 into the sysctl file without the cmdline option will have no affect. Signed-off-by: Sai Prakash Ranjan <redacted> --- .../admin-guide/kernel-parameters.txt | 21 ++++++++ include/linux/ftrace.h | 6 ++- kernel/sysctl.c | 7 +++ kernel/trace/Kconfig | 22 +++++++- kernel/trace/trace.c | 51 +++++++++++++++++++ kernel/trace/trace.h | 7 +++ 6 files changed, 112 insertions(+), 2 deletions(-)[...]quoted
config GCOV_PROFILE_FTRACE bool "Enable GCOV profiling on ftrace subsystem" depends on GCOV_KERNEL@@ -789,4 +810,3 @@ config GCOV_PROFILE_FTRACEendif # FTRACE endif # TRACING_SUPPORT -diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index bf6f1d70484d..018cbbefb769 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c@@ -73,6 +73,11 @@ struct trace_iterator *tracepoint_print_iter;int tracepoint_printk; static DEFINE_STATIC_KEY_FALSE(tracepoint_printk_key); +/* Pipe tracepoints to pstore */ +struct trace_iterator *tracepoint_pstore_iter; +int tracepoint_pstore; +static DEFINE_STATIC_KEY_FALSE(tracepoint_pstore_key); + /* For tracers that don't implement custom flags */ static struct tracer_opt dummy_tracer_opt[] = { { }@@ -238,6 +243,14 @@ static int __init set_tracepoint_printk(char *str)} __setup("tp_printk", set_tracepoint_printk); +static int __init set_tracepoint_pstore(char *str) +{ + if ((strcmp(str, "=0") != 0 && strcmp(str, "=off") != 0)) + tracepoint_pstore = 1; + return 1; +} +__setup("tp_pstore", set_tracepoint_pstore); + unsigned long long ns2usecs(u64 nsec) { nsec += 500;@@ -2376,11 +2389,45 @@ int tracepoint_printk_sysctl(struct ctl_table*table, int write, return ret; } +static DEFINE_MUTEX(tracepoint_pstore_mutex); + +int tracepoint_pstore_sysctl(struct ctl_table *table, int write, + void __user *buffer, size_t *lenp, + loff_t *ppos) +{ + int save_tracepoint_pstore; + int ret; + + mutex_lock(&tracepoint_pstore_mutex); + save_tracepoint_pstore = tracepoint_pstore; + + ret = proc_dointvec(table, write, buffer, lenp, ppos); + + if (!tracepoint_pstore_iter) + tracepoint_pstore = 0; + + if (save_tracepoint_pstore == tracepoint_pstore) + goto out; + + if (tracepoint_pstore) + static_key_enable(&tracepoint_pstore_key.key); + else + static_key_disable(&tracepoint_pstore_key.key); + + out: + mutex_unlock(&tracepoint_pstore_mutex); + + return ret; +} + void trace_event_buffer_commit(struct trace_event_buffer *fbuffer) { if (static_key_false(&tracepoint_printk_key.key)) output_printk(fbuffer); + if (static_key_false(&tracepoint_pstore_key.key)) + pstore_event_call(fbuffer);Can you not find a way to pass the size of the even record here, to pstore? Then you can directly allocate and store the binary record in pstore itself instead of rendering and storing the text in pstore which will be more space (and I think time) efficient. I also think if you do this, then you will not need to use the spinlock in the pstore (which AIUI is preventing the warning you're seeing in the event_call->event.funcs->trace() call).Right, I can check this out.
Hi Joel, Sorry for the long delay in updating this thread. But I just observed one weird behaviour in ftrace-ramoops when I was trying to use binary record instead of rendering text for event-ramoops. Even though we set the ftrace-size in device tree for ramoops, the actual ftrace-ramoops record seems to have more records than specified size. Is this expected or some bug? Below is the ftrace-ramoops size passed in dtsi for db410c and we can see that the ftrace record is more. # cat /sys/module/ramoops/parameters/ftrace_size 131072 # # cat /sys/fs/pstore/ftrace-ramoops-0 | wc -c 560888 # # cat /sys/fs/pstore/ftrace-ramoops-0 | grep CPU:0 | wc -c 137758 # # cat /sys/fs/pstore/ftrace-ramoops-0 | grep CPU:1 | wc -c 140560 # # cat /sys/fs/pstore/ftrace-ramoops-0 | grep CPU:2 | wc -c 141174 # # cat /sys/fs/pstore/ftrace-ramoops-0 | grep CPU:3 | wc -c 141396 # I don't see this in console or dmesg ramoops and also with the event-ramoops which I have posted since we don't use binary record, only ftrace-ramoops uses binary record to store trace data. Also regarding the warning on "event_call->event.funcs->trace()" call, I see it everytime without spinlock. Also we see output_printk using spinlock when making this call. I could not find a way to pass event buffer size and allocate in pstore. Steven can give some hints with this I guess. Steven Rostedt gave some reviews about using raw_spinlocks for this call earlier in this thread. So is it right to not use spinlocks for trace events? One difference I see in ftrace-ramoops and event-ramoops is that ftrace-ramoops is not started on boot and event-ramoops logging can be enabled from boot (late initcall however). Do let me know if you have any way to avoid this warning which is a race I think without spinlock. Thanks, Sai -- QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum, hosted by The Linux Foundation