xref: /linux/kernel/printk/printk_ringbuffer_kunit_test.c (revision 6093a688a07da07808f0122f9aa2a3eed250d853)
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 size;
56 	char text[] __counted_by(size);
57 };
58 
59 #define MAX_RBDATA_TEXT_SIZE 0x80
60 #define MAX_PRB_RECORD_SIZE (sizeof(struct prbtest_rbdata) + MAX_RBDATA_TEXT_SIZE)
61 
62 struct prbtest_data {
63 	struct kunit *test;
64 	struct printk_ringbuffer *ringbuffer;
65 	/* used by writers to signal reader of new records */
66 	wait_queue_head_t new_record_wait;
67 };
68 
69 struct prbtest_thread_data {
70 	unsigned long num;
71 	struct prbtest_data *test_data;
72 };
73 
74 static void prbtest_fail_record(struct kunit *test, const struct prbtest_rbdata *dat, u64 seq)
75 {
76 	unsigned int len;
77 
78 	len = dat->size - 1;
79 
80 	KUNIT_FAIL(test, "BAD RECORD: seq=%llu size=%u text=%.*s\n",
81 		   seq, dat->size,
82 		   len < MAX_RBDATA_TEXT_SIZE ? len : -1,
83 		   len < MAX_RBDATA_TEXT_SIZE ? dat->text : "<invalid>");
84 }
85 
86 static bool prbtest_check_data(const struct prbtest_rbdata *dat)
87 {
88 	unsigned int len;
89 
90 	/* Sane size? At least one character + trailing '\0' */
91 	if (dat->size < 2 || dat->size > MAX_RBDATA_TEXT_SIZE)
92 		return false;
93 
94 	len = dat->size - 1;
95 	if (dat->text[len] != '\0')
96 		return false;
97 
98 	/* String repeats with the same character? */
99 	while (len--) {
100 		if (dat->text[len] != dat->text[0])
101 			return false;
102 	}
103 
104 	return true;
105 }
106 
107 static int prbtest_writer(void *data)
108 {
109 	struct prbtest_thread_data *tr = data;
110 	char text_id = 'A' + tr->num;
111 	struct prb_reserved_entry e;
112 	struct prbtest_rbdata *dat;
113 	u32 record_size, text_size;
114 	unsigned long count = 0;
115 	struct printk_record r;
116 
117 	kunit_info(tr->test_data->test, "start thread %03lu (writer)\n", tr->num);
118 
119 	for (;;) {
120 		/* ensure at least 1 character + trailing '\0' */
121 		text_size = get_random_u32_inclusive(2, MAX_RBDATA_TEXT_SIZE);
122 		if (WARN_ON_ONCE(text_size < 2))
123 			text_size = 2;
124 		if (WARN_ON_ONCE(text_size > MAX_RBDATA_TEXT_SIZE))
125 			text_size = MAX_RBDATA_TEXT_SIZE;
126 
127 		record_size = sizeof(struct prbtest_rbdata) + text_size;
128 		WARN_ON_ONCE(record_size > MAX_PRB_RECORD_SIZE);
129 
130 		/* specify the text sizes for reservation */
131 		prb_rec_init_wr(&r, record_size);
132 
133 		/*
134 		 * Reservation can fail if:
135 		 *
136 		 *      - No free descriptor is available.
137 		 *      - The buffer is full, and the oldest record is reserved
138 		 *        but not yet committed.
139 		 *
140 		 * It actually happens in this test because all CPUs are trying
141 		 * to write an unbounded number of messages in a tight loop.
142 		 * These failures are intentionally ignored because this test
143 		 * focuses on races, ringbuffer consistency, and pushing system
144 		 * usability limits.
145 		 */
146 		if (prb_reserve(&e, tr->test_data->ringbuffer, &r)) {
147 			r.info->text_len = record_size;
148 
149 			dat = (struct prbtest_rbdata *)r.text_buf;
150 			dat->size = text_size;
151 			memset(dat->text, text_id, text_size - 1);
152 			dat->text[text_size - 1] = '\0';
153 
154 			prb_commit(&e);
155 
156 			wake_up_interruptible(&tr->test_data->new_record_wait);
157 		}
158 
159 		if ((count++ & 0x3fff) == 0)
160 			cond_resched();
161 
162 		if (kthread_should_stop())
163 			break;
164 	}
165 
166 	kunit_info(tr->test_data->test, "end thread %03lu: wrote=%lu\n", tr->num, count);
167 
168 	return 0;
169 }
170 
171 struct prbtest_wakeup_timer {
172 	struct timer_list timer;
173 	struct task_struct *task;
174 };
175 
176 static void prbtest_wakeup_callback(struct timer_list *timer)
177 {
178 	struct prbtest_wakeup_timer *wakeup = timer_container_of(wakeup, timer, timer);
179 
180 	set_tsk_thread_flag(wakeup->task, TIF_NOTIFY_SIGNAL);
181 	wake_up_process(wakeup->task);
182 }
183 
184 static int prbtest_reader(struct prbtest_data *test_data, unsigned long timeout_ms)
185 {
186 	struct prbtest_wakeup_timer wakeup;
187 	char text_buf[MAX_PRB_RECORD_SIZE];
188 	unsigned long count = 0;
189 	struct printk_info info;
190 	struct printk_record r;
191 	u64 seq = 0;
192 
193 	wakeup.task = current;
194 	timer_setup_on_stack(&wakeup.timer, prbtest_wakeup_callback, 0);
195 	mod_timer(&wakeup.timer, jiffies + msecs_to_jiffies(timeout_ms));
196 
197 	prb_rec_init_rd(&r, &info, text_buf, sizeof(text_buf));
198 
199 	kunit_info(test_data->test, "start reader\n");
200 
201 	while (!wait_event_interruptible(test_data->new_record_wait,
202 					 prb_read_valid(test_data->ringbuffer, seq, &r))) {
203 		/* check/track the sequence */
204 		if (info.seq < seq)
205 			KUNIT_FAIL(test_data->test, "BAD SEQ READ: request=%llu read=%llu\n",
206 				   seq, info.seq);
207 
208 		if (!prbtest_check_data((struct prbtest_rbdata *)r.text_buf))
209 			prbtest_fail_record(test_data->test,
210 					    (struct prbtest_rbdata *)r.text_buf, info.seq);
211 
212 		if ((count++ & 0x3fff) == 0)
213 			cond_resched();
214 
215 		seq = info.seq + 1;
216 	}
217 
218 	timer_delete_sync(&wakeup.timer);
219 	timer_destroy_on_stack(&wakeup.timer);
220 
221 	kunit_info(test_data->test, "end reader: read=%lu seq=%llu\n", count, info.seq);
222 
223 	return 0;
224 }
225 
226 KUNIT_DEFINE_ACTION_WRAPPER(prbtest_cpumask_cleanup, free_cpumask_var, struct cpumask *);
227 KUNIT_DEFINE_ACTION_WRAPPER(prbtest_kthread_cleanup, kthread_stop, struct task_struct *);
228 
229 static void prbtest_add_cpumask_cleanup(struct kunit *test, cpumask_var_t mask)
230 {
231 	int err;
232 
233 	err = kunit_add_action_or_reset(test, prbtest_cpumask_cleanup, mask);
234 	KUNIT_ASSERT_EQ(test, err, 0);
235 }
236 
237 static void prbtest_add_kthread_cleanup(struct kunit *test, struct task_struct *kthread)
238 {
239 	int err;
240 
241 	err = kunit_add_action_or_reset(test, prbtest_kthread_cleanup, kthread);
242 	KUNIT_ASSERT_EQ(test, err, 0);
243 }
244 
245 static inline void prbtest_prb_reinit(struct printk_ringbuffer *rb)
246 {
247 	prb_init(rb, rb->text_data_ring.data, rb->text_data_ring.size_bits, rb->desc_ring.descs,
248 		 rb->desc_ring.count_bits, rb->desc_ring.infos);
249 }
250 
251 static void test_readerwriter(struct kunit *test)
252 {
253 	/* Equivalent to CONFIG_LOG_BUF_SHIFT=13 */
254 	DEFINE_PRINTKRB(test_rb, 8, 5);
255 
256 	struct prbtest_thread_data *thread_data;
257 	struct prbtest_data *test_data;
258 	struct task_struct *thread;
259 	cpumask_var_t test_cpus;
260 	int cpu, reader_cpu;
261 
262 	KUNIT_ASSERT_TRUE(test, alloc_cpumask_var(&test_cpus, GFP_KERNEL));
263 	prbtest_add_cpumask_cleanup(test, test_cpus);
264 
265 	cpus_read_lock();
266 	/*
267 	 * Failure of KUNIT_ASSERT() kills the current task
268 	 * so it can not be called while the CPU hotplug lock is held.
269 	 * Instead use a snapshot of the online CPUs.
270 	 * If they change during test execution it is unfortunate but not a grave error.
271 	 */
272 	cpumask_copy(test_cpus, cpu_online_mask);
273 	cpus_read_unlock();
274 
275 	/* One CPU is for the reader, all others are writers */
276 	reader_cpu = cpumask_first(test_cpus);
277 	if (cpumask_weight(test_cpus) == 1)
278 		kunit_warn(test, "more than one CPU is recommended");
279 	else
280 		cpumask_clear_cpu(reader_cpu, test_cpus);
281 
282 	/* KUnit test can get restarted more times. */
283 	prbtest_prb_reinit(&test_rb);
284 
285 	test_data = kunit_kmalloc(test, sizeof(*test_data), GFP_KERNEL);
286 	KUNIT_ASSERT_NOT_NULL(test, test_data);
287 	test_data->test = test;
288 	test_data->ringbuffer = &test_rb;
289 	init_waitqueue_head(&test_data->new_record_wait);
290 
291 	kunit_info(test, "running for %lu ms\n", runtime_ms);
292 
293 	for_each_cpu(cpu, test_cpus) {
294 		thread_data = kunit_kmalloc(test, sizeof(*thread_data), GFP_KERNEL);
295 		KUNIT_ASSERT_NOT_NULL(test, thread_data);
296 		thread_data->test_data = test_data;
297 		thread_data->num = cpu;
298 
299 		thread = kthread_run_on_cpu(prbtest_writer, thread_data, cpu,
300 					    "prbtest writer %u");
301 		KUNIT_ASSERT_NOT_ERR_OR_NULL(test, thread);
302 		prbtest_add_kthread_cleanup(test, thread);
303 	}
304 
305 	kunit_info(test, "starting test\n");
306 
307 	set_cpus_allowed_ptr(current, cpumask_of(reader_cpu));
308 	prbtest_reader(test_data, runtime_ms);
309 
310 	kunit_info(test, "completed test\n");
311 }
312 
313 static struct kunit_case prb_test_cases[] = {
314 	KUNIT_CASE_SLOW(test_readerwriter),
315 	{}
316 };
317 
318 static struct kunit_suite prb_test_suite = {
319 	.name       = "printk-ringbuffer",
320 	.test_cases = prb_test_cases,
321 };
322 kunit_test_suite(prb_test_suite);
323 
324 MODULE_IMPORT_NS("EXPORTED_FOR_KUNIT_TESTING");
325 MODULE_AUTHOR("John Ogness <john.ogness@linutronix.de>");
326 MODULE_DESCRIPTION("printk_ringbuffer KUnit test");
327 MODULE_LICENSE("GPL");
328