Message-ID: <CABVgOSmKK2qeZ58+iCkgT9HGaPozVXE0+Z0K4u0hpx9GKg+_gw@mail.gmail.com>
Date: Sat, 3 Aug 2024 15:17:57 +0800
From: David Gow <davidgow@...gle.com>
To: Rae Moar <rmoar@...gle.com>
Cc: shuah@...nel.org, dlatypov@...gle.com, brendan.higgins@...ux.dev, 
	linux-kselftest@...r.kernel.org, kunit-dev@...glegroups.com, 
	linux-kernel@...r.kernel.org
Subject: Re: [PATCH v2] kunit: add test duration attribute

On Thu, 1 Aug 2024 at 04:15, Rae Moar <rmoar@...gle.com> wrote:
>
> Add a new test duration attribute to print the duration of a test run.
>
> Example:
>  KTAP version 1
>     # Subtest: memcpy
>     # module: memcpy_kunit
>     1..4
>     # memcpy_large_test.speed: slow
>     # memcpy_large_test.duration: 1.134787584s
>     ok 1 memcpy_large_test
>     ...
>
> This attribute is printed for each test (excluding parameterized tests).
>
> Add documentation for this new attribute to KUnit docs.
>
> In order to save the timespec64 object, add the ability to save a memory
> allocated object to the attributes framework.
>
> Signed-off-by: Rae Moar <rmoar@...gle.com>
> ---

I like this, but have a few suggestions, neither of which are
blockers, but would be useful future features:
- I'd like a way to filter what attributes are printed at runtime.
Once we get more attributes, this will get rapidly more annoying.
- We should think about keeping attributes around for longer, so we
can access them programmatically after the test finishes.
- (An example of these two could be to re-print out the results with
attributes filtered from debugfs)
- And, one day, it'd be nice to support attributes on parameterised
tests. Maybe with the parameterised test re-work.

None of these ideas are quite organised enough to block this patch,
which otherwise looks good and works well here. But I think they could
inspire some longer-term changes to the way we structure KUnit tests
in-memory and handle debugfs, alongside the other feature requests
we've had for parameterised tests. (Like having explicit context
associated with them, or supporting more arbitrary nesting.)

Regardless, this is

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

Cheers,
-- David

> Changes v1->v2:
> - Change sprintf to kasprintf
>
>  .../dev-tools/kunit/running_tips.rst          |  7 +++
>  include/kunit/attributes.h                    |  5 ++
>  include/kunit/test.h                          |  1 +
>  lib/kunit/attributes.c                        | 54 ++++++++++++++++++-
>  lib/kunit/test.c                              | 25 +++++++--
>  5 files changed, 86 insertions(+), 6 deletions(-)
>
> diff --git a/Documentation/dev-tools/kunit/running_tips.rst b/Documentation/dev-tools/kunit/running_tips.rst
> index bd689db6fdd2..a528d92e5d8f 100644
> --- a/Documentation/dev-tools/kunit/running_tips.rst
> +++ b/Documentation/dev-tools/kunit/running_tips.rst
> @@ -446,3 +446,10 @@ This attribute indicates whether the test uses init data or functions.
>
>  This attribute is automatically saved as a boolean and tests can also be
>  filtered using this attribute.
> +
> +``duration``
> +
> +This attribute indicates the length of time in seconds of the test execution.
> +
> +This attribute is automatically saved as a timespec64 and printed for each test
> +(excluding parameterized tests).
> diff --git a/include/kunit/attributes.h b/include/kunit/attributes.h
> index bc76a0b786d2..89ca54ef380d 100644
> --- a/include/kunit/attributes.h
> +++ b/include/kunit/attributes.h
> @@ -18,6 +18,11 @@ struct kunit_attr_filter {
>         char *input;
>  };
>
> +/*
> + * Frees all of a test's allocated attributes.
> + */
> +void kunit_free_attr(void *test_or_suite, bool is_test);
> +
>  /*
>   * Returns the name of the filter's attribute.
>   */
> diff --git a/include/kunit/test.h b/include/kunit/test.h
> index ec61cad6b71d..dca78d9bd3f6 100644
> --- a/include/kunit/test.h
> +++ b/include/kunit/test.h
> @@ -82,6 +82,7 @@ enum kunit_speed {
>  /* Holds attributes for each test case and suite */
>  struct kunit_attributes {
>         enum kunit_speed speed;
> +       struct timespec64 *duration;
>  };
>
>  /**
> diff --git a/lib/kunit/attributes.c b/lib/kunit/attributes.c
> index 2cf04cc09372..fd01d54e52d7 100644
> --- a/lib/kunit/attributes.c
> +++ b/lib/kunit/attributes.c
> @@ -40,6 +40,7 @@ struct kunit_attr {
>         int (*filter)(void *attr, const char *input, int *err);
>         void *attr_default;
>         enum print_ops print;
> +       bool to_free;
>  };
>
>  /* String Lists for enum Attributes */
> @@ -79,8 +80,22 @@ static const char *attr_string_to_string(void *attr, bool *to_free)
>         return (char *) attr;
>  }
>
> +static const char *attr_duration_to_string(void *attr, bool *to_free)
> +{
> +       struct timespec64 *val = (struct timespec64 *)attr;
> +       char *str = kasprintf(GFP_KERNEL, "%lld.%09lds", val->tv_sec, val->tv_nsec);
> +
> +       *to_free = true;
> +       return str;
> +}
> +
>  /* Filter Methods */
>
> +static int attr_default_filter(void *attr, const char *input, int *err)
> +{
> +       return false;
> +}
> +
>  static const char op_list[] = "<>!=";
>
>  /*
> @@ -246,8 +261,20 @@ static void *attr_is_init_get(void *test_or_suite, bool is_test)
>                 return ((void *) suite->is_init);
>  }
>
> +static void *attr_duration_get(void *test_or_suite, bool is_test)
> +{
> +       struct kunit_case *test = is_test ? test_or_suite : NULL;
> +
> +       if (test && !test->generate_params)
> +               return ((void *) test->attr.duration);
> +       else
> +               return ((void *) NULL);
> +}
> +
>  /* List of all Test Attributes */
>
> +static struct timespec64 duration_default = {0, 0};
> +
>  static struct kunit_attr kunit_attr_list[] = {
>         {
>                 .name = "speed",
> @@ -256,6 +283,7 @@ static struct kunit_attr kunit_attr_list[] = {
>                 .filter = attr_speed_filter,
>                 .attr_default = (void *)KUNIT_SPEED_NORMAL,
>                 .print = PRINT_ALWAYS,
> +               .to_free = false,
>         },
>         {
>                 .name = "module",
> @@ -264,6 +292,7 @@ static struct kunit_attr kunit_attr_list[] = {
>                 .filter = attr_string_filter,
>                 .attr_default = (void *)"",
>                 .print = PRINT_SUITE,
> +               .to_free = false,
>         },
>         {
>                 .name = "is_init",
> @@ -272,10 +301,33 @@ static struct kunit_attr kunit_attr_list[] = {
>                 .filter = attr_bool_filter,
>                 .attr_default = (void *)false,
>                 .print = PRINT_SUITE,
> +               .to_free = false,
> +       },
> +       {
> +               .name = "duration",
> +               .get_attr = attr_duration_get,
> +               .to_string = attr_duration_to_string,
> +               .filter = attr_default_filter,
> +               .attr_default = (void *)(&duration_default),
> +               .print = PRINT_ALWAYS,

I'd love to see a way of toggling this at runtime (e.g., from the
kernel command-line or debugfs). Not needed for the initial patch, but
a mechanism for suppressing this (rather noisy) attribute would be
good to get at some point.

> +               .to_free = true,
>         }
>  };
>
> -/* Helper Functions to Access Attributes */
> +/* Helper Functions to Access/Free Attributes */
> +
> +void kunit_free_attr(void *test_or_suite, bool is_test)
> +{
> +       int i;
> +       void *attr;
> +
> +       for (i = 0; i < ARRAY_SIZE(kunit_attr_list); i++) {
> +               if (kunit_attr_list[i].to_free) {
> +                       attr = kunit_attr_list[i].get_attr(test_or_suite, is_test);
> +                       kfree(attr);
> +               }
> +       }
> +}
>
>  const char *kunit_attr_filter_name(struct kunit_attr_filter filter)
>  {
> diff --git a/lib/kunit/test.c b/lib/kunit/test.c
> index e8b1b52a19ab..0d18e4969015 100644
> --- a/lib/kunit/test.c
> +++ b/lib/kunit/test.c
> @@ -376,11 +376,11 @@ static void kunit_run_case_check_speed(struct kunit *test,
>  /*
>   * Initializes and runs test case. Does not clean up or do post validations.
>   */
> -static void kunit_run_case_internal(struct kunit *test,
> +static struct timespec64 kunit_run_case_internal(struct kunit *test,
>                                     struct kunit_suite *suite,
>                                     struct kunit_case *test_case)
>  {
> -       struct timespec64 start, end;
> +       struct timespec64 start, end, duration;
>
>         if (suite->init) {
>                 int ret;
> @@ -389,7 +389,9 @@ static void kunit_run_case_internal(struct kunit *test,
>                 if (ret) {
>                         kunit_err(test, "failed to initialize: %d\n", ret);
>                         kunit_set_failure(test);
> -                       return;
> +                       duration.tv_sec = 0;
> +                       duration.tv_nsec = 0;
> +                       return duration;
>                 }
>         }
>
> @@ -399,7 +401,11 @@ static void kunit_run_case_internal(struct kunit *test,
>
>         ktime_get_ts64(&end);
>
> -       kunit_run_case_check_speed(test, test_case, timespec64_sub(end, start));
> +       duration = timespec64_sub(end, start);
> +
> +       kunit_run_case_check_speed(test, test_case, duration);
> +
> +       return duration;
>  }
>
>  static void kunit_case_internal_cleanup(struct kunit *test)
> @@ -424,6 +430,7 @@ struct kunit_try_catch_context {
>         struct kunit *test;
>         struct kunit_suite *suite;
>         struct kunit_case *test_case;
> +       struct timespec64 duration;
>  };
>
>  static void kunit_try_run_case(void *data)
> @@ -440,7 +447,7 @@ static void kunit_try_run_case(void *data)
>          * abort will be called, this thread will exit, and finally the parent
>          * thread will resume control and handle any necessary clean up.
>          */
> -       kunit_run_case_internal(test, suite, test_case);
> +       ctx->duration = kunit_run_case_internal(test, suite, test_case);
>  }
>
>  static void kunit_try_run_case_cleanup(void *data)
> @@ -521,6 +528,7 @@ static void kunit_run_case_catch_errors(struct kunit_suite *suite,
>  {
>         struct kunit_try_catch_context context;
>         struct kunit_try_catch *try_catch;
> +       struct timespec64 *duration = kmalloc(sizeof(struct timespec64), GFP_KERNEL);
>
>         try_catch = &test->try_catch;
>
> @@ -533,6 +541,10 @@ static void kunit_run_case_catch_errors(struct kunit_suite *suite,
>         context.test_case = test_case;
>         kunit_try_catch_run(try_catch, &context);
>
> +       duration->tv_sec = context.duration.tv_sec;
> +       duration->tv_nsec = context.duration.tv_nsec;
> +       test_case->attr.duration = duration;
> +
>         /* Now run the cleanup */
>         kunit_try_catch_init(try_catch,
>                              test,
> @@ -670,6 +682,7 @@ int kunit_run_tests(struct kunit_suite *suite)
>                 }
>
>                 kunit_print_attr((void *)test_case, true, KUNIT_LEVEL_CASE);
> +               kunit_free_attr((void *)test_case, true);

Do we want to keep this attribute around for, e.g., debugfs access? I
think we're okay at the moment (we're writing the actual value to the
log), but if we want a more structured way of accessing it, we'll want
to hold off on freeing this until the test is re-executed or the
module unloaded.

>
>                 kunit_print_test_stats(&test, param_stats);
>
> @@ -680,6 +693,7 @@ int kunit_run_tests(struct kunit_suite *suite)
>
>                 kunit_update_stats(&suite_stats, test_case->status);
>                 kunit_accumulate_stats(&total_stats, param_stats);
> +
>         }
>
>         if (suite->suite_exit)
> @@ -688,6 +702,7 @@ int kunit_run_tests(struct kunit_suite *suite)
>         kunit_print_suite_stats(suite, suite_stats, total_stats);
>  suite_end:
>         kunit_print_suite_end(suite);
> +       kunit_free_attr((void *)suite, false);

As above do we want to delay this until module unload and/or test re-execution?

>
>         return 0;
>  }
>
> base-commit: 67c9971cd6d309ecbcb87b942e22ffc194d7a376
> --
> 2.46.0.rc2.264.g509ed76dc8-goog
>

Download attachment "smime.p7s" of type "application/pkcs7-signature" (4014 bytes)

Powered by blists - more mailing lists