]>
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 | */ | |
42a0bb3f | 30 | |
f92bac3b | 31 | #define SAFE_LOG_BUF_LEN ((1 << CONFIG_PRINTK_SAFE_LOG_BUF_SHIFT) - \ |
ddb9baa8 SS |
32 | sizeof(atomic_t) - \ |
33 | sizeof(atomic_t) - \ | |
34 | sizeof(struct irq_work)) | |
42a0bb3f | 35 | |
f92bac3b | 36 | struct printk_safe_seq_buf { |
42a0bb3f | 37 | atomic_t len; /* length of written data */ |
ddb9baa8 | 38 | atomic_t message_lost; |
42a0bb3f | 39 | struct irq_work work; /* IRQ work that flushes the buffer */ |
f92bac3b | 40 | unsigned char buffer[SAFE_LOG_BUF_LEN]; |
42a0bb3f | 41 | }; |
099f1c84 SS |
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 | |
f92bac3b | 47 | static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq); |
099f1c84 | 48 | #endif |
42a0bb3f | 49 | |
ddb9baa8 SS |
50 | /* Get flushed in a more safe context. */ |
51 | static void queue_flush_work(struct printk_safe_seq_buf *s) | |
52 | { | |
ab6f762f | 53 | if (printk_percpu_data_ready()) |
ddb9baa8 | 54 | irq_work_queue(&s->work); |
ddb9baa8 SS |
55 | } |
56 | ||
42a0bb3f | 57 | /* |
099f1c84 SS |
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 | * | |
bc829366 | 62 | * The messages are flushed from irq work (or from panic()), possibly, |
099f1c84 SS |
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. | |
42a0bb3f | 66 | */ |
f4e981cb NI |
67 | static __printf(2, 0) int printk_safe_log_store(struct printk_safe_seq_buf *s, |
68 | const char *fmt, va_list args) | |
42a0bb3f | 69 | { |
099f1c84 | 70 | int add; |
42a0bb3f | 71 | size_t len; |
988a35f8 | 72 | va_list ap; |
42a0bb3f PM |
73 | |
74 | again: | |
75 | len = atomic_read(&s->len); | |
76 | ||
4a998e32 PM |
77 | /* The trailing '\0' is not counted into len. */ |
78 | if (len >= sizeof(s->buffer) - 1) { | |
ddb9baa8 SS |
79 | atomic_inc(&s->message_lost); |
80 | queue_flush_work(s); | |
42a0bb3f | 81 | return 0; |
b522deab | 82 | } |
42a0bb3f PM |
83 | |
84 | /* | |
099f1c84 SS |
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. | |
42a0bb3f PM |
87 | */ |
88 | if (!len) | |
89 | smp_rmb(); | |
90 | ||
988a35f8 TH |
91 | va_copy(ap, args); |
92 | add = vscnprintf(s->buffer + len, sizeof(s->buffer) - len, fmt, ap); | |
93 | va_end(ap); | |
ddb9baa8 SS |
94 | if (!add) |
95 | return 0; | |
42a0bb3f PM |
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 | ||
ddb9baa8 | 105 | queue_flush_work(s); |
42a0bb3f PM |
106 | return add; |
107 | } | |
108 | ||
7acac344 | 109 | static inline void printk_safe_flush_line(const char *text, int len) |
42a0bb3f | 110 | { |
cf9b1106 | 111 | /* |
7acac344 SS |
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. | |
cf9b1106 | 116 | */ |
7acac344 | 117 | printk_deferred("%.*s", len, text); |
42a0bb3f PM |
118 | } |
119 | ||
22c2c7b2 | 120 | /* printk part of the temporary buffer line by line */ |
f92bac3b | 121 | static int printk_safe_flush_buffer(const char *start, size_t len) |
19feeff1 | 122 | { |
22c2c7b2 PM |
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') { | |
f92bac3b | 133 | printk_safe_flush_line(start, c - start + 1); |
22c2c7b2 PM |
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 | ||
f92bac3b | 146 | printk_safe_flush_line(start, c - start); |
22c2c7b2 PM |
147 | start = c++; |
148 | header = true; | |
149 | continue; | |
150 | } | |
151 | ||
152 | header = false; | |
153 | c++; | |
154 | } | |
19feeff1 | 155 | |
22c2c7b2 PM |
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 | ||
f92bac3b SS |
160 | printk_safe_flush_line(start, end - start); |
161 | printk_safe_flush_line(newline, strlen(newline)); | |
22c2c7b2 PM |
162 | } |
163 | ||
164 | return len; | |
19feeff1 SS |
165 | } |
166 | ||
ddb9baa8 SS |
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 | ||
42a0bb3f | 175 | /* |
099f1c84 | 176 | * Flush data from the associated per-CPU buffer. The function |
42a0bb3f PM |
177 | * can be called either via IRQ work or independently. |
178 | */ | |
f92bac3b | 179 | static void __printk_safe_flush(struct irq_work *work) |
42a0bb3f PM |
180 | { |
181 | static raw_spinlock_t read_lock = | |
182 | __RAW_SPIN_LOCK_INITIALIZER(read_lock); | |
f92bac3b SS |
183 | struct printk_safe_seq_buf *s = |
184 | container_of(work, struct printk_safe_seq_buf, work); | |
42a0bb3f | 185 | unsigned long flags; |
22c2c7b2 PM |
186 | size_t len; |
187 | int i; | |
42a0bb3f PM |
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 | |
22c2c7b2 PM |
205 | * @len must only increase. Also it should never overflow the |
206 | * buffer size. | |
42a0bb3f | 207 | */ |
22c2c7b2 | 208 | if ((i && i >= len) || len > sizeof(s->buffer)) { |
f92bac3b | 209 | const char *msg = "printk_safe_flush: internal error\n"; |
19feeff1 | 210 | |
f92bac3b | 211 | printk_safe_flush_line(msg, strlen(msg)); |
22c2c7b2 | 212 | len = 0; |
19feeff1 | 213 | } |
42a0bb3f PM |
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(); | |
f92bac3b | 220 | i += printk_safe_flush_buffer(s->buffer + i, len - i); |
42a0bb3f PM |
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: | |
ddb9baa8 | 232 | report_message_lost(s); |
42a0bb3f PM |
233 | raw_spin_unlock_irqrestore(&read_lock, flags); |
234 | } | |
235 | ||
236 | /** | |
f92bac3b | 237 | * printk_safe_flush - flush all per-cpu nmi buffers. |
42a0bb3f PM |
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 | */ | |
f92bac3b | 243 | void printk_safe_flush(void) |
42a0bb3f PM |
244 | { |
245 | int cpu; | |
246 | ||
099f1c84 SS |
247 | for_each_possible_cpu(cpu) { |
248 | #ifdef CONFIG_PRINTK_NMI | |
f92bac3b | 249 | __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work); |
099f1c84 SS |
250 | #endif |
251 | __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work); | |
252 | } | |
42a0bb3f PM |
253 | } |
254 | ||
cf9b1106 | 255 | /** |
f92bac3b | 256 | * printk_safe_flush_on_panic - flush all per-cpu nmi buffers when the system |
cf9b1106 PM |
257 | * goes down. |
258 | * | |
f92bac3b | 259 | * Similar to printk_safe_flush() but it can be called even in NMI context when |
cf9b1106 PM |
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 | */ | |
f92bac3b | 265 | void printk_safe_flush_on_panic(void) |
cf9b1106 PM |
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 | */ | |
554755be | 271 | if (raw_spin_is_locked(&logbuf_lock)) { |
cf9b1106 PM |
272 | if (num_online_cpus() > 1) |
273 | return; | |
274 | ||
275 | debug_locks_off(); | |
276 | raw_spin_lock_init(&logbuf_lock); | |
277 | } | |
278 | ||
f92bac3b | 279 | printk_safe_flush(); |
cf9b1106 PM |
280 | } |
281 | ||
099f1c84 SS |
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 | */ | |
f4e981cb | 289 | static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args) |
099f1c84 SS |
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 | ||
d1c392c9 | 296 | void notrace printk_nmi_enter(void) |
099f1c84 | 297 | { |
03fc7f9c | 298 | this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK); |
099f1c84 SS |
299 | } |
300 | ||
d1c392c9 | 301 | void notrace printk_nmi_exit(void) |
099f1c84 | 302 | { |
03fc7f9c PM |
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); | |
099f1c84 SS |
325 | } |
326 | ||
327 | #else | |
328 | ||
f4e981cb | 329 | static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args) |
099f1c84 SS |
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 | */ | |
f4e981cb | 341 | static __printf(1, 0) int vprintk_safe(const char *fmt, va_list args) |
099f1c84 SS |
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 | { | |
03fc7f9c PM |
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 | ||
719f6a70 | 376 | /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */ |
099f1c84 SS |
377 | if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK) |
378 | return vprintk_nmi(fmt, args); | |
379 | ||
719f6a70 | 380 | /* Use extra buffer to prevent a recursion deadlock in safe mode. */ |
099f1c84 SS |
381 | if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK) |
382 | return vprintk_safe(fmt, args); | |
383 | ||
719f6a70 | 384 | /* No obstacles. */ |
099f1c84 SS |
385 | return vprintk_default(fmt, args); |
386 | } | |
387 | ||
f92bac3b | 388 | void __init printk_safe_init(void) |
42a0bb3f PM |
389 | { |
390 | int cpu; | |
391 | ||
392 | for_each_possible_cpu(cpu) { | |
099f1c84 SS |
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); | |
42a0bb3f | 397 | |
099f1c84 SS |
398 | #ifdef CONFIG_PRINTK_NMI |
399 | s = &per_cpu(nmi_print_seq, cpu); | |
f92bac3b | 400 | init_irq_work(&s->work, __printk_safe_flush); |
099f1c84 | 401 | #endif |
42a0bb3f PM |
402 | } |
403 | ||
42a0bb3f | 404 | /* Flush pending messages that did not have scheduled IRQ works. */ |
f92bac3b | 405 | printk_safe_flush(); |
42a0bb3f | 406 | } |