Add test cases for the dynamically-extending log buffer.
kunit_log_extend_test_1() logs a series of numbered lines then tests
that the resulting log contains all the lines.
kunit_log_extend_test_2() logs a large number of lines of varying length
to create many fragments, then tests that all lines are present.
kunit_log_frag_sized_line_test() logs a line that exactly fills a
fragment. This should not cause an extension of the log or truncation
of the line.
kunit_log_newline_test() has a new test to append a line that is exactly
the length of the available space in the current fragment and check that
the resulting log has a trailing '\n'.
Signed-off-by: Richard Fitzgerald <[email protected]>
---
lib/kunit/kunit-test.c | 204 +++++++++++++++++++++++++++++++++++++++++
1 file changed, 204 insertions(+)
diff --git a/lib/kunit/kunit-test.c b/lib/kunit/kunit-test.c
index 54dc011c8980..48967d12e053 100644
--- a/lib/kunit/kunit-test.c
+++ b/lib/kunit/kunit-test.c
@@ -7,6 +7,7 @@
*/
#include <kunit/test.h>
#include <kunit/test-bug.h>
+#include <linux/prandom.h>
#include "try-catch-impl.h"
@@ -530,6 +531,31 @@ static struct kunit_suite kunit_resource_test_suite = {
.test_cases = kunit_resource_test_cases,
};
+static char *get_concatenated_log(struct kunit *test, const struct list_head *log,
+ int *num_frags)
+{
+ struct kunit_log_frag *frag;
+ size_t len = 0;
+ int frag_count = 0;
+ char *p;
+
+ list_for_each_entry(frag, log, list)
+ len += strlen(frag->buf);
+
+ len++; /* for terminating '\0' */
+ p = kunit_kmalloc(test, len, GFP_KERNEL);
+
+ list_for_each_entry(frag, log, list) {
+ strlcat(p, frag->buf, len);
+ ++frag_count;
+ }
+
+ if (num_frags)
+ *num_frags = frag_count;
+
+ return p;
+}
+
static void kunit_log_test(struct kunit *test)
{
struct kunit_suite suite;
@@ -568,7 +594,9 @@ static void kunit_log_test(struct kunit *test)
static void kunit_log_newline_test(struct kunit *test)
{
+ struct kunit_suite suite;
struct kunit_log_frag *frag;
+ char *p;
kunit_info(test, "Add newline\n");
if (test->log) {
@@ -576,14 +604,190 @@ static void kunit_log_newline_test(struct kunit *test)
KUNIT_ASSERT_NOT_NULL_MSG(test, strstr(frag->buf, "Add newline\n"),
"Missing log line, full log:\n%s", frag->buf);
KUNIT_EXPECT_NULL(test, strstr(frag->buf, "Add newline\n\n"));
+
+ suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
+ INIT_LIST_HEAD(suite.log);
+ frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
+ kunit_init_log_frag(frag);
+ list_add_tail(&frag->list, suite.log);
+
+ /* String that exactly fills fragment leaving no room for \n */
+ memset(frag->buf, 0, sizeof(frag->buf));
+ memset(frag->buf, 'x', sizeof(frag->buf) - 9);
+ kunit_log_append(suite.log, "12345678");
+ p = get_concatenated_log(test, suite.log, NULL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, p);
+ KUNIT_EXPECT_NOT_NULL_MSG(test, strstr(p, "x12345678\n"),
+ "Newline not appended when fragment is full. Log is:\n'%s'", p);
} else {
kunit_skip(test, "only useful when debugfs is enabled");
}
}
+static void kunit_log_extend_test_1(struct kunit *test)
+{
+#ifdef CONFIG_KUNIT_DEBUGFS
+ struct kunit_suite suite;
+ struct kunit_log_frag *frag;
+ char line[60];
+ char *p, *pn;
+ size_t len, n;
+ int num_lines, num_frags, i;
+
+ suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
+ INIT_LIST_HEAD(suite.log);
+ frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
+ kunit_init_log_frag(frag);
+ KUNIT_EXPECT_EQ(test, frag->buf[0], '\0');
+ list_add_tail(&frag->list, suite.log);
+
+ i = 0;
+ len = 0;
+ do {
+ n = snprintf(line, sizeof(line),
+ "The quick brown fox jumps over the lazy penguin %d\n", i);
+ KUNIT_ASSERT_LT(test, n, sizeof(line));
+ kunit_log_append(suite.log, line);
+ ++i;
+ len += n;
+ } while (len < (sizeof(frag->buf) * 30));
+ num_lines = i;
+
+ p = get_concatenated_log(test, suite.log, &num_frags);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, p);
+ KUNIT_EXPECT_GT(test, num_frags, 1);
+
+ kunit_info(test, "num lines:%d num_frags:%d total len:%zu\n",
+ num_lines, num_frags, strlen(p));
+
+ i = 0;
+ while ((pn = strchr(p, '\n')) != NULL) {
+ *pn = '\0';
+ snprintf(line, sizeof(line),
+ "The quick brown fox jumps over the lazy penguin %d", i);
+ KUNIT_EXPECT_STREQ(test, p, line);
+ p = pn + 1;
+ ++i;
+ }
+ KUNIT_EXPECT_EQ(test, i, num_lines);
+#else
+ kunit_skip(test, "only useful when debugfs is enabled");
+#endif
+}
+
+static void kunit_log_extend_test_2(struct kunit *test)
+{
+#ifdef CONFIG_KUNIT_DEBUGFS
+ struct kunit_suite suite;
+ struct kunit_log_frag *frag;
+ struct rnd_state rnd;
+ char line[101];
+ char *p, *pn;
+ size_t len;
+ int num_lines, num_frags, n, i;
+
+ suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
+ INIT_LIST_HEAD(suite.log);
+ frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
+ kunit_init_log_frag(frag);
+ KUNIT_EXPECT_EQ(test, frag->buf[0], '\0');
+ list_add_tail(&frag->list, suite.log);
+
+ /* Build log line of varying content */
+ line[0] = '\0';
+ i = 0;
+ do {
+ char tmp[9];
+
+ snprintf(tmp, sizeof(tmp), "%x", i++);
+ len = strlcat(line, tmp, sizeof(line));
+ } while (len < sizeof(line) - 1);
+
+ /*
+ * Log lines of different lengths until we have created
+ * many fragments.
+ * The "randomness" must be repeatable.
+ */
+ prandom_seed_state(&rnd, 3141592653589793238ULL);
+ i = 0;
+ len = 0;
+ num_lines = 0;
+ do {
+ kunit_log_append(suite.log, "%s\n", &line[i]);
+ len += sizeof(line) - i;
+ num_lines++;
+ i = prandom_u32_state(&rnd) % (sizeof(line) - 1);
+ } while (len < (sizeof(frag->buf) * 30));
+
+ /* There must be more than one buffer fragment now */
+ KUNIT_EXPECT_FALSE(test, list_is_singular(suite.log));
+
+ p = get_concatenated_log(test, suite.log, &num_frags);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, p);
+ KUNIT_EXPECT_GT(test, num_frags, 1);
+
+ kunit_info(test, "num lines:%d num_frags:%d total len:%zu\n",
+ num_lines, num_frags, strlen(p));
+
+ prandom_seed_state(&rnd, 3141592653589793238ULL);
+ i = 0;
+ n = 0;
+ while ((pn = strchr(p, '\n')) != NULL) {
+ *pn = '\0';
+ KUNIT_EXPECT_STREQ(test, p, &line[i]);
+ p = pn + 1;
+ n++;
+ i = prandom_u32_state(&rnd) % (sizeof(line) - 1);
+ }
+ KUNIT_EXPECT_EQ_MSG(test, n, num_lines, "Not enough lines.");
+#else
+ kunit_skip(test, "only useful when debugfs is enabled");
+#endif
+}
+
+static void kunit_log_frag_sized_line_test(struct kunit *test)
+{
+#ifdef CONFIG_KUNIT_DEBUGFS
+ struct kunit_suite suite;
+ struct kunit_log_frag *frag, *src;
+
+ suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
+ INIT_LIST_HEAD(suite.log);
+ frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
+ kunit_init_log_frag(frag);
+ KUNIT_EXPECT_EQ(test, frag->buf[0], '\0');
+ list_add_tail(&frag->list, suite.log);
+
+ src = kunit_kzalloc(test, sizeof(*src), GFP_KERNEL);
+ KUNIT_ASSERT_NOT_ERR_OR_NULL(test, src);
+ memset(src->buf, 'x', sizeof(src->buf) - 2);
+ KUNIT_ASSERT_EQ(test, strlen(src->buf), sizeof(src->buf) - 2);
+
+ /* Log a string that exactly fills the fragment */
+ kunit_log_append(suite.log, "%s\n", src->buf);
+ KUNIT_EXPECT_TRUE(test, list_is_singular(suite.log));
+ KUNIT_EXPECT_EQ(test, strlen(frag->buf), sizeof(frag->buf) - 1);
+ strlcat(src->buf, "\n", sizeof(src->buf));
+ KUNIT_EXPECT_STREQ(test, frag->buf, src->buf);
+#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),
+ KUNIT_CASE(kunit_log_extend_test_1),
+ KUNIT_CASE(kunit_log_extend_test_2),
+ KUNIT_CASE(kunit_log_frag_sized_line_test),
{}
};
--
2.30.2
On Tue, Aug 8, 2023 at 8:35 AM Richard Fitzgerald
<[email protected]> wrote:
>
> Add test cases for the dynamically-extending log buffer.
>
> kunit_log_extend_test_1() logs a series of numbered lines then tests
> that the resulting log contains all the lines.
>
> kunit_log_extend_test_2() logs a large number of lines of varying length
> to create many fragments, then tests that all lines are present.
>
> kunit_log_frag_sized_line_test() logs a line that exactly fills a
> fragment. This should not cause an extension of the log or truncation
> of the line.
>
> kunit_log_newline_test() has a new test to append a line that is exactly
> the length of the available space in the current fragment and check that
> the resulting log has a trailing '\n'.
>
> Signed-off-by: Richard Fitzgerald <[email protected]>
Hello!
I am happy to see so many tests in this patch series. I've been
working with these patches and the debugfs logs seem to be working
well.
However, when I ran the new kunit-log-test tests three of the tests
failed: kunit_log_extend_test_1(), kunit_log_extend_test_2(), and
kunit_log_newline_test().
The diagnostic info for kunit_log_extend_test_1() reports:
[20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
lib/kunit/kunit-test.c:705
[20:55:27] Expected p == line, but
[20:55:27] p == "xxxxxx…xxxx12345678"
[20:55:27] line == "The quick brown fox jumps over the lazy penguin 0"
…
[20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
lib/kunit/kunit-test.c:705
[20:55:27] Expected p == line, but
[20:55:27] p == "The quick brown fox jumps over the lazy penguin 1"
[20:55:27] line == "The quick brown fox jumps over the lazy penguin 4"
[20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
lib/kunit/kunit-test.c:705
[20:55:27] Expected p == line, but
[20:55:27] p == "The quick brown fox jumps over the lazy penguin 2"
[20:55:27] line == "The quick brown fox jumps over the lazy penguin 5"
…
[20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
lib/kunit/kunit-test.c:709
[20:55:27] Expected i == num_lines, but
[20:55:27] i == 64 (0x40)
[20:55:27] num_lines == 141 (0x8d)
So it looks like the log contains a different number of lines than
expected which is causing the difference of 3 between expected and
what was obtained. Potentially the log is not getting cleared/freed
properly in between test cases?
The diagnostic info for kunit_log_extend_test_2() reports:
[20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
lib/kunit/kunit-test.c:776
[20:55:27] Expected p == &line[i], but
[20:55:27] p ==
"xxxxx...xxxxx123456780123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
[20:55:27] &line[i] ==
"0123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
[20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
lib/kunit/kunit-test.c:781
[20:55:27] Expected n == num_lines, but
[20:55:27] n == 147 (0x93)
[20:55:27] num_lines == 155 (0x9b)
[20:55:27] Not enough lines.
Similar difference in the number of lines here.
The diagnostic info for kunit_log_newline_test() reports that the test
fails on this line:
KUNIT_EXPECT_EQ(test, p[strlen(p) - 1], '\n');
Let me know if you are seeing similar errors. I can post the full log
if that would be helpful.
-Rae
> ---
> lib/kunit/kunit-test.c | 204 +++++++++++++++++++++++++++++++++++++++++
> 1 file changed, 204 insertions(+)
>
> diff --git a/lib/kunit/kunit-test.c b/lib/kunit/kunit-test.c
> index 54dc011c8980..48967d12e053 100644
> --- a/lib/kunit/kunit-test.c
> +++ b/lib/kunit/kunit-test.c
> @@ -7,6 +7,7 @@
> */
> #include <kunit/test.h>
> #include <kunit/test-bug.h>
> +#include <linux/prandom.h>
>
> #include "try-catch-impl.h"
>
> @@ -530,6 +531,31 @@ static struct kunit_suite kunit_resource_test_suite = {
> .test_cases = kunit_resource_test_cases,
> };
>
> +static char *get_concatenated_log(struct kunit *test, const struct list_head *log,
> + int *num_frags)
> +{
> + struct kunit_log_frag *frag;
> + size_t len = 0;
> + int frag_count = 0;
> + char *p;
> +
> + list_for_each_entry(frag, log, list)
> + len += strlen(frag->buf);
> +
> + len++; /* for terminating '\0' */
> + p = kunit_kmalloc(test, len, GFP_KERNEL);
> +
> + list_for_each_entry(frag, log, list) {
> + strlcat(p, frag->buf, len);
> + ++frag_count;
> + }
> +
> + if (num_frags)
> + *num_frags = frag_count;
> +
> + return p;
> +}
> +
> static void kunit_log_test(struct kunit *test)
> {
> struct kunit_suite suite;
> @@ -568,7 +594,9 @@ static void kunit_log_test(struct kunit *test)
>
> static void kunit_log_newline_test(struct kunit *test)
> {
> + struct kunit_suite suite;
> struct kunit_log_frag *frag;
> + char *p;
>
> kunit_info(test, "Add newline\n");
> if (test->log) {
> @@ -576,14 +604,190 @@ static void kunit_log_newline_test(struct kunit *test)
> KUNIT_ASSERT_NOT_NULL_MSG(test, strstr(frag->buf, "Add newline\n"),
> "Missing log line, full log:\n%s", frag->buf);
> KUNIT_EXPECT_NULL(test, strstr(frag->buf, "Add newline\n\n"));
> +
> + suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
> + INIT_LIST_HEAD(suite.log);
> + frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
> + kunit_init_log_frag(frag);
> + list_add_tail(&frag->list, suite.log);
> +
> + /* String that exactly fills fragment leaving no room for \n */
> + memset(frag->buf, 0, sizeof(frag->buf));
> + memset(frag->buf, 'x', sizeof(frag->buf) - 9);
> + kunit_log_append(suite.log, "12345678");
> + p = get_concatenated_log(test, suite.log, NULL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, p);
> + KUNIT_EXPECT_NOT_NULL_MSG(test, strstr(p, "x12345678\n"),
> + "Newline not appended when fragment is full. Log is:\n'%s'", p);
> } else {
> kunit_skip(test, "only useful when debugfs is enabled");
> }
> }
>
> +static void kunit_log_extend_test_1(struct kunit *test)
> +{
> +#ifdef CONFIG_KUNIT_DEBUGFS
> + struct kunit_suite suite;
> + struct kunit_log_frag *frag;
> + char line[60];
> + char *p, *pn;
> + size_t len, n;
> + int num_lines, num_frags, i;
> +
> + suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
> + INIT_LIST_HEAD(suite.log);
> + frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
> + kunit_init_log_frag(frag);
> + KUNIT_EXPECT_EQ(test, frag->buf[0], '\0');
> + list_add_tail(&frag->list, suite.log);
> +
> + i = 0;
> + len = 0;
> + do {
> + n = snprintf(line, sizeof(line),
> + "The quick brown fox jumps over the lazy penguin %d\n", i);
> + KUNIT_ASSERT_LT(test, n, sizeof(line));
> + kunit_log_append(suite.log, line);
> + ++i;
> + len += n;
> + } while (len < (sizeof(frag->buf) * 30));
> + num_lines = i;
> +
> + p = get_concatenated_log(test, suite.log, &num_frags);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, p);
> + KUNIT_EXPECT_GT(test, num_frags, 1);
> +
> + kunit_info(test, "num lines:%d num_frags:%d total len:%zu\n",
> + num_lines, num_frags, strlen(p));
> +
> + i = 0;
> + while ((pn = strchr(p, '\n')) != NULL) {
> + *pn = '\0';
> + snprintf(line, sizeof(line),
> + "The quick brown fox jumps over the lazy penguin %d", i);
> + KUNIT_EXPECT_STREQ(test, p, line);
> + p = pn + 1;
> + ++i;
> + }
> + KUNIT_EXPECT_EQ(test, i, num_lines);
> +#else
> + kunit_skip(test, "only useful when debugfs is enabled");
> +#endif
> +}
> +
> +static void kunit_log_extend_test_2(struct kunit *test)
> +{
> +#ifdef CONFIG_KUNIT_DEBUGFS
> + struct kunit_suite suite;
> + struct kunit_log_frag *frag;
> + struct rnd_state rnd;
> + char line[101];
> + char *p, *pn;
> + size_t len;
> + int num_lines, num_frags, n, i;
> +
> + suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
> + INIT_LIST_HEAD(suite.log);
> + frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
> + kunit_init_log_frag(frag);
> + KUNIT_EXPECT_EQ(test, frag->buf[0], '\0');
> + list_add_tail(&frag->list, suite.log);
> +
> + /* Build log line of varying content */
> + line[0] = '\0';
> + i = 0;
> + do {
> + char tmp[9];
> +
> + snprintf(tmp, sizeof(tmp), "%x", i++);
> + len = strlcat(line, tmp, sizeof(line));
> + } while (len < sizeof(line) - 1);
> +
> + /*
> + * Log lines of different lengths until we have created
> + * many fragments.
> + * The "randomness" must be repeatable.
> + */
> + prandom_seed_state(&rnd, 3141592653589793238ULL);
> + i = 0;
> + len = 0;
> + num_lines = 0;
> + do {
> + kunit_log_append(suite.log, "%s\n", &line[i]);
> + len += sizeof(line) - i;
> + num_lines++;
> + i = prandom_u32_state(&rnd) % (sizeof(line) - 1);
> + } while (len < (sizeof(frag->buf) * 30));
> +
> + /* There must be more than one buffer fragment now */
> + KUNIT_EXPECT_FALSE(test, list_is_singular(suite.log));
> +
> + p = get_concatenated_log(test, suite.log, &num_frags);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, p);
> + KUNIT_EXPECT_GT(test, num_frags, 1);
> +
> + kunit_info(test, "num lines:%d num_frags:%d total len:%zu\n",
> + num_lines, num_frags, strlen(p));
> +
> + prandom_seed_state(&rnd, 3141592653589793238ULL);
> + i = 0;
> + n = 0;
> + while ((pn = strchr(p, '\n')) != NULL) {
> + *pn = '\0';
> + KUNIT_EXPECT_STREQ(test, p, &line[i]);
> + p = pn + 1;
> + n++;
> + i = prandom_u32_state(&rnd) % (sizeof(line) - 1);
> + }
> + KUNIT_EXPECT_EQ_MSG(test, n, num_lines, "Not enough lines.");
> +#else
> + kunit_skip(test, "only useful when debugfs is enabled");
> +#endif
> +}
> +
> +static void kunit_log_frag_sized_line_test(struct kunit *test)
> +{
> +#ifdef CONFIG_KUNIT_DEBUGFS
> + struct kunit_suite suite;
> + struct kunit_log_frag *frag, *src;
> +
> + suite.log = kunit_kzalloc(test, sizeof(*suite.log), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, suite.log);
> + INIT_LIST_HEAD(suite.log);
> + frag = kunit_kmalloc(test, sizeof(*frag), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, frag);
> + kunit_init_log_frag(frag);
> + KUNIT_EXPECT_EQ(test, frag->buf[0], '\0');
> + list_add_tail(&frag->list, suite.log);
> +
> + src = kunit_kzalloc(test, sizeof(*src), GFP_KERNEL);
> + KUNIT_ASSERT_NOT_ERR_OR_NULL(test, src);
> + memset(src->buf, 'x', sizeof(src->buf) - 2);
> + KUNIT_ASSERT_EQ(test, strlen(src->buf), sizeof(src->buf) - 2);
> +
> + /* Log a string that exactly fills the fragment */
> + kunit_log_append(suite.log, "%s\n", src->buf);
> + KUNIT_EXPECT_TRUE(test, list_is_singular(suite.log));
> + KUNIT_EXPECT_EQ(test, strlen(frag->buf), sizeof(frag->buf) - 1);
> + strlcat(src->buf, "\n", sizeof(src->buf));
> + KUNIT_EXPECT_STREQ(test, frag->buf, src->buf);
> +#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),
> + KUNIT_CASE(kunit_log_extend_test_1),
> + KUNIT_CASE(kunit_log_extend_test_2),
> + KUNIT_CASE(kunit_log_frag_sized_line_test),
> {}
> };
>
> --
> 2.30.2
>
On 8/8/23 22:16, Rae Moar wrote:
> On Tue, Aug 8, 2023 at 8:35 AM Richard Fitzgerald
> <[email protected]> wrote:
>>
>> Add test cases for the dynamically-extending log buffer.
>>
>> kunit_log_extend_test_1() logs a series of numbered lines then tests
>> that the resulting log contains all the lines.
>>
>> kunit_log_extend_test_2() logs a large number of lines of varying length
>> to create many fragments, then tests that all lines are present.
>>
>> kunit_log_frag_sized_line_test() logs a line that exactly fills a
>> fragment. This should not cause an extension of the log or truncation
>> of the line.
>>
>> kunit_log_newline_test() has a new test to append a line that is exactly
>> the length of the available space in the current fragment and check that
>> the resulting log has a trailing '\n'.
>>
>> Signed-off-by: Richard Fitzgerald <[email protected]>
>
> Hello!
>
> I am happy to see so many tests in this patch series. I've been
> working with these patches and the debugfs logs seem to be working
> well.
>
> However, when I ran the new kunit-log-test tests three of the tests
> failed: kunit_log_extend_test_1(), kunit_log_extend_test_2(), and
> kunit_log_newline_test().
>
> The diagnostic info for kunit_log_extend_test_1() reports:
>
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:705
> [20:55:27] Expected p == line, but
> [20:55:27] p == "xxxxxx…xxxx12345678"
> [20:55:27] line == "The quick brown fox jumps over the lazy penguin 0"
> …
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:705
> [20:55:27] Expected p == line, but
> [20:55:27] p == "The quick brown fox jumps over the lazy penguin 1"
> [20:55:27] line == "The quick brown fox jumps over the lazy penguin 4"
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:705
> [20:55:27] Expected p == line, but
> [20:55:27] p == "The quick brown fox jumps over the lazy penguin 2"
> [20:55:27] line == "The quick brown fox jumps over the lazy penguin 5"
> …
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:709
> [20:55:27] Expected i == num_lines, but
> [20:55:27] i == 64 (0x40)
> [20:55:27] num_lines == 141 (0x8d)
>
> So it looks like the log contains a different number of lines than
> expected which is causing the difference of 3 between expected and
> what was obtained. Potentially the log is not getting cleared/freed
> properly in between test cases?
>
> The diagnostic info for kunit_log_extend_test_2() reports:
>
> [20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:776
> [20:55:27] Expected p == &line[i], but
> [20:55:27] p ==
> "xxxxx...xxxxx123456780123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
> [20:55:27] &line[i] ==
> "0123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
> [20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:781
> [20:55:27] Expected n == num_lines, but
> [20:55:27] n == 147 (0x93)
> [20:55:27] num_lines == 155 (0x9b)
> [20:55:27] Not enough lines.
>
> Similar difference in the number of lines here.
>
> The diagnostic info for kunit_log_newline_test() reports that the test
> fails on this line:
>
> KUNIT_EXPECT_EQ(test, p[strlen(p) - 1], '\n');
>
> Let me know if you are seeing similar errors. I can post the full log
> if that would be helpful.
>
> -Rae
>
Ah, I see a bug in get_concatenated_log().
Does this change fix it for you?
len++; /* for terminating '\0' */
- p = kunit_kmalloc(test, len, GFP_KERNEL);
+ p = kunit_kzalloc(test, len, GFP_KERNEL);
On 9/8/23 13:11, David Gow wrote:
> On Wed, 9 Aug 2023 at 17:39, Richard Fitzgerald
> <[email protected]> wrote:
>>
>> On 8/8/23 22:16, Rae Moar wrote:
>>> On Tue, Aug 8, 2023 at 8:35 AM Richard Fitzgerald
>>> <[email protected]> wrote:
>>>>
>>>> Add test cases for the dynamically-extending log buffer.
>>>>
>>>> kunit_log_extend_test_1() logs a series of numbered lines then tests
>>>> that the resulting log contains all the lines.
>>>>
>>>> kunit_log_extend_test_2() logs a large number of lines of varying length
>>>> to create many fragments, then tests that all lines are present.
>>>>
>>>> kunit_log_frag_sized_line_test() logs a line that exactly fills a
>>>> fragment. This should not cause an extension of the log or truncation
>>>> of the line.
>>>>
>>>> kunit_log_newline_test() has a new test to append a line that is exactly
>>>> the length of the available space in the current fragment and check that
>>>> the resulting log has a trailing '\n'.
>>>>
>>>> Signed-off-by: Richard Fitzgerald <[email protected]>
>>>
>>> Hello!
>>>
>>> I am happy to see so many tests in this patch series. I've been
>>> working with these patches and the debugfs logs seem to be working
>>> well.
>>>
>>> However, when I ran the new kunit-log-test tests three of the tests
>>> failed: kunit_log_extend_test_1(), kunit_log_extend_test_2(), and
>>> kunit_log_newline_test().
>>>
>>> The diagnostic info for kunit_log_extend_test_1() reports:
>>>
>>> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
>>> lib/kunit/kunit-test.c:705
>>> [20:55:27] Expected p == line, but
>>> [20:55:27] p == "xxxxxx…xxxx12345678"
>>> [20:55:27] line == "The quick brown fox jumps over the lazy penguin 0"
>>> …
>>> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
>>> lib/kunit/kunit-test.c:705
>>> [20:55:27] Expected p == line, but
>>> [20:55:27] p == "The quick brown fox jumps over the lazy penguin 1"
>>> [20:55:27] line == "The quick brown fox jumps over the lazy penguin 4"
>>> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
>>> lib/kunit/kunit-test.c:705
>>> [20:55:27] Expected p == line, but
>>> [20:55:27] p == "The quick brown fox jumps over the lazy penguin 2"
>>> [20:55:27] line == "The quick brown fox jumps over the lazy penguin 5"
>>> …
>>> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
>>> lib/kunit/kunit-test.c:709
>>> [20:55:27] Expected i == num_lines, but
>>> [20:55:27] i == 64 (0x40)
>>> [20:55:27] num_lines == 141 (0x8d)
>>>
>>> So it looks like the log contains a different number of lines than
>>> expected which is causing the difference of 3 between expected and
>>> what was obtained. Potentially the log is not getting cleared/freed
>>> properly in between test cases?
>>>
>>> The diagnostic info for kunit_log_extend_test_2() reports:
>>>
>>> [20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
>>> lib/kunit/kunit-test.c:776
>>> [20:55:27] Expected p == &line[i], but
>>> [20:55:27] p ==
>>> "xxxxx...xxxxx123456780123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
>>> [20:55:27] &line[i] ==
>>> "0123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
>>> [20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
>>> lib/kunit/kunit-test.c:781
>>> [20:55:27] Expected n == num_lines, but
>>> [20:55:27] n == 147 (0x93)
>>> [20:55:27] num_lines == 155 (0x9b)
>>> [20:55:27] Not enough lines.
>>>
>>> Similar difference in the number of lines here.
>>>
>>> The diagnostic info for kunit_log_newline_test() reports that the test
>>> fails on this line:
>>>
>>> KUNIT_EXPECT_EQ(test, p[strlen(p) - 1], '\n');
>>>
>>> Let me know if you are seeing similar errors. I can post the full log
>>> if that would be helpful.
>>>
>>> -Rae
>>>
>>
>> Ah, I see a bug in get_concatenated_log().
>> Does this change fix it for you?
>>
>> len++; /* for terminating '\0' */
>> - p = kunit_kmalloc(test, len, GFP_KERNEL);
>> + p = kunit_kzalloc(test, len, GFP_KERNEL);
>
> This fixes what seems to be the same issue for me, under x86_64/qemu.
>
> Thanks,
> -- David
Good. It seems that the various memory security options have the
side-effect of covering up this bug. I don't know which one exactly
(I've just turned them all off). I had been testing with them on.
I'll send a V3.
On Wed, 9 Aug 2023 at 17:39, Richard Fitzgerald
<[email protected]> wrote:
>
> On 8/8/23 22:16, Rae Moar wrote:
> > On Tue, Aug 8, 2023 at 8:35 AM Richard Fitzgerald
> > <[email protected]> wrote:
> >>
> >> Add test cases for the dynamically-extending log buffer.
> >>
> >> kunit_log_extend_test_1() logs a series of numbered lines then tests
> >> that the resulting log contains all the lines.
> >>
> >> kunit_log_extend_test_2() logs a large number of lines of varying length
> >> to create many fragments, then tests that all lines are present.
> >>
> >> kunit_log_frag_sized_line_test() logs a line that exactly fills a
> >> fragment. This should not cause an extension of the log or truncation
> >> of the line.
> >>
> >> kunit_log_newline_test() has a new test to append a line that is exactly
> >> the length of the available space in the current fragment and check that
> >> the resulting log has a trailing '\n'.
> >>
> >> Signed-off-by: Richard Fitzgerald <[email protected]>
> >
> > Hello!
> >
> > I am happy to see so many tests in this patch series. I've been
> > working with these patches and the debugfs logs seem to be working
> > well.
> >
> > However, when I ran the new kunit-log-test tests three of the tests
> > failed: kunit_log_extend_test_1(), kunit_log_extend_test_2(), and
> > kunit_log_newline_test().
> >
> > The diagnostic info for kunit_log_extend_test_1() reports:
> >
> > [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> > lib/kunit/kunit-test.c:705
> > [20:55:27] Expected p == line, but
> > [20:55:27] p == "xxxxxx…xxxx12345678"
> > [20:55:27] line == "The quick brown fox jumps over the lazy penguin 0"
> > …
> > [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> > lib/kunit/kunit-test.c:705
> > [20:55:27] Expected p == line, but
> > [20:55:27] p == "The quick brown fox jumps over the lazy penguin 1"
> > [20:55:27] line == "The quick brown fox jumps over the lazy penguin 4"
> > [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> > lib/kunit/kunit-test.c:705
> > [20:55:27] Expected p == line, but
> > [20:55:27] p == "The quick brown fox jumps over the lazy penguin 2"
> > [20:55:27] line == "The quick brown fox jumps over the lazy penguin 5"
> > …
> > [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> > lib/kunit/kunit-test.c:709
> > [20:55:27] Expected i == num_lines, but
> > [20:55:27] i == 64 (0x40)
> > [20:55:27] num_lines == 141 (0x8d)
> >
> > So it looks like the log contains a different number of lines than
> > expected which is causing the difference of 3 between expected and
> > what was obtained. Potentially the log is not getting cleared/freed
> > properly in between test cases?
> >
> > The diagnostic info for kunit_log_extend_test_2() reports:
> >
> > [20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
> > lib/kunit/kunit-test.c:776
> > [20:55:27] Expected p == &line[i], but
> > [20:55:27] p ==
> > "xxxxx...xxxxx123456780123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
> > [20:55:27] &line[i] ==
> > "0123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
> > [20:55:27] # kunit_log_extend_test_2: EXPECTATION FAILED at
> > lib/kunit/kunit-test.c:781
> > [20:55:27] Expected n == num_lines, but
> > [20:55:27] n == 147 (0x93)
> > [20:55:27] num_lines == 155 (0x9b)
> > [20:55:27] Not enough lines.
> >
> > Similar difference in the number of lines here.
> >
> > The diagnostic info for kunit_log_newline_test() reports that the test
> > fails on this line:
> >
> > KUNIT_EXPECT_EQ(test, p[strlen(p) - 1], '\n');
> >
> > Let me know if you are seeing similar errors. I can post the full log
> > if that would be helpful.
> >
> > -Rae
> >
>
> Ah, I see a bug in get_concatenated_log().
> Does this change fix it for you?
>
> len++; /* for terminating '\0' */
> - p = kunit_kmalloc(test, len, GFP_KERNEL);
> + p = kunit_kzalloc(test, len, GFP_KERNEL);
This fixes what seems to be the same issue for me, under x86_64/qemu.
Thanks,
-- David