printk_safe.c 11 KB

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