On Sat 19-07-14 00:50:05, Andreas Bombe wrote:
> On Thu, Jul 17, 2014 at 10:31:37AM +0200, Jan Kara wrote:
> > On Wed 16-07-14 23:34:08, Andreas Bombe wrote:
> > > On Mon, Jul 14, 2014 at 10:35:27AM +0200, Jan Kara wrote:
> > > > On Sun 29-06-14 00:50:50, Andreas Bombe wrote:
> > > > > None of the post 3.15 kernel boot for me. They all hang at the GRUB
> > > > > screen telling me it loaded and started the kernel, but the kernel
> > > > > itself stops before it prints anything (or even replaces the GRUB
> > > > > background graphics).
> > > > >
> > > > > I bisected it down to 939f04bec1a4ef6ba4370b0f34b01decc844b1b1
> > > > > "printk:
> > > > > enable interrupts before calling console_trylock_for_printk()".
> > > > > Reverting that patch on the latest kernel (git 24b414d5a7) allows me
> > > > > to
> > > > > boot normally. I fixed the conflict in the revert by leaving in the
> > > > > "if
> > > > > (in_sched) return printed_len;".
> > > > >
> > > > > I have the "early printk via the EFI framebuffer" option enabled,
> > > > > disabling it made no difference however.
> > > > Thanks for report. I've been on vacation so I'm replying with a
> > > > delay. I
> > > > believe this is one of the issues where this patch just uncovers
> > > > underlying
> > > > problem - I belive lockdep tries to report some locking issue in console
> > > > driver code (this patch increased lockdep coverage of console driver
> > > > code)
> > > > however we are holding some locks in printk code which make lockdep
> > > > deadlock. Can you try running with the attached patch?
> > >
> > > EUNABLE
> > >
> > > You forgot to attach a patch.
> > Bah, sorry. Attaching now.
>
> I don't see anything in /sys/kernel/debug/tracing/trace_pipe or
> .../trace (besides the header) with your patch applied. In case you
> meant to test it with the problematic printk change, I also tried with
> the revert reverted. That still hangs as before without any error report
> to see.
Yes, I meant testing my lockdep patch with the problematic printk change.
Thanks for having a look. I'm puzzled why it didn't help.
> I checked the kernel logs and there is also no lockdep report anywhere.
> I get the "trace_printk() being used" notice but nothing else of
> interest around there. Though the notice should mean trace_printk() was
> used at least once?
Yes. Anyway, I'd be grateful if you could run one more test for me so
that I can better understand what's going on. Can you take recent vanilla
kernel (with the revert) and apply attached patch to it? It again enables
interrupts when calling console_unlock() but keeps lockdep coverage
unchanged. It helped Sasha so I want to see whether your case is similar or
different. Thanks!
Honza
--
Jan Kara <j...@suse.cz>
SUSE Labs, CR
>From c73d4093c3fd5013dbf5baccd495d6db24de31cc Mon Sep 17 00:00:00 2001
From: Jan Kara <j...@suse.cz>
Date: Wed, 4 Jun 2014 16:11:37 -0700
Subject: [PATCH] printk: enable interrupts before calling
console_trylock_for_printk()
We need interrupts disabled when calling console_trylock_for_printk()
only so that cpu id we pass to can_use_console() remains valid (for
other things console_sem provides all the exclusion we need and
deadlocks on console_sem due to interrupts are impossible because we use
down_trylock()). However if we are rescheduled, we are guaranteed to
run on an online cpu so we can easily just get the cpu id in
can_use_console().
We can lose a bit of performance when we enable interrupts in
vprintk_emit() and then disable them again in console_unlock() but OTOH
it can somewhat reduce interrupt latency caused by console_unlock().
We avoid calling console_unlock() from vprintk_emit() with lockdep
enabled as that has unveiled quite some bugs leading to system freezes
during boot (e.g. https://lkml.org/lkml/2014/5/30/242).
Signed-off-by: Jan Kara <j...@suse.cz>
---
kernel/printk/printk.c | 31 +++++++++++++++++++++----------
1 file changed, 21 insertions(+), 10 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 13e839dbca07..fe4154d83fe4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1416,10 +1416,9 @@ static int have_callable_console(void)
/*
* Can we actually use the console at this time on this cpu?
*
- * Console drivers may assume that per-cpu resources have
- * been allocated. So unless they're explicitly marked as
- * being able to cope (CON_ANYTIME) don't call them until
- * this CPU is officially up.
+ * Console drivers may assume that per-cpu resources have been allocated. So
+ * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't
+ * call them until this CPU is officially up.
*/
static inline int can_use_console(unsigned int cpu)
{
@@ -1432,8 +1431,10 @@ static inline int can_use_console(unsigned int cpu)
* console_lock held, and 'console_locked' set) if it
* is successful, false otherwise.
*/
-static int console_trylock_for_printk(unsigned int cpu)
+static int console_trylock_for_printk(void)
{
+ unsigned int cpu = smp_processor_id();
+
if (!console_trylock())
return 0;
/*
@@ -1608,7 +1609,8 @@ asmlinkage int vprintk_emit(int facility, int level,
*/
if (!oops_in_progress && !lockdep_recursing(current)) {
recursion_bug = 1;
- goto out_restore_irqs;
+ local_irq_restore(flags);
+ return 0;
}
zap_locks();
}
@@ -1716,21 +1718,30 @@ asmlinkage int vprintk_emit(int facility, int level,
logbuf_cpu = UINT_MAX;
raw_spin_unlock(&logbuf_lock);
+ lockdep_on();
+ local_irq_restore(flags);
/* If called from the scheduler, we can not call up(). */
if (!in_sched) {
+ lockdep_off();
+ /*
+ * Disable preemption to avoid being preempted while holding
+ * console_sem which would prevent anyone from printing to
+ * console
+ */
+ preempt_disable();
+
/*
* Try to acquire and then immediately release the console
* semaphore. The release will print out buffers and wake up
* /dev/kmsg and syslog() users.
*/
- if (console_trylock_for_printk(this_cpu))
+ if (console_trylock_for_printk())
console_unlock();
+ preempt_enable();
+ lockdep_on();
}
- lockdep_on();
-out_restore_irqs:
- local_irq_restore(flags);
return printed_len;
}
EXPORT_SYMBOL(vprintk_emit);
--
1.8.1.4
