2009-06-05 02:28:51

by Peter Chubb

[permalink] [raw]
Subject: Oops with minicom and USB serial with Linux 2.6.30-rc8


A new kernel this morning. Using a Prolific single-port serial
adapter to talk to a BeagleBoard. I regularly get this when I hit the
Beagle's reset button. I'm not sure I trust the traceback; I'll
rebuild with frame pointers and see if I can get a better one.


pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
pl2303 7-2.1:1.0: device disconnected
BUG: unable to handle kernel NULL pointer dereference at (null)
IP: [<c0118369>] __ticket_spin_lock+0x5/0x15
*pde = 00000000
Oops: 0002 [#1] PREEMPT SMP
last sysfs file: /sys/devices/pci0000:00/0000:00:1c.0/0000:02:00.0/rfkill/rfkill0/state
Modules linked in: ext2 mbcache nls_iso8859_1 nls_cp437 cdc_acm pl2303 usbserial kvm_intel kvm kqemu cpufreq_powersave cpufreq_userspace cpufreq_conservative snd_hda_codec_si3054 snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss uvcvideo snd_mixer_oss snd_pcm snd_timer snd iwlagn wmi soundcore snd_page_alloc ehci_hcd joydev uhci_hcd usbcore iwlcore

Pid: 7414, comm: minicom Not tainted (2.6.30-rc8 #17) HP Pavilion dv9700 Notebook PC
EIP: 0060:[<c0118369>] EFLAGS: 00010002 CPU: 1
EIP is at __ticket_spin_lock+0x5/0x15
EAX: 00000000 EBX: 00000282 ECX: 00000000 EDX: 00000100
ESI: 00001d4c EDI: f5bd6600 EBP: f52ba5a0 ESP: f5139d68
DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Process minicom (pid: 7414, ti=f5138000 task=f50db480 task.ti=f5138000)
Stack:
c01183c6 c0444a56 c01237ef 0001fcc4 00000000 f81c43a2 c20200c0 00000096
f5486000 c2022484 00000001 f5139dc8 c01364a3 c0444d3c c0188630 f81c6554
f5bd6600 f5486000 f52ba5a0 f8081708 f5133980 f5bd6658 f81c6978 f5486000
Call Trace:
[<c01183c6>] ? default_spin_lock_flags+0x5/0x7
[<c0444a56>] ? _spin_lock_irqsave+0x27/0x2e
[<c01237ef>] ? try_to_wake_up+0x1b5/0x1bf
[<f81c43a2>] ? pl2303_close+0x44/0x1af [pl2303]
[<c01364a3>] ? autoremove_wake_function+0xd/0x2d
[<c0444d3c>] ? _spin_unlock+0x5/0x1c
[<c0188630>] ? fasync_helper+0xcc/0xde
[<f8081708>] ? serial_close+0x7b/0x122 [usbserial]
[<f8081cb0>] ? serial_open+0x1e1/0x1ed [usbserial]
[<c02ccc0c>] ? tty_open+0x2b6/0x37e
[<c0181442>] ? chrdev_open+0x15d/0x174
[<c01812e5>] ? chrdev_open+0x0/0x174
[<c017daec>] ? __dentry_open+0x132/0x221
[<c017dc6c>] ? nameidata_to_filp+0x29/0x3c
[<c01881d5>] ? do_filp_open+0x402/0x77b
[<c0138823>] ? enqueue_hrtimer+0x5a/0x64
[<c0138ef7>] ? __hrtimer_start_range_ns+0x1ff/0x20b
[<c0138f10>] ? hrtimer_start+0xd/0x11
[<c0444d3c>] ? _spin_unlock+0x5/0x1c
[<c018f1d3>] ? alloc_fd+0xc3/0xcd
[<c017d8e6>] ? do_sys_open+0x44/0xb9
[<c017d99f>] ? sys_open+0x1e/0x23
[<c0103157>] ? sysenter_do_call+0x12/0x2c
Code: 89 44 24 0c 89 da 89 f0 5b 5e e9 48 fd ff ff 89 4c 24 0c 89 5c 24 10 89 f1 5b 0f b7 d2 0f b6 c0 5e e9 29 fe ff ff ba 00 01 00 00 <f0> 66 0f c1 10 38 f2 74 06 f3 90 8a 10 eb f6 c3 53 89 c3 0f b7
EIP: [<c0118369>] __ticket_spin_lock+0x5/0x15 SS:ESP 0068:f5139d68
CR2: 0000000000000000
---[ end trace c4902ecc24bb44b3 ]---
note: minicom[7414] exited with preempt_count 2
BUG: scheduling while atomic: minicom/7414/0x00000002
Modules linked in: ext2 mbcache nls_iso8859_1 nls_cp437 cdc_acm pl2303 usbserial kvm_intel kvm kqemu cpufreq_powersave cpufreq_userspace cpufreq_conservative snd_hda_codec_si3054 snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss uvcvideo snd_mixer_oss snd_pcm snd_timer snd iwlagn wmi soundcore snd_page_alloc ehci_hcd joydev uhci_hcd usbcore iwlcore
Pid: 7414, comm: minicom Tainted: G D 2.6.30-rc8 #17
Call Trace:
[<c0442cfa>] ? __schedule+0x7f/0x766
[<c01506ef>] ? rcu_process_callbacks+0x33/0x39
[<c012a791>] ? __do_softirq+0x12c/0x166
[<c012a94b>] ? irq_exit+0x36/0x62
[<c0112a16>] ? smp_apic_timer_interrupt+0x6c/0x76
[<c0103afd>] ? apic_timer_interrupt+0x31/0x38
[<c015007b>] ? cpu_quiet_msk+0x66/0x9d
[<c011d618>] ? mutex_spin_on_owner+0x43/0x5a
[<c0443a0e>] ? __mutex_lock_slowpath+0xae/0xfc
[<c04438ef>] ? mutex_lock+0x10/0x1e
[<f80816d8>] ? serial_close+0x4b/0x122 [usbserial]
[<c02ca544>] ? tty_fasync+0xc9/0xd0
[<c02cc4c2>] ? tty_release_dev+0x14c/0x3f1
[<c016f0d2>] ? remove_vma+0x3e/0x43
[<c017a9a0>] ? kmem_cache_free+0x66/0xbd
[<c02cc776>] ? tty_release+0xf/0x18
[<c017fd88>] ? __fput+0xa6/0x149
[<c017d801>] ? filp_close+0x4e/0x54
[<c0127d4d>] ? put_files_struct+0x60/0xa6
[<c01290fb>] ? do_exit+0x193/0x584
[<c04429b3>] ? printk+0xe/0x11
[<c0105ed4>] ? oops_end+0x7d/0x80
[<c0119620>] ? no_context+0x105/0x10e
[<c011971f>] ? __bad_area_nosemaphore+0xf6/0xfe
[<c011984f>] ? do_page_fault+0x0/0x1fd
[<c0119731>] ? bad_area_nosemaphore+0xa/0xc
[<c0444fb2>] ? error_code+0x7a/0x80
[<c0118369>] ? __ticket_spin_lock+0x5/0x15
[<c01183c6>] ? default_spin_lock_flags+0x5/0x7
[<c0444a56>] ? _spin_lock_irqsave+0x27/0x2e
[<c01237ef>] ? try_to_wake_up+0x1b5/0x1bf
[<f81c43a2>] ? pl2303_close+0x44/0x1af [pl2303]
[<c01364a3>] ? autoremove_wake_function+0xd/0x2d
[<c0444d3c>] ? _spin_unlock+0x5/0x1c
[<c0188630>] ? fasync_helper+0xcc/0xde
[<f8081708>] ? serial_close+0x7b/0x122 [usbserial]
[<c02cc4c2>] ? tty_release_dev+0x14c/0x3f1
[<c01db6dc>] ? xattr_lookup_poison+0x3a/0x47
[<c0444d3c>] ? _spin_unlock+0x5/0x1c
[<c018c98b>] ? __d_lookup+0xca/0x111
[<f8081682>] ? usb_serial_put+0x1c/0x27 [usbserial]
[<f8081cb0>] ? serial_open+0x1e1/0x1ed [usbserial]
[<c02ccc0c>] ? tty_open+0x2b6/0x37e
[<c0181442>] ? chrdev_open+0x15d/0x174
[<c01812e5>] ? chrdev_open+0x0/0x174
[<c017daec>] ? __dentry_open+0x132/0x221
[<c017dc6c>] ? nameidata_to_filp+0x29/0x3c
[<c01881d5>] ? do_filp_open+0x402/0x77b
[<c0138823>] ? enqueue_hrtimer+0x5a/0x64
[<c0138ef7>] ? __hrtimer_start_range_ns+0x1ff/0x20b
[<c0138f10>] ? hrtimer_start+0xd/0x11
[<c0444d3c>] ? _spin_unlock+0x5/0x1c
[<c018f1d3>] ? alloc_fd+0xc3/0xcd
[<c017d8e6>] ? do_sys_open+0x44/0xb9
[<c017d99f>] ? sys_open+0x1e/0x23
[<c0103157>] ? sysenter_do_call+0x12/0x2c



--
Dr Peter Chubb peter DOT chubb AT nicta.com.au
http://www.ertos.nicta.com.au ERTOS within National ICT Australia
Kernel Engineering Group (KEG): Where Systems Brew.


2009-06-05 03:22:07

by Andrew Morton

[permalink] [raw]
Subject: Re: Oops with minicom and USB serial with Linux 2.6.30-rc8

On Fri, 05 Jun 2009 11:37:33 +1000 Peter Chubb <[email protected]> wrote:

>
> A new kernel this morning. Using a Prolific single-port serial
> adapter to talk to a BeagleBoard. I regularly get this when I hit the
> Beagle's reset button. I'm not sure I trust the traceback; I'll
> rebuild with frame pointers and see if I can get a better one.

Thanks - the trace _is_ a bit hard to decryot.

>
> pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
> pl2303 7-2.1:1.0: device disconnected
> BUG: unable to handle kernel NULL pointer dereference at (null)
> IP: [<c0118369>] __ticket_spin_lock+0x5/0x15
> *pde = 00000000
> Oops: 0002 [#1] PREEMPT SMP
> last sysfs file: /sys/devices/pci0000:00/0000:00:1c.0/0000:02:00.0/rfkill/rfkill0/state
> Modules linked in: ext2 mbcache nls_iso8859_1 nls_cp437 cdc_acm pl2303 usbserial kvm_intel kvm kqemu cpufreq_powersave cpufreq_userspace cpufreq_conservative snd_hda_codec_si3054 snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss uvcvideo snd_mixer_oss snd_pcm snd_timer snd iwlagn wmi soundcore snd_page_alloc ehci_hcd joydev uhci_hcd usbcore iwlcore
>
> Pid: 7414, comm: minicom Not tainted (2.6.30-rc8 #17) HP Pavilion dv9700 Notebook PC
> EIP: 0060:[<c0118369>] EFLAGS: 00010002 CPU: 1
> EIP is at __ticket_spin_lock+0x5/0x15
> EAX: 00000000 EBX: 00000282 ECX: 00000000 EDX: 00000100
> ESI: 00001d4c EDI: f5bd6600 EBP: f52ba5a0 ESP: f5139d68
> DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> Process minicom (pid: 7414, ti=f5138000 task=f50db480 task.ti=f5138000)
> Stack:
> c01183c6 c0444a56 c01237ef 0001fcc4 00000000 f81c43a2 c20200c0 00000096
> f5486000 c2022484 00000001 f5139dc8 c01364a3 c0444d3c c0188630 f81c6554
> f5bd6600 f5486000 f52ba5a0 f8081708 f5133980 f5bd6658 f81c6978 f5486000
> Call Trace:
> [<c01183c6>] ? default_spin_lock_flags+0x5/0x7
> [<c0444a56>] ? _spin_lock_irqsave+0x27/0x2e
> [<c01237ef>] ? try_to_wake_up+0x1b5/0x1bf
> [<f81c43a2>] ? pl2303_close+0x44/0x1af [pl2303]
> [<c01364a3>] ? autoremove_wake_function+0xd/0x2d
> [<c0444d3c>] ? _spin_unlock+0x5/0x1c
> [<c0188630>] ? fasync_helper+0xcc/0xde
> [<f8081708>] ? serial_close+0x7b/0x122 [usbserial]
> [<f8081cb0>] ? serial_open+0x1e1/0x1ed [usbserial]
> [<c02ccc0c>] ? tty_open+0x2b6/0x37e
> [<c0181442>] ? chrdev_open+0x15d/0x174
> [<c01812e5>] ? chrdev_open+0x0/0x174
> [<c017daec>] ? __dentry_open+0x132/0x221
> [<c017dc6c>] ? nameidata_to_filp+0x29/0x3c
> [<c01881d5>] ? do_filp_open+0x402/0x77b
> [<c0138823>] ? enqueue_hrtimer+0x5a/0x64
> [<c0138ef7>] ? __hrtimer_start_range_ns+0x1ff/0x20b
> [<c0138f10>] ? hrtimer_start+0xd/0x11
> [<c0444d3c>] ? _spin_unlock+0x5/0x1c
> [<c018f1d3>] ? alloc_fd+0xc3/0xcd
> [<c017d8e6>] ? do_sys_open+0x44/0xb9
> [<c017d99f>] ? sys_open+0x1e/0x23
> [<c0103157>] ? sysenter_do_call+0x12/0x2c
> Code: 89 44 24 0c 89 da 89 f0 5b 5e e9 48 fd ff ff 89 4c 24 0c 89 5c 24 10 89 f1 5b 0f b7 d2 0f b6 c0 5e e9 29 fe ff ff ba 00 01 00 00 <f0> 66 0f c1 10 38 f2 74 06 f3 90 8a 10 eb f6 c3 53 89 c3 0f b7
> EIP: [<c0118369>] __ticket_spin_lock+0x5/0x15 SS:ESP 0068:f5139d68
> CR2: 0000000000000000

hm, that's the second report of a sys_open->serial_close oops this week.

I don't recall whether we found out what caused the other one?

2009-06-05 04:00:55

by Peter Chubb

[permalink] [raw]
Subject: Re: Oops with minicom and USB serial with Linux 2.6.30-rc8

I rebuilt with frame pointers and debug symbols.
I see lots and lots of:

....
usb 2-2: clear tt 1 (1042) error -71
usb 2-2: clear tt 1 (1042) error -71
usb 2-2: clear tt 1 (1042) error -71
usb 2-2: clear tt 1 (1042) error -71
usb 2-2: clear tt 1 (1042) error -71
usb 2-2: clear tt 1 (1042) error -71
usb 2-2.3: USB disconnect, address 14

Investigations continue... usb 2-2 is the hub to which the PL2303
is attached.

I now see a similar traceback to before, not when I press the reset
button, but when I remove the USB connector.

pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
pl2303 2-2.1:1.0: device disconnected
BUG: unable to handle kernel NULL pointer dereference at 00000014
IP: [<c0149336>] __lock_acquire+0x91/0x12bf
*pde = 00000000
Oops: 0000 [#1] PREEMPT SMP
last sysfs file: /sys/devices/pci0000:00/0000:00:1c.0/0000:02:00.0/rfkill/rfkill
0/state
Modules linked in: cdc_acm kvm_intel kvm kqemu cpufreq_powersave cpufreq_userspace cpufreq_conservative snd_hda_codec_si3054 snd_hda_codec_realtek
snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss
snd_pcm snd_timer iwlagn snd uhci_hcd pl2303 usbserial iwlcore joydev
wmi uvcvideo soundcore snd_page_alloc

Pid: 7718, comm: minicom Not tainted (2.6.30-rc8 #20) HP Pavilion dv9700 Notebook PC
EIP: 0060:[<c0149336>] EFLAGS: 00010046 CPU: 0
EIP is at __lock_acquire+0x91/0x12bf
EAX: 00000046 EBX: 00000046 ECX: 00000010 EDX: 00000002
ESI: 00000000 EDI: 00000000 EBP: f48d3d00 ESP: f48d3c78
DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Process minicom (pid: 7718, ti=f48d2000 task=f4fe08c0 task.ti=f48d2000)
Stack:
f72875ac f4fe0c80 f4fe08c0 f4fe08c0 f48d3d18 00000046 00000002 00000000
00000000 00000010 f4fe08c0 00000000 00000002 00000000 00000000 f6066918
f4fe08c0 f4fe0c70 00000000 00000001 f4fe08c0 f4fe0c88 00000001 00000000
Call Trace:
[<c014a617>] ? lock_acquire+0xb3/0xd6
[<f8628435>] ? pl2303_close+0x48/0x1af [pl2303]
[<c04878c5>] ? _spin_lock_irqsave+0x39/0x49
[<f8628435>] ? pl2303_close+0x48/0x1af [pl2303]
[<f8628435>] ? pl2303_close+0x48/0x1af [pl2303]
[<c04861fc>] ? mutex_lock_nested+0x286/0x2a0
[<f80f7a21>] ? serial_close+0x86/0x12d [usbserial]
[<c02e6a9d>] ? tty_release_dev+0x188/0x423
[<c0485ac4>] ? __mutex_unlock_slowpath+0xf0/0x111
[<c01487df>] ? trace_hardirqs_on_caller+0x103/0x124
[<c0485aed>] ? mutex_unlock+0x8/0xa
[<f80f7998>] ? usb_serial_put+0x2b/0x2e [usbserial]
[<f80f8010>] ? serial_open+0x1fd/0x209 [usbserial]
[<c048770d>] ? _spin_unlock+0x27/0x3c
[<c02e7206>] ? tty_open+0x2c0/0x38a
[<c018fdaa>] ? chrdev_open+0x16b/0x183
[<c018c13d>] ? __dentry_open+0x146/0x23b
[<c018c2cc>] ? nameidata_to_filp+0x2c/0x43
[<c018fc3f>] ? chrdev_open+0x0/0x183
[<c0196f55>] ? do_filp_open+0x3bd/0x6ee
[<c013e85a>] ? __hrtimer_start_range_ns+0x220/0x22b
[<c0289a45>] ? _raw_spin_unlock+0x78/0x7e
[<c019e859>] ? alloc_fd+0xc8/0xd2
[<c018bf1c>] ? do_sys_open+0x44/0xc0
[<c01032a8>] ? sysenter_exit+0xf/0x1f
[<c018bfda>] ? sys_open+0x1e/0x26
[<c010326f>] ? sysenter_do_call+0x12/0x3c
Code: c0 00 0f 84 07 11 00 00 e9 cd 11 00 00 83 7d 98 07 76 0f e8 01 e2 13 00 68 62 0b 57 c0 e9 84 11 00 00 83 7d 98 00 75 0e 8b 4d 9c <8b> 59 04 85 db 0f 85 0e 03 00 00 8b 75 9c 83 3e 00 75 02 89 36

--
Dr Peter Chubb peter DOT chubb AT nicta.com.au
http://www.ertos.nicta.com.au ERTOS within National ICT Australia
Kernel Engineering Group (KEG): Where Systems Brew.

2009-06-05 15:08:58

by Alan Stern

[permalink] [raw]
Subject: Re: Oops with minicom and USB serial with Linux 2.6.30-rc8

On Fri, 5 Jun 2009, Peter Chubb wrote:

> I rebuilt with frame pointers and debug symbols.
> I see lots and lots of:
>
> ....
> usb 2-2: clear tt 1 (1042) error -71
> usb 2-2: clear tt 1 (1042) error -71
> usb 2-2: clear tt 1 (1042) error -71
> usb 2-2: clear tt 1 (1042) error -71
> usb 2-2: clear tt 1 (1042) error -71
> usb 2-2: clear tt 1 (1042) error -71
> usb 2-2.3: USB disconnect, address 14
>
> Investigations continue... usb 2-2 is the hub to which the PL2303
> is attached.
>
> I now see a similar traceback to before, not when I press the reset
> button, but when I remove the USB connector.

A couple of relevant patches were posted recently:

http://marc.info/?l=linux-usb&m=124395806322087&w=2
http://marc.info/?l=linux-usb&m=124395806222085&w=2

The second is more revelant than the first, but it might not apply
without the first one.

Alan Stern