[PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[taoyuhong]

From: Yuhong Tao <taoyuhong@huawei.com>

When tty_open() is opening a serial tty at the first time, after
alloc_tty_struct() is called, before tty->ops->open() is finished.
Serial driever like pl011 on ARM is ready to setup kworker threads
to receive data with flush_to_ldisc(). Serial input at this time
window can trigger kernel oops.
On the other side, flush_to_ldisc() can also oops on a hung-up tty.
It is unknown why flush_to_ldisc() can happen after target tty is hung
up. But both of these 2 situations come into a same result, look like
that:

[   11.287911] [<ffff0000084ba198>] n_tty_receive_buf_common+0x58/0xa58
[   11.290161] [<ffff0000084baba8>] n_tty_receive_buf2+0x10/0x18
[   11.292162] [<ffff0000084bd0a0>] tty_ldisc_receive_buf+0x20/0x68
[   11.294318] [<ffff0000084bd68c>] flush_to_ldisc+0xd4/0xe8
[   11.296181] [<ffff0000080d6958>] process_one_work+0x128/0x2f0
[   11.298166] [<ffff0000080d6b74>] worker_thread+0x54/0x440
[   11.300006] [<ffff0000080dccac>] kthread+0xe4/0xf8
[   11.301642] [<ffff000008082e80>] ret_from_fork+0x10/0x50
[   11.303460] Code: b9009fbf f90047a0 d2844c00 8b170000 (c8dffc03)

Calltrace may have a bit different behind n_tty_receive_buf_common, that
is about accessing to uninitialized or realeased data struct.
Serial driver may has problem, but tty driver can easily handle these 2
oops problems by:

1. Skip data transfer of hung-up tty, in flush_to_ldisc()
2. Mark hungup to tty_struct created by tty_openi(), which will be cleaned
   at the end of tty_open().

This is tested with linux-4.13.9/Debian on ARM virtual machine, whose
serial chip is pl011. You have a little chance to watch this happen, when
keep input from keyboard during system start or shutdown. And it happens
100% if a msleep() is inserted  before tty->ops->open() is called in
tty_open(), after tty_struct is created by tty_init_dev().

Signed-off-by: Yuhong Tao <taoyuhong@huawei.com>
---
 drivers/tty/pty.c      | 1 +
 drivers/tty/tty_io.c   | 3 +++
 drivers/tty/tty_port.c | 5 +++++
 3 files changed, 9 insertions(+)

diff --git a/drivers/tty/pty.c b/drivers/tty/pty.c
index a6d5164..ad5b075 100644
--- a/drivers/tty/pty.c
+++ b/drivers/tty/pty.c
@@ -853,6 +853,7 @@ static int ptmx_open(struct inode *inode, struct file *filp)
 
 	tty_debug_hangup(tty, "opening (count=%d)\n", tty->count);
 
+	clear_bit(TTY_HUPPED, &tty->flags);
 	tty_unlock(tty);
 	return 0;
 err_release:
diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
index 10c4038..f3abad0 100644
--- a/drivers/tty/tty_io.c
+++ b/drivers/tty/tty_io.c
@@ -1313,6 +1313,9 @@ struct tty_struct *tty_init_dev(struct tty_driver *driver, int idx)
 
 	tty->port->itty = tty;
 
+	set_bit(TTY_HUPPED, &tty->flags);
+	barrier();
+
 	/*
 	 * Structures all installed ... call the ldisc open routines.
 	 * If we fail here just call release_tty to clean up.  No need
diff --git a/drivers/tty/tty_port.c b/drivers/tty/tty_port.c
index 6b13719..e43482f 100644
--- a/drivers/tty/tty_port.c
+++ b/drivers/tty/tty_port.c
@@ -34,6 +34,11 @@ static int tty_port_default_receive_buf(struct tty_port *port,
 	if (!disc)
 		return 0;
 
+	if (test_bit(TTY_HUPPED, &tty->flags)) {
+		tty_ldisc_deref(disc);
+		return 0;
+	}
+
 	ret = tty_ldisc_receive_buf(disc, p, (char *)f, count);
 
 	tty_ldisc_deref(disc);
-- 
1.8.3.1

Re: [PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[Greg KH]

On Wed, Oct 25, 2017 at 10:15:35AM +0800, taoyuhong wrote:
> From: Yuhong Tao <taoyuhong@huawei.com>
> 
> When tty_open() is opening a serial tty at the first time, after
> alloc_tty_struct() is called, before tty->ops->open() is finished.
> Serial driever like pl011 on ARM is ready to setup kworker threads
> to receive data with flush_to_ldisc(). Serial input at this time
> window can trigger kernel oops.
> On the other side, flush_to_ldisc() can also oops on a hung-up tty.
> It is unknown why flush_to_ldisc() can happen after target tty is hung
> up. But both of these 2 situations come into a same result, look like
> that:
> 
> [   11.287911] [<ffff0000084ba198>] n_tty_receive_buf_common+0x58/0xa58
> [   11.290161] [<ffff0000084baba8>] n_tty_receive_buf2+0x10/0x18
> [   11.292162] [<ffff0000084bd0a0>] tty_ldisc_receive_buf+0x20/0x68
> [   11.294318] [<ffff0000084bd68c>] flush_to_ldisc+0xd4/0xe8
> [   11.296181] [<ffff0000080d6958>] process_one_work+0x128/0x2f0
> [   11.298166] [<ffff0000080d6b74>] worker_thread+0x54/0x440
> [   11.300006] [<ffff0000080dccac>] kthread+0xe4/0xf8
> [   11.301642] [<ffff000008082e80>] ret_from_fork+0x10/0x50
> [   11.303460] Code: b9009fbf f90047a0 d2844c00 8b170000 (c8dffc03)
> 
> Calltrace may have a bit different behind n_tty_receive_buf_common, that
> is about accessing to uninitialized or realeased data struct.
> Serial driver may has problem, but tty driver can easily handle these 2
> oops problems by:
> 
> 1. Skip data transfer of hung-up tty, in flush_to_ldisc()
> 2. Mark hungup to tty_struct created by tty_openi(), which will be cleaned
>    at the end of tty_open().
> 
> This is tested with linux-4.13.9/Debian on ARM virtual machine, whose
> serial chip is pl011. You have a little chance to watch this happen, when
> keep input from keyboard during system start or shutdown. And it happens
> 100% if a msleep() is inserted  before tty->ops->open() is called in
> tty_open(), after tty_struct is created by tty_init_dev().
> 
> Signed-off-by: Yuhong Tao <taoyuhong@huawei.com>
> ---
>  drivers/tty/pty.c      | 1 +
>  drivers/tty/tty_io.c   | 3 +++
>  drivers/tty/tty_port.c | 5 +++++
>  3 files changed, 9 insertions(+)
> 
> diff --git a/drivers/tty/pty.c b/drivers/tty/pty.c
> index a6d5164..ad5b075 100644
> --- a/drivers/tty/pty.c
> +++ b/drivers/tty/pty.c
> @@ -853,6 +853,7 @@ static int ptmx_open(struct inode *inode, struct file *filp)
>  
>  	tty_debug_hangup(tty, "opening (count=%d)\n", tty->count);
>  
> +	clear_bit(TTY_HUPPED, &tty->flags);

This feels "odd", are we sure that open really should be clearning this
flag?

>  	tty_unlock(tty);
>  	return 0;
>  err_release:
> diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
> index 10c4038..f3abad0 100644
> --- a/drivers/tty/tty_io.c
> +++ b/drivers/tty/tty_io.c
> @@ -1313,6 +1313,9 @@ struct tty_struct *tty_init_dev(struct tty_driver *driver, int idx)
>  
>  	tty->port->itty = tty;
>  
> +	set_bit(TTY_HUPPED, &tty->flags);
> +	barrier();

What is this barrier() call protecting?  Please always comment it so
that we know what is going on in 5 years when we next look at this code
:)

> +
>  	/*
>  	 * Structures all installed ... call the ldisc open routines.
>  	 * If we fail here just call release_tty to clean up.  No need
> diff --git a/drivers/tty/tty_port.c b/drivers/tty/tty_port.c
> index 6b13719..e43482f 100644
> --- a/drivers/tty/tty_port.c
> +++ b/drivers/tty/tty_port.c
> @@ -34,6 +34,11 @@ static int tty_port_default_receive_buf(struct tty_port *port,
>  	if (!disc)
>  		return 0;
>  
> +	if (test_bit(TTY_HUPPED, &tty->flags)) {
> +		tty_ldisc_deref(disc);
> +		return 0;
> +	}
> +

What keeps the bit from being set now right after checking it?

thanks,

greg k-h

Re: [PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[Alan Cox]

> When tty_open() is opening a serial tty at the first time, after
> alloc_tty_struct() is called, before tty->ops->open() is finished.

That's kind of unavoidable.

> Serial driever like pl011 on ARM is ready to setup kworker threads
> to receive data with flush_to_ldisc(). Serial input at this time
> window can trigger kernel oops.

So you shouldn't be queueing I/O at this point.

> On the other side, flush_to_ldisc() can also oops on a hung-up tty.

flush_to_ldisc takes a reference to the tty ldisc so when it's called
from tty_schedule_flip all should be good. 

> Serial driver may has problem, but tty driver can easily handle these 2
> oops problems by:
> 
> 1. Skip data transfer of hung-up tty, in flush_to_ldisc()

No because you may have data you need to drain. If the tty has become
null then the data is dropped anyway, likewise if there is no bound ldisc
to send it to.

> 2. Mark hungup to tty_struct created by tty_openi(), which will be cleaned
>    at the end of tty_open().

You shouldn't be looking at the tty structure, the tty structure is an
object whose lifetime is not aligned to your port. You should be looking
in the tty port structure.

Your port->ops->activate() is called at the point when your port is
activated, and you have other port methods to handle the other cases if
you need to synchronize with them.

Alan

Re: [PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[Alan Cox]

> I can reproduce this problem on CentOS now. It seems better to leave this problem to drivers, not the user process.
> Do you think we should examine serial drivers of ARM, like pl011?

Can you reproduce it on real hardware - I ask because the driver has been
around for years without reports and it would be good to know it's not a
virtual platform problem you are chasing.

> ---------------------------------------------------------------------------------------
> Does it means this serial driver do not support activate/deactive? Is that out of date?
> Because tty driver is complex, I am studying the concept and source code, and need time to find a good solution.

AMBA uses the uart layer. So uart does a lot of the work. 

Yes the driver is complex and the core hangup/receive paths are tricky to
understand. The open path however is fairly simple so the fact you see a
failure there makes me suspicious and I tink that is the first one to
trace because the tty_open paths do not set port->tty until the tty is
initialized properly.

The hangup path is complex and has a history of bugs and races so is a
bit less surprising.

The important detail here is that both the queueing of data and the
hangup are done by schedule_work() and as far as I can see (the code
has changed somewhat since I last dug into that bit) rely on that to avoid
the two executing at the same time.

Alan

Re: 答复: [PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[Greg KH]

On Thu, Oct 26, 2017 at 12:10:20PM +0000, taoyuhong wrote:
> 本邮件及其附件含有华为公司的保密信息，仅限于发送给上面地址中列出的个人或群组。禁
> 止任何其他人以任何形式使用（包括但不限于全部或部分地泄露、复制、或散发）本邮件中
> 的信息。如果您错收了本邮件，请您立即电话或邮件通知发件人并删除本邮件！
> This e-mail and its attachments contain confidential information from HUAWEI, which 
> is intended only for the person or entity whose address is listed above. Any use of the 
> information contained herein in any way (including, but not limited to, total or partial 
> disclosure, reproduction, or dissemination) by persons other than the intended 
> recipient(s) is prohibited. If you receive this e-mail in error, please notify the sender by 
> phone or email immediately and delete it!

Because of this text, I am not allowed to respond to your emails, sorry :(

答复: 答复: [PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[taoyuhong]

Hi Gerg
> Because of this text, I am not allowed to respond to your emails, sorry :(

That is my fault! Please let me re-send these message.

> This feels "odd", are we sure that open really should be clearning this flag?
Because the pty devices also use tty_init_dev(), to create tty_struct , and inside where I set the TTY_HUPPED flag.
If don't clean it at the end of ptmx_ope(), new tty_struct created for a ssh connection will have this bit set 

> What is this barrier() call protecting?  Please always comment it so 
> that we know what is going on in 5 years when we next look at this 
> code
It does not really hung the tty up, just set TTY_HUPPED flag. After the tty structure is generated, a kworker with flush_to_ldisc() would be scheduled to another cpu, not the one who is opening that /dev/tty*. I think a barrier() can ensure the kworker see tty flags change in time.

>What keeps the bit from being set now right after checking it?
After check, next step is to call tty_ldisc_receive_buf(). If anyone obtains all required locks and modifies terminal or line discipline, while receiving is In processing, it should have another problem. Maybe oops again.
I have no idea how to keep the bit being set, but after testing for days, I haven't sawn that happen.

Yuhong Tao

Huawei Technologies Co., Ltd.

Re: 答复: [PATCH] tty: fix flush_to_ldisc() oops before tty_open is done

[gregkh]

On Fri, Nov 03, 2017 at 10:48:04AM +0000, taoyuhong wrote:
> Hi Alan
> 
> Serial tty oops on real arm computer.
> 
> That is Hikey960 board, with 8 cortex-a57 cpus and pl011 serial hardware.
> Debian8 is pre-installed, and I replaced the kernel with linux-stable 4.13.10.
> 
> It is very easy to trigger tty oops, if there are massive input to the serial port. 
> I made a script, send "reboot" repeatedly to the Hikey960 board,
> without any break. So that if system not oops on tty open it can
> reboot and play next round.
> 
> After many times of reboot, the tty oops on system shutdown sequence.
> And I tried more it also happened during system startup.

How is things crashing on startup when you are messing with data being
sent on shutdown?

Are you still sending data at startup time?

> That is what it looks, this is startup tty oops:
> --------------------------------------------------------------
> EFI stub: Booting Linux Kernel...
> EFI stub: Using DTB from configuration table
> EFI stub: Exiting boot services and installing virtual address map...
> [    0.000000] Booting Linux on physical CPU 0x0
> [    0.000000] Linux version 4.13.10-linaro-hikey (root@tayuhong-Aspire-E1-471G) (gcc version 6.3.0 20170406 (Ubuntu/Linaro 6.3.0-12ubuntu2)) 7
> [    0.000000] Boot CPU: AArch64 Processor [410fd033]
> [    0.000000] Machine model: HiKey Development Board
> [    0.000000] efi: Getting EFI parameters from FDT:
> [    0.000000] efi: EFI v2.40 by Linaro HiKey EFI Nov 28 2015 10:50:07
> [    0.000000] efi: 
> [    0.000000] Reserved memory: created CMA memory pool at 0x0000000072c00000, size 128 MiB
> [    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
> [    0.000000] psci: probing for conduit method from DT.
> [    0.000000] psci: PSCIv1.0 detected in firmware.
> [    0.000000] psci: Using standard PSCI v0.2 function IDs
> [    0.000000] psci: Trusted OS migration not required
> [    0.000000] percpu: Embedded 24 pages/cpu @ffffffc07fe6d000 s59544 r8192 d30568 u98304
> [    0.000000] Detected VIPT I-cache on CPU0
> [    0.000000] CPU features: enabling workaround for ARM erratum 845719
> [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 507406
> [    0.000000] Kernel command line: BOOT_IMAGE=/boot/Image413 console=ttyAMA3,115200 root=/dev/disk/by-partlabel/system rw
> ... ...
> Begin: Running /scripts/local-bottom ... done.
> Begin: Running /scripts/init-bottom ... done.
> 
> Welcome to Debian GNU/Linux 8 (jessie)!
> 
>          Expecting device dev-ttyAMA3.device...
> [  OK  ] Reached target Remote File Systems (Pre).
> [  OK  ] Set up automount Arbitrary Executable File Formats F...utomount Point.
> ... ....
> [  OK  ] Started LSB: network benchmark.
> [  OK  ] Started LSB: Advanced IEEE 802.11 management daemon.
> [  OK  ] Reached target Multi-User System.
> [  OK  ] Reached target Graphical Interface.
>          Starting Update UTMP about System Runlevel Changes...
> [  OK  ] Started Update UTMP about System Runlevel Changes.
> [    7.753576] Unable to handle kernel paging request at virtual address 00002260
> [    7.760855] user pgtable: 4k pages, 39-bit VAs, pgd = ffffffc07bc31000
> [    7.760859] [0000000000002260] *pgd=0000000000000000, *pud=0000000000000000
> [    7.760873] Internal error: Oops: 96000005 [#1] PREEMPT SMP
> [    7.760877] Modules linked in:
> [    7.760886] CPU: 0 PID: 54 Comm: kworker/u16:2 Tainted: G        W       4.13.10-linaro-hikey #4
> [    7.760889] Hardware name: HiKey Development Board (DT)
> [    7.760904] Workqueue: events_unbound flush_to_ldisc
> [    7.760908] task: ffffffc07d08f080 task.stack: ffffffc07d17c000
> [    7.760915] PC is at n_tty_receive_buf_common+0x64/0xb18
> [    7.760920] LR is at n_tty_receive_buf_common+0x48/0xb18
> [    7.760924] pc : [<ffffff80084dc5dc>] lr : [<ffffff80084dc5c0>] pstate: 80000145
> .... ....
> [    7.761190] [<ffffff80084dc5dc>] n_tty_receive_buf_common+0x64/0xb18
> [    7.761195] [<ffffff80084dd0a0>] n_tty_receive_buf2+0x10/0x18
> [    7.761200] [<ffffff80084dfb50>] tty_ldisc_receive_buf+0x20/0x70
> [    7.761206] [<ffffff80084e06e0>] tty_port_default_receive_buf+0x40/0x78
> [    7.761211] [<ffffff80084dfd64>] flush_to_ldisc+0xb4/0xc8
> [    7.761221] [<ffffff80080d345c>] process_one_work+0x1ac/0x318
> [    7.761226] [<ffffff80080d3610>] worker_thread+0x48/0x420
> [    7.761233] [<ffffff80080d92d4>] kthread+0xfc/0x128
> [    7.761239] [<ffffff8008082ec0>] ret_from_fork+0x10/0x50
> [    7.761245] Code: b900bfbf f9405ba0 d2844c01 8b010001 (c8dffc23) 
> [    7.761251] ---[ end trace 7165822c665b3e66 ]---
> --------------------------------------------------------------------------------------
> 
> I can't dump Hikey's panic memory for now, so I am not very sure this is the same tty driver issue found on virtual machine.
> So I tried many times, the oops took place by chance, like what has happened on virtual machine.
> I tried to put msleep() in tty_open, then in system startup/shutdown, the serial tty on Hikey can oops for a few input characters, as on virtual machine, too.
> Beside, it needs much more time to trigger tty oops on kernel 4.1, and I didn't saw this happen on kernel 3.18. 
> 
> So I am afraid this is not a virtual machine problem. 
> It may because serial port is not frequently used by general computer users, so this problem is not discovered

The serial port has been used for decades very frequently :)

I don't remember anymore, did you have a proposed patch/fix for this?

thanks,

greg k-h