Re: [PATCH bpf-next 6/9] selftests/bpf: abstract away test log output

[Stanislav Fomichev <sdf@fomichev.me>]

On 07/26, Andrii Nakryiko wrote:
> On Fri, Jul 26, 2019 at 2:31 PM Stanislav Fomichev <sdf@fomichev.me> wrote:
> >
> > On 07/26, Andrii Nakryiko wrote:
> > > This patch changes how test output is printed out. By default, if test
> > > had no errors, the only output will be a single line with test number,
> > > name, and verdict at the end, e.g.:
> > >
> > >   #31 xdp:OK
> > >
> > > If test had any errors, all log output captured during test execution
> > > will be output after test completes.
> > >
> > > It's possible to force output of log with `-v` (`--verbose`) option, in
> > > which case output won't be buffered and will be output immediately.
> > >
> > > To support this, individual tests are required to use helper methods for
> > > logging: `test__printf()` and `test__vprintf()`.
> > >
> > > Signed-off-by: Andrii Nakryiko <andriin@fb.com>
> > > ---
> > >  .../selftests/bpf/prog_tests/bpf_obj_id.c     |   6 +-
> > >  .../bpf/prog_tests/bpf_verif_scale.c          |  31 ++--
> > >  .../bpf/prog_tests/get_stack_raw_tp.c         |   4 +-
> > >  .../selftests/bpf/prog_tests/l4lb_all.c       |   2 +-
> > >  .../selftests/bpf/prog_tests/map_lock.c       |  10 +-
> > >  .../selftests/bpf/prog_tests/send_signal.c    |   8 +-
> > >  .../selftests/bpf/prog_tests/spinlock.c       |   2 +-
> > >  .../bpf/prog_tests/stacktrace_build_id.c      |   4 +-
> > >  .../bpf/prog_tests/stacktrace_build_id_nmi.c  |   4 +-
> > >  .../selftests/bpf/prog_tests/xdp_noinline.c   |   3 +-
> > >  tools/testing/selftests/bpf/test_progs.c      | 135 +++++++++++++-----
> > >  tools/testing/selftests/bpf/test_progs.h      |  37 ++++-
> > >  12 files changed, 173 insertions(+), 73 deletions(-)
> > >
> 
> [...]
> 
> > >               error_cnt++;
> > > -             printf("test_l4lb:FAIL:stats %lld %lld\n", bytes, pkts);
> > > +             test__printf("test_l4lb:FAIL:stats %lld %lld\n", bytes, pkts);
> > #define printf(...) test__printf(...) in tests.h?
> >
> > A bit ugly, but no need to retrain everyone to use new printf wrappers.
> 
> I try to reduce amount of magic and surprising things, not add new
> ones :) I also led by example and converted all current instances of
> printf usage to test__printf, so anyone new will just copy/paste good
> example, hopefully. Even if not, this non-buffered output will be
> immediately obvious to anyone who just runs `sudo ./test_progs`.

[..]
> And
> author of new test with this problem should hopefully be the first and
> the only one to catch and fix this.
Yeah, that is my only concern, that regular printfs will eventually
creep in. It's already confusing to go to/from printf/printk.

2c:

I'm coming from a perspective of tools/testing/selftests/kselftest.h
which is supposed to be a generic framework with custom
printf variants (ksft_print_msg), but I still see a bunch of tests
calling printf :-/

	grep -ril ksft_exit_fail_msg selftests/ | xargs -n1 grep -w printf

Since we don't expect regular buffered io from the tests anyway
it might be easier just to add a bit of magic and call it a day.

> > >       }
> > >  out:
> > >       bpf_object__close(obj);
> > > diff --git a/tools/testing/selftests/bpf/prog_tests/map_lock.c b/tools/testing/selftests/bpf/prog_tests/map_lock.c
> > > index ee99368c595c..2e78217ed3fd 100644
> > > --- a/tools/testing/selftests/bpf/prog_tests/map_lock.c
> > > +++ b/tools/testing/selftests/bpf/prog_tests/map_lock.c
> > > @@ -9,12 +9,12 @@ static void *parallel_map_access(void *arg)
> 
> [...]