On Thu, Oct 10, 2019 at 06:31 PM CEST, Stanislav Fomichev wrote:
> On 10/10, Jakub Sitnicki wrote:
>> On Wed, Oct 09, 2019 at 06:33 PM CEST, Stanislav Fomichev wrote:
>> > On 10/09, Jakub Sitnicki wrote:
[...]
>> >> +/* Not used here. For CHECK macro sake only. */
>> >> +static int duration;
>> > nit: you can use CHECK_FAIL macro instead which doesn't require this.
>> >
>> > if (CHECK_FAIL(expr)) {
>> > printf("something bad has happened\n");
>> > return/goto;
>> > }
>> >
>> > It may be more verbose than doing CHECK() with its embedded error
>> > message, so I leave it up to you to decide on whether you want to switch
>> > to CHECK_FAIL or stick to CHECK.
>> >
>>
>> I wouldn't mind switching to CHECK_FAIL. It reads better than CHECK with
>> error message stuck in the if expression. (There is a side-issue with
>> printf(). Will explain at the end [*].)
>>
>> Another thing to consider is that with CHECK the message indicating a
>> failure ("<test>:FAIL:<lineno>") and the actual explanation message are
>> on the same line. This makes the error log easier to reason.
>>
>> I'm torn here, and considering another alternative to address at least
>> the readability issue:
>>
>> if (fail_expr) {
>> CHECK(1, "action", "explanation");
>> return;
>> }
> Can we use perror for the error reporting?
>
> if (CHECK(fail_expr)) {
> perror("failed to do something"); // will print errno as well
> }
>
> This should give all the info needed to grep for this message and debug
> the problem.
>
> Alternatively, we can copy/move log_err() from the cgroup_helpers.h,
> and use it in test_progs; it prints file:line:errno <msg>.
CHECK_FAIL + perror() works for me. I've been experimenting with
extracting a new macro-helper (patch below) but perhaps it's an
overkill.
[...]
>> [*] The printf() issue.
>>
>> I've noticed that stdio hijacking that test_progs runner applies doesn't
>> quite work. printf() seems to skip the FILE stream buffer and write
>> whole lines directly to stdout. This results in reordered messages on
>> output.
>>
>> Here's a distilled reproducer for what test_progs does:
>>
>> int main(void)
>> {
>> FILE *stream;
>> char *buf;
>> size_t cnt;
>>
>> stream = stdout;
>> stdout = open_memstream(&buf, &cnt);
>> if (!stdout)
>> error(1, errno, "open_memstream");
>>
>> printf("foo");
>> printf("bar\n");
>> printf("baz");
>> printf("qux\n");
>>
>> fflush(stdout);
>> fclose(stdout);
>>
>> buf[cnt] = '\0';
>> fprintf(stream, "<<%s>>", buf);
>> if (buf[cnt-1] != '\n')
>> fprintf(stream, "\n");
>>
>> free(buf);
>> return 0;
>> }
>>
>> On output we get:
>>
>> $ ./hijack_stdout
>> bar
>> qux
>> <<foobaz>>
>> $
> What glibc do you have? I don't see any issues with your reproducer
> on my setup:
>
> $ ./a.out
> <<foobar
> bazqux
>>>$
>
> $ ldd --version
> ldd (Debian GLIBC 2.28-10) 2.28
>
Interesting. I'm on the same version, different distro:
$ rpm -q glibc
glibc-2.28-33.fc29.x86_64
glibc-2.28-33.fc29.i686
I'll need to dig deeper. Thanks for keeping me honest here.
-Jakub
---8<---
>From 66fd85cd3bbb36cf99c8b6cbbb161d3c0533263b Mon Sep 17 00:00:00 2001
From: Jakub Sitnicki <jakub@xxxxxxxxxxxxxx>
Date: Thu, 10 Oct 2019 15:29:28 +0200
Subject: [PATCH net-next] selftests/bpf: test_progs: Extract a macro for
logging failures
When selecting a macro-helper to use for logging a test failure we are
faced with a choice between the shortcomings of CHECK and CHECK_FAIL.
CHECK is intended to be used in conjunction with bpf_prog_test_run(). It
expects a program run duration to be passed to it as an implicit argument.
While CHECK_FAIL is more generic but compared to CHECK doesn't allow
logging a custom error message to explain the failure.
Introduce a new macro-helper - FAIL, that is lower-level than the above it
and it intended to be used just log the failure with an explanation for it.
Because FAIL does in part what CHECK and CHECK_FAIL do, we can reuse it in
these macros. One side-effect is a slight the change in the log format. We
always display the line number where a check has passed/failed.
Signed-off-by: Jakub Sitnicki <jakub@xxxxxxxxxxxxxx>
---
tools/testing/selftests/bpf/test_progs.h | 17 ++++++++++-------
1 file changed, 10 insertions(+), 7 deletions(-)
diff --git a/tools/testing/selftests/bpf/test_progs.h b/tools/testing/selftests/bpf/test_progs.h
index 0c48f64f732b..9e203ff71b78 100644
--- a/tools/testing/selftests/bpf/test_progs.h
+++ b/tools/testing/selftests/bpf/test_progs.h
@@ -92,15 +92,19 @@ struct ipv6_packet {
} __packed;
extern struct ipv6_packet pkt_v6;
+#define FAIL(tag, format...) ({ \
+ test__fail(); \
+ printf("%s:%d:FAIL:%s ", __func__, __LINE__, tag); \
+ printf(format); \
+})
+
#define _CHECK(condition, tag, duration, format...) ({ \
int __ret = !!(condition); \
if (__ret) { \
- test__fail(); \
- printf("%s:FAIL:%s ", __func__, tag); \
- printf(format); \
+ FAIL(tag, format); \
} else { \
- printf("%s:PASS:%s %d nsec\n", \
- __func__, tag, duration); \
+ printf("%s:%d:PASS:%s %d nsec\n", \
+ __func__, __LINE__, tag, duration); \
} \
__ret; \
})
@@ -108,8 +112,7 @@ extern struct ipv6_packet pkt_v6;
#define CHECK_FAIL(condition) ({ \
int __ret = !!(condition); \
if (__ret) { \
- test__fail(); \
- printf("%s:FAIL:%d\n", __func__, __LINE__); \
+ FAIL("", #condition "\n"); \
} \
__ret; \
})
--
2.20.1
