printk_safe.c 11 KB

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