The output of Perf bench gets buffered when I pipe it to a file or to
tee, in such a way that I can see it only at the end.
E.g.
$ perf bench internals synthesize -t
< output comes out fine after each test run >
$ perf bench internals synthesize -t | tee file.txt
< output comes out only at the end of all tests >
This patch resolves this issue for 'bench' and 'test' subcommands.
See, also:
$ perf bench mem all | tee file.txt
$ perf bench sched all | tee file.txt
$ perf bench internals all -t | tee file.txt
$ perf bench internals all | tee file.txt
Suggested-by: Riccardo Mancini <[email protected]>
Signed-off-by: Sohaib Mohamed <[email protected]>
---
v1 -> v2:
- Use setvbuf(), instead of sprinkling fflush() calls and missing some places.
v1: https://lore.kernel.org/linux-perf-users/[email protected]/
---
tools/perf/builtin-bench.c | 5 +++--
tools/perf/tests/builtin-test.c | 3 +++
2 files changed, 6 insertions(+), 2 deletions(-)
diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
index d0895162c2ba..d291f3a8af5f 100644
--- a/tools/perf/builtin-bench.c
+++ b/tools/perf/builtin-bench.c
@@ -226,7 +226,6 @@ static void run_collection(struct collection *coll)
if (!bench->fn)
break;
printf("# Running %s/%s benchmark...\n", coll->name, bench->name);
- fflush(stdout);
argv[1] = bench->name;
run_bench(coll->name, bench->name, bench->fn, 1, argv);
@@ -247,6 +246,9 @@ int cmd_bench(int argc, const char **argv)
struct collection *coll;
int ret = 0;
+ /* Unbuffered output */
+ setvbuf(stdout, NULL, _IONBF, 0);
+
if (argc < 2) {
/* No collection specified. */
print_usage();
@@ -300,7 +302,6 @@ int cmd_bench(int argc, const char **argv)
if (bench_format == BENCH_FORMAT_DEFAULT)
printf("# Running '%s/%s' benchmark:\n", coll->name, bench->name);
- fflush(stdout);
ret = run_bench(coll->name, bench->name, bench->fn, argc-1, argv+1);
goto end;
}
diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
index 8cb5a1c3489e..d92ae4efd2e6 100644
--- a/tools/perf/tests/builtin-test.c
+++ b/tools/perf/tests/builtin-test.c
@@ -606,6 +606,9 @@ int cmd_test(int argc, const char **argv)
if (ret < 0)
return ret;
+ /* Unbuffered output */
+ setvbuf(stdout, NULL, _IONBF, 0);
+
argc = parse_options_subcommand(argc, argv, test_options, test_subcommands, test_usage, 0);
if (argc >= 1 && !strcmp(argv[0], "list"))
return perf_test__list(argc - 1, argv + 1);
--
2.25.1
On Fri, Nov 19, 2021 at 08:14:08AM +0200, Sohaib Mohamed wrote:
> The output of Perf bench gets buffered when I pipe it to a file or to
> tee, in such a way that I can see it only at the end.
>
> E.g.
> $ perf bench internals synthesize -t
> < output comes out fine after each test run >
>
> $ perf bench internals synthesize -t | tee file.txt
> < output comes out only at the end of all tests >
>
> This patch resolves this issue for 'bench' and 'test' subcommands.
I can reproduce this for bench, but not for test subcommand
other that that it makes sense to me
jirka
>
> See, also:
> $ perf bench mem all | tee file.txt
> $ perf bench sched all | tee file.txt
> $ perf bench internals all -t | tee file.txt
> $ perf bench internals all | tee file.txt
>
> Suggested-by: Riccardo Mancini <[email protected]>
> Signed-off-by: Sohaib Mohamed <[email protected]>
> ---
> v1 -> v2:
> - Use setvbuf(), instead of sprinkling fflush() calls and missing some places.
>
> v1: https://lore.kernel.org/linux-perf-users/[email protected]/
> ---
> tools/perf/builtin-bench.c | 5 +++--
> tools/perf/tests/builtin-test.c | 3 +++
> 2 files changed, 6 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
> index d0895162c2ba..d291f3a8af5f 100644
> --- a/tools/perf/builtin-bench.c
> +++ b/tools/perf/builtin-bench.c
> @@ -226,7 +226,6 @@ static void run_collection(struct collection *coll)
> if (!bench->fn)
> break;
> printf("# Running %s/%s benchmark...\n", coll->name, bench->name);
> - fflush(stdout);
>
> argv[1] = bench->name;
> run_bench(coll->name, bench->name, bench->fn, 1, argv);
> @@ -247,6 +246,9 @@ int cmd_bench(int argc, const char **argv)
> struct collection *coll;
> int ret = 0;
>
> + /* Unbuffered output */
> + setvbuf(stdout, NULL, _IONBF, 0);
> +
> if (argc < 2) {
> /* No collection specified. */
> print_usage();
> @@ -300,7 +302,6 @@ int cmd_bench(int argc, const char **argv)
>
> if (bench_format == BENCH_FORMAT_DEFAULT)
> printf("# Running '%s/%s' benchmark:\n", coll->name, bench->name);
> - fflush(stdout);
> ret = run_bench(coll->name, bench->name, bench->fn, argc-1, argv+1);
> goto end;
> }
> diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> index 8cb5a1c3489e..d92ae4efd2e6 100644
> --- a/tools/perf/tests/builtin-test.c
> +++ b/tools/perf/tests/builtin-test.c
> @@ -606,6 +606,9 @@ int cmd_test(int argc, const char **argv)
> if (ret < 0)
> return ret;
>
> + /* Unbuffered output */
> + setvbuf(stdout, NULL, _IONBF, 0);
> +
> argc = parse_options_subcommand(argc, argv, test_options, test_subcommands, test_usage, 0);
> if (argc >= 1 && !strcmp(argv[0], "list"))
> return perf_test__list(argc - 1, argv + 1);
> --
> 2.25.1
>
Em Fri, Nov 19, 2021 at 08:14:08AM +0200, Sohaib Mohamed escreveu:
> The output of Perf bench gets buffered when I pipe it to a file or to
> tee, in such a way that I can see it only at the end.
Humm, not at the end, the output is staggered, i.e. only when the buffer
fills up it is drained and then we have to wait for it to fill up again,
rinse repeat.
I just tested and applied it, adding a note about this patch fixing the
previous output bursty behaviour.
- Arnaldo
> E.g.
> $ perf bench internals synthesize -t
> < output comes out fine after each test run >
>
> $ perf bench internals synthesize -t | tee file.txt
> < output comes out only at the end of all tests >
>
> This patch resolves this issue for 'bench' and 'test' subcommands.
>
> See, also:
> $ perf bench mem all | tee file.txt
> $ perf bench sched all | tee file.txt
> $ perf bench internals all -t | tee file.txt
> $ perf bench internals all | tee file.txt
>
> Suggested-by: Riccardo Mancini <[email protected]>
> Signed-off-by: Sohaib Mohamed <[email protected]>
> ---
> v1 -> v2:
> - Use setvbuf(), instead of sprinkling fflush() calls and missing some places.
>
> v1: https://lore.kernel.org/linux-perf-users/[email protected]/
> ---
> tools/perf/builtin-bench.c | 5 +++--
> tools/perf/tests/builtin-test.c | 3 +++
> 2 files changed, 6 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
> index d0895162c2ba..d291f3a8af5f 100644
> --- a/tools/perf/builtin-bench.c
> +++ b/tools/perf/builtin-bench.c
> @@ -226,7 +226,6 @@ static void run_collection(struct collection *coll)
> if (!bench->fn)
> break;
> printf("# Running %s/%s benchmark...\n", coll->name, bench->name);
> - fflush(stdout);
>
> argv[1] = bench->name;
> run_bench(coll->name, bench->name, bench->fn, 1, argv);
> @@ -247,6 +246,9 @@ int cmd_bench(int argc, const char **argv)
> struct collection *coll;
> int ret = 0;
>
> + /* Unbuffered output */
> + setvbuf(stdout, NULL, _IONBF, 0);
> +
> if (argc < 2) {
> /* No collection specified. */
> print_usage();
> @@ -300,7 +302,6 @@ int cmd_bench(int argc, const char **argv)
>
> if (bench_format == BENCH_FORMAT_DEFAULT)
> printf("# Running '%s/%s' benchmark:\n", coll->name, bench->name);
> - fflush(stdout);
> ret = run_bench(coll->name, bench->name, bench->fn, argc-1, argv+1);
> goto end;
> }
> diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> index 8cb5a1c3489e..d92ae4efd2e6 100644
> --- a/tools/perf/tests/builtin-test.c
> +++ b/tools/perf/tests/builtin-test.c
> @@ -606,6 +606,9 @@ int cmd_test(int argc, const char **argv)
> if (ret < 0)
> return ret;
>
> + /* Unbuffered output */
> + setvbuf(stdout, NULL, _IONBF, 0);
> +
> argc = parse_options_subcommand(argc, argv, test_options, test_subcommands, test_usage, 0);
> if (argc >= 1 && !strcmp(argv[0], "list"))
> return perf_test__list(argc - 1, argv + 1);
> --
> 2.25.1
--
- Arnaldo
Em Sun, Nov 28, 2021 at 04:34:05PM +0100, Jiri Olsa escreveu:
> On Fri, Nov 19, 2021 at 08:14:08AM +0200, Sohaib Mohamed wrote:
> > The output of Perf bench gets buffered when I pipe it to a file or to
> > tee, in such a way that I can see it only at the end.
> >
> > E.g.
> > $ perf bench internals synthesize -t
> > < output comes out fine after each test run >
> >
> > $ perf bench internals synthesize -t | tee file.txt
> > < output comes out only at the end of all tests >
> >
> > This patch resolves this issue for 'bench' and 'test' subcommands.
>
> I can reproduce this for bench, but not for test subcommand
> other that that it makes sense to me
I reproduced it, see my comment to Sohaib's message, its not at the end,
its when the buffer fills up.
From the "it makes sense to me" I'm deriving an Acked-by you, ok?
- Arnaldo
> jirka
>
> >
> > See, also:
> > $ perf bench mem all | tee file.txt
> > $ perf bench sched all | tee file.txt
> > $ perf bench internals all -t | tee file.txt
> > $ perf bench internals all | tee file.txt
> >
> > Suggested-by: Riccardo Mancini <[email protected]>
> > Signed-off-by: Sohaib Mohamed <[email protected]>
> > ---
> > v1 -> v2:
> > - Use setvbuf(), instead of sprinkling fflush() calls and missing some places.
> >
> > v1: https://lore.kernel.org/linux-perf-users/[email protected]/
> > ---
> > tools/perf/builtin-bench.c | 5 +++--
> > tools/perf/tests/builtin-test.c | 3 +++
> > 2 files changed, 6 insertions(+), 2 deletions(-)
> >
> > diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
> > index d0895162c2ba..d291f3a8af5f 100644
> > --- a/tools/perf/builtin-bench.c
> > +++ b/tools/perf/builtin-bench.c
> > @@ -226,7 +226,6 @@ static void run_collection(struct collection *coll)
> > if (!bench->fn)
> > break;
> > printf("# Running %s/%s benchmark...\n", coll->name, bench->name);
> > - fflush(stdout);
> >
> > argv[1] = bench->name;
> > run_bench(coll->name, bench->name, bench->fn, 1, argv);
> > @@ -247,6 +246,9 @@ int cmd_bench(int argc, const char **argv)
> > struct collection *coll;
> > int ret = 0;
> >
> > + /* Unbuffered output */
> > + setvbuf(stdout, NULL, _IONBF, 0);
> > +
> > if (argc < 2) {
> > /* No collection specified. */
> > print_usage();
> > @@ -300,7 +302,6 @@ int cmd_bench(int argc, const char **argv)
> >
> > if (bench_format == BENCH_FORMAT_DEFAULT)
> > printf("# Running '%s/%s' benchmark:\n", coll->name, bench->name);
> > - fflush(stdout);
> > ret = run_bench(coll->name, bench->name, bench->fn, argc-1, argv+1);
> > goto end;
> > }
> > diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> > index 8cb5a1c3489e..d92ae4efd2e6 100644
> > --- a/tools/perf/tests/builtin-test.c
> > +++ b/tools/perf/tests/builtin-test.c
> > @@ -606,6 +606,9 @@ int cmd_test(int argc, const char **argv)
> > if (ret < 0)
> > return ret;
> >
> > + /* Unbuffered output */
> > + setvbuf(stdout, NULL, _IONBF, 0);
> > +
> > argc = parse_options_subcommand(argc, argv, test_options, test_subcommands, test_usage, 0);
> > if (argc >= 1 && !strcmp(argv[0], "list"))
> > return perf_test__list(argc - 1, argv + 1);
> > --
> > 2.25.1
> >
--
- Arnaldo
On Thu, Dec 09, 2021 at 03:51:37PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Sun, Nov 28, 2021 at 04:34:05PM +0100, Jiri Olsa escreveu:
> > On Fri, Nov 19, 2021 at 08:14:08AM +0200, Sohaib Mohamed wrote:
> > > The output of Perf bench gets buffered when I pipe it to a file or to
> > > tee, in such a way that I can see it only at the end.
> > >
> > > E.g.
> > > $ perf bench internals synthesize -t
> > > < output comes out fine after each test run >
> > >
> > > $ perf bench internals synthesize -t | tee file.txt
> > > < output comes out only at the end of all tests >
> > >
> > > This patch resolves this issue for 'bench' and 'test' subcommands.
> >
> > I can reproduce this for bench, but not for test subcommand
> > other that that it makes sense to me
>
> I reproduced it, see my comment to Sohaib's message, its not at the end,
> its when the buffer fills up.
>
> From the "it makes sense to me" I'm deriving an Acked-by you, ok?
ok, yes
Acked-by: Jiri Olsa <[email protected]>
jirka
>
> - Arnaldo
>
> > jirka
> >
> > >
> > > See, also:
> > > $ perf bench mem all | tee file.txt
> > > $ perf bench sched all | tee file.txt
> > > $ perf bench internals all -t | tee file.txt
> > > $ perf bench internals all | tee file.txt
> > >
> > > Suggested-by: Riccardo Mancini <[email protected]>
> > > Signed-off-by: Sohaib Mohamed <[email protected]>
> > > ---
> > > v1 -> v2:
> > > - Use setvbuf(), instead of sprinkling fflush() calls and missing some places.
> > >
> > > v1: https://lore.kernel.org/linux-perf-users/[email protected]/
> > > ---
> > > tools/perf/builtin-bench.c | 5 +++--
> > > tools/perf/tests/builtin-test.c | 3 +++
> > > 2 files changed, 6 insertions(+), 2 deletions(-)
> > >
> > > diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
> > > index d0895162c2ba..d291f3a8af5f 100644
> > > --- a/tools/perf/builtin-bench.c
> > > +++ b/tools/perf/builtin-bench.c
> > > @@ -226,7 +226,6 @@ static void run_collection(struct collection *coll)
> > > if (!bench->fn)
> > > break;
> > > printf("# Running %s/%s benchmark...\n", coll->name, bench->name);
> > > - fflush(stdout);
> > >
> > > argv[1] = bench->name;
> > > run_bench(coll->name, bench->name, bench->fn, 1, argv);
> > > @@ -247,6 +246,9 @@ int cmd_bench(int argc, const char **argv)
> > > struct collection *coll;
> > > int ret = 0;
> > >
> > > + /* Unbuffered output */
> > > + setvbuf(stdout, NULL, _IONBF, 0);
> > > +
> > > if (argc < 2) {
> > > /* No collection specified. */
> > > print_usage();
> > > @@ -300,7 +302,6 @@ int cmd_bench(int argc, const char **argv)
> > >
> > > if (bench_format == BENCH_FORMAT_DEFAULT)
> > > printf("# Running '%s/%s' benchmark:\n", coll->name, bench->name);
> > > - fflush(stdout);
> > > ret = run_bench(coll->name, bench->name, bench->fn, argc-1, argv+1);
> > > goto end;
> > > }
> > > diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> > > index 8cb5a1c3489e..d92ae4efd2e6 100644
> > > --- a/tools/perf/tests/builtin-test.c
> > > +++ b/tools/perf/tests/builtin-test.c
> > > @@ -606,6 +606,9 @@ int cmd_test(int argc, const char **argv)
> > > if (ret < 0)
> > > return ret;
> > >
> > > + /* Unbuffered output */
> > > + setvbuf(stdout, NULL, _IONBF, 0);
> > > +
> > > argc = parse_options_subcommand(argc, argv, test_options, test_subcommands, test_usage, 0);
> > > if (argc >= 1 && !strcmp(argv[0], "list"))
> > > return perf_test__list(argc - 1, argv + 1);
> > > --
> > > 2.25.1
> > >
>
> --
>
> - Arnaldo
>
From: Arnaldo Carvalho de Melo
> Sent: 09 December 2021 18:51
...
> > diff --git a/tools/perf/tests/builtin-test.c b/tools/perf/tests/builtin-test.c
> > index 8cb5a1c3489e..d92ae4efd2e6 100644
> > --- a/tools/perf/tests/builtin-test.c
> > +++ b/tools/perf/tests/builtin-test.c
> > @@ -606,6 +606,9 @@ int cmd_test(int argc, const char **argv)
> > if (ret < 0)
> > return ret;
> >
> > + /* Unbuffered output */
> > + setvbuf(stdout, NULL, _IONBF, 0);
> > +
You only want _IOLBF (line buffered).
Otherwise you are likely to get a lot of write() system calls.
Even multiple ones from the same printf().
Although it can be better just to ensure there is a fflush(stdout)
inside the loop.
David
-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)