On Tue, 21 Jul 2009, Alan Cox wrote: > A tty getting destructed before it should have been would perhaps do some > of it but it doesn't explain how the close path got where it did. > > What should be occurring is > > USB disconnect > usb_serial_disconnect(interface) > tty_hangup(tty) [this is buggy and commented as such in > the USB code as it should do it synchronously] I'll change it to tty_vhangup(tty) eventually. > tty_hangup() > do_tty_hangup() > file->f_ops = &hung_up_tty_ops; > > (so the USB close will never be called) That doesn't make sense. The driver's open method has been called, so of course the driver expects its close method to be called. > ldisc hangup > tty->ops->hangup (no-op on USB serial) What do you mean? There is a serial_hangup method in usb-serial.c and it does get called; see below. > so the trace to me implies that the usb_serial_disconnect is not > happening. That in turn leads the close method to be called on a > disconnected port which in turn crashes stuff. No, you're wrong. Here is a log with some extra debugging lines added: Open /dev/ttyUSB0: [ 278.680845] opening ttyUSB0... [ 278.689268] uhci_hcd 0000:00:1d.1: reserve dev 2 ep81-INT, period 1, phase 0, 19 us [ 278.690246] pl2303 ttyUSB0: serial_open port 0 (ef7fd920), refcount 6 [ 278.696682] opening tty2... [ 278.696766] tty_release_dev of tty2 (tty count=2)... [ 278.699716] opening tty2... Unplug the pl2303 device (a bunch of uninteresting USB messages have been left out): [ 283.618244] usb 2-2: unregistering interface 2-2:1.0 [ 283.618864] pl2303 ttyUSB0: serial_disconnect port 0, refcount 6 The line above was inserted in serial_disconnect. [ 283.618958] ttyUSB0 hangup... [ 283.619722] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0 [ 283.619974] pl2303 2-2:1.0: device disconnected [ 283.620244] usb 2-2:1.0: uevent [ 283.621302] usb 2-2: uevent [ 283.623660] usb-serial ttyUSB0: serial_hangup port 0, refcount 2 The line above was inserted in serial_hangup, as was the following stack dump. [ 283.623765] Pid: 6, comm: events/0 Not tainted 2.6.31-rc3 #2 [ 283.623859] Call Trace: [ 283.623954] [<c11c0111>] ? printk+0xf/0x11 [ 283.624088] [<f08b09d7>] serial_hangup+0x45/0x66 [usbserial] [ 283.624187] [<c112018c>] do_tty_hangup+0x28c/0x2b9 [ 283.624282] [<c102e6fe>] worker_thread+0x168/0x247 [ 283.624374] [<c102e6b9>] ? worker_thread+0x123/0x247 [ 283.624466] [<c111ff00>] ? do_tty_hangup+0x0/0x2b9 [ 283.624560] [<c1031b57>] ? autoremove_wake_function+0x0/0x33 [ 283.624653] [<c102e596>] ? worker_thread+0x0/0x247 [ 283.624744] [<c10318f1>] kthread+0x69/0x6e [ 283.624834] [<c1031888>] ? kthread+0x0/0x6e [ 283.624926] [<c10034ef>] kernel_thread_helper+0x7/0x10 [ 283.625144] usb-serial ttyUSB0: serial_do_free port 0, refcount 2 [ 283.625314] usb-serial ttyUSB0: destroy_serial port 0, refcount 1 [ 283.625408] port_free port 0, refcount 0 Close the open file descriptor: [ 291.227977] tty_release_dev of tty2 (tty count=2)... [ 291.230492] tty_release_dev of ttyUSB0 (tty count=1)... [ 291.230630] serial_close port 107 (ef7fd920) That line was inserted in serial_close. As you can see, the port number is wrong because the port structure has already been deallocated by port_free. And that leads to the following corruption. [ 291.230772] ------------[ cut here ]------------ [ 291.230943] WARNING: at kernel/lockdep.c:2621 __lock_acquire+0x395/0xaf5() [ 291.231037] Hardware name: [ 291.231123] Modules linked in: pl2303 usbserial pcspkr evdev e100 mii ohci_hcd ehci_hcd uhci_hcd floppy processor button thermal_sys usbcore [last unloaded: scsi_wait_scan] [ 291.231901] Pid: 2037, comm: cat Not tainted 2.6.31-rc3 #2 [ 291.231990] Call Trace: [ 291.232042] [<c1021718>] warn_slowpath_common+0x60/0x90 [ 291.232042] [<c1021755>] warn_slowpath_null+0xd/0x10 [ 291.232042] [<c103ed98>] __lock_acquire+0x395/0xaf5 [ 291.232042] [<c1021ca4>] ? release_console_sem+0x197/0x1c4 [ 291.232042] [<c103f540>] lock_acquire+0x48/0x64 [ 291.232042] [<c112689c>] ? tty_port_close_start+0x1a/0x118 [ 291.232042] [<c11c227f>] _spin_lock_irqsave+0x2e/0x3e [ 291.232042] [<c112689c>] ? tty_port_close_start+0x1a/0x118 [ 291.232042] [<c112689c>] tty_port_close_start+0x1a/0x118 [ 291.232042] [<f08b0a5a>] serial_close+0x62/0x91 [usbserial] [ 291.232042] [<c1120c2b>] tty_release_dev+0x191/0x41f [ 291.232042] [<c103d28e>] ? register_lock_class+0x17/0x272 [ 291.232042] [<c1120ecb>] tty_release+0x12/0x1c [ 291.232042] [<c107201f>] __fput+0xe9/0x172 [ 291.232042] [<c10720c1>] fput+0x19/0x1c [ 291.232042] [<c106f93c>] filp_close+0x51/0x5b [ 291.232042] [<c106f9b0>] sys_close+0x6a/0xa4 [ 291.232042] [<c1002a08>] sysenter_do_call+0x12/0x36 [ 291.232042] ---[ end trace 5e364c88669fab14 ]--- [ 291.233897] freeing tty structure... Does this help pin down the source of the problem? Alan Stern -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
