WARNING: at drivers/tty/tty_ldisc.c:766 tty_ldisc_reinit+0x7d/0x90()

WARNING: at drivers/tty/tty_ldisc.c:766 tty_ldisc_reinit+0x7d/0x90()

[Vegard Nossum]

Hi,

I get this with the latest linux.git (git 3a5c37) at boot:

[    7.204114] usb 1-1: khubd timed out on ep0in len=0/255
[    7.244493] usb 1-1: udev 2, busnum 1, minor = 1
[    7.245791] usb 1-1: New USB device found, idVendor=9ac4, idProduct=4b8f
[    7.247330] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    7.249000] usb 1-1: Product: ProxMark-3 RFID Instrument
[    7.250433] usb 1-1: Manufacturer: J. Westhues
[    7.252377] usb 1-1: usb_probe_device
[    7.253911] usb 1-1: configuration #1 chosen from 1 choice
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
[    7.258089] usb 1-1: adding 1-1:1.0 (config #1, interface 0)
[    7.259765] usbhid 1-1:1.0: usb_probe_interface
[    7.261003] usbhid 1-1:1.0: usb_probe_interface - got id
[    7.455562] usbhid 1-1:1.0: looking for a minor, starting at 96
[    7.457603] generic-usb 0003:9AC4:4B8F.0001: hiddev0,hidraw0: USB
HID v1.00 Device [J. Westhues ProxMark-3 RFID Instrument] on
usb-0000:00:01.2-1/input0
[    7.462993] drivers/usb/core/inode.c: creating file '002'
[   74.921035] ------------[ cut here ]------------
[   74.923120] WARNING: at drivers/tty/tty_ldisc.c:766
tty_ldisc_reinit+0x7d/0x90()
[   74.926744] Hardware name: Bochs
[   74.927882] Pid: 1386, comm: login Not tainted 3.0.0-rc7+ #5
[   74.929408] Call Trace:
[   74.930391]  [<c15e9879>] ? printk+0x18/0x1a
[   74.931650]  [<c103e128>] warn_slowpath_common+0x68/0xa0
[   74.933367]  [<c128515d>] ? tty_ldisc_reinit+0x7d/0x90
[   74.934907]  [<c128515d>] ? tty_ldisc_reinit+0x7d/0x90
[   74.936242]  [<c103e1fd>] warn_slowpath_null+0x1d/0x20
[   74.937584]  [<c128515d>] tty_ldisc_reinit+0x7d/0x90
[   74.939152]  [<c128577f>] tty_ldisc_hangup+0xdf/0x200
[   74.968743]  [<c127e4f5>] __tty_hangup+0xe5/0x360
[   74.970158]  [<c127ff3c>] disassociate_ctty+0x6c/0x200
[   74.971526]  [<c104198b>] do_exit+0x55b/0x7d0
[   74.972745]  [<c127dd20>] ? tty_write_lock+0x50/0x50
[   74.974052]  [<c1041c79>] do_group_exit+0x39/0xa0
[   74.975338]  [<c1041cf3>] sys_exit_group+0x13/0x20
[   74.976658]  [<c15ec85c>] sysenter_do_call+0x12/0x2c
[   74.977938]  [<c15e0000>] ? pci_fixup_i450gx+0x40/0x53
[   74.979462] ---[ end trace c3cfae8b1239077b ]---

This is inside qemu/kvm with usb pass-through: -usbdevice host:9ac4:4b8f

Any ideas?

Thanks,


Vegard

Re: WARNING: at drivers/tty/tty_ldisc.c:766 tty_ldisc_reinit+0x7d/0x90()

[Arnd Bergmann]

On Tuesday 19 July 2011 13:33:36 Vegard Nossum wrote:

> [   74.930391]  [<c15e9879>] ? printk+0x18/0x1a
> [   74.931650]  [<c103e128>] warn_slowpath_common+0x68/0xa0
> [   74.933367]  [<c128515d>] ? tty_ldisc_reinit+0x7d/0x90
> [   74.934907]  [<c128515d>] ? tty_ldisc_reinit+0x7d/0x90
> [   74.936242]  [<c103e1fd>] warn_slowpath_null+0x1d/0x20
> [   74.937584]  [<c128515d>] tty_ldisc_reinit+0x7d/0x90
> [   74.939152]  [<c128577f>] tty_ldisc_hangup+0xdf/0x200
> [   74.968743]  [<c127e4f5>] __tty_hangup+0xe5/0x360
> [   74.970158]  [<c127ff3c>] disassociate_ctty+0x6c/0x200
> [   74.971526]  [<c104198b>] do_exit+0x55b/0x7d0
> [   74.972745]  [<c127dd20>] ? tty_write_lock+0x50/0x50
> [   74.974052]  [<c1041c79>] do_group_exit+0x39/0xa0
> [   74.975338]  [<c1041cf3>] sys_exit_group+0x13/0x20
> [   74.976658]  [<c15ec85c>] sysenter_do_call+0x12/0x2c
> [   74.977938]  [<c15e0000>] ? pci_fixup_i450gx+0x40/0x53
> [   74.979462] ---[ end trace c3cfae8b1239077b ]---
> 
> This is inside qemu/kvm with usb pass-through: -usbdevice host:9ac4:4b8f
> 
> Any ideas?

This is the WARN_ON that Jiri added in 92f6fa09b "TTY: ldisc, do not close
until there are readers".

Is the login process that triggered this running on the USB device you pass
through, or do you have vga or serial console?

	Arnd

Re: WARNING: at drivers/tty/tty_ldisc.c:766 tty_ldisc_reinit+0x7d/0x90()

[Vegard Nossum]

On 19 July 2011 19:53, Arnd Bergmann <arnd@arndb.de> wrote:
> On Tuesday 19 July 2011 13:33:36 Vegard Nossum wrote:
>> Any ideas?
>
> This is the WARN_ON that Jiri added in 92f6fa09b "TTY: ldisc, do not close
> until there are readers".
>
> Is the login process that triggered this running on the USB device you pass
> through, or do you have vga or serial console?

I am using console=ttyS0 console=tty0, so I have both vga and serial
console. The login process was running on the vga console.


Vegard

Re: WARNING: at drivers/tty/tty_ldisc.c:766 tty_ldisc_reinit+0x7d/0x90()

[Jiri Slaby]

[-- Attachment #1: Type: text/plain, Size: 854 bytes --]

On 07/19/2011 09:43 PM, Vegard Nossum wrote:
> On 19 July 2011 19:53, Arnd Bergmann <arnd@arndb.de> wrote:
>> On Tuesday 19 July 2011 13:33:36 Vegard Nossum wrote:
>>> Any ideas?
>>
>> This is the WARN_ON that Jiri added in 92f6fa09b "TTY: ldisc, do not close
>> until there are readers".
>>
>> Is the login process that triggered this running on the USB device you pass
>> through, or do you have vga or serial console?
> 
> I am using console=ttyS0 console=tty0, so I have both vga and serial
> console. The login process was running on the vga console.

Hi, hmm, originally wait_for_idle was there without checking the retval.
I added it back with checking the retval. I really wonder who is the
other user of the port. Or if there is a bug in refcounting somewhere.

Could you attach output of the kernel run with the patch attached?

thanks,
-- 
js

[-- Attachment #2: 0001-TTY-tty_ldisc_wait_idle-debug.patch --]
[-- Type: text/x-patch, Size: 1218 bytes --]

>From 5c6bd3fe6d06b13511f366248052ec789c58b88c Mon Sep 17 00:00:00 2001
From: Jiri Slaby <jslaby@suse.cz>
Date: Mon, 8 Aug 2011 16:00:59 +0200
Subject: [PATCH] TTY: tty_ldisc_wait_idle debug

Signed-off-by: Jiri Slaby <jslaby@suse.cz>
---
 drivers/tty/tty_ldisc.c |    9 ++++++++-
 1 files changed, 8 insertions(+), 1 deletions(-)

diff --git a/drivers/tty/tty_ldisc.c b/drivers/tty/tty_ldisc.c
index 512c49f..0b90801 100644
--- a/drivers/tty/tty_ldisc.c
+++ b/drivers/tty/tty_ldisc.c
@@ -26,6 +26,7 @@
 #include <linux/bitops.h>
 #include <linux/delay.h>
 #include <linux/seq_file.h>
+#include <linux/ratelimit.h>
 
 #include <linux/uaccess.h>
 #include <asm/system.h>
@@ -758,11 +759,17 @@ static void tty_reset_termios(struct tty_struct *tty)
 static int tty_ldisc_reinit(struct tty_struct *tty, int ldisc)
 {
 	struct tty_ldisc *ld = tty_ldisc_get(ldisc);
+	int ret;
 
 	if (IS_ERR(ld))
 		return -1;
 
-	WARN_ON_ONCE(tty_ldisc_wait_idle(tty));
+	ret = tty_ldisc_wait_idle(tty);
+	if (ret)
+		printk_ratelimited(KERN_DEBUG "%s: refcount of %ps is still %d\n",
+				__func__,
+				tty->ldisc->ops,
+				atomic_read(&tty->ldisc->users));
 
 	tty_ldisc_close(tty, tty->ldisc);
 	tty_ldisc_put(tty->ldisc);
-- 
1.7.6