The check for free space in the log buffer always passes when "first_seq"
and "next_seq" are equal. In theory, it might cause writing outside of
the log buffer.
Fortunately, the current usage looks safe because the used "text" and "dict"
buffers are quite limited. See the second patch for more details.
Anyway, it is better to be on the safe side and add a check. An easy
solution is done in the 2nd patch and it is improved in the 4th patch.
5th patch fixes the computation of the printed message length.
1st and 3rd patches just do some code refactoring to make the other patches
easier.
The patches can be applied against both linux.git and linux-next.git.
Just a heads up. These patches were created when working safe printk
in NMI context. I have resolved most problems, including my sickness,
and should be able to send the NMI stuff soon.
Petr Mladek (5):
printk: Split code for making free space in the log buffer
printk: Ignore too long messages
printk: Split message size computation
printk: Shrink too long messages
printk: Return really stored message length
kernel/printk/printk.c | 144 ++++++++++++++++++++++++++++++++++++++-----------
1 file changed, 113 insertions(+), 31 deletions(-)
--
1.8.4
There will be needed some fixes in the check for free space. They will
be easier if the code is moved outside of the quite long log_store()
function.
This patch does not change the existing behavior.
Signed-off-by: Petr Mladek <[email protected]>
---
kernel/printk/printk.c | 44 +++++++++++++++++++++++++++++---------------
1 file changed, 29 insertions(+), 15 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a45b50962295..cc7d7defce24 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -297,6 +297,34 @@ static u32 log_next(u32 idx)
return idx + msg->len;
}
+/* check whether there is enough free space for the given message */
+static int logbuf_has_space(u32 msg_size)
+{
+ u32 free;
+
+ if (log_next_idx > log_first_idx)
+ free = max(log_buf_len - log_next_idx, log_first_idx);
+ else
+ free = log_first_idx - log_next_idx;
+
+ /*
+ * We need space also for an empty header that signalizes wrapping
+ * of the buffer.
+ */
+ return free >= msg_size + sizeof(struct printk_log);
+}
+
+static void log_make_free_space(u32 msg_size)
+{
+ while (log_first_seq < log_next_seq) {
+ if (logbuf_has_space(msg_size))
+ return;
+ /* drop old messages until we have enough continuous space */
+ log_first_idx = log_next(log_first_idx);
+ log_first_seq++;
+ }
+}
+
/* insert record into the buffer, discard old ones, update heads */
static void log_store(int facility, int level,
enum log_flags flags, u64 ts_nsec,
@@ -311,21 +339,7 @@ static void log_store(int facility, int level,
pad_len = (-size) & (LOG_ALIGN - 1);
size += pad_len;
- while (log_first_seq < log_next_seq) {
- u32 free;
-
- if (log_next_idx > log_first_idx)
- free = max(log_buf_len - log_next_idx, log_first_idx);
- else
- free = log_first_idx - log_next_idx;
-
- if (free >= size + sizeof(struct printk_log))
- break;
-
- /* drop old messages until we have enough contiuous space */
- log_first_idx = log_next(log_first_idx);
- log_first_seq++;
- }
+ log_make_free_space(size);
if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
/*
--
1.8.4
There was no check for too long messages. The check for free space always passed
when first_seq and next_seq were equal. Enough free space was not guaranteed,
though.
log_store() might be called to store messages up to 64kB + 64kB + 16B. This is
sum of maximal text_len, dict_len values, and the size of the structure
printk_log.
On the other hand, the minimal size for the main log buffer currently is 4kB
and it is enforced only by Kconfig.
The good news is that the usage looks safe right now. log_store() is called only
from vprintk_emit() and cont_flush(). Here the "text" part is always passed
via a static buffer and the length is limited to LOG_LINE_MAX which is 1024.
The "dict" part is NULL in most cases. The only exceptions is when
vprintk_emit() is called from printk_emit() and dev_vprintk_emit().
But printk_emit() is currently used only in devkmsg_writev() and here
"dict" is NULL as well. In dev_vprintk_emit(), "dict" is limited by the
static buffer "hdr" of the size 128 bytes. It meas that the current maximal
printed text is 1024B + 128B + 16B and it always fit the log buffer.
But it is only matter of time when someone calls printk_emit() with unsafe
parameters, especially the "dict" one.
This patch adds a check for the free space when the buffer is empty. It reuses
the already existing log_has_space() function but it has to add an extra
parameter. It defines whether the buffer is empty. Note that the same values
of "first_idx" and "next_idx" might also mean that the buffer is full.
If the buffer is empty, we must respect the current position of the
indexes. We cannot reset them to the beginning of the buffer. Otherwise,
the functions reading the buffer would get crazy.
The question is what to do when the message is too long. This patch uses the
easiest solution and just ignores the problematic message. Let's do something
better in a followup patch.
Signed-off-by: Petr Mladek <[email protected]>
---
kernel/printk/printk.c | 30 +++++++++++++++++++++++-------
1 file changed, 23 insertions(+), 7 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index cc7d7defce24..5de686b6b9e1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -297,12 +297,20 @@ static u32 log_next(u32 idx)
return idx + msg->len;
}
-/* check whether there is enough free space for the given message */
-static int logbuf_has_space(u32 msg_size)
+/*
+ * Check whether there is enough free space for the given message.
+ *
+ * The same values of first_idx and next_idx mean that the buffer
+ * is either empty or full.
+ *
+ * If the buffer is empty, we must respect the position of the indexes.
+ * They cannot be reset to the beginning of the buffer.
+ */
+static int logbuf_has_space(u32 msg_size, bool empty)
{
u32 free;
- if (log_next_idx > log_first_idx)
+ if (log_next_idx > log_first_idx || empty)
free = max(log_buf_len - log_next_idx, log_first_idx);
else
free = log_first_idx - log_next_idx;
@@ -314,15 +322,21 @@ static int logbuf_has_space(u32 msg_size)
return free >= msg_size + sizeof(struct printk_log);
}
-static void log_make_free_space(u32 msg_size)
+static int log_make_free_space(u32 msg_size)
{
while (log_first_seq < log_next_seq) {
- if (logbuf_has_space(msg_size))
- return;
+ if (logbuf_has_space(msg_size, false))
+ return 0;
/* drop old messages until we have enough continuous space */
log_first_idx = log_next(log_first_idx);
log_first_seq++;
}
+
+ /* sequence numbers are equal, so the log buffer is empty */
+ if (logbuf_has_space(msg_size, true))
+ return 0;
+
+ return -ENOMEM;
}
/* insert record into the buffer, discard old ones, update heads */
@@ -339,7 +353,9 @@ static void log_store(int facility, int level,
pad_len = (-size) & (LOG_ALIGN - 1);
size += pad_len;
- log_make_free_space(size);
+ /* if message does not fit empty log buffer, ignore it */
+ if (log_make_free_space(size))
+ return;
if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
/*
--
1.8.4
We will want to recompute the message size when shrinking too long messages.
Let's put the code into separate function.
The side effect of setting "pad_len" is not nice but it is worth removing
the code duplication. Note that I will probably have one more usage for this
function when handling messages safe way in NMI context.
This patch does not change the existing behavior.
Signed-off-by: Petr Mladek <[email protected]>
---
kernel/printk/printk.c | 16 +++++++++++++---
1 file changed, 13 insertions(+), 3 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 5de686b6b9e1..7416dfad0a28 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -339,6 +339,18 @@ static int log_make_free_space(u32 msg_size)
return -ENOMEM;
}
+/* compute the message size including the padding bytes */
+static u32 msg_used_size(u16 text_len, u16 dict_len, u32 *pad_len)
+{
+ u32 size;
+
+ size = sizeof(struct printk_log) + text_len + dict_len;
+ *pad_len = (-size) & (LOG_ALIGN - 1);
+ size += *pad_len;
+
+ return size;
+}
+
/* insert record into the buffer, discard old ones, update heads */
static void log_store(int facility, int level,
enum log_flags flags, u64 ts_nsec,
@@ -349,9 +361,7 @@ static void log_store(int facility, int level,
u32 size, pad_len;
/* number of '\0' padding bytes to next message */
- size = sizeof(struct printk_log) + text_len + dict_len;
- pad_len = (-size) & (LOG_ALIGN - 1);
- size += pad_len;
+ size = msg_used_size(text_len, dict_len, &pad_len);
/* if message does not fit empty log buffer, ignore it */
if (log_make_free_space(size))
--
1.8.4
We might want to print at least part of too long messages and add some warning
for debugging purpose.
The question is how long the shrunken message should be. If we use the whole
buffer, it might get rotated too soon. Let's try to use only 1/4 of the buffer
for now.
Also shrink the whole dictionary. We do not want to parse it or break it in the
middle of some pair of values. It would not cause any real harm but still.
Signed-off-by: Petr Mladek <[email protected]>
---
kernel/printk/printk.c | 42 +++++++++++++++++++++++++++++++++++++++---
1 file changed, 39 insertions(+), 3 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 7416dfad0a28..68a6950ae9de 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -351,6 +351,32 @@ static u32 msg_used_size(u16 text_len, u16 dict_len, u32 *pad_len)
return size;
}
+/*
+ * Define how much of the log buffer we could take at maximum. The value
+ * must be greater than two. Note that only half of the buffer is available
+ * when the index points to the middle.
+ */
+#define MAX_LOG_TAKE_PART 4
+static const char trunc_msg[] = "<truncated>";
+
+static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
+ u16 *dict_len, u32 *pad_len)
+{
+ /*
+ * The message should not take the whole buffer. Otherwise, it might
+ * get removed too soon.
+ */
+ u32 max_text_len = log_buf_len / MAX_LOG_TAKE_PART;
+ if (*text_len > max_text_len)
+ *text_len = max_text_len;
+ /* enable the warning message */
+ *trunc_msg_len = strlen(trunc_msg);
+ /* disable the "dict" completely */
+ *dict_len = 0;
+ /* compute the size again, count also the warning message */
+ return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len);
+}
+
/* insert record into the buffer, discard old ones, update heads */
static void log_store(int facility, int level,
enum log_flags flags, u64 ts_nsec,
@@ -359,13 +385,19 @@ static void log_store(int facility, int level,
{
struct printk_log *msg;
u32 size, pad_len;
+ u16 trunc_msg_len = 0;
/* number of '\0' padding bytes to next message */
size = msg_used_size(text_len, dict_len, &pad_len);
- /* if message does not fit empty log buffer, ignore it */
- if (log_make_free_space(size))
- return;
+ if (log_make_free_space(size)) {
+ /* truncate the message if it is too long for empty buffer */
+ size = truncate_msg(&text_len, &trunc_msg_len,
+ &dict_len, &pad_len);
+ /* survive when the log buffer is too small for trunc_msg */
+ if (log_make_free_space(size))
+ return;
+ }
if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
/*
@@ -381,6 +413,10 @@ static void log_store(int facility, int level,
msg = (struct printk_log *)(log_buf + log_next_idx);
memcpy(log_text(msg), text, text_len);
msg->text_len = text_len;
+ if (trunc_msg_len) {
+ memcpy(log_text(msg) + text_len, trunc_msg, trunc_msg_len);
+ msg->text_len += trunc_msg_len;
+ }
memcpy(log_dict(msg), dict, dict_len);
msg->dict_len = dict_len;
msg->facility = facility;
--
1.8.4
I wonder if anyone uses printk return value but it is there and should be
counted correctly.
This patch modifies log_store() to return the number of really stored bytes
from the 'text' part. Also it handles the return value in vprintk_emit().
Note that log_store() is used also in cont_flush() but we could ignore the
return value there. The function works with characters that were already
counted earlier. In addition, the store could newer fail here because the
length of the printed text is limited by the "cont" buffer and "dict" is NULL.
Signed-off-by: Petr Mladek <[email protected]>
---
kernel/printk/printk.c | 36 +++++++++++++++++++++---------------
1 file changed, 21 insertions(+), 15 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 68a6950ae9de..d3aa0c92b28b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -378,10 +378,10 @@ static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
}
/* insert record into the buffer, discard old ones, update heads */
-static void log_store(int facility, int level,
- enum log_flags flags, u64 ts_nsec,
- const char *dict, u16 dict_len,
- const char *text, u16 text_len)
+static int log_store(int facility, int level,
+ enum log_flags flags, u64 ts_nsec,
+ const char *dict, u16 dict_len,
+ const char *text, u16 text_len)
{
struct printk_log *msg;
u32 size, pad_len;
@@ -396,7 +396,7 @@ static void log_store(int facility, int level,
&dict_len, &pad_len);
/* survive when the log buffer is too small for trunc_msg */
if (log_make_free_space(size))
- return;
+ return 0;
}
if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
@@ -432,6 +432,8 @@ static void log_store(int facility, int level,
/* insert message */
log_next_idx += msg->len;
log_next_seq++;
+
+ return msg->text_len;
}
#ifdef CONFIG_SECURITY_DMESG_RESTRICT
@@ -1606,10 +1608,10 @@ asmlinkage int vprintk_emit(int facility, int level,
"BUG: recent printk recursion!";
recursion_bug = 0;
- printed_len += strlen(recursion_msg);
+ text_len = strlen(recursion_msg);
/* emit KERN_CRIT message */
- log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
- NULL, 0, recursion_msg, printed_len);
+ printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
+ NULL, 0, recursion_msg, text_len);
}
/*
@@ -1662,9 +1664,12 @@ asmlinkage int vprintk_emit(int facility, int level,
cont_flush(LOG_NEWLINE);
/* buffer line if possible, otherwise store it right away */
- if (!cont_add(facility, level, text, text_len))
- log_store(facility, level, lflags | LOG_CONT, 0,
- dict, dictlen, text, text_len);
+ if (cont_add(facility, level, text, text_len))
+ printed_len += text_len;
+ else
+ printed_len += log_store(facility, level,
+ lflags | LOG_CONT, 0,
+ dict, dictlen, text, text_len);
} else {
bool stored = false;
@@ -1683,11 +1688,12 @@ asmlinkage int vprintk_emit(int facility, int level,
cont_flush(LOG_NEWLINE);
}
- if (!stored)
- log_store(facility, level, lflags, 0,
- dict, dictlen, text, text_len);
+ if (stored)
+ printed_len += text_len;
+ else
+ printed_len += log_store(facility, level, lflags, 0,
+ dict, dictlen, text, text_len);
}
- printed_len += text_len;
/*
* Try to acquire and then immediately release the console semaphore.
--
1.8.4