p71924506
/
linux_old1
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

printk: Pass caller information to log_store(). 

When thread1 called printk() which did not end with '\n', and then thread2
called printk() which ends with '\n' before thread1 calls pr_cont(), the
partial content saved into "struct cont" is flushed by thread2 despite the
partial content was generated by thread1. This leads to confusing output
as if the partial content was generated by thread2. Fix this problem by
passing correct caller information to log_store().

Before:

  [ T8533] abcdefghijklm
  [ T8533] ABCDEFGHIJKLMNOPQRSTUVWXYZ
  [ T8532] nopqrstuvwxyz
  [ T8532] abcdefghijklmnopqrstuvwxyz
  [ T8533] abcdefghijklm
  [ T8533] ABCDEFGHIJKLMNOPQRSTUVWXYZ
  [ T8532] nopqrstuvwxyz

After:

  [ T8507] abcdefghijklm
  [ T8508] ABCDEFGHIJKLMNOPQRSTUVWXYZ
  [ T8507] nopqrstuvwxyz
  [ T8507] abcdefghijklmnopqrstuvwxyz
  [ T8507] abcdefghijklm
  [ T8508] ABCDEFGHIJKLMNOPQRSTUVWXYZ
  [ T8507] nopqrstuvwxyz

Link: http://lkml.kernel.org/r/1550314773-8607-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp
To: Dmitry Vyukov <dvyukov@google.com>
To: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
To: Steven Rostedt <rostedt@goodmis.org>
Cc: linux-kernel@vger.kernel.org
Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Reviewed-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
[pmladek: broke 80-column rule where it made more harm than good]
Signed-off-by: Petr Mladek <pmladek@suse.com>
This commit is contained in:
Tetsuo Handa 2019-02-16 19:59:33 +09:00 committed by Petr Mladek
parent 15ff2069cb
commit cbae05d32f
1 changed files with 22 additions and 15 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

37
kernel/printk/printk.c
View File

@ -585,7 +585,7 @@ static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
}
/* insert record into the buffer, discard old ones, update heads */
static int log_store(int facility, int level,
static int log_store(u32 caller_id, int facility, int level,
enum log_flags flags, u64 ts_nsec,
const char *dict, u16 dict_len,
const char *text, u16 text_len)
@ -634,10 +634,7 @@ static int log_store(int facility, int level,
else
msg->ts_nsec = local_clock();
#ifdef CONFIG_PRINTK_CALLER
if (in_task())
msg->caller_id = task_pid_nr(current);
else
msg->caller_id = 0x80000000 + raw_smp_processor_id();
msg->caller_id = caller_id;
#endif
memset(log_dict(msg) + dict_len, 0, pad_len);
msg->len = size;
@ -1800,6 +1797,12 @@ static inline void printk_delay(void)
}
}
static inline u32 printk_caller_id(void)
{
return in_task() ? task_pid_nr(current) :
0x80000000 + raw_smp_processor_id();
}
/*
* Continuation lines are buffered, and not committed to the record buffer
* until the line is complete, or a race forces it. The line fragments
@ -1809,7 +1812,7 @@ static inline void printk_delay(void)
static struct cont {
char buf[LOG_LINE_MAX];
size_t len; /* length == 0 means unused buffer */
struct task_struct *owner; /* task of first print*/
u32 caller_id; /* printk_caller_id() of first print */
u64 ts_nsec; /* time of first print */
u8 level; /* log level of first message */
u8 facility; /* log facility of first message */
@ -1821,12 +1824,13 @@ static void cont_flush(void)
if (cont.len == 0)
return;
log_store(cont.facility, cont.level, cont.flags, cont.ts_nsec,
NULL, 0, cont.buf, cont.len);
log_store(cont.caller_id, cont.facility, cont.level, cont.flags,
cont.ts_nsec, NULL, 0, cont.buf, cont.len);
cont.len = 0;
}
static bool cont_add(int facility, int level, enum log_flags flags, const char *text, size_t len)
static bool cont_add(u32 caller_id, int facility, int level,
enum log_flags flags, const char *text, size_t len)
{
/* If the line gets too long, split it up in separate records. */
if (cont.len + len > sizeof(cont.buf)) {
@ -1837,7 +1841,7 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char *
if (!cont.len) {
cont.facility = facility;
cont.level = level;
cont.owner = current;
cont.caller_id = caller_id;
cont.ts_nsec = local_clock();
cont.flags = flags;
}
@ -1857,13 +1861,15 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char *
static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len)
{
const u32 caller_id = printk_caller_id();
/*
* If an earlier line was buffered, and we're a continuation
* write from the same process, try to add it to the buffer.
* write from the same context, try to add it to the buffer.
*/
if (cont.len) {
if (cont.owner == current && (lflags & LOG_CONT)) {
if (cont_add(facility, level, lflags, text, text_len))
if (cont.caller_id == caller_id && (lflags & LOG_CONT)) {
if (cont_add(caller_id, facility, level, lflags, text, text_len))
return text_len;
}
/* Otherwise, make sure it's flushed */
@ -1876,12 +1882,13 @@ static size_t log_output(int facility, int level, enum log_flags lflags, const c
/* If it doesn't end in a newline, try to buffer the current line */
if (!(lflags & LOG_NEWLINE)) {
if (cont_add(facility, level, lflags, text, text_len))
if (cont_add(caller_id, facility, level, lflags, text, text_len))
return text_len;
}
/* Store it in the record log */
return log_store(facility, level, lflags, 0, dict, dictlen, text, text_len);
return log_store(caller_id, facility, level, lflags, 0,
dict, dictlen, text, text_len);
}
/* Must be called under logbuf_lock. */