linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] perf bench: flush stats when pipe it to a file or to tee
@ 2021-11-12 21:53 Sohaib Mohamed
  2021-11-13 12:16 ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 5+ messages in thread
From: Sohaib Mohamed @ 2021-11-12 21:53 UTC (permalink / raw)
  Cc: sohaib.amhmd, rickyman7, irogers, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Mark Rutland, Alexander Shishkin,
	Jiri Olsa, Namhyung Kim, Yury Norov, Andy Shevchenko,
	Andrew Morton, linux-perf-users, linux-kernel

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 >

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 <rickyman7@gmail.com>
Signed-off-by: Sohaib Mohamed <sohaib.amhmd@gmail.com>
---
 tools/perf/bench/find-bit-bench.c | 1 +
 tools/perf/bench/synthesize.c     | 2 ++
 2 files changed, 3 insertions(+)

diff --git a/tools/perf/bench/find-bit-bench.c b/tools/perf/bench/find-bit-bench.c
index 22b5cfe97023..39fb4184fbcb 100644
--- a/tools/perf/bench/find-bit-bench.c
+++ b/tools/perf/bench/find-bit-bench.c
@@ -113,6 +113,7 @@ static int do_for_each_set_bit(unsigned int num_bits)

 		if (use_of_val == accumulator)  /* Try to avoid compiler tricks. */
 			printf("\n");
+		fflush(stdout);
 	}
 	bitmap_free(to_test);
 	return 0;
diff --git a/tools/perf/bench/synthesize.c b/tools/perf/bench/synthesize.c
index 7401ebbac100..d21d311df61b 100644
--- a/tools/perf/bench/synthesize.c
+++ b/tools/perf/bench/synthesize.c
@@ -92,6 +92,7 @@ static int do_run_single_threaded(struct perf_session *session,
 		update_stats(&event_stats, atomic_read(&event_count));
 	}

+	fflush(stdout);
 	time_average = avg_stats(&time_stats);
 	time_stddev = stddev_stats(&time_stats);
 	printf("  Average %ssynthesis took: %.3f usec (+- %.3f usec)\n",
@@ -186,6 +187,7 @@ static int do_run_multi_threaded(struct target *target,
 		perf_session__delete(session);
 	}

+	fflush(stdout);
 	time_average = avg_stats(&time_stats);
 	time_stddev = stddev_stats(&time_stats);
 	printf("    Average synthesis took: %.3f usec (+- %.3f usec)\n",
--
2.25.1


^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: [PATCH] perf bench: flush stats when pipe it to a file or to tee
  2021-11-12 21:53 [PATCH] perf bench: flush stats when pipe it to a file or to tee Sohaib Mohamed
@ 2021-11-13 12:16 ` Arnaldo Carvalho de Melo
  2021-11-13 12:18   ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2021-11-13 12:16 UTC (permalink / raw)
  To: Sohaib Mohamed
  Cc: rickyman7, irogers, Peter Zijlstra, Ingo Molnar, Mark Rutland,
	Alexander Shishkin, Jiri Olsa, Namhyung Kim, Yury Norov,
	Andy Shevchenko, Andrew Morton, linux-perf-users, linux-kernel

Em Fri, Nov 12, 2021 at 11:53:12PM +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.

Good, now try with 'perf test' :-)

Applying,

- 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 >
> 
> 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 <rickyman7@gmail.com>
> Signed-off-by: Sohaib Mohamed <sohaib.amhmd@gmail.com>
> ---
>  tools/perf/bench/find-bit-bench.c | 1 +
>  tools/perf/bench/synthesize.c     | 2 ++
>  2 files changed, 3 insertions(+)
> 
> diff --git a/tools/perf/bench/find-bit-bench.c b/tools/perf/bench/find-bit-bench.c
> index 22b5cfe97023..39fb4184fbcb 100644
> --- a/tools/perf/bench/find-bit-bench.c
> +++ b/tools/perf/bench/find-bit-bench.c
> @@ -113,6 +113,7 @@ static int do_for_each_set_bit(unsigned int num_bits)
> 
>  		if (use_of_val == accumulator)  /* Try to avoid compiler tricks. */
>  			printf("\n");
> +		fflush(stdout);
>  	}
>  	bitmap_free(to_test);
>  	return 0;
> diff --git a/tools/perf/bench/synthesize.c b/tools/perf/bench/synthesize.c
> index 7401ebbac100..d21d311df61b 100644
> --- a/tools/perf/bench/synthesize.c
> +++ b/tools/perf/bench/synthesize.c
> @@ -92,6 +92,7 @@ static int do_run_single_threaded(struct perf_session *session,
>  		update_stats(&event_stats, atomic_read(&event_count));
>  	}
> 
> +	fflush(stdout);
>  	time_average = avg_stats(&time_stats);
>  	time_stddev = stddev_stats(&time_stats);
>  	printf("  Average %ssynthesis took: %.3f usec (+- %.3f usec)\n",
> @@ -186,6 +187,7 @@ static int do_run_multi_threaded(struct target *target,
>  		perf_session__delete(session);
>  	}
> 
> +	fflush(stdout);
>  	time_average = avg_stats(&time_stats);
>  	time_stddev = stddev_stats(&time_stats);
>  	printf("    Average synthesis took: %.3f usec (+- %.3f usec)\n",
> --
> 2.25.1

-- 

- Arnaldo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [PATCH] perf bench: flush stats when pipe it to a file or to tee
  2021-11-13 12:16 ` Arnaldo Carvalho de Melo
@ 2021-11-13 12:18   ` Arnaldo Carvalho de Melo
  2021-11-15 22:41     ` Sohaib Mohamed
  0 siblings, 1 reply; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2021-11-13 12:18 UTC (permalink / raw)
  To: Sohaib Mohamed
  Cc: rickyman7, irogers, Peter Zijlstra, Ingo Molnar, Mark Rutland,
	Alexander Shishkin, Jiri Olsa, Namhyung Kim, Yury Norov,
	Andy Shevchenko, Andrew Morton, linux-perf-users, linux-kernel

Em Sat, Nov 13, 2021 at 09:16:42AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Nov 12, 2021 at 11:53:12PM +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.
> 
> Good, now try with 'perf test' :-)
> 
> Applying,

Humm, take that back, when I almost did it for 'perf test' I used
setvbuf(), take a look at it so that you don't have to go sprinkling
fflush() calls and missing some places.

- Arnaldo
 
> - 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 >
> > 
> > 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 <rickyman7@gmail.com>
> > Signed-off-by: Sohaib Mohamed <sohaib.amhmd@gmail.com>
> > ---
> >  tools/perf/bench/find-bit-bench.c | 1 +
> >  tools/perf/bench/synthesize.c     | 2 ++
> >  2 files changed, 3 insertions(+)
> > 
> > diff --git a/tools/perf/bench/find-bit-bench.c b/tools/perf/bench/find-bit-bench.c
> > index 22b5cfe97023..39fb4184fbcb 100644
> > --- a/tools/perf/bench/find-bit-bench.c
> > +++ b/tools/perf/bench/find-bit-bench.c
> > @@ -113,6 +113,7 @@ static int do_for_each_set_bit(unsigned int num_bits)
> > 
> >  		if (use_of_val == accumulator)  /* Try to avoid compiler tricks. */
> >  			printf("\n");
> > +		fflush(stdout);
> >  	}
> >  	bitmap_free(to_test);
> >  	return 0;
> > diff --git a/tools/perf/bench/synthesize.c b/tools/perf/bench/synthesize.c
> > index 7401ebbac100..d21d311df61b 100644
> > --- a/tools/perf/bench/synthesize.c
> > +++ b/tools/perf/bench/synthesize.c
> > @@ -92,6 +92,7 @@ static int do_run_single_threaded(struct perf_session *session,
> >  		update_stats(&event_stats, atomic_read(&event_count));
> >  	}
> > 
> > +	fflush(stdout);
> >  	time_average = avg_stats(&time_stats);
> >  	time_stddev = stddev_stats(&time_stats);
> >  	printf("  Average %ssynthesis took: %.3f usec (+- %.3f usec)\n",
> > @@ -186,6 +187,7 @@ static int do_run_multi_threaded(struct target *target,
> >  		perf_session__delete(session);
> >  	}
> > 
> > +	fflush(stdout);
> >  	time_average = avg_stats(&time_stats);
> >  	time_stddev = stddev_stats(&time_stats);
> >  	printf("    Average synthesis took: %.3f usec (+- %.3f usec)\n",
> > --
> > 2.25.1
> 
> -- 
> 
> - Arnaldo

-- 

- Arnaldo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [PATCH] perf bench: flush stats when pipe it to a file or to tee
  2021-11-13 12:18   ` Arnaldo Carvalho de Melo
@ 2021-11-15 22:41     ` Sohaib Mohamed
  2021-11-16 13:47       ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 5+ messages in thread
From: Sohaib Mohamed @ 2021-11-15 22:41 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: rickyman7, irogers, Peter Zijlstra, Ingo Molnar, Mark Rutland,
	Alexander Shishkin, Jiri Olsa, Namhyung Kim, Yury Norov,
	Andy Shevchenko, Andrew Morton, linux-perf-users, linux-kernel

Hello, Arnaldo

On Sat, Nov 13, 2021 at 09:18:22AM -0300, Arnaldo Carvalho de Melo wrote:
> Em Sat, Nov 13, 2021 at 09:16:42AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Fri, Nov 12, 2021 at 11:53:12PM +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.
> >
> > Good, now try with 'perf test' :-)
> >
> > Applying,
>
> Humm, take that back, when I almost did it for 'perf test' I used
> setvbuf(), take a look at it so that you don't have to go sprinkling
> fflush() calls and missing some places.
>
> - Arnaldo

I'm not sure about the meaning of 'perf test' here, Should I write new unit
tests?

I found I could invoke this function at the beginning of perf-bench:
setvbuf(stdout, NULL, _IONBF, 0);
This looks to me will resolve the issue for all perf-bench subcommands.
I'm not sure if a good practice...

This probably is version 2 of this patch:


diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
index d0895162c2ba..a0b812cde1ee 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,8 @@ int cmd_bench(int argc, const char **argv)
        struct collection *coll;
        int ret = 0;

+       setvbuf(stdout, NULL, _IONBF, 0);
+
        if (argc < 2) {
                /* No collection specified. */
                print_usage();
@@ -300,7 +301,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;
                }



Thanks,
- Sohaib

>
> > - 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 >
> > >
> > > 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 <rickyman7@gmail.com>
> > > Signed-off-by: Sohaib Mohamed <sohaib.amhmd@gmail.com>
> > > ---
> > >  tools/perf/bench/find-bit-bench.c | 1 +
> > >  tools/perf/bench/synthesize.c     | 2 ++
> > >  2 files changed, 3 insertions(+)
> > >
> > > diff --git a/tools/perf/bench/find-bit-bench.c b/tools/perf/bench/find-bit-bench.c
> > > index 22b5cfe97023..39fb4184fbcb 100644
> > > --- a/tools/perf/bench/find-bit-bench.c
> > > +++ b/tools/perf/bench/find-bit-bench.c
> > > @@ -113,6 +113,7 @@ static int do_for_each_set_bit(unsigned int num_bits)
> > >
> > >  		if (use_of_val == accumulator)  /* Try to avoid compiler tricks. */
> > >  			printf("\n");
> > > +		fflush(stdout);
> > >  	}
> > >  	bitmap_free(to_test);
> > >  	return 0;
> > > diff --git a/tools/perf/bench/synthesize.c b/tools/perf/bench/synthesize.c
> > > index 7401ebbac100..d21d311df61b 100644
> > > --- a/tools/perf/bench/synthesize.c
> > > +++ b/tools/perf/bench/synthesize.c
> > > @@ -92,6 +92,7 @@ static int do_run_single_threaded(struct perf_session *session,
> > >  		update_stats(&event_stats, atomic_read(&event_count));
> > >  	}
> > >
> > > +	fflush(stdout);
> > >  	time_average = avg_stats(&time_stats);
> > >  	time_stddev = stddev_stats(&time_stats);
> > >  	printf("  Average %ssynthesis took: %.3f usec (+- %.3f usec)\n",
> > > @@ -186,6 +187,7 @@ static int do_run_multi_threaded(struct target *target,
> > >  		perf_session__delete(session);
> > >  	}
> > >
> > > +	fflush(stdout);
> > >  	time_average = avg_stats(&time_stats);
> > >  	time_stddev = stddev_stats(&time_stats);
> > >  	printf("    Average synthesis took: %.3f usec (+- %.3f usec)\n",
> > > --
> > > 2.25.1
> >
> > --
> >
> > - Arnaldo
>
> --
>
> - Arnaldo

^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: [PATCH] perf bench: flush stats when pipe it to a file or to tee
  2021-11-15 22:41     ` Sohaib Mohamed
@ 2021-11-16 13:47       ` Arnaldo Carvalho de Melo
  0 siblings, 0 replies; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2021-11-16 13:47 UTC (permalink / raw)
  To: Sohaib Mohamed
  Cc: rickyman7, irogers, Peter Zijlstra, Ingo Molnar, Mark Rutland,
	Alexander Shishkin, Jiri Olsa, Namhyung Kim, Yury Norov,
	Andy Shevchenko, Andrew Morton, linux-perf-users, linux-kernel

Em Tue, Nov 16, 2021 at 12:41:51AM +0200, Sohaib Mohamed escreveu:
> Hello, Arnaldo
> 
> On Sat, Nov 13, 2021 at 09:18:22AM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Sat, Nov 13, 2021 at 09:16:42AM -0300, Arnaldo Carvalho de Melo escreveu:
> > > Em Fri, Nov 12, 2021 at 11:53:12PM +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.
> > >
> > > Good, now try with 'perf test' :-)
> > >
> > > Applying,
> >
> > Humm, take that back, when I almost did it for 'perf test' I used
> > setvbuf(), take a look at it so that you don't have to go sprinkling
> > fflush() calls and missing some places.
> >
> > - Arnaldo
> 
> I'm not sure about the meaning of 'perf test' here, Should I write new unit
> tests?

Try:

$ perf test 2>&1 | tee /tmp/bla

It uses buffered output, so we see the output in bumps, would be better
to use unbuffered.
 
> I found I could invoke this function at the beginning of perf-bench:
> setvbuf(stdout, NULL, _IONBF, 0);
> This looks to me will resolve the issue for all perf-bench subcommands.
> I'm not sure if a good practice...

Well, it will achieve what you want, right? Unbuffered output, which I
think is desirable.

> This probably is version 2 of this patch:

Yeah, looks ok.

- Arnaldo
 
> 
> diff --git a/tools/perf/builtin-bench.c b/tools/perf/builtin-bench.c
> index d0895162c2ba..a0b812cde1ee 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,8 @@ int cmd_bench(int argc, const char **argv)
>         struct collection *coll;
>         int ret = 0;
> 
> +       setvbuf(stdout, NULL, _IONBF, 0);
> +
>         if (argc < 2) {
>                 /* No collection specified. */
>                 print_usage();
> @@ -300,7 +301,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;
>                 }
> 
> 
> 
> Thanks,
> - Sohaib
> 
> >
> > > - 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 >
> > > >
> > > > 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 <rickyman7@gmail.com>
> > > > Signed-off-by: Sohaib Mohamed <sohaib.amhmd@gmail.com>
> > > > ---
> > > >  tools/perf/bench/find-bit-bench.c | 1 +
> > > >  tools/perf/bench/synthesize.c     | 2 ++
> > > >  2 files changed, 3 insertions(+)
> > > >
> > > > diff --git a/tools/perf/bench/find-bit-bench.c b/tools/perf/bench/find-bit-bench.c
> > > > index 22b5cfe97023..39fb4184fbcb 100644
> > > > --- a/tools/perf/bench/find-bit-bench.c
> > > > +++ b/tools/perf/bench/find-bit-bench.c
> > > > @@ -113,6 +113,7 @@ static int do_for_each_set_bit(unsigned int num_bits)
> > > >
> > > >  		if (use_of_val == accumulator)  /* Try to avoid compiler tricks. */
> > > >  			printf("\n");
> > > > +		fflush(stdout);
> > > >  	}
> > > >  	bitmap_free(to_test);
> > > >  	return 0;
> > > > diff --git a/tools/perf/bench/synthesize.c b/tools/perf/bench/synthesize.c
> > > > index 7401ebbac100..d21d311df61b 100644
> > > > --- a/tools/perf/bench/synthesize.c
> > > > +++ b/tools/perf/bench/synthesize.c
> > > > @@ -92,6 +92,7 @@ static int do_run_single_threaded(struct perf_session *session,
> > > >  		update_stats(&event_stats, atomic_read(&event_count));
> > > >  	}
> > > >
> > > > +	fflush(stdout);
> > > >  	time_average = avg_stats(&time_stats);
> > > >  	time_stddev = stddev_stats(&time_stats);
> > > >  	printf("  Average %ssynthesis took: %.3f usec (+- %.3f usec)\n",
> > > > @@ -186,6 +187,7 @@ static int do_run_multi_threaded(struct target *target,
> > > >  		perf_session__delete(session);
> > > >  	}
> > > >
> > > > +	fflush(stdout);
> > > >  	time_average = avg_stats(&time_stats);
> > > >  	time_stddev = stddev_stats(&time_stats);
> > > >  	printf("    Average synthesis took: %.3f usec (+- %.3f usec)\n",
> > > > --
> > > > 2.25.1
> > >
> > > --
> > >
> > > - Arnaldo
> >
> > --
> >
> > - Arnaldo

-- 

- Arnaldo

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2021-11-16 13:48 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-11-12 21:53 [PATCH] perf bench: flush stats when pipe it to a file or to tee Sohaib Mohamed
2021-11-13 12:16 ` Arnaldo Carvalho de Melo
2021-11-13 12:18   ` Arnaldo Carvalho de Melo
2021-11-15 22:41     ` Sohaib Mohamed
2021-11-16 13:47       ` Arnaldo Carvalho de Melo

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).