[PATCH 0/4] KDB: Fix dmesg command

July 20th, 2012 - 08:30 pm ET by Anton Vorontsov | Report spam

Hi all,

The dmesg command appears to be broken after the printk rework. The old
logic in the kdb code makes no sense in terms of current printk/logging
storage format, and KDB simply hangs forever upon entering 'dmesg'
command.

The first patch revives the command by switching to kmsg_dumper iterator.
As a side-effect, the code is now much more simpler.

A few changes were needed in the printk.c: we needed unlocked variant
of the kmsg_dumper iterator, but these can surely wait for 3.6.

It's probably too late even for the first patch to go to 3.5, but
I'll try to convince otherwise. :-) Here we go:

- The current code is broken for sure, and has no hope to work at
all. It is a regression;
- The new code works for me, and probably works for everyone else;
- If it compiles (and I urge everyone to compile-test it on your
setup), it hardly can make things worse.

Thanks!

include/linux/kmsg_dump.h | 16 +++++++
kernel/debug/kdb/kdb_main.c | 91 +++++++++++++++-
kernel/debug/kdb/kdb_private.h | 1 -
kernel/printk.c | 83 +++++++++++++++++++++++-
4 files changed, 104 insertions(+), 87 deletions(-)

Anton Vorontsov
Email: cbouatmailru@gmail.com
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Follow the discussion Replies

6 replies

Make a reply

Replies

#1 Anton Vorontsov

July 20th, 2012 - 08:30 pm ET | Report spam

dmesg command appears to be broken after the printk rework. The old logic
in kdb code makes no sense in terms of current printk/logging storage
format, and KDB simply hangs forever.

This patch revives the command by switching to kmsg_dumper iterator.

The code is now much more simpler and shorter.

Signed-off-by: Anton Vorontsov

kernel/debug/kdb/kdb_main.c | 91 ++++++++++++++++
1 file changed, 33 insertions(+), 58 deletions(-)

diff --git a/kernel/debug/kdb/kdb_main.c b/kernel/debug/kdb/kdb_main.c
index 67b847d..df17c93 100644
a/kernel/debug/kdb/kdb_main.c
+++ b/kernel/debug/kdb/kdb_main.c
@@ -14,6 +14,7 @@
#include <linux/ctype.h>
#include <linux/string.h>
#include <linux/kernel.h>
+#include <linux/kmsg_dump.h>
#include <linux/reboot.h>
#include <linux/sched.h>
#include <linux/sysrq.h>
@@ -2040,8 +2041,15 @@ static int kdb_env(int argc, const char **argv)
*/
static int kdb_dmesg(int argc, const char **argv)
{
- char *syslog_data[4], *start, *end, c = '\0', *p;
- int diag, logging, logsize, lines = 0, adjust = 0, n;
+ int diag;
+ int logging;
+ int lines = 0;
+ int adjust = 0;
+ int n = 0;
+ int skip = 0;
+ struct kmsg_dumper dumper = { .active = 1 };
+ size_t len;
+ char buf[201];

if (argc > 2)
return KDB_ARGCOUNT;
@@ -2064,22 +2072,10 @@ static int kdb_dmesg(int argc, const char **argv)
kdb_set(2, setargs);
}

- /* syslog_data[0,1] physical start, end+1. syslog_data[2,3]
- * logical start, end+1. */
- kdb_syslog_data(syslog_data);
- if (syslog_data[2] == syslog_data[3])
- return 0;
- logsize = syslog_data[1] - syslog_data[0];
- start = syslog_data[2];
- end = syslog_data[3];
-#define KDB_WRAP(p) (((p - syslog_data[0]) % logsize) + syslog_data[0])
- for (n = 0, p = start; p < end; ++p) {
- c = *KDB_WRAP(p);
- if (c == '')
- ++n;
- }
- if (c != '')
- ++n;
+ kmsg_dump_rewind(&dumper);
+ while (kmsg_dump_get_line(&dumper, 1, NULL, 0, NULL))
+ n++;
+
if (lines < 0) {
if (adjust >= n)
kdb_printf("buffer only contains %d lines, nothing "
@@ -2087,21 +2083,11 @@ static int kdb_dmesg(int argc, const char **argv)
else if (adjust - lines >= n)
kdb_printf("buffer only contains %d lines, last %d "
"lines printed", n, n - adjust);
- if (adjust) {
- for (; start < end && adjust; ++start) {
- if (*KDB_WRAP(start) == '')
- }
- if (start < end)
- ++start;
- }
- for (p = start; p < end && lines; ++p) {
- if (*KDB_WRAP(p) == '')
- ++lines;
- }
- end = p;
+ skip = adjust;
+ lines = abs(lines);
} else if (lines > 0) {
- int skip = n - (adjust + lines);
+ skip = n - lines - adjust;
+ lines = abs(lines);
if (adjust >= n) {
kdb_printf("buffer only contains %d lines, "
"nothing printed", n);
@@ -2112,35 +2098,24 @@ static int kdb_dmesg(int argc, const char **argv)
kdb_printf("buffer only contains %d lines, first "
"%d lines printed", n, lines);
}
- for (; start < end && skip; ++start) {
- if (*KDB_WRAP(start) == '')
- }
- for (p = start; p < end && lines; ++p) {
- if (*KDB_WRAP(p) == '')
- }
- end = p;
+ } else {
+ lines = n;
}
- /* Do a line at a time (max 200 chars) to reduce protocol overhead */
- c = '';
- while (start != end) {
- char buf[201];
- p = buf;
- if (KDB_FLAG(CMD_INTERRUPT))
- return 0;
- while (start < end && (c = *KDB_WRAP(start)) &&
- (p - buf) < sizeof(buf)-1) {
- ++start;
- *p++ = c;
- if (c == '')
- break;
+
+ if (skip >= n || skip < 0)
+ return 0;
+
+ kmsg_dump_rewind(&dumper);
+ while (kmsg_dump_get_line(&dumper, 1, buf, sizeof(buf), &len)) {
+ if (skip) {
+ skip--;
+ continue;
}
- *p = '\0';
- kdb_printf("%s", buf);
+ if (!lines--)
+ break;
+
+ kdb_printf("%.*s", (int)len - 1, buf);
}
- if (c != '')
- kdb_printf("");

return 0;
}
1.7.10.4

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Reply to this message

#2 Anton Vorontsov

July 20th, 2012 - 08:40 pm ET | Report spam

The locked variants are prone to deadlocks (suppose we got to the
debugger w/ the logbuf lock held), so let's switch to nolock
variants.

Signed-off-by: Anton Vorontsov

kernel/debug/kdb/kdb_main.c | 8 ++++-
1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/kernel/debug/kdb/kdb_main.c b/kernel/debug/kdb/kdb_main.c
index df17c93..1f91413 100644
a/kernel/debug/kdb/kdb_main.c
+++ b/kernel/debug/kdb/kdb_main.c
@@ -2072,8 +2072,8 @@ static int kdb_dmesg(int argc, const char **argv)
kdb_set(2, setargs);
}

- kmsg_dump_rewind(&dumper);
- while (kmsg_dump_get_line(&dumper, 1, NULL, 0, NULL))
+ kmsg_dump_rewind_nolock(&dumper);
+ while (kmsg_dump_get_line_nolock(&dumper, 1, NULL, 0, NULL))
n++;

if (lines < 0) {
@@ -2105,8 +2105,8 @@ static int kdb_dmesg(int argc, const char **argv)
if (skip >= n || skip < 0)
return 0;

- kmsg_dump_rewind(&dumper);
- while (kmsg_dump_get_line(&dumper, 1, buf, sizeof(buf), &len)) {
+ kmsg_dump_rewind_nolock(&dumper);
+ while (kmsg_dump_get_line_nolock(&dumper, 1, buf, sizeof(buf), &len)) {
if (skip) {
skip--;
continue;
1.7.10.4
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Reply to this message

#3 Anton Vorontsov

July 20th, 2012 - 08:40 pm ET | Report spam

If used from KDB, the locked variants are prone to deadlocks (suppose we
got to the debugger w/ the logbuf lock held).

So, we have to implement a few routines that grab no logbuf lock.

Yet we don't need these functions in modules, so we don't export them.

Signed-off-by: Anton Vorontsov

include/linux/kmsg_dump.h | 16 +++++++++++
kernel/printk.c | 68 ++++++++++++++++++++++++++++++++++++
2 files changed, 71 insertions(+), 13 deletions(-)

diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
index d6bd501..2e7a1e0 100644
a/include/linux/kmsg_dump.h
+++ b/include/linux/kmsg_dump.h
@@ -55,12 +55,17 @@ struct kmsg_dumper {
#ifdef CONFIG_PRINTK
void kmsg_dump(enum kmsg_dump_reason reason);

+bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
+ char *line, size_t size, size_t *len);
+
bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
char *line, size_t size, size_t *len);

bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
char *buf, size_t size, size_t *len);

+void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper);
+
void kmsg_dump_rewind(struct kmsg_dumper *dumper);

int kmsg_dump_register(struct kmsg_dumper *dumper);
@@ -71,6 +76,13 @@ static inline void kmsg_dump(enum kmsg_dump_reason reason)
{
}

+static inline bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper,
+ bool syslog, const char *line,
+ size_t size, size_t *len)
+{
+ return false;
+}
+
static inline bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
const char *line, size_t size, size_t *len)
{
@@ -83,6 +95,10 @@ static inline bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
return false;
}

+static inline void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
+{
+}
+
static inline void kmsg_dump_rewind(struct kmsg_dumper *dumper)
{
}
diff --git a/kernel/printk.c b/kernel/printk.c
index c812967..ac4bc9e 100644
a/kernel/printk.c
+++ b/kernel/printk.c
@@ -2510,7 +2510,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
@@ -2525,11 +2525,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;
@@ -2537,7 +2538,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;
@@ -2545,10 +2545,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);
@@ -2556,12 +2554,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);

/**
@@ -2664,6 +2691,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
*
@@ -2676,10 +2721,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);
1.7.10.4

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Reply to this message

#4 Anton Vorontsov

July 20th, 2012 - 08:40 pm ET | Report spam

The function is no longer needed, so remove it.

Signed-off-by: Anton Vorontsov

kernel/debug/kdb/kdb_private.h | 1 -
kernel/printk.c | 15
2 files changed, 16 deletions(-)

diff --git a/kernel/debug/kdb/kdb_private.h b/kernel/debug/kdb/kdb_private.h
index 47c4e56..392ec6a 100644
a/kernel/debug/kdb/kdb_private.h
+++ b/kernel/debug/kdb/kdb_private.h
@@ -205,7 +205,6 @@ extern char kdb_grep_string[];
extern int kdb_grep_leading;
extern int kdb_grep_trailing;
extern char *kdb_cmds[];
-extern void kdb_syslog_data(char *syslog_data[]);
extern unsigned long kdb_task_state_string(const char *);
extern char kdb_task_state_char (const struct task_struct *);
extern unsigned long kdb_task_state(const struct task_struct *p,
diff --git a/kernel/printk.c b/kernel/printk.c
index 177fa49..c812967 100644
a/kernel/printk.c
+++ b/kernel/printk.c
@@ -1192,21 +1192,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)
1.7.10.4

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Reply to this message

#5 Andrew Morton

July 23rd, 2012 - 07:20 pm ET | Report spam

On Fri, 20 Jul 2012 17:27:37 -0700
Anton Vorontsov wrote:

dmesg command appears to be broken after the printk rework. The old logic
in kdb code makes no sense in terms of current printk/logging storage
format, and KDB simply hangs forever.

This patch revives the command by switching to kmsg_dumper iterator.

The code is now much more simpler and shorter.

Signed-off-by: Anton Vorontsov

This one should me merged into 3.5.1 methinks. Note that it has been
merged into mainline without a -stable tag.

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Reply to this message

Create a new topicNext page

Make a reply

Make your own search

[PATCH 0/4] KDB: Fix dmesg command

Similar topics

Replies