On 01/19/18 at 02:45pm, Sergey Senozhatsky wrote:
> 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.
>
If too many messages printed on screen, then the next flush will
still scroll up. I thought about adding an option to improve
printk_delay so it can delay every n lines, eg. 25 rows. Maybe that
idea works for this issue?
BTW, if kdump is used then we should avoid adding extra stuff in panic
path.
> 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
>
Thanks
Dave
_______________________________________________
kexec mailing list
kexec@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/kexec
