| Message ID | 20230131220355.1603527-4-rmoar@google.com |
|---|---|
| State | New |
| Headers | show |
| Series | kunit: fix bugs in debugfs logs | expand |
On Wed, 1 Feb 2023 at 06:04, Rae Moar <rmoar@google.com> wrote: > > Fix bug of the extra newline characters in debugfs logs. When a > line is added to debugfs with a newline character at the end, > an extra line appears in the debugfs log. Remove these extra lines. > > Add kunit_log_newline_test to provide test coverage for this issue. > (Also, move kunit_log_test above suite definition to remove the > unnecessary declaration prior to the suite definition) > > Signed-off-by: Rae Moar <rmoar@google.com> > --- I've got some reservations about this patch. Firstly, could we have an example of the problem in the commit message, so we know what we're fixing? Secondly, I _really_ don't like the way this just removes newlines from log lines if there are too many. It feels like a hack, rather than a proper fix. I suspect the actual issue here is in the kunit_log macro in include/kunit/test.h: https://elixir.bootlin.com/linux/latest/source/include/kunit/test.h#L417 kunit_log_append((test_or_suite)->log, fmt "\n", ##__VA_ARGS__); \ The "\n" concatenated here is probably the issue. The printk statement doesn't add a newline, but that's because printk implicitly does if KERN_CONT is not added. So maybe the correct fix here is to use: printk(KERN_CONT lvl fmt "\n", ##__VA_ARGS__) That'd add the newline, rather than get rid of it, but at least should make the behaviour more similar between printk and the debugfs log. Equally, you could use KERN_CONT and get rid of the "\n" in both places, requiring it in log messages. Thirdly, I don't really like the way the test is skipped if debugfs isn't active. Could we skip it if test->log is not valid instead or using a compile-time #ifdef? I do like the move of kunit_log_test though. That definitely cleans things up! Cheers, -- David > lib/kunit/kunit-test.c | 36 ++++++++++++++++++++++++------------ > lib/kunit/test.c | 9 ++++++++- > 2 files changed, 32 insertions(+), 13 deletions(-) > > diff --git a/lib/kunit/kunit-test.c b/lib/kunit/kunit-test.c > index 4df0335d0d06..e9114a466f1e 100644 > --- a/lib/kunit/kunit-test.c > +++ b/lib/kunit/kunit-test.c > @@ -443,18 +443,6 @@ static struct kunit_suite kunit_resource_test_suite = { > .test_cases = kunit_resource_test_cases, > }; > > -static void kunit_log_test(struct kunit *test); > - > -static struct kunit_case kunit_log_test_cases[] = { > - KUNIT_CASE(kunit_log_test), > - {} > -}; > - > -static struct kunit_suite kunit_log_test_suite = { > - .name = "kunit-log-test", > - .test_cases = kunit_log_test_cases, > -}; > - > static void kunit_log_test(struct kunit *test) > { > struct kunit_suite suite; > @@ -481,6 +469,30 @@ static void kunit_log_test(struct kunit *test) > #endif > } > > +static void kunit_log_newline_test(struct kunit *test) > +{ > +#ifdef CONFIG_KUNIT_DEBUGFS > + kunit_info(test, "extra newline\n"); > + > + KUNIT_ASSERT_NOT_NULL_MSG(test, strstr(test->log, "extra newline\n"), > + "Missing log line, full log:\n%s", test->log); > + KUNIT_EXPECT_NULL(test, strstr(test->log, "extra newline\n\n")); > +#else > + kunit_skip(test, "only useful when debugfs is enabled"); > +#endif > +} > + > +static struct kunit_case kunit_log_test_cases[] = { > + KUNIT_CASE(kunit_log_test), > + KUNIT_CASE(kunit_log_newline_test), > + {} > +}; > + > +static struct kunit_suite kunit_log_test_suite = { > + .name = "kunit-log-test", > + .test_cases = kunit_log_test_cases, > +}; > + > static void kunit_status_set_failure_test(struct kunit *test) > { > struct kunit fake; > diff --git a/lib/kunit/test.c b/lib/kunit/test.c > index 27763f0b420c..76d9c31943bf 100644 > --- a/lib/kunit/test.c > +++ b/lib/kunit/test.c > @@ -117,6 +117,7 @@ void kunit_log_append(char *log, const char *fmt, ...) > char line[KUNIT_LOG_SIZE]; > va_list args; > int len_left; > + int line_len; > > if (!log) > return; > @@ -125,10 +126,16 @@ void kunit_log_append(char *log, const char *fmt, ...) > if (len_left <= 0) > return; > > + // Evaluate the length of the line with arguments > va_start(args, fmt); > - vsnprintf(line, sizeof(line), fmt, args); > + line_len = vsnprintf(line, sizeof(line), fmt, args); > va_end(args); > > + // If line has two newline characters, do not print > + // second newline character > + if (fmt[strlen(fmt) - 2] == '\n') > + line[line_len - 1] = '\0'; > + > strncat(log, line, len_left); > } > EXPORT_SYMBOL_GPL(kunit_log_append); > -- > 2.39.1.456.gfc5497dd1b-goog >
On Thu, Feb 9, 2023 at 12:06 AM David Gow <davidgow@google.com> wrote: > > On Wed, 1 Feb 2023 at 06:04, Rae Moar <rmoar@google.com> wrote: > > > > Fix bug of the extra newline characters in debugfs logs. When a > > line is added to debugfs with a newline character at the end, > > an extra line appears in the debugfs log. Remove these extra lines. > > > > Add kunit_log_newline_test to provide test coverage for this issue. > > (Also, move kunit_log_test above suite definition to remove the > > unnecessary declaration prior to the suite definition) > > > > Signed-off-by: Rae Moar <rmoar@google.com> > > --- Hi David! > > I've got some reservations about this patch. > > Firstly, could we have an example of the problem in the commit > message, so we know what we're fixing? Yes, as mentioned in the second patch, I will add an individual "before and after" comparison to each of the patches in v2. This is much clearer than just the overall comparison in the cover letter. > > Secondly, I _really_ don't like the way this just removes newlines > from log lines if there are too many. It feels like a hack, rather > than a proper fix. > > I suspect the actual issue here is in the kunit_log macro in > include/kunit/test.h: > https://elixir.bootlin.com/linux/latest/source/include/kunit/test.h#L417 > > kunit_log_append((test_or_suite)->log, fmt "\n", ##__VA_ARGS__); \ > > The "\n" concatenated here is probably the issue. The printk statement > doesn't add a newline, but that's because printk implicitly does if > KERN_CONT is not added. > > So maybe the correct fix here is to use: > printk(KERN_CONT lvl fmt "\n", ##__VA_ARGS__) > > That'd add the newline, rather than get rid of it, but at least should > make the behaviour more similar between printk and the debugfs log. > Equally, you could use KERN_CONT and get rid of the "\n" in both > places, requiring it in log messages. I understand how this seems a bit hacky. There were quite a few discussions on how to approach this prior to sending this out on this list. But changing the printk to be consistent between the debugfs and normal output is a great idea! This does cause a few tests to have extra lines in the output but shouldn't cause any issues with the parser readable output. I will definitely change this in v2. > > Thirdly, I don't really like the way the test is skipped if debugfs > isn't active. Could we skip it if test->log is not valid instead or > using a compile-time #ifdef? Yes this makes sense. Happy to change this in v2. The kunit_log_test also uses this #ifdef statement. Should this be changed as well? > > I do like the move of kunit_log_test though. That definitely cleans things up! > > Cheers, > -- David > Thanks! Rae > > > lib/kunit/kunit-test.c | 36 ++++++++++++++++++++++++------------ > > lib/kunit/test.c | 9 ++++++++- > > 2 files changed, 32 insertions(+), 13 deletions(-) > > > > diff --git a/lib/kunit/kunit-test.c b/lib/kunit/kunit-test.c > > index 4df0335d0d06..e9114a466f1e 100644 > > --- a/lib/kunit/kunit-test.c > > +++ b/lib/kunit/kunit-test.c > > @@ -443,18 +443,6 @@ static struct kunit_suite kunit_resource_test_suite = { > > .test_cases = kunit_resource_test_cases, > > }; > > > > -static void kunit_log_test(struct kunit *test); > > - > > -static struct kunit_case kunit_log_test_cases[] = { > > - KUNIT_CASE(kunit_log_test), > > - {} > > -}; > > - > > -static struct kunit_suite kunit_log_test_suite = { > > - .name = "kunit-log-test", > > - .test_cases = kunit_log_test_cases, > > -}; > > - > > static void kunit_log_test(struct kunit *test) > > { > > struct kunit_suite suite; > > @@ -481,6 +469,30 @@ static void kunit_log_test(struct kunit *test) > > #endif > > } > > > > +static void kunit_log_newline_test(struct kunit *test) > > +{ > > +#ifdef CONFIG_KUNIT_DEBUGFS > > + kunit_info(test, "extra newline\n"); > > + > > + KUNIT_ASSERT_NOT_NULL_MSG(test, strstr(test->log, "extra newline\n"), > > + "Missing log line, full log:\n%s", test->log); > > + KUNIT_EXPECT_NULL(test, strstr(test->log, "extra newline\n\n")); > > +#else > > + kunit_skip(test, "only useful when debugfs is enabled"); > > +#endif > > +} > > + > > +static struct kunit_case kunit_log_test_cases[] = { > > + KUNIT_CASE(kunit_log_test), > > + KUNIT_CASE(kunit_log_newline_test), > > + {} > > +}; > > + > > +static struct kunit_suite kunit_log_test_suite = { > > + .name = "kunit-log-test", > > + .test_cases = kunit_log_test_cases, > > +}; > > + > > static void kunit_status_set_failure_test(struct kunit *test) > > { > > struct kunit fake; > > diff --git a/lib/kunit/test.c b/lib/kunit/test.c > > index 27763f0b420c..76d9c31943bf 100644 > > --- a/lib/kunit/test.c > > +++ b/lib/kunit/test.c > > @@ -117,6 +117,7 @@ void kunit_log_append(char *log, const char *fmt, ...) > > char line[KUNIT_LOG_SIZE]; > > va_list args; > > int len_left; > > + int line_len; > > > > if (!log) > > return; > > @@ -125,10 +126,16 @@ void kunit_log_append(char *log, const char *fmt, ...) > > if (len_left <= 0) > > return; > > > > + // Evaluate the length of the line with arguments > > va_start(args, fmt); > > - vsnprintf(line, sizeof(line), fmt, args); > > + line_len = vsnprintf(line, sizeof(line), fmt, args); > > va_end(args); > > > > + // If line has two newline characters, do not print > > + // second newline character > > + if (fmt[strlen(fmt) - 2] == '\n') > > + line[line_len - 1] = '\0'; > > + > > strncat(log, line, len_left); > > } > > EXPORT_SYMBOL_GPL(kunit_log_append); > > -- > > 2.39.1.456.gfc5497dd1b-goog > >
diff --git a/lib/kunit/kunit-test.c b/lib/kunit/kunit-test.c index 4df0335d0d06..e9114a466f1e 100644 --- a/lib/kunit/kunit-test.c +++ b/lib/kunit/kunit-test.c @@ -443,18 +443,6 @@ static struct kunit_suite kunit_resource_test_suite = { .test_cases = kunit_resource_test_cases, }; -static void kunit_log_test(struct kunit *test); - -static struct kunit_case kunit_log_test_cases[] = { - KUNIT_CASE(kunit_log_test), - {} -}; - -static struct kunit_suite kunit_log_test_suite = { - .name = "kunit-log-test", - .test_cases = kunit_log_test_cases, -}; - static void kunit_log_test(struct kunit *test) { struct kunit_suite suite; @@ -481,6 +469,30 @@ static void kunit_log_test(struct kunit *test) #endif } +static void kunit_log_newline_test(struct kunit *test) +{ +#ifdef CONFIG_KUNIT_DEBUGFS + kunit_info(test, "extra newline\n"); + + KUNIT_ASSERT_NOT_NULL_MSG(test, strstr(test->log, "extra newline\n"), + "Missing log line, full log:\n%s", test->log); + KUNIT_EXPECT_NULL(test, strstr(test->log, "extra newline\n\n")); +#else + kunit_skip(test, "only useful when debugfs is enabled"); +#endif +} + +static struct kunit_case kunit_log_test_cases[] = { + KUNIT_CASE(kunit_log_test), + KUNIT_CASE(kunit_log_newline_test), + {} +}; + +static struct kunit_suite kunit_log_test_suite = { + .name = "kunit-log-test", + .test_cases = kunit_log_test_cases, +}; + static void kunit_status_set_failure_test(struct kunit *test) { struct kunit fake; diff --git a/lib/kunit/test.c b/lib/kunit/test.c index 27763f0b420c..76d9c31943bf 100644 --- a/lib/kunit/test.c +++ b/lib/kunit/test.c @@ -117,6 +117,7 @@ void kunit_log_append(char *log, const char *fmt, ...) char line[KUNIT_LOG_SIZE]; va_list args; int len_left; + int line_len; if (!log) return; @@ -125,10 +126,16 @@ void kunit_log_append(char *log, const char *fmt, ...) if (len_left <= 0) return; + // Evaluate the length of the line with arguments va_start(args, fmt); - vsnprintf(line, sizeof(line), fmt, args); + line_len = vsnprintf(line, sizeof(line), fmt, args); va_end(args); + // If line has two newline characters, do not print + // second newline character + if (fmt[strlen(fmt) - 2] == '\n') + line[line_len - 1] = '\0'; + strncat(log, line, len_left); } EXPORT_SYMBOL_GPL(kunit_log_append);
Fix bug of the extra newline characters in debugfs logs. When a line is added to debugfs with a newline character at the end, an extra line appears in the debugfs log. Remove these extra lines. Add kunit_log_newline_test to provide test coverage for this issue. (Also, move kunit_log_test above suite definition to remove the unnecessary declaration prior to the suite definition) Signed-off-by: Rae Moar <rmoar@google.com> --- lib/kunit/kunit-test.c | 36 ++++++++++++++++++++++++------------ lib/kunit/test.c | 9 ++++++++- 2 files changed, 32 insertions(+), 13 deletions(-)