[PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Fabio Estevam]

The following sysrq command causes the following lockdep warning:

 # echo t > /proc/sysrq-trigger
 ....
[   20.325246] ======================================================
[   20.325252] WARNING: possible circular locking dependency detected
[   20.325260] 5.15.0-rc2-next-20210924-00004-gd2d6e664f29f-dirty #163
Not tainted
[   20.325273] ------------------------------------------------------
[   20.325279] sh/236 is trying to acquire lock:
[   20.325293] c1618614 (console_owner){-...}-{0:0}, at:
console_unlock+0x180/0x5bc
[   20.325361]
[   20.325361] but task is already holding lock:
[   20.325368] eefccc90 (&pool->lock){-.-.}-{2:2}, at:
show_workqueue_state+0x104/0x3c8
[   20.325432]
[   20.325432] which lock already depends on the new lock.

...

[   20.325657] -> #2 (&pool->lock/1){-.-.}-{2:2}:
[   20.325690]        __queue_work+0x114/0x810
[   20.325710]        queue_work_on+0x54/0x94
[   20.325727]        __imx_uart_rxint.constprop.0+0x1b4/0x2e0
[   20.325760]        imx_uart_int+0x270/0x310

This problem happens because uart_handle_sysrq_char() is called
with the lock held.

Fix this by using the same approach done in commit 5697df7322fe ("serial:
fsl_lpuart: split sysrq handling"), which calls uart_prepare_sysrq_char()
and uart_unlock_and_check_sysrq() instead.

Its commit log says:

"Instead of uart_handle_sysrq_char() use uart_prepare_sysrq_char() and
uart_unlock_and_check_sysrq(). This will call handle_sysrq() without
holding the port lock, which in turn let us drop the spin_trylock hack."

Do the same here to suppress the false positive lockdep warning.

As __imx_uart_rxint() drops the lock now, remove the spin_unlock()
inside imx_uart_rxint(), which is only used on i.MX1.

Tested on a i.MX7D board via 'echo t > /proc/sysrq-trigger' in the
command line and also by passing the "<break> + t" keys in
the serial console.

Signed-off-by: Fabio Estevam <festevam@denx.de>
---
Changes since v2:
- Keep the cast when calling uart_prepare_sysrq_char() - Johan
- Improve commit log and subject - Johan

 drivers/tty/serial/imx.c | 15 +++++----------
 1 file changed, 5 insertions(+), 10 deletions(-)

diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
index 8b121cd869e9..a0135718c588 100644
--- a/drivers/tty/serial/imx.c
+++ b/drivers/tty/serial/imx.c
@@ -803,7 +803,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void *dev_id)
 				continue;
 		}
 
-		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
+		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
 			continue;
 
 		if (unlikely(rx & URXD_ERR)) {
@@ -844,6 +844,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void *dev_id)
 	}
 
 out:
+	uart_unlock_and_check_sysrq(&sport->port);
 	tty_flip_buffer_push(port);
 
 	return IRQ_HANDLED;
@@ -852,15 +853,10 @@ static irqreturn_t __imx_uart_rxint(int irq, void *dev_id)
 static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
 {
 	struct imx_port *sport = dev_id;
-	irqreturn_t ret;
 
 	spin_lock(&sport->port.lock);
 
-	ret = __imx_uart_rxint(irq, dev_id);
-
-	spin_unlock(&sport->port.lock);
-
-	return ret;
+	return __imx_uart_rxint(irq, dev_id);
 }
 
 static void imx_uart_clear_rx_errors(struct imx_port *sport);
@@ -959,6 +955,7 @@ static irqreturn_t imx_uart_int(int irq, void *dev_id)
 		imx_uart_writel(sport, USR1_AGTIM, USR1);
 
 		__imx_uart_rxint(irq, dev_id);
+		spin_lock(&sport->port.lock);
 		ret = IRQ_HANDLED;
 	}
 
@@ -1977,9 +1974,7 @@ imx_uart_console_write(struct console *co, const char *s, unsigned int count)
 	unsigned int ucr1;
 	int locked = 1;
 
-	if (sport->port.sysrq)
-		locked = 0;
-	else if (oops_in_progress)
+	if (oops_in_progress)
 		locked = spin_trylock_irqsave(&sport->port.lock, flags);
 	else
 		spin_lock_irqsave(&sport->port.lock, flags);
-- 
2.25.1

Re: [PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Johan Hovold]

On Fri, Oct 01, 2021 at 07:18:15AM -0300, Fabio Estevam wrote:
> The following sysrq command causes the following lockdep warning:
> 
>  # echo t > /proc/sysrq-trigger
>  ....
> [   20.325246] ======================================================
> [   20.325252] WARNING: possible circular locking dependency detected
> [   20.325260] 5.15.0-rc2-next-20210924-00004-gd2d6e664f29f-dirty #163
> Not tainted
> [   20.325273] ------------------------------------------------------
> [   20.325279] sh/236 is trying to acquire lock:
> [   20.325293] c1618614 (console_owner){-...}-{0:0}, at:
> console_unlock+0x180/0x5bc
> [   20.325361]
> [   20.325361] but task is already holding lock:
> [   20.325368] eefccc90 (&pool->lock){-.-.}-{2:2}, at:
> show_workqueue_state+0x104/0x3c8
> [   20.325432]
> [   20.325432] which lock already depends on the new lock.
> 
> ...
> 
> [   20.325657] -> #2 (&pool->lock/1){-.-.}-{2:2}:
> [   20.325690]        __queue_work+0x114/0x810
> [   20.325710]        queue_work_on+0x54/0x94
> [   20.325727]        __imx_uart_rxint.constprop.0+0x1b4/0x2e0
> [   20.325760]        imx_uart_int+0x270/0x310
> 
> This problem happens because uart_handle_sysrq_char() is called
> with the lock held.
> 
> Fix this by using the same approach done in commit 5697df7322fe ("serial:
> fsl_lpuart: split sysrq handling"), which calls uart_prepare_sysrq_char()
> and uart_unlock_and_check_sysrq() instead.
> 
> Its commit log says:
> 
> "Instead of uart_handle_sysrq_char() use uart_prepare_sysrq_char() and
> uart_unlock_and_check_sysrq(). This will call handle_sysrq() without
> holding the port lock, which in turn let us drop the spin_trylock hack."
> 
> Do the same here to suppress the false positive lockdep warning.
> 
> As __imx_uart_rxint() drops the lock now, remove the spin_unlock()
> inside imx_uart_rxint(), which is only used on i.MX1.
> 
> Tested on a i.MX7D board via 'echo t > /proc/sysrq-trigger' in the
> command line and also by passing the "<break> + t" keys in
> the serial console.
> 
> Signed-off-by: Fabio Estevam <festevam@denx.de>
> ---
> Changes since v2:
> - Keep the cast when calling uart_prepare_sysrq_char() - Johan
> - Improve commit log and subject - Johan

You changed more things since v2 as that was the broken version that
just dropped the lock.

>  drivers/tty/serial/imx.c | 15 +++++----------
>  1 file changed, 5 insertions(+), 10 deletions(-)
> 
> diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
> index 8b121cd869e9..a0135718c588 100644
> --- a/drivers/tty/serial/imx.c
> +++ b/drivers/tty/serial/imx.c
> @@ -803,7 +803,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void *dev_id)
>  				continue;
>  		}
>  
> -		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
> +		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
>  			continue;
>  
>  		if (unlikely(rx & URXD_ERR)) {
> @@ -844,6 +844,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void *dev_id)
>  	}
>  
>  out:
> +	uart_unlock_and_check_sysrq(&sport->port);
>  	tty_flip_buffer_push(port);
>  
>  	return IRQ_HANDLED;
> @@ -852,15 +853,10 @@ static irqreturn_t __imx_uart_rxint(int irq, void *dev_id)
>  static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
>  {
>  	struct imx_port *sport = dev_id;
> -	irqreturn_t ret;
>  
>  	spin_lock(&sport->port.lock);
>  
> -	ret = __imx_uart_rxint(irq, dev_id);
> -
> -	spin_unlock(&sport->port.lock);

No, no, no.

Just replace this unlock with uart_unlock_and_check_sysrq() and do the
corresponding change in imx_uart_int(). The result is an even smaller
diff than what you're currently proposing and without any performance
penalty from dropping and reacquiring the lock.

> -
> -	return ret;
> +	return __imx_uart_rxint(irq, dev_id);
>  }
>  
>  static void imx_uart_clear_rx_errors(struct imx_port *sport);
> @@ -959,6 +955,7 @@ static irqreturn_t imx_uart_int(int irq, void *dev_id)
>  		imx_uart_writel(sport, USR1_AGTIM, USR1);
>  
>  		__imx_uart_rxint(irq, dev_id);
> +		spin_lock(&sport->port.lock);
>  		ret = IRQ_HANDLED;
>  	}

Johan

Re: [PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Fabio Estevam]

Hi Johan,

On 01/10/2021 10:56, Johan Hovold wrote:

>> @@ -852,15 +853,10 @@ static irqreturn_t __imx_uart_rxint(int irq, 
>> void *dev_id)
>>  static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
>>  {
>>  	struct imx_port *sport = dev_id;
>> -	irqreturn_t ret;
>> 
>>  	spin_lock(&sport->port.lock);
>> 
>> -	ret = __imx_uart_rxint(irq, dev_id);
>> -
>> -	spin_unlock(&sport->port.lock);
> 
> No, no, no.
> 
> Just replace this unlock with uart_unlock_and_check_sysrq() and do the

This does not work as uart_unlock_and_check_sysrq() needs to be
called inside __imx_uart_rxint() prior to tty_flip_buffer_push().

> corresponding change in imx_uart_int(). The result is an even smaller
> diff than what you're currently proposing and without any performance
> penalty from dropping and reacquiring the lock.

Yes, I can avoid the unnecessary reacquiring of the lock as you
suggested:

diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
index 8b121cd869e9..5e38bf8fb7b8 100644
--- a/drivers/tty/serial/imx.c
+++ b/drivers/tty/serial/imx.c
@@ -803,7 +803,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void 
*dev_id)
  				continue;
  		}

-		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
+		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
  			continue;

  		if (unlikely(rx & URXD_ERR)) {
@@ -844,6 +844,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void 
*dev_id)
  	}

  out:
+	uart_unlock_and_check_sysrq(&sport->port);
  	tty_flip_buffer_push(port);

  	return IRQ_HANDLED;
@@ -852,15 +853,10 @@ static irqreturn_t __imx_uart_rxint(int irq, void 
*dev_id)
  static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
  {
  	struct imx_port *sport = dev_id;
-	irqreturn_t ret;

  	spin_lock(&sport->port.lock);

-	ret = __imx_uart_rxint(irq, dev_id);
-
-	spin_unlock(&sport->port.lock);
-
-	return ret;
+	return __imx_uart_rxint(irq, dev_id);
  }

  static void imx_uart_clear_rx_errors(struct imx_port *sport);
@@ -955,13 +951,6 @@ static irqreturn_t imx_uart_int(int irq, void 
*dev_id)
  	if ((ucr4 & UCR4_OREN) == 0)
  		usr2 &= ~USR2_ORE;

-	if (usr1 & (USR1_RRDY | USR1_AGTIM)) {
-		imx_uart_writel(sport, USR1_AGTIM, USR1);
-
-		__imx_uart_rxint(irq, dev_id);
-		ret = IRQ_HANDLED;
-	}
-
  	if ((usr1 & USR1_TRDY) || (usr2 & USR2_TXDC)) {
  		imx_uart_transmit_buffer(sport);
  		ret = IRQ_HANDLED;
@@ -991,8 +980,17 @@ static irqreturn_t imx_uart_int(int irq, void 
*dev_id)
  		ret = IRQ_HANDLED;
  	}

+	if (usr1 & (USR1_RRDY | USR1_AGTIM)) {
+		imx_uart_writel(sport, USR1_AGTIM, USR1);
+
+		__imx_uart_rxint(irq, dev_id);
+		ret = IRQ_HANDLED;
+		goto out;
+	}
+
  	spin_unlock(&sport->port.lock);

+out:
  	return ret;
  }

@@ -1977,9 +1975,7 @@ imx_uart_console_write(struct console *co, const 
char *s, unsigned int count)
  	unsigned int ucr1;
  	int locked = 1;

-	if (sport->port.sysrq)
-		locked = 0;
-	else if (oops_in_progress)
+	if (oops_in_progress)
  		locked = spin_trylock_irqsave(&sport->port.lock, flags);
  	else
  		spin_lock_irqsave(&sport->port.lock, flags);

Re: [PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Fabio Estevam]

On 01/10/2021 10:56, Johan Hovold wrote:

> No, no, no.
> 
> Just replace this unlock with uart_unlock_and_check_sysrq() and do the
> corresponding change in imx_uart_int(). The result is an even smaller
> diff than what you're currently proposing and without any performance
> penalty from dropping and reacquiring the lock.

Just to be clear, this is something that I have also tried:

diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
index 8b121cd869e9..b652908f0bf1 100644
--- a/drivers/tty/serial/imx.c
+++ b/drivers/tty/serial/imx.c
@@ -803,7 +803,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void 
*dev_id)
  				continue;
  		}

-		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
+		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
  			continue;

  		if (unlikely(rx & URXD_ERR)) {
@@ -858,7 +858,7 @@ static irqreturn_t imx_uart_rxint(int irq, void 
*dev_id)

  	ret = __imx_uart_rxint(irq, dev_id);

-	spin_unlock(&sport->port.lock);
+	uart_unlock_and_check_sysrq(&sport->port);

  	return ret;
  }
@@ -991,7 +991,7 @@ static irqreturn_t imx_uart_int(int irq, void 
*dev_id)
  		ret = IRQ_HANDLED;
  	}

-	spin_unlock(&sport->port.lock);
+	uart_unlock_and_check_sysrq(&sport->port);

  	return ret;
  }
@@ -1977,9 +1977,7 @@ imx_uart_console_write(struct console *co, const 
char *s, unsigned int count)
  	unsigned int ucr1;
  	int locked = 1;

-	if (sport->port.sysrq)
-		locked = 0;
-	else if (oops_in_progress)
+	if (oops_in_progress)
  		locked = spin_trylock_irqsave(&sport->port.lock, flags);
  	else
  		spin_lock_irqsave(&sport->port.lock, flags);

, but still get the lockdep warning in this case.

Thanks

Re: [PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Johan Hovold]

On Fri, Oct 01, 2021 at 11:15:33PM -0300, Fabio Estevam wrote:
> On 01/10/2021 10:56, Johan Hovold wrote:
> 
> > No, no, no.
> > 
> > Just replace this unlock with uart_unlock_and_check_sysrq() and do the
> > corresponding change in imx_uart_int(). The result is an even smaller
> > diff than what you're currently proposing and without any performance
> > penalty from dropping and reacquiring the lock.
> 
> Just to be clear, this is something that I have also tried:
> 
> diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
> index 8b121cd869e9..b652908f0bf1 100644
> --- a/drivers/tty/serial/imx.c
> +++ b/drivers/tty/serial/imx.c
> @@ -803,7 +803,7 @@ static irqreturn_t __imx_uart_rxint(int irq, void 
> *dev_id)
>   				continue;
>   		}
> 
> -		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
> +		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
>   			continue;
> 
>   		if (unlikely(rx & URXD_ERR)) {
> @@ -858,7 +858,7 @@ static irqreturn_t imx_uart_rxint(int irq, void 
> *dev_id)
> 
>   	ret = __imx_uart_rxint(irq, dev_id);
> 
> -	spin_unlock(&sport->port.lock);
> +	uart_unlock_and_check_sysrq(&sport->port);
> 
>   	return ret;
>   }
> @@ -991,7 +991,7 @@ static irqreturn_t imx_uart_int(int irq, void 
> *dev_id)
>   		ret = IRQ_HANDLED;
>   	}
> 
> -	spin_unlock(&sport->port.lock);
> +	uart_unlock_and_check_sysrq(&sport->port);
> 
>   	return ret;
>   }

> , but still get the lockdep warning in this case.

Ok, thanks for testing. The above is what I meant and it does fix the
false-positive lockdep splat which motivated
uart_unlock_and_check_sysrq() to be added in the first place.

Looking closer at the splat you reported (which you've edited quite
heavily), it becomes apparent that you are now hitting a different
locking issue. And it's not a false positive this time.

There a problem with the workqueue debugging code, which unless fixed at
the source, would prevent any console driver from queueing work while
holding a lock also taken in their write paths. And
tty_flip_buffer_push() is just one example of many.

I can easily reproduce the splat with another serial driver, and I've
also been able to trigger the actual deadlock.

I've prepared a patch that takes care of the workqueue state dumping,
which I'll send as a reply to this mail. Would you mind giving it a spin
with the imx driver as well?

Note that you may hit the other, false-positive, lockdep splat when
running with the workqueue fix, but the above diff should then address
that.

Johan

[PATCH] workqueue: fix state-dump console deadlock

[Johan Hovold]

Console drivers often queue work while holding locks also taken in their
console write paths, something which can lead to deadlocks on SMP when
dumping workqueue state (e.g. sysrq-t or on suspend failures).

For serial console drivers this could look like:

	CPU0				CPU1
	----				----

	show_workqueue_state();
	  lock(&pool->lock);		<IRQ>
	  				  lock(&port->lock);
					  schedule_work();
					    lock(&pool->lock);
	  printk();
	    lock(console_owner);
	    lock(&port->lock);

where workqueues are, for example, used to push data to the line
discipline, process break signals and handle modem-status changes. Line
disciplines and serdev drivers can also queue work on write-wakeup
notifications, etc.

Reworking every console driver to avoid queuing work while holding locks
also taken in their write paths would complicate drivers and is neither
desirable or feasible.

Instead use the deferred-printk mechanism to avoid printing while
holding pool locks when dumping workqueue state.

Note that there are a few WARN_ON() assertions in the workqueue code
which could potentially also trigger a deadlock. Hopefully the ongoing
printk rework will provide a general solution for this eventually.

This was originally reported after a lockdep splat when executing
sysrq-t with the imx serial driver.

Fixes: 3494fc30846d ("workqueue: dump workqueues on sysrq-t")
Cc: stable@vger.kernel.org	# 4.0
Reported-by: Fabio Estevam <festevam@denx.de>
Signed-off-by: Johan Hovold <johan@kernel.org>
---
 kernel/workqueue.c | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index 33a6b4a2443d..fded64b48b96 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -4830,8 +4830,16 @@ void show_workqueue_state(void)
 
 		for_each_pwq(pwq, wq) {
 			raw_spin_lock_irqsave(&pwq->pool->lock, flags);
-			if (pwq->nr_active || !list_empty(&pwq->inactive_works))
+			if (pwq->nr_active || !list_empty(&pwq->inactive_works)) {
+				/*
+				 * Defer printing to avoid deadlocks in console
+				 * drivers that queue work while holding locks
+				 * also taken in their write paths.
+				 */
+				printk_deferred_enter();
 				show_pwq(pwq);
+				printk_deferred_exit();
+			}
 			raw_spin_unlock_irqrestore(&pwq->pool->lock, flags);
 			/*
 			 * We could be printing a lot from atomic context, e.g.
-- 
2.32.0

Re: [PATCH] workqueue: fix state-dump console deadlock

[Petr Mladek]

On Wed 2021-10-06 10:11:15, Johan Hovold wrote:
> Console drivers often queue work while holding locks also taken in their
> console write paths, something which can lead to deadlocks on SMP when
> dumping workqueue state (e.g. sysrq-t or on suspend failures).
> 
> For serial console drivers this could look like:
> 
> 	CPU0				CPU1
> 	----				----
> 
> 	show_workqueue_state();
> 	  lock(&pool->lock);		<IRQ>
> 	  				  lock(&port->lock);
> 					  schedule_work();
> 					    lock(&pool->lock);
> 	  printk();
> 	    lock(console_owner);
> 	    lock(&port->lock);
> 
> where workqueues are, for example, used to push data to the line
> discipline, process break signals and handle modem-status changes. Line
> disciplines and serdev drivers can also queue work on write-wakeup
> notifications, etc.
> 
> Reworking every console driver to avoid queuing work while holding locks
> also taken in their write paths would complicate drivers and is neither
> desirable or feasible.
> 
> Instead use the deferred-printk mechanism to avoid printing while
> holding pool locks when dumping workqueue state.
> 
> Note that there are a few WARN_ON() assertions in the workqueue code
> which could potentially also trigger a deadlock. Hopefully the ongoing
> printk rework will provide a general solution for this eventually.
> 
> This was originally reported after a lockdep splat when executing
> sysrq-t with the imx serial driver.
> 
> Fixes: 3494fc30846d ("workqueue: dump workqueues on sysrq-t")
> Cc: stable@vger.kernel.org	# 4.0
> Reported-by: Fabio Estevam <festevam@denx.de>
> Signed-off-by: Johan Hovold <johan@kernel.org>
> ---
>  kernel/workqueue.c | 10 +++++++++-
>  1 file changed, 9 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
> index 33a6b4a2443d..fded64b48b96 100644
> --- a/kernel/workqueue.c
> +++ b/kernel/workqueue.c
> @@ -4830,8 +4830,16 @@ void show_workqueue_state(void)
>  
>  		for_each_pwq(pwq, wq) {
>  			raw_spin_lock_irqsave(&pwq->pool->lock, flags);
> -			if (pwq->nr_active || !list_empty(&pwq->inactive_works))
> +			if (pwq->nr_active || !list_empty(&pwq->inactive_works)) {
> +				/*
> +				 * Defer printing to avoid deadlocks in console
> +				 * drivers that queue work while holding locks
> +				 * also taken in their write paths.
> +				 */
> +				printk_deferred_enter();
>  				show_pwq(pwq);
> +				printk_deferred_exit();
> +			}
>  			raw_spin_unlock_irqrestore(&pwq->pool->lock, flags);
>  			/*
>  			 * We could be printing a lot from atomic context, e.g.

This handles only one printk() caller. But there are many more callers
under pool->lock, for example in the next for-cycle in this function:

	for_each_pool(pool, pi) {
		raw_spin_lock_irqsave(&pool->lock, flags);
[...]
		pr_info("pool %d:", pool->id);
		pr_cont_pool_info(pool);
		pr_cont(" hung=%us workers=%d",

And this is the problem with printk_deferred() and printk_deferred_enter().
It is a "catch a mole" approach. It might end up with switching half
of the kernel into printk_deferred().

John Ogness is working on a generic solution where any printk() will
be deferred out of box. consoles will be called from a dedicated
kthreads.

John has already worked on reworking printk() two years or so. It gets
slowly because we need to be careful. Also we started with
implementing lockless ringbuffer which was a big challenge. Anyway, there
is a stable progress. The lockless ringbuffer is done. And the
kthreads are the very next step.

printk_deferred() is currently used only in the scheduler code where
the deadlocks really happened in the past. printk_deferred_enter()
is used only in printk() because it would be otherwise hard to debug
and lockdep would always report problems there.

From this perspective, I suggest to ignore this possible deadlock if
they do not happen in the real life.

If you really want to avoid the lockdep report. Alternative and
probably easier workaround is to temporary disable lockdep around
queuing the work in the console code. I do not see any reason
why workqueue code would call back to console code directly.
So the only source of a possible deadlock is the printk() path.
But I think that it is not worth it. It is better to concentrate
on the printk() rework.

Best Regards,
Petr

Re: [PATCH] workqueue: fix state-dump console deadlock

[Johan Hovold]

On Wed, Oct 06, 2021 at 11:19:01AM +0200, Petr Mladek wrote:
> On Wed 2021-10-06 10:11:15, Johan Hovold wrote:
> > Console drivers often queue work while holding locks also taken in their
> > console write paths, something which can lead to deadlocks on SMP when
> > dumping workqueue state (e.g. sysrq-t or on suspend failures).
> > 
> > For serial console drivers this could look like:
> > 
> > 	CPU0				CPU1
> > 	----				----
> > 
> > 	show_workqueue_state();
> > 	  lock(&pool->lock);		<IRQ>
> > 	  				  lock(&port->lock);
> > 					  schedule_work();
> > 					    lock(&pool->lock);
> > 	  printk();
> > 	    lock(console_owner);
> > 	    lock(&port->lock);
> > 
> > where workqueues are, for example, used to push data to the line
> > discipline, process break signals and handle modem-status changes. Line
> > disciplines and serdev drivers can also queue work on write-wakeup
> > notifications, etc.
> > 
> > Reworking every console driver to avoid queuing work while holding locks
> > also taken in their write paths would complicate drivers and is neither
> > desirable or feasible.
> > 
> > Instead use the deferred-printk mechanism to avoid printing while
> > holding pool locks when dumping workqueue state.
> > 
> > Note that there are a few WARN_ON() assertions in the workqueue code
> > which could potentially also trigger a deadlock. Hopefully the ongoing
> > printk rework will provide a general solution for this eventually.
> > 
> > This was originally reported after a lockdep splat when executing
> > sysrq-t with the imx serial driver.
> > 
> > Fixes: 3494fc30846d ("workqueue: dump workqueues on sysrq-t")
> > Cc: stable@vger.kernel.org	# 4.0
> > Reported-by: Fabio Estevam <festevam@denx.de>
> > Signed-off-by: Johan Hovold <johan@kernel.org>
> > ---
> >  kernel/workqueue.c | 10 +++++++++-
> >  1 file changed, 9 insertions(+), 1 deletion(-)
> > 
> > diff --git a/kernel/workqueue.c b/kernel/workqueue.c
> > index 33a6b4a2443d..fded64b48b96 100644
> > --- a/kernel/workqueue.c
> > +++ b/kernel/workqueue.c
> > @@ -4830,8 +4830,16 @@ void show_workqueue_state(void)
> >  
> >  		for_each_pwq(pwq, wq) {
> >  			raw_spin_lock_irqsave(&pwq->pool->lock, flags);
> > -			if (pwq->nr_active || !list_empty(&pwq->inactive_works))
> > +			if (pwq->nr_active || !list_empty(&pwq->inactive_works)) {
> > +				/*
> > +				 * Defer printing to avoid deadlocks in console
> > +				 * drivers that queue work while holding locks
> > +				 * also taken in their write paths.
> > +				 */
> > +				printk_deferred_enter();
> >  				show_pwq(pwq);
> > +				printk_deferred_exit();
> > +			}
> >  			raw_spin_unlock_irqrestore(&pwq->pool->lock, flags);
> >  			/*
> >  			 * We could be printing a lot from atomic context, e.g.
> 
> This handles only one printk() caller. But there are many more callers
> under pool->lock, for example in the next for-cycle in this function:
> 
> 	for_each_pool(pool, pi) {
> 		raw_spin_lock_irqsave(&pool->lock, flags);
> [...]
> 		pr_info("pool %d:", pool->id);
> 		pr_cont_pool_info(pool);
> 		pr_cont(" hung=%us workers=%d",

Heh, thanks for catching that one. As noted above, I did look through
the other instances, which are mostly asserts, but missed this obvious
one.

There does not seem to be "many more callers" under the pool lock when
not counting the WARN_ON()s (which we also have in the scheduler code).

> And this is the problem with printk_deferred() and printk_deferred_enter().
> It is a "catch a mole" approach. It might end up with switching half
> of the kernel into printk_deferred().

The workqueue implementation is core infrastructure where, like in the
scheduler, some extra care can be justified.
 
> John Ogness is working on a generic solution where any printk() will
> be deferred out of box. consoles will be called from a dedicated
> kthreads.
> 
> John has already worked on reworking printk() two years or so. It gets
> slowly because we need to be careful. Also we started with
> implementing lockless ringbuffer which was a big challenge. Anyway, there
> is a stable progress. The lockless ringbuffer is done. And the
> kthreads are the very next step.
> 
> printk_deferred() is currently used only in the scheduler code where
> the deadlocks really happened in the past. 

It's actually used in a few places outside of the scheduler already to
prevent deadlocks and suppress lockdep warnings.

> printk_deferred_enter()
> is used only in printk() because it would be otherwise hard to debug
> and lockdep would always report problems there.

printk_deferred_enter() is also used in a couple of places outside of
printk already.

> From this perspective, I suggest to ignore this possible deadlock if
> they do not happen in the real life.
> 
> If you really want to avoid the lockdep report. Alternative and
> probably easier workaround is to temporary disable lockdep around
> queuing the work in the console code.

Now *that* would be playing whack-a-mole. As I alluded to in the commit
message there are ton of places where we queue work under the serial
driver port lock and its generally not done explicitly in the drivers
themselves but rather in the tty layer helpers, line disciplines, serdev
drivers, etc.

Disabling lockdep is not an option here.

> I do not see any reason
> why workqueue code would call back to console code directly.
> So the only source of a possible deadlock is the printk() path.
> But I think that it is not worth it. It is better to concentrate
> on the printk() rework.

Right, it's only printk, and it's only in show_workqueue_state() (when
ignoring the assertions). Since we can't suppress the lockdep warning in
the console drivers, and since this function is called outside of sysrq
handling too (e.g. on suspend failures), I'd say the workaround is
warranted until the printk rework is done.

Johan

Re: [PATCH] workqueue: fix state-dump console deadlock

[Fabio Estevam]

Hi Johan,

On 06/10/2021 05:11, Johan Hovold wrote:
> Console drivers often queue work while holding locks also taken in 
> their
> console write paths, something which can lead to deadlocks on SMP when
> dumping workqueue state (e.g. sysrq-t or on suspend failures).
> 
> For serial console drivers this could look like:
> 
> 	CPU0				CPU1
> 	----				----
> 
> 	show_workqueue_state();
> 	  lock(&pool->lock);		<IRQ>
> 	  				  lock(&port->lock);
> 					  schedule_work();
> 					    lock(&pool->lock);
> 	  printk();
> 	    lock(console_owner);
> 	    lock(&port->lock);
> 
> where workqueues are, for example, used to push data to the line
> discipline, process break signals and handle modem-status changes. Line
> disciplines and serdev drivers can also queue work on write-wakeup
> notifications, etc.
> 
> Reworking every console driver to avoid queuing work while holding 
> locks
> also taken in their write paths would complicate drivers and is neither
> desirable or feasible.
> 
> Instead use the deferred-printk mechanism to avoid printing while
> holding pool locks when dumping workqueue state.
> 
> Note that there are a few WARN_ON() assertions in the workqueue code
> which could potentially also trigger a deadlock. Hopefully the ongoing
> printk rework will provide a general solution for this eventually.
> 
> This was originally reported after a lockdep splat when executing
> sysrq-t with the imx serial driver.
> 
> Fixes: 3494fc30846d ("workqueue: dump workqueues on sysrq-t")
> Cc: stable@vger.kernel.org	# 4.0
> Reported-by: Fabio Estevam <festevam@denx.de>
> Signed-off-by: Johan Hovold <johan@kernel.org>

With this patch applied, I no longer get the lockdep splat when 
executing
sysrq-t with the imx serial driver, thanks:

Tested-by: Fabio Estevam <festevam@denx.de>

Re: [PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Fabio Estevam]

Hi Johan,

On 06/10/2021 05:10, Johan Hovold wrote:

> Ok, thanks for testing. The above is what I meant and it does fix the
> false-positive lockdep splat which motivated
> uart_unlock_and_check_sysrq() to be added in the first place.
> 
> Looking closer at the splat you reported (which you've edited quite
> heavily), it becomes apparent that you are now hitting a different
> locking issue. And it's not a false positive this time.
> 
> There a problem with the workqueue debugging code, which unless fixed 
> at
> the source, would prevent any console driver from queueing work while
> holding a lock also taken in their write paths. And
> tty_flip_buffer_push() is just one example of many.
> 
> I can easily reproduce the splat with another serial driver, and I've
> also been able to trigger the actual deadlock.
> 
> I've prepared a patch that takes care of the workqueue state dumping,
> which I'll send as a reply to this mail. Would you mind giving it a 
> spin
> with the imx driver as well?

Yes, after applying only your patch I no longer get the lockdep
splat. I have replied with my Tested-by, thanks.

Re: [PATCH v3] serial: imx: Suppress false positive sysrq lockdep warning

[Johan Hovold]

On Wed, Oct 06, 2021 at 07:52:25AM -0300, Fabio Estevam wrote:

> On 06/10/2021 05:10, Johan Hovold wrote:

> > I've prepared a patch that takes care of the workqueue state dumping,
> > which I'll send as a reply to this mail. Would you mind giving it a 
> > spin
> > with the imx driver as well?
> 
> Yes, after applying only your patch I no longer get the lockdep
> splat. I have replied with my Tested-by, thanks.

Perfect, thanks for confirming.

Johan