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