Re: [PATCH v2] tty: use printk_deferred() at tty_msg()

From: Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>
To: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Cc: Petr Mladek <pmladek@suse.com>, Jiri Slaby <jirislaby@kernel.org>,
	Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
	Steven Rostedt <rostedt@goodmis.org>,
	John Ogness <john.ogness@linutronix.de>,
	linux-kernel@vger.kernel.org
Subject: Re: [PATCH v2] tty: use printk_deferred() at tty_msg()
Date: Wed, 7 Apr 2021 23:24:33 +0900	[thread overview]
Message-ID: <051b550c-1cdd-6503-d2b7-0877bf0578fc@i-love.sakura.ne.jp> (raw)
In-Reply-To: <YG24F9Kx+tjxhh8G@kroah.com>

On 2021/04/07 22:48, Greg Kroah-Hartman wrote:
>> By the way, as soon as applying this patch, I guess that syzkaller starts
>> generating hung task reports because /dev/ttyprintk can trivially trigger
>> flood of
>>
>>   tty_warn(tty, "%s: tty->count = 1 port count = %d\n", __func__,
>>            port->count);
>>
>> message, and adding
>>
>>   if (strcmp(tty_driver_name(tty), "ttyprintk"))
> 
> Odd, how can ttyprintk() generate that mess?

So far three tests and results:

  https://groups.google.com/g/syzkaller-bugs/c/yRLYijD2tbw/m/WifLgadvAAAJ
  https://groups.google.com/g/syzkaller-bugs/c/yRLYijD2tbw/m/w2_MiMmAAAAJ
  https://groups.google.com/g/syzkaller-bugs/c/yRLYijD2tbw/m/hfsQqSOPAAAJ

Patch https://syzkaller.appspot.com/x/patch.diff?x=145e4c9ad00000 generated
console output https://syzkaller.appspot.com/x/log.txt?x=162f9fced00000 .

Patch https://syzkaller.appspot.com/x/patch.diff?x=14839931d00000 did not
flood the console output enough to fire khungtaskd.

Maybe it is because /dev/ttyprintk can be opened/closed by multiple processes
without serialization?

Running

  for i in $(seq 1 100); do sleep 1 > /dev/ttyprintk & done

results in

  tty_port_close_start: tty->count = 1 port count = 100

. If tty_port_open() from tpk_open() can do

  spin_lock_irq(&port->lock);
  ++port->count;
  spin_unlock_irq(&port->lock);

when tty_port_close_start() from tty_port_close() from tpk_close() is doing

  spin_lock_irqsave(&port->lock, flags);
  if (tty->count == 1 && port->count != 1) {
    tty_warn(tty, "%s: tty->count = 1 port count = %d\n", __func__,
             port->count);
    port->count = 1;
  }
  if (--port->count < 0) {
    tty_warn(tty, "%s: bad port count (%d)\n", __func__,
             port->count);
    port->count = 0;
  }

  if (port->count) {
    spin_unlock_irqrestore(&port->lock, flags);
    return 0;
  }
  spin_unlock_irqrestore(&port->lock, flags);

, what prevents port->count from getting larger than 1 ?