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