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 static void queue_flush_work(struct printk_safe_seq_buf *s)
52 {
53 if (printk_percpu_data_ready())
54 irq_work_queue(&s->work);
55 }
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 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 len = atomic_read(&s->len);
76
77 /* The trailing '\0' is not counted into len. */
78 if (len >= sizeof(s->buffer) - 1) {
79 atomic_inc(&s->message_lost);
80 queue_flush_work(s);
81 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 if (!len)
89 smp_rmb();
90
91 va_copy(ap, args);
92 add = vscnprintf(s->buffer + len, sizeof(s->buffer) - len, fmt, ap);
93 va_end(ap);
94 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 if (atomic_cmpxchg(&s->len, len, len + add) != len)
103 goto again;
104
105 queue_flush_work(s);
106 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 printk_deferred("%.*s", len, text);
118 }
119
120 /* printk part of the temporary buffer line by line */
121 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 end = start + len;
128 header = true;
129
130 /* Print line by line. */
131 while (c < end) {
132 if (*c == '\n') {
133 printk_safe_flush_line(start, c - start + 1);
134 start = ++c;
135 header = true;
136 continue;
137 }
138
139 /* Handle continuous lines or missing new line. */
140 if ((c + 1 < end) && printk_get_level(c)) {
141 if (header) {
142 c = printk_skip_level(c);
143 continue;
144 }
145
146 printk_safe_flush_line(start, c - start);
147 start = c++;
148 header = true;
149 continue;
150 }
151
152 header = false;
153 c++;
154 }
155
156 /* Check if there was a partial line. Ignore pure header. */
157 if (start < end && !header) {
158 static const char newline[] = KERN_CONT "\n";
159
160 printk_safe_flush_line(start, end - start);
161 printk_safe_flush_line(newline, strlen(newline));
162 }
163
164 return len;
165 }
166
167 static void report_message_lost(struct printk_safe_seq_buf *s)
168 {
169 int lost = atomic_xchg(&s->message_lost, 0);
170
171 if (lost)
172 printk_deferred("Lost %d message(s)!\n", lost);
173 }
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 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 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 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 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 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 smp_rmb();
220 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 if (atomic_cmpxchg(&s->len, len, 0) != len)
229 goto more;
230
231 out:
232 report_message_lost(s);
233 raw_spin_unlock_irqrestore(&read_lock, flags);
234 }
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 void printk_safe_flush(void)
244 {
245 int cpu;
246
247 for_each_possible_cpu(cpu) {
248 #ifdef CONFIG_PRINTK_NMI
249 __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work);
250 #endif
251 __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work);
252 }
253 }
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 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 if (raw_spin_is_locked(&logbuf_lock)) {
272 if (num_online_cpus() > 1)
273 return;
274
275 debug_locks_off();
276 raw_spin_lock_init(&logbuf_lock);
277 }
278
279 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 struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
292
293 return printk_safe_log_store(s, fmt, args);
294 }
295
296 void notrace printk_nmi_enter(void)
297 {
298 this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK);
299 }
300
301 void notrace printk_nmi_exit(void)
302 {
303 this_cpu_and(printk_context, ~PRINTK_NMI_CONTEXT_MASK);
304 }
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 void printk_nmi_direct_enter(void)
317 {
318 if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
319 this_cpu_or(printk_context, PRINTK_NMI_DIRECT_CONTEXT_MASK);
320 }
321
322 void printk_nmi_direct_exit(void)
323 {
324 this_cpu_and(printk_context, ~PRINTK_NMI_DIRECT_CONTEXT_MASK);
325 }
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 struct printk_safe_seq_buf *s = this_cpu_ptr(&safe_print_seq);
344
345 return printk_safe_log_store(s, fmt, args);
346 }
347
348 /* Can be preempted by NMI. */
349 void __printk_safe_enter(void)
350 {
351 this_cpu_inc(printk_context);
352 }
353
354 /* Can be preempted by NMI. */
355 void __printk_safe_exit(void)
356 {
357 this_cpu_dec(printk_context);
358 }
359
360 __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 if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) &&
367 raw_spin_trylock(&logbuf_lock)) {
368 int len;
369
370 len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
371 raw_spin_unlock(&logbuf_lock);
372 defer_console_output();
373 return len;
374 }
375
376 /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */
377 if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
378 return vprintk_nmi(fmt, args);
379
380 /* Use extra buffer to prevent a recursion deadlock in safe mode. */
381 if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
382 return vprintk_safe(fmt, args);
383
384 /* No obstacles. */
385 return vprintk_default(fmt, args);
386 }
387
388 void __init printk_safe_init(void)
389 {
390 int cpu;
391
392 for_each_possible_cpu(cpu) {
393 struct printk_safe_seq_buf *s;
394
395 s = &per_cpu(safe_print_seq, cpu);
396 init_irq_work(&s->work, __printk_safe_flush);
397
398 #ifdef CONFIG_PRINTK_NMI
399 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 printk_safe_flush();
406 }