Merge tag 'driver-core-3.6-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git...
[firefly-linux-kernel-4.4.55.git] / kernel / printk.c
index 177fa49357a5d346f1296ca431d4a674c7659508..50c96b5651b696766c915b57dec92b5629a78866 100644 (file)
@@ -216,6 +216,7 @@ struct log {
  */
 static DEFINE_RAW_SPINLOCK(logbuf_lock);
 
+#ifdef CONFIG_PRINTK
 /* the next printk record to read by syslog(READ) or /proc/kmsg */
 static u64 syslog_seq;
 static u32 syslog_idx;
@@ -228,14 +229,19 @@ static u32 log_first_idx;
 
 /* index and sequence number of the next record to store in the buffer */
 static u64 log_next_seq;
-#ifdef CONFIG_PRINTK
 static u32 log_next_idx;
 
+/* the next printk record to write to the console */
+static u64 console_seq;
+static u32 console_idx;
+static enum log_flags console_prev;
+
 /* the next printk record to read after the last 'clear' command */
 static u64 clear_seq;
 static u32 clear_idx;
 
-#define LOG_LINE_MAX 1024
+#define PREFIX_MAX             32
+#define LOG_LINE_MAX           1024 - PREFIX_MAX
 
 /* record buffer */
 #if defined(CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS)
@@ -360,6 +366,7 @@ static void log_store(int facility, int level,
 struct devkmsg_user {
        u64 seq;
        u32 idx;
+       enum log_flags prev;
        struct mutex lock;
        char buf[8192];
 };
@@ -425,6 +432,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
        struct log *msg;
        u64 ts_usec;
        size_t i;
+       char cont = '-';
        size_t len;
        ssize_t ret;
 
@@ -462,8 +470,25 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
        msg = log_from_idx(user->idx);
        ts_usec = msg->ts_nsec;
        do_div(ts_usec, 1000);
-       len = sprintf(user->buf, "%u,%llu,%llu;",
-                     (msg->facility << 3) | msg->level, user->seq, ts_usec);
+
+       /*
+        * If we couldn't merge continuation line fragments during the print,
+        * export the stored flags to allow an optional external merge of the
+        * records. Merging the records isn't always neccessarily correct, like
+        * when we hit a race during printing. In most cases though, it produces
+        * better readable output. 'c' in the record flags mark the first
+        * fragment of a line, '+' the following.
+        */
+       if (msg->flags & LOG_CONT && !(user->prev & LOG_CONT))
+               cont = 'c';
+       else if ((msg->flags & LOG_CONT) ||
+                ((user->prev & LOG_CONT) && !(msg->flags & LOG_PREFIX)))
+               cont = '+';
+
+       len = sprintf(user->buf, "%u,%llu,%llu,%c;",
+                     (msg->facility << 3) | msg->level,
+                     user->seq, ts_usec, cont);
+       user->prev = msg->flags;
 
        /* escape non-printable characters */
        for (i = 0; i < msg->text_len; i++) {
@@ -646,6 +671,15 @@ void log_buf_kexec_setup(void)
        VMCOREINFO_SYMBOL(log_buf_len);
        VMCOREINFO_SYMBOL(log_first_idx);
        VMCOREINFO_SYMBOL(log_next_idx);
+       /*
+        * Export struct log size and field offsets. User space tools can
+        * parse it and detect any changes to structure down the line.
+        */
+       VMCOREINFO_STRUCT_SIZE(log);
+       VMCOREINFO_OFFSET(log, ts_nsec);
+       VMCOREINFO_OFFSET(log, len);
+       VMCOREINFO_OFFSET(log, text_len);
+       VMCOREINFO_OFFSET(log, dict_len);
 }
 #endif
 
@@ -876,7 +910,7 @@ static size_t msg_print_text(const struct log *msg, enum log_flags prev,
 
                if (buf) {
                        if (print_prefix(msg, syslog, NULL) +
-                           text_len + 1>= size - len)
+                           text_len + 1 >= size - len)
                                break;
 
                        if (prefix)
@@ -907,7 +941,7 @@ static int syslog_print(char __user *buf, int size)
        struct log *msg;
        int len = 0;
 
-       text = kmalloc(LOG_LINE_MAX, GFP_KERNEL);
+       text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
        if (!text)
                return -ENOMEM;
 
@@ -930,7 +964,8 @@ static int syslog_print(char __user *buf, int size)
 
                skip = syslog_partial;
                msg = log_from_idx(syslog_idx);
-               n = msg_print_text(msg, syslog_prev, true, text, LOG_LINE_MAX);
+               n = msg_print_text(msg, syslog_prev, true, text,
+                                  LOG_LINE_MAX + PREFIX_MAX);
                if (n - syslog_partial <= size) {
                        /* message fits into buffer, move forward */
                        syslog_idx = log_next(syslog_idx);
@@ -969,7 +1004,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
        char *text;
        int len = 0;
 
-       text = kmalloc(LOG_LINE_MAX, GFP_KERNEL);
+       text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
        if (!text)
                return -ENOMEM;
 
@@ -1022,7 +1057,8 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
                        struct log *msg = log_from_idx(idx);
                        int textlen;
 
-                       textlen = msg_print_text(msg, prev, true, text, LOG_LINE_MAX);
+                       textlen = msg_print_text(msg, prev, true, text,
+                                                LOG_LINE_MAX + PREFIX_MAX);
                        if (textlen < 0) {
                                len = textlen;
                                break;
@@ -1192,21 +1228,6 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
        return do_syslog(type, buf, len, SYSLOG_FROM_CALL);
 }
 
-#ifdef CONFIG_KGDB_KDB
-/* kdb dmesg command needs access to the syslog buffer.  do_syslog()
- * uses locks so it cannot be used during debugging.  Just tell kdb
- * where the start and end of the physical and logical logs are.  This
- * is equivalent to do_syslog(3).
- */
-void kdb_syslog_data(char *syslog_data[4])
-{
-       syslog_data[0] = log_buf;
-       syslog_data[1] = log_buf + log_buf_len;
-       syslog_data[2] = log_buf + log_first_idx;
-       syslog_data[3] = log_buf + log_next_idx;
-}
-#endif /* CONFIG_KGDB_KDB */
-
 static bool __read_mostly ignore_loglevel;
 
 static int __init ignore_loglevel_setup(char *str)
@@ -1364,20 +1385,36 @@ static struct cont {
        u64 ts_nsec;                    /* time of first print */
        u8 level;                       /* log level of first message */
        u8 facility;                    /* log level of first message */
+       enum log_flags flags;           /* prefix, newline flags */
        bool flushed:1;                 /* buffer sealed and committed */
 } cont;
 
-static void cont_flush(void)
+static void cont_flush(enum log_flags flags)
 {
        if (cont.flushed)
                return;
        if (cont.len == 0)
                return;
 
-       log_store(cont.facility, cont.level, LOG_NOCONS, cont.ts_nsec,
-                 NULL, 0, cont.buf, cont.len);
-
-       cont.flushed = true;
+       if (cont.cons) {
+               /*
+                * If a fragment of this line was directly flushed to the
+                * console; wait for the console to pick up the rest of the
+                * line. LOG_NOCONS suppresses a duplicated output.
+                */
+               log_store(cont.facility, cont.level, flags | LOG_NOCONS,
+                         cont.ts_nsec, NULL, 0, cont.buf, cont.len);
+               cont.flags = flags;
+               cont.flushed = true;
+       } else {
+               /*
+                * If no fragment of this line ever reached the console,
+                * just submit it to the store and free the buffer.
+                */
+               log_store(cont.facility, cont.level, flags, 0,
+                         NULL, 0, cont.buf, cont.len);
+               cont.len = 0;
+       }
 }
 
 static bool cont_add(int facility, int level, const char *text, size_t len)
@@ -1386,7 +1423,8 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
                return false;
 
        if (cont.len + len > sizeof(cont.buf)) {
-               cont_flush();
+               /* the line gets too long, split it up in separate records */
+               cont_flush(LOG_CONT);
                return false;
        }
 
@@ -1395,12 +1433,17 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
                cont.level = level;
                cont.owner = current;
                cont.ts_nsec = local_clock();
+               cont.flags = 0;
                cont.cons = 0;
                cont.flushed = false;
        }
 
        memcpy(cont.buf + cont.len, text, len);
        cont.len += len;
+
+       if (cont.len > (sizeof(cont.buf) * 80) / 100)
+               cont_flush(LOG_CONT);
+
        return true;
 }
 
@@ -1409,7 +1452,7 @@ static size_t cont_print_text(char *text, size_t size)
        size_t textlen = 0;
        size_t len;
 
-       if (cont.cons == 0) {
+       if (cont.cons == 0 && (console_prev & LOG_NEWLINE)) {
                textlen += print_time(cont.ts_nsec, text);
                size -= textlen;
        }
@@ -1424,7 +1467,8 @@ static size_t cont_print_text(char *text, size_t size)
        }
 
        if (cont.flushed) {
-               text[textlen++] = '\n';
+               if (cont.flags & LOG_NEWLINE)
+                       text[textlen++] = '\n';
                /* got everything, release buffer */
                cont.len = 0;
        }
@@ -1522,7 +1566,7 @@ asmlinkage int vprintk_emit(int facility, int level,
                 * or another task also prints continuation lines.
                 */
                if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
-                       cont_flush();
+                       cont_flush(LOG_NEWLINE);
 
                /* buffer line if possible, otherwise store it right away */
                if (!cont_add(facility, level, text, text_len))
@@ -1540,7 +1584,7 @@ asmlinkage int vprintk_emit(int facility, int level,
                if (cont.len && cont.owner == current) {
                        if (!(lflags & LOG_PREFIX))
                                stored = cont_add(facility, level, text, text_len);
-                       cont_flush();
+                       cont_flush(LOG_NEWLINE);
                }
 
                if (!stored)
@@ -1631,9 +1675,20 @@ asmlinkage int printk(const char *fmt, ...)
 }
 EXPORT_SYMBOL(printk);
 
-#else
+#else /* CONFIG_PRINTK */
 
+#define LOG_LINE_MAX           0
+#define PREFIX_MAX             0
 #define LOG_LINE_MAX 0
+static u64 syslog_seq;
+static u32 syslog_idx;
+static u64 console_seq;
+static u32 console_idx;
+static enum log_flags syslog_prev;
+static u64 log_first_seq;
+static u32 log_first_idx;
+static u64 log_next_seq;
+static enum log_flags console_prev;
 static struct cont {
        size_t len;
        size_t cons;
@@ -1917,10 +1972,34 @@ void wake_up_klogd(void)
                this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP);
 }
 
-/* the next printk record to write to the console */
-static u64 console_seq;
-static u32 console_idx;
-static enum log_flags console_prev;
+static void console_cont_flush(char *text, size_t size)
+{
+       unsigned long flags;
+       size_t len;
+
+       raw_spin_lock_irqsave(&logbuf_lock, flags);
+
+       if (!cont.len)
+               goto out;
+
+       /*
+        * We still queue earlier records, likely because the console was
+        * busy. The earlier ones need to be printed before this one, we
+        * did not flush any fragment so far, so just let it queue up.
+        */
+       if (console_seq < log_next_seq && !cont.cons)
+               goto out;
+
+       len = cont_print_text(text, size);
+       raw_spin_unlock(&logbuf_lock);
+       stop_critical_timings();
+       call_console_drivers(cont.level, text, len);
+       start_critical_timings();
+       local_irq_restore(flags);
+       return;
+out:
+       raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+}
 
 /**
  * console_unlock - unlock the console system
@@ -1938,7 +2017,7 @@ static enum log_flags console_prev;
  */
 void console_unlock(void)
 {
-       static char text[LOG_LINE_MAX];
+       static char text[LOG_LINE_MAX + PREFIX_MAX];
        static u64 seen_seq;
        unsigned long flags;
        bool wake_klogd = false;
@@ -1952,19 +2031,7 @@ void console_unlock(void)
        console_may_schedule = 0;
 
        /* flush buffered message fragment immediately to console */
-       raw_spin_lock_irqsave(&logbuf_lock, flags);
-       if (cont.len && (cont.cons < cont.len || cont.flushed)) {
-               size_t len;
-
-               len = cont_print_text(text, sizeof(text));
-               raw_spin_unlock(&logbuf_lock);
-               stop_critical_timings();
-               call_console_drivers(cont.level, text, len);
-               start_critical_timings();
-               local_irq_restore(flags);
-       } else
-               raw_spin_unlock_irqrestore(&logbuf_lock, flags);
-
+       console_cont_flush(text, sizeof(text));
 again:
        for (;;) {
                struct log *msg;
@@ -2001,6 +2068,7 @@ skip:
                         * will properly dump everything later.
                         */
                        msg->flags &= ~LOG_NOCONS;
+                       console_prev = msg->flags;
                        goto skip;
                }
 
@@ -2525,7 +2593,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 }
 
 /**
- * kmsg_dump_get_line - retrieve one kmsg log line
+ * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version)
  * @dumper: registered kmsg dumper
  * @syslog: include the "<4>" prefixes
  * @line: buffer to copy the line to
@@ -2540,11 +2608,12 @@ void kmsg_dump(enum kmsg_dump_reason reason)
  *
  * A return value of FALSE indicates that there are no more records to
  * read.
+ *
+ * The function is similar to kmsg_dump_get_line(), but grabs no locks.
  */
-bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
-                       char *line, size_t size, size_t *len)
+bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
+                              char *line, size_t size, size_t *len)
 {
-       unsigned long flags;
        struct log *msg;
        size_t l = 0;
        bool ret = false;
@@ -2552,7 +2621,6 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
        if (!dumper->active)
                goto out;
 
-       raw_spin_lock_irqsave(&logbuf_lock, flags);
        if (dumper->cur_seq < log_first_seq) {
                /* messages are gone, move to first available one */
                dumper->cur_seq = log_first_seq;
@@ -2560,10 +2628,8 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
        }
 
        /* last entry */
-       if (dumper->cur_seq >= log_next_seq) {
-               raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+       if (dumper->cur_seq >= log_next_seq)
                goto out;
-       }
 
        msg = log_from_idx(dumper->cur_idx);
        l = msg_print_text(msg, 0, syslog, line, size);
@@ -2571,12 +2637,41 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
        dumper->cur_idx = log_next(dumper->cur_idx);
        dumper->cur_seq++;
        ret = true;
-       raw_spin_unlock_irqrestore(&logbuf_lock, flags);
 out:
        if (len)
                *len = l;
        return ret;
 }
+
+/**
+ * kmsg_dump_get_line - retrieve one kmsg log line
+ * @dumper: registered kmsg dumper
+ * @syslog: include the "<4>" prefixes
+ * @line: buffer to copy the line to
+ * @size: maximum size of the buffer
+ * @len: length of line placed into buffer
+ *
+ * Start at the beginning of the kmsg buffer, with the oldest kmsg
+ * record, and copy one record into the provided buffer.
+ *
+ * Consecutive calls will return the next available record moving
+ * towards the end of the buffer with the youngest messages.
+ *
+ * A return value of FALSE indicates that there are no more records to
+ * read.
+ */
+bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
+                       char *line, size_t size, size_t *len)
+{
+       unsigned long flags;
+       bool ret;
+
+       raw_spin_lock_irqsave(&logbuf_lock, flags);
+       ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len);
+       raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+
+       return ret;
+}
 EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
 
 /**
@@ -2678,6 +2773,24 @@ out:
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
 
+/**
+ * kmsg_dump_rewind_nolock - reset the interator (unlocked version)
+ * @dumper: registered kmsg dumper
+ *
+ * Reset the dumper's iterator so that kmsg_dump_get_line() and
+ * kmsg_dump_get_buffer() can be called again and used multiple
+ * times within the same dumper.dump() callback.
+ *
+ * The function is similar to kmsg_dump_rewind(), but grabs no locks.
+ */
+void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
+{
+       dumper->cur_seq = clear_seq;
+       dumper->cur_idx = clear_idx;
+       dumper->next_seq = log_next_seq;
+       dumper->next_idx = log_next_idx;
+}
+
 /**
  * kmsg_dump_rewind - reset the interator
  * @dumper: registered kmsg dumper
@@ -2691,10 +2804,7 @@ void kmsg_dump_rewind(struct kmsg_dumper *dumper)
        unsigned long flags;
 
        raw_spin_lock_irqsave(&logbuf_lock, flags);
-       dumper->cur_seq = clear_seq;
-       dumper->cur_idx = clear_idx;
-       dumper->next_seq = log_next_seq;
-       dumper->next_idx = log_next_idx;
+       kmsg_dump_rewind_nolock(dumper);
        raw_spin_unlock_irqrestore(&logbuf_lock, flags);
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);