On Thu 2024-11-21 15:56:34, John Ogness wrote:
> From: Thomas Weißschuh <thomas.weisssc...@linutronix.de>
>
> The KUnit test validates the correct operation of the ringbuffer.
> A separate dedicated ringbuffer is used so that the global printk
> ringbuffer is not touched.
Thanks a lot for upstreaming this test!
> --- a/init/Kconfig
> +++ b/init/Kconfig
> @@ -1576,6 +1576,18 @@ config PRINTK
> very difficult to diagnose system problems, saying N here is
> strongly discouraged.
>
> +config PRINTK_RINGBUFFER_TEST
I would call it PRINTK_RINGBUFFER_KUNIT_TEST to make it clear
that it is a KUNIT test. Also it helps to find KUNIT tests
in .config.
Anyway, Documentation/dev-tools/kunit/style.rst suggests the
FOO_KUNIT_TEST name.
> + tristate "Test for the printk ringbuffer" if !KUNIT_ALL_TESTS
> + depends on PRINTK && KUNIT
> + default KUNIT_ALL_TESTS
> + help
> + This builds the printk ringbuffer KUnit test suite.
> +
> + For more information on KUnit and unit tests in general, please refer
> + to the KUnit documentation.
> +
> + If unsure, say N.
> +
> config BUG
> bool "BUG() support" if EXPERT
> default y
> --- /dev/null
> +++ b/kernel/printk/printk_ringbuffer_test.c
> @@ -0,0 +1,350 @@
[...]
> +/* test data structure */
> +struct rbdata {
> + unsigned int len;
> + char text[] __counted_by(len);
> +};
> +
> +#define MAX_RBDATA_LEN (0x7f + 1)
> +#define MAX_RECORD_SIZE (sizeof(struct rbdata) + MAX_RBDATA_LEN + 1)
It is far from clear what the two +1 are for here.
Also 0x7f is hardcoded below once again.
I would personally do:
/* A mask used to generate random text len. */
#define RBDATA_TEXT_LEN_RND_MASK 0x7f
/* +2 to ensure at least 1 character + terminator. */
#define MAX_RBDATA_TEXT_SIZE (RBDATA_TEXT_LEN_RND_MASK + 2)
#define MAX_PRB_RECORD_SIZE (sizeof(struct rbdata) + MAX_RBDATA_TEXT_SIZE)
Note that I used the suffix _SIZE because I counted the terminator
in both definitions, see below.
> +static struct test_running {
> + int runstate;
> + unsigned long num;
> + struct kunit *test;
> +} *test_running;
> +static int halt_test;
> +
> +static void fail_record(struct kunit *test, struct rbdata *dat, u64 seq)
> +{
> + char buf[MAX_RBDATA_LEN + 1];
char buf[MAX_RBDATA_TEXT_SIZE];
> + snprintf(buf, sizeof(buf), "%s", dat->text);
> + buf[sizeof(buf) - 1] = 0;
> +
> + KUNIT_FAIL(test, "BAD RECORD: seq=%llu len=%u text=%s\n",
> + seq, dat->len, dat->len < sizeof(buf) ? buf : "<invalid>");
> +}
> +
> +static bool check_data(struct rbdata *dat)
> +{
> + unsigned int len;
> +
> + len = strnlen(dat->text, MAX_RBDATA_LEN + 1);
len = strnlen(dat->text, MAX_RBDATA_TEXT_SIZE);
> + /* Sane length? */
> + if (len != dat->len || !len || len > MAX_RBDATA_LEN)
if (len != dat->len || !len || len >= MAX_RBDATA_TEXT_SIZE)
Note that I have used >= instead of > because it is the _SIZE.
> + return false;
> +
> + /* String repeats with the same character? */
> + while (len) {
> + len--;
> + if (dat->text[len] != dat->text[0])
> + return false;
> + }
> +
> + return true;
> +}
> +
> +/* Equivalent to CONFIG_LOG_BUF_SHIFT=13 */
> +DEFINE_PRINTKRB(test_rb, 8, 5);
> +
> +static int prbtest_writer(void *data)
> +{
> + struct test_running *tr = data;
> + char text_id = 'A' + tr->num;
> + struct prb_reserved_entry e;
> + unsigned long count = 0;
> + struct printk_record r;
> + u64 min_ns = (u64)-1;
> + struct rbdata *dat;
> + u64 total_ns = 0;
> + u64 max_ns = 0;
> + u64 post_ns;
> + u64 pre_ns;
> + int len;
> +
> + set_cpus_allowed_ptr(current, cpumask_of(tr->num));
> +
> + kunit_info(tr->test, "start thread %03lu (writer)\n", tr->num);
> +
> + tr->runstate = 1;
> +
> + for (;;) {
> + /* +2 to ensure at least 1 character + terminator. */
> + len = sizeof(struct rbdata) + (get_random_u32() & 0x7f) + 2;
len = sizeof(struct rbdata) +
(get_random_u32() & RBDATA_TEXT_LEN_RND_MASK) + 2;
I would add
WARN_ON_ONCE(len <= MAX_PRB_RECORD_SIZE);
> + /* specify the text sizes for reservation */
> + prb_rec_init_wr(&r, len);
> +
> + pre_ns = local_clock();
> +
> + if (prb_reserve(&e, &test_rb, &r)) {
> + r.info->text_len = len;
> +
> + len -= sizeof(struct rbdata) + 1;
I would add brackets to make it more clear that we actually substract
the "1":
len -= (sizeof(struct rbdata) + 1);
or even better might be to create two variables:
/* +1 to ensure at least 1 character*/
len = (get_random_u32() & 0x7f) + 1;
size = sizeof(struct rbdata) + len + 1;
> +
> + dat = (struct rbdata *)&r.text_buf[0];
> + dat->len = len;
> + memset(&dat->text[0], text_id, len);
> + dat->text[len] = 0;
> +
> + prb_commit(&e);
> +
> + post_ns = local_clock();
I think that the counting of the time will be misleading in CONFIG_PREEMPT=y.
We should disable preemption or even interrupts to get right numbers.
> + wake_up_interruptible(&test_wait);
> +
> + post_ns -= pre_ns;
> + if (post_ns < min_ns)
> + min_ns = post_ns;
> + if (post_ns > max_ns)
> + max_ns = post_ns;
> + total_ns += post_ns;
> + }
> +
> + if ((count++ & 0x3fff) == 0)
> + schedule();
This won't work as expected with CONFIG_PREEMPT=y.
IMHO, we should use simply use cond_resched() here.
a
> + if (READ_ONCE(halt_test) == 1)
> + break;
> + }
> +
> + kunit_info(tr->test, "end thread %03lu: wrote=%lu min_ns=%llu
> avg_ns=%llu max_ns=%llu\n",
> + tr->num, count, min_ns, total_ns / (u64)count, max_ns);
> +
> + tr->runstate = 2;
> +
> + return 0;
> +}
> +
> +static int prbtest_reader(void *data)
> +{
> + struct test_running *tr = data;
> + char text_buf[MAX_RECORD_SIZE];
> + unsigned long total_lost = 0;
> + unsigned long max_lost = 0;
> + unsigned long count = 0;
> + struct printk_info info;
> + struct printk_record r;
> + int did_sched = 1;
> + u64 seq = 0;
> +
> + set_cpus_allowed_ptr(current, cpumask_of(tr->num));
> +
> + prb_rec_init_rd(&r, &info, &text_buf[0], sizeof(text_buf));
> +
> + kunit_info(tr->test, "start thread %03lu (reader)\n", tr->num);
> +
> + tr->runstate = 1;
> +
> + while (!wait_event_interruptible(test_wait,
> + kthread_should_stop() ||
> + prb_read_valid(&test_rb, seq, &r))) {
> + bool error = false;
> +
> + if (kthread_should_stop())
> + break;
> + /* check/track the sequence */
> + if (info.seq < seq) {
> + KUNIT_FAIL(tr->test, "BAD SEQ READ: request=%llu
> read=%llu\n",
> + seq, info.seq);
> + error = true;
> + } else if (info.seq != seq && !did_sched) {
> + total_lost += info.seq - seq;
> + if (max_lost < info.seq - seq)
> + max_lost = info.seq - seq;
> + }
> +
> + if (!check_data((struct rbdata *)&r.text_buf[0])) {
> + fail_record(tr->test, (struct rbdata *)&r.text_buf[0],
> info.seq);
> + error = true;
> + }
> +
> + if (error)
> + WRITE_ONCE(halt_test, 1);
> +
> + did_sched = 0;
> + if ((count++ & 0x3fff) == 0) {
> + did_sched = 1;
> + schedule();
> + }
This won't work with CONFIG_PREEMPT=Y. I would use cond_resched()
and detect scheduling by checking the switch count. I think that
it should be:
switch_count = READ_ONCE(current->nvcsw + current->nivcsw);
It is inspired by check_hung_task().
> + if (READ_ONCE(halt_test) == 1)
> + break;
> +
> + seq = info.seq + 1;
> + }
> +
> + kunit_info(tr->test,
> + "end thread %03lu: read=%lu seq=%llu total_lost=%lu
> max_lost=%lu\n",
> + tr->num, count, info.seq, total_lost, max_lost);
> +
> + while (!kthread_should_stop())
> + msleep(1000);
> + tr->runstate = 2;
> +
> + return 0;
> +}
This is what I have found on top of the review by David Gow.
Best Regards,
Petr
