diff mbox series

[v4,10/10] kunit: string-stream: Test performance of string_stream

Message ID 20230814132309.32641-11-rf@opensource.cirrus.com (mailing list archive)
State New
Delegated to: Brendan Higgins
Headers show
Series kunit: Add dynamically-extending log | expand

Commit Message

Richard Fitzgerald Aug. 14, 2023, 1:23 p.m. UTC
Add a test of the speed and memory use of string_stream.

string_stream_performance_test() doesn't actually "test" anything (it
cannot fail unless the system has run out of allocatable memory) but it
measures the speed and memory consumption of the string_stream and reports
the result.

This allows changes in the string_stream implementation to be compared.

Signed-off-by: Richard Fitzgerald <rf@opensource.cirrus.com>
---
 lib/kunit/string-stream-test.c | 54 ++++++++++++++++++++++++++++++++++
 1 file changed, 54 insertions(+)

Comments

David Gow Aug. 15, 2023, 9:17 a.m. UTC | #1
On Mon, 14 Aug 2023 at 21:23, Richard Fitzgerald
<rf@opensource.cirrus.com> wrote:
>
> Add a test of the speed and memory use of string_stream.
>
> string_stream_performance_test() doesn't actually "test" anything (it
> cannot fail unless the system has run out of allocatable memory) but it
> measures the speed and memory consumption of the string_stream and reports
> the result.
>
> This allows changes in the string_stream implementation to be compared.
>
> Signed-off-by: Richard Fitzgerald <rf@opensource.cirrus.com>
> ---

Thanks, this is very useful.

My results are (UML):
   # string_stream_performance_test: Time elapsed:           5021 us
   # string_stream_performance_test: Total string length:    573890
   # string_stream_performance_test: Bytes requested:        823930
   # string_stream_performance_test: Actual bytes allocated: 1048312

KUnit isn't really ideal for performance testing, but this works well
enough and fits in well alongside the other string stream tests.

Reviewed-by: David Gow <davidgow@google.com>

Cheers,
-- David


>  lib/kunit/string-stream-test.c | 54 ++++++++++++++++++++++++++++++++++
>  1 file changed, 54 insertions(+)
>
> diff --git a/lib/kunit/string-stream-test.c b/lib/kunit/string-stream-test.c
> index 05bfade2bd8a..b55cc14f43fb 100644
> --- a/lib/kunit/string-stream-test.c
> +++ b/lib/kunit/string-stream-test.c
> @@ -8,7 +8,9 @@
>
>  #include <kunit/static_stub.h>
>  #include <kunit/test.h>
> +#include <linux/ktime.h>
>  #include <linux/slab.h>
> +#include <linux/timekeeping.h>
>
>  #include "string-stream.h"
>
> @@ -370,6 +372,57 @@ static void string_stream_auto_newline_test(struct kunit *test)
>                            "One\nTwo\nThree\nFour\nFive\nSix\nSeven\n\nEight\n");
>  }
>
> +/*
> + * This doesn't actually "test" anything. It reports time taken
> + * and memory used for logging a large number of lines.
> + */
> +static void string_stream_performance_test(struct kunit *test)
> +{
> +       struct string_stream_fragment *frag_container;
> +       struct string_stream *stream;
> +       char test_line[101];
> +       ktime_t start_time, end_time;
> +       size_t len, bytes_requested, actual_bytes_used, total_string_length;
> +       int offset, i;
> +
> +       stream = alloc_string_stream(test, GFP_KERNEL);
> +       KUNIT_ASSERT_NOT_ERR_OR_NULL(test, stream);
> +
> +       memset(test_line, 'x', sizeof(test_line) - 1);
> +       test_line[sizeof(test_line) - 1] = '\0';
> +
> +       start_time = ktime_get();
> +       for (i = 0; i < 10000; i++) {
> +               offset = i % (sizeof(test_line) - 1);
> +               string_stream_add(stream, "%s: %d\n", &test_line[offset], i);
> +       }
> +       end_time = ktime_get();
> +
> +       /*
> +        * Calculate memory used. This doesn't include invisible
> +        * overhead due to kernel allocator fragment size rounding.
> +        */
> +       bytes_requested = sizeof(*stream);
> +       actual_bytes_used = ksize(stream);
> +       total_string_length = 0;
> +
> +       list_for_each_entry(frag_container, &stream->fragments, node) {
> +               bytes_requested += sizeof(*frag_container);
> +               actual_bytes_used += ksize(frag_container);
> +
> +               len = strlen(frag_container->fragment);
> +               total_string_length += len;
> +               bytes_requested += len + 1; /* +1 for '\0' */
> +               actual_bytes_used += ksize(frag_container->fragment);
> +       }
> +
> +       kunit_info(test, "Time elapsed:           %lld us\n",
> +                  ktime_us_delta(end_time, start_time));
> +       kunit_info(test, "Total string length:    %zu\n", total_string_length);
> +       kunit_info(test, "Bytes requested:        %zu\n", bytes_requested);
> +       kunit_info(test, "Actual bytes allocated: %zu\n", actual_bytes_used);
> +}
> +
>  static int string_stream_test_init(struct kunit *test)
>  {
>         struct string_stream_test_priv *priv;
> @@ -400,6 +453,7 @@ static struct kunit_case string_stream_test_cases[] = {
>         KUNIT_CASE(string_stream_append_empty_string_test),
>         KUNIT_CASE(string_stream_no_auto_newline_test),
>         KUNIT_CASE(string_stream_auto_newline_test),
> +       KUNIT_CASE(string_stream_performance_test),
>         {}
>  };
>
> --
> 2.30.2
>
diff mbox series

Patch

diff --git a/lib/kunit/string-stream-test.c b/lib/kunit/string-stream-test.c
index 05bfade2bd8a..b55cc14f43fb 100644
--- a/lib/kunit/string-stream-test.c
+++ b/lib/kunit/string-stream-test.c
@@ -8,7 +8,9 @@ 
 
 #include <kunit/static_stub.h>
 #include <kunit/test.h>
+#include <linux/ktime.h>
 #include <linux/slab.h>
+#include <linux/timekeeping.h>
 
 #include "string-stream.h"
 
@@ -370,6 +372,57 @@  static void string_stream_auto_newline_test(struct kunit *test)
 			   "One\nTwo\nThree\nFour\nFive\nSix\nSeven\n\nEight\n");
 }
 
+/*
+ * This doesn't actually "test" anything. It reports time taken
+ * and memory used for logging a large number of lines.
+ */
+static void string_stream_performance_test(struct kunit *test)
+{
+	struct string_stream_fragment *frag_container;
+	struct string_stream *stream;
+	char test_line[101];
+	ktime_t start_time, end_time;
+	size_t len, bytes_requested, actual_bytes_used, total_string_length;
+	int offset, i;
+
+	stream = alloc_string_stream(test, GFP_KERNEL);
+	KUNIT_ASSERT_NOT_ERR_OR_NULL(test, stream);
+
+	memset(test_line, 'x', sizeof(test_line) - 1);
+	test_line[sizeof(test_line) - 1] = '\0';
+
+	start_time = ktime_get();
+	for (i = 0; i < 10000; i++) {
+		offset = i % (sizeof(test_line) - 1);
+		string_stream_add(stream, "%s: %d\n", &test_line[offset], i);
+	}
+	end_time = ktime_get();
+
+	/*
+	 * Calculate memory used. This doesn't include invisible
+	 * overhead due to kernel allocator fragment size rounding.
+	 */
+	bytes_requested = sizeof(*stream);
+	actual_bytes_used = ksize(stream);
+	total_string_length = 0;
+
+	list_for_each_entry(frag_container, &stream->fragments, node) {
+		bytes_requested += sizeof(*frag_container);
+		actual_bytes_used += ksize(frag_container);
+
+		len = strlen(frag_container->fragment);
+		total_string_length += len;
+		bytes_requested += len + 1; /* +1 for '\0' */
+		actual_bytes_used += ksize(frag_container->fragment);
+	}
+
+	kunit_info(test, "Time elapsed:           %lld us\n",
+		   ktime_us_delta(end_time, start_time));
+	kunit_info(test, "Total string length:    %zu\n", total_string_length);
+	kunit_info(test, "Bytes requested:        %zu\n", bytes_requested);
+	kunit_info(test, "Actual bytes allocated: %zu\n", actual_bytes_used);
+}
+
 static int string_stream_test_init(struct kunit *test)
 {
 	struct string_stream_test_priv *priv;
@@ -400,6 +453,7 @@  static struct kunit_case string_stream_test_cases[] = {
 	KUNIT_CASE(string_stream_append_empty_string_test),
 	KUNIT_CASE(string_stream_no_auto_newline_test),
 	KUNIT_CASE(string_stream_auto_newline_test),
+	KUNIT_CASE(string_stream_performance_test),
 	{}
 };