2018-02-19 02:43:05

by Du, Changbin

[permalink] [raw]
Subject: [PATCH v4] perf ftrace: Append an EOL when write tracing files

From: Changbin Du <[email protected]>

Before this change, the '--graph-funcs', '--nograph-funcs' and
'--trace-funcs' options didn't work as expected when the <func> doesn't
exist. Because the kernel side hid possible errors.

$ sudo ./perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
0) 0.140 us | rcu_all_qs();
3) 0.304 us | mutex_unlock();
0) 0.153 us | find_vma();
3) 0.088 us | __fsnotify_parent();
0) 6.145 us | handle_mm_fault();
3) 0.089 us | fsnotify();
3) 0.161 us | __sb_end_write();
3) 0.710 us | SyS_close();
3) 7.848 us | exit_to_usermode_loop();

On above example, I specified function filter 'abcdefg' but all functions
are enabled. The expected error is hidden.

The original fix is to make the kernel support '\0' as end of string:
https://lkml.org/lkml/2018/1/16/116

But above fix cannot be compatible with old kernels. Then Namhyung Kim
suggest adding a space after function name.

This patch will append an '\n' when write tracing file. After this fix,
the perf will report correct error state. Also let it print an error if
reset_tracing_files() fails.

Cc: Namhyung Kim <[email protected]>
Signed-off-by: Changbin Du <[email protected]>

---
v4: check strdup() return. (Kim)
v3: Took Kim's suggestion that add a space after function name.
v2: Rebase.
---
tools/perf/builtin-ftrace.c | 18 ++++++++++++++++--
1 file changed, 16 insertions(+), 2 deletions(-)

diff --git a/tools/perf/builtin-ftrace.c b/tools/perf/builtin-ftrace.c
index 25a42ac..f42f228 100644
--- a/tools/perf/builtin-ftrace.c
+++ b/tools/perf/builtin-ftrace.c
@@ -72,6 +72,7 @@ static int __write_tracing_file(const char *name, const char *val, bool append)
ssize_t size = strlen(val);
int flags = O_WRONLY;
char errbuf[512];
+ char *val_copy;

file = get_tracing_file(name);
if (!file) {
@@ -91,12 +92,23 @@ static int __write_tracing_file(const char *name, const char *val, bool append)
goto out;
}

- if (write(fd, val, size) == size)
+ /*
+ * Copy the original value and append a '\n'. Without this,
+ * the kernel can hide possible errors.
+ */
+ val_copy = strdup(val);
+ if (!val_copy)
+ goto out_close;
+ val_copy[size] = '\n';
+
+ if (write(fd, val_copy, size + 1) == size + 1)
ret = 0;
else
pr_debug("write '%s' to tracing/%s failed: %s\n",
val, name, str_error_r(errno, errbuf, sizeof(errbuf)));

+ free(val_copy);
+out_close:
close(fd);
out:
put_tracing_file(file);
@@ -280,8 +292,10 @@ static int __cmd_ftrace(struct perf_ftrace *ftrace, int argc, const char **argv)
signal(SIGCHLD, sig_handler);
signal(SIGPIPE, sig_handler);

- if (reset_tracing_files(ftrace) < 0)
+ if (reset_tracing_files(ftrace) < 0) {
+ pr_err("failed to reset ftrace\n");
goto out;
+ }

/* reset ftrace buffer */
if (write_tracing_file("trace", "0") < 0)
--
2.7.4



2018-02-19 06:00:58

by Namhyung Kim

[permalink] [raw]
Subject: Re: [PATCH v4] perf ftrace: Append an EOL when write tracing files

On Mon, Feb 19, 2018 at 10:33:29AM +0800, [email protected] wrote:
> From: Changbin Du <[email protected]>
>
> Before this change, the '--graph-funcs', '--nograph-funcs' and
> '--trace-funcs' options didn't work as expected when the <func> doesn't
> exist. Because the kernel side hid possible errors.
>
> $ sudo ./perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
> 0) 0.140 us | rcu_all_qs();
> 3) 0.304 us | mutex_unlock();
> 0) 0.153 us | find_vma();
> 3) 0.088 us | __fsnotify_parent();
> 0) 6.145 us | handle_mm_fault();
> 3) 0.089 us | fsnotify();
> 3) 0.161 us | __sb_end_write();
> 3) 0.710 us | SyS_close();
> 3) 7.848 us | exit_to_usermode_loop();
>
> On above example, I specified function filter 'abcdefg' but all functions
> are enabled. The expected error is hidden.
>
> The original fix is to make the kernel support '\0' as end of string:
> https://lkml.org/lkml/2018/1/16/116
>
> But above fix cannot be compatible with old kernels. Then Namhyung Kim
> suggest adding a space after function name.
>
> This patch will append an '\n' when write tracing file. After this fix,
> the perf will report correct error state. Also let it print an error if
> reset_tracing_files() fails.
>
> Cc: Namhyung Kim <[email protected]>
> Signed-off-by: Changbin Du <[email protected]>

Acked-by: Namhyung Kim <[email protected]>

Thanks,
Namhyung


>
> ---
> v4: check strdup() return. (Kim)
> v3: Took Kim's suggestion that add a space after function name.
> v2: Rebase.
> ---
> tools/perf/builtin-ftrace.c | 18 ++++++++++++++++--
> 1 file changed, 16 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/builtin-ftrace.c b/tools/perf/builtin-ftrace.c
> index 25a42ac..f42f228 100644
> --- a/tools/perf/builtin-ftrace.c
> +++ b/tools/perf/builtin-ftrace.c
> @@ -72,6 +72,7 @@ static int __write_tracing_file(const char *name, const char *val, bool append)
> ssize_t size = strlen(val);
> int flags = O_WRONLY;
> char errbuf[512];
> + char *val_copy;
>
> file = get_tracing_file(name);
> if (!file) {
> @@ -91,12 +92,23 @@ static int __write_tracing_file(const char *name, const char *val, bool append)
> goto out;
> }
>
> - if (write(fd, val, size) == size)
> + /*
> + * Copy the original value and append a '\n'. Without this,
> + * the kernel can hide possible errors.
> + */
> + val_copy = strdup(val);
> + if (!val_copy)
> + goto out_close;
> + val_copy[size] = '\n';
> +
> + if (write(fd, val_copy, size + 1) == size + 1)
> ret = 0;
> else
> pr_debug("write '%s' to tracing/%s failed: %s\n",
> val, name, str_error_r(errno, errbuf, sizeof(errbuf)));
>
> + free(val_copy);
> +out_close:
> close(fd);
> out:
> put_tracing_file(file);
> @@ -280,8 +292,10 @@ static int __cmd_ftrace(struct perf_ftrace *ftrace, int argc, const char **argv)
> signal(SIGCHLD, sig_handler);
> signal(SIGPIPE, sig_handler);
>
> - if (reset_tracing_files(ftrace) < 0)
> + if (reset_tracing_files(ftrace) < 0) {
> + pr_err("failed to reset ftrace\n");
> goto out;
> + }
>
> /* reset ftrace buffer */
> if (write_tracing_file("trace", "0") < 0)
> --
> 2.7.4
>

2018-02-19 14:14:04

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [PATCH v4] perf ftrace: Append an EOL when write tracing files

Em Mon, Feb 19, 2018 at 10:33:29AM +0800, [email protected] escreveu:
> From: Changbin Du <[email protected]>
>
> Before this change, the '--graph-funcs', '--nograph-funcs' and
> '--trace-funcs' options didn't work as expected when the <func> doesn't
> exist. Because the kernel side hid possible errors.
>
> $ sudo ./perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
> 0) 0.140 us | rcu_all_qs();
> 3) 0.304 us | mutex_unlock();
> 0) 0.153 us | find_vma();
> 3) 0.088 us | __fsnotify_parent();
> 0) 6.145 us | handle_mm_fault();
> 3) 0.089 us | fsnotify();
> 3) 0.161 us | __sb_end_write();
> 3) 0.710 us | SyS_close();
> 3) 7.848 us | exit_to_usermode_loop();
>
> On above example, I specified function filter 'abcdefg' but all functions
> are enabled. The expected error is hidden.
>
> The original fix is to make the kernel support '\0' as end of string:
> https://lkml.org/lkml/2018/1/16/116
>
> But above fix cannot be compatible with old kernels. Then Namhyung Kim
> suggest adding a space after function name.
>
> This patch will append an '\n' when write tracing file. After this fix,
> the perf will report correct error state. Also let it print an error if
> reset_tracing_files() fails.

Ok, now it prints:

[root@jouet ~]# perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
failed to set tracing filters
[root@jouet ~]#

which is too vague, i.e. the user is left without knowing what was it
that didn't work in setting the filter.

It would be better to have:

[root@jouet ~]# perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
failed to set tracing filters: function 'abcdefg' not found.
[root@jouet ~]#

Anyway, this improves the current situation, so I'm applying it.

- Arnaldo

Subject: [tip:perf/core] perf ftrace: Append an EOL when write tracing files

Commit-ID: 63cd02d84be5f7b3bc4f8fbb93cc1f871f84ae1d
Gitweb: https://git.kernel.org/tip/63cd02d84be5f7b3bc4f8fbb93cc1f871f84ae1d
Author: Changbin Du <[email protected]>
AuthorDate: Mon, 19 Feb 2018 10:33:29 +0800
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Mon, 19 Feb 2018 09:49:12 -0300

perf ftrace: Append an EOL when write tracing files

Before this change, the '--graph-funcs', '--nograph-funcs' and
'--trace-funcs' options didn't work as expected when the <func> doesn't
exist. Because the kernel side hid possible errors.

$ sudo ./perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
0) 0.140 us | rcu_all_qs();
3) 0.304 us | mutex_unlock();
0) 0.153 us | find_vma();
3) 0.088 us | __fsnotify_parent();
0) 6.145 us | handle_mm_fault();
3) 0.089 us | fsnotify();
3) 0.161 us | __sb_end_write();
3) 0.710 us | SyS_close();
3) 7.848 us | exit_to_usermode_loop();

On the example above, I specified the function filter 'abcdefg' but all
functions are enabled. The expected result is for all functions to be
filtered, since there is no such function ('abcdefg')

The original fix is to make the kernel support '\0' as end of string:
https://lkml.org/lkml/2018/1/16/116

But above fix cannot be compatible with old kernels. Then Namhyung Kim
suggest adding a space after function name.

This patch will append an '\n' when write tracing file. After this fix,
the perf will report correct error state. Also let it print an error if
reset_tracing_files() fails.

Committer testing:

Now it prints:

# perf ftrace -a --graph-depth 1 --graph-funcs abcdefg
failed to set tracing filters
#

And for an existing function:

# perf ftrace -a --graph-depth 1 --graph-funcs SyS_open
3) | SyS_open() {
3) ! 494.899 us | }
0) + 23.910 us | SyS_open();
1) + 17.115 us | SyS_open();
1) + 13.900 us | SyS_open();
------------------------------------------
3) qemu-sy-2817 => pickup-1290
------------------------------------------

3) + 20.021 us | SyS_open();
#

Signed-off-by: Changbin Du <[email protected]>
Tested-by: Arnaldo Carvalho de Melo <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/builtin-ftrace.c | 18 ++++++++++++++++--
1 file changed, 16 insertions(+), 2 deletions(-)

diff --git a/tools/perf/builtin-ftrace.c b/tools/perf/builtin-ftrace.c
index 25a42ac..f42f228 100644
--- a/tools/perf/builtin-ftrace.c
+++ b/tools/perf/builtin-ftrace.c
@@ -72,6 +72,7 @@ static int __write_tracing_file(const char *name, const char *val, bool append)
ssize_t size = strlen(val);
int flags = O_WRONLY;
char errbuf[512];
+ char *val_copy;

file = get_tracing_file(name);
if (!file) {
@@ -91,12 +92,23 @@ static int __write_tracing_file(const char *name, const char *val, bool append)
goto out;
}

- if (write(fd, val, size) == size)
+ /*
+ * Copy the original value and append a '\n'. Without this,
+ * the kernel can hide possible errors.
+ */
+ val_copy = strdup(val);
+ if (!val_copy)
+ goto out_close;
+ val_copy[size] = '\n';
+
+ if (write(fd, val_copy, size + 1) == size + 1)
ret = 0;
else
pr_debug("write '%s' to tracing/%s failed: %s\n",
val, name, str_error_r(errno, errbuf, sizeof(errbuf)));

+ free(val_copy);
+out_close:
close(fd);
out:
put_tracing_file(file);
@@ -280,8 +292,10 @@ static int __cmd_ftrace(struct perf_ftrace *ftrace, int argc, const char **argv)
signal(SIGCHLD, sig_handler);
signal(SIGPIPE, sig_handler);

- if (reset_tracing_files(ftrace) < 0)
+ if (reset_tracing_files(ftrace) < 0) {
+ pr_err("failed to reset ftrace\n");
goto out;
+ }

/* reset ftrace buffer */
if (write_tracing_file("trace", "0") < 0)