All of lore.kernel.org
 help / color / mirror / Atom feed
* 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
@ 2009-08-08 17:47 Bruno Prémont
  2009-08-09 14:02 ` Ozan Çağlayan
  2009-08-10 15:18 ` Alan Stern
  0 siblings, 2 replies; 42+ messages in thread
From: Bruno Prémont @ 2009-08-08 17:47 UTC (permalink / raw)
  To: Greg Kroah-Hartman; +Cc: linux-kernel, linux-usb, Rafael J. Wysocki

I tried bisecting this but bisect did end up on a fully unrelated commit
(which is not even being compiled into my kernel).
Possibly the failed bisect could be related to mis-classified kernel
panic/hang while pulling the USB cable (there were two such panics for the
whole iteration)?

There are quite a few patches touching tty, ttyUSB and friends between
rc4 and now so pretty hard to guess on the correct one.

The oops always happens when I disconnect the USB serial console (here
the one built into Marvell SheevaPlug) while having minicom connected
to it.
During the bisection for the last few bad iterations minicom got killed
(segfault), the bad ones on the iteration left a minicom zombie in 'D'
state.

Regards,
Bruno


In case if can be of some use, here is the bisect log:
git bisect start
# bad: [cf265c2c5df57b0025713791cab06cc685eb3bfe] Revert "Subject: [PATCH V2] drm/i915: Detect lvds channel according to fixed mode line"
git bisect bad cf265c2c5df57b0025713791cab06cc685eb3bfe
# good: [4be3bd7849165e7efa6b0b35a23d6a3598d97465] Linux 2.6.31-rc4
git bisect good 4be3bd7849165e7efa6b0b35a23d6a3598d97465
# good: [4be3bd7849165e7efa6b0b35a23d6a3598d97465] Linux 2.6.31-rc4
git bisect good 4be3bd7849165e7efa6b0b35a23d6a3598d97465
# bad: [3822a0e38c329a598cb6f5baa16be7504e0db8d9] mmc: orphan subsystem
git bisect bad 3822a0e38c329a598cb6f5baa16be7504e0db8d9
# bad: [7d084d96fdf1d791cb171da57efc1ca89d68dd6c] libata: Updates and fixes for pata_at91 driver
git bisect bad 7d084d96fdf1d791cb171da57efc1ca89d68dd6c
# good: [6a31d4aeab85a02f9a57ca37b935054393daa794] Merge branch 'fixes-for-linus' of git://git.monstr.eu/linux-2.6-microblaze
git bisect good 6a31d4aeab85a02f9a57ca37b935054393daa794
# bad: [f1462147f15a954a1a0553390846c6fa3ca742b1] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-2.6
git bisect bad f1462147f15a954a1a0553390846c6fa3ca742b1
# bad: [d14a7679ae9b7d4eb4b92e81f5039b719fd98c4d] Merge branch 'master' of git://git.kernel.org/pub/scm/linux/kernel/git/linville/wireless-2.6
git bisect bad d14a7679ae9b7d4eb4b92e81f5039b719fd98c4d
# bad: [7adfd5c71693b81e995283805b17aa4a2ee0ecd9] rt2x00: Fix chipset detection for rt2500usb
git bisect bad 7adfd5c71693b81e995283805b17aa4a2ee0ecd9
# bad: [48ab3578a65c5168ecaaa3b21292b643b7bcc2d5] rfkill: fix rfkill_set_states() to set the hw state
git bisect bad 48ab3578a65c5168ecaaa3b21292b643b7bcc2d5
# bad: [7b80ece41aea0b73283c6df5a8f25d40aa13135d] iwlwifi: only update byte count table during aggregation
git bisect bad 7b80ece41aea0b73283c6df5a8f25d40aa13135d
# bad: [872ed1902f511a8947021c562f5728a5bf0640b5] iwlwifi: only show active power level via sysfs
git bisect bad 872ed1902f511a8947021c562f5728a5bf0640b5
# bad: [513a2396d8e8327aff1ce50bea3fb4f16ff3455b] iwmc3200wifi: fix NULL pointer dereference in iwm_if_free
git bisect bad 513a2396d8e8327aff1ce50bea3fb4f16ff3455b


[ 1638.060039] usb 1-2: new full speed USB device using uhci_hcd and address 2
[ 1638.278185] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[ 1638.278195] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1638.278204] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[ 1638.278210] usb 1-2: Manufacturer: FTDI
[ 1638.278216] usb 1-2: SerialNumber: FTS55QK6
[ 1638.278444] usb 1-2: configuration #1 chosen from 1 choice
[ 1638.760727] usbcore: registered new interface driver usbserial
[ 1638.760732] usbserial: USB Serial Driver core
[ 1638.772202] USB Serial support registered for FTDI USB Serial Device
[ 1638.772318] usb 1-2: Ignoring serial port reserved for JTAG
[ 1638.772374] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[ 1638.772414] usb 1-2: Detected FT2232C
[ 1638.772417] usb 1-2: Number of endpoints 2
[ 1638.772420] usb 1-2: Endpoint 1 MaxPacketSize 64
[ 1638.772423] usb 1-2: Endpoint 2 MaxPacketSize 64
[ 1638.772426] usb 1-2: Setting MaxPacketSize 64
[ 1638.774239] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[ 1638.774268] usbcore: registered new interface driver ftdi_sio
[ 1638.774271] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[ 1761.750059] usb 1-2: USB disconnect, address 2
[ 1761.750475] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[ 1761.750505] ftdi_sio 1-2:1.1: device disconnected
[ 1761.751734] tty_port_close_start: count = -1
[ 1769.392487] BUG: unable to handle kernel paging request at 61762056
[ 1769.392742] IP: [<de765d28>] serial_do_free+0x38/0x80 [usbserial]
[ 1769.392979] *pde = 00000000 
[ 1769.393101] Oops: 0000 [#1] 
[ 1769.393223] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[ 1769.393468] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec nsc_ircc ac97_bus snd_pcm snd_timer i2c_i801 pcspkr irda snd snd_page_alloc ehci_hcd uhci_hcd crc_ccitt usbcore
[ 1769.394814] 
[ 1769.394890] Pid: 2588, comm: minicom Tainted: G   M       (2.6.31-rc5 #2) TravelMate 660
[ 1769.395144] EIP: 0060:[<de765d28>] EFLAGS: 00010246 CPU: 0
[ 1769.395344] EIP is at serial_do_free+0x38/0x80 [usbserial]
[ 1769.395519] EAX: 6176203a EBX: daad3000 ECX: de765d70 EDX: daad3a00
[ 1769.395747] ESI: daad3038 EDI: 00000000 EBP: dc397e24 ESP: dc397e18
[ 1769.395945]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 1769.396135] Process minicom (pid: 2588, ti=dc397000 task=dd8e46a0 task.ti=dc397000)
[ 1769.396374] Stack:
[ 1769.396458]  daad3a00 dc37e400 00000000 dc397e4c de765dd6 00000000 dc397e4c c115cf85
[ 1769.396835] <0> dc37e4a0 dc383d80 dc37e400 00000000 00000000 dc397edc c115f0c0 00000001
[ 1769.397256] <0> 00000002 c15a8380 dc383d80 00000000 00000000 c18541c0 40000000 00000000
[ 1769.397689] Call Trace:
[ 1769.397799]  [<de765dd6>] ? serial_close+0x66/0xa0 [usbserial]
[ 1769.397992]  [<c115cf85>] ? tty_fasync+0x55/0xe0
[ 1769.398163]  [<c115f0c0>] ? tty_release_dev+0x130/0x490
[ 1769.398339]  [<c1056b82>] ? put_page+0x42/0x120
[ 1769.398507]  [<c10895b6>] ? mntput_no_expire+0x16/0x60
[ 1769.398675]  [<c115f42a>] ? tty_release+0xa/0x10
[ 1769.398844]  [<c1075d2c>] ? __fput+0xdc/0x1d0
[ 1769.398987]  [<c1075e3f>] ? fput+0x1f/0x30
[ 1769.399142]  [<c1072d9e>] ? filp_close+0x3e/0x70
[ 1769.399297]  [<c1024dd2>] ? put_files_struct+0xa2/0xc0
[ 1769.399481]  [<c1024e0c>] ? exit_files+0x1c/0x20
[ 1769.399633]  [<c1026169>] ? do_exit+0xb9/0x630
[ 1769.399798]  [<c103aab8>] ? __put_cred+0x18/0x20
[ 1769.399950]  [<c102670d>] ? do_group_exit+0x2d/0x80
[ 1769.400145]  [<c1026773>] ? sys_exit_group+0x13/0x20
[ 1769.400309]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[ 1769.400488] Code: 24 04 89 7c 24 08 80 b8 b6 00 00 00 00 74 14 8b 1c 24 8b 74 24 04 8b 7c 24 08 89 ec 5d c3 90 8d 74 26 00 8b 18 8b 43 04 8d 73 38 <8b> 78 1c 8d 82 bc 00 00 00 e8 1a c1 a4 e2 89 f0 e8 33 1d b5 e2 
[ 1769.402352] EIP: [<de765d28>] serial_do_free+0x38/0x80 [usbserial] SS:ESP 0068:dc397e18
[ 1769.402649] CR2: 0000000061762056
[ 1769.402775] ---[ end trace e6175462c2b3a1ba ]---
[ 1769.402923] Fixing recursive fault but reboot is needed!

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-08 17:47 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use Bruno Prémont
@ 2009-08-09 14:02 ` Ozan Çağlayan
  2009-08-09 15:00   ` Alan Stern
  2009-08-10 15:18 ` Alan Stern
  1 sibling, 1 reply; 42+ messages in thread
From: Ozan Çağlayan @ 2009-08-09 14:02 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Greg Kroah-Hartman, linux-kernel, linux-usb, Rafael J. Wysocki

Bruno Prémont wrote:
> I tried bisecting this but bisect did end up on a fully unrelated commit
> (which is not even being compiled into my kernel).
> Possibly the failed bisect could be related to mis-classified kernel
> panic/hang while pulling the USB cable (there were two such panics for the
> whole iteration)?
>
> There are quite a few patches touching tty, ttyUSB and friends between
> rc4 and now so pretty hard to guess on the correct one.
>
> The oops always happens when I disconnect the USB serial console (here
> the one built into Marvell SheevaPlug) while having minicom connected
> to it.
> During the bisection for the last few bad iterations minicom got killed
> (segfault), the bad ones on the iteration left a minicom zombie in 'D'
> state.
>
> Regards,
> Bruno
>
>   

That may be a related/possible fix for that,

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=b68f2fb9e73f46037fbeca5fbd4ae8a7ddd8ef6b

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-09 14:02 ` Ozan Çağlayan
@ 2009-08-09 15:00   ` Alan Stern
  0 siblings, 0 replies; 42+ messages in thread
From: Alan Stern @ 2009-08-09 15:00 UTC (permalink / raw)
  To: Ozan Çağlayan
  Cc: Bruno Prémont, Greg Kroah-Hartman, linux-kernel, linux-usb,
	Rafael J. Wysocki

On Sun, 9 Aug 2009, [UTF-8] Ozan Çağlayan wrote:

> Bruno Prémont wrote:
> > I tried bisecting this but bisect did end up on a fully unrelated commit
> > (which is not even being compiled into my kernel).
> > Possibly the failed bisect could be related to mis-classified kernel
> > panic/hang while pulling the USB cable (there were two such panics for the
> > whole iteration)?
> >
> > There are quite a few patches touching tty, ttyUSB and friends between
> > rc4 and now so pretty hard to guess on the correct one.
> >
> > The oops always happens when I disconnect the USB serial console (here
> > the one built into Marvell SheevaPlug) while having minicom connected
> > to it.
> > During the bisection for the last few bad iterations minicom got killed
> > (segfault), the bad ones on the iteration left a minicom zombie in 'D'
> > state.
> >
> > Regards,
> > Bruno
> >
> >   
> 
> That may be a related/possible fix for that,
> 
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=b68f2fb9e73f46037fbeca5fbd4ae8a7ddd8ef6b

That patch is already present in 2.6.31-rc5.

The problem here may be related to the fact that the serial port is
being used as a console.  For non-console ports this doesn't happen.

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-08 17:47 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use Bruno Prémont
  2009-08-09 14:02 ` Ozan Çağlayan
@ 2009-08-10 15:18 ` Alan Stern
  2009-08-10 15:44   ` Greg KH
  1 sibling, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-10 15:18 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Greg Kroah-Hartman, linux-kernel, linux-usb, Rafael J. Wysocki

On Sat, 8 Aug 2009, Bruno [UTF-8] Prémont wrote:

> I tried bisecting this but bisect did end up on a fully unrelated commit
> (which is not even being compiled into my kernel).
> Possibly the failed bisect could be related to mis-classified kernel
> panic/hang while pulling the USB cable (there were two such panics for the
> whole iteration)?
> 
> There are quite a few patches touching tty, ttyUSB and friends between
> rc4 and now so pretty hard to guess on the correct one.
> 
> The oops always happens when I disconnect the USB serial console (here
> the one built into Marvell SheevaPlug) while having minicom connected
> to it.
> During the bisection for the last few bad iterations minicom got killed
> (segfault), the bad ones on the iteration left a minicom zombie in 'D'
> state.

By the way, there are quite a few serial patches in Greg KH's tree.  At 
least one of them looks like it is meant to fix exactly this problem.

Can you try running with

http://www.kernel.org/pub/linux/kernel/people/gregkh/gregkh-2.6/gregkh-all-2.6.31-rc5.patch

applied to the standard 2.6.31-rc5 source?

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 15:18 ` Alan Stern
@ 2009-08-10 15:44   ` Greg KH
  2009-08-10 17:18     ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Greg KH @ 2009-08-10 15:44 UTC (permalink / raw)
  To: Alan Stern
  Cc: Bruno Prémont, Greg Kroah-Hartman, linux-kernel, linux-usb,
	Rafael J. Wysocki

On Mon, Aug 10, 2009 at 11:18:29AM -0400, Alan Stern wrote:
> On Sat, 8 Aug 2009, Bruno [UTF-8] Prémont wrote:
> 
> > I tried bisecting this but bisect did end up on a fully unrelated commit
> > (which is not even being compiled into my kernel).
> > Possibly the failed bisect could be related to mis-classified kernel
> > panic/hang while pulling the USB cable (there were two such panics for the
> > whole iteration)?
> > 
> > There are quite a few patches touching tty, ttyUSB and friends between
> > rc4 and now so pretty hard to guess on the correct one.
> > 
> > The oops always happens when I disconnect the USB serial console (here
> > the one built into Marvell SheevaPlug) while having minicom connected
> > to it.
> > During the bisection for the last few bad iterations minicom got killed
> > (segfault), the bad ones on the iteration left a minicom zombie in 'D'
> > state.
> 
> By the way, there are quite a few serial patches in Greg KH's tree.  At 
> least one of them looks like it is meant to fix exactly this problem.
> 
> Can you try running with
> 
> http://www.kernel.org/pub/linux/kernel/people/gregkh/gregkh-2.6/gregkh-all-2.6.31-rc5.patch
> 
> applied to the standard 2.6.31-rc5 source?

Yes, that would be good to find out, so we can pick the right patch to
send in now.

thanks,

greg k-h

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 15:44   ` Greg KH
@ 2009-08-10 17:18     ` Bruno Prémont
  2009-08-10 18:13       ` Greg KH
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-10 17:18 UTC (permalink / raw)
  To: Greg KH
  Cc: Alan Stern, Greg Kroah-Hartman, linux-kernel, linux-usb,
	Rafael J. Wysocki

On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> On Mon, Aug 10, 2009 at 11:18:29AM -0400, Alan Stern wrote:
> > On Sat, 8 Aug 2009, Bruno Prémont wrote:
> > 
> > > I tried bisecting this but bisect did end up on a fully unrelated
> > > commit (which is not even being compiled into my kernel).
> > > Possibly the failed bisect could be related to mis-classified
> > > kernel panic/hang while pulling the USB cable (there were two
> > > such panics for the whole iteration)?
> > > 
> > > There are quite a few patches touching tty, ttyUSB and friends
> > > between rc4 and now so pretty hard to guess on the correct one.
> > > 
> > > The oops always happens when I disconnect the USB serial console
> > > (here the one built into Marvell SheevaPlug) while having minicom
> > > connected to it.
> > > During the bisection for the last few bad iterations minicom got
> > > killed (segfault), the bad ones on the iteration left a minicom
> > > zombie in 'D' state.
> > 
> > By the way, there are quite a few serial patches in Greg KH's
> > tree.  At least one of them looks like it is meant to fix exactly
> > this problem.
> > 
> > Can you try running with
> > 
> > http://www.kernel.org/pub/linux/kernel/people/gregkh/gregkh-2.6/gregkh-all-2.6.31-rc5.patch
> > 
> > applied to the standard 2.6.31-rc5 source?
> 
> Yes, that would be good to find out, so we can pick the right patch to
> send in now.
> 
> thanks,
> 
> greg k-h
> 

Unfortunately none of the patches in gregkh-all-2.6.31-rc5.patch do fix
it.
With these patches minicom segfaults instead of remaining as a zombie
(but that also happened during my bisect sequence.

In this case it looks rather like some use-after-free as kernel tries
to access some memory at an address pretty far away from NULL.

thanks,
Bruno

Here the kernel log for this attempt:
[   78.730035] usb 1-2: new full speed USB device using uhci_hcd and address 2
[   78.948188] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[   78.948198] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   78.948206] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[   78.948213] usb 1-2: Manufacturer: FTDI
[   78.948219] usb 1-2: SerialNumber: FTS55QK6
[   78.948452] usb 1-2: configuration #1 chosen from 1 choice
[   79.053847] usbcore: registered new interface driver usbserial
[   79.053851] usbserial: USB Serial Driver core
[   79.072653] USB Serial support registered for FTDI USB Serial Device
[   79.072865] usb 1-2: Ignoring serial port reserved for JTAG
[   79.072968] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[   79.073030] usb 1-2: Detected FT2232C
[   79.073036] usb 1-2: Number of endpoints 2
[   79.073042] usb 1-2: Endpoint 1 MaxPacketSize 64
[   79.073049] usb 1-2: Endpoint 2 MaxPacketSize 64
[   79.073055] usb 1-2: Setting MaxPacketSize 64
[   79.074355] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[   79.074395] usbcore: registered new interface driver ftdi_sio
[   79.074401] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  199.731548] loop0 used greatest stack depth: 1104 bytes left
[  213.040179] usb 1-2: USB disconnect, address 2
[  213.040577] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  213.040607] ftdi_sio 1-2:1.1: device disconnected
[  213.040893] tty_port_close_start: count = -1
[  213.040914] BUG: unable to handle kernel paging request at de1ab42c
[  213.041166] IP: [<c1165026>] tty_port_close_start+0x96/0x170
[  213.046870] *pde = 00000000 
[  213.052897] Oops: 0002 [#1] 
[  213.058817] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  213.064956] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus snd_pcm snd_timer pcspkr snd ehci_hcd i2c_i801 snd_page_alloc uhci_hcd nsc_ircc usbcore irda crc_ccitt
[  213.078798] 
[  213.085472] Pid: 2119, comm: minicom Tainted: G   M       (2.6.31-rc5-gregkh #3) TravelMate 660
[  213.092424] EIP: 0060:[<c1165026>] EFLAGS: 00010096 CPU: 0
[  213.099402] EIP is at tty_port_close_start+0x96/0x170
[  213.106429] EAX: de1ab42c EBX: dd1ab404 ECX: ffffffff EDX: c13c6564
[  213.113587] ESI: 00000286 EDI: daafc000 EBP: daaead8c ESP: daaead74
[  213.120747]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  213.127925] Process minicom (pid: 2119, ti=daaea000 task=dd952120 task.ti=daaea000)
[  213.135206] Stack:
[  213.142493]  c1374da0 ffffffff c1084cbd dd1ab400 dd1ab404 daafc000 daaeadb4 dfae8a36
[  213.142869] <0> 00000000 daaeadb4 c115cb85 daafc0a0 db067e80 daafc000 00000000 00000000
[  213.150558] <0> daaeae44 c115ed00 daaeaef4 4c99875a dd9d4a80 db067e80 00000000 00000000
[  213.165774] Call Trace:
[  213.173463]  [<c1084cbd>] ? dput+0x8d/0x120
[  213.181179]  [<dfae8a36>] ? serial_close+0x36/0x90 [usbserial]
[  213.188945]  [<c115cb85>] ? tty_fasync+0x55/0xe0
[  213.196693]  [<c115ed00>] ? tty_release_dev+0x130/0x490
[  213.204434]  [<c12b6d8e>] ? mutex_lock+0xe/0x20
[  213.212142]  [<dfae8dc9>] ? usb_serial_put+0x29/0x30 [usbserial]
[  213.219890]  [<dfae9060>] ? serial_open+0x70/0x250 [usbserial]
[  213.227741]  [<c115f70d>] ? tty_open+0x45d/0x4b0
[  213.235653]  [<c1076fe6>] ? chrdev_open+0x96/0x140
[  213.243604]  [<c1072d7f>] ? __dentry_open+0x9f/0x250
[  213.251588]  [<c1073019>] ? nameidata_to_filp+0x59/0x70
[  213.259570]  [<c1076f50>] ? chrdev_open+0x0/0x140
[  213.267596]  [<c107f2f9>] ? do_filp_open+0x269/0x890
[  213.275626]  [<c10389ec>] ? ktime_get_ts+0x4c/0x50
[  213.283673]  [<c1072b47>] ? do_sys_open+0x57/0x140
[  213.291762]  [<c1026b65>] ? alarm_setitimer+0x35/0x70
[  213.299872]  [<c1072c99>] ? sys_open+0x29/0x40
[  213.307998]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  213.316146] Code: eb b8 89 44 24 04 c7 04 24 a0 4d 37 c1 e8 3d 10 15 00 c7 43 0c 00 00 00 00 8d b6 00 00 00 00 8d bf 00 00 00 00 8d 83 28 00 00 01 <80> 8b 28 00 00 01 01 80 8f 2c 01 00 00 20 56 9d 0f b6 87 94 00 
[  213.334752] EIP: [<c1165026>] tty_port_close_start+0x96/0x170 SS:ESP 0068:daaead74
[  213.343661] CR2: 00000000de1ab42c
[  213.352536] ---[ end trace 4e30eef18c7e8fe3 ]---

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 17:18     ` Bruno Prémont
@ 2009-08-10 18:13       ` Greg KH
  2009-08-10 18:35         ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Greg KH @ 2009-08-10 18:13 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Stern, Greg Kroah-Hartman, linux-kernel, linux-usb,
	Rafael J. Wysocki

On Mon, Aug 10, 2009 at 07:18:22PM +0200, Bruno Prémont wrote:
> On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> > On Mon, Aug 10, 2009 at 11:18:29AM -0400, Alan Stern wrote:
> > > On Sat, 8 Aug 2009, Bruno Prémont wrote:
> > > 
> > > > I tried bisecting this but bisect did end up on a fully unrelated
> > > > commit (which is not even being compiled into my kernel).
> > > > Possibly the failed bisect could be related to mis-classified
> > > > kernel panic/hang while pulling the USB cable (there were two
> > > > such panics for the whole iteration)?
> > > > 
> > > > There are quite a few patches touching tty, ttyUSB and friends
> > > > between rc4 and now so pretty hard to guess on the correct one.
> > > > 
> > > > The oops always happens when I disconnect the USB serial console
> > > > (here the one built into Marvell SheevaPlug) while having minicom
> > > > connected to it.
> > > > During the bisection for the last few bad iterations minicom got
> > > > killed (segfault), the bad ones on the iteration left a minicom
> > > > zombie in 'D' state.

Ok, a few questions.

Are you pulling the device out when you have a console attached to the
device, or just a "normal" minicom connection with it?  I can't seem to
duplicate this here at the moment for some reason :(

thanks,

greg k-h

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 18:13       ` Greg KH
@ 2009-08-10 18:35         ` Bruno Prémont
  2009-08-10 18:51           ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-10 18:35 UTC (permalink / raw)
  To: Greg KH
  Cc: Alan Stern, Greg Kroah-Hartman, linux-kernel, linux-usb,
	Rafael J. Wysocki

On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> On Mon, Aug 10, 2009 at 07:18:22PM +0200, Bruno Prémont wrote:
> > On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> > > On Mon, Aug 10, 2009 at 11:18:29AM -0400, Alan Stern wrote:
> > > > On Sat, 8 Aug 2009, Bruno Prémont wrote:
> > > > 
> > > > > I tried bisecting this but bisect did end up on a fully
> > > > > unrelated commit (which is not even being compiled into my
> > > > > kernel). Possibly the failed bisect could be related to
> > > > > mis-classified kernel panic/hang while pulling the USB cable
> > > > > (there were two such panics for the whole iteration)?
> > > > > 
> > > > > There are quite a few patches touching tty, ttyUSB and friends
> > > > > between rc4 and now so pretty hard to guess on the correct
> > > > > one.
> > > > > 
> > > > > The oops always happens when I disconnect the USB serial
> > > > > console (here the one built into Marvell SheevaPlug) while
> > > > > having minicom connected to it.
> > > > > During the bisection for the last few bad iterations minicom
> > > > > got killed (segfault), the bad ones on the iteration left a
> > > > > minicom zombie in 'D' state.
> 
> Ok, a few questions.
> 
> Are you pulling the device out when you have a console attached to the
> device, or just a "normal" minicom connection with it?  I can't seem
> to duplicate this here at the moment for some reason :(
> 
> thanks,
> 
> greg k-h
> 

The SheevaPlug has a getty running on ttyS0 (agetty 115200 ttyS0 vt100).
That ttyS0 is exported via the FTDI USB to Serial+JTag converter.

On the laptop side (where the kernel Oopses) I see /dev/ttyUSB0 (which
I instruct minicom to use via symlink to
/dev/serial/by-id/usb-FTDI_SheevaPlug_JTAGKey_FT2232D_B_FTS55QK6-if01-port0
 -- minicom is limited to 63byte length for path to tty device)

I run minicom with the following parameters:
  minicom -o -c on sheeva

/etc/minicom/minirc.sheeva
  pu port             /etc/minicom/tty-sheeva
  pu rtscts           No

That is 115200 8N1, with neither hardware nor software flow control.

I'm pulling the USB cable while minicom is running and agetty on the
other side is waiting for password input. (pulling the USB cable is
too easy - and same effect is obtained when pulling power from the
SheevaPlug)


I have not tried yet with a different USB serial device but will do so
soon to see if I can reproduce it there. (the other USBSerial device I
have is: 067b:2303 Prolific Technology, Inc. PL2303 Serial Port)

thanks,
Bruno

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 18:35         ` Bruno Prémont
@ 2009-08-10 18:51           ` Bruno Prémont
  2009-08-10 19:29             ` Greg KH
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-10 18:51 UTC (permalink / raw)
  Cc: Greg KH, Alan Stern, Greg Kroah-Hartman, linux-kernel, linux-usb,
	Rafael J. Wysocki

On Mon, 10 August 2009 Bruno Prémont <bonbons@linux-vserver.org> wrote:
> On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> > On Mon, Aug 10, 2009 at 07:18:22PM +0200, Bruno Prémont wrote:
> > > On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> > > > On Mon, Aug 10, 2009 at 11:18:29AM -0400, Alan Stern wrote:
> > > > > On Sat, 8 Aug 2009, Bruno Prémont wrote:
> > > > > 
> > > > > > I tried bisecting this but bisect did end up on a fully
> > > > > > unrelated commit (which is not even being compiled into my
> > > > > > kernel). Possibly the failed bisect could be related to
> > > > > > mis-classified kernel panic/hang while pulling the USB cable
> > > > > > (there were two such panics for the whole iteration)?
> > > > > > 
> > > > > > There are quite a few patches touching tty, ttyUSB and
> > > > > > friends between rc4 and now so pretty hard to guess on the
> > > > > > correct one.
> > > > > > 
> > > > > > The oops always happens when I disconnect the USB serial
> > > > > > console (here the one built into Marvell SheevaPlug) while
> > > > > > having minicom connected to it.
> > > > > > During the bisection for the last few bad iterations minicom
> > > > > > got killed (segfault), the bad ones on the iteration left a
> > > > > > minicom zombie in 'D' state.
> > 
> > Ok, a few questions.
> > 
> > Are you pulling the device out when you have a console attached to
> > the device, or just a "normal" minicom connection with it?  I can't
> > seem to duplicate this here at the moment for some reason :(
> > 
> > thanks,
> > 
> > greg k-h
> > 
> 
> The SheevaPlug has a getty running on ttyS0 (agetty 115200 ttyS0
> vt100). That ttyS0 is exported via the FTDI USB to Serial+JTag
> converter.
> 
> On the laptop side (where the kernel Oopses) I see /dev/ttyUSB0 (which
> I instruct minicom to use via symlink to
> /dev/serial/by-id/usb-_SheevaPlug_JTAGKey_FT2232D_B_FTS55QK6-if01-port0 -- minicom is
> limited to 63byte length for path to tty device)
> 
> I run minicom with the following parameters:
>   minicom -o -c on sheeva
> 
> /etc/minicom/minirc.sheeva
>   pu port             /etc/minicom/tty-sheeva
>   pu rtscts           No
> 
> That is 115200 8N1, with neither hardware nor software flow control.
> 
> I'm pulling the USB cable while minicom is running and agetty on the
> other side is waiting for password input. (pulling the USB cable is
> too easy - and same effect is obtained when pulling power from the
> SheevaPlug)
> 
> 
> I have not tried yet with a different USB serial device but will do so
> soon to see if I can reproduce it there. (the other USBSerial device I
> have is: 067b:2303 Prolific Technology, Inc. PL2303 Serial Port)

I can't reproduce with this one.

Similar setup, but instead of SheevaPlug (with it's kernel started with
console=ttyS0,115200 + agetty run by init) I just started agetty (same
parameters) on a x86 box with uart serial port (e.g. that x86 kernel
does not have console kernel parameter) and connected that one via
NullModem cable to the Prolific USBSerial converter.

In this case, no matter how often I pull the USBSerial converter there
is no Oops.

So it must be something that FTDI driver does differently from e.g.
Prolific one.

thanks,
Bruno

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 18:51           ` Bruno Prémont
@ 2009-08-10 19:29             ` Greg KH
  2009-08-18 17:00               ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Greg KH @ 2009-08-10 19:29 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Greg KH, Alan Stern, linux-kernel, linux-usb, Rafael J. Wysocki

On Mon, Aug 10, 2009 at 08:51:15PM +0200, Bruno Prémont wrote:
> On Mon, 10 August 2009 Bruno Prémont <bonbons@linux-vserver.org> wrote:
> > On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> > > On Mon, Aug 10, 2009 at 07:18:22PM +0200, Bruno Prémont wrote:
> > > > On Mon, 10 August 2009 Greg KH <greg@kroah.com> wrote:
> > > > > On Mon, Aug 10, 2009 at 11:18:29AM -0400, Alan Stern wrote:
> > > > > > On Sat, 8 Aug 2009, Bruno Prémont wrote:
> > > > > > 
> > > > > > > I tried bisecting this but bisect did end up on a fully
> > > > > > > unrelated commit (which is not even being compiled into my
> > > > > > > kernel). Possibly the failed bisect could be related to
> > > > > > > mis-classified kernel panic/hang while pulling the USB cable
> > > > > > > (there were two such panics for the whole iteration)?
> > > > > > > 
> > > > > > > There are quite a few patches touching tty, ttyUSB and
> > > > > > > friends between rc4 and now so pretty hard to guess on the
> > > > > > > correct one.
> > > > > > > 
> > > > > > > The oops always happens when I disconnect the USB serial
> > > > > > > console (here the one built into Marvell SheevaPlug) while
> > > > > > > having minicom connected to it.
> > > > > > > During the bisection for the last few bad iterations minicom
> > > > > > > got killed (segfault), the bad ones on the iteration left a
> > > > > > > minicom zombie in 'D' state.
> > > 
> > > Ok, a few questions.
> > > 
> > > Are you pulling the device out when you have a console attached to
> > > the device, or just a "normal" minicom connection with it?  I can't
> > > seem to duplicate this here at the moment for some reason :(
> > > 
> > > thanks,
> > > 
> > > greg k-h
> > > 
> > 
> > The SheevaPlug has a getty running on ttyS0 (agetty 115200 ttyS0
> > vt100). That ttyS0 is exported via the FTDI USB to Serial+JTag
> > converter.
> > 
> > On the laptop side (where the kernel Oopses) I see /dev/ttyUSB0 (which
> > I instruct minicom to use via symlink to
> > /dev/serial/by-id/usb-_SheevaPlug_JTAGKey_FT2232D_B_FTS55QK6-if01-port0 -- minicom is
> > limited to 63byte length for path to tty device)
> > 
> > I run minicom with the following parameters:
> >   minicom -o -c on sheeva
> > 
> > /etc/minicom/minirc.sheeva
> >   pu port             /etc/minicom/tty-sheeva
> >   pu rtscts           No
> > 
> > That is 115200 8N1, with neither hardware nor software flow control.
> > 
> > I'm pulling the USB cable while minicom is running and agetty on the
> > other side is waiting for password input. (pulling the USB cable is
> > too easy - and same effect is obtained when pulling power from the
> > SheevaPlug)
> > 
> > 
> > I have not tried yet with a different USB serial device but will do so
> > soon to see if I can reproduce it there. (the other USBSerial device I
> > have is: 067b:2303 Prolific Technology, Inc. PL2303 Serial Port)
> 
> I can't reproduce with this one.
> 
> Similar setup, but instead of SheevaPlug (with it's kernel started with
> console=ttyS0,115200 + agetty run by init) I just started agetty (same
> parameters) on a x86 box with uart serial port (e.g. that x86 kernel
> does not have console kernel parameter) and connected that one via
> NullModem cable to the Prolific USBSerial converter.
> 
> In this case, no matter how often I pull the USBSerial converter there
> is no Oops.
> 
> So it must be something that FTDI driver does differently from e.g.
> Prolific one.

Ok, thanks, I'll dig through my big box of usb devices to try to find a
ftdi device, I was testing this out on a pl2303 device, which is why I
couldn't reproduce it it seems.

greg k-h

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-10 19:29             ` Greg KH
@ 2009-08-18 17:00               ` Bruno Prémont
  2009-08-18 22:36                 ` Greg KH
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-18 17:00 UTC (permalink / raw)
  To: Greg KH; +Cc: Greg KH, Alan Stern, linux-kernel, linux-usb, Rafael J. Wysocki

Hi Greg,

Were you able to reproduce this with a FTDI usbserial device?


I just had a short look with 2.6.31-rc6, it crashes harder... once
kernel did panic with general protection fault after reporting
  tty_port_close_start: count=-1
The second time id started output of an Oops but only half of the first
line ever showed up on screen (Intel KMS).

Note: this was with just usbserial.ko and ftdi_sio.ko rebuilt with
CONFIG_DEBUG_INFO=y in the hope to find out what did access a bad
pointer. (make CONFIG_DEBUG_INFO=y drivers/usb/serial/$module.ko)

Will retry now with a fresh compile with CONFIG_DEBUG_INFO enabled for
whole kernel and see if I can get better information, eventually
switching to vesa framebuffer in case the partial output happens again.

This pretty much looks like unbalanced ref-count...

Thanks,
Bruno

On Mon, 10 August 2009 Greg KH <gregkh@suse.de> wrote:
> > > I have not tried yet with a different USB serial device but will
> > > do so soon to see if I can reproduce it there. (the other
> > > USBSerial device I have is: 067b:2303 Prolific Technology, Inc.
> > > PL2303 Serial Port)
> > 
> > I can't reproduce with this one.
> > 
> > Similar setup, but instead of SheevaPlug (with it's kernel started
> > with console=ttyS0,115200 + agetty run by init) I just started
> > agetty (same parameters) on a x86 box with uart serial port (e.g.
> > that x86 kernel does not have console kernel parameter) and
> > connected that one via NullModem cable to the Prolific USBSerial
> > converter.
> > 
> > In this case, no matter how often I pull the USBSerial converter
> > there is no Oops.
> > 
> > So it must be something that FTDI driver does differently from e.g.
> > Prolific one.
> 
> Ok, thanks, I'll dig through my big box of usb devices to try to find
> a ftdi device, I was testing this out on a pl2303 device, which is
> why I couldn't reproduce it it seems.

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-18 17:00               ` Bruno Prémont
@ 2009-08-18 22:36                 ` Greg KH
  2009-08-18 23:16                   ` Greg KH
  2009-08-19 17:22                   ` Bruno Prémont
  0 siblings, 2 replies; 42+ messages in thread
From: Greg KH @ 2009-08-18 22:36 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Greg KH, Alan Stern, linux-kernel, linux-usb, Rafael J. Wysocki

On Tue, Aug 18, 2009 at 07:00:16PM +0200, Bruno Prémont wrote:
> Hi Greg,
> 
> Were you able to reproduce this with a FTDI usbserial device?

No, I can't find one in my box.  I'll go dig in the attic next to try to
find on, I knew I had one before...

> I just had a short look with 2.6.31-rc6, it crashes harder... once
> kernel did panic with general protection fault after reporting
>   tty_port_close_start: count=-1
> The second time id started output of an Oops but only half of the first
> line ever showed up on screen (Intel KMS).
> 
> Note: this was with just usbserial.ko and ftdi_sio.ko rebuilt with
> CONFIG_DEBUG_INFO=y in the hope to find out what did access a bad
> pointer. (make CONFIG_DEBUG_INFO=y drivers/usb/serial/$module.ko)
> 
> Will retry now with a fresh compile with CONFIG_DEBUG_INFO enabled for
> whole kernel and see if I can get better information, eventually
> switching to vesa framebuffer in case the partial output happens again.
> 
> This pretty much looks like unbalanced ref-count...

Yeah, it sounds like it.  More info would be great to have if you can
get it.

thanks,

greg k-h

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-18 22:36                 ` Greg KH
@ 2009-08-18 23:16                   ` Greg KH
  2009-08-19 17:22                   ` Bruno Prémont
  1 sibling, 0 replies; 42+ messages in thread
From: Greg KH @ 2009-08-18 23:16 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Greg KH, Alan Stern, linux-kernel, linux-usb, Rafael J. Wysocki

On Tue, Aug 18, 2009 at 03:36:48PM -0700, Greg KH wrote:
> On Tue, Aug 18, 2009 at 07:00:16PM +0200, Bruno Prémont wrote:
> > Hi Greg,
> > 
> > Were you able to reproduce this with a FTDI usbserial device?
> 
> No, I can't find one in my box.  I'll go dig in the attic next to try to
> find on, I knew I had one before...

Nope, all I found was mcd_u232 and pl2303 devices, no ftdi ones :(

Anyone have a brand name, or a link to one online that I can buy so that
I can get one for testing?

thanks,

greg k-h

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-18 22:36                 ` Greg KH
  2009-08-18 23:16                   ` Greg KH
@ 2009-08-19 17:22                   ` Bruno Prémont
  2009-08-19 18:20                     ` Alan Stern
  1 sibling, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-19 17:22 UTC (permalink / raw)
  To: Greg KH; +Cc: Greg KH, Alan Stern, linux-kernel, linux-usb, Rafael J. Wysocki

On Tue, 18 August 2009 Greg KH <gregkh@suse.de> wrote:
> Yeah, it sounds like it.  More info would be great to have if you can
> get it.

I did try to understand what happens exactly, using backtrace from
kernel compiled with debug info and running objdump on usbserial.ko.


Trace used:
[  593.681350] BUG: unable to handle kernel paging request at 00700128
[  593.681604] IP: [<dea40d28>] serial_do_free+0x38/0x80 [usbserial]
[  593.681842] *pde = 00000000 
[  593.681964] Oops: 0000 [#1] 
[  593.682085] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  593.682330] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus nsc_ircc uhci_hcd ehci_hcd irda snd_pcm snd_timer usbcore snd snd_page_alloc pcspkr i2c_i801 crc_ccitt
[  593.683672] 
[  593.683747] Pid: 2209, comm: minicom Tainted: G   M       (2.6.31-rc6 #1) TravelMate 660
[  593.684001] EIP: 0060:[<dea40d28>] EFLAGS: 00010246 CPU: 0
[  593.684200] EIP is at serial_do_free+0x38/0x80 [usbserial]
[  593.684375] EAX: 0070010c EBX: dd1b2e00 ECX: dea40d70 EDX: dd1b2200
[  593.684590] ESI: dd1b2e38 EDI: 00000000 EBP: da050e24 ESP: da050e18
[  593.684787]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[  593.684976] Process minicom (pid: 2209, ti=da050000 task=dd9addd0 task.ti=da050000)
[  593.685214] Stack:
[  593.685298]  dd1b2200 dd12fc00 00000000 da050e4c dea40dd6 00000000 da050e4c c115d1a5
[  593.685673] <0> dd12fca0 dd804b00 dd12fc00 00000000 00000000 da050edc c115f2e0 00000001
[  593.686091] <0> 00000002 c17b1200 dd804b00 00000000 00000000 c1850740 40000000 00000000
[  593.686520] Call Trace:
[  593.686631]  [<dea40dd6>] ? serial_close+0x66/0xa0 [usbserial]
[  593.686824]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  593.686994]  [<c115f2e0>] ? tty_release_dev+0x130/0x490
[  593.687170]  [<c1056d72>] ? put_page+0x42/0x120
[  593.687339]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  593.687505]  [<c115f64a>] ? tty_release+0xa/0x10
[  593.687673]  [<c1075f1c>] ? __fput+0xdc/0x1d0
[  593.687817]  [<c107602f>] ? fput+0x1f/0x30
[  593.687970]  [<c1072f8e>] ? filp_close+0x3e/0x70
[  593.688126]  [<c1024fa2>] ? put_files_struct+0xa2/0xc0
[  593.688310]  [<c1024fdc>] ? exit_files+0x1c/0x20
[  593.688462]  [<c1026339>] ? do_exit+0xb9/0x630
[  593.688628]  [<c103acd8>] ? __put_cred+0x18/0x20
[  593.688780]  [<c10268dd>] ? do_group_exit+0x2d/0x80
[  593.688957]  [<c1026943>] ? sys_exit_group+0x13/0x20
[  593.689119]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  593.689298] Code: 24 04 89 7c 24 08 80 b8 b6 00 00 00 00 74 14 8b 1c 24 8b 74 24 04 8b 7c 24 08 89 ec 5d c3 90 8d 74 26 00 8b 18 8b 43 04 8d 73 38 <8b> 78 1c 8d 82 bc 00 00 00 e8 fa 13 77 e2 89 f0 e8 33 70 87 e2 
[  593.691175] EIP: [<dea40d28>] serial_do_free+0x38/0x80 [usbserial] SS:ESP 0068:da050e18
[  593.691473] CR2: 0000000000700128
[  593.691600] ---[ end trace bf5aabaeba706ceb ]---


Objdump (objdump -l -D usbserial.ko) result for serial_do_free:

00000cf0 <serial_do_free>:
serial_do_free():
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:322
     cf0:       55                      push   %ebp
     cf1:       89 c2                   mov    %eax,%edx
     cf3:       89 e5                   mov    %esp,%ebp
     cf5:       83 ec 0c                sub    $0xc,%esp
     cf8:       89 1c 24                mov    %ebx,(%esp)
     cfb:       89 74 24 04             mov    %esi,0x4(%esp)
     cff:       89 7c 24 08             mov    %edi,0x8(%esp)
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:328
     d03:       80 b8 b6 00 00 00 00    cmpb   $0x0,0xb6(%eax)
     d0a:       74 14                   je     d20 <serial_do_free+0x30>
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:342
     d0c:       8b 1c 24                mov    (%esp),%ebx
     d0f:       8b 74 24 04             mov    0x4(%esp),%esi
     d13:       8b 7c 24 08             mov    0x8(%esp),%edi
     d17:       89 ec                   mov    %ebp,%esp
     d19:       5d                      pop    %ebp
     d1a:       c3                      ret    
     d1b:       90                      nop    
     d1c:       8d 74 26 00             lea    0x0(%esi),%esi
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:331
     d20:       8b 18                   mov    (%eax),%ebx
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:332
     d22:       8b 43 04                mov    0x4(%ebx),%eax
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:335
     d25:       8d 73 38                lea    0x38(%ebx),%esi
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:332
     d28:       8b 78 1c                mov    0x1c(%eax),%edi
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:333
     d2b:       8d 82 bc 00 00 00       lea    0xbc(%edx),%eax
     d31:       e8 fc ff ff ff          call   d32 <serial_do_free+0x42>
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:335
     d36:       89 f0                   mov    %esi,%eax
     d38:       e8 fc ff ff ff          call   d39 <serial_do_free+0x49>
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:336
     d3d:       f6 43 0c 01             testb  $0x1,0xc(%ebx)
     d41:       74 1d                   je     d60 <serial_do_free+0x70>
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:338
     d43:       89 f0                   mov    %esi,%eax
     d45:       e8 fc ff ff ff          call   d46 <serial_do_free+0x56>
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:339
     d4a:       89 d8                   mov    %ebx,%eax
     d4c:       e8 fc ff ff ff          call   d4d <serial_do_free+0x5d>
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:341
     d51:       89 f8                   mov    %edi,%eax
     d53:       e8 fc ff ff ff          call   d54 <serial_do_free+0x64>
     d58:       eb b2                   jmp    d0c <serial_do_free+0x1c>
     d5a:       8d b6 00 00 00 00       lea    0x0(%esi),%esi
/usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:337
     d60:       8b 43 08                mov    0x8(%ebx),%eax
     d63:       e8 fc ff ff ff          call   d64 <serial_do_free+0x74>
     d68:       eb d9                   jmp    d43 <serial_do_free+0x53>
     d6a:       8d b6 00 00 00 00       lea    0x0(%esi),%esi


>From what I understand it's serial->type which points to 0x00700128,
which is inside of some freed memory.

     d22:       8b 43 04                mov    0x4(%ebx),%eax
        copy & serial (EBX)->type to EAX

     d28:       8b 78 1c                mov    0x1c(%eax),%edi
        copy type (EAX)->driver.owner to EDI

Am I reading this disassembled code correctly?

Verifying by adding a few printk()'s inside serial_do_free() confirms my
understanding of the objdump and also tells me that after unplug
serial_do_free() is called twice (with different addresses for port->serial->type)!
The first one (right after unplug) survives, the second one (when exiting
minicom) crashes.

Extract from the logs with my printk()'s
[  266.290632] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  266.290938] ftdi_sio 2-2:1.1: device disconnected
[  266.292378] tty_port_close_start: count = -1
[  266.292535] serial_do_free(port @da0d9000)
[  266.292692]   serial @da3e9840
[  266.292791]   type   @deb45660
/* exit minicom */
[  290.728196] serial_do_free(port @da0d9000)
[  290.728341]   serial @da0d9200
[  290.728461]   type   @3a6e6967
[  290.728591] BUG: unable to handle kernel paging request at 3a6e6983
[  290.728823] IP: [<deb02d5d>] serial_do_free+0x6d/0xd0 [usbserial]
[  290.729059] *pde = 00000000 
[  290.729182] Oops: 0000 [#1] 
[  290.729303] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  290.729548] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd snd_timer nsc_ircc usbcore pcspkr irda snd snd_page_alloc i2c_i801 crc_ccitt
[  290.730912] 
[  290.730987] Pid: 2206, comm: minicom Tainted: G   M       (2.6.31-rc6 #1) TravelMate 660
[  290.731242] EIP: 0060:[<deb02d5d>] EFLAGS: 00010282 CPU: 0
[  290.731441] EIP is at serial_do_free+0x6d/0xd0 [usbserial]
[  290.731615] EAX: 3a6e6967 EBX: da0d9000 ECX: ffffffff EDX: c13c6584
[  290.731829] ESI: da0d9200 EDI: 00000000 EBP: d8dc9e24 ESP: d8dc9e10
[  290.732027]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[  290.732218] Process minicom (pid: 2206, ti=d8dc9000 task=dd8e5090 task.ti=d8dc9000)


Printk's were added:

	if (port->console)
		return;
	/* here */
	serial = serial->port;
	owner = serial->type->driver.owner /* crash here */

Is it useful to check calls to serial_do_free() for my pl2303
usb2serial converter? (e.g. to compare behavior from both of them)

Thanks,
Bruno

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-19 17:22                   ` Bruno Prémont
@ 2009-08-19 18:20                     ` Alan Stern
  2009-08-19 20:15                       ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-19 18:20 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Greg KH, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Wed, 19 Aug 2009, Bruno [UTF-8] Prémont wrote:

> I did try to understand what happens exactly, using backtrace from
> kernel compiled with debug info and running objdump on usbserial.ko.

> Verifying by adding a few printk()'s inside serial_do_free() confirms my
> understanding of the objdump and also tells me that after unplug
> serial_do_free() is called twice (with different addresses for port->serial->type)!

In fact, with different values for port->serial.  Probably because port 
was deallocated before the second call occurred.

> The first one (right after unplug) survives, the second one (when exiting
> minicom) crashes.
> 
> Extract from the logs with my printk()'s
> [  266.290632] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
> [  266.290938] ftdi_sio 2-2:1.1: device disconnected
> [  266.292378] tty_port_close_start: count = -1
> [  266.292535] serial_do_free(port @da0d9000)
> [  266.292692]   serial @da3e9840
> [  266.292791]   type   @deb45660
> /* exit minicom */
> [  290.728196] serial_do_free(port @da0d9000)
> [  290.728341]   serial @da0d9200
> [  290.728461]   type   @3a6e6967
> [  290.728591] BUG: unable to handle kernel paging request at 3a6e6983
> [  290.728823] IP: [<deb02d5d>] serial_do_free+0x6d/0xd0 [usbserial]

> Printk's were added:
> 
> 	if (port->console)
> 		return;
> 	/* here */
> 	serial = serial->port;
> 	owner = serial->type->driver.owner /* crash here */
> 
> Is it useful to check calls to serial_do_free() for my pl2303
> usb2serial converter? (e.g. to compare behavior from both of them)

You could try; it wouldn't hurt.  More useful would be to add some 
debugging messages to destroy_serial().  There should not be any calls 
to serial_do_free() after destroy_serial() runs.

Also add some messages to the places that call usb_serial_put() and
usb_serial_get_by_index().

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-19 18:20                     ` Alan Stern
@ 2009-08-19 20:15                       ` Bruno Prémont
  2009-08-19 21:01                         ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-19 20:15 UTC (permalink / raw)
  To: Alan Stern
  Cc: Greg KH, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Wed, 19 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> On Wed, 19 Aug 2009, Bruno Prémont wrote:
> > I did try to understand what happens exactly, using backtrace from
> > kernel compiled with debug info and running objdump on usbserial.ko.
> 
> > Verifying by adding a few printk()'s inside serial_do_free()
> > confirms my understanding of the objdump and also tells me that
> > after unplug serial_do_free() is called twice (with different
> > addresses for port->serial->type)!
> 
> In fact, with different values for port->serial.  Probably because
> port was deallocated before the second call occurred.
> 
> > The first one (right after unplug) survives, the second one (when
> > exiting minicom) crashes.
> > 
> > Extract from the logs with my printk()'s
> > [  266.290632] ftdi_sio ttyUSB0: FTDI USB Serial Device converter
> > now disconnected from ttyUSB0 [  266.290938] ftdi_sio 2-2:1.1:
> > device disconnected [  266.292378] tty_port_close_start: count = -1
> > [  266.292535] serial_do_free(port @da0d9000)
> > [  266.292692]   serial @da3e9840
> > [  266.292791]   type   @deb45660
> > /* exit minicom */
> > [  290.728196] serial_do_free(port @da0d9000)
> > [  290.728341]   serial @da0d9200
> > [  290.728461]   type   @3a6e6967
> > [  290.728591] BUG: unable to handle kernel paging request at
> > 3a6e6983 [  290.728823] IP: [<deb02d5d>] serial_do_free+0x6d/0xd0
> > [usbserial]
> 
> > Printk's were added:
> > 
> > 	if (port->console)
> > 		return;
> > 	/* here */
> > 	serial = serial->port;
> > 	owner = serial->type->driver.owner /* crash here */
> > 
> > Is it useful to check calls to serial_do_free() for my pl2303
> > usb2serial converter? (e.g. to compare behavior from both of them)
> 
> You could try; it wouldn't hurt.
Huh that caused me a NULL port->serial on second call to serial_do_free()
with the pl2302... weird!

Just run minicom -o -c on server (with no getty listening on the other
side, a good old legacy uart of x86 box).

After more tries with pl2302 it seems possible to reproduce, but it is
harder. For now it's rather the second attempt that is eventually
successful as getting an Oops, though each time with NULL pointer
dereference instead of bad pointer for serial->type.

> More useful would be to add some debugging messages to
> destroy_serial(). There should not be any calls to serial_do_free()
> after destroy_serial() runs.
> 
> Also add some messages to the places that call usb_serial_put() and
> usb_serial_get_by_index().

I've added WARN_ON()s in usb_serial_put() and usb_serial_get_by_index()
in order to have information on who called us (easier than searching
around and adding lots of printk()s and output is also more verbose :)

Below, my changes to usb-serial.c and dmesg extracts for crash cases with
pl2302 and ftdi_sio.

You have guessed right, there are calls to serial_do_free() after
destroy_serial() in the crash cases. destroy_serial when disconnecting
device and final serial_do_free() when exiting minicom.



These are the changes I made to 2.6.31-rc6 to get debugging output:
diff --git a/drivers/usb/serial/usb-serial.c b/drivers/usb/serial/usb-serial.c
index 99188c9..7859e44 100644
--- a/drivers/usb/serial/usb-serial.c
+++ b/drivers/usb/serial/usb-serial.c
@@ -74,6 +74,8 @@ struct usb_serial *usb_serial_get_by_index(unsigned index)
 
 	mutex_lock(&table_lock);
 	serial = serial_table[index];
+	printk("usb_serial_get_by_index(index %d): @%p\n", index, serial);
+	WARN_ON(true);
 
 	if (serial)
 		kref_get(&serial->kref);
@@ -135,7 +137,9 @@ static void destroy_serial(struct kref *kref)
 	struct usb_serial_port *port;
 	int i;
 
+	printk("destroy_serial(kref @%p)\n", kref);
 	serial = to_usb_serial(kref);
+	printk("  serial @%p\n", serial);
 
 	dbg("%s - %s", __func__, serial->type->description);
 
@@ -171,6 +175,8 @@ static void destroy_serial(struct kref *kref)
 
 void usb_serial_put(struct usb_serial *serial)
 {
+	printk("usb_serial_put(serial @%p)\n", serial);
+	WARN_ON(true);
 	mutex_lock(&table_lock);
 	kref_put(&serial->kref, destroy_serial);
 	mutex_unlock(&table_lock);
@@ -328,6 +334,10 @@ static void serial_do_free(struct usb_serial_port *port)
 	if (port->console)
 		return;
 
+	printk(KERN_DEBUG "serial_do_free(port @%p)\n", port);
+	printk(KERN_DEBUG "  serial @%p\n", port ? port->serial : NULL);
+	printk(KERN_DEBUG "  type   @%p\n", port && port->serial ? port->serial->type : NULL);
+
 	serial = port->serial;
 	owner = serial->type->driver.owner;
 	put_device(&port->dev);



dmesg extract for pl2302 attempt
[   79.230040] usb 2-1: new full speed USB device using uhci_hcd and address 2
[   79.396191] usb 2-1: New USB device found, idVendor=067b, idProduct=2303
[   79.396201] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[   79.396209] usb 2-1: Product: USB-Serial Controller
[   79.396216] usb 2-1: Manufacturer: Prolific Technology Inc.
[   79.396444] usb 2-1: configuration #1 chosen from 1 choice
[   79.532613] usbcore: registered new interface driver usbserial
[   79.532617] usbserial: USB Serial Driver core
[   79.559641] USB Serial support registered for pl2303
[   79.559694] pl2303 2-1:1.0: pl2303 converter detected
[   79.571376] usb 2-1: pl2303 converter now attached to ttyUSB0
[   79.571419] usbcore: registered new interface driver pl2303
[   79.571425] pl2303: Prolific PL2303 USB to serial adaptor driver
[  100.366955] usb_serial_get_by_index(index 0): @d9cc29c0
[  100.367151] ------------[ cut here ]------------
[  100.367345] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  100.367696] Hardware name: TravelMate 660
[  100.367843] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  100.369196] Pid: 2160, comm: minicom Tainted: G   M       2.6.31-rc6 #1
[  100.369434] Call Trace:
[  100.369529]  [<c12b7052>] ? printk+0x18/0x1e
[  100.369694]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  100.369917]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  100.370143]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  100.370363]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  100.370554]  [<dea49182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  100.370774]  [<dea4936d>] serial_open+0x2d/0x250 [usbserial]
[  100.370975]  [<c115f7b9>] ? tty_init_dev+0x89/0x160
[  100.371135]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  100.371299]  [<c1077566>] chrdev_open+0x96/0x140
[  100.371454]  [<c10732ff>] __dentry_open+0x9f/0x250
[  100.371628]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  100.371793]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  100.371964]  [<c107f889>] do_filp_open+0x269/0x890
[  100.372121]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  100.372298]  [<c10730c7>] do_sys_open+0x57/0x140
[  100.372451]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  100.372632]  [<c1073219>] sys_open+0x29/0x40
[  100.372774]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  100.372951] ---[ end trace d126221248e369ae ]---
[  149.040186] usb 2-1: USB disconnect, address 2
[  149.040856] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
[  149.041116] usb_serial_put(serial @d9cc29c0)
[  149.041254] ------------[ cut here ]------------
[  149.041438] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  149.041778] Hardware name: TravelMate 660
[  149.041922] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  149.043273] Pid: 978, comm: khubd Tainted: G   M    W  2.6.31-rc6 #1
[  149.043489] Call Trace:
[  149.043583]  [<c12b7052>] ? printk+0x18/0x1e
[  149.043746]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  149.043946]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  149.044141]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  149.044335]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  149.044525]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  149.044720]  [<dea48f81>] usb_serial_disconnect+0xf1/0x160 [usbserial]
[  149.044981]  [<deb54447>] ? usb_disable_interface+0x37/0x50 [usbcore]
[  149.045214]  [<deb57221>] usb_unbind_interface+0xf1/0x130 [usbcore]
[  149.045437]  [<c11b5441>] __device_release_driver+0x51/0xa0
[  149.045618]  [<c11b5540>] device_release_driver+0x20/0x40
[  149.045809]  [<c11b4aad>] bus_remove_device+0x7d/0xb0
[  149.045974]  [<c11b2ef2>] device_del+0x102/0x190
[  149.046167]  [<deb543a7>] usb_disable_device+0x87/0xf0 [usbcore]
[  149.046384]  [<deb4f8a6>] usb_disconnect+0x96/0xf0 [usbcore]
[  149.046608]  [<deb50989>] hub_thread+0x829/0x1210 [usbcore]
[  149.046796]  [<c10357a0>] ? autoremove_wake_function+0x0/0x50
[  149.047022]  [<deb50160>] ? hub_thread+0x0/0x1210 [usbcore]
[  149.047203]  [<c10353cc>] kthread+0x7c/0x90
[  149.047358]  [<c1035350>] ? kthread+0x0/0x90
[  149.047500]  [<c1003673>] kernel_thread_helper+0x7/0x14
[  149.047684] ---[ end trace d126221248e369af ]---
[  149.047833] pl2303 2-1:1.0: device disconnected
[  184.321029] serial_do_free(port @d9c61a00)
[  184.321175]   serial @d9cc29c0
[  184.321297]   type   @de77dc20
[  184.321398] usb_serial_put(serial @d9cc29c0)
[  184.321550] ------------[ cut here ]------------
[  184.321715] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  184.322074] Hardware name: TravelMate 660
[  184.322202] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  184.323568] Pid: 2160, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  184.323775] Call Trace:
[  184.323883]  [<c12b7052>] ? printk+0x18/0x1e
[  184.324032]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  184.324246]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  184.324426]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  184.324636]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  184.324810]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  184.325022]  [<dea48db9>] serial_do_free+0x99/0xd0 [usbserial]
[  184.325217]  [<dea48e57>] serial_close+0x67/0xa0 [usbserial]
[  184.325417]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  184.325569]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  184.325756]  [<c1056d72>] ? put_page+0x42/0x120
[  184.325908]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  184.326091]  [<c115f64a>] tty_release+0xa/0x10
[  184.326237]  [<c1075f1c>] __fput+0xdc/0x1d0
[  184.326391]  [<c107602f>] fput+0x1f/0x30
[  184.326523]  [<c1072f8e>] filp_close+0x3e/0x70
[  184.326687]  [<c1024fa2>] put_files_struct+0xa2/0xc0
[  184.326849]  [<c1024fdc>] exit_files+0x1c/0x20
[  184.327011]  [<c1026339>] do_exit+0xb9/0x630
[  184.327154]  [<c103acd8>] ? __put_cred+0x18/0x20
[  184.327322]  [<c10268dd>] do_group_exit+0x2d/0x80
[  184.327476]  [<c1026943>] sys_exit_group+0x13/0x20
[  184.327650]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  184.327810] ---[ end trace d126221248e369b0 ]---
[  184.327974] destroy_serial(kref @d9cc29f4)
[  184.328105]   serial @d9cc29c0
[  300.000233] Machine check events logged
[  417.320036] usb 2-1: new full speed USB device using uhci_hcd and address 3
[  417.486198] usb 2-1: New USB device found, idVendor=067b, idProduct=2303
[  417.486418] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  417.486663] usb 2-1: Product: USB-Serial Controller
[  417.486820] usb 2-1: Manufacturer: Prolific Technology Inc.
[  417.487238] usb 2-1: configuration #1 chosen from 1 choice
[  417.490544] pl2303 2-1:1.0: pl2303 converter detected
[  417.502366] usb 2-1: pl2303 converter now attached to ttyUSB0
[  419.476126] usb_serial_get_by_index(index 0): @d9cc2720
[  419.476320] ------------[ cut here ]------------
[  419.476518] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  419.476870] Hardware name: TravelMate 660
[  419.477016] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  419.478371] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  419.478609] Call Trace:
[  419.478704]  [<c12b7052>] ? printk+0x18/0x1e
[  419.478869]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  419.479092]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  419.487714]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  419.496407]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  419.505172]  [<dea49182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  419.514032]  [<dea4936d>] serial_open+0x2d/0x250 [usbserial]
[  419.522887]  [<c115f7b9>] ? tty_init_dev+0x89/0x160
[  419.531577]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  419.540063]  [<c1077566>] chrdev_open+0x96/0x140
[  419.548236]  [<c10732ff>] __dentry_open+0x9f/0x250
[  419.556144]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  419.563852]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  419.571517]  [<c107f889>] do_filp_open+0x269/0x890
[  419.579145]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  419.586769]  [<c10730c7>] do_sys_open+0x57/0x140
[  419.594351]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  419.601918]  [<c1073219>] sys_open+0x29/0x40
[  419.609406]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  419.616902] ---[ end trace d126221248e369b1 ]---
[  434.000189] usb 2-1: USB disconnect, address 3
[  434.001726] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
[  434.001986] usb_serial_put(serial @d9cc2720)
[  434.002126] ------------[ cut here ]------------
[  434.002310] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  434.002650] Hardware name: TravelMate 660
[  434.002795] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  434.004145] Pid: 978, comm: khubd Tainted: G   M    W  2.6.31-rc6 #1
[  434.004361] Call Trace:
[  434.004455]  [<c12b7052>] ? printk+0x18/0x1e
[  434.004620]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.004818]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  434.005014]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.005208]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  434.005398]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  434.005594]  [<dea48f81>] usb_serial_disconnect+0xf1/0x160 [usbserial]
[  434.005857]  [<deb54447>] ? usb_disable_interface+0x37/0x50 [usbcore]
[  434.006091]  [<deb57221>] usb_unbind_interface+0xf1/0x130 [usbcore]
[  434.006314]  [<c11b5441>] __device_release_driver+0x51/0xa0
[  434.006495]  [<c11b5540>] device_release_driver+0x20/0x40
[  434.006686]  [<c11b4aad>] bus_remove_device+0x7d/0xb0
[  434.006850]  [<c11b2ef2>] device_del+0x102/0x190
[  434.007043]  [<deb543a7>] usb_disable_device+0x87/0xf0 [usbcore]
[  434.007261]  [<deb4f8a6>] usb_disconnect+0x96/0xf0 [usbcore]
[  434.007486]  [<deb50989>] hub_thread+0x829/0x1210 [usbcore]
[  434.007673]  [<c10357a0>] ? autoremove_wake_function+0x0/0x50
[  434.007901]  [<deb50160>] ? hub_thread+0x0/0x1210 [usbcore]
[  434.008082]  [<c10353cc>] kthread+0x7c/0x90
[  434.008236]  [<c1035350>] ? kthread+0x0/0x90
[  434.008379]  [<c1003673>] kernel_thread_helper+0x7/0x14
[  434.008562] ---[ end trace d126221248e369b2 ]---
[  434.008710] pl2303 2-1:1.0: device disconnected
[  434.009183] usb_serial_get_by_index(index 0): @d9cc2720
[  434.009354] ------------[ cut here ]------------
[  434.009532] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  434.009885] Hardware name: TravelMate 660
[  434.010054] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  434.011402] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  434.011626] Call Trace:
[  434.011714]  [<c12b7052>] ? printk+0x18/0x1e
[  434.011877]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  434.012097]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  434.012293]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  434.012511]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  434.012701]  [<dea49182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  434.012920]  [<dea4936d>] serial_open+0x2d/0x250 [usbserial]
[  434.013123]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  434.013292]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  434.013456]  [<c1077566>] chrdev_open+0x96/0x140
[  434.013611]  [<c10732ff>] __dentry_open+0x9f/0x250
[  434.013786]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  434.013950]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  434.014120]  [<c107f889>] do_filp_open+0x269/0x890
[  434.014278]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  434.023849]  [<c10730c7>] do_sys_open+0x57/0x140
[  434.033742]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  434.043683]  [<c1073219>] sys_open+0x29/0x40
[  434.053671]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  434.063679] ---[ end trace d126221248e369b3 ]---
[  434.079109] usb_serial_put(serial @d9cc2720)
[  434.083537] ------------[ cut here ]------------
[  434.087641] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  434.091916] Hardware name: TravelMate 660
[  434.096132] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  434.105454] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  434.109980] Call Trace:
[  434.114426]  [<c12b7052>] ? printk+0x18/0x1e
[  434.118801]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.123133]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  434.127306]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.131466]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  434.135581]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  434.139755]  [<dea493b0>] serial_open+0x70/0x250 [usbserial]
[  434.143923]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  434.148035]  [<c1077566>] chrdev_open+0x96/0x140
[  434.152172]  [<c10732ff>] __dentry_open+0x9f/0x250
[  434.156257]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  434.160367]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  434.164429]  [<c107f889>] do_filp_open+0x269/0x890
[  434.168489]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  434.172551]  [<c10730c7>] do_sys_open+0x57/0x140
[  434.176561]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  434.180600]  [<c1073219>] sys_open+0x29/0x40
[  434.184596]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  434.188611] ---[ end trace d126221248e369b4 ]---
[  434.193345] tty_port_close_start: count = -1
[  434.290041] serial_do_free(port @d8df5c00)
[  434.299763]   serial @d9cc2720
[  434.309450]   type   @de77dc20
[  434.319321] usb_serial_put(serial @d9cc2720)
[  434.323540] ------------[ cut here ]------------
[  434.327490] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  434.331601] Hardware name: TravelMate 660
[  434.335662] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  434.344746] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  434.349160] Call Trace:
[  434.353463]  [<c12b7052>] ? printk+0x18/0x1e
[  434.357707]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.361868]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  434.365907]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.369882]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  434.373881]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  434.377868]  [<dea48db9>] serial_do_free+0x99/0xd0 [usbserial]
[  434.381857]  [<dea48e57>] serial_close+0x67/0xa0 [usbserial]
[  434.385792]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  434.389716]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  434.393638]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  434.397546]  [<c10207e3>] ? __cond_resched+0x23/0x40
[  434.401443]  [<c12b7d7e>] ? mutex_lock+0xe/0x20
[  434.405321]  [<dea48d0b>] ? usb_serial_put+0x4b/0x60 [usbserial]
[  434.409216]  [<dea493b0>] ? serial_open+0x70/0x250 [usbserial]
[  434.413153]  [<c115fced>] tty_open+0x45d/0x4b0
[  434.417051]  [<c1077566>] chrdev_open+0x96/0x140
[  434.420985]  [<c10732ff>] __dentry_open+0x9f/0x250
[  434.424892]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  434.428818]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  434.432630]  [<c107f889>] do_filp_open+0x269/0x890
[  434.436315]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  434.439985]  [<c10730c7>] do_sys_open+0x57/0x140
[  434.443676]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  434.447346]  [<c1073219>] sys_open+0x29/0x40
[  434.451022]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  434.454672] ---[ end trace d126221248e369b5 ]---
[  434.459076] destroy_serial(kref @d9cc2754)
[  434.462686]   serial @d9cc2720
[  454.363600] serial_do_free(port @d8df5c00)
[  454.363745]   serial @d8df5a00
[  454.363868]   type   @(null)
[  454.363992] BUG: unable to handle kernel NULL pointer dereference at 0000001c
[  454.364252] IP: [<dea48d8d>] serial_do_free+0x6d/0xd0 [usbserial]
[  454.364487] *pde = 00000000 
[  454.364609] Oops: 0000 [#1] 
[  454.364731] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  454.364974] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
[  454.366315] 
[  454.366391] Pid: 2186, comm: minicom Tainted: G   M    W  (2.6.31-rc6 #1) TravelMate 660
[  454.366644] EIP: 0060:[<dea48d8d>] EFLAGS: 00010282 CPU: 0
[  454.366844] EIP is at serial_do_free+0x6d/0xd0 [usbserial]
[  454.367018] EAX: 00000000 EBX: d8df5c00 ECX: ffffffff EDX: c13c6584
[  454.367245] ESI: d8df5a00 EDI: 00000000 EBP: d8cc3e24 ESP: d8cc3e10
[  454.367444]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[  454.367633] Process minicom (pid: 2186, ti=d8cc3000 task=dd8e1dd0 task.ti=d8cc3000)
[  454.367870] Stack:
[  454.367954]  dea4cc4e 00000000 d8df5c00 dd0d8c00 00000000 d8cc3e4c dea48e57 00000000
[  454.368329] <0> d8cc3e4c c115d1a5 dd0d8ca0 dd8d1180 dd0d8c00 00000000 00000000 d8cc3edc
[  454.368749] <0> c115f2e0 40000000 d8cc3e94 00000082 dd8d1180 00000000 00000000 00000000
[  454.369178] Call Trace:
[  454.369290]  [<dea48e57>] ? serial_close+0x67/0xa0 [usbserial]
[  454.369483]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  454.369652]  [<c115f2e0>] ? tty_release_dev+0x130/0x490
[  454.369828]  [<c1056d72>] ? put_page+0x42/0x120
[  454.369993]  [<c105435a>] ? free_hot_page+0xa/0x10
[  454.370195]  [<c105438f>] ? __free_pages+0x2f/0x40
[  454.370356]  [<c107042e>] ? __free_slab+0xae/0x160
[  454.370530]  [<c115f64a>] ? tty_release+0xa/0x10
[  454.370681]  [<c1075f1c>] ? __fput+0xdc/0x1d0
[  454.370840]  [<c107602f>] ? fput+0x1f/0x30
[  454.370976]  [<c1072f8e>] ? filp_close+0x3e/0x70
[  454.371148]  [<c1024fa2>] ? put_files_struct+0xa2/0xc0
[  454.371315]  [<c1024fdc>] ? exit_files+0x1c/0x20
[  454.371483]  [<c1026339>] ? do_exit+0xb9/0x630
[  454.371631]  [<c103acd8>] ? __put_cred+0x18/0x20
[  454.371799]  [<c10268dd>] ? do_group_exit+0x2d/0x80
[  454.371959]  [<c1026943>] ? sys_exit_group+0x13/0x20
[  454.372137]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  454.372300] Code: a4 de 89 44 24 04 e8 cd e2 86 e2 8b 13 31 c0 85 d2 74 03 8b 42 04 89 44 24 04 c7 04 24 4e cc a4 de e8 b2 e2 86 e2 8b 33 8b 46 04 <8b> 78 1c 8d 83 bc 00 00 00 e8 95 93 76 e2 8d 5e 38 89 d8 e8 cb 
[  454.374157] EIP: [<dea48d8d>] serial_do_free+0x6d/0xd0 [usbserial] SS:ESP 0068:d8cc3e10
[  454.374470] CR2: 000000000000001c
[  454.374580] ---[ end trace d126221248e369b6 ]---
[  454.374742] Fixing recursive fault but reboot is needed!

First unplug attempt with running minicom survived, the second attempt
crashed.



dmesg extract for ftdi_sio attempt:
[   97.650041] usb 1-2: new full speed USB device using uhci_hcd and address 2
[   97.868191] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[   97.868410] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   97.868655] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[   97.868831] usb 1-2: Manufacturer: FTDI
[   97.868972] usb 1-2: SerialNumber: FTS55QK6
[   97.869346] usb 1-2: configuration #1 chosen from 1 choice
[   98.005741] usbcore: registered new interface driver usbserial
[   98.005961] usbserial: USB Serial Driver core
[   98.105309] USB Serial support registered for FTDI USB Serial Device
[   98.105782] usb 1-2: Ignoring serial port reserved for JTAG
[   98.106078] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[   98.106359] usb 1-2: Detected FT2232C
[   98.106482] usb 1-2: Number of endpoints 2
[   98.106634] usb 1-2: Endpoint 1 MaxPacketSize 64
[   98.106783] usb 1-2: Endpoint 2 MaxPacketSize 64
[   98.106947] usb 1-2: Setting MaxPacketSize 64
[   98.108347] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[   98.108641] usbcore: registered new interface driver ftdi_sio
[   98.108824] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  109.201971] usb_serial_get_by_index(index 0): @d8c60c00
[  109.211271] ------------[ cut here ]------------
[  109.220604] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  109.230195] Hardware name: TravelMate 660
[  109.239718] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus ehci_hcd uhci_hcd nsc_ircc snd_pcm usbcore irda snd_timer pcspkr snd i2c_i801 snd_page_alloc crc_ccitt
[  109.260505] Pid: 2163, comm: minicom Tainted: G   M       2.6.31-rc6 #1
[  109.270831] Call Trace:
[  109.281027]  [<c12b7052>] ? printk+0x18/0x1e
[  109.291242]  [<dea5d182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  109.301505]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  109.311732]  [<dea5d182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  109.322008]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  109.332244]  [<dea5d182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  109.342515]  [<dea5d36d>] serial_open+0x2d/0x250 [usbserial]
[  109.352742]  [<c115f7b9>] ? tty_init_dev+0x89/0x160
[  109.362895]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  109.372987]  [<c1077566>] chrdev_open+0x96/0x140
[  109.383039]  [<c10732ff>] __dentry_open+0x9f/0x250
[  109.393033]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  109.402978]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  109.412910]  [<c107f889>] do_filp_open+0x269/0x890
[  109.422804]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  109.432598]  [<c10730c7>] do_sys_open+0x57/0x140
[  109.442338]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  109.451867]  [<c1073219>] sys_open+0x29/0x40
[  109.461165]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  109.470466] ---[ end trace 3473a8310f07944c ]---
[  119.290059] usb 1-2: USB disconnect, address 2
[  119.290625] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  119.290932] usb_serial_put(serial @d8c60c00)
[  119.291070] ------------[ cut here ]------------
[  119.291255] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  119.291584] Hardware name: TravelMate 660
[  119.291728] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus ehci_hcd uhci_hcd nsc_ircc snd_pcm usbcore irda snd_timer pcspkr snd i2c_i801 snd_page_alloc crc_ccitt
[  119.293082] Pid: 989, comm: khubd Tainted: G   M    W  2.6.31-rc6 #1
[  119.293313] Call Trace:
[  119.293406]  [<c12b7052>] ? printk+0x18/0x1e
[  119.293570]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.293769]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  119.293964]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.294158]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  119.294348]  [<dea5cceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  119.294543]  [<dea5cf81>] usb_serial_disconnect+0xf1/0x160 [usbserial]
[  119.294819]  [<deb54447>] ? usb_disable_interface+0x37/0x50 [usbcore]
[  119.295053]  [<deb57221>] usb_unbind_interface+0xf1/0x130 [usbcore]
[  119.295276]  [<c11b5441>] __device_release_driver+0x51/0xa0
[  119.295457]  [<c11b5540>] device_release_driver+0x20/0x40
[  119.295649]  [<c11b4aad>] bus_remove_device+0x7d/0xb0
[  119.295813]  [<c11b2ef2>] device_del+0x102/0x190
[  119.296006]  [<deb543a7>] usb_disable_device+0x87/0xf0 [usbcore]
[  119.296223]  [<deb4f8a6>] usb_disconnect+0x96/0xf0 [usbcore]
[  119.296448]  [<deb50989>] hub_thread+0x829/0x1210 [usbcore]
[  119.296636]  [<c10357a0>] ? autoremove_wake_function+0x0/0x50
[  119.296863]  [<deb50160>] ? hub_thread+0x0/0x1210 [usbcore]
[  119.297044]  [<c10353cc>] kthread+0x7c/0x90
[  119.297198]  [<c1035350>] ? kthread+0x0/0x90
[  119.297341]  [<c1003673>] kernel_thread_helper+0x7/0x14
[  119.297524] ---[ end trace 3473a8310f07944d ]---
[  119.297673] ftdi_sio 1-2:1.1: device disconnected
[  119.299108] usb_serial_get_by_index(index 0): @d8c60c00
[  119.299287] ------------[ cut here ]------------
[  119.299473] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  119.299823] Hardware name: TravelMate 660
[  119.299968] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus ehci_hcd uhci_hcd nsc_ircc snd_pcm usbcore irda snd_timer pcspkr snd i2c_i801 snd_page_alloc crc_ccitt
[  119.301355] Pid: 2163, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  119.301562] Call Trace:
[  119.301667]  [<c12b7052>] ? printk+0x18/0x1e
[  119.301815]  [<dea5d182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  119.302051]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  119.302230]  [<dea5d182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  119.302464]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  119.302638]  [<dea5d182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  119.302873]  [<dea5d36d>] serial_open+0x2d/0x250 [usbserial]
[  119.303061]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  119.303247]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  119.303395]  [<c1077566>] chrdev_open+0x96/0x140
[  119.303566]  [<c10732ff>] __dentry_open+0x9f/0x250
[  119.313182]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  119.323123]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  119.333092]  [<c107f889>] do_filp_open+0x269/0x890
[  119.343121]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  119.353157]  [<c10730c7>] do_sys_open+0x57/0x140
[  119.363185]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  119.373242]  [<c1073219>] sys_open+0x29/0x40
[  119.383280]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  119.393324] ---[ end trace 3473a8310f07944e ]---
[  119.408837] usb_serial_put(serial @d8c60c00)
[  119.413343] ------------[ cut here ]------------
[  119.417526] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  119.421858] Hardware name: TravelMate 660
[  119.426125] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus ehci_hcd uhci_hcd nsc_ircc snd_pcm usbcore irda snd_timer pcspkr snd i2c_i801 snd_page_alloc crc_ccitt
[  119.435491] Pid: 2163, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  119.440021] Call Trace:
[  119.444452]  [<c12b7052>] ? printk+0x18/0x1e
[  119.448835]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.453171]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  119.457354]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.461511]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  119.465632]  [<dea5cceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  119.469788]  [<dea5d3b0>] serial_open+0x70/0x250 [usbserial]
[  119.473949]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  119.478075]  [<c1077566>] chrdev_open+0x96/0x140
[  119.482212]  [<c10732ff>] __dentry_open+0x9f/0x250
[  119.486300]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  119.490406]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  119.494476]  [<c107f889>] do_filp_open+0x269/0x890
[  119.498540]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  119.502596]  [<c10730c7>] do_sys_open+0x57/0x140
[  119.506622]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  119.510654]  [<c1073219>] sys_open+0x29/0x40
[  119.514676]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  119.518689] ---[ end trace 3473a8310f07944f ]---
[  119.523383] tty_port_close_start: count = -1
[  119.527396] serial_do_free(port @da025e00)
[  119.531404]   serial @d8c60c00
[  119.535353]   type   @deb0e660
[  119.539434] usb_serial_put(serial @d8c60c00)
[  119.543430] ------------[ cut here ]------------
[  119.547389] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  119.551513] Hardware name: TravelMate 660
[  119.555583] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus ehci_hcd uhci_hcd nsc_ircc snd_pcm usbcore irda snd_timer pcspkr snd i2c_i801 snd_page_alloc crc_ccitt
[  119.564707] Pid: 2163, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  119.569109] Call Trace:
[  119.573439]  [<c12b7052>] ? printk+0x18/0x1e
[  119.577675]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.581857]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  119.585894]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.589896]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  119.593885]  [<dea5cceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  119.597906]  [<dea5cdb9>] serial_do_free+0x99/0xd0 [usbserial]
[  119.601891]  [<dea5ce57>] serial_close+0x67/0xa0 [usbserial]
[  119.605852]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  119.609774]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  119.613714]  [<dea5cceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  119.617621]  [<c10207e3>] ? __cond_resched+0x23/0x40
[  119.621535]  [<c12b7d7e>] ? mutex_lock+0xe/0x20
[  119.625407]  [<dea5cd0b>] ? usb_serial_put+0x4b/0x60 [usbserial]
[  119.629318]  [<dea5d3b0>] ? serial_open+0x70/0x250 [usbserial]
[  119.633249]  [<c115fced>] tty_open+0x45d/0x4b0
[  119.637046]  [<c1077566>] chrdev_open+0x96/0x140
[  119.640727]  [<c10732ff>] __dentry_open+0x9f/0x250
[  119.644412]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  119.648080]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  119.651781]  [<c107f889>] do_filp_open+0x269/0x890
[  119.655451]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  119.659128]  [<c10730c7>] do_sys_open+0x57/0x140
[  119.662807]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  119.666484]  [<c1073219>] sys_open+0x29/0x40
[  119.670149]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  119.673808] ---[ end trace 3473a8310f079450 ]---
[  119.678200] destroy_serial(kref @d8c60c34)
[  119.681814]   serial @d8c60c00
[  128.465874] serial_do_free(port @da025e00)
[  128.466022]   serial @da025400
[  128.466147]   type   @203a6e69
[  128.466277] BUG: unable to handle kernel paging request at 203a6e85
[  128.466510] IP: [<dea5cd8d>] serial_do_free+0x6d/0xd0 [usbserial]
[  128.466747] *pde = 00000000 
[  128.466870] Oops: 0000 [#1] 
[  128.466991] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  128.467236] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus ehci_hcd uhci_hcd nsc_ircc snd_pcm usbcore irda snd_timer pcspkr snd i2c_i801 snd_page_alloc crc_ccitt
[  128.468576] 
[  128.468651] Pid: 2163, comm: minicom Tainted: G   M    W  (2.6.31-rc6 #1) TravelMate 660
[  128.468905] EIP: 0060:[<dea5cd8d>] EFLAGS: 00010282 CPU: 0
[  128.469105] EIP is at serial_do_free+0x6d/0xd0 [usbserial]
[  128.469279] EAX: 203a6e69 EBX: da025e00 ECX: ffffffff EDX: c13c6584
[  128.469507] ESI: da025400 EDI: 00000000 EBP: db56de24 ESP: db56de10
[  128.469706]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[  128.469895] Process minicom (pid: 2163, ti=db56d000 task=dd9ac9f0 task.ti=db56d000)
[  128.470166] Stack:
[  128.470236]  dea60c4e 203a6e69 da025e00 db442c00 00000000 db56de4c dea5ce57 00000000
[  128.470612] <0> db56de4c c115d1a5 db442ca0 d9c84280 db442c00 00000000 00000000 db56dedc
[  128.471032] <0> c115f2e0 00000001 00000002 c17b1c00 d9c84280 00000000 00000000 c1817d80
[  128.471479] Call Trace:
[  128.471576]  [<dea5ce57>] ? serial_close+0x67/0xa0 [usbserial]
[  128.471784]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  128.471938]  [<c115f2e0>] ? tty_release_dev+0x130/0x490
[  128.472130]  [<c1056d72>] ? put_page+0x42/0x120
[  128.472282]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  128.472466]  [<c115f64a>] ? tty_release+0xa/0x10
[  128.472618]  [<c1075f1c>] ? __fput+0xdc/0x1d0
[  128.472777]  [<c107602f>] ? fput+0x1f/0x30
[  128.472914]  [<c1072f8e>] ? filp_close+0x3e/0x70
[  128.473086]  [<c1024fa2>] ? put_files_struct+0xa2/0xc0
[  128.473253]  [<c1024fdc>] ? exit_files+0x1c/0x20
[  128.473421]  [<c1026339>] ? do_exit+0xb9/0x630
[  128.473570]  [<c103acd8>] ? __put_cred+0x18/0x20
[  128.473738]  [<c10268dd>] ? do_group_exit+0x2d/0x80
[  128.473898]  [<c1026943>] ? sys_exit_group+0x13/0x20
[  128.474076]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  128.474240] Code: a6 de 89 44 24 04 e8 cd a2 85 e2 8b 13 31 c0 85 d2 74 03 8b 42 04 89 44 24 04 c7 04 24 4e 0c a6 de e8 b2 a2 85 e2 8b 33 8b 46 04 <8b> 78 1c 8d 83 bc 00 00 00 e8 95 53 75 e2 8d 5e 38 89 d8 e8 cb 
[  128.476094] EIP: [<dea5cd8d>] serial_do_free+0x6d/0xd0 [usbserial] SS:ESP 0068:db56de10
[  128.476408] CR2: 00000000203a6e85
[  128.476518] ---[ end trace 3473a8310f079451 ]---
[  128.476680] Fixing recursive fault but reboot is needed!

With ftdi it crashes on first attempt each time I try.

^ permalink raw reply related	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-19 20:15                       ` Bruno Prémont
@ 2009-08-19 21:01                         ` Alan Stern
  2009-08-19 21:50                           ` Alan Cox
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-19 21:01 UTC (permalink / raw)
  To: Bruno Prémont, Alan Cox
  Cc: Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Wed, 19 Aug 2009, Bruno [UTF-8] Prémont wrote:

> I've added WARN_ON()s in usb_serial_put() and usb_serial_get_by_index()
> in order to have information on who called us (easier than searching
> around and adding lots of printk()s and output is also more verbose :)
> 
> Below, my changes to usb-serial.c and dmesg extracts for crash cases with
> pl2302 and ftdi_sio.
> 
> You have guessed right, there are calls to serial_do_free() after
> destroy_serial() in the crash cases. destroy_serial when disconnecting
> device and final serial_do_free() when exiting minicom.

Good work.  This shows clearly where the problem is.

> [  417.320036] usb 2-1: new full speed USB device using uhci_hcd and address 3
> [  417.486198] usb 2-1: New USB device found, idVendor=067b, idProduct=2303
> [  417.486418] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [  417.486663] usb 2-1: Product: USB-Serial Controller
> [  417.486820] usb 2-1: Manufacturer: Prolific Technology Inc.
> [  417.487238] usb 2-1: configuration #1 chosen from 1 choice
> [  417.490544] pl2303 2-1:1.0: pl2303 converter detected
> [  417.502366] usb 2-1: pl2303 converter now attached to ttyUSB0

The pl2303 was plugged in.

> [  419.476126] usb_serial_get_by_index(index 0): @d9cc2720
> [  419.476320] ------------[ cut here ]------------
> [  419.476518] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
> [  419.476870] Hardware name: TravelMate 660
> [  419.477016] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
> [  419.478371] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
> [  419.478609] Call Trace:
> [  419.478704]  [<c12b7052>] ? printk+0x18/0x1e
> [  419.478869]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
> [  419.479092]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
> [  419.487714]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
> [  419.496407]  [<c1023765>] warn_slowpath_null+0x15/0x20
> [  419.505172]  [<dea49182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
> [  419.514032]  [<dea4936d>] serial_open+0x2d/0x250 [usbserial]

Minicom opened the device file.

> [  434.000189] usb 2-1: USB disconnect, address 3
> [  434.001726] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
> [  434.001986] usb_serial_put(serial @d9cc2720)
> [  434.002126] ------------[ cut here ]------------
> [  434.002310] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
> [  434.002650] Hardware name: TravelMate 660
> [  434.002795] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
> [  434.004145] Pid: 978, comm: khubd Tainted: G   M    W  2.6.31-rc6 #1
> [  434.004361] Call Trace:
> [  434.004455]  [<c12b7052>] ? printk+0x18/0x1e
> [  434.004620]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.004818]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
> [  434.005014]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.005208]  [<c1023765>] warn_slowpath_null+0x15/0x20
> [  434.005398]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
> [  434.005594]  [<dea48f81>] usb_serial_disconnect+0xf1/0x160 [usbserial]
...
> [  434.008710] pl2303 2-1:1.0: device disconnected

The pl2303 was unplugged.

> [  434.009183] usb_serial_get_by_index(index 0): @d9cc2720
> [  434.009354] ------------[ cut here ]------------
> [  434.009532] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
> [  434.009885] Hardware name: TravelMate 660
> [  434.010054] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
> [  434.011402] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
> [  434.011626] Call Trace:
> [  434.011714]  [<c12b7052>] ? printk+0x18/0x1e
> [  434.011877]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
> [  434.012097]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
> [  434.012293]  [<dea49182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
> [  434.012511]  [<c1023765>] warn_slowpath_null+0x15/0x20
> [  434.012701]  [<dea49182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
> [  434.012920]  [<dea4936d>] serial_open+0x2d/0x250 [usbserial]
> [  434.013123]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
> [  434.013292]  [<c115fa4d>] tty_open+0x1bd/0x4b0

For some reason, minicom attempted to reopen the device file 
immediately.

> [  434.079109] usb_serial_put(serial @d9cc2720)
> [  434.083537] ------------[ cut here ]------------
> [  434.087641] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
> [  434.091916] Hardware name: TravelMate 660
> [  434.096132] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
> [  434.105454] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
> [  434.109980] Call Trace:
> [  434.114426]  [<c12b7052>] ? printk+0x18/0x1e
> [  434.118801]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.123133]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
> [  434.127306]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.131466]  [<c1023765>] warn_slowpath_null+0x15/0x20
> [  434.135581]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
> [  434.139755]  [<dea493b0>] serial_open+0x70/0x250 [usbserial]
> [  434.143923]  [<c115fa4d>] tty_open+0x1bd/0x4b0

The open failed, because the device had been unplugged.  serial_open()
would therefore return -ENODEV.

> [  434.193345] tty_port_close_start: count = -1
> [  434.290041] serial_do_free(port @d8df5c00)
> [  434.299763]   serial @d9cc2720
> [  434.309450]   type   @de77dc20
> [  434.319321] usb_serial_put(serial @d9cc2720)
> [  434.323540] ------------[ cut here ]------------
> [  434.327490] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
> [  434.331601] Hardware name: TravelMate 660
> [  434.335662] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
> [  434.344746] Pid: 2186, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
> [  434.349160] Call Trace:
> [  434.353463]  [<c12b7052>] ? printk+0x18/0x1e
> [  434.357707]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.361868]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
> [  434.365907]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.369882]  [<c1023765>] warn_slowpath_null+0x15/0x20
> [  434.373881]  [<dea48ceb>] usb_serial_put+0x2b/0x60 [usbserial]
> [  434.377868]  [<dea48db9>] serial_do_free+0x99/0xd0 [usbserial]
> [  434.381857]  [<dea48e57>] serial_close+0x67/0xa0 [usbserial]
> [  434.385792]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
> [  434.389716]  [<c115f2e0>] tty_release_dev+0x130/0x490
> [  434.393638]  [<dea48ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
> [  434.397546]  [<c10207e3>] ? __cond_resched+0x23/0x40
> [  434.401443]  [<c12b7d7e>] ? mutex_lock+0xe/0x20
> [  434.405321]  [<dea48d0b>] ? usb_serial_put+0x4b/0x60 [usbserial]
> [  434.409216]  [<dea493b0>] ? serial_open+0x70/0x250 [usbserial]
> [  434.413153]  [<c115fced>] tty_open+0x45d/0x4b0

This is the key.  When the open failed, tty_open() went on to call
tty_release_dev(), which in turn called serial_close().  In other
words, the TTY layer was trying to close a device reference which had
never successfully been opened!  This resulted in an unbalanced call
to usb_serial_put().

> [  434.459076] destroy_serial(kref @d9cc2754)
> [  434.462686]   serial @d9cc2720

The extra put caused the data structure to be released too soon.

> [  454.363600] serial_do_free(port @d8df5c00)
> [  454.363745]   serial @d8df5a00
> [  454.363868]   type   @(null)
> [  454.363992] BUG: unable to handle kernel NULL pointer dereference at 0000001c
> [  454.364252] IP: [<dea48d8d>] serial_do_free+0x6d/0xd0 [usbserial]
> [  454.364487] *pde = 00000000 
> [  454.364609] Oops: 0000 [#1] 
> [  454.364731] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
> [  454.364974] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 snd_ac97_codec ac97_bus uhci_hcd snd_pcm ehci_hcd nsc_ircc usbcore snd_timer irda snd pcspkr i2c_i801 snd_page_alloc crc_ccitt
> [  454.366315] 
> [  454.366391] Pid: 2186, comm: minicom Tainted: G   M    W  (2.6.31-rc6 #1) TravelMate 660
> [  454.366644] EIP: 0060:[<dea48d8d>] EFLAGS: 00010282 CPU: 0
> [  454.366844] EIP is at serial_do_free+0x6d/0xd0 [usbserial]
> [  454.367018] EAX: 00000000 EBX: d8df5c00 ECX: ffffffff EDX: c13c6584
> [  454.367245] ESI: d8df5a00 EDI: 00000000 EBP: d8cc3e24 ESP: d8cc3e10
> [  454.367444]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
> [  454.367633] Process minicom (pid: 2186, ti=d8cc3000 task=dd8e1dd0 task.ti=d8cc3000)
> [  454.367870] Stack:
> [  454.367954]  dea4cc4e 00000000 d8df5c00 dd0d8c00 00000000 d8cc3e4c dea48e57 00000000
> [  454.368329] <0> d8cc3e4c c115d1a5 dd0d8ca0 dd8d1180 dd0d8c00 00000000 00000000 d8cc3edc
> [  454.368749] <0> c115f2e0 40000000 d8cc3e94 00000082 dd8d1180 00000000 00000000 00000000
> [  454.369178] Call Trace:
> [  454.369290]  [<dea48e57>] ? serial_close+0x67/0xa0 [usbserial]
> [  454.369483]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
> [  454.369652]  [<c115f2e0>] ? tty_release_dev+0x130/0x490
> [  454.369828]  [<c1056d72>] ? put_page+0x42/0x120
> [  454.369993]  [<c105435a>] ? free_hot_page+0xa/0x10
> [  454.370195]  [<c105438f>] ? __free_pages+0x2f/0x40
> [  454.370356]  [<c107042e>] ? __free_slab+0xae/0x160
> [  454.370530]  [<c115f64a>] ? tty_release+0xa/0x10
> [  454.370681]  [<c1075f1c>] ? __fput+0xdc/0x1d0
> [  454.370840]  [<c107602f>] ? fput+0x1f/0x30
> [  454.370976]  [<c1072f8e>] ? filp_close+0x3e/0x70
> [  454.371148]  [<c1024fa2>] ? put_files_struct+0xa2/0xc0
> [  454.371315]  [<c1024fdc>] ? exit_files+0x1c/0x20
> [  454.371483]  [<c1026339>] ? do_exit+0xb9/0x630

And this is the actual close that occurred when minicom exited.  But
by then it was too late.

So Alan, what's the explanation?  An unsuccessful open method call
should not lead to a close method call.

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-19 21:01                         ` Alan Stern
@ 2009-08-19 21:50                           ` Alan Cox
  2009-08-19 22:44                             ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Cox @ 2009-08-19 21:50 UTC (permalink / raw)
  To: Alan Stern
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

> So Alan, what's the explanation?  An unsuccessful open method call
> should not lead to a close method call.

For tty it always has since back in 0.9x, and most drivers depend upon
this behaviour.

Alan


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-19 21:50                           ` Alan Cox
@ 2009-08-19 22:44                             ` Alan Stern
  2009-08-20 19:25                               ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-19 22:44 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

On Wed, 19 Aug 2009, Alan Cox wrote:

> > So Alan, what's the explanation?  An unsuccessful open method call
> > should not lead to a close method call.
> 
> For tty it always has since back in 0.9x, and most drivers depend upon
> this behaviour.

Curiouser and curiouser...

Okay Bruno, try out this patch and let's see if it helps.  It should 
fix the problem with the pl2303.  I'm not so sure about the FTDI device 
because that driver maintains its own reference count for its private 
data.

Alan Stern


Index: usb-2.6/drivers/usb/serial/usb-serial.c
===================================================================
--- usb-2.6.orig/drivers/usb/serial/usb-serial.c
+++ usb-2.6/drivers/usb/serial/usb-serial.c
@@ -209,8 +209,13 @@ static int serial_open (struct tty_struc
 	 * to be acquired while serial->disc_mutex is held.
 	 */
 	mutex_unlock(&serial->disc_mutex);
+
+	/* For reasons that have been lost in antiquity, the TTY layer calls
+	 * our close method even if the open call fails.  Hence we must not
+	 * drop the reference obtained by usb_serial_get_by_index().
+	 */
 	if (retval)
-		goto bailout_serial_put;
+		return retval;
 
 	if (mutex_lock_interruptible(&port->mutex)) {
 		retval = -ERESTARTSYS;
@@ -276,8 +281,6 @@ bailout_mutex_unlock:
 	mutex_unlock(&port->mutex);
 bailout_port_put:
 	put_device(&port->dev);
-bailout_serial_put:
-	usb_serial_put(serial);
 	return retval;
 }
 


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-19 22:44                             ` Alan Stern
@ 2009-08-20 19:25                               ` Bruno Prémont
  2009-08-20 21:20                                 ` Alan Stern
  2009-08-20 21:58                                 ` Alan Cox
  0 siblings, 2 replies; 42+ messages in thread
From: Bruno Prémont @ 2009-08-20 19:25 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Wed, 19 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> On Wed, 19 Aug 2009, Alan Cox wrote:
> 
> > > So Alan, what's the explanation?  An unsuccessful open method call
> > > should not lead to a close method call.
> > 
> > For tty it always has since back in 0.9x, and most drivers depend
> > upon this behaviour.
> 
> Curiouser and curiouser...
> 
> Okay Bruno, try out this patch and let's see if it helps.  It should 
> fix the problem with the pl2303.  I'm not so sure about the FTDI
> device because that driver maintains its own reference count for its
> private data.
> 
> Alan Stern

No, that one does not really help (well it avoids dereferencing a bad
pointer (NULL for pl2302 or invalid for ftdi) with serial_do_free() after
destroy_serial() but is does underflow module refcount (refcount ends
up at 2^32-1) and lets the kernel stall/panic a short time later without
any useful information at that moment (only very first line of trace
ever appears) [ftdi for the panic/freeze].

So I would say at best it's just a step towards the solution...
there are still unbalanced operations left (module refcount being the
visible one, then probably the already mentioned private book-keeping
of ftdi)!

Bruno

> Index: usb-2.6/drivers/usb/serial/usb-serial.c
> ===================================================================
> --- usb-2.6.orig/drivers/usb/serial/usb-serial.c
> +++ usb-2.6/drivers/usb/serial/usb-serial.c
> @@ -209,8 +209,13 @@ static int serial_open (struct tty_struc
>  	 * to be acquired while serial->disc_mutex is held.
>  	 */
>  	mutex_unlock(&serial->disc_mutex);
> +
> +	/* For reasons that have been lost in antiquity, the TTY
> layer calls
> +	 * our close method even if the open call fails.  Hence we
> must not
> +	 * drop the reference obtained by usb_serial_get_by_index().
> +	 */
>  	if (retval)
> -		goto bailout_serial_put;
> +		return retval;
>  
>  	if (mutex_lock_interruptible(&port->mutex)) {
>  		retval = -ERESTARTSYS;
> @@ -276,8 +281,6 @@ bailout_mutex_unlock:
>  	mutex_unlock(&port->mutex);
>  bailout_port_put:
>  	put_device(&port->dev);
> -bailout_serial_put:
> -	usb_serial_put(serial);
>  	return retval;
>  }
>  
> 

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-20 19:25                               ` Bruno Prémont
@ 2009-08-20 21:20                                 ` Alan Stern
  2009-08-21  9:25                                   ` Bruno Prémont
  2009-08-20 21:58                                 ` Alan Cox
  1 sibling, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-20 21:20 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Thu, 20 Aug 2009, Bruno [UTF-8] Prémont wrote:

> No, that one does not really help (well it avoids dereferencing a bad
> pointer (NULL for pl2302 or invalid for ftdi) with serial_do_free() after
> destroy_serial() but is does underflow module refcount (refcount ends
> up at 2^32-1) and lets the kernel stall/panic a short time later without
> any useful information at that moment (only very first line of trace
> ever appears) [ftdi for the panic/freeze].

More information, please.  Does the problem occur with the pl2303 or 
only with the ftdi?  Which module's refcount underflows?  What else can 
you provide?

I don't see the same sort of thing with my pl2303 device, but maybe
I'm using a different version of minicom.

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-20 19:25                               ` Bruno Prémont
  2009-08-20 21:20                                 ` Alan Stern
@ 2009-08-20 21:58                                 ` Alan Cox
  2009-08-21 14:02                                   ` Alan Stern
  1 sibling, 1 reply; 42+ messages in thread
From: Alan Cox @ 2009-08-20 21:58 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Stern, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

> > +	/* For reasons that have been lost in antiquity, the TTY
> > layer calls
> > +	 * our close method even if the open call fails.  Hence we
> > must not
> > +	 * drop the reference obtained by usb_serial_get_by_index().

Not lost in antiquity:

The logic is this


	open
	do some opening work
	block on carrier
						HANGUP
	open returns error

	cleanup still required

So the tty layer always went that way so that the awkward cases around an
opening failing with a hangup just go away. For the normal drivers which
basically do

open:
	tty layer open work
		open hardware and set ASYNCB_INITIALIZED
	block for carrier

close:
	if (!hung_up) {
		if initialized
			shutdown()
	}

the USB layer works really hard to be completely different (in part
because the old code simply didn't implement open semantics properly or
hangup correctly - hence things like mgetty fail on them).

The later patches I was working on were trying to get USB serial to the
point where the model was that drv->open/drv->close were the hardware
init/shutdown and did indeed get called in nice matching open/close pairs
and not re-entered or called unserialized.

Nice spot on the ASYNC v ASYNCB bug Alan btw

Alan (the other one)


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-20 21:20                                 ` Alan Stern
@ 2009-08-21  9:25                                   ` Bruno Prémont
  2009-08-21 15:43                                     ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-21  9:25 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Thu, 20 Aug 2009 17:20:35 Alan Stern <stern@rowland.harvard.edu> wrote:
> On Thu, 20 Aug 2009, Bruno [UTF-8] Prémont wrote:
> 
> > No, that one does not really help (well it avoids dereferencing a
> > bad pointer (NULL for pl2302 or invalid for ftdi) with
> > serial_do_free() after destroy_serial() but is does underflow
> > module refcount (refcount ends up at 2^32-1) and lets the kernel
> > stall/panic a short time later without any useful information at
> > that moment (only very first line of trace ever appears) [ftdi for
> > the panic/freeze].
> 
> More information, please.  Does the problem occur with the pl2303 or 
> only with the ftdi?  Which module's refcount underflows?  What else
> can you provide?

The module refcount was for both. It's the pl2302/ftdi-sio module's
refcount.

I don't remember for sure about the panic if it also affects
pl2302 or not.
At least one of the panics was when running dmesg after exiting minicom.

I will redo the tests this evening when I get home and report back with
more details.

> I don't see the same sort of thing with my pl2303 device, but maybe
> I'm using a different version of minicom.
> 
> Alan Stern

Bruno

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-20 21:58                                 ` Alan Cox
@ 2009-08-21 14:02                                   ` Alan Stern
  0 siblings, 0 replies; 42+ messages in thread
From: Alan Stern @ 2009-08-21 14:02 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

On Thu, 20 Aug 2009, Alan Cox wrote:

> So the tty layer always went that way so that the awkward cases around an
> opening failing with a hangup just go away. For the normal drivers which
> basically do
> 
> open:
> 	tty layer open work
> 		open hardware and set ASYNCB_INITIALIZED
> 	block for carrier
> 
> close:
> 	if (!hung_up) {
> 		if initialized
> 			shutdown()
> 	}
> 
> the USB layer works really hard to be completely different (in part
> because the old code simply didn't implement open semantics properly or
> hangup correctly - hence things like mgetty fail on them).
> 
> The later patches I was working on were trying to get USB serial to the
> point where the model was that drv->open/drv->close were the hardware
> init/shutdown and did indeed get called in nice matching open/close pairs
> and not re-entered or called unserialized.

That is indeed the best approach.  How much is still needed to make it 
work?

> Nice spot on the ASYNC v ASYNCB bug Alan btw

Hah!  Crashing with a big oops was a pretty strong hint that something
was wrong.  The tricky part was grovelling through the disassembly 
listing and figuring out why the offsets were so huge.  :-)

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21  9:25                                   ` Bruno Prémont
@ 2009-08-21 15:43                                     ` Alan Stern
  2009-08-21 15:48                                       ` Alan Cox
  2009-08-21 16:50                                       ` Bruno Prémont
  0 siblings, 2 replies; 42+ messages in thread
From: Alan Stern @ 2009-08-21 15:43 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Fri, 21 Aug 2009, Bruno [UTF-8] Prémont wrote:

> The module refcount was for both. It's the pl2302/ftdi-sio module's
> refcount.
> 
> I don't remember for sure about the panic if it also affects
> pl2302 or not.
> At least one of the panics was when running dmesg after exiting minicom.
> 
> I will redo the tests this evening when I get home and report back with
> more details.

Apparently the problem is in serial_do_free(); it doesn't know 
whether it's getting called for a successful open or an unsuccessful 
open, so it decrements the module count when it shouldn't.  The same is 
true for port->dev's refcount.

Alan, related to this problem is the fact that usb_serial_driver
doesn't include a "hangup" method.  I'm not sure that making
serial_hangup() call serial_do_down() is correct, but if it is then
shouldn't we call port->serial->type->open() afterwards?  Otherwise the
lower driver can't know that the port is still open.

Furthermore, shouldn't we check ASYNCB_INITIALIZED in serial_close()?

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 15:43                                     ` Alan Stern
@ 2009-08-21 15:48                                       ` Alan Cox
  2009-08-21 17:39                                         ` Alan Stern
  2009-08-21 16:50                                       ` Bruno Prémont
  1 sibling, 1 reply; 42+ messages in thread
From: Alan Cox @ 2009-08-21 15:48 UTC (permalink / raw)
  To: Alan Stern
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

> Alan, related to this problem is the fact that usb_serial_driver
> doesn't include a "hangup" method.  I'm not sure that making
> serial_hangup() call serial_do_down() is correct, but if it is then
> shouldn't we call port->serial->type->open() afterwards?  Otherwise the
> lower driver can't know that the port is still open.

After a hangup the port isn't open (at the physical level anyway). It may
be re-opened by another open() call later but the original user lost
access to it and shouldn't touch the h/w post hangup completion.

> Furthermore, shouldn't we check ASYNCB_INITIALIZED in serial_close()?

Possibly - I was in the middle of debugging the newest bits when Linus
annoyed me. Certainly there are issues in the current code if you get
a hangup while waiting for open to complete. I fixed that in the patches
I sent Greg but didn't finish debugging it.


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 15:43                                     ` Alan Stern
  2009-08-21 15:48                                       ` Alan Cox
@ 2009-08-21 16:50                                       ` Bruno Prémont
  1 sibling, 0 replies; 42+ messages in thread
From: Bruno Prémont @ 2009-08-21 16:50 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Fri, 21 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> On Fri, 21 Aug 2009, Bruno [UTF-8] Prémont wrote:
> 
> > The module refcount was for both. It's the pl2302/ftdi-sio module's
> > refcount.
> > 
> > I don't remember for sure about the panic if it also affects
> > pl2302 or not.
> > At least one of the panics was when running dmesg after exiting
> > minicom.
> > 
> > I will redo the tests this evening when I get home and report back
> > with more details.
> 
> Apparently the problem is in serial_do_free(); it doesn't know 
> whether it's getting called for a successful open or an unsuccessful 
> open, so it decrements the module count when it shouldn't.  The same
> is true for port->dev's refcount.

That makes sense, see below dmesg log extracts (from USB plug-in until
after exiting minicom), there are two calls to serial_do_free().

On USB disconnect module refcount is zero, on minicom exit it underflows.

> Alan, related to this problem is the fact that usb_serial_driver
> doesn't include a "hangup" method.  I'm not sure that making
> serial_hangup() call serial_do_down() is correct, but if it is then
> shouldn't we call port->serial->type->open() afterwards?  Otherwise
> the lower driver can't know that the port is still open.
> 
> Furthermore, shouldn't we check ASYNCB_INITIALIZED in serial_close()?
> 
> Alan Stern

This time I had no crash (neither with ftdi nor with pl2302), possibly
a matter of what memory areas were affected...

Bruno


dmesg + lsmod as at end of dmesg log. First for ftdi device, second for
pl2302 device:

[  389.940038] usb 1-2: new full speed USB device using uhci_hcd and address 2
[  390.158982] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[  390.159202] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  390.159447] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[  390.159622] usb 1-2: Manufacturer: FTDI
[  390.159763] usb 1-2: SerialNumber: FTS55QK6
[  390.160160] usb 1-2: configuration #1 chosen from 1 choice
[  390.243200] usbcore: registered new interface driver usbserial
[  390.243309] usbserial: USB Serial Driver core
[  390.274397] USB Serial support registered for FTDI USB Serial Device
[  390.274888] usb 1-2: Ignoring serial port reserved for JTAG
[  390.275185] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[  390.275467] usb 1-2: Detected FT2232C
[  390.275589] usb 1-2: Number of endpoints 2
[  390.275740] usb 1-2: Endpoint 1 MaxPacketSize 64
[  390.275888] usb 1-2: Endpoint 2 MaxPacketSize 64
[  390.276052] usb 1-2: Setting MaxPacketSize 64
[  390.278136] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[  390.278435] usbcore: registered new interface driver ftdi_sio
[  390.278619] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  394.507447] usb_serial_get_by_index(index 0): @dd0b88a0
[  394.507642] ------------[ cut here ]------------
[  394.507836] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  394.508189] Hardware name: TravelMate 660
[  394.508334] Modules linked in: ftdi_sio usbserial usb_storage squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd i2c_i801 ehci_hcd uhci_hcd usbcore snd_page_alloc pcspkr crc_ccitt
[  394.509752] Pid: 3116, comm: minicom Tainted: G   M       2.6.31-rc6 #1
[  394.509959] Call Trace:
[  394.510089]  [<c12b7052>] ? printk+0x18/0x1e
[  394.510241]  [<df57b182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  394.510480]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  394.510660]  [<df57b182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  394.510894]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  394.511068]  [<df57b182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  394.511304]  [<df57b36d>] serial_open+0x2d/0x250 [usbserial]
[  394.511490]  [<c115f7b9>] ? tty_init_dev+0x89/0x160
[  394.511666]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  394.511815]  [<c1077566>] chrdev_open+0x96/0x140
[  394.511986]  [<c10732ff>] __dentry_open+0x9f/0x250
[  394.512144]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  394.512324]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  394.512478]  [<c107f889>] do_filp_open+0x269/0x890
[  394.512652]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  394.512812]  [<c10730c7>] do_sys_open+0x57/0x140
[  394.512983]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  394.513148]  [<c1073219>] sys_open+0x29/0x40
[  394.513306]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  394.513466] ---[ end trace a4862da83be6d4cc ]---
[  410.250064] usb 1-2: USB disconnect, address 2
[  410.250628] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  410.250935] usb_serial_put(serial @dd0b88a0)
[  410.251074] ------------[ cut here ]------------
[  410.251257] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  410.251586] Hardware name: TravelMate 660
[  410.251730] Modules linked in: ftdi_sio usbserial usb_storage squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd i2c_i801 ehci_hcd uhci_hcd usbcore snd_page_alloc pcspkr crc_ccitt
[  410.253139] Pid: 976, comm: khubd Tainted: G   M    W  2.6.31-rc6 #1
[  410.253339] Call Trace:
[  410.253448]  [<c12b7052>] ? printk+0x18/0x1e
[  410.253598]  [<df57aceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  410.253813]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  410.253992]  [<df57aceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  410.254202]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  410.254376]  [<df57aceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  410.254588]  [<df57af81>] usb_serial_disconnect+0xf1/0x160 [usbserial]
[  410.254835]  [<dea3f447>] ? usb_disable_interface+0x37/0x50 [usbcore]
[  410.255086]  [<dea42221>] usb_unbind_interface+0xf1/0x130 [usbcore]
[  410.255293]  [<c11b5441>] __device_release_driver+0x51/0xa0
[  410.255491]  [<c11b5540>] device_release_driver+0x20/0x40
[  410.255666]  [<c11b4aad>] bus_remove_device+0x7d/0xb0
[  410.255847]  [<c11b2ef2>] device_del+0x102/0x190
[  410.256025]  [<dea3f3a7>] usb_disable_device+0x87/0xf0 [usbcore]
[  410.256259]  [<dea3a8a6>] usb_disconnect+0x96/0xf0 [usbcore]
[  410.256469]  [<dea3b989>] hub_thread+0x829/0x1210 [usbcore]
[  410.256672]  [<c10357a0>] ? autoremove_wake_function+0x0/0x50
[  410.256882]  [<dea3b160>] ? hub_thread+0x0/0x1210 [usbcore]
[  410.257079]  [<c10353cc>] kthread+0x7c/0x90
[  410.257217]  [<c1035350>] ? kthread+0x0/0x90
[  410.257376]  [<c1003673>] kernel_thread_helper+0x7/0x14
[  410.257543] ---[ end trace a4862da83be6d4cd ]---
[  410.257708] ftdi_sio 1-2:1.1: device disconnected
[  410.258188] usb_serial_get_by_index(index 0): @dd0b88a0
[  410.258358] ------------[ cut here ]------------
[  410.258537] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  410.258887] Hardware name: TravelMate 660
[  410.259031] Modules linked in: ftdi_sio usbserial usb_storage squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd i2c_i801 ehci_hcd uhci_hcd usbcore snd_page_alloc pcspkr crc_ccitt
[  410.260453] Pid: 3116, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  410.260660] Call Trace:
[  410.260763]  [<c12b7052>] ? printk+0x18/0x1e
[  410.260912]  [<df57b182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  410.261161]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  410.261340]  [<df57b182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  410.261589]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  410.261763]  [<df57b182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  410.262012]  [<df57b36d>] serial_open+0x2d/0x250 [usbserial]
[  410.262198]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  410.262384]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  410.262531]  [<c1077566>] chrdev_open+0x96/0x140
[  410.262701]  [<c10732ff>] __dentry_open+0x9f/0x250
[  410.262859]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  410.263040]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  410.263194]  [<c107f889>] do_filp_open+0x269/0x890
[  410.263367]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  410.273068]  [<c10730c7>] do_sys_open+0x57/0x140
[  410.283083]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  410.293149]  [<c1073219>] sys_open+0x29/0x40
[  410.303259]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  410.313388] ---[ end trace a4862da83be6d4ce ]---
[  410.331134] tty_port_close_start: count = -1
[  410.335326] serial_do_free(port @d8c72400)
[  410.339451]   serial @dd0b88a0
[  410.343874]   type   @df5d8660
[  410.348150] usb_serial_put(serial @dd0b88a0)
[  410.352244] ------------[ cut here ]------------
[  410.356280] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  410.360483] Hardware name: TravelMate 660
[  410.364569] Modules linked in: ftdi_sio usbserial usb_storage squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd i2c_i801 ehci_hcd uhci_hcd usbcore snd_page_alloc pcspkr crc_ccitt
[  410.373535] Pid: 3116, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  410.377676] Call Trace:
[  410.381732]  [<c12b7052>] ? printk+0x18/0x1e
[  410.385770]  [<df57aceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  410.389857]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  410.393946]  [<df57aceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  410.398034]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  410.402115]  [<df57aceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  410.406209]  [<df57adb9>] serial_do_free+0x99/0xd0 [usbserial]
[  410.410283]  [<df57ae57>] serial_close+0x67/0xa0 [usbserial]
[  410.414352]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  410.418378]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  410.422426]  [<c102372e>] ? warn_slowpath_common+0x9e/0xc0
[  410.426440]  [<c10207e3>] ? __cond_resched+0x23/0x40
[  410.430475]  [<c12b7555>] ? _cond_resched+0x25/0x40
[  410.434478]  [<c12b7d7e>] ? mutex_lock+0xe/0x20
[  410.438499]  [<df57b3a9>] ? serial_open+0x69/0x250 [usbserial]
[  410.442530]  [<c115fced>] tty_open+0x45d/0x4b0
[  410.446533]  [<c1077566>] chrdev_open+0x96/0x140
[  410.450546]  [<c10732ff>] __dentry_open+0x9f/0x250
[  410.454546]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  410.458525]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  410.462523]  [<c107f889>] do_filp_open+0x269/0x890
[  410.466498]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  410.470499]  [<c10730c7>] do_sys_open+0x57/0x140
[  410.474455]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  410.478424]  [<c1073219>] sys_open+0x29/0x40
[  410.482384]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  410.486332] ---[ end trace a4862da83be6d4cf ]---
[  518.992741] serial_do_free(port @d8c72400)
[  518.992888]   serial @dd0b88a0
[  518.993010]   type   @df5d8660
[  518.993115] usb_serial_put(serial @dd0b88a0)
[  518.993268] ------------[ cut here ]------------
[  518.993435] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  518.993794] Hardware name: TravelMate 660
[  518.993923] Modules linked in: ftdi_sio usbserial usb_storage squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd i2c_i801 ehci_hcd uhci_hcd usbcore snd_page_alloc pcspkr crc_ccitt
[  518.995333] Pid: 3116, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  518.995571] Call Trace:
[  518.995665]  [<c12b7052>] ? printk+0x18/0x1e
[  518.995830]  [<df57aceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  518.996029]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  518.996225]  [<df57aceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  518.996419]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  518.996609]  [<df57aceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  518.996804]  [<df57adb9>] serial_do_free+0x99/0xd0 [usbserial]
[  518.997016]  [<df57ae57>] serial_close+0x67/0xa0 [usbserial]
[  518.997200]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  518.997369]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  518.997539]  [<c1056d72>] ? put_page+0x42/0x120
[  518.997708]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  518.997875]  [<c115f64a>] tty_release+0xa/0x10
[  518.998037]  [<c1075f1c>] __fput+0xdc/0x1d0
[  518.998174]  [<c107602f>] fput+0x1f/0x30
[  518.998323]  [<c1072f8e>] filp_close+0x3e/0x70
[  518.998470]  [<c1024fa2>] put_files_struct+0xa2/0xc0
[  518.998648]  [<c1024fdc>] exit_files+0x1c/0x20
[  518.998795]  [<c1026339>] do_exit+0xb9/0x630
[  518.998954]  [<c103acd8>] ? __put_cred+0x18/0x20
[  518.999107]  [<c10268dd>] do_group_exit+0x2d/0x80
[  518.999277]  [<c1026943>] sys_exit_group+0x13/0x20
[  518.999434]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  518.999610] ---[ end trace a4862da83be6d4d0 ]---
[  518.999758] destroy_serial(kref @dd0b88d4)
[  518.999905]   serial @dd0b88a0

Module                  Size  Used by
ftdi_sio               51372  4294967295 
usbserial              31164  1 ftdi_sio
usb_storage            49504  0 
squashfs               20936  1 
zlib_inflate           16164  1 squashfs
nfs                   141068  0 
lockd                  65768  1 nfs
nfs_acl                 2884  1 nfs
sunrpc                170044  3 nfs,lockd,nfs_acl
8021q                  19872  0 
snd_pcm_oss            36096  0 
snd_mixer_oss          14564  1 snd_pcm_oss
xfs                   483008  1 
exportfs                3844  1 xfs
loop                   14352  2 
snd_intel8x0           29792  0 
nsc_ircc               16112  0 
snd_ac97_codec        101540  1 snd_intel8x0
ac97_bus                1540  1 snd_ac97_codec
irda                  101496  1 nsc_ircc
snd_pcm                60524  3 snd_pcm_oss,snd_intel8x0,snd_ac97_codec
snd_timer              18344  1 snd_pcm
snd                    48772  6 snd_pcm_oss,snd_mixer_oss,snd_intel8x0,snd_ac97_codec,snd_pcm,snd_timer
i2c_i801                8500  0 
ehci_hcd               33972  0 
uhci_hcd               21876  0 
usbcore               133920  5 ftdi_sio,usbserial,usb_storage,ehci_hcd,uhci_hcd
snd_page_alloc          8044  2 snd_intel8x0,snd_pcm
pcspkr                  2276  0 
crc_ccitt               1796  1 irda




[  691.010035] usb 1-1: new full speed USB device using uhci_hcd and address 2
[  691.176987] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[  691.177206] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  691.177451] usb 1-1: Product: USB-Serial Controller
[  691.177608] usb 1-1: Manufacturer: Prolific Technology Inc.
[  691.178025] usb 1-1: configuration #1 chosen from 1 choice
[  691.254399] usbcore: registered new interface driver usbserial
[  691.254507] usbserial: USB Serial Driver core
[  691.274470] USB Serial support registered for pl2303
[  691.274732] pl2303 1-1:1.0: pl2303 converter detected
[  691.286169] usb 1-1: pl2303 converter now attached to ttyUSB0
[  691.286430] usbcore: registered new interface driver pl2303
[  691.286610] pl2303: Prolific PL2303 USB to serial adaptor driver
[  702.598739] usb_serial_get_by_index(index 0): @da6a3780
[  702.598931] ------------[ cut here ]------------
[  702.599124] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  702.599476] Hardware name: TravelMate 660
[  702.599621] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec ac97_bus nsc_ircc irda snd_pcm snd_timer snd ehci_hcd pcspkr i2c_i801 uhci_hcd snd_page_alloc crc_ccitt usbcore
[  702.601064] Pid: 2528, comm: minicom Tainted: G   M       2.6.31-rc6 #1
[  702.601272] Call Trace:
[  702.601383]  [<c12b7052>] ? printk+0x18/0x1e
[  702.601532]  [<deb16182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  702.601771]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  702.601950]  [<deb16182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  702.602198]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  702.602372]  [<deb16182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  702.602621]  [<deb1636d>] serial_open+0x2d/0x250 [usbserial]
[  702.602806]  [<c115f7b9>] ? tty_init_dev+0x89/0x160
[  702.602981]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  702.603129]  [<c1077566>] chrdev_open+0x96/0x140
[  702.603300]  [<c10732ff>] __dentry_open+0x9f/0x250
[  702.603457]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  702.603637]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  702.603793]  [<c107f889>] do_filp_open+0x269/0x890
[  702.603966]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  702.604126]  [<c10730c7>] do_sys_open+0x57/0x140
[  702.604296]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  702.604461]  [<c1073219>] sys_open+0x29/0x40
[  702.604619]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  702.604779] ---[ end trace 11618bfb3543f78d ]---
[  733.750062] usb 1-1: USB disconnect, address 2
[  733.751174] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
[  733.751434] usb_serial_put(serial @da6a3780)
[  733.751573] ------------[ cut here ]------------
[  733.751756] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  733.752096] Hardware name: TravelMate 660
[  733.752241] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec ac97_bus nsc_ircc irda snd_pcm snd_timer snd ehci_hcd pcspkr i2c_i801 uhci_hcd snd_page_alloc crc_ccitt usbcore
[  733.753645] Pid: 956, comm: khubd Tainted: G   M    W  2.6.31-rc6 #1
[  733.753846] Call Trace:
[  733.753954]  [<c12b7052>] ? printk+0x18/0x1e
[  733.754103]  [<deb15ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  733.754317]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  733.754497]  [<deb15ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  733.754707]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  733.754880]  [<deb15ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  733.755092]  [<deb15f81>] usb_serial_disconnect+0xf1/0x160 [usbserial]
[  733.755339]  [<dea0c447>] ? usb_disable_interface+0x37/0x50 [usbcore]
[  733.755590]  [<dea0f221>] usb_unbind_interface+0xf1/0x130 [usbcore]
[  733.755797]  [<c11b5441>] __device_release_driver+0x51/0xa0
[  733.755994]  [<c11b5540>] device_release_driver+0x20/0x40
[  733.756169]  [<c11b4aad>] bus_remove_device+0x7d/0xb0
[  733.756349]  [<c11b2ef2>] device_del+0x102/0x190
[  733.756528]  [<dea0c3a7>] usb_disable_device+0x87/0xf0 [usbcore]
[  733.756762]  [<dea078a6>] usb_disconnect+0x96/0xf0 [usbcore]
[  733.756971]  [<dea08989>] hub_thread+0x829/0x1210 [usbcore]
[  733.757175]  [<c10357a0>] ? autoremove_wake_function+0x0/0x50
[  733.757386]  [<dea08160>] ? hub_thread+0x0/0x1210 [usbcore]
[  733.757584]  [<c10353cc>] kthread+0x7c/0x90
[  733.757722]  [<c1035350>] ? kthread+0x0/0x90
[  733.757881]  [<c1003673>] kernel_thread_helper+0x7/0x14
[  733.758049] ---[ end trace 11618bfb3543f78e ]---
[  733.758213] pl2303 1-1:1.0: device disconnected
[  733.759141] usb_serial_get_by_index(index 0): @da6a3780
[  733.759316] ------------[ cut here ]------------
[  733.759497] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:78 usb_serial_get_by_index+0x42/0x70 [usbserial]()
[  733.759847] Hardware name: TravelMate 660
[  733.759992] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec ac97_bus nsc_ircc irda snd_pcm snd_timer snd ehci_hcd pcspkr i2c_i801 uhci_hcd snd_page_alloc crc_ccitt usbcore
[  733.761423] Pid: 2528, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  733.761660] Call Trace:
[  733.761750]  [<c12b7052>] ? printk+0x18/0x1e
[  733.761914]  [<deb16182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  733.762133]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  733.762329]  [<deb16182>] ? usb_serial_get_by_index+0x42/0x70 [usbserial]
[  733.762547]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  733.762737]  [<deb16182>] usb_serial_get_by_index+0x42/0x70 [usbserial]
[  733.762957]  [<deb1636d>] serial_open+0x2d/0x250 [usbserial]
[  733.763159]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  733.763328]  [<c115fa4d>] tty_open+0x1bd/0x4b0
[  733.763492]  [<c1077566>] chrdev_open+0x96/0x140
[  733.763647]  [<c10732ff>] __dentry_open+0x9f/0x250
[  733.763821]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  733.763985]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  733.764155]  [<c107f889>] do_filp_open+0x269/0x890
[  733.764313]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  733.773926]  [<c10730c7>] do_sys_open+0x57/0x140
[  733.783856]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  733.793832]  [<c1073219>] sys_open+0x29/0x40
[  733.803856]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  733.813897] ---[ end trace 11618bfb3543f78f ]---
[  733.829386] tty_port_close_start: count = -1
[  733.930036] serial_do_free(port @dd86ae00)
[  733.940088]   serial @da6a3780
[  733.950089]   type   @deb25c20
[  733.960455] usb_serial_put(serial @da6a3780)
[  733.964507] ------------[ cut here ]------------
[  733.968561] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  733.973026] Hardware name: TravelMate 660
[  733.977130] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec ac97_bus nsc_ircc irda snd_pcm snd_timer snd ehci_hcd pcspkr i2c_i801 uhci_hcd snd_page_alloc crc_ccitt usbcore
[  733.986053] Pid: 2528, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  733.990213] Call Trace:
[  733.994262]  [<c12b7052>] ? printk+0x18/0x1e
[  733.998300]  [<deb15ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  734.002543]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  734.006612]  [<deb15ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  734.010724]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  734.014796]  [<deb15ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  734.018898]  [<deb15db9>] serial_do_free+0x99/0xd0 [usbserial]
[  734.022988]  [<deb15e57>] serial_close+0x67/0xa0 [usbserial]
[  734.027062]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  734.031105]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  734.035140]  [<c102372e>] ? warn_slowpath_common+0x9e/0xc0
[  734.039158]  [<c10207e3>] ? __cond_resched+0x23/0x40
[  734.043201]  [<c12b7555>] ? _cond_resched+0x25/0x40
[  734.047213]  [<c12b7d7e>] ? mutex_lock+0xe/0x20
[  734.051243]  [<deb163a9>] ? serial_open+0x69/0x250 [usbserial]
[  734.055258]  [<c115fced>] tty_open+0x45d/0x4b0
[  734.059281]  [<c1077566>] chrdev_open+0x96/0x140
[  734.063302]  [<c10732ff>] __dentry_open+0x9f/0x250
[  734.067307]  [<c1073599>] nameidata_to_filp+0x59/0x70
[  734.071304]  [<c10774d0>] ? chrdev_open+0x0/0x140
[  734.075288]  [<c107f889>] do_filp_open+0x269/0x890
[  734.079264]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  734.083275]  [<c10730c7>] do_sys_open+0x57/0x140
[  734.087234]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  734.091225]  [<c1073219>] sys_open+0x29/0x40
[  734.095170]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  734.099124] ---[ end trace 11618bfb3543f790 ]---
[  834.133234] serial_do_free(port @dd86ae00)
[  834.133379]   serial @da6a3780
[  834.133499]   type   @deb25c20
[  834.133621] usb_serial_put(serial @da6a3780)
[  834.133757] ------------[ cut here ]------------
[  834.133939] WARNING: at /usr/src/linux-2.6/drivers/usb/serial/usb-serial.c:179 usb_serial_put+0x2b/0x60 [usbserial]()
[  834.134266] Hardware name: TravelMate 660
[  834.134410] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec ac97_bus nsc_ircc irda snd_pcm snd_timer snd ehci_hcd pcspkr i2c_i801 uhci_hcd snd_page_alloc crc_ccitt usbcore
[  834.135811] Pid: 2528, comm: minicom Tainted: G   M    W  2.6.31-rc6 #1
[  834.136018] Call Trace:
[  834.136127]  [<c12b7052>] ? printk+0x18/0x1e
[  834.136276]  [<deb15ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  834.136489]  [<c10236fc>] warn_slowpath_common+0x6c/0xc0
[  834.136669]  [<deb15ceb>] ? usb_serial_put+0x2b/0x60 [usbserial]
[  834.136878]  [<c1023765>] warn_slowpath_null+0x15/0x20
[  834.137051]  [<deb15ceb>] usb_serial_put+0x2b/0x60 [usbserial]
[  834.137262]  [<deb15db9>] serial_do_free+0x99/0xd0 [usbserial]
[  834.137457]  [<deb15e57>] serial_close+0x67/0xa0 [usbserial]
[  834.137658]  [<c115d1a5>] ? tty_fasync+0x55/0xe0
[  834.137810]  [<c115f2e0>] tty_release_dev+0x130/0x490
[  834.137995]  [<c1056d72>] ? put_page+0x42/0x120
[  834.138148]  [<c10897b6>] ? mntput_no_expire+0x16/0x60
[  834.138331]  [<c115f64a>] tty_release+0xa/0x10
[  834.138477]  [<c1075f1c>] __fput+0xdc/0x1d0
[  834.138630]  [<c107602f>] fput+0x1f/0x30
[  834.138763]  [<c1072f8e>] filp_close+0x3e/0x70
[  834.138926]  [<c1024fa2>] put_files_struct+0xa2/0xc0
[  834.139088]  [<c1024fdc>] exit_files+0x1c/0x20
[  834.139251]  [<c1026339>] do_exit+0xb9/0x630
[  834.139393]  [<c103acd8>] ? __put_cred+0x18/0x20
[  834.139562]  [<c10268dd>] do_group_exit+0x2d/0x80
[  834.139717]  [<c1026943>] sys_exit_group+0x13/0x20
[  834.139890]  [<c1002e08>] sysenter_do_call+0x12/0x26
[  834.140084] ---[ end trace 11618bfb3543f791 ]---
[  834.141308] destroy_serial(kref @da6a37b4)
[  834.141366]   serial @da6a3780

Module                  Size  Used by
pl2303                 16808  4294967295 
usbserial              31164  1 pl2303
squashfs               20936  1 
zlib_inflate           16164  1 squashfs
nfs                   141068  0 
lockd                  65768  1 nfs
nfs_acl                 2884  1 nfs
sunrpc                170044  3 nfs,lockd,nfs_acl
8021q                  19872  0 
snd_pcm_oss            36096  0 
snd_mixer_oss          14564  1 snd_pcm_oss
xfs                   483008  1 
exportfs                3844  1 xfs
loop                   14352  2 
usb_storage            49504  0 
snd_intel8x0           29792  0 
snd_ac97_codec        101540  1 snd_intel8x0
ac97_bus                1540  1 snd_ac97_codec
nsc_ircc               16112  0 
irda                  101496  1 nsc_ircc
snd_pcm                60524  3 snd_pcm_oss,snd_intel8x0,snd_ac97_codec
snd_timer              18344  1 snd_pcm
snd                    48772  6 snd_pcm_oss,snd_mixer_oss,snd_intel8x0,snd_ac97_codec,snd_pcm,snd_timer
ehci_hcd               33972  0 
pcspkr                  2276  0 
i2c_i801                8500  0 
uhci_hcd               21876  0 
snd_page_alloc          8044  2 snd_intel8x0,snd_pcm
crc_ccitt               1796  1 irda
usbcore               133920  5 pl2303,usbserial,usb_storage,ehci_hcd,uhci_hcd




^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 15:48                                       ` Alan Cox
@ 2009-08-21 17:39                                         ` Alan Stern
  2009-08-21 18:42                                           ` Alan Cox
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-21 17:39 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

On Fri, 21 Aug 2009, Alan Cox wrote:

> > Alan, related to this problem is the fact that usb_serial_driver
> > doesn't include a "hangup" method.  I'm not sure that making
> > serial_hangup() call serial_do_down() is correct, but if it is then
> > shouldn't we call port->serial->type->open() afterwards?  Otherwise the
> > lower driver can't know that the port is still open.
> 
> After a hangup the port isn't open (at the physical level anyway). It may
> be re-opened by another open() call later

Or, oddly enough, another open() call earlier...

> but the original user lost
> access to it and shouldn't touch the h/w post hangup completion.

Then surely serial_open() should call serial->type->open() _after_ 
tty_port_block_til_ready(), not before.

> > Furthermore, shouldn't we check ASYNCB_INITIALIZED in serial_close()?
> 
> Possibly - I was in the middle of debugging the newest bits when Linus
> annoyed me. Certainly there are issues in the current code if you get
> a hangup while waiting for open to complete. I fixed that in the patches
> I sent Greg but didn't finish debugging it.

Well, yes.  The way it is now, you get:

	serial_open()				/* first user */
		serial->type->open()		/* initializes the hardware */
		tty_port_block_til_ready()	/* returns immediately */

	serial_open()				/* second user */
		serial->type->open skipped because the port
			is already open
		tty_port_block_til_ready()	/* blocks */

	serial_hangup()				/* first connection drops */
		serial_do_down()
			serial->type-close()	/* resets the hardware */

		... tty_port_block_til_ready() returns

Now the second user tries to do stuff but the hardware isn't ready.  
Instead this should go:

	serial_open()				/* first user */
		tty_port_block_til_ready()	/* returns immediately */
		serial->type->open()		/* initializes the hardware */

	serial_open()				/* second user */
		tty_port_block_til_ready()	/* blocks */

	serial_hangup()				/* first connection drops */
		serial_do_down()
			serial->type-close()	/* resets the hardware */

		... tty_port_block_til_ready() returns
		serial->type->open()		/* not skipped */

Now the second user can proceed to use the hardware.  Or have I 
misunderstood how this is intended to work?

Alan Stern

P.S.: Can you explain the reason why tty_port and tty_struct are two 
separate structures?  Isn't the same port always associated with the 
same tty?


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 17:39                                         ` Alan Stern
@ 2009-08-21 18:42                                           ` Alan Cox
  2009-08-21 20:52                                             ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Cox @ 2009-08-21 18:42 UTC (permalink / raw)
  To: Alan Stern
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

> Then surely serial_open() should call serial->type->open() _after_ 
> tty_port_block_til_ready(), not before.

It needs the hardware active and running to do the block_til_ready

> Now the second user tries to do stuff but the hardware isn't ready.  
> Instead this should go:
> 
> 	serial_open()				/* first user */
> 		tty_port_block_til_ready()	/* returns immediately */
> 		serial->type->open()		/* initializes the hardware */
> 
> 	serial_open()				/* second user */
> 		tty_port_block_til_ready()	/* blocks */

If the first user succeeded then second should open immediately as the use
count is >= 1 already. It is re-opening the open device, unless the
hangup occurs first.

> 
> 	serial_hangup()				/* first connection drops */
> 		serial_do_down()
> 			serial->type-close()	/* resets the hardware */
> 
> 		... tty_port_block_til_ready() returns
> 		serial->type->open()		/* not skipped */
> 
> Now the second user can proceed to use the hardware.  Or have I 
> misunderstood how this is intended to work?


Usual paths

	open
	block_til_ready
	open returns 0
	do stuff
	close

	open
	block_til_ready
	open returns 0
	do stuff
	hangup (closes hw side)
	further stuff errors
	close (does nothing to the hw side tty_port_close knows about
	this)

	open
	block_til_ready
	hangup
	open returns error
	close path called - knows about hangup in tty_close_port


Hence the reason it always calls the close path to cleanup hardware and
other resources even if open returns an error

> 
> Alan Stern
> 
> P.S.: Can you explain the reason why tty_port and tty_struct are two 
> separate structures?  Isn't the same port always associated with the 
> same tty?

The tty structure is the virtual interface side, the tty_port is the
hardware device. Historically the port side varied randomly by device
preventing any commonality being extracted into helpers.

For most hardware the tty_port lifetime is the physical port lifetime,
the tty lifetime is open->final close (or a final kref drop afterwards)

It also means eventually that we can have a tty_port and things hung off
it for all hardware which means

- Most of the locking costs for receiving v hangup go away (as you
  queue to the tty_port not the tty - ie move the tty_buffer struct)
- It becomes possible to have a proper generic console/debug console
  without hacks and fake tty devices.


Most drivers tend to look like

	open
		test ASYNC_INITIALIZED
			init hardware
			[either in full or clean up partial]
			set ASYNC_INITIALIZED)
		any other alloc/counter magic
		tty->private_data = my stuff
		block_til_ready
	return ok/error

	close
		if (hung_up)
			return
		if (tty->driver_data == NULL)
			return
		counts
		clean up resources
		if (last && test_clear INITIALIZED)
			deinit-hardware
	return ok/error

	hangup
		if (initialized & test_clear INITIALIZED) {
			deinit hardware
		}

which is where I was trying to get the USB code.


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 18:42                                           ` Alan Cox
@ 2009-08-21 20:52                                             ` Alan Stern
  2009-08-21 23:16                                               ` Alan Cox
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-21 20:52 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

On Fri, 21 Aug 2009, Alan Cox wrote:

> > 	serial_open()				/* first user */
> > 		tty_port_block_til_ready()	/* returns immediately */
> > 		serial->type->open()		/* initializes the hardware */
> > 
> > 	serial_open()				/* second user */
> > 		tty_port_block_til_ready()	/* blocks */
> 
> If the first user succeeded then second should open immediately as the use
> count is >= 1 already. It is re-opening the open device, unless the
> hangup occurs first.

What about protecting the use counter?  In tty_port.c it's always
protected by port->lock, but not in serial_open().  Is that a mistake?

How are hangups synchronized with opens?  Do you rely on the BKL?  
Suppose a hangup occurs, and do_tty_hangup() marks all the existing
file references with hung_up_tty_fops.  But before it gets around to
calling tty->ops->hangup(), another open occurs.  I can't imagine the
BKL will prevent this; do_tty_hangup() is so complex it must sleep
somewhere.  Thus it's possible for __tty_open() to call
tty->ops->open() before tty->ops->hangup() is called, which means the
open will succeed.

The when the driver's hangup routine finally gets around to calling
tty_port_hangup(), port->count will be set back to 0.  So now we've got
an uncounted open file.


> Most drivers tend to look like
> 
> 	open
> 		test ASYNC_INITIALIZED
> 			init hardware
> 			[either in full or clean up partial]
> 			set ASYNC_INITIALIZED)
> 		any other alloc/counter magic
> 		tty->private_data = my stuff

tty->driver_data, right?

> 		block_til_ready
> 	return ok/error
> 
> 	close
> 		if (hung_up)
> 			return
> 		if (tty->driver_data == NULL)
> 			return
> 		counts

Is "counts" shorthand for:

		if (tty_port_close_start(...) == 0)
			return
?

> 		clean up resources
> 		if (last && test_clear INITIALIZED)

How do you check for "last"?  Doesn't the fact that we are here mean 
that there are no remaining open references?

> 			deinit-hardware
> 	return ok/error
> 
> 	hangup
> 		if (initialized & test_clear INITIALIZED) {

What is "initialized" supposed to be?  Isn't INITIALIZED enough?

> 			deinit hardware
> 		}
> 
> which is where I was trying to get the USB code.

It doesn't look as though we're too far away.  Thanks for the detailed 
explanations.

Alan Stern

P.S.: Consider this code in tty_port_block_til_ready():

	/* if non-blocking mode is set we can pass directly to open unless
	   the port has just hung up or is in another error state */
	if ((filp->f_flags & O_NONBLOCK) ||
			(tty->flags & (1 << TTY_IO_ERROR))) {
		port->flags |= ASYNC_NORMAL_ACTIVE;
		return 0;
	}

The comment doesn't agree with the logic of the test.  Which is wrong?


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 20:52                                             ` Alan Stern
@ 2009-08-21 23:16                                               ` Alan Cox
  2009-08-22  2:30                                                 ` Alan Stern
  2009-08-23  2:51                                                 ` Alan Stern
  0 siblings, 2 replies; 42+ messages in thread
From: Alan Cox @ 2009-08-21 23:16 UTC (permalink / raw)
  To: Alan Stern
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

> What about protecting the use counter?  In tty_port.c it's always
> protected by port->lock, but not in serial_open().  Is that a mistake?

Ah good an easy question to begin with

Yes it is in error.

> How are hangups synchronized with opens?  Do you rely on the BKL? 

In a sense this is up the driver. hangup can only occur from two paths

1.	User triggered hangup (requires open has completed, user has an
fd)

2.	Driver calls hangup from its interrupt or other similar event
handler

The core of both hangup and open are still BKL protected against
one another (ugly - wants fixing), release_one_dev() liekwise. This is
probably inadequate as they may well sleep in various spots

> Suppose a hangup occurs, and do_tty_hangup() marks all the existing
> file references with hung_up_tty_fops.  But before it gets around to
> calling tty->ops->hangup(), another open occurs.  I can't imagine the
> BKL will prevent this; do_tty_hangup() is so complex it must sleep
> somewhere.  Thus it's possible for __tty_open() to call
> tty->ops->open() before tty->ops->hangup() is called, which means the
> open will succeed.

I don't think that is any different (logically) to the new open occuring
just after the hangup. In other words I agree its a race but I am not
sure it is of itself an actual problem

> The when the driver's hangup routine finally gets around to calling
> tty_port_hangup(), port->count will be set back to 0.  So now we've got
> an uncounted open file.

But that would be and I don't immediately see anything preventing it from
happening. Or if it can't happen there is a good deal of luck rather than
judgement involved 8)

The hangup path doesn't sleep until it has set TTY_HUPPED and I think
until the tty_kref_put calls are done. The ops->close/hangup can
certainly sleep however and would be the first point that hangup sleeps.
So it is I think safe that way - but not at all a good design at the
moment.

On the open side tty_reopen can sleep as can tty_init_dev.

block_til_ready ought to be safe as of itself and is coded to avoid the
problem. It checks tty_hung_up_p under the port lock before adjusting the
port count. hangup takes the same lock when adjusting the port count.

tty_hung_up_p relies on the filp operations changes and BKL

So I think the tty_port parts work (half through luck) but the serial.c
bits may well not and without the BKL it would fall apart totally at the
moment.

> 
> 
> > Most drivers tend to look like
> > 
> > 	open
> > 		test ASYNC_INITIALIZED
> > 			init hardware
> > 			[either in full or clean up partial]
> > 			set ASYNC_INITIALIZED)
> > 		any other alloc/counter magic
> > 		tty->private_data = my stuff
> 
> tty->driver_data, right?

Yes sorry

> 
> > 		block_til_ready
> > 	return ok/error
> > 
> > 	close
> > 		if (hung_up)
> > 			return
> > 		if (tty->driver_data == NULL)
> > 			return
> > 		counts
> 
> Is "counts" shorthand for:
> 
> 		if (tty_port_close_start(...) == 0)
> 			return

Usually - but not all drivers use tty_port_close_start yet, some still
open code all the open/close posix logic or some variant of it

> ?
> 
> > 		clean up resources
> > 		if (last && test_clear INITIALIZED)
> 
> How do you check for "last"?  Doesn't the fact that we are here mean 
> that there are no remaining open references?

It means there are no remaining file references to the handle, but you
may have multiple file handles referencing the same tty

(eg

	open /dev/ttyS0
	open /dev/ttyS0

produces two handles to one tty. The tty closes at the hardware level
when the last file handle reference goes away. This is important because
of open /dev/tty, and the like)

ie we have a count of users of the file, which on hitting zero calls
tty_release_dev and eventually the port close method. we have a separate
count above that of opens to the port which we drop by one for each final
close of a file handle.

> 
> > 			deinit-hardware
> > 	return ok/error
> > 
> > 	hangup
> > 		if (initialized & test_clear INITIALIZED) {
> 
> What is "initialized" supposed to be?  Isn't INITIALIZED enough?

It depends on the driver. I believe for anything using the helpers it is
enough but I may be wrong.

> P.S.: Consider this code in tty_port_block_til_ready():
> 
> 	/* if non-blocking mode is set we can pass directly to open unless
> 	   the port has just hung up or is in another error state */
> 	if ((filp->f_flags & O_NONBLOCK) ||
> 			(tty->flags & (1 << TTY_IO_ERROR))) {
> 		port->flags |= ASYNC_NORMAL_ACTIVE;
> 		return 0;
> 	}
> 
> The comment doesn't agree with the logic of the test.  Which is wrong?

The code and comment were copied from the original drivers (and occur in
several places ;))

The intended logic is

	if O_NONBLOCK is set
		succeed immediately
	if there is a hangup (or other pending error)
		succeed immediately

So if this occurs

	open
		hangup

we don't do

	open
		hangup
	block for carrier
	twiddle thumbs ...


but do

	open
		hangup
	ok fd = 4
	read fd
		-EIO

(ditto for a hangup from say unplugging the hardware where it would
 make no sense to wait for the carrier)

 
--
	"Alan, I'm getting a bit worried about you."
				-- Linus Torvalds

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 23:16                                               ` Alan Cox
@ 2009-08-22  2:30                                                 ` Alan Stern
  2009-08-23  2:51                                                 ` Alan Stern
  1 sibling, 0 replies; 42+ messages in thread
From: Alan Stern @ 2009-08-22  2:30 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

On Sat, 22 Aug 2009, Alan Cox wrote:

> > What about protecting the use counter?  In tty_port.c it's always
> > protected by port->lock, but not in serial_open().  Is that a mistake?
> 
> Ah good an easy question to begin with
> 
> Yes it is in error.

Okay, I'll fix it.

> The core of both hangup and open are still BKL protected against
> one another (ugly - wants fixing), release_one_dev() liekwise. This is
> probably inadequate as they may well sleep in various spots

Would you consider ideas for changing the protection to something else?  
I don't have anything in mind at the moment -- I need to study the code
some more to understand it better.  But eventually a possibility may
suggest itself.

> > > 		clean up resources
> > > 		if (last && test_clear INITIALIZED)
> > 
> > How do you check for "last"?  Doesn't the fact that we are here mean 
> > that there are no remaining open references?
> 
> It means there are no remaining file references to the handle, but you
> may have multiple file handles referencing the same tty

So basically this amounts to testing whether port->count == 0?  But 
isn't that already implicit when tty_port_close_start() returns 0?

It sounds like this is another little thingy needed only by drivers
that don't use the new helpers.

> > P.S.: Consider this code in tty_port_block_til_ready():
> > 
> > 	/* if non-blocking mode is set we can pass directly to open unless
> > 	   the port has just hung up or is in another error state */
> > 	if ((filp->f_flags & O_NONBLOCK) ||
> > 			(tty->flags & (1 << TTY_IO_ERROR))) {
> > 		port->flags |= ASYNC_NORMAL_ACTIVE;
> > 		return 0;
> > 	}
> > 
> > The comment doesn't agree with the logic of the test.  Which is wrong?
> 
> The code and comment were copied from the original drivers (and occur in
> several places ;))
> 
> The intended logic is
> 
> 	if O_NONBLOCK is set
> 		succeed immediately
> 	if there is a hangup (or other pending error)
> 		succeed immediately

Got it -- the comment is wrong.  It should say something like:

	/* If non-blocking mode is set or the port is in an error state
	 * then we can return directly; tty_open() will handle everything.
	 */

Thanks,

Alan Stern




^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-21 23:16                                               ` Alan Cox
  2009-08-22  2:30                                                 ` Alan Stern
@ 2009-08-23  2:51                                                 ` Alan Stern
  2009-08-23 16:15                                                   ` Alan Stern
  1 sibling, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-23  2:51 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

Alan:

There's a problem with the tty->ops->shutdown method.  It needs to
release the last port reference owned by the current tty.  But when was
that reference originally acquired?  Evidently during the first time
serial_open() was called for the current tty.

The problem is that serial_open() has no way to know if a particular 
invocation is the first one for this tty!  The ASYNCB_INITIALIZED flag 
doesn't help, because it might not get set during the first call (i.e., 
if an error occurs).

To do this right, we need a flag in the tty_struct or the tty_port
which serial_open() can set when acquiring that first reference and
shutdown method can clear.  Should I add such a flag?

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-23  2:51                                                 ` Alan Stern
@ 2009-08-23 16:15                                                   ` Alan Stern
  2009-08-23 16:30                                                     ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-23 16:15 UTC (permalink / raw)
  To: Alan Cox
  Cc: Bruno Prémont, Greg KH, Kernel development list, USB list,
	Rafael J. Wysocki

On Sat, 22 Aug 2009, Alan Stern wrote:

> Alan:
> 
> There's a problem with the tty->ops->shutdown method.  It needs to
> release the last port reference owned by the current tty.  But when was
> that reference originally acquired?  Evidently during the first time
> serial_open() was called for the current tty.
> 
> The problem is that serial_open() has no way to know if a particular 
> invocation is the first one for this tty!  The ASYNCB_INITIALIZED flag 
> doesn't help, because it might not get set during the first call (i.e., 
> if an error occurs).
> 
> To do this right, we need a flag in the tty_struct or the tty_port
> which serial_open() can set when acquiring that first reference and
> shutdown method can clear.  Should I add such a flag?

Never mind, I figured out an answer.  Instead of a new flag, the 
routine can simply test whether or not tty->driver_data has been set.

One more question: Under what circumstances should serial_open() 
increment port->port.count?  It seems that this should happen on every 
call unless tty->driver_data is NULL or filp has been hung up.  Is that 
right?

I have a big patch almost ready for testing.  Unfortunately I don't 
have access to my usual hardware right now, so I can't test it until 
the middle of the week.  Bruno, if you like I will send you the patch 
when it looks okay and you can try it out.

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-23 16:15                                                   ` Alan Stern
@ 2009-08-23 16:30                                                     ` Bruno Prémont
  2009-08-24  1:24                                                       ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-23 16:30 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Sun, 23 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> I have a big patch almost ready for testing.  Unfortunately I don't 
> have access to my usual hardware right now, so I can't test it until 
> the middle of the week.  Bruno, if you like I will send you the patch 
> when it looks okay and you can try it out.

Fine for me, I can test every week-day during evening as well as during
week-end (European time, UTC+2).
If there are any specific tests (other than the surviving of disconnect)
that I shall run, just ask!

Bruno

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-23 16:30                                                     ` Bruno Prémont
@ 2009-08-24  1:24                                                       ` Alan Stern
  2009-08-24 20:15                                                         ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-24  1:24 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Sun, 23 Aug 2009, Bruno [UTF-8] Prémont wrote:

> On Sun, 23 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> > I have a big patch almost ready for testing.  Unfortunately I don't 
> > have access to my usual hardware right now, so I can't test it until 
> > the middle of the week.  Bruno, if you like I will send you the patch 
> > when it looks okay and you can try it out.
> 
> Fine for me, I can test every week-day during evening as well as during
> week-end (European time, UTC+2).
> If there are any specific tests (other than the surviving of disconnect)
> that I shall run, just ask!

Here it is.  This is meant to apply on top of gregkh-all-2.6.31-rc6;  
it replaces the small patch you tried earlier.  In fact this ought to
be split up into at least four individual patches, but you can test it
all in one piece.

Surviving disconnect, ability to reconnect, deallocating memory 
(destroy_serial and port_free) at the right time...  Anything else you 
can think of.

Alan Stern

P.S.: You may already have the first part, with the changes to
tty_port.c.



Index: usb-2.6/drivers/char/tty_port.c
===================================================================
--- usb-2.6.orig/drivers/char/tty_port.c
+++ usb-2.6/drivers/char/tty_port.c
@@ -100,7 +100,7 @@ EXPORT_SYMBOL(tty_port_tty_set);
 static void tty_port_shutdown(struct tty_port *port)
 {
 	if (port->ops->shutdown &&
-		test_and_clear_bit(ASYNC_INITIALIZED, &port->flags))
+		test_and_clear_bit(ASYNCB_INITIALIZED, &port->flags))
 			port->ops->shutdown(port);
 	
 }
@@ -311,7 +311,7 @@ int tty_port_close_start(struct tty_port
 			port->ops->drop(port);
 		return 0;
 	}
-	set_bit(ASYNC_CLOSING, &port->flags);
+	set_bit(ASYNCB_CLOSING, &port->flags);
 	tty->closing = 1;
 	spin_unlock_irqrestore(&port->lock, flags);
 	/* Don't block on a stalled port, just pull the chain */
Index: usb-2.6/drivers/usb/serial/usb-serial.c
===================================================================
--- usb-2.6.orig/drivers/usb/serial/usb-serial.c
+++ usb-2.6/drivers/usb/serial/usb-serial.c
@@ -126,8 +126,10 @@ static void return_serial(struct usb_ser
 
 	dbg("%s", __func__);
 
+	mutex_lock(&table_lock);
 	for (i = 0; i < serial->num_ports; ++i)
 		serial_table[serial->minor + i] = NULL;
+	mutex_unlock(&table_lock);
 }
 
 static void destroy_serial(struct kref *kref)
@@ -146,35 +148,24 @@ static void destroy_serial(struct kref *
 
 	serial->type->release(serial);
 
-	for (i = 0; i < serial->num_ports; ++i) {
+	for (i = 0; i < serial->num_port_pointers; ++i) {
 		port = serial->port[i];
 		if (port)
-			put_device(&port->dev);
-	}
-
-	/* If this is a "fake" port, we have to clean it up here, as it will
-	 * not get cleaned up in port_release() as it was never registered with
-	 * the driver core */
-	if (serial->num_ports < serial->num_port_pointers) {
-		for (i = serial->num_ports;
-					i < serial->num_port_pointers; ++i) {
-			port = serial->port[i];
-			if (port)
-				port_free(port);
-		}
+			port_free(port);
 	}
 
 	usb_put_dev(serial->dev);
-
-	/* free up any memory that we allocated */
 	kfree(serial);
 }
 
+void usb_serial_get(struct usb_serial *serial)
+{
+	kref_get(&serial->kref);
+}
+
 void usb_serial_put(struct usb_serial *serial)
 {
-	mutex_lock(&table_lock);
 	kref_put(&serial->kref, destroy_serial);
-	mutex_unlock(&table_lock);
 }
 
 /*****************************************************************************
@@ -186,16 +177,13 @@ static int serial_open (struct tty_struc
 	struct usb_serial_port *port;
 	unsigned int portNumber;
 	int retval = 0;
-	int first = 0;
 
 	dbg("%s", __func__);
 
 	/* get the serial object associated with this tty pointer */
 	serial = usb_serial_get_by_index(tty->index);
-	if (!serial) {
-		tty->driver_data = NULL;
+	if (!serial)
 		return -ENODEV;
-	}
 
 	mutex_lock(&serial->disc_mutex);
 	portNumber = tty->index - serial->minor;
@@ -209,24 +197,42 @@ static int serial_open (struct tty_struc
 	 * to be acquired while serial->disc_mutex is held.
 	 */
 	mutex_unlock(&serial->disc_mutex);
-	if (retval)
-		goto bailout_serial_put;
 
+	/* serial is pinned by port->dev, so we can drop its reference */
+	usb_serial_put(serial);
+
+	/* Associate this tty with our port structure, if it isn't already
+	 * associated.  This reference will be dropped in serial_shutdown(),
+	 * when the TTY layer is finished with the tty.
+	 */
+	if (retval == 0 && !tty->driver_data) {
+		tty->driver_data = port;
+		get_device(&port->dev);
+	}
+
+	/* Every open call associated with a port must increment the
+	 * port's use counter, even if the call fails, unless the tty
+	 * has been hung up.
+	 */
+	if (tty->driver_data) {
+		spin_lock_irq(&port->port.lock);
+		if (!tty_hung_up_p(filp))
+			++port->port.count;
+		spin_unlock_irq(&port->port.lock);
+		tty_port_tty_set(&port->port, tty);
+	}
+
+	if (retval)
+		return retval;
 	if (mutex_lock_interruptible(&port->mutex)) {
 		retval = -ERESTARTSYS;
 		goto bailout_port_put;
 	}
 
-	++port->port.count;
-
-	/* set up our port structure making the tty driver
-	 * remember our port object, and us it */
-	tty->driver_data = port;
-	tty_port_tty_set(&port->port, tty);
-
-	/* If the console is attached, the device is already open */
-	if (port->port.count == 1 && !port->console) {
-		first = 1;
+	/* Do the device-specific open only if the hardware isn't
+	 * already initialized.
+	 */
+	if (!test_bit(ASYNCB_INITIALIZED, &port->port.flags)) {
 		/* lock this module before we call it
 		 * this may fail, which means we must bail out,
 		 * safe because we are called with BKL held */
@@ -243,8 +249,6 @@ static int serial_open (struct tty_struc
 		if (retval)
 			goto bailout_module_put;
 
-		/* only call the device specific open if this
-		 * is the first time the port is opened */
 		retval = serial->type->open(tty, port);
 		if (retval)
 			goto bailout_interface_put;
@@ -252,32 +256,26 @@ static int serial_open (struct tty_struc
 		set_bit(ASYNCB_INITIALIZED, &port->port.flags);
 	}
 	mutex_unlock(&port->mutex);
+
+	/* The port object was pinned by the tty when the association
+	 * was made above.  We don't need an extra reference for each
+	 * open call.
+	 */
+	put_device(&port->dev);
+
 	/* Now do the correct tty layer semantics */
 	retval = tty_port_block_til_ready(&port->port, tty, filp);
-	if (retval == 0) {
-		if (!first)
-			usb_serial_put(serial);
-		return 0;
-	}
-	mutex_lock(&port->mutex);
-	if (first == 0)
-		goto bailout_mutex_unlock;
-	/* Undo the initial port actions */
-	mutex_lock(&serial->disc_mutex);
-bailout_interface_put:
+	return retval;
+
+ bailout_interface_put:
 	usb_autopm_put_interface(serial->interface);
-bailout_module_put:
+ bailout_module_put:
 	mutex_unlock(&serial->disc_mutex);
 	module_put(serial->type->driver.owner);
-bailout_mutex_unlock:
-	port->port.count = 0;
-	tty->driver_data = NULL;
-	tty_port_tty_set(&port->port, NULL);
+ bailout_mutex_unlock:
 	mutex_unlock(&port->mutex);
-bailout_port_put:
+ bailout_port_put:
 	put_device(&port->dev);
-bailout_serial_put:
-	usb_serial_put(serial);
 	return retval;
 }
 
@@ -287,56 +285,34 @@ bailout_serial_put:
  *
  *	Shut down a USB port unless it is the console. We never shut down the
  *	console hardware as it will always be in use.
- *
- *	Don't free any resources at this point
  */
 static void serial_do_down(struct usb_serial_port *port)
 {
-	struct usb_serial_driver *drv = port->serial->type;
+	struct usb_serial *serial = port->serial;
+	struct usb_serial_driver *drv = serial->type;
 
 	/* The console is magical, do not hang up the console hardware
 	   or there will be tears */
 	if (port->console)
 		return;
 
+	/* Don't call the close method if the hardware hasn't been
+	 * initialized.
+	 */
+	if (!test_and_clear_bit(ASYNCB_INITIALIZED, &port->port.flags))
+		return;
+
 	mutex_lock(&port->mutex);
 	if (drv->close)
 		drv->close(port);
 	mutex_unlock(&port->mutex);
-}
-
-/**
- *	serial_do_free		-	free resources post close/hangup
- *	@port: port to free up
- *
- *	Do the resource freeing and refcount dropping for the port. We must
- *	be careful about ordering and we must avoid freeing up the console.
- *
- *	Called when the last tty kref is dropped.
- */
 
-static void serial_do_free(struct tty_struct *tty)
-{
-	struct usb_serial_port *port = tty->driver_data;
-	struct usb_serial *serial;
-	struct module *owner;
+	module_put(drv->driver.owner);
 
-	/* The console is magical, do not hang up the console hardware
-	   or there will be tears */
-	if (port == NULL || port->console)
-		return;
-
-	serial = port->serial;
-	owner = serial->type->driver.owner;
-	put_device(&port->dev);
-	/* Mustn't dereference port any more */
 	mutex_lock(&serial->disc_mutex);
 	if (!serial->disconnected)
 		usb_autopm_put_interface(serial->interface);
 	mutex_unlock(&serial->disc_mutex);
-	usb_serial_put(serial);
-	/* Mustn't dereference serial any more */
-	module_put(owner);
 }
 
 static void serial_close(struct tty_struct *tty, struct file *filp)
@@ -348,21 +324,45 @@ static void serial_close(struct tty_stru
 
 	dbg("%s - port %d", __func__, port->number);
 
+	if (tty_hung_up_p(filp))
+		return;
 	if (tty_port_close_start(&port->port, tty, filp) == 0)
 		return;
+
 	serial_do_down(port);		
 	tty_port_close_end(&port->port, tty);
 	tty_port_tty_set(&port->port, NULL);
-
 }
 
 static void serial_hangup(struct tty_struct *tty)
 {
 	struct usb_serial_port *port = tty->driver_data;
+
 	serial_do_down(port);
 	tty_port_hangup(&port->port);
-	/* We must not free port yet - the USB serial layer depends on it's
-	   continued existence */
+}
+
+/**
+ * serial_shutdown - free resources post close/hangup
+ * @tty: TTY whose port should be freed
+ *
+ * Do the resource freeing and refcount dropping for the port. We must
+ * avoid freeing up the console.
+ *
+ * Called when the last tty kref is dropped.
+ */
+static void serial_shutdown(struct tty_struct *tty)
+{
+	struct usb_serial_port *port = tty->driver_data;
+
+	/* The console is magical, do not hang up the console hardware
+	   or there will be tears */
+	if (port == NULL || port->console)
+		return;
+
+	/* Release the reference owned by the tty object */
+	tty->driver_data = NULL;
+	put_device(&port->dev);
 }
 
 static int serial_write(struct tty_struct *tty, const unsigned char *buf,
@@ -581,7 +581,9 @@ static void port_release(struct device *
 	struct usb_serial_port *port = to_usb_serial_port(dev);
 
 	dbg ("%s - %s", __func__, dev_name(dev));
-	port_free(port);
+
+	/* The port structure will be freed in destroy_serial(). */
+	usb_serial_put(port->serial);
 }
 
 static void kill_traffic(struct usb_serial_port *port)
@@ -945,10 +947,16 @@ int usb_serial_probe(struct usb_interfac
 			goto probe_error;
 		tty_port_init(&port->port);
 		port->port.ops = &serial_port_ops;
-		port->serial = serial;
 		spin_lock_init(&port->lock);
 		mutex_init(&port->mutex);
 		INIT_WORK(&port->work, usb_serial_port_work);
+		port->dev.parent = &interface->dev;
+		port->dev.driver = NULL;
+		port->dev.bus = &usb_serial_bus_type;
+		port->dev.release = &port_release;
+		device_initialize(&port->dev);
+		port->serial = serial;
+		usb_serial_get(serial);
 		serial->port[i] = port;
 	}
 
@@ -1097,15 +1105,10 @@ int usb_serial_probe(struct usb_interfac
 	/* register all of the individual ports with the driver core */
 	for (i = 0; i < num_ports; ++i) {
 		port = serial->port[i];
-		port->dev.parent = &interface->dev;
-		port->dev.driver = NULL;
-		port->dev.bus = &usb_serial_bus_type;
-		port->dev.release = &port_release;
-
 		dev_set_name(&port->dev, "ttyUSB%d", port->number);
 		dbg ("%s - registering %s", __func__, dev_name(&port->dev));
 		port->dev_state = PORT_REGISTERING;
-		retval = device_register(&port->dev);
+		retval = device_add(&port->dev);
 		if (retval) {
 			dev_err(&port->dev, "Error registering port device, "
 				"continuing\n");
@@ -1123,41 +1126,13 @@ exit:
 	return 0;
 
 probe_error:
-	for (i = 0; i < num_bulk_in; ++i) {
-		port = serial->port[i];
-		if (!port)
-			continue;
-		usb_free_urb(port->read_urb);
-		kfree(port->bulk_in_buffer);
-	}
-	for (i = 0; i < num_bulk_out; ++i) {
-		port = serial->port[i];
-		if (!port)
-			continue;
-		if (port->write_fifo)
-			kfifo_free(port->write_fifo);
-		usb_free_urb(port->write_urb);
-		kfree(port->bulk_out_buffer);
-	}
-	for (i = 0; i < num_interrupt_in; ++i) {
-		port = serial->port[i];
-		if (!port)
-			continue;
-		usb_free_urb(port->interrupt_in_urb);
-		kfree(port->interrupt_in_buffer);
-	}
-	for (i = 0; i < num_interrupt_out; ++i) {
+	/* free all the ports, along with their URBs */
+	for (i = 0; i < serial->num_port_pointers; ++i) {
 		port = serial->port[i];
-		if (!port)
-			continue;
-		usb_free_urb(port->interrupt_out_urb);
-		kfree(port->interrupt_out_buffer);
+		if (port)
+			put_device(&port->dev);
 	}
-
-	/* free up any memory that we allocated */
-	for (i = 0; i < serial->num_port_pointers; ++i)
-		kfree(serial->port[i]);
-	kfree(serial);
+	usb_serial_put(serial);
 	return -EIO;
 }
 EXPORT_SYMBOL_GPL(usb_serial_probe);
@@ -1205,6 +1180,7 @@ void usb_serial_disconnect(struct usb_in
 				port->dev_state = PORT_UNREGISTERED;
 			}
 		}
+		put_device(&port->dev);
 	}
 	serial->type->disconnect(serial);
 
@@ -1269,7 +1245,7 @@ static const struct tty_operations seria
 	.chars_in_buffer =	serial_chars_in_buffer,
 	.tiocmget =		serial_tiocmget,
 	.tiocmset =		serial_tiocmset,
-	.shutdown = 		serial_do_free,
+	.shutdown = 		serial_shutdown,
 	.install = 		serial_install,
 	.proc_fops =		&serial_proc_fops,
 };


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-24  1:24                                                       ` Alan Stern
@ 2009-08-24 20:15                                                         ` Bruno Prémont
  2009-08-25  1:42                                                           ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-24 20:15 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Sun, 23 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:

> On Sun, 23 Aug 2009, Bruno [UTF-8] Prémont wrote:
> 
> > On Sun, 23 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> > > I have a big patch almost ready for testing.  Unfortunately I
> > > don't have access to my usual hardware right now, so I can't test
> > > it until the middle of the week.  Bruno, if you like I will send
> > > you the patch when it looks okay and you can try it out.
> > 
> > Fine for me, I can test every week-day during evening as well as
> > during week-end (European time, UTC+2).
> > If there are any specific tests (other than the surviving of
> > disconnect) that I shall run, just ask!
> 
> Here it is.  This is meant to apply on top of gregkh-all-2.6.31-rc6;  
> it replaces the small patch you tried earlier.  In fact this ought to
> be split up into at least four individual patches, but you can test it
> all in one piece.
> 
> Surviving disconnect, ability to reconnect, deallocating memory 
> (destroy_serial and port_free) at the right time...  Anything else
> you can think of.
> 
> Alan Stern
> 
> P.S.: You may already have the first part, with the changes to
> tty_port.c.
Yep, that one was already included


The patch does not work properly:

When I plug in the USB2serial converter (be it ftdi or pl2302) device
node is created properly and minicom can use it.

When I exit minicom I can no longer start it again, eventually I get
a killed minicom with NULL-dereference

A rmmod/modprobe cycle works but the end result is no device node
created by udev and udev's path_id helper is stuck. (unable to
determine where for now as netconsole causes trouble with netdev
polling)
I will have a deeper look tomorrow as this evening is already over.

Bruno


Trace result for ftdi device:
[   75.620038] usb 1-2: new full speed USB device using uhci_hcd and address 2
[   75.838941] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[   75.844208] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   75.849432] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[   75.854628] usb 1-2: Manufacturer: FTDI
[   75.859783] usb 1-2: SerialNumber: FTS55QK6
[   75.866989] usb 1-2: configuration #1 chosen from 1 choice
[   76.001724] usbcore: registered new interface driver usbserial
[   76.006901] usbserial: USB Serial Driver core
[   76.085962] USB Serial support registered for FTDI USB Serial Device
[   76.091471] usb 1-2: Ignoring serial port reserved for JTAG
[   76.093889] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[   76.096350] usb 1-2: Detected FT2232C
[   76.098739] usb 1-2: Number of endpoints 2
[   76.101418] usb 1-2: Endpoint 1 MaxPacketSize 64
[   76.103792] usb 1-2: Endpoint 2 MaxPacketSize 64
[   76.106153] usb 1-2: Setting MaxPacketSize 64
[   76.111012] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[   76.113433] usbcore: registered new interface driver ftdi_sio
[   76.115797] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  163.471333] BUG: unable to handle kernel NULL pointer dereference at 00000064
[  163.471531] IP: [<c115f7ae>] tty_open+0x11e/0x4b0
[  163.471650] *pde = 00000000 
[  163.471730] Oops: 0000 [#1] 
[  163.471809] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  163.471944] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd snd_page_alloc ehci_hcd pcspkr i2c_i801 uhci_hcd usbcore crc_ccitt
[  163.472927] 
[  163.472967] Pid: 2157, comm: minicom Tainted: G   M       (2.6.31-rc6-gregkh #2) TravelMate 660
[  163.473148] EIP: 0060:[<c115f7ae>] EFLAGS: 00010246 CPU: 0
[  163.473247] EIP is at tty_open+0x11e/0x4b0
[  163.473338] EAX: dba89000 EBX: dbdb2480 ECX: 00000000 EDX: 00000000
[  163.473449] ESI: dd24d400 EDI: 0bc00000 EBP: db646e70 ESP: db646e4c
[  163.473575]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  163.473673] Process minicom (pid: 2157, ti=db646000 task=dd9ae7c0 task.ti=db646000)
[  163.473833] Stack:
[  163.473873]  dbdb2484 dbe24e00 dba8e67c 00000902 00000100 00000000 00000000 dbdb2488
[  163.474133] <0> dba8e67c db646e8c c1077246 dbe24e00 db646e98 dbe24e00 dba8e67c 00000000
[  163.474431] <0> db646ea8 c1072fdf dd8afb00 dd524f00 dbe24e00 db646ef4 dbe24e00 db646ec4
[  163.474751] Call Trace:
[  163.474808]  [<c1077246>] ? chrdev_open+0x96/0x140
[  163.474918]  [<c1072fdf>] ? __dentry_open+0x9f/0x250
[  163.475012]  [<c1073279>] ? nameidata_to_filp+0x59/0x70
[  163.475124]  [<c10771b0>] ? chrdev_open+0x0/0x140
[  163.475214]  [<c107f569>] ? do_filp_open+0x269/0x890
[  163.475324]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  163.475417]  [<c1072da7>] ? do_sys_open+0x57/0x140
[  163.475525]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  163.475619]  [<c1072ef9>] ? sys_open+0x29/0x40
[  163.475719]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  163.475811] Code: d0 89 45 f0 8d 43 04 89 45 dc e8 9e f7 f9 ff 85 db 74 ca 85 f6 0f 84 22 02 00 00 80 be 84 00 00 00 00 8b 56 08 0f 88 32 01 00 00 <66> 83 7a 64 04 75 0b 66 83 7a 66 01 0f 84 05 01 00 00 ff 86 88 
[  163.477244] EIP: [<c115f7ae>] tty_open+0x11e/0x4b0 SS:ESP 0068:db646e4c
[  163.477410] CR2: 0000000000000064
[  163.477472] ---[ end trace e2a30538356d938d ]---

# Plug-in
# minicom
# exit minicom
# minicom
#   (it can't open serial port & exits)
# minicom
#   -> havok
# rmmod + modprobe
# minicom
#   (ad infinitum as no dev node,
#    udev fails to recreate device node: hangs on path_id)



Similar results for pl2302:
[   69.260039] usb 1-1: new full speed USB device using uhci_hcd and address 2
[   69.426990] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[   69.427000] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[   69.427008] usb 1-1: Product: USB-Serial Controller
[   69.427015] usb 1-1: Manufacturer: Prolific Technology Inc.
[   69.427242] usb 1-1: configuration #1 chosen from 1 choice
[   69.558897] usbcore: registered new interface driver usbserial
[   69.558906] usbserial: USB Serial Driver core
[   69.612215] USB Serial support registered for pl2303
[   69.612267] pl2303 1-1:1.0: pl2303 converter detected
[   69.624165] usb 1-1: pl2303 converter now attached to ttyUSB0
[   69.624205] usbcore: registered new interface driver pl2303
[   69.624211] pl2303: Prolific PL2303 USB to serial adaptor driver
[  140.790070] usb 1-1: USB disconnect, address 2
[  140.793165] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
[  140.796051] pl2303 1-1:1.0: device disconnected
[  147.280036] usb 1-1: new full speed USB device using uhci_hcd and address 3
[  147.446990] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[  147.449674] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  147.452428] usb 1-1: Product: USB-Serial Controller
[  147.455149] usb 1-1: Manufacturer: Prolific Technology Inc.
[  147.459847] usb 1-1: configuration #1 chosen from 1 choice
[  147.466047] pl2303 1-1:1.0: pl2303 converter detected
[  147.479158] usb 1-1: pl2303 converter now attached to ttyUSB0
[  168.770687] BUG: unable to handle kernel paging request at 697665c8
[  168.770876] IP: [<c115f7ae>] tty_open+0x11e/0x4b0
[  168.770995] *pde = 00000000 
[  168.771075] Oops: 0000 [#1] 
[  168.771154] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  168.771304] Modules linked in: pl2303 usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec ac97_bus snd_pcm snd_timer ehci_hcd snd uhci_hcd usbcore pcspkr snd_page_alloc nsc_ircc i2c_i801 irda crc_ccitt
[  168.772283] 
[  168.772322] Pid: 2166, comm: minicom Tainted: G   M       (2.6.31-rc6-gregkh #2) TravelMate 660
[  168.772503] EIP: 0060:[<c115f7ae>] EFLAGS: 00010202 CPU: 0
[  168.772602] EIP is at tty_open+0x11e/0x4b0
[  168.772694] EAX: db661800 EBX: db07c6c0 ECX: 00000000 EDX: 69766564
[  168.772804] ESI: db17e000 EDI: 0bc00000 EBP: db17ae70 ESP: db17ae4c
[  168.772944]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  168.773041] Process minicom (pid: 2166, ti=db17a000 task=dd9ae7c0 task.ti=db17a000)
[  168.773202] Stack:
[  168.773242]  db07c6c4 dd07d200 dd33c4f4 00000902 00000100 00000000 00000000 db07c6c8
[  168.773502] <0> dd33c4f4 db17ae8c c1077246 dd07d200 00000000 dd07d200 dd33c4f4 00000000
[  168.773799] <0> db17aea8 c1072fdf dd8d2680 dd502e80 dd07d200 db17aef4 dd07d200 db17aec4
[  168.774120] Call Trace:
[  168.774177]  [<c1077246>] ? chrdev_open+0x96/0x140
[  168.774287]  [<c1072fdf>] ? __dentry_open+0x9f/0x250
[  168.774380]  [<c1073279>] ? nameidata_to_filp+0x59/0x70
[  168.774492]  [<c10771b0>] ? chrdev_open+0x0/0x140
[  168.774582]  [<c107f569>] ? do_filp_open+0x269/0x890
[  168.774691]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  168.774784]  [<c1072da7>] ? do_sys_open+0x57/0x140
[  168.774893]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  168.774987]  [<c1072ef9>] ? sys_open+0x29/0x40
[  168.775088]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  168.775180] Code: d0 89 45 f0 8d 43 04 89 45 dc e8 9e f7 f9 ff 85 db 74 ca 85 f6 0f 84 22 02 00 00 80 be 84 00 00 00 00 8b 56 08 0f 88 32 01 00 00 <66> 83 7a 64 04 75 0b 66 83 7a 66 01 0f 84 05 01 00 00 ff 86 88 
[  168.776606] EIP: [<c115f7ae>] tty_open+0x11e/0x4b0 SS:ESP 0068:db17ae4c
[  168.776772] CR2: 00000000697665c8
[  168.776836] ---[ end trace f7ba75fd75a3f993 ]---


For both cases EIP is at:
  drivers/char/tty_io.c:1253:
1246:static int tty_reopen(struct tty_struct *tty)
1247:{
1248:	struct tty_driver *driver = tty->driver;
...
1253:	if (driver->type == TTY_DRIVER_TYPE_PTY &&
1254:	    driver->subtype == PTY_TYPE_MASTER) {

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-24 20:15                                                         ` Bruno Prémont
@ 2009-08-25  1:42                                                           ` Alan Stern
  2009-08-25 20:19                                                             ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-25  1:42 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Mon, 24 Aug 2009, Bruno [UTF-8] Prémont wrote:

> The patch does not work properly:
> 
> When I plug in the USB2serial converter (be it ftdi or pl2302) device
> node is created properly and minicom can use it.
> 
> When I exit minicom I can no longer start it again, eventually I get
> a killed minicom with NULL-dereference
> 
> A rmmod/modprobe cycle works but the end result is no device node
> created by udev and udev's path_id helper is stuck. (unable to
> determine where for now as netconsole causes trouble with netdev
> polling)
> I will have a deeper look tomorrow as this evening is already over.
> 
> Bruno
> 
> 
> Trace result for ftdi device:

> [   76.115797] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
> [  163.471333] BUG: unable to handle kernel NULL pointer dereference at 00000064
> [  163.471531] IP: [<c115f7ae>] tty_open+0x11e/0x4b0
> [  163.471650] *pde = 00000000 
> [  163.471730] Oops: 0000 [#1] 
> [  163.471809] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
> [  163.471944] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 nsc_ircc snd_ac97_codec ac97_bus irda snd_pcm snd_timer snd snd_page_alloc ehci_hcd pcspkr i2c_i801 uhci_hcd usbcore crc_ccitt
> [  163.472927] 
> [  163.472967] Pid: 2157, comm: minicom Tainted: G   M       (2.6.31-rc6-gregkh #2) TravelMate 660
> [  163.473148] EIP: 0060:[<c115f7ae>] EFLAGS: 00010246 CPU: 0
> [  163.473247] EIP is at tty_open+0x11e/0x4b0

> For both cases EIP is at:
>   drivers/char/tty_io.c:1253:
> 1246:static int tty_reopen(struct tty_struct *tty)
> 1247:{
> 1248:	struct tty_driver *driver = tty->driver;
> ...
> 1253:	if (driver->type == TTY_DRIVER_TYPE_PTY &&
> 1254:	    driver->subtype == PTY_TYPE_MASTER) {

Okay, thanks for trying it out.  

Apparently the tty isn't getting removed from the driver the way it
should when minicom closes it the first time.  And no wonder -- I just
realized that my new serial_shutdown() routine doesn't call
tty_shutdown(tty).  Try inserting such a call right before
tty->driver_data gets set to NULL.

The division of labor between the TTY core and the lower drivers makes 
very little sense...

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-25  1:42                                                           ` Alan Stern
@ 2009-08-25 20:19                                                             ` Bruno Prémont
  2009-08-25 23:42                                                               ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-25 20:19 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Mon, 24 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> Apparently the tty isn't getting removed from the driver the way it
> should when minicom closes it the first time.  And no wonder -- I just
> realized that my new serial_shutdown() routine doesn't call
> tty_shutdown(tty).  Try inserting such a call right before
> tty->driver_data gets set to NULL.

Done that, it brings us to n_tty_set_termios() this time:

[  107.990039] usb 2-2: new full speed USB device using uhci_hcd and address 2
[  108.208982] usb 2-2: New USB device found, idVendor=9e88, idProduct=9e8f
[  108.208992] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  108.209000] usb 2-2: Product: SheevaPlug JTAGKey FT2232D B
[  108.209007] usb 2-2: Manufacturer: FTDI
[  108.209013] usb 2-2: SerialNumber: FTS55QK6
[  108.209243] usb 2-2: configuration #1 chosen from 1 choice
[  108.323938] usbcore: registered new interface driver usbserial
[  108.323943] usbserial: USB Serial Driver core
[  108.357581] USB Serial support registered for FTDI USB Serial Device
[  108.357819] usb 2-2: Ignoring serial port reserved for JTAG
[  108.357924] ftdi_sio 2-2:1.1: FTDI USB Serial Device converter detected
[  108.357990] usb 2-2: Detected FT2232C
[  108.357996] usb 2-2: Number of endpoints 2
[  108.358003] usb 2-2: Endpoint 1 MaxPacketSize 64
[  108.358009] usb 2-2: Endpoint 2 MaxPacketSize 64
[  108.358015] usb 2-2: Setting MaxPacketSize 64
[  108.360175] usb 2-2: FTDI USB Serial Device converter now attached to ttyUSB0
[  108.360216] usbcore: registered new interface driver ftdi_sio
[  108.360223] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  200.248102] BUG: unable to handle kernel NULL pointer dereference at 0000000c
[  200.248257] IP: [<c115ff36>] n_tty_set_termios+0x1a6/0x410
[  200.248369] *pde = 00000000 
[  200.248429] Oops: 0000 [#1] 
[  200.248489] last sysfs file: /sys/devices/virtual/hwmon/hwmon0/temp1_input
[  200.248607] Modules linked in: ftdi_sio usbserial squashfs zlib_inflate nfs lockd nfs_acl sunrpc 8021q snd_pcm_oss snd_mixer_oss xfs exportfs loop usb_storage snd_intel8x0 snd_ac97_codec nsc_ircc ac97_bus irda snd_pcm pcspkr i2c_i801 snd_timer uhci_hcd ehci_hcd snd snd_page_alloc crc_ccitt usbcore
[  200.249280] 
[  200.249317] Pid: 2155, comm: minicom Tainted: G   M       (2.6.31-rc6-gregkh #2) TravelMate 660
[  200.249466] EIP: 0060:[<c115ff36>] EFLAGS: 00010246 CPU: 0
[  200.249563] EIP is at n_tty_set_termios+0x1a6/0x410
[  200.249649] EAX: 00000000 EBX: dbdd9000 ECX: 00000000 EDX: 00000000
[  200.249757] ESI: 00000000 EDI: 00000000 EBP: dd2dade8 ESP: dd2dadd8
[  200.249866]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[  200.249962] Process minicom (pid: 2155, ti=dd2da000 task=dd91b500 task.ti=dd2da000)
[  200.250090] Stack:
[  200.250129]  c11616ab dbdd9000 dbdd9000 00000000 dd2dadf4 c11617db dbaf20e8 dd2dae04
[  200.250312] <0> c1164280 dbdd9000 dbdd9000 dd2dae20 c1164432 dbaf20e8 dbdd9000 dbdd9000
[  200.250514] <0> db953a80 dbdd9000 dd2dae44 c115f5b9 dd2dae7c dd2daef4 00000000 00000000
[  200.250722] Call Trace:
[  200.250773]  [<c11616ab>] ? reset_buffer_flags+0xab/0xe0
[  200.250870]  [<c11617db>] ? n_tty_open+0x3b/0x90
[  200.250954]  [<c1164280>] ? tty_ldisc_open+0x30/0x50
[  200.251044]  [<c1164432>] ? tty_ldisc_setup+0x22/0x70
[  200.251135]  [<c115f5b9>] ? tty_init_dev+0x89/0x160
[  200.251223]  [<c115f9fc>] ? tty_open+0x36c/0x4b0
[  200.251310]  [<c1077246>] ? chrdev_open+0x96/0x140
[  200.251400]  [<c1072fdf>] ? __dentry_open+0x9f/0x250
[  200.251490]  [<c1073279>] ? nameidata_to_filp+0x59/0x70
[  200.251584]  [<c10771b0>] ? chrdev_open+0x0/0x140
[  200.251672]  [<c107f569>] ? do_filp_open+0x269/0x890
[  200.251762]  [<c1038c5c>] ? ktime_get_ts+0x4c/0x50
[  200.251852]  [<c1072da7>] ? do_sys_open+0x57/0x140
[  200.251943]  [<c1026d55>] ? alarm_setitimer+0x35/0x70
[  200.252035]  [<c1072ef9>] ? sys_open+0x29/0x40
[  200.252116]  [<c1002e08>] ? sysenter_do_call+0x12/0x26
[  200.252205] Code: 31 c0 f3 ab 0f b6 93 2c 01 00 00 31 f6 8b 83 60 01 00 00 8b 7b 30 89 b3 74 03 00 00 80 e2 fd 89 83 78 03 00 00 88 93 2c 01 00 00 <8b> 47 0c 83 e0 02 0f 85 8a fe ff ff 8b 8b 64 01 00 00 85 c9 0f 
[  200.252995] EIP: [<c115ff36>] n_tty_set_termios+0x1a6/0x410 SS:ESP 0068:dd2dadd8
[  200.253134] CR2: 000000000000000c
[  200.253225] ---[ end trace f4b79a25ac2c3be9 ]---

My actions:
  plug-in ftdi
  run minicom
  exit minicom
  run minicom -> bang

Bang at:
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1456

1449:	if (canon_change) {
1450:		memset(&tty->read_flags, 0, sizeof tty->read_flags);
1451:		tty->canon_head = tty->read_tail;
1452:		tty->canon_data = 0;
1453:		tty->erasing = 0;
1454:	}
1455:
1456:	if (canon_change && !L_ICANON(tty) && tty->read_cnt)
1457:		wake_up_interruptible(&tty->read_wait);

Not sure which part of the if() it is that explodes, I would guess
it's !L_ICANON(tty):

	#define ICANON      0000002
	#define _L_FLAG(tty, f) ((tty)->termios->c_lflag & (f))
	#define L_ICANON(tty)  _L_FLAG((tty), ICANON)
=>
	if (canon_change && !((tty)->termios->c_lflag & (ICANON)) && tty->read_cnt)
=>
	tty->termios is probably NULL


Anyhow, here is the matching extract of objdump for n_tty.o:
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1453
     37f:       0f b6 93 2c 01 00 00    movzbl 0x12c(%ebx),%edx
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1452
     386:       31 f6                   xor    %esi,%esi
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1451
     388:       8b 83 60 01 00 00       mov    0x160(%ebx),%eax
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1456
     38e:       8b 7b 30                mov    0x30(%ebx),%edi
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1452
     391:       89 b3 74 03 00 00       mov    %esi,0x374(%ebx)
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1453
     397:       80 e2 fd                and    $0xfd,%dl
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1451
     39a:       89 83 78 03 00 00       mov    %eax,0x378(%ebx)
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1453
     3a0:       88 93 2c 01 00 00       mov    %dl,0x12c(%ebx)
/tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1456
>    3a6:       8b 47 0c                mov    0xc(%edi),%eax
     3a9:       83 e0 02                and    $0x2,%eax
     3ac:       0f 85 8a fe ff ff       jne    23c <n_tty_set_termios+0x3c>
     3b2:       8b 8b 64 01 00 00       mov    0x164(%ebx),%ecx
     3b8:       85 c9                   test   %ecx,%ecx
     3ba:       0f 84 7c fe ff ff       je     23c <n_tty_set_termios+0x3c>



Some further notes:
- disconnect causes the device to vanish and minicom to tell so.
  Quit minicom works without complaint. Any restart produces
  the same effect as above
- after this trace some lock remains taken that causes processes
  to stall (processes ending up in D state)
- when booting with this kernel some part of the init sequence
  never shows up on screen (e.g. everything from init's runlevel
  3 is missing and getty's prompt shows up with some delay compared
  to gettys on other VTs.


Bruno

^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-25 20:19                                                             ` Bruno Prémont
@ 2009-08-25 23:42                                                               ` Alan Stern
  2009-08-26 20:32                                                                 ` Bruno Prémont
  0 siblings, 1 reply; 42+ messages in thread
From: Alan Stern @ 2009-08-25 23:42 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Tue, 25 Aug 2009, Bruno [UTF-8] Prémont wrote:

> On Mon, 24 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> > Apparently the tty isn't getting removed from the driver the way it
> > should when minicom closes it the first time.  And no wonder -- I just
> > realized that my new serial_shutdown() routine doesn't call
> > tty_shutdown(tty).  Try inserting such a call right before
> > tty->driver_data gets set to NULL.
> 
> Done that, it brings us to n_tty_set_termios() this time:

> [  200.248102] BUG: unable to handle kernel NULL pointer dereference at 0000000c
> [  200.248257] IP: [<c115ff36>] n_tty_set_termios+0x1a6/0x410

> My actions:
>   plug-in ftdi
>   run minicom
>   exit minicom
>   run minicom -> bang
> 
> Bang at:
> /tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1456
> 
> 1449:	if (canon_change) {
> 1450:		memset(&tty->read_flags, 0, sizeof tty->read_flags);
> 1451:		tty->canon_head = tty->read_tail;
> 1452:		tty->canon_data = 0;
> 1453:		tty->erasing = 0;
> 1454:	}
> 1455:
> 1456:	if (canon_change && !L_ICANON(tty) && tty->read_cnt)
> 1457:		wake_up_interruptible(&tty->read_wait);
> 
> Not sure which part of the if() it is that explodes, I would guess
> it's !L_ICANON(tty):
> 
> 	#define ICANON      0000002
> 	#define _L_FLAG(tty, f) ((tty)->termios->c_lflag & (f))
> 	#define L_ICANON(tty)  _L_FLAG((tty), ICANON)
> =>
> 	if (canon_change && !((tty)->termios->c_lflag & (ICANON)) && tty->read_cnt)
> =>
> 	tty->termios is probably NULL

Unquestionably that is the problem.

It looks like something is wrong in serial_install().  We want to call 
tty_init_termios(tty) always, regardless of whether 
tty->driver->termios[idx] is NULL.  But after the call it definitely 
won't be NULL, so the test has to be made before the call is done.  
Something like this:

	struct ktermios *t = tty->driver->termios[idx];

	/* perform the standard setup */
	retval = tty_init_termios(tty);
	if (retval)
		return retval;

	/* If the specialized termios setup has yet to be done */
	if (!t) {
		...

Want to try that?

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-25 23:42                                                               ` Alan Stern
@ 2009-08-26 20:32                                                                 ` Bruno Prémont
  2009-08-27  2:19                                                                   ` Alan Stern
  0 siblings, 1 reply; 42+ messages in thread
From: Bruno Prémont @ 2009-08-26 20:32 UTC (permalink / raw)
  To: Alan Stern
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Tue, 25 August 2009 Alan Stern <stern@rowland.harvard.edu> wrote:
> On Tue, 25 Aug 2009, Bruno Prémont wrote:
> > Bang at:
> > /tmp/linux-2.6.31-rc6-gregkh/drivers/char/n_tty.c:1456
> > 
> > 1456:	if (canon_change && !L_ICANON(tty) && tty->read_cnt)
> > 1457:		wake_up_interruptible(&tty->read_wait);
> > 
> > 	#define ICANON      0000002
> > 	#define _L_FLAG(tty, f) ((tty)->termios->c_lflag & (f))
> > 	#define L_ICANON(tty)  _L_FLAG((tty), ICANON)
> > =>
> > 	if (canon_change && !((tty)->termios->c_lflag & (ICANON)) && tty->read_cnt)
> > =>
> > 	tty->termios is probably NULL
> 
> Unquestionably that is the problem.
> 
> It looks like something is wrong in serial_install().  We want to
> call tty_init_termios(tty) always, regardless of whether 
> tty->driver->termios[idx] is NULL.  But after the call it definitely 
> won't be NULL, so the test has to be made before the call is done.  
> Something like this:
> 
> 	struct ktermios *t = tty->driver->termios[idx];
> 
> 	/* perform the standard setup */
> 	retval = tty_init_termios(tty);
> 	if (retval)
> 		return retval;
> 
> 	/* If the specialized termios setup has yet to be done */
> 	if (!t) {
> 		...
> 
> Want to try that?

Change applied to usb-serial.c, serial_instal().
Tried it out with both pl2302 and ftdi-sio, no visible issues!

Actions I tried: connect, disconnect (with minicom running as well as
without), start/stop minicom multiple times.

I've seen nothing unexpected or bad in kernel log (just a note that
some sending failed while typing into minicom and pulling the USB
plug: pl2303_write_bulk_callback - failed resubmitting write urb, error -19)

Bruno


Full log while trying out:
[   96.060039] usb 1-2: new full speed USB device using uhci_hcd and address 2
[   96.278980] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[   96.279105] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   96.279249] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[   96.279346] usb 1-2: Manufacturer: FTDI
[   96.279433] usb 1-2: SerialNumber: FTS55QK6
[   96.279746] usb 1-2: configuration #1 chosen from 1 choice
[   96.386173] usbcore: registered new interface driver usbserial
[   96.386245] usbserial: USB Serial Driver core
[   96.448488] USB Serial support registered for FTDI USB Serial Device
[   96.448888] usb 1-2: Ignoring serial port reserved for JTAG
[   96.449106] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[   96.449296] usb 1-2: Detected FT2232C
[   96.449367] usb 1-2: Number of endpoints 2
[   96.449460] usb 1-2: Endpoint 1 MaxPacketSize 64
[   96.449544] usb 1-2: Endpoint 2 MaxPacketSize 64
[   96.449643] usb 1-2: Setting MaxPacketSize 64
[   96.450799] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[   96.450895] usbcore: registered new interface driver ftdi_sio
[   96.450938] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  147.540073] usb 1-2: USB disconnect, address 2
[  147.540627] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  147.540820] ftdi_sio 1-2:1.1: device disconnected
[  177.410037] usb 1-2: new full speed USB device using uhci_hcd and address 3
[  177.628979] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[  177.629105] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  177.629251] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[  177.629349] usb 1-2: Manufacturer: FTDI
[  177.629436] usb 1-2: SerialNumber: FTS55QK6
[  177.629751] usb 1-2: configuration #1 chosen from 1 choice
[  177.637131] usb 1-2: Ignoring serial port reserved for JTAG
[  177.642161] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[  177.642379] usb 1-2: Detected FT2232C
[  177.642452] usb 1-2: Number of endpoints 2
[  177.642546] usb 1-2: Endpoint 1 MaxPacketSize 64
[  177.642629] usb 1-2: Endpoint 2 MaxPacketSize 64
[  177.642729] usb 1-2: Setting MaxPacketSize 64
[  177.643137] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[  199.790072] usb 1-2: USB disconnect, address 3
[  199.790622] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  199.790815] ftdi_sio 1-2:1.1: device disconnected
[  202.910037] usb 1-2: new full speed USB device using uhci_hcd and address 4
[  203.128984] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[  203.129101] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  203.129242] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[  203.129333] usb 1-2: Manufacturer: FTDI
[  203.129415] usb 1-2: SerialNumber: FTS55QK6
[  203.129723] usb 1-2: configuration #1 chosen from 1 choice
[  203.137131] usb 1-2: Ignoring serial port reserved for JTAG
[  203.142155] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[  203.142366] usb 1-2: Detected FT2232C
[  203.142431] usb 1-2: Number of endpoints 2
[  203.142519] usb 1-2: Endpoint 1 MaxPacketSize 64
[  203.142596] usb 1-2: Endpoint 2 MaxPacketSize 64
[  203.142691] usb 1-2: Setting MaxPacketSize 64
[  203.143150] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB1
[  266.033894] usbcore: deregistering interface driver ftdi_sio
[  266.038905] ftdi_sio ttyUSB1: FTDI USB Serial Device converter now disconnected from ttyUSB1
[  266.042730] ftdi_sio 1-2:1.1: device disconnected
[  266.045992] USB Serial deregistering driver FTDI USB Serial Device
[  284.281542] usbcore: deregistering interface driver usbserial
[  288.540072] usb 1-2: USB disconnect, address 4
[  294.000036] usb 1-2: new full speed USB device using uhci_hcd and address 5
[  294.218988] usb 1-2: New USB device found, idVendor=9e88, idProduct=9e8f
[  294.219114] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  294.219259] usb 1-2: Product: SheevaPlug JTAGKey FT2232D B
[  294.219357] usb 1-2: Manufacturer: FTDI
[  294.219443] usb 1-2: SerialNumber: FTS55QK6
[  294.219759] usb 1-2: configuration #1 chosen from 1 choice
[  294.261216] usbcore: registered new interface driver usbserial
[  294.261288] usbserial: USB Serial Driver core
[  294.267068] USB Serial support registered for FTDI USB Serial Device
[  294.267281] usb 1-2: Ignoring serial port reserved for JTAG
[  294.267383] ftdi_sio 1-2:1.1: FTDI USB Serial Device converter detected
[  294.267479] usb 1-2: Detected FT2232C
[  294.267509] usb 1-2: Number of endpoints 2
[  294.267555] usb 1-2: Endpoint 1 MaxPacketSize 64
[  294.267590] usb 1-2: Endpoint 2 MaxPacketSize 64
[  294.267639] usb 1-2: Setting MaxPacketSize 64
[  294.269091] usb 1-2: FTDI USB Serial Device converter now attached to ttyUSB0
[  294.269197] usbcore: registered new interface driver ftdi_sio
[  294.269240] ftdi_sio: v1.5.0:USB FTDI Serial Converters Driver
[  300.000027] Machine check events logged
[  723.280035] usb 1-1: new full speed USB device using uhci_hcd and address 6
[  723.446315] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[  723.450777] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  723.455164] usb 1-1: Product: USB-Serial Controller
[  723.459524] usb 1-1: Manufacturer: Prolific Technology Inc.
[  723.465908] usb 1-1: configuration #1 chosen from 1 choice
[  723.916652] USB Serial support registered for pl2303
[  723.921271] pl2303 1-1:1.0: pl2303 converter detected
[  723.935435] usb 1-1: pl2303 converter now attached to ttyUSB1
[  723.939890] usbcore: registered new interface driver pl2303
[  723.944327] pl2303: Prolific PL2303 USB to serial adaptor driver
[  739.750073] usb 1-1: USB disconnect, address 6
[  739.750909] pl2303 ttyUSB1: pl2303 converter now disconnected from ttyUSB1
[  739.751075] pl2303 1-1:1.0: device disconnected
[  743.530041] usb 1-1: new full speed USB device using uhci_hcd and address 7
[  743.696932] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[  743.697050] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  743.697190] usb 1-1: Product: USB-Serial Controller
[  743.697271] usb 1-1: Manufacturer: Prolific Technology Inc.
[  743.697600] usb 1-1: configuration #1 chosen from 1 choice
[  743.700108] pl2303 1-1:1.0: pl2303 converter detected
[  743.712094] usb 1-1: pl2303 converter now attached to ttyUSB2
[  752.250070] usb 1-1: USB disconnect, address 7
[  752.250499] usb 1-1: pl2303_write_bulk_callback - failed resubmitting write urb, error -19
[  752.251803] pl2303 ttyUSB2: pl2303 converter now disconnected from ttyUSB2
[  752.251967] pl2303 1-1:1.0: device disconnected
[  776.780035] usb 1-1: new full speed USB device using uhci_hcd and address 8
[  776.946378] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[  776.946496] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  776.946633] usb 1-1: Product: USB-Serial Controller
[  776.946716] usb 1-1: Manufacturer: Prolific Technology Inc.
[  776.947044] usb 1-1: configuration #1 chosen from 1 choice
[  776.949528] pl2303 1-1:1.0: pl2303 converter detected
[  776.961542] usb 1-1: pl2303 converter now attached to ttyUSB3
[  816.250068] usb 1-1: USB disconnect, address 8
[  816.250476] pl2303 ttyUSB3: pl2303 converter now disconnected from ttyUSB3
[  816.250644] pl2303 1-1:1.0: device disconnected
[  818.250058] usb 1-2: USB disconnect, address 5
[  818.250531] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[  818.250723] ftdi_sio 1-2:1.1: device disconnected
[  829.914462] usbcore: deregistering interface driver pl2303
[  829.915564] USB Serial deregistering driver pl2303
[  829.915958] usbcore: deregistering interface driver ftdi_sio
[  829.916113] USB Serial deregistering driver FTDI USB Serial Device
[  829.916472] usbcore: deregistering interface driver usbserial


^ permalink raw reply	[flat|nested] 42+ messages in thread

* Re: 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use
  2009-08-26 20:32                                                                 ` Bruno Prémont
@ 2009-08-27  2:19                                                                   ` Alan Stern
  0 siblings, 0 replies; 42+ messages in thread
From: Alan Stern @ 2009-08-27  2:19 UTC (permalink / raw)
  To: Bruno Prémont
  Cc: Alan Cox, Greg KH, Kernel development list, USB list, Rafael J. Wysocki

On Wed, 26 Aug 2009, Bruno [UTF-8] Prémont wrote:

> Change applied to usb-serial.c, serial_instal().
> Tried it out with both pl2302 and ftdi-sio, no visible issues!
> 
> Actions I tried: connect, disconnect (with minicom running as well as
> without), start/stop minicom multiple times.
> 
> I've seen nothing unexpected or bad in kernel log (just a note that
> some sending failed while typing into minicom and pulling the USB
> plug: pl2303_write_bulk_callback - failed resubmitting write urb, error -19)

Great!  Okay, I'll break this up into a bunch of logically separate 
patches and submit them for 2.6.32.  When they have gotten sufficient 
testing, they can be back-ported into 2.6.31.stable.

Alan Stern


^ permalink raw reply	[flat|nested] 42+ messages in thread

end of thread, other threads:[~2009-08-27  2:19 UTC | newest]

Thread overview: 42+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2009-08-08 17:47 2.6.31-rc5 regression: Oops when USB Serial disconnected while in use Bruno Prémont
2009-08-09 14:02 ` Ozan Çağlayan
2009-08-09 15:00   ` Alan Stern
2009-08-10 15:18 ` Alan Stern
2009-08-10 15:44   ` Greg KH
2009-08-10 17:18     ` Bruno Prémont
2009-08-10 18:13       ` Greg KH
2009-08-10 18:35         ` Bruno Prémont
2009-08-10 18:51           ` Bruno Prémont
2009-08-10 19:29             ` Greg KH
2009-08-18 17:00               ` Bruno Prémont
2009-08-18 22:36                 ` Greg KH
2009-08-18 23:16                   ` Greg KH
2009-08-19 17:22                   ` Bruno Prémont
2009-08-19 18:20                     ` Alan Stern
2009-08-19 20:15                       ` Bruno Prémont
2009-08-19 21:01                         ` Alan Stern
2009-08-19 21:50                           ` Alan Cox
2009-08-19 22:44                             ` Alan Stern
2009-08-20 19:25                               ` Bruno Prémont
2009-08-20 21:20                                 ` Alan Stern
2009-08-21  9:25                                   ` Bruno Prémont
2009-08-21 15:43                                     ` Alan Stern
2009-08-21 15:48                                       ` Alan Cox
2009-08-21 17:39                                         ` Alan Stern
2009-08-21 18:42                                           ` Alan Cox
2009-08-21 20:52                                             ` Alan Stern
2009-08-21 23:16                                               ` Alan Cox
2009-08-22  2:30                                                 ` Alan Stern
2009-08-23  2:51                                                 ` Alan Stern
2009-08-23 16:15                                                   ` Alan Stern
2009-08-23 16:30                                                     ` Bruno Prémont
2009-08-24  1:24                                                       ` Alan Stern
2009-08-24 20:15                                                         ` Bruno Prémont
2009-08-25  1:42                                                           ` Alan Stern
2009-08-25 20:19                                                             ` Bruno Prémont
2009-08-25 23:42                                                               ` Alan Stern
2009-08-26 20:32                                                                 ` Bruno Prémont
2009-08-27  2:19                                                                   ` Alan Stern
2009-08-21 16:50                                       ` Bruno Prémont
2009-08-20 21:58                                 ` Alan Cox
2009-08-21 14:02                                   ` Alan Stern

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.