Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1360348

Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async

From Byungchul Park <byungchul.park@lge.com>
Newsgroups linux.kernel
Subject Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async
Date 2016-03-18 06:50 +0100
Message-ID <rdVsl-1kZ-7@gated-at.bofh.it> (permalink)
References (5 earlier) <rddB0-588-9@gated-at.bofh.it> <rdedI-5Je-27@gated-at.bofh.it> <rdex4-5QB-5@gated-at.bofh.it> <rdh1T-7IW-5@gated-at.bofh.it> <rdu8P-8hX-19@gated-at.bofh.it>
Organization linux.* mail to news gateway

Show all headers | View raw


On Thu, Mar 17, 2016 at 09:34:50AM +0900, Sergey Senozhatsky wrote:
> > I am curious about how you make the wake_up_process() call and I may want
> > to talk about it at the next spin. Anyway, then we will lose the last
> > message when "if (logbuf_cpu == this_cpu)" acts. Is it acceptible?
> 
> yes, this is how it is. "BUG: recent printk recursion!" will be printed
> instead of the message.

I am not sure if it's the best way. For example, in the case suspecting
rq->lock, we cannot inform about the rq's "lockup suspected" while a
printk() is printing something, whatever it is, asynchronously. We can
avoid the infinite recursion with the patch I attached below, even though
the wake_up() and friends are used out of the section protected by
logbuf_lock.

> > IMHO it's not a good choice to use wake_up() and friend within a printk()
> > since it can additionally cause another recursion. Of course, it does not
> > happen if the condition (logbuf_cpu == this_cpu) acts. But I don't think
> > it's good to rely on the condition with losing a message. Anyway I really
> > really want to see your next spin and talk.
> 
> the alternative is NOT significantly better. pending bit is checked in
> IRQ, so one simply can do
> 
> 	local_irq_save();
> 	while (xxx) printk();
> 	local_irq_restore();
> 
> and _in the worst case_ nothing will be printed to console until IRQ are

Yes, you are right. But I am not sure yet.

> I'd probably prefer to add wake_up_process() to vprintk_emit() and do it
> under the logbuf lock. first, we don't suffer from disabled IRQs on current
> CPU, second we have somewhat better chances to break printk() recursion
> *in some cases*.

I think the logbuf_cpu is not for it. It's a kind of last resort. It would
be better to avoid using it if we can. And we can.

> > This cannot happen. console_lock() cannot continue because the prior
> > console_unlock() does not release console_sem.lock yet when
> > wake_up_process() is called. Only a deadlock exists. And my patch solves
> > the problem so that the deadlock cannot happen.
> 
> ah, we lost in patches. I was talking about yet another patch
> (you probably not aware of. you were not Cc'd. Sorry!) that
> makes console_unlock() asynchronous:
> 
> http://marc.info/?l=linux-kernel&m=145750373530161

I checked it now. Do you mean the wake_up_process() introduced in the new
patch in console_unlock()? If so, I also think it does not make a deadlock,
just can make a recursion in the worst case. I thought it was the
wake_up_process() in up() which is eventually called from console_unlock().
A deadlock can happen with the wake_up_proces() in up(). :-)

Thanks,
Byungchul

-----8<-----
From 81f06a6f9c7f2e782267a2539c6c869d4214354c Mon Sep 17 00:00:00 2001
From: Byungchul Park <byungchul.park@lge.com>
Date: Fri, 18 Mar 2016 11:35:24 +0900
Subject: [PATCH] lib/spinlock_debug: Prevent a unnecessary recursive
 spin_dump()

Printing "lockup suspected" for the same lock more than once is
meaningless. Furtheremore, it can cause an infinite recursion if it's
on the way printing something by printk().

Signed-off-by: Byungchul Park <byungchul.park@lge.com>
---
 kernel/locking/spinlock_debug.c | 15 +++++++++++++--
 1 file changed, 13 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/spinlock_debug.c b/kernel/locking/spinlock_debug.c
index fd24588..30559c6 100644
--- a/kernel/locking/spinlock_debug.c
+++ b/kernel/locking/spinlock_debug.c
@@ -138,14 +138,25 @@ static void __spin_lock_debug(raw_spinlock_t *lock)
 {
 	u64 i;
 	u64 loops = loops_per_jiffy * HZ;
+	static raw_spinlock_t *suspected_lock = NULL;
 
 	for (i = 0; i < loops; i++) {
 		if (arch_spin_trylock(&lock->raw_lock))
 			return;
 		__delay(1);
 	}
-	/* lockup suspected: */
-	spin_dump(lock, "lockup suspected");
+
+	/*
+	 * When we suspect a lockup, it's good enough to inform it once for
+	 * the same lock. Otherwise it could cause an infinite recursion if
+	 * it's within printk().
+	 */
+	if (suspected_lock != lock) {
+		suspected_lock = lock;
+		/* lockup suspected: */
+		spin_dump(lock, "lockup suspected");
+		suspected_lock = NULL;
+	}
 #ifdef CONFIG_SMP
 	trigger_all_cpu_backtrace();
 #endif
-- 
1.9.1

Back to linux.kernel | Previous | NextPrevious in thread | Next in thread | Find similar | Unroll thread


Thread

[RFC][PATCH v4 0/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-03-14 15:20 +0100
  [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-03-14 15:20 +0100
    Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Jan Kara <jack@suse.cz> - 2016-03-15 11:10 +0100
      Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-03-15 15:20 +0100
        Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Byungchul Park <byungchul.park@lge.com> - 2016-03-16 06:50 +0100
          Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-16 08:00 +0100
            Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Byungchul Park <byungchul.park@lge.com> - 2016-03-16 08:40 +0100
              Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-16 09:00 +0100
                Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Byungchul Park <byungchul.park@lge.com> - 2016-03-16 11:40 +0100
                Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-17 01:40 +0100
                Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Byungchul Park <byungchul.park@lge.com> - 2016-03-18 06:50 +0100
                Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-18 08:20 +0100
                RE: [RFC][PATCH v4 1/2] printk: Make printk() completely async "byungchul.park" <byungchul.park@lge.com> - 2016-03-18 09:30 +0100
          Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Byungchul Park <byungchul.park@lge.com> - 2016-03-16 08:10 +0100
            Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-16 08:10 +0100
    Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Petr Mladek <pmladek@suse.com> - 2016-03-15 17:00 +0100
      Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-16 03:10 +0100
        Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Byungchul Park <byungchul.park@lge.com> - 2016-03-16 03:20 +0100
          Re: [RFC][PATCH v4 1/2] printk: Make printk() completely async Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-16 03:40 +0100
  [RFC][PATCH v4 2/2] printk: Skip messages on oops Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-03-14 15:20 +0100
    Re: [RFC][PATCH v4 2/2] printk: Skip messages on oops Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-03-17 12:00 +0100

csiph-web