On 07/26, Andrii Nakryiko wrote:

On Fri, Jul 26, 2019 at 2:31 PM Stanislav Fomichev [off-list ref] wrote:

quoted

On 07/26, Andrii Nakryiko wrote:

quoted

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 <redacted>
---
 .../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(-)

[...]

quoted

quoted

              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.

quoted

quoted

      }
 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)

[...]