xref: /linux/kernel/printk/printk_ringbuffer_kunit_test.c (revision 5ea2bcdfbf46fc3aac239ea371a9561053cc977a)
1 // SPDX-License-Identifier: GPL-2.0
2 
3 #include <linux/cpuhplock.h>
4 #include <linux/cpumask.h>
5 #include <linux/init.h>
6 #include <linux/kthread.h>
7 #include <linux/module.h>
8 #include <linux/moduleparam.h>
9 #include <linux/random.h>
10 #include <linux/slab.h>
11 #include <linux/timer.h>
12 #include <linux/wait.h>
13 
14 #include <kunit/resource.h>
15 #include <kunit/test.h>
16 
17 #include "printk_ringbuffer.h"
18 
19 /*
20  * This KUnit tests the data integrity of the lockless printk_ringbuffer.
21  * From multiple CPUs it writes messages of varying length and content while
22  * a reader validates the correctness of the messages.
23  *
24  * IMPORTANT: The more CPUs you can use for this KUnit, the better!
25  *
26  * The test works by starting "num_online_cpus() - 1" writer threads, each
27  * pinned to their own CPU. Each writer thread loops, writing data of varying
28  * length into a printk_ringbuffer as fast as possible. The data content is
29  * an embedded data struct followed by string content repeating the byte:
30  *
31  *      'A' + CPUID
32  *
33  * The reader is running on the remaining online CPU, or if there is only one
34  * CPU on the same as the writer.
35  * It ensures that the embedded struct content is consistent with the string
36  * and that the string * is terminated and is composed of the same repeating
37  * byte as its first byte.
38  *
39  * Because the threads are running in such tight loops, they will call
40  * cond_resched() from time to time so the system stays functional.
41  *
42  * If the reader encounters an error, the test is aborted and some
43  * information about the error is reported.
44  * The runtime of the test can be configured with the runtime_ms module parameter.
45  *
46  * Note that the test is performed on a separate printk_ringbuffer instance
47  * and not the instance used by printk().
48  */
49 
50 static unsigned long runtime_ms = 10 * MSEC_PER_SEC;
51 module_param(runtime_ms, ulong, 0400);
52 
53 /* test data structure */
54 struct prbtest_rbdata {
55 	unsigned int len;
56 	char text[] __counted_by(len);
57 };
58 
59 #define MAX_RBDATA_TEXT_SIZE 0x7f
60 /* +1 for terminator. */
61 #define MAX_PRB_RECORD_SIZE (sizeof(struct prbtest_rbdata) + MAX_RBDATA_TEXT_SIZE + 1)
62 
63 struct prbtest_data {
64 	struct kunit *test;
65 	struct printk_ringbuffer *ringbuffer;
66 	/* used by writers to signal reader of new records */
67 	wait_queue_head_t new_record_wait;
68 };
69 
70 struct prbtest_thread_data {
71 	unsigned long num;
72 	struct prbtest_data *test_data;
73 };
74 
75 static void prbtest_fail_record(struct kunit *test, const struct prbtest_rbdata *dat, u64 seq)
76 {
77 	KUNIT_FAIL(test, "BAD RECORD: seq=%llu len=%u text=%.*s\n",
78 		   seq, dat->len,
79 		   dat->len <= MAX_RBDATA_TEXT_SIZE ? dat->len : -1,
80 		   dat->len <= MAX_RBDATA_TEXT_SIZE ? dat->text : "<invalid>");
81 }
82 
83 static bool prbtest_check_data(const struct prbtest_rbdata *dat)
84 {
85 	unsigned int len;
86 
87 	/* Sane length? */
88 	if (dat->len < 1 || dat->len > MAX_RBDATA_TEXT_SIZE)
89 		return false;
90 
91 	if (dat->text[dat->len] != '\0')
92 		return false;
93 
94 	/* String repeats with the same character? */
95 	len = dat->len;
96 	while (len--) {
97 		if (dat->text[len] != dat->text[0])
98 			return false;
99 	}
100 
101 	return true;
102 }
103 
104 static int prbtest_writer(void *data)
105 {
106 	struct prbtest_thread_data *tr = data;
107 	char text_id = 'A' + tr->num;
108 	struct prb_reserved_entry e;
109 	struct prbtest_rbdata *dat;
110 	u32 record_size, text_size;
111 	unsigned long count = 0;
112 	struct printk_record r;
113 
114 	kunit_info(tr->test_data->test, "start thread %03lu (writer)\n", tr->num);
115 
116 	for (;;) {
117 		/* ensure at least 1 character */
118 		text_size = get_random_u32_inclusive(1, MAX_RBDATA_TEXT_SIZE);
119 		/* +1 for terminator. */
120 		record_size = sizeof(struct prbtest_rbdata) + text_size + 1;
121 		WARN_ON_ONCE(record_size > MAX_PRB_RECORD_SIZE);
122 
123 		/* specify the text sizes for reservation */
124 		prb_rec_init_wr(&r, record_size);
125 
126 		if (prb_reserve(&e, tr->test_data->ringbuffer, &r)) {
127 			r.info->text_len = record_size;
128 
129 			dat = (struct prbtest_rbdata *)r.text_buf;
130 			dat->len = text_size;
131 			memset(dat->text, text_id, text_size);
132 			dat->text[text_size] = 0;
133 
134 			prb_commit(&e);
135 
136 			wake_up_interruptible(&tr->test_data->new_record_wait);
137 		}
138 
139 		if ((count++ & 0x3fff) == 0)
140 			cond_resched();
141 
142 		if (kthread_should_stop())
143 			break;
144 	}
145 
146 	kunit_info(tr->test_data->test, "end thread %03lu: wrote=%lu\n", tr->num, count);
147 
148 	return 0;
149 }
150 
151 struct prbtest_wakeup_timer {
152 	struct timer_list timer;
153 	struct task_struct *task;
154 };
155 
156 static void prbtest_wakeup_callback(struct timer_list *timer)
157 {
158 	struct prbtest_wakeup_timer *wakeup = timer_container_of(wakeup, timer, timer);
159 
160 	set_tsk_thread_flag(wakeup->task, TIF_NOTIFY_SIGNAL);
161 	wake_up_process(wakeup->task);
162 }
163 
164 static int prbtest_reader(struct prbtest_data *test_data, unsigned long timeout_ms)
165 {
166 	struct prbtest_wakeup_timer wakeup;
167 	char text_buf[MAX_PRB_RECORD_SIZE];
168 	unsigned long count = 0;
169 	struct printk_info info;
170 	struct printk_record r;
171 	u64 seq = 0;
172 
173 	wakeup.task = current;
174 	timer_setup_on_stack(&wakeup.timer, prbtest_wakeup_callback, 0);
175 	mod_timer(&wakeup.timer, jiffies + msecs_to_jiffies(timeout_ms));
176 
177 	prb_rec_init_rd(&r, &info, text_buf, sizeof(text_buf));
178 
179 	kunit_info(test_data->test, "start reader\n");
180 
181 	while (!wait_event_interruptible(test_data->new_record_wait,
182 					 prb_read_valid(test_data->ringbuffer, seq, &r))) {
183 		/* check/track the sequence */
184 		if (info.seq < seq)
185 			KUNIT_FAIL(test_data->test, "BAD SEQ READ: request=%llu read=%llu\n",
186 				   seq, info.seq);
187 
188 		if (!prbtest_check_data((struct prbtest_rbdata *)r.text_buf))
189 			prbtest_fail_record(test_data->test,
190 					    (struct prbtest_rbdata *)r.text_buf, info.seq);
191 
192 		if ((count++ & 0x3fff) == 0)
193 			cond_resched();
194 
195 		seq = info.seq + 1;
196 	}
197 
198 	timer_delete_sync(&wakeup.timer);
199 	timer_destroy_on_stack(&wakeup.timer);
200 
201 	kunit_info(test_data->test, "end reader: read=%lu seq=%llu\n", count, info.seq);
202 
203 	return 0;
204 }
205 
206 KUNIT_DEFINE_ACTION_WRAPPER(prbtest_kthread_cleanup, kthread_stop, struct task_struct *);
207 
208 static void prbtest_add_kthread_cleanup(struct kunit *test, struct task_struct *kthread)
209 {
210 	int err;
211 
212 	err = kunit_add_action_or_reset(test, prbtest_kthread_cleanup, kthread);
213 	KUNIT_ASSERT_EQ(test, err, 0);
214 }
215 
216 static inline void prbtest_prb_reinit(struct printk_ringbuffer *rb)
217 {
218 	prb_init(rb, rb->text_data_ring.data, rb->text_data_ring.size_bits, rb->desc_ring.descs,
219 		 rb->desc_ring.count_bits, rb->desc_ring.infos);
220 }
221 
222 static void test_readerwriter(struct kunit *test)
223 {
224 	/* Equivalent to CONFIG_LOG_BUF_SHIFT=13 */
225 	DEFINE_PRINTKRB(test_rb, 8, 5);
226 
227 	struct prbtest_thread_data *thread_data;
228 	struct prbtest_data *test_data;
229 	struct task_struct *thread;
230 	cpumask_t test_cpus;
231 	int cpu, reader_cpu;
232 
233 	cpus_read_lock();
234 	/*
235 	 * Failure of KUNIT_ASSERT() kills the current task
236 	 * so it can not be called while the CPU hotplug lock is held.
237 	 * Instead use a snapshot of the online CPUs.
238 	 * If they change during test execution it is unfortunate but not a grave error.
239 	 */
240 	cpumask_copy(&test_cpus, cpu_online_mask);
241 	cpus_read_unlock();
242 
243 	/* One CPU is for the reader, all others are writers */
244 	reader_cpu = cpumask_first(&test_cpus);
245 	if (cpumask_weight(&test_cpus) == 1)
246 		kunit_warn(test, "more than one CPU is recommended");
247 	else
248 		cpumask_clear_cpu(reader_cpu, &test_cpus);
249 
250 	/* KUnit test can get restarted more times. */
251 	prbtest_prb_reinit(&test_rb);
252 
253 	test_data = kunit_kmalloc(test, sizeof(*test_data), GFP_KERNEL);
254 	KUNIT_ASSERT_NOT_NULL(test, test_data);
255 	test_data->test = test;
256 	test_data->ringbuffer = &test_rb;
257 	init_waitqueue_head(&test_data->new_record_wait);
258 
259 	kunit_info(test, "running for %lu ms\n", runtime_ms);
260 
261 	for_each_cpu(cpu, &test_cpus) {
262 		thread_data = kunit_kmalloc(test, sizeof(*thread_data), GFP_KERNEL);
263 		KUNIT_ASSERT_NOT_NULL(test, thread_data);
264 		thread_data->test_data = test_data;
265 		thread_data->num = cpu;
266 
267 		thread = kthread_run_on_cpu(prbtest_writer, thread_data, cpu,
268 					    "prbtest writer %u");
269 		KUNIT_ASSERT_NOT_ERR_OR_NULL(test, thread);
270 		prbtest_add_kthread_cleanup(test, thread);
271 	}
272 
273 	kunit_info(test, "starting test\n");
274 
275 	set_cpus_allowed_ptr(current, cpumask_of(reader_cpu));
276 	prbtest_reader(test_data, runtime_ms);
277 
278 	kunit_info(test, "completed test\n");
279 }
280 
281 static struct kunit_case prb_test_cases[] = {
282 	KUNIT_CASE_SLOW(test_readerwriter),
283 	{}
284 };
285 
286 static struct kunit_suite prb_test_suite = {
287 	.name       = "printk-ringbuffer",
288 	.test_cases = prb_test_cases,
289 };
290 kunit_test_suite(prb_test_suite);
291 
292 MODULE_IMPORT_NS("EXPORTED_FOR_KUNIT_TESTING");
293 MODULE_AUTHOR("John Ogness <john.ogness@linutronix.de>");
294 MODULE_DESCRIPTION("printk_ringbuffer KUnit test");
295 MODULE_LICENSE("GPL");
296