[PATCH bpf-next] bpf: test_bpf: Print total...

[PATCH bpf-next] bpf: test_bpf: Print total time of test in the summary

From: Tiezhu Yang <yangtiezhu@loongson.cn>
Date: 2021-08-21 12:14:18

The total time of test is useful to compare the performance
when bpf_jit_enable is 0 or 1, so print it in the summary.

Signed-off-by: Tiezhu Yang <yangtiezhu@loongson.cn>
---
 lib/test_bpf.c | 27 +++++++++++++++++++++------
 1 file changed, 21 insertions(+), 6 deletions(-)

diff --git a/lib/test_bpf.c b/lib/test_bpf.c
index 830a18e..b1b17ba 100644
--- a/lib/test_bpf.c
+++ b/lib/test_bpf.c

@@ -8920,6 +8920,9 @@ static __init int test_skb_segment_single(const struct skb_segment_test *test)
 static __init int test_skb_segment(void)
 {
 	int i, err_cnt = 0, pass_cnt = 0;
+	u64 start, finish;
+
+	start = ktime_get_ns();
 
 	for (i = 0; i < ARRAY_SIZE(skb_segment_tests); i++) {
 		const struct skb_segment_test *test = &skb_segment_tests[i];

@@ -8935,8 +8938,10 @@ static __init int test_skb_segment(void)
 		}
 	}
 
-	pr_info("%s: Summary: %d PASSED, %d FAILED\n", __func__,
-		pass_cnt, err_cnt);
+	finish = ktime_get_ns();
+
+	pr_info("%s: Summary: %d PASSED, %d FAILED in %llu nsec\n",
+		__func__, pass_cnt, err_cnt, finish - start);
 	return err_cnt ? -EINVAL : 0;
 }

@@ -8944,6 +8949,9 @@ static __init int test_bpf(void)
 {
 	int i, err_cnt = 0, pass_cnt = 0;
 	int jit_cnt = 0, run_cnt = 0;
+	u64 start, finish;
+
+	start = ktime_get_ns();
 
 	for (i = 0; i < ARRAY_SIZE(tests); i++) {
 		struct bpf_prog *fp;

@@ -8983,8 +8991,10 @@ static __init int test_bpf(void)
 		}
 	}
 
-	pr_info("Summary: %d PASSED, %d FAILED, [%d/%d JIT'ed]\n",
-		pass_cnt, err_cnt, jit_cnt, run_cnt);
+	finish = ktime_get_ns();
+
+	pr_info("Summary: %d PASSED, %d FAILED, [%d/%d JIT'ed] in %llu nsec\n",
+		pass_cnt, err_cnt, jit_cnt, run_cnt, finish - start);
 
 	return err_cnt ? -EINVAL : 0;
 }

@@ -9192,6 +9202,9 @@ static __init int test_tail_calls(struct bpf_array *progs)
 {
 	int i, err_cnt = 0, pass_cnt = 0;
 	int jit_cnt = 0, run_cnt = 0;
+	u64 start, finish;
+
+	start = ktime_get_ns();
 
 	for (i = 0; i < ARRAY_SIZE(tail_call_tests); i++) {
 		struct tail_call_test *test = &tail_call_tests[i];

@@ -9222,8 +9235,10 @@ static __init int test_tail_calls(struct bpf_array *progs)
 		}
 	}
 
-	pr_info("%s: Summary: %d PASSED, %d FAILED, [%d/%d JIT'ed]\n",
-		__func__, pass_cnt, err_cnt, jit_cnt, run_cnt);
+	finish = ktime_get_ns();
+
+	pr_info("%s: Summary: %d PASSED, %d FAILED, [%d/%d JIT'ed] in %llu nsec\n",
+		__func__, pass_cnt, err_cnt, jit_cnt, run_cnt, finish - start);
 
 	return err_cnt ? -EINVAL : 0;
 }

-- 
2.1.0

Re: [PATCH bpf-next] bpf: test_bpf: Print total time of test in the summary

From: Daniel Borkmann <daniel@iogearbox.net>
Date: 2021-08-23 15:48:17

On 8/21/21 2:13 PM, Tiezhu Yang wrote:

quoted hunk

The total time of test is useful to compare the performance
when bpf_jit_enable is 0 or 1, so print it in the summary.

Signed-off-by: Tiezhu Yang <yangtiezhu@loongson.cn>
---
  lib/test_bpf.c | 27 +++++++++++++++++++++------
  1 file changed, 21 insertions(+), 6 deletions(-)

diff --git a/lib/test_bpf.c b/lib/test_bpf.c
index 830a18e..b1b17ba 100644
--- a/lib/test_bpf.c
+++ b/lib/test_bpf.c

@@ -8920,6 +8920,9 @@ static __init int test_skb_segment_single(const struct skb_segment_test *test)
  static __init int test_skb_segment(void)
  {
  	int i, err_cnt = 0, pass_cnt = 0;
+	u64 start, finish;
+
+	start = ktime_get_ns();
  
  	for (i = 0; i < ARRAY_SIZE(skb_segment_tests); i++) {
  		const struct skb_segment_test *test = &skb_segment_tests[i];

@@ -8935,8 +8938,10 @@ static __init int test_skb_segment(void)
  		}
  	}
  
-	pr_info("%s: Summary: %d PASSED, %d FAILED\n", __func__,
-		pass_cnt, err_cnt);
+	finish = ktime_get_ns();
+
+	pr_info("%s: Summary: %d PASSED, %d FAILED in %llu nsec\n",
+		__func__, pass_cnt, err_cnt, finish - start);
  	return err_cnt ? -EINVAL : 0;
  }

I don't think this gives you any accurate results (e.g. what if this gets migrated
or preempted?); maybe rather use the duration from __run_one() ..

Thanks,
Daniel

`h`	back out one level
`j`	next message in thread
`k`	previous message in thread
`l`	drill in
`Esc`	close help / fold thread tree
`?`	toggle this help