Re: serial core: crash / race condition on unbind

[Peter Hurley]

[ +cc Alan ]

On 03/10/2014 04:48 PM, Geert Uytterhoeven wrote:
> On Fri, Mar 7, 2014 at 5:55 PM, Geert Uytterhoeven <geert@xxxxxxxxxxxxxx> wrote:
> > When unbinding a serial driver, uart_remove_one_port() clears
> > uart_state.uart_port:
> >
> >          state->uart_port = NULL;
> >
> > If the serial port is still in use (e.g. by getty), uart_close() will be
> > called later:
>
> After more digging into the code, uart_close() is supposed to be
> called "before",
> not "later".
>
> uart_remove_one_port() does:
>
>          /*
>           * Remove the devices from the tty layer
>           */
>          tty_unregister_device(drv->tty_driver, uport->line);
>
> i.e. remove the port, so there will be no new users?
>
>          if (port->tty)
>                  tty_vhangup(port->tty);

[Aside: the above needs to be fixed by getting a reference for port->tty. IOW,

	tty = tty_port_tty_get(port);
	if (tty) {
		tty_vhangup(tty);
		tty_kref_put(tty);
	}

]


> tty_vhangup() will:
>    - set all relevant filp->f_op to &hung_up_tty_fops, so uart_close()
>      will notice the port has been closed,
>    - call uart_hangup(),
>    - call uart_close().

Not quite.

When hanging up a tty, if any of the open file pointers are consoles
(ie., opened via /dev/console or /dev/ttyN), those open files are
not closed on hangup. In this case, tty_vhangup() closes the _other_
file pointers via tty->ops->close() ==> uart_close().

The console file pointers are left open and operational until all
have explicitly been closed (or implicitly by process exit).

If there are no console file pointers for this tty, tty_vhangup()
calls tty->ops->hangup() instead, which indicates to the tty driver
that all open file pointers are closed and the tty device can
shutdown.

>          [...]
>
>          /*
>           * Indicate that there isn't a port here anymore.
>           */
>          uport->type = PORT_UNKNOWN;
>
>          state->uart_port = NULL;

How did this ever work?

Detaching the ll driver from the tty port in this manner is not ok;
as you already note, it blows up if consoles are still running.

This resetting (if necessary at all) could be done in uart_shutdown()
after uart_port_shutdown() -- some minor code reorg would be required
in uart_close() to make that work properly [ and probably should be
done anyway, like uart_flush_buffer() _before_ uart_shutdown ;) ]

Although I'm not sure how to do the 8250 port re-assignments in
serial8250_unregister_port...


> only here uart_port is set to NULL, after uart_close() has already been called.
>
> >          static void uart_close(struct tty_struct *tty, struct file *filp)
> >          {
> >                  struct uart_state *state = tty->driver_data;
> >                  struct uart_port *uport;
> >
> >                  ...
> >
> >                  if (!state)
> >                          return;
> >
> >                  uport = state->uart_port;
> >
> > uport is NULL
> >
> >                  ...
> >
> >                  pr_debug("uart_close(%d) called\n", uport->line);
> >
> > If debugging is enabled, it will already crash here while dereferencing uport
> > (this one is easily fixed)
> >
> >                  if (tty_port_close_start(port, tty, filp) == 0)
> >                          return;
> >
> >                  ...
> >
> >                  uart_flush_buffer(tty);
> >
> > uart_flush_buffer() will try to obtain the port's spinlock:
> >
> >          static void uart_flush_buffer(struct tty_struct *tty)
> >          {
> >                  struct uart_state *state = tty->driver_data;
> >                  struct uart_port *port;
> >
> >                  ...
> >
> >                  port = state->uart_port;
> >
> > port is NULL
> >
> >                  ...
> >
> >                  spin_lock_irqsave(&port->lock, flags);
> >
> > Crash!!
> >
> > It doesn't always crash, though.
> >
> > Sometimes uart_close() returns after the tty_port_close_start() above,
>
> This is the expected behavior, as filp->f_op == &hung_up_tty_fops
> (set from tty_vhangup() et al.).
>
> > without a crash (bypassing e.g. the call to uart_change_pm() :-(
>
> (The bypassing is normal: shutdown of the port is done in uart_hangup()
>   (called from tty_vhangup() et al.).
>   For the lack of calling uart_change_pm(), see my "[PATCH/RFC] serial_core:
>   Fix pm imbalance on unbind", https://lkml.org/lkml/2014/3/10/496))


Ok, I'll go look at that, too.


> However, what I'm seeing is that there are several calls to uart_close()
> where filp->f_op != &hung_up_tty_fops. Hence uart_close() doesn't abort
> after tty_port_close_start(). Shouldn't the call to tty_unregister_device()
> prevent these from happening?
>
> I can easily widen the race window by adding an msleep() after the call to
> tty_vhangup() in uart_remove_one_port().
>
> Then I start getting the warnings printed by tty_port_close_start():
>      tty_port_close_start: tty->count = 1 port count = 2.
>      tty_port_close_start: tty->count = 1 port count = 0.
>
> How come there's a port count mismatch?
>
> If any of these happen when state->uart_port is already NULL, the kernel
> crashes (fortunately not deadly, as I'm left without a serial console):
>
> tty_port_close_start: tty->count = 1 port count = 2.
> console [ttySC6] disabled
> tty_port_close_start: tty->count = 1 port count = 0.
> Unable to handle kernel NULL pointer dereference at virtual address 00000000
> pgd = c0004000
> [00000000] *pgd=00000000
> Internal error: Oops: 17 [#1] SMP ARM
> Modules linked in:
> CPU: 0 PID: 1333 Comm: getty Not tainted
> 3.14.0-rc5-koelsch-00343-g2fccf32beb8d-dirty #552
> task: ee519b40 ti: ee474000 task.ti: ee474000
> PC is at _raw_spin_lock_irqsave+0x1c/0x54
> LR is at uart_flush_buffer+0x38/0x7c
> pc : [<c0349254>]    lr : [<c01ff008>]    psr: a00f0093
> sp : ee475e10  ip : ee475e20  fp : ee475e1c
> r10: ee808760  r9 : 00000000  r8 : eee3061c
> r7 : 00000000  r6 : eee305b8  r5 : 00000000  r4 : ee441c00
> r3 : 00000000  r2 : 08000000  r1 : eee3064c  r0 : a00f0013
> Flags: NzCv  IRQs off  FIQs on  Mode SVC_32  ISA ARM  Segment user
> Control: 10c5347d  Table: 6e5a006a  DAC: 00000015
> Process getty (pid: 1333, stack limit = 0xee474240)
> Stack: (0xee475e10 to 0xee476000)
> 5e00:                                     ee475e3c ee475e20 c01ff008 c0349244
> 5e20: eee305b8 eee30654 ee441c00 00000000 ee475e64 ee475e40 c01ff1c4 c01fefdc
> 5e40: ee441c00 00000000 00000008 00000006 eee61800 ee808760 ee475edc ee475e68
> 5e60: c01e6c4c c01ff134 ee475e8c ee475e78 ee461c00 eefa6a80 ee97fcd8 ee461400
> 5e80: ee475eac ee475e90 ee475ea4 ee475e98 c00681a4 c006817c ee475ecc ee475ea8
> 5ea0: 00000000 ee9a3980 00000000 00000000 eec33ed0 eee61800 eed8fad8 00000008
> 5ec0: eee61808 00000000 eec33e10 ee808760 ee475f14 ee475ee0 c00bb98c c01e6b30
> 5ee0: 00000000 00000000 c00d5f04 ee519b40 00000000 c04a97b0 ee643238 c000ee44
> 5f00: ee474000 00000000 ee475f24 ee475f18 c00bbae8 c00bb8b8 ee475f44 ee475f28
> 5f20: c003c32c c00bbae4 00000000 ee519b40 ee643200 00000000 ee475f74 ee475f48
> 5f40: c0025c54 c003c27c 08de8590 00000001 c00414c8 ef1ed2f8 00000000 00000000
> 5f60: 00000000 000000f8 ee475f94 ee475f78 c00262f0 c00258b0 000712b2 000712c6
> 5f80: 00000001 000000f8 ee475fa4 ee475f98 c0026334 c0026258 00000000 ee475fa8
> 5fa0: c000ecc0 c0026328 000712b2 000712c6 00000001 b6ea44c0 00000008 00000001
> 5fc0: 000712b2 000712c6 00000001 000000f8 00000001 b6f894b8 00000001 00000000
> 5fe0: 000000f8 bee837ec b6f17de3 b6ebc8e6 600f0030 00000001 c2b00000 00000002
> Backtrace:
> [<c0349238>] (_raw_spin_lock_irqsave) from [<c01ff008>]
> (uart_flush_buffer+0x38/0x7c)
> [<c01fefd0>] (uart_flush_buffer) from [<c01ff1c4>] (uart_close+0x9c/0x194)
>   r7:00000000 r6:ee441c00 r5:eee30654 r4:eee305b8
> [<c01ff128>] (uart_close) from [<c01e6c4c>] (tty_release+0x128/0x4b4)
>   r10:ee808760 r8:eee61800 r7:00000006 r6:00000008 r5:00000000 r4:ee441c00
> [<c01e6b24>] (tty_release) from [<c00bb98c>] (__fput+0xe0/0x1e0)
>   r10:ee808760 r9:eec33e10 r8:00000000 r7:eee61808 r6:00000008 r5:eed8fad8
>   r4:eee61800
> [<c00bb8ac>] (__fput) from [<c00bbae8>] (____fput+0x10/0x14)
>   r10:00000000 r9:ee474000 r8:c000ee44 r7:ee643238 r6:c04a97b0 r5:00000000
>   r4:ee519b40
> [<c00bbad8>] (____fput) from [<c003c32c>] (task_work_run+0xbc/0xd0)
> [<c003c270>] (task_work_run) from [<c0025c54>] (do_exit+0x3b0/0x8bc)
>   r6:00000000 r5:ee643200 r4:ee519b40 r3:00000000
> [<c00258a4>] (do_exit) from [<c00262f0>] (do_group_exit+0xa4/0xd0)
>   r7:000000f8
> [<c002624c>] (do_group_exit) from [<c0026334>] (__wake_up_parent+0x0/0x28)
>   r7:000000f8 r6:00000001 r5:000712c6 r4:000712b2
> [<c002631c>] (SyS_exit_group) from [<c000ecc0>] (ret_fast_syscall+0x0/0x30)
> Code: e1a03000 e10f0000 f10c0080 f593f000 (e1932f9f)
> ---[ end trace ca2990c7ac60181d ]---
> Fixing recursive fault but reboot is needed!
>
> > This is with sh-sci, but I don't think the driver matters.

Yep, all the ll drivers will crash here.

> Note that this only happens if the serial port is used as a serial console.
> Without a serial console, everything works fine (after "[PATCH/RFC]
> serial_core: Fix pm imbalance on unbind", https://lkml.org/lkml/2014/3/10/496)

Regards,
Peter Hurley

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/