[PATCH 0/3] makedumpfile: harden parsing of old prink buffer

[PATCH 0/3] makedumpfile: harden parsing of old prink buffer

[Philipp Rudo]

Hi,

dumping the dmesg can cause an endless loop for the old prink mechanism (>
v3.5.0 and < v5.10.0) when the log_buf got corrupted. This series fixes those
cases by adding a cycle detection. The cycle detection is implemented in a
generic way so that it can be reused in other parts of makedumpfile.

Thanks
Philipp

Philipp Rudo (3):
  makedumpfile: add generic cycle detection
  makedumpfile: use pointer arithmetics for dump_dmesg
  makedumpfile: use cycle detection when parsing the prink log_buf

 Makefile       |  2 +-
 detect_cycle.c | 99 ++++++++++++++++++++++++++++++++++++++++++++++++++
 detect_cycle.h | 40 ++++++++++++++++++++
 makedumpfile.c | 65 +++++++++++++++++++++++++--------
 4 files changed, 190 insertions(+), 16 deletions(-)
 create mode 100644 detect_cycle.c
 create mode 100644 detect_cycle.h

-- 
2.35.1

[PATCH 1/3] makedumpfile: add generic cycle detection

[Philipp Rudo]

In order to work makedumpfile needs to interpret data read from the
dump. This can cause problems as the data from the dump cannot be
trusted (otherwise the kernel wouldn't have panicked in the first
place). This also means that every loop which stop condition depend on
data read from the dump has a chance to loop forever. Thus add a generic
cycle detection mechanism that allows to detect and handle such
situations appropriately.

For cycle detection use Brent's algorithm [1] as it has constant memory
usage. With this it can also be used in the kdump kernel without the
danger that it runs oom when iterating large data structures.
Furthermore it only depends on some pointer arithmetic. Thus the
performance impact (as long as no cycle was detected) should be
comparatively small.

[1] https://en.wikipedia.org/wiki/Cycle_detection#Brent's_algorithm

Suggested-by: Dave Wysochanski <dwysocha@redhat.com>
Signed-off-by: Philipp Rudo <prudo@redhat.com>
---
 Makefile       |  2 +-
 detect_cycle.c | 99 ++++++++++++++++++++++++++++++++++++++++++++++++++
 detect_cycle.h | 40 ++++++++++++++++++++
 3 files changed, 140 insertions(+), 1 deletion(-)
 create mode 100644 detect_cycle.c
 create mode 100644 detect_cycle.h

diff --git a/Makefile b/Makefile
index 9f9fd22..e9a474f 100644
--- a/Makefile
+++ b/Makefile
@@ -45,7 +45,7 @@ CFLAGS_ARCH += -m32
 endif
 
 SRC_BASE = makedumpfile.c makedumpfile.h diskdump_mod.h sadump_mod.h sadump_info.h
-SRC_PART = print_info.c dwarf_info.c elf_info.c erase_info.c sadump_info.c cache.c tools.c printk.c
+SRC_PART = print_info.c dwarf_info.c elf_info.c erase_info.c sadump_info.c cache.c tools.c printk.c detect_cycle.c
 OBJ_PART=$(patsubst %.c,%.o,$(SRC_PART))
 SRC_ARCH = arch/arm.c arch/arm64.c arch/x86.c arch/x86_64.c arch/ia64.c arch/ppc64.c arch/s390x.c arch/ppc.c arch/sparc64.c arch/mips64.c
 OBJ_ARCH=$(patsubst %.c,%.o,$(SRC_ARCH))
diff --git a/detect_cycle.c b/detect_cycle.c
new file mode 100644
index 0000000..6b551a7
--- /dev/null
+++ b/detect_cycle.c
@@ -0,0 +1,99 @@
+/*
+ * detect_cycle.c  --  Generic cycle detection using Brent's algorithm
+ *
+ * Created by: Philipp Rudo <prudo@redhat.com>
+ *
+ * Copyright (c) 2022 Red Hat, Inc. All rights reserved.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ */
+
+#include <stdlib.h>
+
+#include "detect_cycle.h"
+
+struct detect_cycle {
+	/* First entry of the list */
+	void *head;
+
+	/* Variables required by Brent's algorithm */
+	void *fast_p;
+	void *slow_p;
+	unsigned long length;
+	unsigned long power;
+
+	/* Function to get the next entry in the list */
+	dc_next_t next;
+
+	/* Private data passed to next */
+	void *data;
+};
+
+struct detect_cycle *dc_init(void *head, void *data, dc_next_t next)
+{
+	struct detect_cycle *new;
+
+	new = malloc(sizeof(*new));
+	if (!new)
+		return NULL;
+
+	new->next = next;
+	new->data = data;
+
+	new->head = head;
+	new->slow_p = head;
+	new->fast_p = head;
+	new->length = 0;
+	new->power  = 2;
+
+	return new;
+}
+
+int dc_next(struct detect_cycle *dc, void **next)
+{
+
+	if (dc->length == dc->power) {
+		dc->length = 0;
+		dc->power *= 2;
+		dc->slow_p = dc->fast_p;
+	}
+
+	dc->fast_p = dc->next(dc->fast_p, dc->data);
+	dc->length++;
+
+	if (dc->slow_p == dc->fast_p)
+		return 1;
+
+	*next = dc->fast_p;
+	return 0;
+}
+
+void dc_find_start(struct detect_cycle *dc, void **first, unsigned long *len)
+{
+	void *slow_p, *fast_p;
+	unsigned long tmp;
+
+	slow_p = fast_p = dc->head;
+	tmp = dc->length;
+
+	while (tmp) {
+		fast_p = dc->next(fast_p, dc->data);
+		tmp--;
+	}
+
+	while (slow_p != fast_p) {
+		slow_p = dc->next(slow_p, dc->data);
+		fast_p = dc->next(fast_p, dc->data);
+	}
+
+	*first = slow_p;
+	*len = dc->length;
+}
diff --git a/detect_cycle.h b/detect_cycle.h
new file mode 100644
index 0000000..2ca75c7
--- /dev/null
+++ b/detect_cycle.h
@@ -0,0 +1,40 @@
+/*
+ * detect_cycle.h  --  Generic cycle detection using Brent's algorithm
+ *
+ * Created by: Philipp Rudo <prudo@redhat.com>
+ *
+ * Copyright (c) 2022 Red Hat, Inc. All rights reserved.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ */
+
+struct detect_cycle;
+
+typedef void *(*dc_next_t)(void *prev, void *data);
+
+/*
+ * Initialize cycle detection.
+ * Returns a pointer to allocated struct detect_cycle. The caller is
+ * responsible to free the memory after use.
+ */
+struct detect_cycle *dc_init(void *head, void *data, dc_next_t next);
+
+/*
+ * Get next entry in the list using dc->next.
+ * Returns 1 when cycle was detected, 0 otherwise.
+ */
+int dc_next(struct detect_cycle *dc, void **next);
+
+/*
+ * Get the start and length of the cycle. Must only be called after cycle was
+ * detected by dc_next.
+ */
+void dc_find_start(struct detect_cycle *dc, void **first, unsigned long *len);
-- 
2.35.1

[PATCH 2/3] makedumpfile: use pointer arithmetics for dump_dmesg

[Philipp Rudo]

When parsing the printk buffer for the old printk mechanism (> v3.5.0+ and
< 5.10.0) a log entry is currently specified by the offset into the
buffer where the entry starts. Change this to use a pointers instead.
This is done in preparation for using the new cycle detection mechanism.

Signed-off-by: Philipp Rudo <prudo@redhat.com>
---
 makedumpfile.c | 25 +++++++++++--------------
 1 file changed, 11 insertions(+), 14 deletions(-)

diff --git a/makedumpfile.c b/makedumpfile.c
index 7ed9756..edf128b 100644
--- a/makedumpfile.c
+++ b/makedumpfile.c
@@ -5482,13 +5482,10 @@ dump_log_entry(char *logptr, int fp, const char *file_name)
  * get log record by index; idx must point to valid message.
  */
 static char *
-log_from_idx(unsigned int idx, char *logbuf)
+log_from_idx(char *logptr, char *logbuf)
 {
-	char *logptr;
 	unsigned int msglen;
 
-	logptr = logbuf + idx;
-
 	/*
 	 * A length == 0 record is the end of buffer marker.
 	 * Wrap around and return the message at the start of
@@ -5502,14 +5499,13 @@ log_from_idx(unsigned int idx, char *logbuf)
 	return logptr;
 }
 
-static long
-log_next(unsigned int idx, char *logbuf)
+static void *
+log_next(void *_logptr, void *_logbuf)
 {
-	char *logptr;
+	char *logptr = _logptr;
+	char *logbuf = _logbuf;
 	unsigned int msglen;
 
-	logptr = logbuf + idx;
-
 	/*
 	 * A length == 0 record is the end of buffer marker. Wrap around and
 	 * read the message at the start of the buffer as *this* one, and
@@ -5519,10 +5515,10 @@ log_next(unsigned int idx, char *logbuf)
 	msglen = USHORT(logptr + OFFSET(printk_log.len));
 	if (!msglen) {
 		msglen = USHORT(logbuf + OFFSET(printk_log.len));
-		return msglen;
+		return logbuf + msglen;
 	}
 
-	return idx + msglen;
+	return logptr + msglen;
 }
 
 int
@@ -5530,11 +5526,12 @@ dump_dmesg()
 {
 	int log_buf_len, length_log, length_oldlog, ret = FALSE;
 	unsigned long index, log_buf, log_end;
-	unsigned int idx, log_first_idx, log_next_idx;
+	unsigned int log_first_idx, log_next_idx;
 	unsigned long long first_idx_sym;
 	unsigned long log_end_2_6_24;
 	unsigned      log_end_2_6_25;
 	char *log_buffer = NULL, *log_ptr = NULL;
+	char *idx;
 
 	/*
 	 * log_end has been changed to "unsigned" since linux-2.6.25.
@@ -5681,8 +5678,8 @@ dump_dmesg()
 			ERRMSG("Can't open output file.\n");
 			goto out;
 		}
-		idx = log_first_idx;
-		while (idx != log_next_idx) {
+		idx = log_buffer + log_first_idx;
+		while (idx != log_buffer + log_next_idx) {
 			log_ptr = log_from_idx(idx, log_buffer);
 			if (!dump_log_entry(log_ptr, info->fd_dumpfile,
 					    info->name_dumpfile))
-- 
2.35.1

[PATCH 3/3] makedumpfile: use cycle detection when parsing the prink log_buf

[Philipp Rudo]

The old printk mechanism (> v3.5.0 and < v5.10.0) had a fixed size
buffer (log_buf) that contains all messages. The location for the next
message is stored in log_next_idx. In case the log_buf runs full
log_next_idx wraps around and starts overwriting old messages@the
beginning of the buffer. The wraparound is denoted by a message with
msg->len == 0.

Following the behavior described above blindly in makedumpfile is
dangerous as e.g. a memory corruption could overwrite (parts of) the
log_buf. If the corruption adds a message with msg->len == 0 this leads
to an endless loop when dumping the dmesg with makedumpfile appending
the messages up to the corruption over and over again to the output file
until file system is full. Fix this by using cycle detection and aboard
once one is detected.

While at it also verify that the index is within the log_buf and thus
guard against corruptions with msg->len != 0.

Fixes: 36c2458 ("[PATCH] --dump-dmesg fix for post 3.5 kernels.")
Reported-by: Audra Mitchell <aubaker@redhat.com>
Suggested-by: Dave Wysochanski <dwysocha@redhat.com>
Signed-off-by: Philipp Rudo <prudo@redhat.com>
---
 makedumpfile.c | 42 ++++++++++++++++++++++++++++++++++++++++--
 1 file changed, 40 insertions(+), 2 deletions(-)

diff --git a/makedumpfile.c b/makedumpfile.c
index edf128b..2738d16 100644
--- a/makedumpfile.c
+++ b/makedumpfile.c
@@ -15,6 +15,7 @@
  */
 #include "makedumpfile.h"
 #include "print_info.h"
+#include "detect_cycle.h"
 #include "dwarf_info.h"
 #include "elf_info.h"
 #include "erase_info.h"
@@ -5528,10 +5529,11 @@ dump_dmesg()
 	unsigned long index, log_buf, log_end;
 	unsigned int log_first_idx, log_next_idx;
 	unsigned long long first_idx_sym;
+	struct detect_cycle *dc = NULL;
 	unsigned long log_end_2_6_24;
 	unsigned      log_end_2_6_25;
 	char *log_buffer = NULL, *log_ptr = NULL;
-	char *idx;
+	char *idx, *next_idx;
 
 	/*
 	 * log_end has been changed to "unsigned" since linux-2.6.25.
@@ -5679,12 +5681,47 @@ dump_dmesg()
 			goto out;
 		}
 		idx = log_buffer + log_first_idx;
+		dc = dc_init(idx, log_buffer, log_next);
 		while (idx != log_buffer + log_next_idx) {
 			log_ptr = log_from_idx(idx, log_buffer);
 			if (!dump_log_entry(log_ptr, info->fd_dumpfile,
 					    info->name_dumpfile))
 				goto out;
-			idx = log_next(idx, log_buffer);
+			if (dc_next(dc, (void **) &next_idx)) {
+				unsigned long len;
+				char *first;
+
+				/* Clear everything we have already written... */
+				ftruncate(info->fd_dumpfile, 0);
+				lseek(info->fd_dumpfile, 0, SEEK_SET);
+
+				/* ...and only write up to the corruption. */
+				dc_find_start(dc, (void **) &first, &len);
+				idx = log_buffer + log_first_idx;
+				while (len) {
+					log_ptr = log_from_idx(idx, log_buffer);
+					if (!dump_log_entry(log_ptr,
+							    info->fd_dumpfile,
+							    info->name_dumpfile))
+						goto out;
+					idx = log_next(idx, log_buffer);
+					len--;
+				}
+				ERRMSG("Cycle when parsing dmesg detected.\n");
+				ERRMSG("The printk log_buf is most likely corrupted.\n");
+				ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
+				close_files_for_creating_dumpfile();
+				goto out;
+			}
+			if (next_idx < log_buffer ||
+			    next_idx > log_buffer + log_buf_len - SIZE(printk_log)) {
+				ERRMSG("Index outside log_buf detected.\n");
+				ERRMSG("The printk log_buf is most likely corrupted.\n");
+				ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
+				close_files_for_creating_dumpfile();
+				goto out;
+			}
+			idx = next_idx;
 		}
 		if (!close_files_for_creating_dumpfile())
 			goto out;
@@ -5694,6 +5731,7 @@ dump_dmesg()
 out:
 	if (log_buffer)
 		free(log_buffer);
+	free(dc);
 
 	return ret;
 }
-- 
2.35.1

[PATCH 0/3] makedumpfile: harden parsing of old prink buffer

[David Wysochanski]

On Mon, Mar 7, 2022 at 12:23 PM Philipp Rudo <prudo@redhat.com> wrote:
>
> Hi,
>
> dumping the dmesg can cause an endless loop for the old prink mechanism (>
> v3.5.0 and < v5.10.0) when the log_buf got corrupted. This series fixes those
> cases by adding a cycle detection. The cycle detection is implemented in a
> generic way so that it can be reused in other parts of makedumpfile.
>
> Thanks
> Philipp
>
> Philipp Rudo (3):
>   makedumpfile: add generic cycle detection
>   makedumpfile: use pointer arithmetics for dump_dmesg
>   makedumpfile: use cycle detection when parsing the prink log_buf
>
>  Makefile       |  2 +-
>  detect_cycle.c | 99 ++++++++++++++++++++++++++++++++++++++++++++++++++
>  detect_cycle.h | 40 ++++++++++++++++++++
>  makedumpfile.c | 65 +++++++++++++++++++++++++--------
>  4 files changed, 190 insertions(+), 16 deletions(-)
>  create mode 100644 detect_cycle.c
>  create mode 100644 detect_cycle.h
>
> --
> 2.35.1
>

You can add
Tested-by: Dave Wysochanski <dwysocha@redhat.com>

As I mentioned in the Red Hat bug, for my testing, I ran over 1,000
vmcores as a test set comparing "makedumpfile --dump-dmesg" output and
saw no difference.  Then I ran the one vmcore we found the loop on,
and with these patches the loop was correctly detected and
makedumpfile terminated rather than running forever.

I'm still reviewing code a bit and may have a few minor bits of
feedback in a few days.  However, I don't offhand see anything that
sticks out as wrong so far the code looks good.

Thanks for doing this patchset.

[PATCH 2/3] makedumpfile: use pointer arithmetics for dump_dmesg

[David Wysochanski]

On Mon, Mar 7, 2022 at 12:23 PM Philipp Rudo <prudo@redhat.com> wrote:
>
> When parsing the printk buffer for the old printk mechanism (> v3.5.0+ and
> < 5.10.0) a log entry is currently specified by the offset into the
> buffer where the entry starts. Change this to use a pointers instead.
> This is done in preparation for using the new cycle detection mechanism.
>
> Signed-off-by: Philipp Rudo <prudo@redhat.com>
> ---
>  makedumpfile.c | 25 +++++++++++--------------
>  1 file changed, 11 insertions(+), 14 deletions(-)
>
> diff --git a/makedumpfile.c b/makedumpfile.c
> index 7ed9756..edf128b 100644
> --- a/makedumpfile.c
> +++ b/makedumpfile.c
> @@ -5482,13 +5482,10 @@ dump_log_entry(char *logptr, int fp, const char *file_name)
>   * get log record by index; idx must point to valid message.
>   */
>  static char *
> -log_from_idx(unsigned int idx, char *logbuf)
> +log_from_idx(char *logptr, char *logbuf)

How about "log_from_ptr" since 'idx' has special name and you're
changing this to a ptr now?

>  {
> -       char *logptr;
>         unsigned int msglen;
>
> -       logptr = logbuf + idx;
> -
>         /*
>          * A length == 0 record is the end of buffer marker.
>          * Wrap around and return the message at the start of
> @@ -5502,14 +5499,13 @@ log_from_idx(unsigned int idx, char *logbuf)
>         return logptr;
>  }
>
> -static long
> -log_next(unsigned int idx, char *logbuf)
> +static void *
> +log_next(void *_logptr, void *_logbuf)
>  {
> -       char *logptr;
> +       char *logptr = _logptr;
> +       char *logbuf = _logbuf;
>         unsigned int msglen;
>
> -       logptr = logbuf + idx;
> -
>         /*
>          * A length == 0 record is the end of buffer marker. Wrap around and
>          * read the message at the start of the buffer as *this* one, and
> @@ -5519,10 +5515,10 @@ log_next(unsigned int idx, char *logbuf)
>         msglen = USHORT(logptr + OFFSET(printk_log.len));
>         if (!msglen) {
>                 msglen = USHORT(logbuf + OFFSET(printk_log.len));
> -               return msglen;
> +               return logbuf + msglen;
>         }
>
> -       return idx + msglen;
> +       return logptr + msglen;
>  }
>
>  int
> @@ -5530,11 +5526,12 @@ dump_dmesg()
>  {
>         int log_buf_len, length_log, length_oldlog, ret = FALSE;
>         unsigned long index, log_buf, log_end;
> -       unsigned int idx, log_first_idx, log_next_idx;
> +       unsigned int log_first_idx, log_next_idx;
>         unsigned long long first_idx_sym;
>         unsigned long log_end_2_6_24;
>         unsigned      log_end_2_6_25;
>         char *log_buffer = NULL, *log_ptr = NULL;
> +       char *idx;
>
>         /*
>          * log_end has been changed to "unsigned" since linux-2.6.25.
> @@ -5681,8 +5678,8 @@ dump_dmesg()
>                         ERRMSG("Can't open output file.\n");
>                         goto out;
>                 }
> -               idx = log_first_idx;
> -               while (idx != log_next_idx) {
> +               idx = log_buffer + log_first_idx;
> +               while (idx != log_buffer + log_next_idx) {

I would find another name other than "idx" here, maybe just "ptr"?


>                         log_ptr = log_from_idx(idx, log_buffer);
>                         if (!dump_log_entry(log_ptr, info->fd_dumpfile,
>                                             info->name_dumpfile))
> --
> 2.35.1
>

[PATCH 3/3] makedumpfile: use cycle detection when parsing the prink log_buf

[David Wysochanski]

On Mon, Mar 7, 2022 at 12:23 PM Philipp Rudo <prudo@redhat.com> wrote:
>
> The old printk mechanism (> v3.5.0 and < v5.10.0) had a fixed size
> buffer (log_buf) that contains all messages. The location for the next
> message is stored in log_next_idx. In case the log_buf runs full
> log_next_idx wraps around and starts overwriting old messages at the
> beginning of the buffer. The wraparound is denoted by a message with
> msg->len == 0.
>
> Following the behavior described above blindly in makedumpfile is
> dangerous as e.g. a memory corruption could overwrite (parts of) the
> log_buf. If the corruption adds a message with msg->len == 0 this leads
> to an endless loop when dumping the dmesg with makedumpfile appending
> the messages up to the corruption over and over again to the output file
> until file system is full. Fix this by using cycle detection and aboard
> once one is detected.
>
> While at it also verify that the index is within the log_buf and thus
> guard against corruptions with msg->len != 0.
>
> Fixes: 36c2458 ("[PATCH] --dump-dmesg fix for post 3.5 kernels.")
> Reported-by: Audra Mitchell <aubaker@redhat.com>
> Suggested-by: Dave Wysochanski <dwysocha@redhat.com>
> Signed-off-by: Philipp Rudo <prudo@redhat.com>
> ---
>  makedumpfile.c | 42 ++++++++++++++++++++++++++++++++++++++++--
>  1 file changed, 40 insertions(+), 2 deletions(-)
>
> diff --git a/makedumpfile.c b/makedumpfile.c
> index edf128b..2738d16 100644
> --- a/makedumpfile.c
> +++ b/makedumpfile.c
> @@ -15,6 +15,7 @@
>   */
>  #include "makedumpfile.h"
>  #include "print_info.h"
> +#include "detect_cycle.h"
>  #include "dwarf_info.h"
>  #include "elf_info.h"
>  #include "erase_info.h"
> @@ -5528,10 +5529,11 @@ dump_dmesg()
>         unsigned long index, log_buf, log_end;
>         unsigned int log_first_idx, log_next_idx;
>         unsigned long long first_idx_sym;
> +       struct detect_cycle *dc = NULL;
>         unsigned long log_end_2_6_24;
>         unsigned      log_end_2_6_25;
>         char *log_buffer = NULL, *log_ptr = NULL;
> -       char *idx;
> +       char *idx, *next_idx;
>

Would be clearer to call the above "next_ptr" rather than "next_idx"
(as far as I know 'index' refers to 32-bit quantities).
Same comment about the "idx" variable, maybe "ptr"?



>         /*
>          * log_end has been changed to "unsigned" since linux-2.6.25.
> @@ -5679,12 +5681,47 @@ dump_dmesg()
>                         goto out;
>                 }
>                 idx = log_buffer + log_first_idx;
> +               dc = dc_init(idx, log_buffer, log_next);
>                 while (idx != log_buffer + log_next_idx) {
>                         log_ptr = log_from_idx(idx, log_buffer);
>                         if (!dump_log_entry(log_ptr, info->fd_dumpfile,
>                                             info->name_dumpfile))
>                                 goto out;
> -                       idx = log_next(idx, log_buffer);
> +                       if (dc_next(dc, (void **) &next_idx)) {
> +                               unsigned long len;
> +                               char *first;
> +
> +                               /* Clear everything we have already written... */
> +                               ftruncate(info->fd_dumpfile, 0);
> +                               lseek(info->fd_dumpfile, 0, SEEK_SET);
> +

I'm not sure I understand why you're doing this.

> +                               /* ...and only write up to the corruption. */
> +                               dc_find_start(dc, (void **) &first, &len);
> +                               idx = log_buffer + log_first_idx;
> +                               while (len) {

I don't think this is correct.  It looks like "len" is the length of
the loop segment, correct?
But don't you want to print the whole buffer until the corruption?
That means you need to print both the non-loop segment plus the loop segment.
With the 'while(len)' you're only printing # of entries == loop segment.
Look at the diagram here:
https://listman.redhat.com/archives/crash-utility/2018-July/007582.html



> +                                       log_ptr = log_from_idx(idx, log_buffer);
> +                                       if (!dump_log_entry(log_ptr,
> +                                                           info->fd_dumpfile,
> +                                                           info->name_dumpfile))
> +                                               goto out;
> +                                       idx = log_next(idx, log_buffer);
> +                                       len--;
> +                               }
> +                               ERRMSG("Cycle when parsing dmesg detected.\n");
> +                               ERRMSG("The printk log_buf is most likely corrupted.\n");
> +                               ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
> +                               close_files_for_creating_dumpfile();
> +                               goto out;
> +                       }
> +                       if (next_idx < log_buffer ||
> +                           next_idx > log_buffer + log_buf_len - SIZE(printk_log)) {
> +                               ERRMSG("Index outside log_buf detected.\n");
> +                               ERRMSG("The printk log_buf is most likely corrupted.\n");
> +                               ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
> +                               close_files_for_creating_dumpfile();
> +                               goto out;
> +                       }
> +                       idx = next_idx;
>                 }
>                 if (!close_files_for_creating_dumpfile())
>                         goto out;
> @@ -5694,6 +5731,7 @@ dump_dmesg()
>  out:
>         if (log_buffer)
>                 free(log_buffer);
> +       free(dc);
>
>         return ret;
>  }
> --
> 2.35.1
>

[PATCH 3/3] makedumpfile: use cycle detection when parsing the prink log_buf

[Philipp Rudo]

Hi Dave,

On Wed, 9 Mar 2022 03:48:12 -0500
David Wysochanski <dwysocha@redhat.com> wrote:

> On Mon, Mar 7, 2022 at 12:23 PM Philipp Rudo <prudo@redhat.com> wrote:
> >
> > The old printk mechanism (> v3.5.0 and < v5.10.0) had a fixed size
> > buffer (log_buf) that contains all messages. The location for the next
> > message is stored in log_next_idx. In case the log_buf runs full
> > log_next_idx wraps around and starts overwriting old messages at the
> > beginning of the buffer. The wraparound is denoted by a message with
> > msg->len == 0.
> >
> > Following the behavior described above blindly in makedumpfile is
> > dangerous as e.g. a memory corruption could overwrite (parts of) the
> > log_buf. If the corruption adds a message with msg->len == 0 this leads
> > to an endless loop when dumping the dmesg with makedumpfile appending
> > the messages up to the corruption over and over again to the output file
> > until file system is full. Fix this by using cycle detection and aboard
> > once one is detected.
> >
> > While at it also verify that the index is within the log_buf and thus
> > guard against corruptions with msg->len != 0.
> >
> > Fixes: 36c2458 ("[PATCH] --dump-dmesg fix for post 3.5 kernels.")
> > Reported-by: Audra Mitchell <aubaker@redhat.com>
> > Suggested-by: Dave Wysochanski <dwysocha@redhat.com>
> > Signed-off-by: Philipp Rudo <prudo@redhat.com>
> > ---
> >  makedumpfile.c | 42 ++++++++++++++++++++++++++++++++++++++++--
> >  1 file changed, 40 insertions(+), 2 deletions(-)
> >
> > diff --git a/makedumpfile.c b/makedumpfile.c
> > index edf128b..2738d16 100644
> > --- a/makedumpfile.c
> > +++ b/makedumpfile.c
> > @@ -15,6 +15,7 @@
> >   */
> >  #include "makedumpfile.h"
> >  #include "print_info.h"
> > +#include "detect_cycle.h"
> >  #include "dwarf_info.h"
> >  #include "elf_info.h"
> >  #include "erase_info.h"
> > @@ -5528,10 +5529,11 @@ dump_dmesg()
> >         unsigned long index, log_buf, log_end;
> >         unsigned int log_first_idx, log_next_idx;
> >         unsigned long long first_idx_sym;
> > +       struct detect_cycle *dc = NULL;
> >         unsigned long log_end_2_6_24;
> >         unsigned      log_end_2_6_25;
> >         char *log_buffer = NULL, *log_ptr = NULL;
> > -       char *idx;
> > +       char *idx, *next_idx;
> >  
> 
> Would be clearer to call the above "next_ptr" rather than "next_idx"
> (as far as I know 'index' refers to 32-bit quantities).
> Same comment about the "idx" variable, maybe "ptr"?

Hmm... I stuck with idx as the kernel uses the same name. In my
opinion using the same name makes it easier to see that both variables
contain the same "quantity" even when the implementation is slightly
different (in the kernel idx is the offset in the log_buf just like it
was in makedumpfile before patch 2). But my opinion isn't very strong
on the naming. So when the consent is to rename the variable I'm open
to do it.

@Kazu: Do you have a preference here?

Same for your comments in patch 2.

> >         /*
> >          * log_end has been changed to "unsigned" since linux-2.6.25.
> > @@ -5679,12 +5681,47 @@ dump_dmesg()
> >                         goto out;
> >                 }
> >                 idx = log_buffer + log_first_idx;
> > +               dc = dc_init(idx, log_buffer, log_next);
> >                 while (idx != log_buffer + log_next_idx) {
> >                         log_ptr = log_from_idx(idx, log_buffer);
> >                         if (!dump_log_entry(log_ptr, info->fd_dumpfile,
> >                                             info->name_dumpfile))
> >                                 goto out;
> > -                       idx = log_next(idx, log_buffer);
> > +                       if (dc_next(dc, (void **) &next_idx)) {
> > +                               unsigned long len;
> > +                               char *first;
> > +
> > +                               /* Clear everything we have already written... */
> > +                               ftruncate(info->fd_dumpfile, 0);
> > +                               lseek(info->fd_dumpfile, 0, SEEK_SET);
> > +  
> 
> I'm not sure I understand why you're doing this.

That's because in every pass of the loop the entry is written to the
output file. So most likely the output file already contains more
than needed. Thus we somehow need to trim the file to the end of
the cycle. Thus I decided to go brute force and simply clear all
content from the file and write all we need a second time.

In our very specific case there are 2704 lines to the corruption. That
means that the function has already written 6798 (4095 + 2704 - 1) lines
till it detects the cycle. 
 
> > +                               /* ...and only write up to the corruption. */
> > +                               dc_find_start(dc, (void **) &first, &len);
> > +                               idx = log_buffer + log_first_idx;
> > +                               while (len) {  
> 
> I don't think this is correct.  It looks like "len" is the length of
> the loop segment, correct?
> But don't you want to print the whole buffer until the corruption?
> That means you need to print both the non-loop segment plus the loop segment.
> With the 'while(len)' you're only printing # of entries == loop segment.
> Look at the diagram here:
> https://listman.redhat.com/archives/crash-utility/2018-July/007582.html

True... I'll fix it in v2...

Thanks
Philipp

> 
> > +                                       log_ptr = log_from_idx(idx, log_buffer);
> > +                                       if (!dump_log_entry(log_ptr,
> > +                                                           info->fd_dumpfile,
> > +                                                           info->name_dumpfile))
> > +                                               goto out;
> > +                                       idx = log_next(idx, log_buffer);
> > +                                       len--;
> > +                               }
> > +                               ERRMSG("Cycle when parsing dmesg detected.\n");
> > +                               ERRMSG("The printk log_buf is most likely corrupted.\n");
> > +                               ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
> > +                               close_files_for_creating_dumpfile();
> > +                               goto out;
> > +                       }
> > +                       if (next_idx < log_buffer ||
> > +                           next_idx > log_buffer + log_buf_len - SIZE(printk_log)) {
> > +                               ERRMSG("Index outside log_buf detected.\n");
> > +                               ERRMSG("The printk log_buf is most likely corrupted.\n");
> > +                               ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
> > +                               close_files_for_creating_dumpfile();
> > +                               goto out;
> > +                       }
> > +                       idx = next_idx;
> >                 }
> >                 if (!close_files_for_creating_dumpfile())
> >                         goto out;
> > @@ -5694,6 +5731,7 @@ dump_dmesg()
> >  out:
> >         if (log_buffer)
> >                 free(log_buffer);
> > +       free(dc);
> >
> >         return ret;
> >  }
> > --
> > 2.35.1
> >  
> 

[PATCH 3/3] makedumpfile: use cycle detection when parsing the prink log_buf

[HAGIO KAZUHITO =?unknown-8bit?b?6JCp5bC+IOS4gOS7gQ==?=]

-----Original Message-----
> Hi Dave,
> 
> On Wed, 9 Mar 2022 03:48:12 -0500
> David Wysochanski <dwysocha@redhat.com> wrote:
> 
> > On Mon, Mar 7, 2022 at 12:23 PM Philipp Rudo <prudo@redhat.com> wrote:
> > >
> > > The old printk mechanism (> v3.5.0 and < v5.10.0) had a fixed size
> > > buffer (log_buf) that contains all messages. The location for the next
> > > message is stored in log_next_idx. In case the log_buf runs full
> > > log_next_idx wraps around and starts overwriting old messages at the
> > > beginning of the buffer. The wraparound is denoted by a message with
> > > msg->len == 0.
> > >
> > > Following the behavior described above blindly in makedumpfile is
> > > dangerous as e.g. a memory corruption could overwrite (parts of) the
> > > log_buf. If the corruption adds a message with msg->len == 0 this leads
> > > to an endless loop when dumping the dmesg with makedumpfile appending
> > > the messages up to the corruption over and over again to the output file
> > > until file system is full. Fix this by using cycle detection and aboard
> > > once one is detected.
> > >
> > > While at it also verify that the index is within the log_buf and thus
> > > guard against corruptions with msg->len != 0.
> > >
> > > Fixes: 36c2458 ("[PATCH] --dump-dmesg fix for post 3.5 kernels.")
> > > Reported-by: Audra Mitchell <aubaker@redhat.com>
> > > Suggested-by: Dave Wysochanski <dwysocha@redhat.com>
> > > Signed-off-by: Philipp Rudo <prudo@redhat.com>
> > > ---
> > >  makedumpfile.c | 42 ++++++++++++++++++++++++++++++++++++++++--
> > >  1 file changed, 40 insertions(+), 2 deletions(-)
> > >
> > > diff --git a/makedumpfile.c b/makedumpfile.c
> > > index edf128b..2738d16 100644
> > > --- a/makedumpfile.c
> > > +++ b/makedumpfile.c
> > > @@ -15,6 +15,7 @@
> > >   */
> > >  #include "makedumpfile.h"
> > >  #include "print_info.h"
> > > +#include "detect_cycle.h"
> > >  #include "dwarf_info.h"
> > >  #include "elf_info.h"
> > >  #include "erase_info.h"
> > > @@ -5528,10 +5529,11 @@ dump_dmesg()
> > >         unsigned long index, log_buf, log_end;
> > >         unsigned int log_first_idx, log_next_idx;
> > >         unsigned long long first_idx_sym;
> > > +       struct detect_cycle *dc = NULL;
> > >         unsigned long log_end_2_6_24;
> > >         unsigned      log_end_2_6_25;
> > >         char *log_buffer = NULL, *log_ptr = NULL;
> > > -       char *idx;
> > > +       char *idx, *next_idx;
> > >
> >
> > Would be clearer to call the above "next_ptr" rather than "next_idx"
> > (as far as I know 'index' refers to 32-bit quantities).
> > Same comment about the "idx" variable, maybe "ptr"?
> 
> Hmm... I stuck with idx as the kernel uses the same name. In my
> opinion using the same name makes it easier to see that both variables
> contain the same "quantity" even when the implementation is slightly
> different (in the kernel idx is the offset in the log_buf just like it
> was in makedumpfile before patch 2). But my opinion isn't very strong
> on the naming. So when the consent is to rename the variable I'm open
> to do it.
> 
> @Kazu: Do you have a preference here?

Personally I think it will be more readable to use "*ptr" for pointers
in this case, as Dave says.

Thanks,
Kazu

> 
> Same for your comments in patch 2.
> 
> > >         /*
> > >          * log_end has been changed to "unsigned" since linux-2.6.25.
> > > @@ -5679,12 +5681,47 @@ dump_dmesg()
> > >                         goto out;
> > >                 }
> > >                 idx = log_buffer + log_first_idx;
> > > +               dc = dc_init(idx, log_buffer, log_next);
> > >                 while (idx != log_buffer + log_next_idx) {
> > >                         log_ptr = log_from_idx(idx, log_buffer);
> > >                         if (!dump_log_entry(log_ptr, info->fd_dumpfile,
> > >                                             info->name_dumpfile))
> > >                                 goto out;
> > > -                       idx = log_next(idx, log_buffer);
> > > +                       if (dc_next(dc, (void **) &next_idx)) {
> > > +                               unsigned long len;
> > > +                               char *first;
> > > +
> > > +                               /* Clear everything we have already written... */
> > > +                               ftruncate(info->fd_dumpfile, 0);
> > > +                               lseek(info->fd_dumpfile, 0, SEEK_SET);
> > > +
> >
> > I'm not sure I understand why you're doing this.
> 
> That's because in every pass of the loop the entry is written to the
> output file. So most likely the output file already contains more
> than needed. Thus we somehow need to trim the file to the end of
> the cycle. Thus I decided to go brute force and simply clear all
> content from the file and write all we need a second time.
> 
> In our very specific case there are 2704 lines to the corruption. That
> means that the function has already written 6798 (4095 + 2704 - 1) lines
> till it detects the cycle.
> 
> > > +                               /* ...and only write up to the corruption. */
> > > +                               dc_find_start(dc, (void **) &first, &len);
> > > +                               idx = log_buffer + log_first_idx;
> > > +                               while (len) {
> >
> > I don't think this is correct.  It looks like "len" is the length of
> > the loop segment, correct?
> > But don't you want to print the whole buffer until the corruption?
> > That means you need to print both the non-loop segment plus the loop segment.
> > With the 'while(len)' you're only printing # of entries == loop segment.
> > Look at the diagram here:
> > https://listman.redhat.com/archives/crash-utility/2018-July/007582.html
> 
> True... I'll fix it in v2...
> 
> Thanks
> Philipp
> 
> >
> > > +                                       log_ptr = log_from_idx(idx, log_buffer);
> > > +                                       if (!dump_log_entry(log_ptr,
> > > +                                                           info->fd_dumpfile,
> > > +                                                           info->name_dumpfile))
> > > +                                               goto out;
> > > +                                       idx = log_next(idx, log_buffer);
> > > +                                       len--;
> > > +                               }
> > > +                               ERRMSG("Cycle when parsing dmesg detected.\n");
> > > +                               ERRMSG("The printk log_buf is most likely corrupted.\n");
> > > +                               ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
> > > +                               close_files_for_creating_dumpfile();
> > > +                               goto out;
> > > +                       }
> > > +                       if (next_idx < log_buffer ||
> > > +                           next_idx > log_buffer + log_buf_len - SIZE(printk_log)) {
> > > +                               ERRMSG("Index outside log_buf detected.\n");
> > > +                               ERRMSG("The printk log_buf is most likely corrupted.\n");
> > > +                               ERRMSG("log_buf = 0x%lx, idx = 0x%lx\n", log_buf, idx - log_buffer);
> > > +                               close_files_for_creating_dumpfile();
> > > +                               goto out;
> > > +                       }
> > > +                       idx = next_idx;
> > >                 }
> > >                 if (!close_files_for_creating_dumpfile())
> > >                         goto out;
> > > @@ -5694,6 +5731,7 @@ dump_dmesg()
> > >  out:
> > >         if (log_buffer)
> > >                 free(log_buffer);
> > > +       free(dc);
> > >
> > >         return ret;
> > >  }
> > > --
> > > 2.35.1
> > >
> >
> 
> 
> _______________________________________________
> kexec mailing list
> kexec at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/kexec

[PATCH 3/3] makedumpfile: use cycle detection when parsing the prink log_buf

[Philipp Rudo]

Hi Kazu,


On Fri, 11 Mar 2022 07:59:47 +0000
HAGIO KAZUHITO(?????) <k-hagio-ab@nec.com> wrote:

> -----Original Message-----
> > Hi Dave,
> > 
> > On Wed, 9 Mar 2022 03:48:12 -0500
> > David Wysochanski <dwysocha@redhat.com> wrote:
> >   
> > > On Mon, Mar 7, 2022 at 12:23 PM Philipp Rudo <prudo@redhat.com> wrote:  
> > > >
> > > > The old printk mechanism (> v3.5.0 and < v5.10.0) had a fixed size
> > > > buffer (log_buf) that contains all messages. The location for the next
> > > > message is stored in log_next_idx. In case the log_buf runs full
> > > > log_next_idx wraps around and starts overwriting old messages at the
> > > > beginning of the buffer. The wraparound is denoted by a message with
> > > > msg->len == 0.
> > > >
> > > > Following the behavior described above blindly in makedumpfile is
> > > > dangerous as e.g. a memory corruption could overwrite (parts of) the
> > > > log_buf. If the corruption adds a message with msg->len == 0 this leads
> > > > to an endless loop when dumping the dmesg with makedumpfile appending
> > > > the messages up to the corruption over and over again to the output file
> > > > until file system is full. Fix this by using cycle detection and aboard
> > > > once one is detected.
> > > >
> > > > While at it also verify that the index is within the log_buf and thus
> > > > guard against corruptions with msg->len != 0.
> > > >
> > > > Fixes: 36c2458 ("[PATCH] --dump-dmesg fix for post 3.5 kernels.")
> > > > Reported-by: Audra Mitchell <aubaker@redhat.com>
> > > > Suggested-by: Dave Wysochanski <dwysocha@redhat.com>
> > > > Signed-off-by: Philipp Rudo <prudo@redhat.com>
> > > > ---
> > > >  makedumpfile.c | 42 ++++++++++++++++++++++++++++++++++++++++--
> > > >  1 file changed, 40 insertions(+), 2 deletions(-)
> > > >
> > > > diff --git a/makedumpfile.c b/makedumpfile.c
> > > > index edf128b..2738d16 100644
> > > > --- a/makedumpfile.c
> > > > +++ b/makedumpfile.c
> > > > @@ -15,6 +15,7 @@
> > > >   */
> > > >  #include "makedumpfile.h"
> > > >  #include "print_info.h"
> > > > +#include "detect_cycle.h"
> > > >  #include "dwarf_info.h"
> > > >  #include "elf_info.h"
> > > >  #include "erase_info.h"
> > > > @@ -5528,10 +5529,11 @@ dump_dmesg()
> > > >         unsigned long index, log_buf, log_end;
> > > >         unsigned int log_first_idx, log_next_idx;
> > > >         unsigned long long first_idx_sym;
> > > > +       struct detect_cycle *dc = NULL;
> > > >         unsigned long log_end_2_6_24;
> > > >         unsigned      log_end_2_6_25;
> > > >         char *log_buffer = NULL, *log_ptr = NULL;
> > > > -       char *idx;
> > > > +       char *idx, *next_idx;
> > > >  
> > >
> > > Would be clearer to call the above "next_ptr" rather than "next_idx"
> > > (as far as I know 'index' refers to 32-bit quantities).
> > > Same comment about the "idx" variable, maybe "ptr"?  
> > 
> > Hmm... I stuck with idx as the kernel uses the same name. In my
> > opinion using the same name makes it easier to see that both variables
> > contain the same "quantity" even when the implementation is slightly
> > different (in the kernel idx is the offset in the log_buf just like it
> > was in makedumpfile before patch 2). But my opinion isn't very strong
> > on the naming. So when the consent is to rename the variable I'm open
> > to do it.
> > 
> > @Kazu: Do you have a preference here?  
> 
> Personally I think it will be more readable to use "*ptr" for pointers
> in this case, as Dave says.

ok, then I'll rename it in v2.

Thanks
Philipp