Branch data Line data Source code
1 : : // SPDX-License-Identifier: GPL-2.0-or-later
2 : : /*
3 : : * printk_safe.c - Safe printk for printk-deadlock-prone contexts
4 : : */
5 : :
6 : : #include <linux/preempt.h>
7 : : #include <linux/spinlock.h>
8 : : #include <linux/debug_locks.h>
9 : : #include <linux/smp.h>
10 : : #include <linux/cpumask.h>
11 : : #include <linux/irq_work.h>
12 : : #include <linux/printk.h>
13 : :
14 : : #include "internal.h"
15 : :
16 : : /*
17 : : * printk() could not take logbuf_lock in NMI context. Instead,
18 : : * it uses an alternative implementation that temporary stores
19 : : * the strings into a per-CPU buffer. The content of the buffer
20 : : * is later flushed into the main ring buffer via IRQ work.
21 : : *
22 : : * The alternative implementation is chosen transparently
23 : : * by examinig current printk() context mask stored in @printk_context
24 : : * per-CPU variable.
25 : : *
26 : : * The implementation allows to flush the strings also from another CPU.
27 : : * There are situations when we want to make sure that all buffers
28 : : * were handled or when IRQs are blocked.
29 : : */
30 : :
31 : : #define SAFE_LOG_BUF_LEN ((1 << CONFIG_PRINTK_SAFE_LOG_BUF_SHIFT) - \
32 : : sizeof(atomic_t) - \
33 : : sizeof(atomic_t) - \
34 : : sizeof(struct irq_work))
35 : :
36 : : struct printk_safe_seq_buf {
37 : : atomic_t len; /* length of written data */
38 : : atomic_t message_lost;
39 : : struct irq_work work; /* IRQ work that flushes the buffer */
40 : : unsigned char buffer[SAFE_LOG_BUF_LEN];
41 : : };
42 : :
43 : : static DEFINE_PER_CPU(struct printk_safe_seq_buf, safe_print_seq);
44 : : static DEFINE_PER_CPU(int, printk_context);
45 : :
46 : : #ifdef CONFIG_PRINTK_NMI
47 : : static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq);
48 : : #endif
49 : :
50 : : /* Get flushed in a more safe context. */
51 : 0 : static void queue_flush_work(struct printk_safe_seq_buf *s)
52 : : {
53 [ # # ]: 0 : if (printk_percpu_data_ready())
54 : 0 : irq_work_queue(&s->work);
55 : 0 : }
56 : :
57 : : /*
58 : : * Add a message to per-CPU context-dependent buffer. NMI and printk-safe
59 : : * have dedicated buffers, because otherwise printk-safe preempted by
60 : : * NMI-printk would have overwritten the NMI messages.
61 : : *
62 : : * The messages are flushed from irq work (or from panic()), possibly,
63 : : * from other CPU, concurrently with printk_safe_log_store(). Should this
64 : : * happen, printk_safe_log_store() will notice the buffer->len mismatch
65 : : * and repeat the write.
66 : : */
67 : 0 : static __printf(2, 0) int printk_safe_log_store(struct printk_safe_seq_buf *s,
68 : : const char *fmt, va_list args)
69 : : {
70 : : int add;
71 : : size_t len;
72 : : va_list ap;
73 : :
74 : : again:
75 : 0 : len = atomic_read(&s->len);
76 : :
77 : : /* The trailing '\0' is not counted into len. */
78 [ # # ]: 0 : if (len >= sizeof(s->buffer) - 1) {
79 : 0 : atomic_inc(&s->message_lost);
80 : 0 : queue_flush_work(s);
81 : 0 : return 0;
82 : : }
83 : :
84 : : /*
85 : : * Make sure that all old data have been read before the buffer
86 : : * was reset. This is not needed when we just append data.
87 : : */
88 [ # # ]: 0 : if (!len)
89 : 0 : smp_rmb();
90 : :
91 : 0 : va_copy(ap, args);
92 : 0 : add = vscnprintf(s->buffer + len, sizeof(s->buffer) - len, fmt, ap);
93 : 0 : va_end(ap);
94 [ # # ]: 0 : if (!add)
95 : : return 0;
96 : :
97 : : /*
98 : : * Do it once again if the buffer has been flushed in the meantime.
99 : : * Note that atomic_cmpxchg() is an implicit memory barrier that
100 : : * makes sure that the data were written before updating s->len.
101 : : */
102 [ # # ]: 0 : if (atomic_cmpxchg(&s->len, len, len + add) != len)
103 : : goto again;
104 : :
105 : 0 : queue_flush_work(s);
106 : 0 : return add;
107 : : }
108 : :
109 : : static inline void printk_safe_flush_line(const char *text, int len)
110 : : {
111 : : /*
112 : : * Avoid any console drivers calls from here, because we may be
113 : : * in NMI or printk_safe context (when in panic). The messages
114 : : * must go only into the ring buffer at this stage. Consoles will
115 : : * get explicitly called later when a crashdump is not generated.
116 : : */
117 : 0 : printk_deferred("%.*s", len, text);
118 : : }
119 : :
120 : : /* printk part of the temporary buffer line by line */
121 : 0 : static int printk_safe_flush_buffer(const char *start, size_t len)
122 : : {
123 : : const char *c, *end;
124 : : bool header;
125 : :
126 : : c = start;
127 : 0 : end = start + len;
128 : : header = true;
129 : :
130 : : /* Print line by line. */
131 [ # # ]: 0 : while (c < end) {
132 [ # # ]: 0 : if (*c == '\n') {
133 : 0 : printk_safe_flush_line(start, c - start + 1);
134 : 0 : start = ++c;
135 : : header = true;
136 : 0 : continue;
137 : : }
138 : :
139 : : /* Handle continuous lines or missing new line. */
140 [ # # # # ]: 0 : if ((c + 1 < end) && printk_get_level(c)) {
141 [ # # ]: 0 : if (header) {
142 : : c = printk_skip_level(c);
143 : 0 : continue;
144 : : }
145 : :
146 : 0 : printk_safe_flush_line(start, c - start);
147 : : start = c++;
148 : : header = true;
149 : 0 : continue;
150 : : }
151 : :
152 : : header = false;
153 : : c++;
154 : : }
155 : :
156 : : /* Check if there was a partial line. Ignore pure header. */
157 [ # # ]: 0 : if (start < end && !header) {
158 : : static const char newline[] = KERN_CONT "\n";
159 : :
160 : 0 : printk_safe_flush_line(start, end - start);
161 : : printk_safe_flush_line(newline, strlen(newline));
162 : : }
163 : :
164 : 0 : return len;
165 : : }
166 : :
167 : 1656 : static void report_message_lost(struct printk_safe_seq_buf *s)
168 : : {
169 : 1656 : int lost = atomic_xchg(&s->message_lost, 0);
170 : :
171 [ - + ]: 1656 : if (lost)
172 : 0 : printk_deferred("Lost %d message(s)!\n", lost);
173 : 1656 : }
174 : :
175 : : /*
176 : : * Flush data from the associated per-CPU buffer. The function
177 : : * can be called either via IRQ work or independently.
178 : : */
179 : 1656 : static void __printk_safe_flush(struct irq_work *work)
180 : : {
181 : : static raw_spinlock_t read_lock =
182 : : __RAW_SPIN_LOCK_INITIALIZER(read_lock);
183 : : struct printk_safe_seq_buf *s =
184 : 1656 : container_of(work, struct printk_safe_seq_buf, work);
185 : : unsigned long flags;
186 : : size_t len;
187 : : int i;
188 : :
189 : : /*
190 : : * The lock has two functions. First, one reader has to flush all
191 : : * available message to make the lockless synchronization with
192 : : * writers easier. Second, we do not want to mix messages from
193 : : * different CPUs. This is especially important when printing
194 : : * a backtrace.
195 : : */
196 : 1656 : raw_spin_lock_irqsave(&read_lock, flags);
197 : :
198 : : i = 0;
199 : : more:
200 : : len = atomic_read(&s->len);
201 : :
202 : : /*
203 : : * This is just a paranoid check that nobody has manipulated
204 : : * the buffer an unexpected way. If we printed something then
205 : : * @len must only increase. Also it should never overflow the
206 : : * buffer size.
207 : : */
208 [ + - - + ]: 1656 : if ((i && i >= len) || len > sizeof(s->buffer)) {
209 : : const char *msg = "printk_safe_flush: internal error\n";
210 : :
211 : : printk_safe_flush_line(msg, strlen(msg));
212 : : len = 0;
213 : : }
214 : :
215 [ - + ]: 1656 : if (!len)
216 : : goto out; /* Someone else has already flushed the buffer. */
217 : :
218 : : /* Make sure that data has been written up to the @len */
219 : 0 : smp_rmb();
220 : 0 : i += printk_safe_flush_buffer(s->buffer + i, len - i);
221 : :
222 : : /*
223 : : * Check that nothing has got added in the meantime and truncate
224 : : * the buffer. Note that atomic_cmpxchg() is an implicit memory
225 : : * barrier that makes sure that the data were copied before
226 : : * updating s->len.
227 : : */
228 [ # # ]: 0 : if (atomic_cmpxchg(&s->len, len, 0) != len)
229 : : goto more;
230 : :
231 : : out:
232 : 1656 : report_message_lost(s);
233 : 1656 : raw_spin_unlock_irqrestore(&read_lock, flags);
234 : 1656 : }
235 : :
236 : : /**
237 : : * printk_safe_flush - flush all per-cpu nmi buffers.
238 : : *
239 : : * The buffers are flushed automatically via IRQ work. This function
240 : : * is useful only when someone wants to be sure that all buffers have
241 : : * been flushed at some point.
242 : : */
243 : 207 : void printk_safe_flush(void)
244 : : {
245 : : int cpu;
246 : :
247 [ + + ]: 1242 : for_each_possible_cpu(cpu) {
248 : : #ifdef CONFIG_PRINTK_NMI
249 : 828 : __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work);
250 : : #endif
251 : 828 : __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work);
252 : : }
253 : 207 : }
254 : :
255 : : /**
256 : : * printk_safe_flush_on_panic - flush all per-cpu nmi buffers when the system
257 : : * goes down.
258 : : *
259 : : * Similar to printk_safe_flush() but it can be called even in NMI context when
260 : : * the system goes down. It does the best effort to get NMI messages into
261 : : * the main ring buffer.
262 : : *
263 : : * Note that it could try harder when there is only one CPU online.
264 : : */
265 : 0 : void printk_safe_flush_on_panic(void)
266 : : {
267 : : /*
268 : : * Make sure that we could access the main ring buffer.
269 : : * Do not risk a double release when more CPUs are up.
270 : : */
271 [ # # ]: 0 : if (raw_spin_is_locked(&logbuf_lock)) {
272 [ # # ]: 0 : if (num_online_cpus() > 1)
273 : 0 : return;
274 : :
275 : 0 : debug_locks_off();
276 : 0 : raw_spin_lock_init(&logbuf_lock);
277 : : }
278 : :
279 : 0 : printk_safe_flush();
280 : : }
281 : :
282 : : #ifdef CONFIG_PRINTK_NMI
283 : : /*
284 : : * Safe printk() for NMI context. It uses a per-CPU buffer to
285 : : * store the message. NMIs are not nested, so there is always only
286 : : * one writer running. But the buffer might get flushed from another
287 : : * CPU, so we need to be careful.
288 : : */
289 : : static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args)
290 : : {
291 : 0 : struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
292 : :
293 : 0 : return printk_safe_log_store(s, fmt, args);
294 : : }
295 : :
296 : 0 : void notrace printk_nmi_enter(void)
297 : : {
298 : 0 : this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK);
299 : 0 : }
300 : :
301 : 0 : void notrace printk_nmi_exit(void)
302 : : {
303 : 0 : this_cpu_and(printk_context, ~PRINTK_NMI_CONTEXT_MASK);
304 : 0 : }
305 : :
306 : : /*
307 : : * Marks a code that might produce many messages in NMI context
308 : : * and the risk of losing them is more critical than eventual
309 : : * reordering.
310 : : *
311 : : * It has effect only when called in NMI context. Then printk()
312 : : * will try to store the messages into the main logbuf directly
313 : : * and use the per-CPU buffers only as a fallback when the lock
314 : : * is not available.
315 : : */
316 : 0 : void printk_nmi_direct_enter(void)
317 : : {
318 [ # # ]: 0 : if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
319 : 0 : this_cpu_or(printk_context, PRINTK_NMI_DIRECT_CONTEXT_MASK);
320 : 0 : }
321 : :
322 : 0 : void printk_nmi_direct_exit(void)
323 : : {
324 : 0 : this_cpu_and(printk_context, ~PRINTK_NMI_DIRECT_CONTEXT_MASK);
325 : 0 : }
326 : :
327 : : #else
328 : :
329 : : static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args)
330 : : {
331 : : return 0;
332 : : }
333 : :
334 : : #endif /* CONFIG_PRINTK_NMI */
335 : :
336 : : /*
337 : : * Lock-less printk(), to avoid deadlocks should the printk() recurse
338 : : * into itself. It uses a per-CPU buffer to store the message, just like
339 : : * NMI.
340 : : */
341 : : static __printf(1, 0) int vprintk_safe(const char *fmt, va_list args)
342 : : {
343 : 0 : struct printk_safe_seq_buf *s = this_cpu_ptr(&safe_print_seq);
344 : :
345 : 0 : return printk_safe_log_store(s, fmt, args);
346 : : }
347 : :
348 : : /* Can be preempted by NMI. */
349 : 533288 : void __printk_safe_enter(void)
350 : : {
351 : 1066576 : this_cpu_inc(printk_context);
352 : 533283 : }
353 : :
354 : : /* Can be preempted by NMI. */
355 : 533288 : void __printk_safe_exit(void)
356 : : {
357 : 1066576 : this_cpu_dec(printk_context);
358 : 533281 : }
359 : :
360 : 48810 : __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
361 : : {
362 : : /*
363 : : * Try to use the main logbuf even in NMI. But avoid calling console
364 : : * drivers that might have their own locks.
365 : : */
366 [ - + # # ]: 146430 : if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) &&
367 : 0 : raw_spin_trylock(&logbuf_lock)) {
368 : : int len;
369 : :
370 : 0 : len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
371 : : raw_spin_unlock(&logbuf_lock);
372 : 0 : defer_console_output();
373 : 0 : return len;
374 : : }
375 : :
376 : : /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */
377 [ - + ]: 146418 : if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
378 : 0 : return vprintk_nmi(fmt, args);
379 : :
380 : : /* Use extra buffer to prevent a recursion deadlock in safe mode. */
381 [ - + ]: 146428 : if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
382 : 0 : return vprintk_safe(fmt, args);
383 : :
384 : : /* No obstacles. */
385 : 48809 : return vprintk_default(fmt, args);
386 : : }
387 : :
388 : 207 : void __init printk_safe_init(void)
389 : : {
390 : : int cpu;
391 : :
392 [ + + ]: 1242 : for_each_possible_cpu(cpu) {
393 : : struct printk_safe_seq_buf *s;
394 : :
395 : 828 : s = &per_cpu(safe_print_seq, cpu);
396 : : init_irq_work(&s->work, __printk_safe_flush);
397 : :
398 : : #ifdef CONFIG_PRINTK_NMI
399 : 828 : s = &per_cpu(nmi_print_seq, cpu);
400 : : init_irq_work(&s->work, __printk_safe_flush);
401 : : #endif
402 : : }
403 : :
404 : : /* Flush pending messages that did not have scheduled IRQ works. */
405 : 207 : printk_safe_flush();
406 : 207 : }
|
