On 9/26/2018 3:16 PM, Sai Prakash Ranjan wrote:
On 9/26/2018 2:55 AM, Joel Fernandes wrote:
On Sat, Sep 8, 2018 at 1:28 PM Sai Prakash Ranjan
<saiprakash.ranjan@xxxxxxxxxxxxxx> wrote:
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 <saiprakash.ranjan@xxxxxxxxxxxxxx>
---
.../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(-)
[...]
config GCOV_PROFILE_FTRACE
bool "Enable GCOV profiling on ftrace subsystem"
depends on GCOV_KERNEL
@@ -789,4 +810,3 @@ config GCOV_PROFILE_FTRACE
endif # 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
