Messages in this thread | | | Date | Wed, 23 Dec 2015 12:57:32 +0900 | From | Sergey Senozhatsky <> | Subject | Re: [PATCH 1/7] printk: Hand over printing to console if printing too long |
| |
On (12/23/15 12:37), Sergey Senozhatsky wrote: > Date: Wed, 23 Dec 2015 12:37:24 +0900 > From: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> > To: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> > Cc: Jan Kara <jack@suse.cz>, Sergey Senozhatsky > <sergey.senozhatsky@gmail.com>, Andrew Morton <akpm@linux-foundation.org>, > Petr Mladek <pmladek@suse.cz>, KY Sri nivasan <kys@microsoft.com>, Steven > Rostedt <rostedt@goodmis.org>, linux-kernel@vger.kernel.org > Subject: Re: [PATCH 1/7] printk: Hand over printing to console if printing > too long > User-Agent: Mutt/1.5.24 (2015-08-30) > > On (12/23/15 10:54), Sergey Senozhatsky wrote: > > On (12/22/15 14:47), Jan Kara wrote: > > [..] > > > @@ -1803,10 +1869,24 @@ asmlinkage int vprintk_emit(int facility, int level, > > > logbuf_cpu = UINT_MAX; > > > raw_spin_unlock(&logbuf_lock); > > > lockdep_on(); > > > + /* > > > + * By default we print message to console asynchronously so that kernel > > > + * doesn't get stalled due to slow serial console. That can lead to > > > + * softlockups, lost interrupts, or userspace timing out under heavy > > > + * printing load. > > > + * > > > + * However we resort to synchronous printing of messages during early > > > + * boot, when oops is in progress, or when synchronous printing was > > > + * explicitely requested by kernel parameter. > > > + */ > > > + if (keventd_up() && !oops_in_progress && !sync_print) { > > > + __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT); > > > + irq_work_queue(this_cpu_ptr(&wake_up_klogd_work)); > > > + } else > > > + sync_print = true; > > oops, didn't have enough coffee... missed that `else sync_print = true' :( >
ah, never mind my previous email... it's a local variable, so the very next printk() happening right after bust_spinlocks(0) will irq_work_queue(). I'd prefer CPUs to print stacks rather than burn cpu cycles in `while (1) cpu_relax()' loop.
so
else { printk_sync = true; sync_print = true; /* and remove this local variable entirely may be*/ }
> > can we replace this oops_in_progress check with something more reliable? > > > > CPU0 CPU1 - CPUN > > panic() > > local_irq_disable() executing foo() with irqs disabled, > > console_verbose() or processing an extremely long irq handler. > > bust_spinlocks() > > oops_in_progress++
or we huge enough number of CPUs, `deep' stack traces, slow serial and CPU doing dump_stack() under raw_spin_lock(&stop_lock), so it can take longer than 1 second to print the stacks and thus panic CPU will set oops_in_progress back to 0.
> > smp_send_stop() > > > > bust_spinlocks() > > oops_in_progress-- ok, IPI arrives > > dump_stack()/printk()/etc from IPI_CPU_STOP > > "while (1) cpu_relax()" with irq/fiq disabled/halt/etc. > > > > smp_send_stop() wrapped in `oops_in_progress++/oops_in_progress--' is arch specific, > > and some platforms don't do any IPI-delivered (e.g. via num_online_cpus()) checks at > > all. Some do. For example, arm/arm64: > > > > void smp_send_stop(void) > > ... > > /* Wait up to one second for other CPUs to stop */ > > timeout = USEC_PER_SEC; > > while (num_online_cpus() > 1 && timeout--) > > udelay(1); > > > > if (num_online_cpus() > 1) > > pr_warn("SMP: failed to stop secondary CPUs\n"); > > ... > > > > > > so there are non-zero chances that IPI will arrive to CPU after 'oops_in_progress--', > > and thus dump_stack()/etc. happening on that/those cpu/cpus will be lost. > > > > > > bust_spinlocks(0) does > > ... > > if (--oops_in_progress == 0) > > wake_up_klogd(); > > ... > > > > but local cpu has irqs disabled and `panic_timeout' can be zero. > > > > How about setting 'sync_print' to 'true' in... > > bust_spinlocks() /* only set to true */ > > or > > console_verbose() /* um... may be... */ > > or > > having a separate one-liner for that > > > > void console_panic_mode(void) > > { > > sync_print = true;
printk_sync = true;
> > } > > > > and call it early in panic(), before we send out IPI_STOP.
-ss
| |