[PATCH] tracing: let user specify tracing_thresh after selecting function_graph

[PATCH] tracing: let user specify tracing_thresh after selecting function_graph

[Stanislav Fomichev]

Currently, tracing_thresh works only if we specify it before selecting
function_graph tracer. If we do the opposite, tracing_thresh will change
it's value, but it will not be applied.
To fix it, we need to always register handlers which take tracing_thresh into
account.

Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
---
 kernel/trace/trace_functions_graph.c | 8 ++------
 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index deff11200261..a894031986a3 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -433,12 +433,8 @@ static int graph_trace_init(struct trace_array *tr)
 	int ret;
 
 	set_graph_array(tr);
-	if (tracing_thresh)
-		ret = register_ftrace_graph(&trace_graph_thresh_return,
-					    &trace_graph_thresh_entry);
-	else
-		ret = register_ftrace_graph(&trace_graph_return,
-					    &trace_graph_entry);
+	ret = register_ftrace_graph(&trace_graph_thresh_return,
+				    &trace_graph_thresh_entry);
 	if (ret)
 		return ret;
 	tracing_start_cmdline_record();
-- 
1.8.3.2

Re: [PATCH] tracing: let user specify tracing_thresh after selecting function_graph

[Steven Rostedt]

On Tue,  3 Jun 2014 21:12:49 +0400
Stanislav Fomichev <stfomichev@yandex-team.ru> wrote:

> Currently, tracing_thresh works only if we specify it before selecting
> function_graph tracer. If we do the opposite, tracing_thresh will change
> it's value, but it will not be applied.
> To fix it, we need to always register handlers which take tracing_thresh into
> account.
> 
> Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
> ---
>  kernel/trace/trace_functions_graph.c | 8 ++------
>  1 file changed, 2 insertions(+), 6 deletions(-)
> 
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index deff11200261..a894031986a3 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -433,12 +433,8 @@ static int graph_trace_init(struct trace_array *tr)
>  	int ret;
>  
>  	set_graph_array(tr);
> -	if (tracing_thresh)
> -		ret = register_ftrace_graph(&trace_graph_thresh_return,
> -					    &trace_graph_thresh_entry);
> -	else
> -		ret = register_ftrace_graph(&trace_graph_return,
> -					    &trace_graph_entry);
> +	ret = register_ftrace_graph(&trace_graph_thresh_return,
> +				    &trace_graph_thresh_entry);
>  	if (ret)
>  		return ret;
>  	tracing_start_cmdline_record();

I would rather not endure the overhead of checking tracing_thresh
every time. I never use it, I didn't even know there was someone that
did ;-)

I'm not saying you can't fix this bug, I'm just saying that it
shouldn't be done this way.

Ideally there should be a callback for the tracer to deal with it, but
instead, you can for now just hardcode a function graph tracer callback
into tracing_max_lat_write(). Something like this:

	if (ptr == &tracing_thresh)
		ftrace_update_func_graph_thresh();

And then if the function tracer is active, stop it, and then restart it
with the tracing thresh function.

-- Steve

Re: [PATCHv2] tracing: let user specify tracing_thresh after selecting function_graph

[Stanislav Fomichev]

> Ideally there should be a callback for the tracer to deal with it, but
> instead, you can for now just hardcode a function graph tracer callback
> into tracing_max_lat_write(). Something like this:
> 
> 	if (ptr == &tracing_thresh)
> 		ftrace_update_func_graph_thresh();
> 
> And then if the function tracer is active, stop it, and then restart it
> with the tracing thresh function.
Attached new patch which adds new callback and uses it in function_graph
tracer (not sure whether I need to check graph_array in
graph_trace_update_thresh). Maybe it makes sense to split it into two commits
(add callback itself, use it in the function_graph tracer)?

Btw, I also tried to use static_keys/jump_labels in places where
tracing_thresh is checked, but got double faults. Is there a reason I
can't use jump labels inside tracers?

---

Currently, tracing_thresh works only if we specify it before selecting
function_graph tracer. If we do the opposite, tracing_thresh will change
it's value, but it will not be applied.
To fix it, we add update_thresh callback which is called whenever
tracing_thresh is updated and for function_graph tracer we register
handler which reinitializes tracer depending on tracing_thresh.

Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
---
 kernel/trace/trace.c                 | 60 +++++++++++++++++++++++++++++++-----
 kernel/trace/trace.h                 |  2 ++
 kernel/trace/trace_functions_graph.c | 10 ++++++
 3 files changed, 65 insertions(+), 7 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 737b0efa1a62..06fbb4b7e646 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4077,10 +4077,9 @@ tracing_set_trace_write(struct file *filp, const char __user *ubuf,
 }
 
 static ssize_t
-tracing_max_lat_read(struct file *filp, char __user *ubuf,
-		     size_t cnt, loff_t *ppos)
+nsecs_read(unsigned long *ptr, char __user *ubuf,
+	   size_t cnt, loff_t *ppos)
 {
-	unsigned long *ptr = filp->private_data;
 	char buf[64];
 	int r;
 
@@ -4092,10 +4091,9 @@ tracing_max_lat_read(struct file *filp, char __user *ubuf,
 }
 
 static ssize_t
-tracing_max_lat_write(struct file *filp, const char __user *ubuf,
-		      size_t cnt, loff_t *ppos)
+nsecs_write(unsigned long *ptr, const char __user *ubuf,
+	    size_t cnt, loff_t *ppos)
 {
-	unsigned long *ptr = filp->private_data;
 	unsigned long val;
 	int ret;
 
@@ -4108,6 +4106,47 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
 	return cnt;
 }
 
+static ssize_t
+tracing_thresh_read(struct file *filp, char __user *ubuf,
+		    size_t cnt, loff_t *ppos)
+{
+	return nsecs_read(&tracing_thresh, ubuf, cnt, ppos);
+}
+
+static ssize_t
+tracing_thresh_write(struct file *filp, const char __user *ubuf,
+		     size_t cnt, loff_t *ppos)
+{
+	struct trace_array *tr = filp->private_data;
+	int ret;
+
+	ret = nsecs_write(&tracing_thresh, ubuf, cnt, ppos);
+	if (ret < 0)
+		return ret;
+
+	if (tr->current_trace->update_thresh) {
+		ret = tr->current_trace->update_thresh(tr);
+		if (ret)
+			return ret;
+	}
+
+	return cnt;
+}
+
+static ssize_t
+tracing_max_lat_read(struct file *filp, char __user *ubuf,
+		     size_t cnt, loff_t *ppos)
+{
+	return nsecs_read(filp->private_data, ubuf, cnt, ppos);
+}
+
+static ssize_t
+tracing_max_lat_write(struct file *filp, const char __user *ubuf,
+		      size_t cnt, loff_t *ppos)
+{
+	return nsecs_write(filp->private_data, ubuf, cnt, ppos);
+}
+
 static int tracing_open_pipe(struct inode *inode, struct file *filp)
 {
 	struct trace_array *tr = inode->i_private;
@@ -5024,6 +5063,13 @@ static int snapshot_raw_open(struct inode *inode, struct file *filp)
 #endif /* CONFIG_TRACER_SNAPSHOT */
 
 
+static const struct file_operations tracing_thresh_fops = {
+	.open		= tracing_open_generic,
+	.read		= tracing_thresh_read,
+	.write		= tracing_thresh_write,
+	.llseek		= generic_file_llseek,
+};
+
 static const struct file_operations tracing_max_lat_fops = {
 	.open		= tracing_open_generic,
 	.read		= tracing_max_lat_read,
@@ -6359,7 +6405,7 @@ static __init int tracer_init_debugfs(void)
 #endif
 
 	trace_create_file("tracing_thresh", 0644, d_tracer,
-			&tracing_thresh, &tracing_max_lat_fops);
+			&global_trace, &tracing_thresh_fops);
 
 	trace_create_file("README", 0444, d_tracer,
 			NULL, &tracing_readme_fops);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 2e29d7ba5a52..960c523de47d 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -321,6 +321,7 @@ struct tracer_flags {
  * @reset: called when one switches to another tracer
  * @start: called when tracing is unpaused (echo 1 > tracing_enabled)
  * @stop: called when tracing is paused (echo 0 > tracing_enabled)
+ * @update_thresh: called when tracing_thresh is updated
  * @open: called when the trace file is opened
  * @pipe_open: called when the trace_pipe file is opened
  * @wait_pipe: override how the user waits for traces on trace_pipe
@@ -340,6 +341,7 @@ struct tracer {
 	void			(*reset)(struct trace_array *tr);
 	void			(*start)(struct trace_array *tr);
 	void			(*stop)(struct trace_array *tr);
+	int			(*update_thresh)(struct trace_array *tr);
 	void			(*open)(struct trace_iterator *iter);
 	void			(*pipe_open)(struct trace_iterator *iter);
 	void			(*wait_pipe)(struct trace_iterator *iter);
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index deff11200261..7440541a3b4f 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -450,6 +450,15 @@ static void graph_trace_reset(struct trace_array *tr)
 {
 	tracing_stop_cmdline_record();
 	unregister_ftrace_graph();
+	set_graph_array(NULL);
+}
+
+void graph_trace_update_thresh(struct trace_array *tr)
+{
+	if (graph_array) {
+		graph_trace_reset(tr);
+		graph_trace_init(tr);
+	}
 }
 
 static int max_bytes_for_cpu;
@@ -1501,6 +1510,7 @@ static struct trace_event graph_trace_ret_event = {
 
 static struct tracer graph_trace __tracer_data = {
 	.name		= "function_graph",
+	.update_thresh	= graph_trace_update_thresh,
 	.open		= graph_trace_open,
 	.pipe_open	= graph_trace_open,
 	.close		= graph_trace_close,
-- 
1.8.3.2

Re: [PATCHv2] tracing: let user specify tracing_thresh after selecting function_graph

[Steven Rostedt]

On Wed, 4 Jun 2014 17:33:50 +0400
Stanislav Fomichev <stfomichev@yandex-team.ru> wrote:

> > Ideally there should be a callback for the tracer to deal with it, but
> > instead, you can for now just hardcode a function graph tracer callback
> > into tracing_max_lat_write(). Something like this:
> > 
> > 	if (ptr == &tracing_thresh)
> > 		ftrace_update_func_graph_thresh();
> > 
> > And then if the function tracer is active, stop it, and then restart it
> > with the tracing thresh function.
> Attached new patch which adds new callback and uses it in function_graph
> tracer (not sure whether I need to check graph_array in
> graph_trace_update_thresh). Maybe it makes sense to split it into two commits
> (add callback itself, use it in the function_graph tracer)?

Sometimes it's better to do it in two commits, but as this is rather
a small change, one is good enough.

> 
> Btw, I also tried to use static_keys/jump_labels in places where
> tracing_thresh is checked, but got double faults. Is there a reason I
> can't use jump labels inside tracers?

You mean inside the function tracers. I could envision problems with
that, but I don't know exactly what would cause those problems. Have
patches to show? You may have done something unrelated that caused the
issue.

> 
> ---
> 
> Currently, tracing_thresh works only if we specify it before selecting
> function_graph tracer. If we do the opposite, tracing_thresh will change
> it's value, but it will not be applied.
> To fix it, we add update_thresh callback which is called whenever
> tracing_thresh is updated and for function_graph tracer we register
> handler which reinitializes tracer depending on tracing_thresh.
> 
> Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
> ---
>  kernel/trace/trace.c                 | 60 +++++++++++++++++++++++++++++++-----
>  kernel/trace/trace.h                 |  2 ++
>  kernel/trace/trace_functions_graph.c | 10 ++++++
>  3 files changed, 65 insertions(+), 7 deletions(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 737b0efa1a62..06fbb4b7e646 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4077,10 +4077,9 @@ tracing_set_trace_write(struct file *filp, const char __user *ubuf,
>  }
>  
>  static ssize_t
> -tracing_max_lat_read(struct file *filp, char __user *ubuf,
> -		     size_t cnt, loff_t *ppos)
> +nsecs_read(unsigned long *ptr, char __user *ubuf,

Nit, although these are static functions, I still like to add "trace"
or "tracing" to their names. Makes it easier to grep for.

> +	   size_t cnt, loff_t *ppos)
>  {
> -	unsigned long *ptr = filp->private_data;
>  	char buf[64];
>  	int r;
>  
> @@ -4092,10 +4091,9 @@ tracing_max_lat_read(struct file *filp, char __user *ubuf,
>  }
>  
>  static ssize_t
> -tracing_max_lat_write(struct file *filp, const char __user *ubuf,
> -		      size_t cnt, loff_t *ppos)
> +nsecs_write(unsigned long *ptr, const char __user *ubuf,
> +	    size_t cnt, loff_t *ppos)
>  {
> -	unsigned long *ptr = filp->private_data;
>  	unsigned long val;
>  	int ret;
>  
> @@ -4108,6 +4106,47 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
>  	return cnt;
>  }
>  
> +static ssize_t
> +tracing_thresh_read(struct file *filp, char __user *ubuf,
> +		    size_t cnt, loff_t *ppos)
> +{
> +	return nsecs_read(&tracing_thresh, ubuf, cnt, ppos);
> +}
> +
> +static ssize_t
> +tracing_thresh_write(struct file *filp, const char __user *ubuf,
> +		     size_t cnt, loff_t *ppos)
> +{
> +	struct trace_array *tr = filp->private_data;
> +	int ret;
> +
> +	ret = nsecs_write(&tracing_thresh, ubuf, cnt, ppos);
> +	if (ret < 0)
> +		return ret;
> +

You need to take the trace_types_lock mutex here, otherwise
current_trace can change from under you.

-- Steve


> +	if (tr->current_trace->update_thresh) {
> +		ret = tr->current_trace->update_thresh(tr);
> +		if (ret)
> +			return ret;
> +	}
> +
> +	return cnt;
> +}
> +
> +static ssize_t
> +tracing_max_lat_read(struct file *filp, char __user *ubuf,
> +		     size_t cnt, loff_t *ppos)
> +{
> +	return nsecs_read(filp->private_data, ubuf, cnt, ppos);
> +}
> +
> +static ssize_t
> +tracing_max_lat_write(struct file *filp, const char __user *ubuf,
> +		      size_t cnt, loff_t *ppos)
> +{
> +	return nsecs_write(filp->private_data, ubuf, cnt, ppos);
> +}
> +
>  static int tracing_open_pipe(struct inode *inode, struct file *filp)
>  {
>  	struct trace_array *tr = inode->i_private;
> @@ -5024,6 +5063,13 @@ static int snapshot_raw_open(struct inode *inode, struct file *filp)
>  #endif /* CONFIG_TRACER_SNAPSHOT */
>  
>  
> +static const struct file_operations tracing_thresh_fops = {
> +	.open		= tracing_open_generic,
> +	.read		= tracing_thresh_read,
> +	.write		= tracing_thresh_write,
> +	.llseek		= generic_file_llseek,
> +};
> +
>  static const struct file_operations tracing_max_lat_fops = {
>  	.open		= tracing_open_generic,
>  	.read		= tracing_max_lat_read,
> @@ -6359,7 +6405,7 @@ static __init int tracer_init_debugfs(void)
>  #endif
>  
>  	trace_create_file("tracing_thresh", 0644, d_tracer,
> -			&tracing_thresh, &tracing_max_lat_fops);
> +			&global_trace, &tracing_thresh_fops);
>  
>  	trace_create_file("README", 0444, d_tracer,
>  			NULL, &tracing_readme_fops);
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 2e29d7ba5a52..960c523de47d 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -321,6 +321,7 @@ struct tracer_flags {
>   * @reset: called when one switches to another tracer
>   * @start: called when tracing is unpaused (echo 1 > tracing_enabled)
>   * @stop: called when tracing is paused (echo 0 > tracing_enabled)
> + * @update_thresh: called when tracing_thresh is updated
>   * @open: called when the trace file is opened
>   * @pipe_open: called when the trace_pipe file is opened
>   * @wait_pipe: override how the user waits for traces on trace_pipe
> @@ -340,6 +341,7 @@ struct tracer {
>  	void			(*reset)(struct trace_array *tr);
>  	void			(*start)(struct trace_array *tr);
>  	void			(*stop)(struct trace_array *tr);
> +	int			(*update_thresh)(struct trace_array *tr);
>  	void			(*open)(struct trace_iterator *iter);
>  	void			(*pipe_open)(struct trace_iterator *iter);
>  	void			(*wait_pipe)(struct trace_iterator *iter);
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index deff11200261..7440541a3b4f 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -450,6 +450,15 @@ static void graph_trace_reset(struct trace_array *tr)
>  {
>  	tracing_stop_cmdline_record();
>  	unregister_ftrace_graph();
> +	set_graph_array(NULL);

Hmm, this looks like it can cause issues. Unless you change
trace_graph_entry() and trace_graph_return to have:

	struct trace_array *tr = ACCESS_ONCE(graph_array);
	[..]

	if (!tr)
		return 0;

-- Steve

> +}
> +
> +void graph_trace_update_thresh(struct trace_array *tr)
> +{
> +	if (graph_array) {
> +		graph_trace_reset(tr);
> +		graph_trace_init(tr);
> +	}
>  }
>  
>  static int max_bytes_for_cpu;
> @@ -1501,6 +1510,7 @@ static struct trace_event graph_trace_ret_event = {
>  
>  static struct tracer graph_trace __tracer_data = {
>  	.name		= "function_graph",
> +	.update_thresh	= graph_trace_update_thresh,
>  	.open		= graph_trace_open,
>  	.pipe_open	= graph_trace_open,
>  	.close		= graph_trace_close,

Re: [PATCHv2] tracing: let user specify tracing_thresh after selecting function_graph

[Stanislav Fomichev]

> You mean inside the function tracers. I could envision problems with
> that, but I don't know exactly what would cause those problems. Have
> patches to show? You may have done something unrelated that caused the
> issue.
Maybe I'm using jump labels incorrectly, patch attached below.
And, when I set tracing_thresh after selecting function_graph, I get:

[   42.337679] PANIC: double fault, error_code: 0x0
[   42.337357] PANIC: double fault, error_code: 0x0
[   42.337357] CPU: 1 PID: 1388 Comm: bash Not tainted 3.15.0-upstream #33
[   42.337357] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   42.337357] task: ffff88001f5b3aa0 ti: ffff8800185d4000 task.ti: ffff8800185d4000
[   42.337357] RIP: 0010:[<ffffffff811006d4>]  [<ffffffff811006d4>] trace_buffer_lock_reserve+0x4/0x80
[   42.337357] RSP: 0000:ffff88001f7ffff0  EFLAGS: 00010086
[   42.337357] RAX: 0000000000000000 RBX: ffff88001e409d80 RCX: 0000000000000046
[   42.337357] RDX: 0000000000000018 RSI: 000000000000000b RDI: ffff88001e409d80
[   42.337357] RBP: ffff88001f800070 R08: 0000000000000000 R09: 0000000000000554
[   42.337357] R10: 0000000000000000 R11: 0000000000000013 R12: ffffffff81054e30
[   42.337357] R13: 0000000000000000 R14: 0000000000000286 R15: 0000000000000003
[   42.337357] FS:  00007f5a6cd83700(0000) GS:ffff88001fd00000(0000) knlGS:0000000000000000
[   42.337357] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   42.337357] CR2: ffff88001f7fffe8 CR3: 0000000000e20000 CR4: 00000000000006e0
[   42.337357] Stack:
[   42.337357]  ffffffffa0010f50 ffffffffa0011170
[   42.337357] Call Trace:
[   42.337357]  <UNK> 
[   42.337357] Code: 02 00 00 48 63 ca 89 14 bd a0 4b ed 81 89 34 8d 60 43 eb 81 89 35 bd 44 dd 00 e9 45 ff ff ff 0f 1f 84 00 00 00 00 00 48 83 ec 28 <48> 89 1c 24 89 f3 48 8
9 d6 48 89 6c 24 08 4c 89 64 24 10 48 89 
[   42.337357] Kernel panic - not syncing: Machine halted.
[   42.337357] CPU: 1 PID: 1388 Comm: bash Not tainted 3.15.0-upstream #33
[   42.337357] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   42.337357]  0000000000000000 ffffffff810184f5 ffffffff816673d3 ffffffff8193437f
[   42.337357]  ffffffff8166223e 0000000000000000 ffffffff00000008 ffff88001fd06f28
[   42.337357]  ffff88001fd06ec8 00000000000012cc 0000000000000082 0000000000000082
[   42.337357] Call Trace:
[   42.337357]  <#DF>  [<ffffffff810184f5>] ? show_stack+0x5/0x50
[   42.337357]  [<ffffffff816673d3>] ? dump_stack+0x41/0x51
[   42.337357]  [<ffffffff8166223e>] ? panic+0xca/0x1e7
[   42.337357]  [<ffffffff8104d89d>] ? df_debug+0x2d/0x30
[   42.337357]  [<ffffffff81015518>] ? do_double_fault+0x58/0x80
[   42.337357]  [<ffffffff81054e30>] ? perf_trace_x86_exceptions+0x130/0x130
[   42.337357]  [<ffffffff81670d08>] ? double_fault+0x28/0x30
[   42.337357]  [<ffffffff81054e30>] ? perf_trace_x86_exceptions+0x130/0x130
[   42.337357]  [<ffffffff811006d4>] ? trace_buffer_lock_reserve+0x4/0x80
[   42.337679]  <<EOE>>  <UNK> 
[   42.337679] CPU: 0 PID: 1386 Comm: sshd Not tainted 3.15.0-upstream #33
[   42.337679] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   42.337679] task: ffff88001f5b29e0 ti: ffff88001849c000 task.ti: ffff88001849c000
[   42.337679] RIP: 0010:[<ffffffff811006d4>]  [<ffffffff811006d4>] trace_buffer_lock_reserve+0x4/0x80
[   42.337679] RSP: 0018:ffff88001f7ffff0  EFLAGS: 00010086
[   42.337679] RAX: 0000000000000000 RBX: ffff88001e409d80 RCX: 0000000000000046
[   42.337679] RDX: 0000000000000018 RSI: 000000000000000b RDI: ffff88001e409d80
[   42.337679] RBP: ffff88001f800070 R08: 0000000000010000 R09: 00000000000000f4
[   42.337679] R10: 0000000000000000 R11: 0000000000000010 R12: ffffffff81054e30
[   42.337679] R13: 0000000000000000 R14: ffff88001fc0dff8 R15: 0000000000000003
[   42.337679] FS:  00007f2b388a87c0(0000) GS:ffff88001fc00000(0000) knlGS:0000000000000000
[   42.337679] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   42.337679] CR2: ffff88001f7fffe8 CR3: 00000000179ea000 CR4: 00000000000006f0
[   42.337679] Stack:
[   42.337679]  ffffffffa0010f50 ffffffffa0011170
[   42.337679] Call Trace:
[   42.337679]  <UNK> 
[   42.337679] Code: 02 00 00 48 63 ca 89 14 bd a0 4b ed 81 89 34 8d 60 43 eb 81 89 35 bd 44 dd 00 e9 45 ff ff ff 0f 1f 84 00 00 00 00 00 48 83 ec 28 <48> 89 1c 24 89 f3 48 89 d6 48 89 6c 24 08 4c 89 64 24 10 48 89 
[   42.337357] Shutting down cpus with NMI
[   42.337357] Kernel Offset: 0x0 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffff9fffffff)
[   42.337357] ---[ end Kernel panic - not syncing: Machine halted.

--

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 737b0efa1a62..0b58d2ff94f6 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -750,6 +750,14 @@ static int __init set_buf_size(char *str)
 }
 __setup("trace_buf_size=", set_buf_size);
 
+static void update_tracing_thresh_enabled(void)
+{
+	if (tracing_thresh && !static_key_enabled(&__tracing_thresh_enabled))
+		static_key_slow_inc(&__tracing_thresh_enabled);
+	if (!tracing_thresh && static_key_enabled(&__tracing_thresh_enabled))
+		static_key_slow_dec(&__tracing_thresh_enabled);
+}
+
 static int __init set_tracing_thresh(char *str)
 {
 	unsigned long threshold;
@@ -761,6 +769,7 @@ static int __init set_tracing_thresh(char *str)
 	if (ret < 0)
 		return 0;
 	tracing_thresh = threshold * 1000;
+	update_tracing_thresh_enabled();
 	return 1;
 }
 __setup("tracing_thresh=", set_tracing_thresh);
@@ -980,6 +989,7 @@ static arch_spinlock_t ftrace_max_lock =
 	(arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED;
 
 unsigned long __read_mostly	tracing_thresh;
+struct static_key		__tracing_thresh_enabled;
 
 #ifdef CONFIG_TRACER_MAX_TRACE
 unsigned long __read_mostly	tracing_max_latency;
@@ -4104,6 +4114,7 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
 		return ret;
 
 	*ptr = val * 1000;
+	update_tracing_thresh_enabled();
 
 	return cnt;
 }
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 2e29d7ba5a52..ab32c1f33917 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -606,6 +606,12 @@ extern cpumask_var_t __read_mostly tracing_buffer_mask;
 extern unsigned long nsecs_to_usecs(unsigned long nsecs);
 
 extern unsigned long tracing_thresh;
+extern struct static_key __tracing_thresh_enabled;
+
+static inline bool tracing_thresh_enabled(void)
+{
+	return static_key_false(&__tracing_thresh_enabled);
+}
 
 #ifdef CONFIG_TRACER_MAX_TRACE
 extern unsigned long tracing_max_latency;
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index deff11200261..0a893120c05a 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -332,7 +332,7 @@ int trace_graph_entry(struct ftrace_graph_ent *trace)
 
 int trace_graph_thresh_entry(struct ftrace_graph_ent *trace)
 {
-	if (tracing_thresh)
+	if (tracing_thresh_enabled())
 		return 1;
 	else
 		return trace_graph_entry(trace);
@@ -421,7 +421,7 @@ void set_graph_array(struct trace_array *tr)
 
 void trace_graph_thresh_return(struct ftrace_graph_ret *trace)
 {
-	if (tracing_thresh &&
+	if (tracing_thresh_enabled() &&
 	    (trace->rettime - trace->calltime < tracing_thresh))
 		return;
 	else
@@ -433,12 +433,8 @@ static int graph_trace_init(struct trace_array *tr)
 	int ret;
 
 	set_graph_array(tr);
-	if (tracing_thresh)
-		ret = register_ftrace_graph(&trace_graph_thresh_return,
-					    &trace_graph_thresh_entry);
-	else
-		ret = register_ftrace_graph(&trace_graph_return,
-					    &trace_graph_entry);
+	ret = register_ftrace_graph(&trace_graph_thresh_return,
+				    &trace_graph_thresh_entry);
 	if (ret)
 		return ret;
 	tracing_start_cmdline_record();

Re: [PATCHv2] tracing: let user specify tracing_thresh after selecting function_graph

[Stanislav Fomichev]

Hi Steven,

Did you have some spare time to check why I'm getting triple fault with the
jump labels inside function tracers? Or will you just pull my another
patch without them?

On Thu, Jun 05, 2014 at 11:38:39AM +0400, Stanislav Fomichev wrote:
> > You mean inside the function tracers. I could envision problems with
> > that, but I don't know exactly what would cause those problems. Have
> > patches to show? You may have done something unrelated that caused the
> > issue.
> Maybe I'm using jump labels incorrectly, patch attached below.
> And, when I set tracing_thresh after selecting function_graph, I get:
> 
> [   42.337679] PANIC: double fault, error_code: 0x0
> [   42.337357] PANIC: double fault, error_code: 0x0
> [   42.337357] CPU: 1 PID: 1388 Comm: bash Not tainted 3.15.0-upstream #33
> [   42.337357] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [   42.337357] task: ffff88001f5b3aa0 ti: ffff8800185d4000 task.ti: ffff8800185d4000
> [   42.337357] RIP: 0010:[<ffffffff811006d4>]  [<ffffffff811006d4>] trace_buffer_lock_reserve+0x4/0x80
> [   42.337357] RSP: 0000:ffff88001f7ffff0  EFLAGS: 00010086
> [   42.337357] RAX: 0000000000000000 RBX: ffff88001e409d80 RCX: 0000000000000046
> [   42.337357] RDX: 0000000000000018 RSI: 000000000000000b RDI: ffff88001e409d80
> [   42.337357] RBP: ffff88001f800070 R08: 0000000000000000 R09: 0000000000000554
> [   42.337357] R10: 0000000000000000 R11: 0000000000000013 R12: ffffffff81054e30
> [   42.337357] R13: 0000000000000000 R14: 0000000000000286 R15: 0000000000000003
> [   42.337357] FS:  00007f5a6cd83700(0000) GS:ffff88001fd00000(0000) knlGS:0000000000000000
> [   42.337357] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   42.337357] CR2: ffff88001f7fffe8 CR3: 0000000000e20000 CR4: 00000000000006e0
> [   42.337357] Stack:
> [   42.337357]  ffffffffa0010f50 ffffffffa0011170
> [   42.337357] Call Trace:
> [   42.337357]  <UNK> 
> [   42.337357] Code: 02 00 00 48 63 ca 89 14 bd a0 4b ed 81 89 34 8d 60 43 eb 81 89 35 bd 44 dd 00 e9 45 ff ff ff 0f 1f 84 00 00 00 00 00 48 83 ec 28 <48> 89 1c 24 89 f3 48 8
> 9 d6 48 89 6c 24 08 4c 89 64 24 10 48 89 
> [   42.337357] Kernel panic - not syncing: Machine halted.
> [   42.337357] CPU: 1 PID: 1388 Comm: bash Not tainted 3.15.0-upstream #33
> [   42.337357] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [   42.337357]  0000000000000000 ffffffff810184f5 ffffffff816673d3 ffffffff8193437f
> [   42.337357]  ffffffff8166223e 0000000000000000 ffffffff00000008 ffff88001fd06f28
> [   42.337357]  ffff88001fd06ec8 00000000000012cc 0000000000000082 0000000000000082
> [   42.337357] Call Trace:
> [   42.337357]  <#DF>  [<ffffffff810184f5>] ? show_stack+0x5/0x50
> [   42.337357]  [<ffffffff816673d3>] ? dump_stack+0x41/0x51
> [   42.337357]  [<ffffffff8166223e>] ? panic+0xca/0x1e7
> [   42.337357]  [<ffffffff8104d89d>] ? df_debug+0x2d/0x30
> [   42.337357]  [<ffffffff81015518>] ? do_double_fault+0x58/0x80
> [   42.337357]  [<ffffffff81054e30>] ? perf_trace_x86_exceptions+0x130/0x130
> [   42.337357]  [<ffffffff81670d08>] ? double_fault+0x28/0x30
> [   42.337357]  [<ffffffff81054e30>] ? perf_trace_x86_exceptions+0x130/0x130
> [   42.337357]  [<ffffffff811006d4>] ? trace_buffer_lock_reserve+0x4/0x80
> [   42.337679]  <<EOE>>  <UNK> 
> [   42.337679] CPU: 0 PID: 1386 Comm: sshd Not tainted 3.15.0-upstream #33
> [   42.337679] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [   42.337679] task: ffff88001f5b29e0 ti: ffff88001849c000 task.ti: ffff88001849c000
> [   42.337679] RIP: 0010:[<ffffffff811006d4>]  [<ffffffff811006d4>] trace_buffer_lock_reserve+0x4/0x80
> [   42.337679] RSP: 0018:ffff88001f7ffff0  EFLAGS: 00010086
> [   42.337679] RAX: 0000000000000000 RBX: ffff88001e409d80 RCX: 0000000000000046
> [   42.337679] RDX: 0000000000000018 RSI: 000000000000000b RDI: ffff88001e409d80
> [   42.337679] RBP: ffff88001f800070 R08: 0000000000010000 R09: 00000000000000f4
> [   42.337679] R10: 0000000000000000 R11: 0000000000000010 R12: ffffffff81054e30
> [   42.337679] R13: 0000000000000000 R14: ffff88001fc0dff8 R15: 0000000000000003
> [   42.337679] FS:  00007f2b388a87c0(0000) GS:ffff88001fc00000(0000) knlGS:0000000000000000
> [   42.337679] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   42.337679] CR2: ffff88001f7fffe8 CR3: 00000000179ea000 CR4: 00000000000006f0
> [   42.337679] Stack:
> [   42.337679]  ffffffffa0010f50 ffffffffa0011170
> [   42.337679] Call Trace:
> [   42.337679]  <UNK> 
> [   42.337679] Code: 02 00 00 48 63 ca 89 14 bd a0 4b ed 81 89 34 8d 60 43 eb 81 89 35 bd 44 dd 00 e9 45 ff ff ff 0f 1f 84 00 00 00 00 00 48 83 ec 28 <48> 89 1c 24 89 f3 48 89 d6 48 89 6c 24 08 4c 89 64 24 10 48 89 
> [   42.337357] Shutting down cpus with NMI
> [   42.337357] Kernel Offset: 0x0 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffff9fffffff)
> [   42.337357] ---[ end Kernel panic - not syncing: Machine halted.
> 
> --
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 737b0efa1a62..0b58d2ff94f6 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -750,6 +750,14 @@ static int __init set_buf_size(char *str)
>  }
>  __setup("trace_buf_size=", set_buf_size);
>  
> +static void update_tracing_thresh_enabled(void)
> +{
> +	if (tracing_thresh && !static_key_enabled(&__tracing_thresh_enabled))
> +		static_key_slow_inc(&__tracing_thresh_enabled);
> +	if (!tracing_thresh && static_key_enabled(&__tracing_thresh_enabled))
> +		static_key_slow_dec(&__tracing_thresh_enabled);
> +}
> +
>  static int __init set_tracing_thresh(char *str)
>  {
>  	unsigned long threshold;
> @@ -761,6 +769,7 @@ static int __init set_tracing_thresh(char *str)
>  	if (ret < 0)
>  		return 0;
>  	tracing_thresh = threshold * 1000;
> +	update_tracing_thresh_enabled();
>  	return 1;
>  }
>  __setup("tracing_thresh=", set_tracing_thresh);
> @@ -980,6 +989,7 @@ static arch_spinlock_t ftrace_max_lock =
>  	(arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED;
>  
>  unsigned long __read_mostly	tracing_thresh;
> +struct static_key		__tracing_thresh_enabled;
>  
>  #ifdef CONFIG_TRACER_MAX_TRACE
>  unsigned long __read_mostly	tracing_max_latency;
> @@ -4104,6 +4114,7 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
>  		return ret;
>  
>  	*ptr = val * 1000;
> +	update_tracing_thresh_enabled();
>  
>  	return cnt;
>  }
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 2e29d7ba5a52..ab32c1f33917 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -606,6 +606,12 @@ extern cpumask_var_t __read_mostly tracing_buffer_mask;
>  extern unsigned long nsecs_to_usecs(unsigned long nsecs);
>  
>  extern unsigned long tracing_thresh;
> +extern struct static_key __tracing_thresh_enabled;
> +
> +static inline bool tracing_thresh_enabled(void)
> +{
> +	return static_key_false(&__tracing_thresh_enabled);
> +}
>  
>  #ifdef CONFIG_TRACER_MAX_TRACE
>  extern unsigned long tracing_max_latency;
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index deff11200261..0a893120c05a 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -332,7 +332,7 @@ int trace_graph_entry(struct ftrace_graph_ent *trace)
>  
>  int trace_graph_thresh_entry(struct ftrace_graph_ent *trace)
>  {
> -	if (tracing_thresh)
> +	if (tracing_thresh_enabled())
>  		return 1;
>  	else
>  		return trace_graph_entry(trace);
> @@ -421,7 +421,7 @@ void set_graph_array(struct trace_array *tr)
>  
>  void trace_graph_thresh_return(struct ftrace_graph_ret *trace)
>  {
> -	if (tracing_thresh &&
> +	if (tracing_thresh_enabled() &&
>  	    (trace->rettime - trace->calltime < tracing_thresh))
>  		return;
>  	else
> @@ -433,12 +433,8 @@ static int graph_trace_init(struct trace_array *tr)
>  	int ret;
>  
>  	set_graph_array(tr);
> -	if (tracing_thresh)
> -		ret = register_ftrace_graph(&trace_graph_thresh_return,
> -					    &trace_graph_thresh_entry);
> -	else
> -		ret = register_ftrace_graph(&trace_graph_return,
> -					    &trace_graph_entry);
> +	ret = register_ftrace_graph(&trace_graph_thresh_return,
> +				    &trace_graph_thresh_entry);
>  	if (ret)
>  		return ret;
>  	tracing_start_cmdline_record();

-- 
Станислав Фомичев
http://staff/stfomichev

Re: [PATCHv2] tracing: let user specify tracing_thresh after selecting function_graph

[Steven Rostedt]

On Tue, 15 Jul 2014 13:27:19 +0400
Stanislav Fomichev <stfomichev@yandex-team.ru> wrote:

> Hi Steven,
> 
> Did you have some spare time to check why I'm getting triple fault with the
> jump labels inside function tracers? Or will you just pull my another
> patch without them?

No, I don't want the overhead of that check if it isn't needed. You
don't need to put a jump label in there either.

Just create another ftrace_ops function that we can update that does
the check when the function is needed. Look at what happens when
someone sets the set_ftrace_pid file.

-- Steve

Re: [PATCHv3] tracing: let user specify tracing_thresh after selecting function_graph

[Stanislav Fomichev]

Currently, tracing_thresh works only if we specify it before selecting
function_graph tracer. If we do the opposite, tracing_thresh will change
it's value, but it will not be applied.
To fix it, we add update_thresh callback which is called whenever
tracing_thresh is updated and for function_graph tracer we register
handler which reinitializes tracer depending on tracing_thresh.

Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
---
 kernel/trace/trace.c                 | 65 ++++++++++++++++++++++++++++++++----
 kernel/trace/trace.h                 |  2 ++
 kernel/trace/trace_functions_graph.c | 20 +++++++++--
 3 files changed, 77 insertions(+), 10 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index f243444a3772..986e6cad27d7 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4224,10 +4224,9 @@ tracing_set_trace_write(struct file *filp, const char __user *ubuf,
 }
 
 static ssize_t
-tracing_max_lat_read(struct file *filp, char __user *ubuf,
-		     size_t cnt, loff_t *ppos)
+tracing_nsecs_read(unsigned long *ptr, char __user *ubuf,
+		   size_t cnt, loff_t *ppos)
 {
-	unsigned long *ptr = filp->private_data;
 	char buf[64];
 	int r;
 
@@ -4239,10 +4238,9 @@ tracing_max_lat_read(struct file *filp, char __user *ubuf,
 }
 
 static ssize_t
-tracing_max_lat_write(struct file *filp, const char __user *ubuf,
-		      size_t cnt, loff_t *ppos)
+tracing_nsecs_write(unsigned long *ptr, const char __user *ubuf,
+		    size_t cnt, loff_t *ppos)
 {
-	unsigned long *ptr = filp->private_data;
 	unsigned long val;
 	int ret;
 
@@ -4255,6 +4253,52 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
 	return cnt;
 }
 
+static ssize_t
+tracing_thresh_read(struct file *filp, char __user *ubuf,
+		    size_t cnt, loff_t *ppos)
+{
+	return tracing_nsecs_read(&tracing_thresh, ubuf, cnt, ppos);
+}
+
+static ssize_t
+tracing_thresh_write(struct file *filp, const char __user *ubuf,
+		     size_t cnt, loff_t *ppos)
+{
+	struct trace_array *tr = filp->private_data;
+	int ret;
+
+	mutex_lock(&trace_types_lock);
+	ret = tracing_nsecs_write(&tracing_thresh, ubuf, cnt, ppos);
+	if (ret < 0)
+		goto out;
+
+	if (tr->current_trace->update_thresh) {
+		ret = tr->current_trace->update_thresh(tr);
+		if (ret < 0)
+			goto out;
+	}
+
+	ret = cnt;
+out:
+	mutex_unlock(&trace_types_lock);
+
+	return ret;
+}
+
+static ssize_t
+tracing_max_lat_read(struct file *filp, char __user *ubuf,
+		     size_t cnt, loff_t *ppos)
+{
+	return tracing_nsecs_read(filp->private_data, ubuf, cnt, ppos);
+}
+
+static ssize_t
+tracing_max_lat_write(struct file *filp, const char __user *ubuf,
+		      size_t cnt, loff_t *ppos)
+{
+	return tracing_nsecs_write(filp->private_data, ubuf, cnt, ppos);
+}
+
 static int tracing_open_pipe(struct inode *inode, struct file *filp)
 {
 	struct trace_array *tr = inode->i_private;
@@ -5156,6 +5200,13 @@ static int snapshot_raw_open(struct inode *inode, struct file *filp)
 #endif /* CONFIG_TRACER_SNAPSHOT */
 
 
+static const struct file_operations tracing_thresh_fops = {
+	.open		= tracing_open_generic,
+	.read		= tracing_thresh_read,
+	.write		= tracing_thresh_write,
+	.llseek		= generic_file_llseek,
+};
+
 static const struct file_operations tracing_max_lat_fops = {
 	.open		= tracing_open_generic,
 	.read		= tracing_max_lat_read,
@@ -6519,7 +6570,7 @@ static __init int tracer_init_debugfs(void)
 	init_tracer_debugfs(&global_trace, d_tracer);
 
 	trace_create_file("tracing_thresh", 0644, d_tracer,
-			&tracing_thresh, &tracing_max_lat_fops);
+			&global_trace, &tracing_thresh_fops);
 
 	trace_create_file("README", 0444, d_tracer,
 			NULL, &tracing_readme_fops);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 9258f5a815db..385391fb1d3b 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -339,6 +339,7 @@ struct tracer_flags {
  * @reset: called when one switches to another tracer
  * @start: called when tracing is unpaused (echo 1 > tracing_enabled)
  * @stop: called when tracing is paused (echo 0 > tracing_enabled)
+ * @update_thresh: called when tracing_thresh is updated
  * @open: called when the trace file is opened
  * @pipe_open: called when the trace_pipe file is opened
  * @close: called when the trace file is released
@@ -357,6 +358,7 @@ struct tracer {
 	void			(*reset)(struct trace_array *tr);
 	void			(*start)(struct trace_array *tr);
 	void			(*stop)(struct trace_array *tr);
+	int			(*update_thresh)(struct trace_array *tr);
 	void			(*open)(struct trace_iterator *iter);
 	void			(*pipe_open)(struct trace_iterator *iter);
 	void			(*close)(struct trace_iterator *iter);
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 4de3e57f723c..10d86cf83cb8 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -279,7 +279,7 @@ static inline int ftrace_graph_ignore_irqs(void)
 
 int trace_graph_entry(struct ftrace_graph_ent *trace)
 {
-	struct trace_array *tr = graph_array;
+	struct trace_array *tr = ACCESS_ONCE(graph_array);
 	struct trace_array_cpu *data;
 	unsigned long flags;
 	long disabled;
@@ -287,7 +287,7 @@ int trace_graph_entry(struct ftrace_graph_ent *trace)
 	int cpu;
 	int pc;
 
-	if (!ftrace_trace_task(current))
+	if (!tr || !ftrace_trace_task(current))
 		return 0;
 
 	/* trace it when it is-nested-in or is a function enabled. */
@@ -384,13 +384,16 @@ void __trace_graph_return(struct trace_array *tr,
 
 void trace_graph_return(struct ftrace_graph_ret *trace)
 {
-	struct trace_array *tr = graph_array;
+	struct trace_array *tr = ACCESS_ONCE(graph_array);
 	struct trace_array_cpu *data;
 	unsigned long flags;
 	long disabled;
 	int cpu;
 	int pc;
 
+	if (!tr)
+		return;
+
 	local_irq_save(flags);
 	cpu = raw_smp_processor_id();
 	data = per_cpu_ptr(tr->trace_buffer.data, cpu);
@@ -443,6 +446,16 @@ static void graph_trace_reset(struct trace_array *tr)
 {
 	tracing_stop_cmdline_record();
 	unregister_ftrace_graph();
+	set_graph_array(NULL);
+}
+
+int graph_trace_update_thresh(struct trace_array *tr)
+{
+	if (graph_array) {
+		graph_trace_reset(tr);
+		return graph_trace_init(tr);
+	}
+	return 0;
 }
 
 static int max_bytes_for_cpu;
@@ -1495,6 +1508,7 @@ static struct trace_event graph_trace_ret_event = {
 
 static struct tracer graph_trace __tracer_data = {
 	.name		= "function_graph",
+	.update_thresh	= graph_trace_update_thresh,
 	.open		= graph_trace_open,
 	.pipe_open	= graph_trace_open,
 	.close		= graph_trace_close,
-- 
1.9.1

Re: [PATCHv3] tracing: let user specify tracing_thresh after selecting function_graph

[Steven Rostedt]

On Tue, 15 Jul 2014 19:31:57 +0400
Stanislav Fomichev <stfomichev@yandex-team.ru> wrote:

> Currently, tracing_thresh works only if we specify it before selecting
> function_graph tracer. If we do the opposite, tracing_thresh will change
> it's value, but it will not be applied.
> To fix it, we add update_thresh callback which is called whenever
> tracing_thresh is updated and for function_graph tracer we register
> handler which reinitializes tracer depending on tracing_thresh.
> 
> Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
> ---
>  kernel/trace/trace.c                 | 65 ++++++++++++++++++++++++++++++++----
>  kernel/trace/trace.h                 |  2 ++
>  kernel/trace/trace_functions_graph.c | 20 +++++++++--
>  3 files changed, 77 insertions(+), 10 deletions(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index f243444a3772..986e6cad27d7 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4224,10 +4224,9 @@ tracing_set_trace_write(struct file *filp, const char __user *ubuf,
>  }
>  
>  static ssize_t
> -tracing_max_lat_read(struct file *filp, char __user *ubuf,
> -		     size_t cnt, loff_t *ppos)
> +tracing_nsecs_read(unsigned long *ptr, char __user *ubuf,
> +		   size_t cnt, loff_t *ppos)
>  {
> -	unsigned long *ptr = filp->private_data;
>  	char buf[64];
>  	int r;
>  
> @@ -4239,10 +4238,9 @@ tracing_max_lat_read(struct file *filp, char __user *ubuf,
>  }
>  
>  static ssize_t
> -tracing_max_lat_write(struct file *filp, const char __user *ubuf,
> -		      size_t cnt, loff_t *ppos)
> +tracing_nsecs_write(unsigned long *ptr, const char __user *ubuf,
> +		    size_t cnt, loff_t *ppos)
>  {
> -	unsigned long *ptr = filp->private_data;
>  	unsigned long val;
>  	int ret;
>  
> @@ -4255,6 +4253,52 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
>  	return cnt;
>  }
>  
> +static ssize_t
> +tracing_thresh_read(struct file *filp, char __user *ubuf,
> +		    size_t cnt, loff_t *ppos)
> +{
> +	return tracing_nsecs_read(&tracing_thresh, ubuf, cnt, ppos);
> +}
> +
> +static ssize_t
> +tracing_thresh_write(struct file *filp, const char __user *ubuf,
> +		     size_t cnt, loff_t *ppos)
> +{
> +	struct trace_array *tr = filp->private_data;
> +	int ret;
> +
> +	mutex_lock(&trace_types_lock);
> +	ret = tracing_nsecs_write(&tracing_thresh, ubuf, cnt, ppos);
> +	if (ret < 0)
> +		goto out;
> +
> +	if (tr->current_trace->update_thresh) {
> +		ret = tr->current_trace->update_thresh(tr);
> +		if (ret < 0)
> +			goto out;
> +	}
> +
> +	ret = cnt;
> +out:
> +	mutex_unlock(&trace_types_lock);
> +
> +	return ret;
> +}
> +
> +static ssize_t
> +tracing_max_lat_read(struct file *filp, char __user *ubuf,
> +		     size_t cnt, loff_t *ppos)
> +{
> +	return tracing_nsecs_read(filp->private_data, ubuf, cnt, ppos);
> +}
> +
> +static ssize_t
> +tracing_max_lat_write(struct file *filp, const char __user *ubuf,
> +		      size_t cnt, loff_t *ppos)
> +{
> +	return tracing_nsecs_write(filp->private_data, ubuf, cnt, ppos);
> +}
> +
>  static int tracing_open_pipe(struct inode *inode, struct file *filp)
>  {
>  	struct trace_array *tr = inode->i_private;
> @@ -5156,6 +5200,13 @@ static int snapshot_raw_open(struct inode *inode, struct file *filp)
>  #endif /* CONFIG_TRACER_SNAPSHOT */
>  
>  
> +static const struct file_operations tracing_thresh_fops = {
> +	.open		= tracing_open_generic,
> +	.read		= tracing_thresh_read,
> +	.write		= tracing_thresh_write,
> +	.llseek		= generic_file_llseek,
> +};
> +
>  static const struct file_operations tracing_max_lat_fops = {
>  	.open		= tracing_open_generic,
>  	.read		= tracing_max_lat_read,
> @@ -6519,7 +6570,7 @@ static __init int tracer_init_debugfs(void)
>  	init_tracer_debugfs(&global_trace, d_tracer);
>  
>  	trace_create_file("tracing_thresh", 0644, d_tracer,
> -			&tracing_thresh, &tracing_max_lat_fops);
> +			&global_trace, &tracing_thresh_fops);
>  
>  	trace_create_file("README", 0444, d_tracer,
>  			NULL, &tracing_readme_fops);
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 9258f5a815db..385391fb1d3b 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -339,6 +339,7 @@ struct tracer_flags {
>   * @reset: called when one switches to another tracer
>   * @start: called when tracing is unpaused (echo 1 > tracing_enabled)
>   * @stop: called when tracing is paused (echo 0 > tracing_enabled)
> + * @update_thresh: called when tracing_thresh is updated
>   * @open: called when the trace file is opened
>   * @pipe_open: called when the trace_pipe file is opened
>   * @close: called when the trace file is released
> @@ -357,6 +358,7 @@ struct tracer {
>  	void			(*reset)(struct trace_array *tr);
>  	void			(*start)(struct trace_array *tr);
>  	void			(*stop)(struct trace_array *tr);
> +	int			(*update_thresh)(struct trace_array *tr);
>  	void			(*open)(struct trace_iterator *iter);
>  	void			(*pipe_open)(struct trace_iterator *iter);
>  	void			(*close)(struct trace_iterator *iter);
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 4de3e57f723c..10d86cf83cb8 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -279,7 +279,7 @@ static inline int ftrace_graph_ignore_irqs(void)
>  
>  int trace_graph_entry(struct ftrace_graph_ent *trace)
>  {
> -	struct trace_array *tr = graph_array;
> +	struct trace_array *tr = ACCESS_ONCE(graph_array);
>  	struct trace_array_cpu *data;
>  	unsigned long flags;
>  	long disabled;
> @@ -287,7 +287,7 @@ int trace_graph_entry(struct ftrace_graph_ent *trace)
>  	int cpu;
>  	int pc;
>  
> -	if (!ftrace_trace_task(current))
> +	if (!tr || !ftrace_trace_task(current))
>  		return 0;
>  
>  	/* trace it when it is-nested-in or is a function enabled. */
> @@ -384,13 +384,16 @@ void __trace_graph_return(struct trace_array *tr,
>  
>  void trace_graph_return(struct ftrace_graph_ret *trace)
>  {
> -	struct trace_array *tr = graph_array;
> +	struct trace_array *tr = ACCESS_ONCE(graph_array);
>  	struct trace_array_cpu *data;
>  	unsigned long flags;
>  	long disabled;
>  	int cpu;
>  	int pc;
>  
> +	if (!tr)
> +		return;
> +

Let's not add branches into the fast path. This isn't needed. I'll
explain below.


>  	local_irq_save(flags);
>  	cpu = raw_smp_processor_id();
>  	data = per_cpu_ptr(tr->trace_buffer.data, cpu);
> @@ -443,6 +446,16 @@ static void graph_trace_reset(struct trace_array *tr)
>  {
>  	tracing_stop_cmdline_record();
>  	unregister_ftrace_graph();
> +	set_graph_array(NULL);
> +}
> +
> +int graph_trace_update_thresh(struct trace_array *tr)

The only way graph_trace_update_thresh() can be called is if the
current tracer happens to be the function graph tracer. Which means
that we are currently tracing and graph_array will be set. This will
not be called if function graph tracing is not set, because it is
called with the trace_types_lock mutex held.

Get rid of the graph_array tests and don't modify it. That is, just do
the reset and init unconditionally here.

-- Steve

> +{
> +	if (graph_array) {
> +		graph_trace_reset(tr);
> +		return graph_trace_init(tr);
> +	}
> +	return 0;
>  }
>  
>  static int max_bytes_for_cpu;
> @@ -1495,6 +1508,7 @@ static struct trace_event graph_trace_ret_event = {
>  
>  static struct tracer graph_trace __tracer_data = {
>  	.name		= "function_graph",
> +	.update_thresh	= graph_trace_update_thresh,
>  	.open		= graph_trace_open,
>  	.pipe_open	= graph_trace_open,
>  	.close		= graph_trace_close,

Re: [PATCHv4] tracing: let user specify tracing_thresh after selecting function_graph

[Stanislav Fomichev]

Currently, tracing_thresh works only if we specify it before selecting
function_graph tracer. If we do the opposite, tracing_thresh will change
it's value, but it will not be applied.
To fix it, we add update_thresh callback which is called whenever
tracing_thresh is updated and for function_graph tracer we register
handler which reinitializes tracer depending on tracing_thresh.

Signed-off-by: Stanislav Fomichev <stfomichev@yandex-team.ru>
---
 kernel/trace/trace.c                 | 65 ++++++++++++++++++++++++++++++++----
 kernel/trace/trace.h                 |  2 ++
 kernel/trace/trace_functions_graph.c |  7 ++++
 3 files changed, 67 insertions(+), 7 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index f243444a3772..986e6cad27d7 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4224,10 +4224,9 @@ tracing_set_trace_write(struct file *filp, const char __user *ubuf,
 }
 
 static ssize_t
-tracing_max_lat_read(struct file *filp, char __user *ubuf,
-		     size_t cnt, loff_t *ppos)
+tracing_nsecs_read(unsigned long *ptr, char __user *ubuf,
+		   size_t cnt, loff_t *ppos)
 {
-	unsigned long *ptr = filp->private_data;
 	char buf[64];
 	int r;
 
@@ -4239,10 +4238,9 @@ tracing_max_lat_read(struct file *filp, char __user *ubuf,
 }
 
 static ssize_t
-tracing_max_lat_write(struct file *filp, const char __user *ubuf,
-		      size_t cnt, loff_t *ppos)
+tracing_nsecs_write(unsigned long *ptr, const char __user *ubuf,
+		    size_t cnt, loff_t *ppos)
 {
-	unsigned long *ptr = filp->private_data;
 	unsigned long val;
 	int ret;
 
@@ -4255,6 +4253,52 @@ tracing_max_lat_write(struct file *filp, const char __user *ubuf,
 	return cnt;
 }
 
+static ssize_t
+tracing_thresh_read(struct file *filp, char __user *ubuf,
+		    size_t cnt, loff_t *ppos)
+{
+	return tracing_nsecs_read(&tracing_thresh, ubuf, cnt, ppos);
+}
+
+static ssize_t
+tracing_thresh_write(struct file *filp, const char __user *ubuf,
+		     size_t cnt, loff_t *ppos)
+{
+	struct trace_array *tr = filp->private_data;
+	int ret;
+
+	mutex_lock(&trace_types_lock);
+	ret = tracing_nsecs_write(&tracing_thresh, ubuf, cnt, ppos);
+	if (ret < 0)
+		goto out;
+
+	if (tr->current_trace->update_thresh) {
+		ret = tr->current_trace->update_thresh(tr);
+		if (ret < 0)
+			goto out;
+	}
+
+	ret = cnt;
+out:
+	mutex_unlock(&trace_types_lock);
+
+	return ret;
+}
+
+static ssize_t
+tracing_max_lat_read(struct file *filp, char __user *ubuf,
+		     size_t cnt, loff_t *ppos)
+{
+	return tracing_nsecs_read(filp->private_data, ubuf, cnt, ppos);
+}
+
+static ssize_t
+tracing_max_lat_write(struct file *filp, const char __user *ubuf,
+		      size_t cnt, loff_t *ppos)
+{
+	return tracing_nsecs_write(filp->private_data, ubuf, cnt, ppos);
+}
+
 static int tracing_open_pipe(struct inode *inode, struct file *filp)
 {
 	struct trace_array *tr = inode->i_private;
@@ -5156,6 +5200,13 @@ static int snapshot_raw_open(struct inode *inode, struct file *filp)
 #endif /* CONFIG_TRACER_SNAPSHOT */
 
 
+static const struct file_operations tracing_thresh_fops = {
+	.open		= tracing_open_generic,
+	.read		= tracing_thresh_read,
+	.write		= tracing_thresh_write,
+	.llseek		= generic_file_llseek,
+};
+
 static const struct file_operations tracing_max_lat_fops = {
 	.open		= tracing_open_generic,
 	.read		= tracing_max_lat_read,
@@ -6519,7 +6570,7 @@ static __init int tracer_init_debugfs(void)
 	init_tracer_debugfs(&global_trace, d_tracer);
 
 	trace_create_file("tracing_thresh", 0644, d_tracer,
-			&tracing_thresh, &tracing_max_lat_fops);
+			&global_trace, &tracing_thresh_fops);
 
 	trace_create_file("README", 0444, d_tracer,
 			NULL, &tracing_readme_fops);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 9258f5a815db..385391fb1d3b 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -339,6 +339,7 @@ struct tracer_flags {
  * @reset: called when one switches to another tracer
  * @start: called when tracing is unpaused (echo 1 > tracing_enabled)
  * @stop: called when tracing is paused (echo 0 > tracing_enabled)
+ * @update_thresh: called when tracing_thresh is updated
  * @open: called when the trace file is opened
  * @pipe_open: called when the trace_pipe file is opened
  * @close: called when the trace file is released
@@ -357,6 +358,7 @@ struct tracer {
 	void			(*reset)(struct trace_array *tr);
 	void			(*start)(struct trace_array *tr);
 	void			(*stop)(struct trace_array *tr);
+	int			(*update_thresh)(struct trace_array *tr);
 	void			(*open)(struct trace_iterator *iter);
 	void			(*pipe_open)(struct trace_iterator *iter);
 	void			(*close)(struct trace_iterator *iter);
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 4de3e57f723c..898e4d6db213 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -445,6 +445,12 @@ static void graph_trace_reset(struct trace_array *tr)
 	unregister_ftrace_graph();
 }
 
+int graph_trace_update_thresh(struct trace_array *tr)
+{
+	graph_trace_reset(tr);
+	return graph_trace_init(tr);
+}
+
 static int max_bytes_for_cpu;
 
 static enum print_line_t
@@ -1495,6 +1501,7 @@ static struct trace_event graph_trace_ret_event = {
 
 static struct tracer graph_trace __tracer_data = {
 	.name		= "function_graph",
+	.update_thresh	= graph_trace_update_thresh,
 	.open		= graph_trace_open,
 	.pipe_open	= graph_trace_open,
 	.close		= graph_trace_close,
-- 
1.9.1