[PATCH] RFC: console: hack up console_lock more v3

[PATCH] RFC: console: hack up console_lock more v3

[Daniel Vetter]

console_trylock, called from within printk, can be called from pretty
much anywhere. Including try_to_wake_up. Note that this isn't common,
usually the box is in pretty bad shape at that point already. But it
really doesn't help when then lockdep jumps in and spams the logs,
potentially obscuring the real backtrace we're really interested in.
One case I've seen (slightly simplified backtrace):

 Call Trace:
  <IRQ>
  console_trylock+0xe/0x60
  vprintk_emit+0xf1/0x320
  printk+0x4d/0x69
  __warn_printk+0x46/0x90
  native_smp_send_reschedule+0x2f/0x40
  check_preempt_curr+0x81/0xa0
  ttwu_do_wakeup+0x14/0x220
  try_to_wake_up+0x218/0x5f0
  pollwake+0x6f/0x90
  credit_entropy_bits+0x204/0x310
  add_interrupt_randomness+0x18f/0x210
  handle_irq+0x67/0x160
  do_IRQ+0x5e/0x130
  common_interrupt+0xf/0xf
  </IRQ>

This alone isn't a problem, but the spinlock in the semaphore is also
still held while waking up waiters (up() -> __up() -> try_to_wake_up()
callchain), which then closes the runqueue vs. semaphore.lock loop,
and upsets lockdep, which issues a circular locking splat to dmesg.
Worse it upsets developers, since we don't want to spam dmesg with
clutter when the machine is dying already.

Fix this by creating a prinkt_safe_up() which calls wake_up_process
outside of the spinlock. This isn't correct in full generality, but
good enough for console_lock:

- console_lock doesn't use interruptible or killable or timeout down()
  calls, hence an up() is the only thing that can wake up a process.
  Hence the process can't get woken and killed and reaped while we try
  to wake it up too.

- semaphore.c always updates the waiter list while under the spinlock,
  so there's no other races. Specifically another process that races
  with a quick console_lock/unlock while we've dropped the spinlock
  already won't see our own waiter.

Note that we only have to break the recursion for the semaphore.lock
spinlock of the console_lock. Recursion within various scheduler
related locks is already prevented by the printk_safe_enter/exit pair
in __up_console_sem().

Also cc'ing John Ogness since perhaps his printk rework fixes this all
properly.

v2: Ditch attempt to fix console_trylock.

v3: Add a comment explaining why the taks we're waking won't
disappear (Chris), and improve commit message to address review
questions.

Signed-off-by: Daniel Vetter <daniel.vetter@intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Will Deacon <will.deacon@arm.com>
Cc: Petr Mladek <pmladek@suse.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
Cc: John Ogness <john.ogness@linutronix.de>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: linux-kernel@vger.kernel.org
Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>
---
 include/linux/semaphore.h  |  1 +
 kernel/locking/semaphore.c | 31 +++++++++++++++++++++++++++++++
 kernel/printk/printk.c     |  2 +-
 3 files changed, 33 insertions(+), 1 deletion(-)

diff --git a/include/linux/semaphore.h b/include/linux/semaphore.h
index 11c86fbfeb98..7e839c72809d 100644
--- a/include/linux/semaphore.h
+++ b/include/linux/semaphore.h
@@ -41,6 +41,7 @@ extern int __must_check down_interruptible(struct semaphore *sem);
 extern int __must_check down_killable(struct semaphore *sem);
 extern int __must_check down_trylock(struct semaphore *sem);
 extern int __must_check down_timeout(struct semaphore *sem, long jiffies);
+extern void printk_safe_up(struct semaphore *sem);
 extern void up(struct semaphore *sem);
 
 #endif /* __LINUX_SEMAPHORE_H */
diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
index 561acdd39960..55a896f18d91 100644
--- a/kernel/locking/semaphore.c
+++ b/kernel/locking/semaphore.c
@@ -197,6 +197,37 @@ struct semaphore_waiter {
 	bool up;
 };
 
+/**
+ * printk_safe_up - release the semaphore in console_unlock
+ * @sem: the semaphore to release
+ *
+ * Release the semaphore.  Unlike mutexes, up() may be called from any
+ * context and even by tasks which have never called down().
+ *
+ * NOTE: This is a special version of up() for console_unlock only. It is only
+ * safe if there are no killable, interruptible or timing out down() calls.
+ */
+void printk_safe_up(struct semaphore *sem)
+{
+	unsigned long flags;
+	struct semaphore_waiter *waiter = NULL;
+
+	raw_spin_lock_irqsave(&sem->lock, flags);
+	if (likely(list_empty(&sem->wait_list))) {
+		sem->count++;
+	} else {
+		waiter = list_first_entry(&sem->wait_list,
+					  struct semaphore_waiter, list);
+		list_del(&waiter->list);
+		waiter->up = true;
+	}
+	raw_spin_unlock_irqrestore(&sem->lock, flags);
+
+	if (waiter) /* protected by being sole wake source */
+		wake_up_process(waiter->task);
+}
+EXPORT_SYMBOL(printk_safe_up);
+
 /*
  * Because this function is inlined, the 'state' parameter will be
  * constant, and thus optimised away by the compiler.  Likewise the
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 02ca827b8fac..62303929afda 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -234,7 +234,7 @@ static void __up_console_sem(unsigned long ip)
 	mutex_release(&console_lock_dep_map, 1, ip);
 
 	printk_safe_enter_irqsave(flags);
-	up(&console_sem);
+	printk_safe_up(&console_sem);
 	printk_safe_exit_irqrestore(flags);
 }
 #define up_console_sem() __up_console_sem(_RET_IP_)
-- 
2.20.1

Re: [PATCH] RFC: console: hack up console_lock more v3

[Chris Wilson]

Quoting Daniel Vetter (2019-05-09 13:09:03)
> console_trylock, called from within printk, can be called from pretty
> much anywhere. Including try_to_wake_up. Note that this isn't common,
> usually the box is in pretty bad shape at that point already. But it
> really doesn't help when then lockdep jumps in and spams the logs,
> potentially obscuring the real backtrace we're really interested in.
> One case I've seen (slightly simplified backtrace):
> 
>  Call Trace:
>   <IRQ>
>   console_trylock+0xe/0x60
>   vprintk_emit+0xf1/0x320
>   printk+0x4d/0x69
>   __warn_printk+0x46/0x90
>   native_smp_send_reschedule+0x2f/0x40
>   check_preempt_curr+0x81/0xa0
>   ttwu_do_wakeup+0x14/0x220
>   try_to_wake_up+0x218/0x5f0
>   pollwake+0x6f/0x90
>   credit_entropy_bits+0x204/0x310
>   add_interrupt_randomness+0x18f/0x210
>   handle_irq+0x67/0x160
>   do_IRQ+0x5e/0x130
>   common_interrupt+0xf/0xf
>   </IRQ>
> 
> This alone isn't a problem, but the spinlock in the semaphore is also
> still held while waking up waiters (up() -> __up() -> try_to_wake_up()
> callchain), which then closes the runqueue vs. semaphore.lock loop,
> and upsets lockdep, which issues a circular locking splat to dmesg.
> Worse it upsets developers, since we don't want to spam dmesg with
> clutter when the machine is dying already.
> 
> Fix this by creating a prinkt_safe_up() which calls wake_up_process
> outside of the spinlock. This isn't correct in full generality, but
> good enough for console_lock:
> 
> - console_lock doesn't use interruptible or killable or timeout down()
>   calls, hence an up() is the only thing that can wake up a process.
>   Hence the process can't get woken and killed and reaped while we try
>   to wake it up too.
> 
> - semaphore.c always updates the waiter list while under the spinlock,
>   so there's no other races. Specifically another process that races
>   with a quick console_lock/unlock while we've dropped the spinlock
>   already won't see our own waiter.
> 
> Note that we only have to break the recursion for the semaphore.lock
> spinlock of the console_lock. Recursion within various scheduler
> related locks is already prevented by the printk_safe_enter/exit pair
> in __up_console_sem().
> 
> Also cc'ing John Ogness since perhaps his printk rework fixes this all
> properly.
> 
> v2: Ditch attempt to fix console_trylock.
> 
> v3: Add a comment explaining why the taks we're waking won't
> disappear (Chris), and improve commit message to address review
> questions.
> 
> Signed-off-by: Daniel Vetter <daniel.vetter@intel.com>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Will Deacon <will.deacon@arm.com>
> Cc: Petr Mladek <pmladek@suse.com>
> Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
> Cc: John Ogness <john.ogness@linutronix.de>
> Cc: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: linux-kernel@vger.kernel.org
> Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>

I'm a bit nervous about that this is only safe for the precisely
controlled conditions, but then again that it is called printk_safe
should deter any other users.

The logic checks out, and you convinced me that the dereference is
protected, so
Reviewed-by: Chris Wilson <chris@chris-wilson.co.uk>
-Chris

Re: [PATCH] RFC: console: hack up console_lock more v3

[Peter Zijlstra]

On Thu, May 09, 2019 at 02:09:03PM +0200, Daniel Vetter wrote:
> Fix this by creating a prinkt_safe_up() which calls wake_up_process
> outside of the spinlock. This isn't correct in full generality, but
> good enough for console_lock:
> 
> - console_lock doesn't use interruptible or killable or timeout down()
>   calls, hence an up() is the only thing that can wake up a process.

Wrong :/ Any task can be woken at any random time. We must, at all
times, assume spurious wakeups will happen.

> +void printk_safe_up(struct semaphore *sem)
> +{
> +	unsigned long flags;
> +	struct semaphore_waiter *waiter = NULL;
> +
> +	raw_spin_lock_irqsave(&sem->lock, flags);
> +	if (likely(list_empty(&sem->wait_list))) {
> +		sem->count++;
> +	} else {
> +		waiter = list_first_entry(&sem->wait_list,
> +					  struct semaphore_waiter, list);
> +		list_del(&waiter->list);
> +		waiter->up = true;
> +	}
> +	raw_spin_unlock_irqrestore(&sem->lock, flags);
> +
> +	if (waiter) /* protected by being sole wake source */
> +		wake_up_process(waiter->task);
> +}
> +EXPORT_SYMBOL(printk_safe_up);

Since its only used from printk, that EXPORT really isn't needed.

Something like the below might work.

---
 kernel/locking/semaphore.c | 26 +++++++++++++-------------
 1 file changed, 13 insertions(+), 13 deletions(-)

diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
index 561acdd39960..ac0a67e95aac 100644
--- a/kernel/locking/semaphore.c
+++ b/kernel/locking/semaphore.c
@@ -38,7 +38,6 @@ static noinline void __down(struct semaphore *sem);
 static noinline int __down_interruptible(struct semaphore *sem);
 static noinline int __down_killable(struct semaphore *sem);
 static noinline int __down_timeout(struct semaphore *sem, long timeout);
-static noinline void __up(struct semaphore *sem);
 
 /**
  * down - acquire the semaphore
@@ -178,14 +177,24 @@ EXPORT_SYMBOL(down_timeout);
  */
 void up(struct semaphore *sem)
 {
+	struct semaphore_waiter *waiter;
+	DEFINE_WAKE_Q(wake_q);
 	unsigned long flags;
 
 	raw_spin_lock_irqsave(&sem->lock, flags);
-	if (likely(list_empty(&sem->wait_list)))
+	if (likely(list_empty(&sem->wait_list))) {
 		sem->count++;
-	else
-		__up(sem);
+		goto unlock;
+	}
+
+	waiter = list_first_entry(&sem->wait_list, struct semaphore_waiter, list);
+	list_del(&waiter->list);
+	waiter->up = true;
+	wake_q_add(&wake_q, waiter->task);
+unlock:
 	raw_spin_unlock_irqrestore(&sem->lock, flags);
+
+	wake_up_q(&wake_q);
 }
 EXPORT_SYMBOL(up);
 
@@ -252,12 +261,3 @@ static noinline int __sched __down_timeout(struct semaphore *sem, long timeout)
 {
 	return __down_common(sem, TASK_UNINTERRUPTIBLE, timeout);
 }
-
-static noinline void __sched __up(struct semaphore *sem)
-{
-	struct semaphore_waiter *waiter = list_first_entry(&sem->wait_list,
-						struct semaphore_waiter, list);
-	list_del(&waiter->list);
-	waiter->up = true;
-	wake_up_process(waiter->task);
-}

Re: [PATCH] RFC: console: hack up console_lock more v3

[Daniel Vetter]

On Thu, May 9, 2019 at 2:31 PM Peter Zijlstra <peterz@infradead.org> wrote:
> On Thu, May 09, 2019 at 02:09:03PM +0200, Daniel Vetter wrote:
> > Fix this by creating a prinkt_safe_up() which calls wake_up_process
> > outside of the spinlock. This isn't correct in full generality, but
> > good enough for console_lock:
> >
> > - console_lock doesn't use interruptible or killable or timeout down()
> >   calls, hence an up() is the only thing that can wake up a process.
>
> Wrong :/ Any task can be woken at any random time. We must, at all
> times, assume spurious wakeups will happen.

Out of curiosity, where do these come from? I know about the races
where you need to recheck on the waiter side to avoid getting stuck,
but didn't know about this. Are these earlier (possibly spurious)
wakeups that got held up and delayed for a while, then hit the task
much later when it's already continued doing something else? Or even
more random, and even if I never put a task on a wait list or anything
else, ever, it can get woken spuriously?

> > +void printk_safe_up(struct semaphore *sem)
> > +{
> > +     unsigned long flags;
> > +     struct semaphore_waiter *waiter = NULL;
> > +
> > +     raw_spin_lock_irqsave(&sem->lock, flags);
> > +     if (likely(list_empty(&sem->wait_list))) {
> > +             sem->count++;
> > +     } else {
> > +             waiter = list_first_entry(&sem->wait_list,
> > +                                       struct semaphore_waiter, list);
> > +             list_del(&waiter->list);
> > +             waiter->up = true;
> > +     }
> > +     raw_spin_unlock_irqrestore(&sem->lock, flags);
> > +
> > +     if (waiter) /* protected by being sole wake source */
> > +             wake_up_process(waiter->task);
> > +}
> > +EXPORT_SYMBOL(printk_safe_up);
>
> Since its only used from printk, that EXPORT really isn't needed.
>
> Something like the below might work.

Yeah that looks like the proper fix. I guess semaphores are uncritical
enough that we can roll this out for everyone. Thanks for the hint.
-Daniel

>
> ---
>  kernel/locking/semaphore.c | 26 +++++++++++++-------------
>  1 file changed, 13 insertions(+), 13 deletions(-)
>
> diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
> index 561acdd39960..ac0a67e95aac 100644
> --- a/kernel/locking/semaphore.c
> +++ b/kernel/locking/semaphore.c
> @@ -38,7 +38,6 @@ static noinline void __down(struct semaphore *sem);
>  static noinline int __down_interruptible(struct semaphore *sem);
>  static noinline int __down_killable(struct semaphore *sem);
>  static noinline int __down_timeout(struct semaphore *sem, long timeout);
> -static noinline void __up(struct semaphore *sem);
>
>  /**
>   * down - acquire the semaphore
> @@ -178,14 +177,24 @@ EXPORT_SYMBOL(down_timeout);
>   */
>  void up(struct semaphore *sem)
>  {
> +       struct semaphore_waiter *waiter;
> +       DEFINE_WAKE_Q(wake_q);
>         unsigned long flags;
>
>         raw_spin_lock_irqsave(&sem->lock, flags);
> -       if (likely(list_empty(&sem->wait_list)))
> +       if (likely(list_empty(&sem->wait_list))) {
>                 sem->count++;
> -       else
> -               __up(sem);
> +               goto unlock;
> +       }
> +
> +       waiter = list_first_entry(&sem->wait_list, struct semaphore_waiter, list);
> +       list_del(&waiter->list);
> +       waiter->up = true;
> +       wake_q_add(&wake_q, waiter->task);
> +unlock:
>         raw_spin_unlock_irqrestore(&sem->lock, flags);
> +
> +       wake_up_q(&wake_q);
>  }
>  EXPORT_SYMBOL(up);
>
> @@ -252,12 +261,3 @@ static noinline int __sched __down_timeout(struct semaphore *sem, long timeout)
>  {
>         return __down_common(sem, TASK_UNINTERRUPTIBLE, timeout);
>  }
> -
> -static noinline void __sched __up(struct semaphore *sem)
> -{
> -       struct semaphore_waiter *waiter = list_first_entry(&sem->wait_list,
> -                                               struct semaphore_waiter, list);
> -       list_del(&waiter->list);
> -       waiter->up = true;
> -       wake_up_process(waiter->task);
> -}



-- 
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch

Re: [PATCH] RFC: console: hack up console_lock more v3

[Peter Zijlstra]

On Thu, May 09, 2019 at 03:06:09PM +0200, Daniel Vetter wrote:
> On Thu, May 9, 2019 at 2:31 PM Peter Zijlstra <peterz@infradead.org> wrote:
> > On Thu, May 09, 2019 at 02:09:03PM +0200, Daniel Vetter wrote:
> > > Fix this by creating a prinkt_safe_up() which calls wake_up_process
> > > outside of the spinlock. This isn't correct in full generality, but
> > > good enough for console_lock:
> > >
> > > - console_lock doesn't use interruptible or killable or timeout down()
> > >   calls, hence an up() is the only thing that can wake up a process.
> >
> > Wrong :/ Any task can be woken at any random time. We must, at all
> > times, assume spurious wakeups will happen.
> 
> Out of curiosity, where do these come from? I know about the races
> where you need to recheck on the waiter side to avoid getting stuck,
> but didn't know about this. Are these earlier (possibly spurious)
> wakeups that got held up and delayed for a while, then hit the task
> much later when it's already continued doing something else?

Yes, this. So they all more or less have the form:

CPU0		CPU1

		enqueue_waiter()
done = true;
if (waiters)
		for (;;) {
		  if (done)
		    break;

		  ...
		}

		dequeue_waiter()

		do something else again

  wake_up_task
		<gets wakeup>


The wake_q thing made the above much more common, but we've had it
forever.

> Or even
> more random, and even if I never put a task on a wait list or anything
> else, ever, it can get woken spuriously?

I had patches that did that on purpose, but no.

> > Something like the below might work.
> 
> Yeah that looks like the proper fix. I guess semaphores are uncritical
> enough that we can roll this out for everyone. Thanks for the hint.

It's actually an optimization that we never did because semaphores are
so uncritical :-)

The thing is, by delaying the wakup until after we've released the
spinlock, the waiter will not contend on the spinlock the moment it
wakes.

Re: [PATCH] RFC: console: hack up console_lock more v3

[Petr Mladek]

On Thu 2019-05-09 14:09:03, Daniel Vetter wrote:
> console_trylock, called from within printk, can be called from pretty
> much anywhere. Including try_to_wake_up. Note that this isn't common,
> usually the box is in pretty bad shape at that point already. But it
> really doesn't help when then lockdep jumps in and spams the logs,
> potentially obscuring the real backtrace we're really interested in.
> One case I've seen (slightly simplified backtrace):
> 
>  Call Trace:
>   <IRQ>
>   console_trylock+0xe/0x60
>   vprintk_emit+0xf1/0x320
>   printk+0x4d/0x69
>   __warn_printk+0x46/0x90
>   native_smp_send_reschedule+0x2f/0x40
>   check_preempt_curr+0x81/0xa0
>   ttwu_do_wakeup+0x14/0x220
>   try_to_wake_up+0x218/0x5f0
>   pollwake+0x6f/0x90
>   credit_entropy_bits+0x204/0x310
>   add_interrupt_randomness+0x18f/0x210
>   handle_irq+0x67/0x160
>   do_IRQ+0x5e/0x130
>   common_interrupt+0xf/0xf
>   </IRQ>
> 
> This alone isn't a problem, but the spinlock in the semaphore is also
> still held while waking up waiters (up() -> __up() -> try_to_wake_up()
> callchain), which then closes the runqueue vs. semaphore.lock loop,
> and upsets lockdep, which issues a circular locking splat to dmesg.
> Worse it upsets developers, since we don't want to spam dmesg with
> clutter when the machine is dying already.
> 
> Fix this by creating a prinkt_safe_up() which calls wake_up_process
> outside of the spinlock. This isn't correct in full generality, but
> good enough for console_lock:
> 
> - console_lock doesn't use interruptible or killable or timeout down()
>   calls, hence an up() is the only thing that can wake up a process.
>   Hence the process can't get woken and killed and reaped while we try
>   to wake it up too.
> 
> - semaphore.c always updates the waiter list while under the spinlock,
>   so there's no other races. Specifically another process that races
>   with a quick console_lock/unlock while we've dropped the spinlock
>   already won't see our own waiter.
> 
> Note that we only have to break the recursion for the semaphore.lock
> spinlock of the console_lock. Recursion within various scheduler
> related locks is already prevented by the printk_safe_enter/exit pair
> in __up_console_sem().

This is not fully true. printk_safe() helps only when
the first try_to_wake_up() is called from printk_safe() context.

> --- a/kernel/locking/semaphore.c
> +++ b/kernel/locking/semaphore.c
> @@ -197,6 +197,37 @@ struct semaphore_waiter {
>  	bool up;
>  };
>  
> +/**
> + * printk_safe_up - release the semaphore in console_unlock
> + * @sem: the semaphore to release
> + *
> + * Release the semaphore.  Unlike mutexes, up() may be called from any
> + * context and even by tasks which have never called down().
> + *
> + * NOTE: This is a special version of up() for console_unlock only. It is only
> + * safe if there are no killable, interruptible or timing out down() calls.
> + */
> +void printk_safe_up(struct semaphore *sem)
> +{
> +	unsigned long flags;
> +	struct semaphore_waiter *waiter = NULL;
> +
> +	raw_spin_lock_irqsave(&sem->lock, flags);
> +	if (likely(list_empty(&sem->wait_list))) {
> +		sem->count++;
> +	} else {
> +		waiter = list_first_entry(&sem->wait_list,
> +					  struct semaphore_waiter, list);
> +		list_del(&waiter->list);
> +		waiter->up = true;
> +	}
> +	raw_spin_unlock_irqrestore(&sem->lock, flags);
> +
> +	if (waiter) /* protected by being sole wake source */
> +		wake_up_process(waiter->task);

I still do not see how this could help. Let's take the above
backtrace as example:

   <IRQ>
   console_trylock+0xe/0x60
   vprintk_emit+0xf1/0x320
   printk+0x4d/0x69
   __warn_printk+0x46/0x90
   native_smp_send_reschedule +0x2f/0x40
   check_preempt_curr+0x81/0xa0
   ttwu_do_wakeup+0x14/0x220
   try_to_wake_up+0x218/0x5f0
   pollwake+0x6f/0x90
   credit_entropy_bits+0x204/0x310
   add_interrupt_randomness+0x18f/0x210
   handle_irq+0x67/0x160
   do_IRQ+0x5e/0x130
   common_interrupt+0xf/0xf
   </IRQ>

We have the following chain of calls:

  + do_IRQ()
    ...
      + try_to_wake_up()    # takes p->pi_lock
        + ttwu_remote()     # takes rq lock
          + ttwu_do_wakeup()
	    + check_preempt_curr()
	      + native_smp_send_reschedule()
	        + __warn_printk()
		  + printk()
		    + vprintk_emit()
		      + console_trylock() # success
		      + console_unlock()
		        + up_console_sem()
			  + up() # wait list in not empty
			    + __up()
			      + wake_up_process()
			        + try_to_wake_up()

!BANG! Deadlock on p->pi_lock.

It does not matter if the nested try_to_wake_up() was called
under sem->lock or outside.

By other words. The patch removed one lockdep warning. But it just
just delayed the deadlock. It will not happen on sem->lock but
later on p->pi_lock.

I am repeating myself. But IMHO, the only solution is to introduce
printk deferred context and use it in WARN_DEFERRED().

Best Regards,
Petr

Re: [PATCH] RFC: console: hack up console_lock more v3

[Daniel Vetter]

On Thu, May 9, 2019 at 4:56 PM Petr Mladek <pmladek@suse.com> wrote:
>
> On Thu 2019-05-09 14:09:03, Daniel Vetter wrote:
> > console_trylock, called from within printk, can be called from pretty
> > much anywhere. Including try_to_wake_up. Note that this isn't common,
> > usually the box is in pretty bad shape at that point already. But it
> > really doesn't help when then lockdep jumps in and spams the logs,
> > potentially obscuring the real backtrace we're really interested in.
> > One case I've seen (slightly simplified backtrace):
> >
> >  Call Trace:
> >   <IRQ>
> >   console_trylock+0xe/0x60
> >   vprintk_emit+0xf1/0x320
> >   printk+0x4d/0x69
> >   __warn_printk+0x46/0x90
> >   native_smp_send_reschedule+0x2f/0x40
> >   check_preempt_curr+0x81/0xa0
> >   ttwu_do_wakeup+0x14/0x220
> >   try_to_wake_up+0x218/0x5f0
> >   pollwake+0x6f/0x90
> >   credit_entropy_bits+0x204/0x310
> >   add_interrupt_randomness+0x18f/0x210
> >   handle_irq+0x67/0x160
> >   do_IRQ+0x5e/0x130
> >   common_interrupt+0xf/0xf
> >   </IRQ>
> >
> > This alone isn't a problem, but the spinlock in the semaphore is also
> > still held while waking up waiters (up() -> __up() -> try_to_wake_up()
> > callchain), which then closes the runqueue vs. semaphore.lock loop,
> > and upsets lockdep, which issues a circular locking splat to dmesg.
> > Worse it upsets developers, since we don't want to spam dmesg with
> > clutter when the machine is dying already.
> >
> > Fix this by creating a prinkt_safe_up() which calls wake_up_process
> > outside of the spinlock. This isn't correct in full generality, but
> > good enough for console_lock:
> >
> > - console_lock doesn't use interruptible or killable or timeout down()
> >   calls, hence an up() is the only thing that can wake up a process.
> >   Hence the process can't get woken and killed and reaped while we try
> >   to wake it up too.
> >
> > - semaphore.c always updates the waiter list while under the spinlock,
> >   so there's no other races. Specifically another process that races
> >   with a quick console_lock/unlock while we've dropped the spinlock
> >   already won't see our own waiter.
> >
> > Note that we only have to break the recursion for the semaphore.lock
> > spinlock of the console_lock. Recursion within various scheduler
> > related locks is already prevented by the printk_safe_enter/exit pair
> > in __up_console_sem().
>
> This is not fully true. printk_safe() helps only when
> the first try_to_wake_up() is called from printk_safe() context.
>
> > --- a/kernel/locking/semaphore.c
> > +++ b/kernel/locking/semaphore.c
> > @@ -197,6 +197,37 @@ struct semaphore_waiter {
> >       bool up;
> >  };
> >
> > +/**
> > + * printk_safe_up - release the semaphore in console_unlock
> > + * @sem: the semaphore to release
> > + *
> > + * Release the semaphore.  Unlike mutexes, up() may be called from any
> > + * context and even by tasks which have never called down().
> > + *
> > + * NOTE: This is a special version of up() for console_unlock only. It is only
> > + * safe if there are no killable, interruptible or timing out down() calls.
> > + */
> > +void printk_safe_up(struct semaphore *sem)
> > +{
> > +     unsigned long flags;
> > +     struct semaphore_waiter *waiter = NULL;
> > +
> > +     raw_spin_lock_irqsave(&sem->lock, flags);
> > +     if (likely(list_empty(&sem->wait_list))) {
> > +             sem->count++;
> > +     } else {
> > +             waiter = list_first_entry(&sem->wait_list,
> > +                                       struct semaphore_waiter, list);
> > +             list_del(&waiter->list);
> > +             waiter->up = true;
> > +     }
> > +     raw_spin_unlock_irqrestore(&sem->lock, flags);
> > +
> > +     if (waiter) /* protected by being sole wake source */
> > +             wake_up_process(waiter->task);
>
> I still do not see how this could help. Let's take the above
> backtrace as example:
>
>    <IRQ>
>    console_trylock+0xe/0x60
>    vprintk_emit+0xf1/0x320
>    printk+0x4d/0x69
>    __warn_printk+0x46/0x90
>    native_smp_send_reschedule +0x2f/0x40
>    check_preempt_curr+0x81/0xa0
>    ttwu_do_wakeup+0x14/0x220
>    try_to_wake_up+0x218/0x5f0
>    pollwake+0x6f/0x90
>    credit_entropy_bits+0x204/0x310
>    add_interrupt_randomness+0x18f/0x210
>    handle_irq+0x67/0x160
>    do_IRQ+0x5e/0x130
>    common_interrupt+0xf/0xf
>    </IRQ>
>
> We have the following chain of calls:
>
>   + do_IRQ()
>     ...
>       + try_to_wake_up()    # takes p->pi_lock
>         + ttwu_remote()     # takes rq lock
>           + ttwu_do_wakeup()
>             + check_preempt_curr()
>               + native_smp_send_reschedule()
>                 + __warn_printk()
>                   + printk()
>                     + vprintk_emit()
>                       + console_trylock() # success
>                       + console_unlock()
>                         + up_console_sem()
>                           + up() # wait list in not empty
>                             + __up()
>                               + wake_up_process()
>                                 + try_to_wake_up()
>
> !BANG! Deadlock on p->pi_lock.

Hm right ... I only looked at this starting with console_unlock.

> It does not matter if the nested try_to_wake_up() was called
> under sem->lock or outside.
>
> By other words. The patch removed one lockdep warning. But it just
> just delayed the deadlock. It will not happen on sem->lock but
> later on p->pi_lock.
>
> I am repeating myself. But IMHO, the only solution is to introduce
> printk deferred context and use it in WARN_DEFERRED().

One thing to keep in mind is that the kernel is already dying, and
things will come crashing down later on (I've seen this only in dmesg
tails capture in pstore in our CI, i.e. the box died for good). I just
want to make sure that the useful information isn't overwritten by
more dmesg splats that happen as a consequence of us somehow trying to
run things on an offline cpu. Once console_unlock has completed in
your above backtrace and the important stuff has gone out I'm totally
fine with the kernel just dying. Pulling the wake_up_process out from
under the semaphore.lock is enough to prevent lockdep from dumping
more stuff while we're trying to print the important things, and I
think the untangling of the locking hiararchy is useful irrespective
of this lockdep splat. Plus Peter doesn't sound like he likes to roll
out more printk_deferred kind of things.

But if you think I should do the printk_deferred thing too I can look
into that. Just not quite sure what that's supposed to look like now.
-Daniel





--
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch

Re: [PATCH] RFC: console: hack up console_lock more v3

[Petr Mladek]

On Thu 2019-05-09 18:43:12, Daniel Vetter wrote:
> One thing to keep in mind is that the kernel is already dying, and
> things will come crashing down later on

This is important information. I havn't seen it mentioned earlier.

> (I've seen this only in dmesg
> tails capture in pstore in our CI, i.e. the box died for good). I just
> want to make sure that the useful information isn't overwritten by
> more dmesg splats that happen as a consequence of us somehow trying to
> run things on an offline cpu. Once console_unlock has completed in
> your above backtrace and the important stuff has gone out I'm totally
> fine with the kernel just dying. Pulling the wake_up_process out from
> under the semaphore.lock is enough to prevent lockdep from dumping
> more stuff while we're trying to print the important things,

With the more stuff you mean the lockdep splat? If yes, it might
make sense to call debug_locks_off() earlier in panic().


> and I think the untangling of the locking hiararchy is useful irrespective
> of this lockdep splat. Plus Peter doesn't sound like he likes to roll
> out more printk_deferred kind of things.
>
> But if you think I should do the printk_deferred thing too I can look
> into that. Just not quite sure what that's supposed to look like now.

Your patch might remove the particular lockdep splat. It might be
worth it (Peter mentioned also an optimization effect). Anyway
it will not prevent the deadlock.

The only way to avoid the deadlock is to use printk_deferred()
with the current printk() code.


Finally, I have recently worked on similar problem with dying system.
I sent the following patch for testing. I wonder if it might be
acceptable upstream:


From: Petr Mladek <pmladek@suse.com>
Subject: sched/x86: Do not warn about offline CPUs when all are being stopped
Patch-mainline: No, just for testing
References: bsc#1104406

The warning about rescheduling offline CPUs cause dealock when
the CPUs need to get stopped using NMI. It might happen with
logbuf_lock, locks used by console drivers, especially tty.
But it might also be caused by a registered kernel message
dumper, for example, pstore.

The warning is pretty common when there is a high load and
CPUs are being stopped by native_stop_other_cpus(). But
they are not really useful in this context. And they scrolls
the really important messages off the screen.

We need to fix printk() in the long term. But disabling
the message looks reasonable at least in the meantime.

Signed-off-by: Petr Mladek <pmladek@suse.com>
---
 arch/x86/kernel/smp.c |    3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

--- a/arch/x86/kernel/smp.c
+++ b/arch/x86/kernel/smp.c
@@ -124,7 +124,8 @@ static bool smp_no_nmi_ipi = false;
  */
 static void native_smp_send_reschedule(int cpu)
 {
-	if (unlikely(cpu_is_offline(cpu))) {
+	if (unlikely(cpu_is_offline(cpu) &&
+		     atomic_read(&stopping_cpu) < 0)) {
 		WARN(1, "sched: Unexpected reschedule of offline CPU#%d!\n", cpu);
 		return;
 	}

Re: [PATCH] RFC: console: hack up console_lock more v3

[Sergey Senozhatsky]

On (05/10/19 11:15), Petr Mladek wrote:
[..]
>  arch/x86/kernel/smp.c |    3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)
> 
> --- a/arch/x86/kernel/smp.c
> +++ b/arch/x86/kernel/smp.c
> @@ -124,7 +124,8 @@ static bool smp_no_nmi_ipi = false;
>   */
>  static void native_smp_send_reschedule(int cpu)
>  {
> -	if (unlikely(cpu_is_offline(cpu))) {
> +	if (unlikely(cpu_is_offline(cpu) &&
> +		     atomic_read(&stopping_cpu) < 0)) {
>  		WARN(1, "sched: Unexpected reschedule of offline CPU#%d!\n", cpu);
>  		return;
>  	}

I think we need to remove CPU which we IPI_STOP from
idle_cpus_mask. So then scheduler won't pick up stopped
CPUs (cpumask_first(nohz.idle_cpus_mask)) and attempt
rescheduling to them. It seems that currently
native_stop_other_cpus() doesn't do that.

	-ss

Re: [PATCH] RFC: console: hack up console_lock more v3

[Daniel Vetter]

On Fri, May 10, 2019 at 11:15 AM Petr Mladek <pmladek@suse.com> wrote:
> On Thu 2019-05-09 18:43:12, Daniel Vetter wrote:
> > One thing to keep in mind is that the kernel is already dying, and
> > things will come crashing down later on
>
> This is important information. I havn't seen it mentioned earlier.

I thought I explained that, sorry if this wasn't clear.

> > (I've seen this only in dmesg
> > tails capture in pstore in our CI, i.e. the box died for good). I just
> > want to make sure that the useful information isn't overwritten by
> > more dmesg splats that happen as a consequence of us somehow trying to
> > run things on an offline cpu. Once console_unlock has completed in
> > your above backtrace and the important stuff has gone out I'm totally
> > fine with the kernel just dying. Pulling the wake_up_process out from
> > under the semaphore.lock is enough to prevent lockdep from dumping
> > more stuff while we're trying to print the important things,
>
> With the more stuff you mean the lockdep splat? If yes, it might
> make sense to call debug_locks_off() earlier in panic().

I'm not sure this only happens in panics (I'm honestly not sure at all
why we're complaining about offline cpus). But in general I've seen
piles of dying systems that dump WARNINGS and then eventually panic.
Still would be good to not have a pointless lockdep splat in between.

> > and I think the untangling of the locking hiararchy is useful irrespective
> > of this lockdep splat. Plus Peter doesn't sound like he likes to roll
> > out more printk_deferred kind of things.
> >
> > But if you think I should do the printk_deferred thing too I can look
> > into that. Just not quite sure what that's supposed to look like now.
>
> Your patch might remove the particular lockdep splat. It might be
> worth it (Peter mentioned also an optimization effect). Anyway
> it will not prevent the deadlock.
>
> The only way to avoid the deadlock is to use printk_deferred()
> with the current printk() code.
>
>
> Finally, I have recently worked on similar problem with dying system.
> I sent the following patch for testing. I wonder if it might be
> acceptable upstream:
>
>
> From: Petr Mladek <pmladek@suse.com>
> Subject: sched/x86: Do not warn about offline CPUs when all are being stopped
> Patch-mainline: No, just for testing
> References: bsc#1104406
>
> The warning about rescheduling offline CPUs cause dealock when
> the CPUs need to get stopped using NMI. It might happen with
> logbuf_lock, locks used by console drivers, especially tty.
> But it might also be caused by a registered kernel message
> dumper, for example, pstore.
>
> The warning is pretty common when there is a high load and
> CPUs are being stopped by native_stop_other_cpus(). But
> they are not really useful in this context. And they scrolls
> the really important messages off the screen.
>
> We need to fix printk() in the long term. But disabling
> the message looks reasonable at least in the meantime.
>
> Signed-off-by: Petr Mladek <pmladek@suse.com>
> ---
>  arch/x86/kernel/smp.c |    3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)
>
> --- a/arch/x86/kernel/smp.c
> +++ b/arch/x86/kernel/smp.c
> @@ -124,7 +124,8 @@ static bool smp_no_nmi_ipi = false;
>   */
>  static void native_smp_send_reschedule(int cpu)
>  {
> -       if (unlikely(cpu_is_offline(cpu))) {
> +       if (unlikely(cpu_is_offline(cpu) &&
> +                    atomic_read(&stopping_cpu) < 0)) {

Hm yeah this sounds like another fix which would stop things from
getting worse when the machine is dying. I can try and stuff this (or
something like this, I honestly have no idea about cpu handling code
so no idea what's reasonable) into our CI and see what happens.

Thanks, Daniel

>                 WARN(1, "sched: Unexpected reschedule of offline CPU#%d!\n", cpu);
>                 return;
>         }



-- 
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch

[PATCH] kernel/locking/semaphore: use wake_q in up()

[Daniel Vetter]

console_trylock, called from within printk, can be called from pretty
much anywhere. Including try_to_wake_up. Note that this isn't common,
usually the box is in pretty bad shape at that point already. But it
really doesn't help when then lockdep jumps in and spams the logs,
potentially obscuring the real backtrace we're really interested in.
One case I've seen (slightly simplified backtrace):

 Call Trace:
  <IRQ>
  console_trylock+0xe/0x60
  vprintk_emit+0xf1/0x320
  printk+0x4d/0x69
  __warn_printk+0x46/0x90
  native_smp_send_reschedule+0x2f/0x40
  check_preempt_curr+0x81/0xa0
  ttwu_do_wakeup+0x14/0x220
  try_to_wake_up+0x218/0x5f0
  pollwake+0x6f/0x90
  credit_entropy_bits+0x204/0x310
  add_interrupt_randomness+0x18f/0x210
  handle_irq+0x67/0x160
  do_IRQ+0x5e/0x130
  common_interrupt+0xf/0xf
  </IRQ>

This alone isn't a problem, but the spinlock in the semaphore is also
still held while waking up waiters (up() -> __up() -> try_to_wake_up()
callchain), which then closes the runqueue vs. semaphore.lock loop,
and upsets lockdep, which issues a circular locking splat to dmesg.
Worse it upsets developers, since we don't want to spam dmesg with
clutter when the machine is dying already.

Fix this specific locking recursion by moving the wake_up_process out
from under the semaphore.lock spinlock, using wake_q as recommended by
Peter Zijlstra.

As Petr Mladek points out this doesn't fix all the locking recursions
in this area. If we actually recursive in the above callchain:

      + try_to_wake_up()    # takes p->pi_lock
        + ttwu_remote()     # takes rq lock
          + ttwu_do_wakeup()
            + check_preempt_curr()
              + native_smp_send_reschedule()
                + __warn_printk()
                  + printk()
                    + vprintk_emit()
                      + console_trylock() # success
                      + console_unlock()
                        + up_console_sem()
                          + up() # wait list in not empty
                            + __up()
                              + wake_up_process()
                                + try_to_wake_up()

Then there's any number of scheduler related locks will deadlock.
Given that the kernel is dying already (the printk() in
native_smp_send_reschedule() happens because we run on an offlined
CPU) I think there's limited value in trying to fix this:

- We haven't seen the actual deadlock in our CI, only lockdep
  complaining about the possibility.

- The real issue is that the lockdep splat hides useful dmesg
  information we capture in e.g. pstore or on screen about the real
  cause of why the kernel is dying.

- The console_unlock in the above callchain should have managed to get
  all the dmesg up to that point out already. Dying later on is
  somewhat ok - I've only seen this lockdep splat in pstore when the
  machine died anyway.

Also cc'ing John Ogness since perhaps his printk rework fixes this all
properly.

v2: Ditch attempt to fix console_trylock.

v3: Add a comment explaining why the taks we're waking won't
disappear (Chris), and improve commit message to address review
questions.

v4: Use wake_q (Peter Z).

Signed-off-by: Daniel Vetter <daniel.vetter@intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Will Deacon <will.deacon@arm.com>
Cc: Petr Mladek <pmladek@suse.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
Cc: John Ogness <john.ogness@linutronix.de>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: linux-kernel@vger.kernel.org
Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>
---
 kernel/locking/semaphore.c | 42 +++++++++++++++++++-------------------
 1 file changed, 21 insertions(+), 21 deletions(-)

diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
index 561acdd39960..7a6f33715688 100644
--- a/kernel/locking/semaphore.c
+++ b/kernel/locking/semaphore.c
@@ -33,12 +33,12 @@
 #include <linux/semaphore.h>
 #include <linux/spinlock.h>
 #include <linux/ftrace.h>
+#include <linux/sched/wake_q.h>
 
 static noinline void __down(struct semaphore *sem);
 static noinline int __down_interruptible(struct semaphore *sem);
 static noinline int __down_killable(struct semaphore *sem);
 static noinline int __down_timeout(struct semaphore *sem, long timeout);
-static noinline void __up(struct semaphore *sem);
 
 /**
  * down - acquire the semaphore
@@ -169,6 +169,14 @@ int down_timeout(struct semaphore *sem, long timeout)
 }
 EXPORT_SYMBOL(down_timeout);
 
+/* Functions for the contended case */
+
+struct semaphore_waiter {
+	struct list_head list;
+	struct task_struct *task;
+	bool up;
+};
+
 /**
  * up - release the semaphore
  * @sem: the semaphore to release
@@ -179,24 +187,25 @@ EXPORT_SYMBOL(down_timeout);
 void up(struct semaphore *sem)
 {
 	unsigned long flags;
+	struct semaphore_waiter *waiter;
+	DEFINE_WAKE_Q(wake_q);
 
 	raw_spin_lock_irqsave(&sem->lock, flags);
-	if (likely(list_empty(&sem->wait_list)))
+	if (likely(list_empty(&sem->wait_list))) {
 		sem->count++;
-	else
-		__up(sem);
+	} else {
+		waiter =  list_first_entry(&sem->wait_list,
+					   struct semaphore_waiter, list);
+		list_del(&waiter->list);
+		waiter->up = true;
+		wake_q_add(&wake_q, waiter->task);
+	}
 	raw_spin_unlock_irqrestore(&sem->lock, flags);
+
+	wake_up_q(&wake_q);
 }
 EXPORT_SYMBOL(up);
 
-/* Functions for the contended case */
-
-struct semaphore_waiter {
-	struct list_head list;
-	struct task_struct *task;
-	bool up;
-};
-
 /*
  * Because this function is inlined, the 'state' parameter will be
  * constant, and thus optimised away by the compiler.  Likewise the
@@ -252,12 +261,3 @@ static noinline int __sched __down_timeout(struct semaphore *sem, long timeout)
 {
 	return __down_common(sem, TASK_UNINTERRUPTIBLE, timeout);
 }
-
-static noinline void __sched __up(struct semaphore *sem)
-{
-	struct semaphore_waiter *waiter = list_first_entry(&sem->wait_list,
-						struct semaphore_waiter, list);
-	list_del(&waiter->list);
-	waiter->up = true;
-	wake_up_process(waiter->task);
-}
-- 
2.20.1

Re: [PATCH] kernel/locking/semaphore: use wake_q in up()

[Sergey Senozhatsky]

On (05/09/19 22:06), Daniel Vetter wrote:
[..]
> +/* Functions for the contended case */
> +
> +struct semaphore_waiter {
> +	struct list_head list;
> +	struct task_struct *task;
> +	bool up;
> +};
> +
>  /**
>   * up - release the semaphore
>   * @sem: the semaphore to release
> @@ -179,24 +187,25 @@ EXPORT_SYMBOL(down_timeout);
>  void up(struct semaphore *sem)
>  {
>  	unsigned long flags;
> +	struct semaphore_waiter *waiter;
> +	DEFINE_WAKE_Q(wake_q);
>  
>  	raw_spin_lock_irqsave(&sem->lock, flags);
> -	if (likely(list_empty(&sem->wait_list)))
> +	if (likely(list_empty(&sem->wait_list))) {
>  		sem->count++;
> -	else
> -		__up(sem);
> +	} else {
> +		waiter =  list_first_entry(&sem->wait_list,
> +					   struct semaphore_waiter, list);
> +		list_del(&waiter->list);
> +		waiter->up = true;
> +		wake_q_add(&wake_q, waiter->task);
> +	}
>  	raw_spin_unlock_irqrestore(&sem->lock, flags);

So the new code still can printk/WARN under sem->lock in some buggy
cases.

E.g.
	wake_q_add()
	 get_task_struct()
	  refcount_inc_checked()
	   WARN_ONCE()

Are we fine with that?

	-ss

Re: [PATCH] kernel/locking/semaphore: use wake_q in up()

[Daniel Vetter]

On Fri, May 10, 2019 at 7:50 AM Sergey Senozhatsky
<sergey.senozhatsky.work@gmail.com> wrote:
>
> On (05/09/19 22:06), Daniel Vetter wrote:
> [..]
> > +/* Functions for the contended case */
> > +
> > +struct semaphore_waiter {
> > +     struct list_head list;
> > +     struct task_struct *task;
> > +     bool up;
> > +};
> > +
> >  /**
> >   * up - release the semaphore
> >   * @sem: the semaphore to release
> > @@ -179,24 +187,25 @@ EXPORT_SYMBOL(down_timeout);
> >  void up(struct semaphore *sem)
> >  {
> >       unsigned long flags;
> > +     struct semaphore_waiter *waiter;
> > +     DEFINE_WAKE_Q(wake_q);
> >
> >       raw_spin_lock_irqsave(&sem->lock, flags);
> > -     if (likely(list_empty(&sem->wait_list)))
> > +     if (likely(list_empty(&sem->wait_list))) {
> >               sem->count++;
> > -     else
> > -             __up(sem);
> > +     } else {
> > +             waiter =  list_first_entry(&sem->wait_list,
> > +                                        struct semaphore_waiter, list);
> > +             list_del(&waiter->list);
> > +             waiter->up = true;
> > +             wake_q_add(&wake_q, waiter->task);
> > +     }
> >       raw_spin_unlock_irqrestore(&sem->lock, flags);
>
> So the new code still can printk/WARN under sem->lock in some buggy
> cases.
>
> E.g.
>         wake_q_add()
>          get_task_struct()
>           refcount_inc_checked()
>            WARN_ONCE()
>
> Are we fine with that?

Hm not great. It's not as bad as the one I'm trying to fix (or not the
same at least), because with the wake up chain we have a few locks in
there. Which allows lockdep to connect the loop and complain, even
when we never actually hit that specific recursion. I.e. once hitting
a WARN_ON from try_to_wake_up is enough, plus a totally separate
callchain can then close the semaphore.lock->scheduler locks part.
Your chain only goes boom if it happens from the console_lock's up.

wake_q_add_safe would be an option, but then we somehow need to
arrange for down to call get_task_struct(current) and releasing that,
but only if there's no waker who needs that task ref. Sounds tricky
... Also not sure we want to stuff that trickery into the generic
semaphore code.
-Daniel
-- 
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch

Re: [PATCH] kernel/locking/semaphore: use wake_q in up()

[Petr Mladek]

On Thu 2019-05-09 22:06:33, Daniel Vetter wrote:
> console_trylock, called from within printk, can be called from pretty
> much anywhere. Including try_to_wake_up. Note that this isn't common,
> usually the box is in pretty bad shape at that point already. But it
> really doesn't help when then lockdep jumps in and spams the logs,
> potentially obscuring the real backtrace we're really interested in.
> One case I've seen (slightly simplified backtrace):
> 
> Fix this specific locking recursion by moving the wake_up_process out
> from under the semaphore.lock spinlock, using wake_q as recommended by
> Peter Zijlstra.

It might make sense to mention also the optimization effect mentioned
by Peter.

> diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
> index 561acdd39960..7a6f33715688 100644
> --- a/kernel/locking/semaphore.c
> +++ b/kernel/locking/semaphore.c
> @@ -169,6 +169,14 @@ int down_timeout(struct semaphore *sem, long timeout)
>  }
>  EXPORT_SYMBOL(down_timeout);
>  
> +/* Functions for the contended case */
> +
> +struct semaphore_waiter {
> +	struct list_head list;
> +	struct task_struct *task;
> +	bool up;
> +};
> +
>  /**
>   * up - release the semaphore
>   * @sem: the semaphore to release
> @@ -179,24 +187,25 @@ EXPORT_SYMBOL(down_timeout);
>  void up(struct semaphore *sem)
>  {
>  	unsigned long flags;
> +	struct semaphore_waiter *waiter;
> +	DEFINE_WAKE_Q(wake_q);

We need to call wake_q_init(&wake_q) to make sure that
it is empty.

Best Regards,
Petr

>  	raw_spin_lock_irqsave(&sem->lock, flags);
> -	if (likely(list_empty(&sem->wait_list)))
> +	if (likely(list_empty(&sem->wait_list))) {
>  		sem->count++;
> -	else
> -		__up(sem);
> +	} else {
> +		waiter =  list_first_entry(&sem->wait_list,
> +					   struct semaphore_waiter, list);
> +		list_del(&waiter->list);
> +		waiter->up = true;
> +		wake_q_add(&wake_q, waiter->task);
> +	}
>  	raw_spin_unlock_irqrestore(&sem->lock, flags);
> +
> +	wake_up_q(&wake_q);
>  }
>  EXPORT_SYMBOL(up);
>  
> -/* Functions for the contended case */
> -
> -struct semaphore_waiter {
> -	struct list_head list;
> -	struct task_struct *task;
> -	bool up;
> -};
> -
>  /*
>   * Because this function is inlined, the 'state' parameter will be
>   * constant, and thus optimised away by the compiler.  Likewise the

Re: [PATCH] kernel/locking/semaphore: use wake_q in up()

[Daniel Vetter]

On Fri, May 10, 2019 at 11:28 AM Petr Mladek <pmladek@suse.com> wrote:
>
> On Thu 2019-05-09 22:06:33, Daniel Vetter wrote:
> > console_trylock, called from within printk, can be called from pretty
> > much anywhere. Including try_to_wake_up. Note that this isn't common,
> > usually the box is in pretty bad shape at that point already. But it
> > really doesn't help when then lockdep jumps in and spams the logs,
> > potentially obscuring the real backtrace we're really interested in.
> > One case I've seen (slightly simplified backtrace):
> >
> > Fix this specific locking recursion by moving the wake_up_process out
> > from under the semaphore.lock spinlock, using wake_q as recommended by
> > Peter Zijlstra.
>
> It might make sense to mention also the optimization effect mentioned
> by Peter.
>
> > diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
> > index 561acdd39960..7a6f33715688 100644
> > --- a/kernel/locking/semaphore.c
> > +++ b/kernel/locking/semaphore.c
> > @@ -169,6 +169,14 @@ int down_timeout(struct semaphore *sem, long timeout)
> >  }
> >  EXPORT_SYMBOL(down_timeout);
> >
> > +/* Functions for the contended case */
> > +
> > +struct semaphore_waiter {
> > +     struct list_head list;
> > +     struct task_struct *task;
> > +     bool up;
> > +};
> > +
> >  /**
> >   * up - release the semaphore
> >   * @sem: the semaphore to release
> > @@ -179,24 +187,25 @@ EXPORT_SYMBOL(down_timeout);
> >  void up(struct semaphore *sem)
> >  {
> >       unsigned long flags;
> > +     struct semaphore_waiter *waiter;
> > +     DEFINE_WAKE_Q(wake_q);
>
> We need to call wake_q_init(&wake_q) to make sure that
> it is empty.

DEFINE_WAKE_Q does that already, and if it didn't, I'd wonder how I
managed to boot with this patch. console_lock is usally terribly
contented because thanks to fbcon we must do a full display modeset
while holding it, which takes forever. As long as anyone printks
meanwhile (guaranteed while loading drivers really) you have
contention.
-Daniel


> Best Regards,
> Petr
>
> >       raw_spin_lock_irqsave(&sem->lock, flags);
> > -     if (likely(list_empty(&sem->wait_list)))
> > +     if (likely(list_empty(&sem->wait_list))) {
> >               sem->count++;
> > -     else
> > -             __up(sem);
> > +     } else {
> > +             waiter =  list_first_entry(&sem->wait_list,
> > +                                        struct semaphore_waiter, list);
> > +             list_del(&waiter->list);
> > +             waiter->up = true;
> > +             wake_q_add(&wake_q, waiter->task);
> > +     }
> >       raw_spin_unlock_irqrestore(&sem->lock, flags);
> > +
> > +     wake_up_q(&wake_q);
> >  }
> >  EXPORT_SYMBOL(up);
> >
> > -/* Functions for the contended case */
> > -
> > -struct semaphore_waiter {
> > -     struct list_head list;
> > -     struct task_struct *task;
> > -     bool up;
> > -};
> > -
> >  /*
> >   * Because this function is inlined, the 'state' parameter will be
> >   * constant, and thus optimised away by the compiler.  Likewise the



-- 
Daniel Vetter
Software Engineer, Intel Corporation
+41 (0) 79 365 57 48 - http://blog.ffwll.ch

Re: [PATCH] kernel/locking/semaphore: use wake_q in up()

[Petr Mladek]

On Fri 2019-05-10 17:20:15, Daniel Vetter wrote:
> On Fri, May 10, 2019 at 11:28 AM Petr Mladek <pmladek@suse.com> wrote:
> >
> > On Thu 2019-05-09 22:06:33, Daniel Vetter wrote:
> > > console_trylock, called from within printk, can be called from pretty
> > > much anywhere. Including try_to_wake_up. Note that this isn't common,
> > > usually the box is in pretty bad shape at that point already. But it
> > > really doesn't help when then lockdep jumps in and spams the logs,
> > > potentially obscuring the real backtrace we're really interested in.
> > > One case I've seen (slightly simplified backtrace):
> > >
> > > Fix this specific locking recursion by moving the wake_up_process out
> > > from under the semaphore.lock spinlock, using wake_q as recommended by
> > > Peter Zijlstra.
> >
> > It might make sense to mention also the optimization effect mentioned
> > by Peter.
> >
> > > diff --git a/kernel/locking/semaphore.c b/kernel/locking/semaphore.c
> > > index 561acdd39960..7a6f33715688 100644
> > > --- a/kernel/locking/semaphore.c
> > > +++ b/kernel/locking/semaphore.c
> > > @@ -169,6 +169,14 @@ int down_timeout(struct semaphore *sem, long timeout)
> > >  }
> > >  EXPORT_SYMBOL(down_timeout);
> > >
> > > +/* Functions for the contended case */
> > > +
> > > +struct semaphore_waiter {
> > > +     struct list_head list;
> > > +     struct task_struct *task;
> > > +     bool up;
> > > +};
> > > +
> > >  /**
> > >   * up - release the semaphore
> > >   * @sem: the semaphore to release
> > > @@ -179,24 +187,25 @@ EXPORT_SYMBOL(down_timeout);
> > >  void up(struct semaphore *sem)
> > >  {
> > >       unsigned long flags;
> > > +     struct semaphore_waiter *waiter;
> > > +     DEFINE_WAKE_Q(wake_q);
> >
> > We need to call wake_q_init(&wake_q) to make sure that
> > it is empty.
> 
> DEFINE_WAKE_Q does that already, and if it didn't, I'd wonder how I
> managed to boot with this patch. console_lock is usally terribly
> contented because thanks to fbcon we must do a full display modeset
> while holding it, which takes forever. As long as anyone printks
> meanwhile (guaranteed while loading drivers really) you have
> contention.
> -Daniel

You are right. It is initialized by DEFINE_WAKE_Q.
The patch looks correct to me then:

Reviewed-by: Petr Mladek <pmladek@suse,com>

Best Regards,
Petr