All of lore.kernel.org
 help / color / mirror / Atom feed
* Regression in fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()")
@ 2019-09-17 14:10 Uwe Kleine-König
  2019-09-18  1:30 ` Sergey Senozhatsky
  0 siblings, 1 reply; 6+ messages in thread
From: Uwe Kleine-König @ 2019-09-17 14:10 UTC (permalink / raw)
  To: Sergey Senozhatsky, Tetsuo Handa, Steven Rostedt, Petr Mladek
  Cc: linux-kernel

Hello,

Today it saw sysrq on an UART driven by drivers/tty/serial/imx.c report
a lockdep issue. Bisecting pointed to 

	fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()")

When I type <break>t I get:

[   87.940104] sysrq: SysRq : This sysrq operation is disabled.
[   87.948752] 
[   87.948772] ======================================================
[   87.948787] WARNING: possible circular locking dependency detected
[   87.948798] 4.14.0-12954-gfd5f7cde1b85 #26 Not tainted
[   87.948813] ------------------------------------------------------
[   87.948822] swapper/0 is trying to acquire lock:
[   87.948829]  (console_owner){-...}, at: [<c015e438>] console_unlock+0x110/0x598
[   87.948861] 
[   87.948869] but task is already holding lock:
[   87.948874]  (&port_lock_key){-.-.}, at: [<c048d5b0>] imx_rxint+0x2c/0x290
[   87.948902] 
[   87.948911] which lock already depends on the new lock.
[   87.948917] 
[   87.948923] 
[   87.948932] the existing dependency chain (in reverse order) is:
[   87.948938] 
[   87.948943] -> #1 (&port_lock_key){-.-.}:
[   87.948975]        _raw_spin_lock_irqsave+0x5c/0x70
[   87.948983]        imx_console_write+0x138/0x15c
[   87.948991]        console_unlock+0x204/0x598
[   87.949000]        register_console+0x21c/0x3e8
[   87.949008]        uart_add_one_port+0x3e4/0x4dc
[   87.949019]        platform_drv_probe+0x3c/0x78
[   87.949027]        driver_probe_device+0x25c/0x47c
[   87.949035]        __driver_attach+0xec/0x114
[   87.949044]        bus_for_each_dev+0x80/0xb0
[   87.949054]        bus_add_driver+0x1d4/0x264
[   87.949062]        driver_register+0x80/0xfc
[   87.949069]        imx_serial_init+0x28/0x48
[   87.949078]        do_one_initcall+0x44/0x18c
[   87.949087]        kernel_init_freeable+0x11c/0x1cc
[   87.949095]        kernel_init+0x10/0x114
[   87.949103]        ret_from_fork+0x14/0x30
[   87.949108] 
[   87.949113] -> #0 (console_owner){-...}:
[   87.949145]        lock_acquire+0x100/0x23c
[   87.949154]        console_unlock+0x1a4/0x598
[   87.949162]        vprintk_emit+0x1a4/0x45c
[   87.949171]        vprintk_default+0x28/0x30
[   87.949180]        printk+0x28/0x38
[   87.949189]        __handle_sysrq+0x1c4/0x244
[   87.949196]        imx_rxint+0x258/0x290
[   87.949206]        imx_int+0x170/0x178
[   87.949216]        __handle_irq_event_percpu+0x78/0x418
[   87.949225]        handle_irq_event_percpu+0x24/0x6c
[   87.949233]        handle_irq_event+0x40/0x64
[   87.949242]        handle_level_irq+0xb4/0x138
[   87.949252]        generic_handle_irq+0x28/0x3c
[   87.949261]        __handle_domain_irq+0x50/0xb0
[   87.949269]        avic_handle_irq+0x3c/0x5c
[   87.949277]        __irq_svc+0x6c/0xa4
[   87.949287]        arch_cpu_idle+0x30/0x40
[   87.949297]        arch_cpu_idle+0x30/0x40
[   87.949305]        do_idle+0xa0/0x104
[   87.949313]        cpu_startup_entry+0x14/0x18
[   87.949323]        start_kernel+0x30c/0x368
[   87.949328] 
[   87.949337] other info that might help us debug this:
[   87.949342] 
[   87.949351]  Possible unsafe locking scenario:
[   87.949356] 
[   87.949364]        CPU0                    CPU1
[   87.949372]        ----                    ----
[   87.949378]   lock(&port_lock_key);
[   87.949398]                                lock(console_owner);
[   87.949423]                                lock(&port_lock_key);
[   87.949441]   lock(console_owner);
[   87.949459] 
[   87.949466]  *** DEADLOCK ***
[   87.949471] 
[   87.949478] 3 locks held by swapper/0:
[   87.949484]  #0:  (&port_lock_key){-.-.}, at: [<c048d5b0>] imx_rxint+0x2c/0x290
[   87.949515]  #1:  (rcu_read_lock){....}, at: [<c0486ea8>] __handle_sysrq+0x0/0x244
[   87.949549]  #2:  (console_lock){+.+.}, at: [<c015ea58>] vprintk_emit+0x198/0x45c
[   87.949581] 
[   87.949588] stack backtrace:
[   87.949600] CPU: 0 PID: 0 Comm: swapper Not tainted 4.14.0-12954-gfd5f7cde1b85 #26
[   87.949611] Hardware name: Freescale i.MX25 (Device Tree Support)
[   87.949623] [<c0108f70>] (unwind_backtrace) from [<c010680c>] (show_stack+0x18/0x1c)
[   87.949635] [<c010680c>] (show_stack) from [<c01526ec>] (print_circular_bug+0x284/0x3c0)
[   87.949647] [<c01526ec>] (print_circular_bug) from [<c0153714>] (check_prev_add+0x4ac/0x7cc)
[   87.949660] [<c0153714>] (check_prev_add) from [<c015561c>] (__lock_acquire+0x9e8/0x13bc)
[   87.949671] [<c015561c>] (__lock_acquire) from [<c0156a28>] (lock_acquire+0x100/0x23c)
[   87.949683] [<c0156a28>] (lock_acquire) from [<c015e4cc>] (console_unlock+0x1a4/0x598)
[   87.949696] [<c015e4cc>] (console_unlock) from [<c015ea64>] (vprintk_emit+0x1a4/0x45c)
[   87.949707] [<c015ea64>] (vprintk_emit) from [<c015eec8>] (vprintk_default+0x28/0x30)
[   87.949719] [<c015eec8>] (vprintk_default) from [<c015fa80>] (printk+0x28/0x38)
[   87.949730] [<c015fa80>] (printk) from [<c048706c>] (__handle_sysrq+0x1c4/0x244)
[   87.949742] [<c048706c>] (__handle_sysrq) from [<c048d7dc>] (imx_rxint+0x258/0x290)
[   87.949753] [<c048d7dc>] (imx_rxint) from [<c048edd0>] (imx_int+0x170/0x178)
[   87.949765] [<c048edd0>] (imx_int) from [<c0160ce4>] (__handle_irq_event_percpu+0x78/0x418)
[   87.949781] [<c0160ce4>] (__handle_irq_event_percpu) from [<c01610a8>] (handle_irq_event_percpu+0x24/0x6c)
[   87.949794] [<c01610a8>] (handle_irq_event_percpu) from [<c0161130>] (handle_irq_event+0x40/0x64)
[   87.949808] [<c0161130>] (handle_irq_event) from [<c01642b4>] (handle_level_irq+0xb4/0x138)
[   87.949821] [<c01642b4>] (handle_level_irq) from [<c01602dc>] (generic_handle_irq+0x28/0x3c)
[   87.949833] [<c01602dc>] (generic_handle_irq) from [<c01608e4>] (__handle_domain_irq+0x50/0xb0)
[   87.949846] [<c01608e4>] (__handle_domain_irq) from [<c0101494>] (avic_handle_irq+0x3c/0x5c)
[   87.949857] [<c0101494>] (avic_handle_irq) from [<c01075ec>] (__irq_svc+0x6c/0xa4)
[   87.949866] Exception stack(0xc0c01f48 to 0xc0c01f90)
[   87.949879] 1f40:                   00000001 00000001 00000000 20000013 ffffe000 c0c078c8
[   87.949891] 1f60: c0c835aa c094ac0c c7eeca40 c0b3a920 00053177 00000000 00000000 c0c01f98
[   87.949900] 1f80: c01548b4 c01033bc 20000013 ffffffff
[   87.949911] [<c01075ec>] (__irq_svc) from [<c01033bc>] (arch_cpu_idle+0x30/0x40)
[   87.949922] [<c01033bc>] (arch_cpu_idle) from [<c014f09c>] (do_idle+0xa0/0x104)
[   87.949934] [<c014f09c>] (do_idle) from [<c014f448>] (cpu_startup_entry+0x14/0x18)
[   87.949946] [<c014f448>] (cpu_startup_entry) from [<c0b00c78>] (start_kernel+0x30c/0x368)

I didn't even try to understand that change, so for now you just get the
lockdep splat :-)

Best regards
Uwe

-- 
Pengutronix e.K.                           | Uwe Kleine-König            |
Industrial Linux Solutions                 | http://www.pengutronix.de/  |

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Regression in fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()")
  2019-09-17 14:10 Regression in fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()") Uwe Kleine-König
@ 2019-09-18  1:30 ` Sergey Senozhatsky
  2019-09-18  7:11   ` Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")] Uwe Kleine-König
  0 siblings, 1 reply; 6+ messages in thread
From: Sergey Senozhatsky @ 2019-09-18  1:30 UTC (permalink / raw)
  To: Uwe Kleine-König
  Cc: Sergey Senozhatsky, Tetsuo Handa, Steven Rostedt, Petr Mladek,
	linux-kernel, Sergey Senozhatsky

On (09/17/19 16:10), Uwe Kleine-König wrote:
> Hello,
>
> Today it saw sysrq on an UART driven by drivers/tty/serial/imx.c report
> a lockdep issue. Bisecting pointed to
>
> 	fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()")

Hmmm...

I don't see how this patch can affect anything. It simply
disables preemption in printk().

> When I type <break>t I get:
> 
> [   87.940104] sysrq: SysRq : This sysrq operation is disabled.
> [   87.948752] 
> [   87.948772] ======================================================
> [   87.948787] WARNING: possible circular locking dependency detected
> [   87.948798] 4.14.0-12954-gfd5f7cde1b85 #26 Not tainted
> [   87.948813] ------------------------------------------------------
> [   87.948822] swapper/0 is trying to acquire lock:
> [   87.948829]  (console_owner){-...}, at: [<c015e438>] console_unlock+0x110/0x598
> [   87.948861] 
> [   87.948869] but task is already holding lock:
> [   87.948874]  (&port_lock_key){-.-.}, at: [<c048d5b0>] imx_rxint+0x2c/0x290
> [   87.948902] 
> [   87.948911] which lock already depends on the new lock.
> [   87.948917] 
> [   87.948923] 
> [   87.948932] the existing dependency chain (in reverse order) is:
> [   87.948938] 
> [   87.948943] -> #1 (&port_lock_key){-.-.}:
> [   87.948975]        _raw_spin_lock_irqsave+0x5c/0x70
> [   87.948983]        imx_console_write+0x138/0x15c
> [   87.948991]        console_unlock+0x204/0x598
> [   87.949000]        register_console+0x21c/0x3e8
> [   87.949008]        uart_add_one_port+0x3e4/0x4dc
> [   87.949019]        platform_drv_probe+0x3c/0x78
> [   87.949027]        driver_probe_device+0x25c/0x47c
> [   87.949035]        __driver_attach+0xec/0x114
> [   87.949044]        bus_for_each_dev+0x80/0xb0
> [   87.949054]        bus_add_driver+0x1d4/0x264
> [   87.949062]        driver_register+0x80/0xfc
> [   87.949069]        imx_serial_init+0x28/0x48
> [   87.949078]        do_one_initcall+0x44/0x18c
> [   87.949087]        kernel_init_freeable+0x11c/0x1cc
> [   87.949095]        kernel_init+0x10/0x114
> [   87.949103]        ret_from_fork+0x14/0x30

This is "normal" locking path

	console_sem -> port->lock

	printk()
	 lock console_sem
	  imx_console_write()
	   lock port->lock

> [   87.949113] -> #0 (console_owner){-...}:
> [   87.949145]        lock_acquire+0x100/0x23c
> [   87.949154]        console_unlock+0x1a4/0x598
> [   87.949162]        vprintk_emit+0x1a4/0x45c
> [   87.949171]        vprintk_default+0x28/0x30
> [   87.949180]        printk+0x28/0x38
> [   87.949189]        __handle_sysrq+0x1c4/0x244
> [   87.949196]        imx_rxint+0x258/0x290
> [   87.949206]        imx_int+0x170/0x178
> [   87.949216]        __handle_irq_event_percpu+0x78/0x418
> [   87.949225]        handle_irq_event_percpu+0x24/0x6c
> [   87.949233]        handle_irq_event+0x40/0x64
> [   87.949242]        handle_level_irq+0xb4/0x138
> [   87.949252]        generic_handle_irq+0x28/0x3c
> [   87.949261]        __handle_domain_irq+0x50/0xb0
> [   87.949269]        avic_handle_irq+0x3c/0x5c
> [   87.949277]        __irq_svc+0x6c/0xa4
> [   87.949287]        arch_cpu_idle+0x30/0x40
> [   87.949297]        arch_cpu_idle+0x30/0x40
> [   87.949305]        do_idle+0xa0/0x104
> [   87.949313]        cpu_startup_entry+0x14/0x18
> [   87.949323]        start_kernel+0x30c/0x368

This one is a "reverse" locking path...

	port->lock -> console_sem

There is more to it:

 imxint()
  lock port->lock
   uart_handle_sysrq_char()
    handle_sysrq()
     printk()
      lock conosole_sem
       imx_console_write()
        lock port->lock			[boom]

This path re-enters serial driver. But it doesn't deadlock, because
uart_handle_sysrq_char() sets a special flag port->sysrq, and serial
consoles are expected to make sure that they don't lock port->lock
in this case. Otherwise we will kill the system:

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

So I'd say that lockdep is correct, but there are several hacks which
prevent actual deadlock.

No idea why bisection has pointed at fd5f7cde1b85, it really doesn't
change the locking patterns.

	-ss

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")]
  2019-09-18  1:30 ` Sergey Senozhatsky
@ 2019-09-18  7:11   ` Uwe Kleine-König
  2019-09-18  7:52     ` Sergey Senozhatsky
  0 siblings, 1 reply; 6+ messages in thread
From: Uwe Kleine-König @ 2019-09-18  7:11 UTC (permalink / raw)
  To: Sergey Senozhatsky
  Cc: Tetsuo Handa, Steven Rostedt, Petr Mladek, linux-kernel,
	Sergey Senozhatsky

Hello Sergey,

On Wed, Sep 18, 2019 at 10:30:32AM +0900, Sergey Senozhatsky wrote:
> On (09/17/19 16:10), Uwe Kleine-König wrote:
> > Hello,
> >
> > Today it saw sysrq on an UART driven by drivers/tty/serial/imx.c report
> > a lockdep issue. Bisecting pointed to
> >
> > 	fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()")
> 
> Hmmm...
> 
> I don't see how this patch can affect anything. It simply
> disables preemption in printk().

I rechecked and indeed fd5f7cde1b85's parent has the problem, too, so I
did a mistake during my bisection :-|

Redoing the bisection (a bit quicker this time) points to

dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes")

Sorry for the confusion.

> > When I type <break>t I get:
> > 
> > [   87.940104] sysrq: SysRq : This sysrq operation is disabled.
> > [   87.948752] 
> > [   87.948772] ======================================================
> > [   87.948787] WARNING: possible circular locking dependency detected
> > [   87.948798] 4.14.0-12954-gfd5f7cde1b85 #26 Not tainted
> > [   87.948813] ------------------------------------------------------
> > [   87.948822] swapper/0 is trying to acquire lock:
> > [   87.948829]  (console_owner){-...}, at: [<c015e438>] console_unlock+0x110/0x598
> > [   87.948861] 
> > [   87.948869] but task is already holding lock:
> > [   87.948874]  (&port_lock_key){-.-.}, at: [<c048d5b0>] imx_rxint+0x2c/0x290
> > [   87.948902] 
> > [   87.948911] which lock already depends on the new lock.
> > [   87.948917] 
> > [   87.948923] 
> > [   87.948932] the existing dependency chain (in reverse order) is:
> > [   87.948938] 
> > [   87.948943] -> #1 (&port_lock_key){-.-.}:
> > [   87.948975]        _raw_spin_lock_irqsave+0x5c/0x70
> > [   87.948983]        imx_console_write+0x138/0x15c
> > [   87.948991]        console_unlock+0x204/0x598
> > [   87.949000]        register_console+0x21c/0x3e8
> > [   87.949008]        uart_add_one_port+0x3e4/0x4dc
> > [   87.949019]        platform_drv_probe+0x3c/0x78
> > [   87.949027]        driver_probe_device+0x25c/0x47c
> > [   87.949035]        __driver_attach+0xec/0x114
> > [   87.949044]        bus_for_each_dev+0x80/0xb0
> > [   87.949054]        bus_add_driver+0x1d4/0x264
> > [   87.949062]        driver_register+0x80/0xfc
> > [   87.949069]        imx_serial_init+0x28/0x48
> > [   87.949078]        do_one_initcall+0x44/0x18c
> > [   87.949087]        kernel_init_freeable+0x11c/0x1cc
> > [   87.949095]        kernel_init+0x10/0x114
> > [   87.949103]        ret_from_fork+0x14/0x30
> 
> This is "normal" locking path
> 
> 	console_sem -> port->lock
> 
> 	printk()
> 	 lock console_sem
> 	  imx_console_write()
> 	   lock port->lock
> 
> > [   87.949113] -> #0 (console_owner){-...}:
> > [   87.949145]        lock_acquire+0x100/0x23c
> > [   87.949154]        console_unlock+0x1a4/0x598
> > [   87.949162]        vprintk_emit+0x1a4/0x45c
> > [   87.949171]        vprintk_default+0x28/0x30
> > [   87.949180]        printk+0x28/0x38
> > [   87.949189]        __handle_sysrq+0x1c4/0x244
> > [   87.949196]        imx_rxint+0x258/0x290
> > [   87.949206]        imx_int+0x170/0x178
> > [   87.949216]        __handle_irq_event_percpu+0x78/0x418
> > [   87.949225]        handle_irq_event_percpu+0x24/0x6c
> > [   87.949233]        handle_irq_event+0x40/0x64
> > [   87.949242]        handle_level_irq+0xb4/0x138
> > [   87.949252]        generic_handle_irq+0x28/0x3c
> > [   87.949261]        __handle_domain_irq+0x50/0xb0
> > [   87.949269]        avic_handle_irq+0x3c/0x5c
> > [   87.949277]        __irq_svc+0x6c/0xa4
> > [   87.949287]        arch_cpu_idle+0x30/0x40
> > [   87.949297]        arch_cpu_idle+0x30/0x40
> > [   87.949305]        do_idle+0xa0/0x104
> > [   87.949313]        cpu_startup_entry+0x14/0x18
> > [   87.949323]        start_kernel+0x30c/0x368
> 
> This one is a "reverse" locking path...
> 
> 	port->lock -> console_sem
> 
> There is more to it:
> 
>  imxint()
>   lock port->lock
>    uart_handle_sysrq_char()
>     handle_sysrq()
>      printk()
>       lock conosole_sem
>        imx_console_write()
>         lock port->lock			[boom]
> 
> This path re-enters serial driver. But it doesn't deadlock, because
> uart_handle_sysrq_char() sets a special flag port->sysrq, and serial
> consoles are expected to make sure that they don't lock port->lock
> in this case. Otherwise we will kill the system:
> 
> 	void serial_console_write(...)
> 	{
> 	...
>           if (sport->port.sysrq)
>                   locked = 0;
>           else if (oops_in_progress)
>                   locked = spin_trylock_irqsave(&sport->port.lock, flags);
>           else
>                   spin_lock_irqsave(&sport->port.lock, flags);
>  	...
> 	}
> 
> So I'd say that lockdep is correct, but there are several hacks which
> prevent actual deadlock.

Just to make sure, I got you right: With the way lockdep works it is
right to assume there is a problem, but in fact there isn't?
This is IMHO unfortunate because such false positives reduces the
usefulness of lockdep considerably. :-|

> No idea why bisection has pointed at fd5f7cde1b85, it really doesn't
> change the locking patterns.

See above. I bent off wrongly during bisection and dbdda842fe96
("printk: Add console owner and waiter logic to load balance console
writes") is the first commit that issues the lockdep splat. I guess that
doesn't change what you said above though.

Best regards
Uwe

-- 
Pengutronix e.K.                           | Uwe Kleine-König            |
Industrial Linux Solutions                 | http://www.pengutronix.de/  |

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")]
  2019-09-18  7:11   ` Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")] Uwe Kleine-König
@ 2019-09-18  7:52     ` Sergey Senozhatsky
  2019-09-26  8:58       ` Petr Mladek
  0 siblings, 1 reply; 6+ messages in thread
From: Sergey Senozhatsky @ 2019-09-18  7:52 UTC (permalink / raw)
  To: Uwe Kleine-König
  Cc: Sergey Senozhatsky, Tetsuo Handa, Steven Rostedt, Petr Mladek,
	linux-kernel, Sergey Senozhatsky

On (09/18/19 09:11), Uwe Kleine-König wrote:
> I rechecked and indeed fd5f7cde1b85's parent has the problem, too, so I
> did a mistake during my bisection :-|
> 
> Redoing the bisection (a bit quicker this time) points to
> 
> dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes")
> 
> Sorry for the confusion.

No worries!

[..]
> > So I'd say that lockdep is correct, but there are several hacks which
> > prevent actual deadlock.
> 
> Just to make sure, I got you right: With the way lockdep works it is
> right to assume there is a problem, but in fact there isn't?

I'd probably say so... Unless I'm missing something.

sysrq-over-serial is handled from the serial driver's IRQ handler,
under serial driver's port->lock. sysrq handling calls printk(), which
takes console_sem/owner and re-enters the serial driver via ->write()
callback.

So lockdep sees a reverse locking pattern: port->lock goes before
console_sem/owner, which is not the usual order.

> This is IMHO unfortunate because such false positives reduces the
> usefulness of lockdep considerably. :-|

I agree.

port->sysrq state is global to uart port. IOW, if CPUA sets port->sysrq
then all printk->write() paths (from any other CPU) become lockless.

This makes me wonder is we really need to hold port->lock for
uart_handle_sysrq_char(). I sort of doubt it...

Can you try the following patch? It's against linux-next, I guess
you can backport to your kernel.

The basic idea is to handle sysrq out of port->lock.

I didn't test it all (not even sure if it compiles).

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

diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
index 87c58f9f6390..f0dd807b52df 100644
--- a/drivers/tty/serial/imx.c
+++ b/drivers/tty/serial/imx.c
@@ -731,9 +731,9 @@ static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
 	struct imx_port *sport = dev_id;
 	unsigned int rx, flg, ignored = 0;
 	struct tty_port *port = &sport->port.state->port;
+	unsigned long flags;
 
-	spin_lock(&sport->port.lock);
-
+	uart_port_lock_irqsave(&sport->port, flags);
 	while (imx_uart_readl(sport, USR2) & USR2_RDR) {
 		u32 usr2;
 
@@ -749,8 +749,8 @@ static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
 				continue;
 		}
 
-		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
-			continue;
+		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
+			break;
 
 		if (unlikely(rx & URXD_ERR)) {
 			if (rx & URXD_BRK)
@@ -792,7 +792,7 @@ static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
 	}
 
 out:
-	spin_unlock(&sport->port.lock);
+	uart_unlock_and_check_sysrq(&sport->port, flags);
 	tty_flip_buffer_push(port);
 	return IRQ_HANDLED;
 }

^ permalink raw reply related	[flat|nested] 6+ messages in thread

* Re: Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")]
  2019-09-18  7:52     ` Sergey Senozhatsky
@ 2019-09-26  8:58       ` Petr Mladek
  2019-09-27  4:26         ` Sergey Senozhatsky
  0 siblings, 1 reply; 6+ messages in thread
From: Petr Mladek @ 2019-09-26  8:58 UTC (permalink / raw)
  To: Sergey Senozhatsky
  Cc: Uwe Kleine-König, Sergey Senozhatsky, Steven Rostedt,
	Tetsuo Handa, linux-kernel

On Wed 2019-09-18 16:52:52, Sergey Senozhatsky wrote:
> On (09/18/19 09:11), Uwe Kleine-König wrote:
> > I rechecked and indeed fd5f7cde1b85's parent has the problem, too, so I
> > did a mistake during my bisection :-|
> > 
> > Redoing the bisection (a bit quicker this time) points to
> > 
> > dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes")
> > 
> > Sorry for the confusion.
> 
> No worries!
> 
> [..]
> > > So I'd say that lockdep is correct, but there are several hacks which
> > > prevent actual deadlock.
>
> The basic idea is to handle sysrq out of port->lock.

Great idea!

> I didn't test it all (not even sure if it compiles).
> 
> ---
>  drivers/tty/serial/imx.c | 10 +++++-----
>  1 file changed, 5 insertions(+), 5 deletions(-)
> 
> diff --git a/drivers/tty/serial/imx.c b/drivers/tty/serial/imx.c
> index 87c58f9f6390..f0dd807b52df 100644
> --- a/drivers/tty/serial/imx.c
> +++ b/drivers/tty/serial/imx.c
> @@ -731,9 +731,9 @@ static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
>  	struct imx_port *sport = dev_id;
>  	unsigned int rx, flg, ignored = 0;
>  	struct tty_port *port = &sport->port.state->port;
> +	unsigned long flags;
>  
> -	spin_lock(&sport->port.lock);
> -
> +	uart_port_lock_irqsave(&sport->port, flags);

uart_port_lock_irqsave() does not exist. Instead the current users
do:

     spin_lock_irqsave(&port->lock, flags);

>  	while (imx_uart_readl(sport, USR2) & USR2_RDR) {
>  		u32 usr2;
>  
> @@ -749,8 +749,8 @@ static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
>  				continue;
>  		}
>  
> -		if (uart_handle_sysrq_char(&sport->port, (unsigned char)rx))
> -			continue;
> +		if (uart_prepare_sysrq_char(&sport->port, (unsigned char)rx))
> +			break;
>  
>  		if (unlikely(rx & URXD_ERR)) {
>  			if (rx & URXD_BRK)
> @@ -792,7 +792,7 @@ static irqreturn_t imx_uart_rxint(int irq, void *dev_id)
>  	}
>  
>  out:
> -	spin_unlock(&sport->port.lock);
> +	uart_unlock_and_check_sysrq(&sport->port, flags);

This API has been introduced for exactly this reason. See the commit
6e1935819db0c91ce4a5af ("serial: core: Allow processing sysrq at port
unlock time").

I like this approach. It allows to remove hacks with locks.

Well, Sergey's patch is nice example that the API is a bit confusing.
I would either make it symmetric and make a variant without saving
irq flags:

    uart_lock(port);
    uart_unlock_and_handle_sysrq(port);

    uart_lock_irqsave(port, flags);
    uart_unlock_irqrestore_and_handle_sysrq(port);

Or I would keep the locking as is and add some API
just for the sysrq handling:


   int uart_store_sysrq_char(struct uart_port *port, unsigned int ch);
   unsigned int uart_get_sysrq_char(struct uart_port *port);

And use it the following way:

	int handle_irq()
	{
		unsined int sysrq, sysrq_ch;

		spin_lock(&port->lock);
		[...]
			sysrq = uart_store_sysrq_char(port, ch);
			if (!sysrq)
				[...]
		[...]

	out:
		sysrq_ch = uart_get_sysrq_char(port);
		spin_unlock(&port->lock);

		if (sysrq_ch)
			handle_sysrq(sysrq_ch);
	}

I prefer the 2nd option. It is more code. But it is more
self explanatory.

What do you think?

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")]
  2019-09-26  8:58       ` Petr Mladek
@ 2019-09-27  4:26         ` Sergey Senozhatsky
  0 siblings, 0 replies; 6+ messages in thread
From: Sergey Senozhatsky @ 2019-09-27  4:26 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Uwe Kleine-König, Sergey Senozhatsky,
	Steven Rostedt, Tetsuo Handa, linux-kernel

On (09/26/19 10:58), Petr Mladek wrote:
[..]
> > -	spin_lock(&sport->port.lock);
> > -
> > +	uart_port_lock_irqsave(&sport->port, flags);
> 
> uart_port_lock_irqsave() does not exist.

... Oh. Good catch! Apparently I still carry around my patch set
which added printk_safe to TTY/UART locking API.

> Instead the current users do:
> 
>      spin_lock_irqsave(&port->lock, flags);

Right.

[..]

> I like this approach. It allows to remove hacks with locks.

[..]

> Or I would keep the locking as is and add some API
> just for the sysrq handling:
>
>
>    int uart_store_sysrq_char(struct uart_port *port, unsigned int ch);
>    unsigned int uart_get_sysrq_char(struct uart_port *port);

Looks good. We also probably can remove struct uart_port's
->sysrq member and clean up locking in drivers' ->write()
callbacks:

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

Because this ->sysrq branch makes driver completely lockless globally,
for all CPUs, not only for sysrq-CPU.

> And use it the following way:
> 
> 	int handle_irq()
> 	{
> 		unsined int sysrq, sysrq_ch;
> 
> 		spin_lock(&port->lock);
> 		[...]
> 			sysrq = uart_store_sysrq_char(port, ch);
> 			if (!sysrq)
> 				[...]
> 		[...]
> 
> 	out:
> 		sysrq_ch = uart_get_sysrq_char(port);
> 		spin_unlock(&port->lock);
> 
> 		if (sysrq_ch)
> 			handle_sysrq(sysrq_ch);
> 	}

Looks good.

	-ss

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2019-09-27  4:26 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-09-17 14:10 Regression in fd5f7cde1b85 ("printk: Never set console_may_schedule in console_trylock()") Uwe Kleine-König
2019-09-18  1:30 ` Sergey Senozhatsky
2019-09-18  7:11   ` Regression in dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes") [Was: Regression in fd5f7cde1b85 ("...")] Uwe Kleine-König
2019-09-18  7:52     ` Sergey Senozhatsky
2019-09-26  8:58       ` Petr Mladek
2019-09-27  4:26         ` Sergey Senozhatsky

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.