Re: INFO: rcu detected stall in n_tty_receive_char_special

[Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>]

On 2018/04/24 1:01, Tetsuo Handa wrote:
> Bisection reached to commit e052c6d15c61cc4c ("tty: Use unbound workqueue
> for all input workers") added in 4.4-rc1.
> 
> Reverting that commit on top of 4.4 solved the lockup. But unfortunately,
> reverting that commit on top of 4.16 only helped surviving the test longer
> than vanilla 4.16; still stalls at __process_echoes(). There might be similar
> changes which need to be reverted as well.

I noticed that when stall inside __process_echoes() occurs, it is looping at
discard loop added by commit cbfd0340ae199337 ("n_tty: Process echoes in blocks").
Since ldata->echo_commit < ldata->echo_tail is for some reason true upon entry,
the discard loop serves as almost infinite loop.

--- a/drivers/tty/n_tty.c
+++ b/drivers/tty/n_tty.c
@@ -613,12 +613,21 @@ static size_t __process_echoes(struct tty_struct *tty)
 	int	space, old_space;
 	size_t tail;
 	unsigned char c;
+	unsigned long start = jiffies;
 
 	old_space = space = tty_write_room(tty);
 
 	tail = ldata->echo_tail;
+	if (ldata->echo_commit < tail)
+		printk("BUG1: ldata->echo_commit=%ld tail=%ld space=%d old_space=%d\n",
+		       ldata->echo_commit, tail, space, old_space);
 	while (ldata->echo_commit != tail) {
 		c = echo_buf(ldata, tail);
+		if (time_after(jiffies, start + 5 * HZ)) {
+			printk("ldata->echo_commit=%ld tail=%ld c=%c space=%d old_space=%d\n",
+			       ldata->echo_commit, tail, c, space, old_space);
+			start = jiffies;
+		}
 		if (c == ECHO_OP_START) {
 			unsigned char op;
 			int no_space_left = 0;
@@ -729,6 +738,11 @@ static size_t __process_echoes(struct tty_struct *tty)
 	 * of echo overrun before the next commit), then discard enough
 	 * data at the tail to prevent a subsequent overrun */
 	while (ldata->echo_commit - tail >= ECHO_DISCARD_WATERMARK) {
+		if (time_after(jiffies, start + 5 * HZ)) {
+			printk("ldata->echo_commit=%ld ldata->echo_tail=%ld tail=%ld space=%d old_space=%d\n",
+			       ldata->echo_commit, ldata->echo_tail, tail, space, old_space);
+			start = jiffies;
+		}
 		if (echo_buf(ldata, tail) == ECHO_OP_START) {
 			if (echo_buf(ldata, tail + 1) == ECHO_OP_ERASE_TAB)
 				tail += 3;
@@ -739,6 +753,9 @@ static size_t __process_echoes(struct tty_struct *tty)
 	}
 
 	ldata->echo_tail = tail;
+	if (ldata->echo_commit < tail)
+		printk("BUG2: ldata->echo_commit=%ld tail=%ld space=%d old_space=%d\n",
+		       ldata->echo_commit, tail, space, old_space);
 	return old_space - space;
 }
 


[    5.890788] input: PC Speaker as /devices/platform/pcspkr/input/input4
[   27.357324] BUG1: ldata->echo_commit=120 tail=130 space=7936 old_space=7936
[   32.358527] ldata->echo_commit=120 ldata->echo_tail=130 tail=2994833619 space=0 old_space=7936
[   37.362404] ldata->echo_commit=120 ldata->echo_tail=130 tail=5930715049 space=0 old_space=7936
[   42.366124] ldata->echo_commit=120 ldata->echo_tail=130 tail=8943875147 space=0 old_space=7936
[   47.370508] ldata->echo_commit=120 ldata->echo_tail=130 tail=11950164125 space=0 old_space=7936
[   52.374224] ldata->echo_commit=120 ldata->echo_tail=130 tail=14880807667 space=0 old_space=7936
[   57.378597] ldata->echo_commit=120 ldata->echo_tail=130 tail=17821338400 space=0 old_space=7936
[   62.383638] ldata->echo_commit=120 ldata->echo_tail=130 tail=20811717629 space=0 old_space=7936
[   63.203807] sysrq: SysRq : Resetting

[    5.843667] input: PC Speaker as /devices/platform/pcspkr/input/input4
[   28.306346] BUG1: ldata->echo_commit=128 tail=130 space=7936 old_space=7936
[   33.307133] ldata->echo_commit=128 ldata->echo_tail=130 tail=2892537244 space=0 old_space=7936
[   38.311478] ldata->echo_commit=128 ldata->echo_tail=130 tail=5766457276 space=0 old_space=7936
[   43.315319] ldata->echo_commit=128 ldata->echo_tail=130 tail=8686538551 space=0 old_space=7936
[   48.319164] ldata->echo_commit=128 ldata->echo_tail=130 tail=11556458920 space=0 old_space=7936
[   50.122017] sysrq: SysRq : Resetting

[    6.026322] input: PC Speaker as /devices/platform/pcspkr/input/input4
[   38.149864] BUG1: ldata->echo_commit=118 tail=130 space=7936 old_space=7936
[   43.150167] ldata->echo_commit=118 ldata->echo_tail=130 tail=2789490540 space=0 old_space=7936
[   48.154012] ldata->echo_commit=118 ldata->echo_tail=130 tail=5592467000 space=0 old_space=7936
[   53.158365] ldata->echo_commit=118 ldata->echo_tail=130 tail=8376906144 space=0 old_space=7936
[   58.162211] ldata->echo_commit=118 ldata->echo_tail=130 tail=11158984120 space=0 old_space=7936
[   60.487338] sysrq: SysRq : Resetting

[    9.170831] input: PC Speaker as /devices/platform/pcspkr/input/input4
[   25.929908] BUG1: ldata->echo_commit=120 tail=130 space=7936 old_space=7936
[   30.930553] ldata->echo_commit=120 ldata->echo_tail=130 tail=3008469343 space=0 old_space=7936
[   35.935475] ldata->echo_commit=120 ldata->echo_tail=130 tail=5857403750 space=0 old_space=7936
[   40.940153] ldata->echo_commit=120 ldata->echo_tail=130 tail=8858176994 space=0 old_space=7936
[   45.944527] ldata->echo_commit=120 ldata->echo_tail=130 tail=11838898685 space=0 old_space=7936
[   48.948625] sysrq: SysRq : Resetting

[    6.071991] input: PC Speaker as /devices/platform/pcspkr/input/input4
[   22.890428] BUG1: ldata->echo_commit=128 tail=130 space=7936 old_space=7936
[   27.891372] ldata->echo_commit=128 ldata->echo_tail=130 tail=3064270209 space=0 old_space=7936
[   32.895212] ldata->echo_commit=128 ldata->echo_tail=130 tail=6085270166 space=0 old_space=7936
[   37.899047] ldata->echo_commit=128 ldata->echo_tail=130 tail=9102650663 space=0 old_space=7936
[   42.903405] ldata->echo_commit=128 ldata->echo_tail=130 tail=12195198062 space=0 old_space=7936
[   44.497876] sysrq: SysRq : Resetting

[    5.804688] input: PC Speaker as /devices/platform/pcspkr/input/input4
[   23.632487] BUG1: ldata->echo_commit=102 tail=130 space=7936 old_space=7936
[   28.633878] ldata->echo_commit=102 ldata->echo_tail=130 tail=2930081035 space=0 old_space=7936
[   33.638168] ldata->echo_commit=102 ldata->echo_tail=130 tail=5867627875 space=0 old_space=7936
[   38.654062] ldata->echo_commit=102 ldata->echo_tail=130 tail=8804236495 space=0 old_space=7936
[   40.296804] sysrq: SysRq : Resetting