LCOV - code coverage report
Current view: top level - kernel/printk - printk_safe.c (source / functions) Hit Total Coverage
Test: combined.info Lines: 50 142 35.2 %
Date: 2022-03-28 16:04:14 Functions: 7 15 46.7 %
Branches: 11 56 19.6 %

           Branch data     Line data    Source code
       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/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
      23                 :            :  * by examinig current printk() context mask stored in @printk_context
      24                 :            :  * per-CPU variable.
      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                 :            :  */
      30                 :            : static int printk_safe_irq_ready __read_mostly;
      31                 :            : 
      32                 :            : #define SAFE_LOG_BUF_LEN ((1 << CONFIG_PRINTK_SAFE_LOG_BUF_SHIFT) -       \
      33                 :            :                                 sizeof(atomic_t) -                      \
      34                 :            :                                 sizeof(atomic_t) -                      \
      35                 :            :                                 sizeof(struct irq_work))
      36                 :            : 
      37                 :            : struct printk_safe_seq_buf {
      38                 :            :         atomic_t                len;    /* length of written data */
      39                 :            :         atomic_t                message_lost;
      40                 :            :         struct irq_work         work;   /* IRQ work that flushes the buffer */
      41                 :            :         unsigned char           buffer[SAFE_LOG_BUF_LEN];
      42                 :            : };
      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
      48                 :            : static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq);
      49                 :            : #endif
      50                 :            : 
      51                 :            : /* Get flushed in a more safe context. */
      52                 :          0 : static void queue_flush_work(struct printk_safe_seq_buf *s)
      53                 :            : {
      54                 :          0 :         if (printk_safe_irq_ready)
      55                 :          0 :                 irq_work_queue(&s->work);
      56                 :            : }
      57                 :            : 
      58                 :            : /*
      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                 :            :  *
      63                 :            :  * The messages are flushed from irq work (or from panic()), possibly,
      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.
      67                 :            :  */
      68                 :          0 : static __printf(2, 0) int printk_safe_log_store(struct printk_safe_seq_buf *s,
      69                 :            :                                                 const char *fmt, va_list args)
      70                 :            : {
      71                 :          0 :         int add;
      72                 :          0 :         size_t len;
      73                 :          0 :         va_list ap;
      74                 :            : 
      75                 :          0 : again:
      76                 :          0 :         len = atomic_read(&s->len);
      77                 :            : 
      78                 :            :         /* The trailing '\0' is not counted into len. */
      79         [ #  # ]:          0 :         if (len >= sizeof(s->buffer) - 1) {
      80                 :          0 :                 atomic_inc(&s->message_lost);
      81         [ #  # ]:          0 :                 queue_flush_work(s);
      82                 :          0 :                 return 0;
      83                 :            :         }
      84                 :            : 
      85                 :            :         /*
      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.
      88                 :            :          */
      89         [ #  # ]:          0 :         if (!len)
      90                 :          0 :                 smp_rmb();
      91                 :            : 
      92                 :          0 :         va_copy(ap, args);
      93                 :          0 :         add = vscnprintf(s->buffer + len, sizeof(s->buffer) - len, fmt, ap);
      94                 :          0 :         va_end(ap);
      95         [ #  # ]:          0 :         if (!add)
      96                 :            :                 return 0;
      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         [ #  # ]:          0 :         if (atomic_cmpxchg(&s->len, len, len + add) != len)
     104                 :          0 :                 goto again;
     105                 :            : 
     106         [ #  # ]:          0 :         queue_flush_work(s);
     107                 :            :         return add;
     108                 :            : }
     109                 :            : 
     110                 :          0 : 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                 :          0 :         printk_deferred("%.*s", len, text);
     119                 :          0 : }
     120                 :            : 
     121                 :            : /* printk part of the temporary buffer line by line */
     122                 :          0 : static int printk_safe_flush_buffer(const char *start, size_t len)
     123                 :            : {
     124                 :          0 :         const char *c, *end;
     125                 :          0 :         bool header;
     126                 :            : 
     127                 :          0 :         c = start;
     128                 :          0 :         end = start + len;
     129                 :          0 :         header = true;
     130                 :            : 
     131                 :            :         /* Print line by line. */
     132         [ #  # ]:          0 :         while (c < end) {
     133         [ #  # ]:          0 :                 if (*c == '\n') {
     134                 :          0 :                         printk_safe_flush_line(start, c - start + 1);
     135                 :          0 :                         start = ++c;
     136                 :          0 :                         header = true;
     137                 :          0 :                         continue;
     138                 :            :                 }
     139                 :            : 
     140                 :            :                 /* Handle continuous lines or missing new line. */
     141   [ #  #  #  # ]:          0 :                 if ((c + 1 < end) && printk_get_level(c)) {
     142         [ #  # ]:          0 :                         if (header) {
     143         [ #  # ]:          0 :                                 c = printk_skip_level(c);
     144                 :          0 :                                 continue;
     145                 :            :                         }
     146                 :            : 
     147                 :          0 :                         printk_safe_flush_line(start, c - start);
     148                 :          0 :                         start = c++;
     149                 :          0 :                         header = true;
     150                 :          0 :                         continue;
     151                 :            :                 }
     152                 :            : 
     153                 :            :                 header = false;
     154                 :            :                 c++;
     155                 :            :         }
     156                 :            : 
     157                 :            :         /* Check if there was a partial line. Ignore pure header. */
     158         [ #  # ]:          0 :         if (start < end && !header) {
     159                 :          0 :                 static const char newline[] = KERN_CONT "\n";
     160                 :            : 
     161                 :          0 :                 printk_safe_flush_line(start, end - start);
     162                 :          0 :                 printk_safe_flush_line(newline, strlen(newline));
     163                 :            :         }
     164                 :            : 
     165                 :          0 :         return len;
     166                 :            : }
     167                 :            : 
     168                 :         26 : static void report_message_lost(struct printk_safe_seq_buf *s)
     169                 :            : {
     170                 :         26 :         int lost = atomic_xchg(&s->message_lost, 0);
     171                 :            : 
     172         [ -  + ]:         26 :         if (lost)
     173                 :          0 :                 printk_deferred("Lost %d message(s)!\n", lost);
     174                 :         26 : }
     175                 :            : 
     176                 :            : /*
     177                 :            :  * Flush data from the associated per-CPU buffer. The function
     178                 :            :  * can be called either via IRQ work or independently.
     179                 :            :  */
     180                 :         26 : static void __printk_safe_flush(struct irq_work *work)
     181                 :            : {
     182                 :         26 :         static raw_spinlock_t read_lock =
     183                 :            :                 __RAW_SPIN_LOCK_INITIALIZER(read_lock);
     184                 :         26 :         struct printk_safe_seq_buf *s =
     185                 :         26 :                 container_of(work, struct printk_safe_seq_buf, work);
     186                 :         26 :         unsigned long flags;
     187                 :         26 :         size_t len;
     188                 :         26 :         int i;
     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                 :         26 :         raw_spin_lock_irqsave(&read_lock, flags);
     198                 :            : 
     199                 :         26 :         i = 0;
     200                 :         26 : more:
     201                 :         26 :         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
     206                 :            :          * @len must only increase. Also it should never overflow the
     207                 :            :          * buffer size.
     208                 :            :          */
     209   [ -  +  -  -  :         26 :         if ((i && i >= len) || len > sizeof(s->buffer)) {
                   -  + ]
     210                 :          0 :                 const char *msg = "printk_safe_flush: internal error\n";
     211                 :            : 
     212                 :          0 :                 printk_safe_flush_line(msg, strlen(msg));
     213                 :          0 :                 len = 0;
     214                 :            :         }
     215                 :            : 
     216         [ +  - ]:         26 :         if (!len)
     217                 :         26 :                 goto out; /* Someone else has already flushed the buffer. */
     218                 :            : 
     219                 :            :         /* Make sure that data has been written up to the @len */
     220                 :          0 :         smp_rmb();
     221                 :          0 :         i += printk_safe_flush_buffer(s->buffer + i, len - i);
     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         [ #  # ]:          0 :         if (atomic_cmpxchg(&s->len, len, 0) != len)
     230                 :          0 :                 goto more;
     231                 :            : 
     232                 :          0 : out:
     233                 :         26 :         report_message_lost(s);
     234                 :         26 :         raw_spin_unlock_irqrestore(&read_lock, flags);
     235                 :         26 : }
     236                 :            : 
     237                 :            : /**
     238                 :            :  * printk_safe_flush - flush all per-cpu nmi buffers.
     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                 :            :  */
     244                 :         13 : void printk_safe_flush(void)
     245                 :            : {
     246                 :         13 :         int cpu;
     247                 :            : 
     248         [ +  + ]:         26 :         for_each_possible_cpu(cpu) {
     249                 :            : #ifdef CONFIG_PRINTK_NMI
     250                 :         13 :                 __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work);
     251                 :            : #endif
     252                 :         13 :                 __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work);
     253                 :            :         }
     254                 :         13 : }
     255                 :            : 
     256                 :            : /**
     257                 :            :  * printk_safe_flush_on_panic - flush all per-cpu nmi buffers when the system
     258                 :            :  *      goes down.
     259                 :            :  *
     260                 :            :  * Similar to printk_safe_flush() but it can be called even in NMI context when
     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                 :            :  */
     266                 :          0 : void printk_safe_flush_on_panic(void)
     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                 :            :          */
     272         [ #  # ]:          0 :         if (raw_spin_is_locked(&logbuf_lock)) {
     273         [ #  # ]:          0 :                 if (num_online_cpus() > 1)
     274                 :            :                         return;
     275                 :            : 
     276                 :          0 :                 debug_locks_off();
     277                 :          0 :                 raw_spin_lock_init(&logbuf_lock);
     278                 :            :         }
     279                 :            : 
     280                 :          0 :         printk_safe_flush();
     281                 :            : }
     282                 :            : 
     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                 :            :  */
     290                 :          0 : static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args)
     291                 :            : {
     292                 :          0 :         struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq);
     293                 :            : 
     294                 :          0 :         return printk_safe_log_store(s, fmt, args);
     295                 :            : }
     296                 :            : 
     297                 :          0 : void notrace printk_nmi_enter(void)
     298                 :            : {
     299                 :          0 :         this_cpu_or(printk_context, PRINTK_NMI_CONTEXT_MASK);
     300                 :          0 : }
     301                 :            : 
     302                 :          0 : void notrace printk_nmi_exit(void)
     303                 :            : {
     304                 :          0 :         this_cpu_and(printk_context, ~PRINTK_NMI_CONTEXT_MASK);
     305                 :          0 : }
     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                 :          0 : void printk_nmi_direct_enter(void)
     318                 :            : {
     319         [ #  # ]:          0 :         if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
     320                 :          0 :                 this_cpu_or(printk_context, PRINTK_NMI_DIRECT_CONTEXT_MASK);
     321                 :          0 : }
     322                 :            : 
     323                 :          0 : void printk_nmi_direct_exit(void)
     324                 :            : {
     325                 :          0 :         this_cpu_and(printk_context, ~PRINTK_NMI_DIRECT_CONTEXT_MASK);
     326                 :          0 : }
     327                 :            : 
     328                 :            : #else
     329                 :            : 
     330                 :            : static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args)
     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                 :            :  */
     342                 :          0 : static __printf(1, 0) int vprintk_safe(const char *fmt, va_list args)
     343                 :            : {
     344                 :          0 :         struct printk_safe_seq_buf *s = this_cpu_ptr(&safe_print_seq);
     345                 :            : 
     346                 :          0 :         return printk_safe_log_store(s, fmt, args);
     347                 :            : }
     348                 :            : 
     349                 :            : /* Can be preempted by NMI. */
     350                 :      47097 : void __printk_safe_enter(void)
     351                 :            : {
     352                 :      47097 :         this_cpu_inc(printk_context);
     353                 :      47097 : }
     354                 :            : 
     355                 :            : /* Can be preempted by NMI. */
     356                 :      47097 : void __printk_safe_exit(void)
     357                 :            : {
     358                 :      47097 :         this_cpu_dec(printk_context);
     359                 :      47097 : }
     360                 :            : 
     361                 :       6089 : __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
     362                 :            : {
     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   [ -  +  -  - ]:       6089 :         if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) &&
     368                 :          0 :             raw_spin_trylock(&logbuf_lock)) {
     369                 :          0 :                 int len;
     370                 :            : 
     371                 :          0 :                 len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
     372                 :          0 :                 raw_spin_unlock(&logbuf_lock);
     373                 :          0 :                 defer_console_output();
     374                 :          0 :                 return len;
     375                 :            :         }
     376                 :            : 
     377                 :            :         /* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */
     378         [ -  + ]:       6089 :         if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
     379                 :          0 :                 return vprintk_nmi(fmt, args);
     380                 :            : 
     381                 :            :         /* Use extra buffer to prevent a recursion deadlock in safe mode. */
     382         [ -  + ]:       6089 :         if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK)
     383                 :          0 :                 return vprintk_safe(fmt, args);
     384                 :            : 
     385                 :            :         /* No obstacles. */
     386                 :       6089 :         return vprintk_default(fmt, args);
     387                 :            : }
     388                 :            : 
     389                 :         13 : void __init printk_safe_init(void)
     390                 :            : {
     391                 :         13 :         int cpu;
     392                 :            : 
     393         [ +  + ]:         26 :         for_each_possible_cpu(cpu) {
     394                 :         13 :                 struct printk_safe_seq_buf *s;
     395                 :            : 
     396                 :         13 :                 s = &per_cpu(safe_print_seq, cpu);
     397                 :         13 :                 init_irq_work(&s->work, __printk_safe_flush);
     398                 :            : 
     399                 :            : #ifdef CONFIG_PRINTK_NMI
     400                 :         13 :                 s = &per_cpu(nmi_print_seq, cpu);
     401                 :         13 :                 init_irq_work(&s->work, __printk_safe_flush);
     402                 :            : #endif
     403                 :            :         }
     404                 :            : 
     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                 :         13 :         barrier();
     411                 :         13 :         printk_safe_irq_ready = 1;
     412                 :            : 
     413                 :            :         /* Flush pending messages that did not have scheduled IRQ works. */
     414                 :         13 :         printk_safe_flush();
     415                 :         13 : }

Generated by: LCOV version 1.14