Re: [PATCH] print kdump kernel loaded status in stack dump

From: Sergey Senozhatsky
Date: Fri Jan 19 2018 - 00:45:54 EST


On (01/18/18 10:02), Andi Kleen wrote:
> Dave Young <dyoung@xxxxxxxxxx> writes:
> > printk("%sHardware name: %s\n",
> > log_lvl, dump_stack_arch_desc_str);
> > + if (kexec_crash_loaded())
> > + printk("%skdump kernel loaded\n", log_lvl);
>
> Oops/warnings are getting longer and longer, often scrolling away
> from the screen, and if the kernel crashes backscroll does not work
> anymore, so precious information is lost.

true. I even ended up having a console_reflush_on_panic() function. it
simply re-prints with a delay [so I can at least read the oops] logbuf
entries every once in a while, staring with the first oops_in_progress
record.

something like below [it's completely hacked up, but at least gives
an idea]

---

include/linux/console.h | 1 +
kernel/panic.c | 7 +++++++
kernel/printk/printk.c | 39 ++++++++++++++++++++++++++++++++++++++-
3 files changed, 46 insertions(+), 1 deletion(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index b8920a031a3e..502e3f539448 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -168,6 +168,7 @@ extern void console_unlock(void);
extern void console_conditional_schedule(void);
extern void console_unblank(void);
extern void console_flush_on_panic(void);
+extern void console_reflush_on_panic(void);
extern struct tty_driver *console_device(int *);
extern void console_stop(struct console *);
extern void console_start(struct console *);
diff --git a/kernel/panic.c b/kernel/panic.c
index 2cfef408fec9..39cd59bbfaab 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -137,6 +137,7 @@ void panic(const char *fmt, ...)
va_list args;
long i, i_next = 0;
int state = 0;
+ int reflush_tick = 0;
int old_cpu, this_cpu;
bool _crash_kexec_post_notifiers = crash_kexec_post_notifiers;

@@ -298,6 +299,12 @@ void panic(const char *fmt, ...)
i_next = i + 3600 / PANIC_BLINK_SPD;
}
mdelay(PANIC_TIMER_STEP);
+
+ reflush_tick++;
+ if (reflush_tick == 32) { /* don't reflush too often */
+ console_reflush_on_panic();
+ reflush_tick = 0;
+ }
}
}

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 9cb943c90d98..ef3f28d4c741 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -426,6 +426,10 @@ static u32 log_next_idx;
static u64 console_seq;
static u32 console_idx;

+/* index and sequence number of the record which started the oops print out */
+static u64 log_oops_seq;
+static u32 log_oops_idx;
+
/* the next printk record to read after the last 'clear' command */
static u64 clear_seq;
static u32 clear_idx;
@@ -1736,6 +1740,15 @@ static inline void printk_delay(void)
}
}

+/*
+ * Why do we have printk_delay() in vprintk_emit()
+ * and not in console_unlock()?
+ */
+static inline void console_unlock_delay(void)
+{
+ printk_delay();
+}
+
/*
* Continuation lines are buffered, and not committed to the record buffer
* until the line is complete, or a race forces it. The line fragments
@@ -1849,6 +1862,7 @@ asmlinkage int vprintk_emit(int facility, int level,

/* This stops the holder of console_sem just where we want him */
logbuf_lock_irqsave(flags);
+
/*
* The printf needs to come first; we need the syslog
* prefix which might be passed-in as a parameter.
@@ -1890,7 +1904,11 @@ asmlinkage int vprintk_emit(int facility, int level,
lflags |= LOG_PREFIX|LOG_NEWLINE;

printed_len = log_output(facility, level, lflags, dict, dictlen, text, text_len);
-
+ /* Oops... */
+ if (oops_in_progress && !log_oops_seq) {
+ log_oops_seq = log_next_seq;
+ log_oops_idx = log_next_idx;
+ }
logbuf_unlock_irqrestore(flags);

/* If called from the scheduler, we can not call up(). */
@@ -2396,6 +2414,7 @@ void console_unlock(void)

stop_critical_timings(); /* don't trace print latency */
call_console_drivers(ext_text, ext_len, text, len);
+ console_unlock_delay();
start_critical_timings();

if (console_lock_spinning_disable_and_check()) {
@@ -2495,6 +2514,24 @@ void console_flush_on_panic(void)
console_unlock();
}

+/**
+ * console_reflush_on_panic - re-flush console content starting from the
+ * first oops_in_progress record
+ */
+void console_reflush_on_panic(void)
+{
+ unsigned long flags;
+
+ logbuf_lock_irqsave(flags);
+ console_seq = log_oops_seq;
+ console_idx = log_oops_idx;
+ logbuf_unlock_irqrestore(flags);
+
+ if (!printk_delay_msec)
+ printk_delay_msec = 273; /* I can't read any faster */
+ console_flush_on_panic();
+}
+
/*
* Return the console tty driver structure and its associated index
*/
--
2.16.0