Re: Endless print of uhci_result_common: failed with status 440000

Re: Endless print of uhci_result_common: failed with status 440000

[Zdenek Kabelac]

2011/4/11 Alan Stern <stern@rowland.harvard.edu>:
> On Mon, 11 Apr 2011, Zdenek Kabelac wrote:
>
>> Ok - add some more memory debug:
>>
>> [   13.347268] usb 1-1: USB disconnect, device number 3
>> [   13.348113] btusb_bulk_complete: hci0 urb ffff8801367f6528 failed
>> to resubmit (19)
>> [   13.349111] btusb_intr_complete: hci0 urb ffff8801367f6840 failed
>> to resubmit (19)
>> [   13.349143] btusb_bulk_complete: hci0 urb ffff8801367fa630 failed
>> to resubmit (19)
>> [   13.409856] general protection fault: 0000 [#1] PREEMPT SMP
>> [   13.413340] last sysfs file:
>> /sys/devices/pci0000:00/0000:00:19.0/net/eth0/uevent
>> [   13.413340] CPU 0
>> [   13.413340] Modules linked in: ipt_REJECT xt_physdev xt_state
>> iptable_filter ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4
>> nf_conntrack nf_defrag_ipv4 ip_tables x_tables dm_mirror
>> dm_region_hash dm_log dm_mod snd_hda_codec_analog btusb bluetooth
>> virtio_net kvm_intel kvm arc4 ecb crypto_blkcipher cryptomgr aead
>> crypto_algapi iwl3945 iwl_legacy snd_hda_intel snd_hda_codec usbhid
>> snd_seq snd_seq_device mac80211 hid iTCO_wdt iTCO_vendor_support
>> snd_pcm psmouse i2c_i801 serio_raw cfg80211 thinkpad_acpi snd_timer
>> snd e1000e soundcore snd_page_alloc nvram wmi evdev i915
>> drm_kms_helper drm i2c_algo_bit i2c_core uinput autofs4 pcmcia
>> uhci_hcd ehci_hcd sdhci_pci sdhci sr_mod mmc_core yenta_socket cdrom
>> usbcore video backlight [last unloaded: scsi_wait_scan]
>> [   13.413340]
>> [   13.413340] Pid: 815, comm: bluetoothd Not tainted
>> 2.6.39-rc2-00144-gca71856 #121 LENOVO 6464CTO/6464CTO
>> [   13.413340] RIP: 0010:[<ffffffff8109ae43>]  [<ffffffff8109ae43>]
>> module_put+0x33/0x1b0
>> [   13.413340] RSP: 0018:ffff8801389e1d68  EFLAGS: 00010296
>> [   13.413340] RAX: ffffffffa04a32a6 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000
>> [   13.413340] RDX: 0000000000000000 RSI: ffffffffa04a32a6 RDI: ffffffff8109ae43
>> [   13.413340] RBP: ffff8801389e1d98 R08: 0000000000000000 R09: 0000000000000000
>> [   13.413340] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88013b028590
>> [   13.413340] R13: 00000000ffffffed R14: ffff8801390ac7b0 R15: 000000000000000a
>> [   13.413340] FS:  00007fe99d67d720(0000) GS:ffff88013ba00000(0000)
>> knlGS:0000000000000000
>> [   13.413340] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>> [   13.413340] CR2: 00007fe99d4902b0 CR3: 0000000134dea000 CR4: 00000000000006f0
>> [   13.413340] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> [   13.413340] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
>> [   13.413340] Process bluetoothd (pid: 815, threadinfo
>> ffff8801389e0000, task ffff8801387d23a0)
>> [   13.413340] Stack:
>> [   13.413340]  ffff88013b028000 ffff88013b028000 ffff88013b028590
>> 00000000ffffffed
>> [   13.413340]  ffff8801390ac7b0 000000000000000a ffff8801389e1de8
>> ffffffffa04a32a6
>> [   13.413340]  ffff8801389e1db8 ffffffff8124f11a ffff8801389e1dd8
>> 00000000400448c9
>> [   13.413340] Call Trace:
>> [   13.413340]  [<ffffffffa04a32a6>] hci_dev_open+0x96/0x3f0 [bluetooth]
>> [   13.413340]  [<ffffffff8124f11a>] ? security_capable+0x2a/0x30
>> [   13.413340]  [<ffffffffa04b0172>] hci_sock_ioctl+0x1e2/0x4b0 [bluetooth]
>
>> So - it looks like disabling BT in runtime is not enough  to avoid problems ;)
>>
>> So I've blacklisted  bluetooth & btusb -  and made quite several
>> suspend/resume cycles  -
>> and without  a single problem.
>>
>> So I'll keep an eye on this - but so far complete deactivation of BT
>> either in BIOS or modules blacklisting solves the problem of weird
>> USB deadlocking.
>
> Clearly there's something going wrong in the Bluetooth drivers.  You
> should try posting some of this on the linux-bluetooth mailing list.

I've created:

https://bugzilla.kernel.org/show_bug.cgi?id=33062

and I'm cc-ing linux-bluetooth.

Zdenek

Re: Endless print of uhci_result_common: failed with status 440000

[Zdenek Kabelac]

2011/4/11 Zdenek Kabelac <zdenek.kabelac@gmail.com>:
> 2011/4/11 Alan Stern <stern@rowland.harvard.edu>:
>> On Mon, 11 Apr 2011, Zdenek Kabelac wrote:
>>
>>> Ok - add some more memory debug:
>>>
>>> [   13.347268] usb 1-1: USB disconnect, device number 3
>>> [   13.348113] btusb_bulk_complete: hci0 urb ffff8801367f6528 failed
>>> to resubmit (19)
>>> [   13.349111] btusb_intr_complete: hci0 urb ffff8801367f6840 failed
>>> to resubmit (19)
>>> [   13.349143] btusb_bulk_complete: hci0 urb ffff8801367fa630 failed
>>> to resubmit (19)
>>> [   13.409856] general protection fault: 0000 [#1] PREEMPT SMP
>>> [   13.413340] last sysfs file:
>>> /sys/devices/pci0000:00/0000:00:19.0/net/eth0/uevent
>>> [   13.413340] CPU 0
>>> [   13.413340] Modules linked in: ipt_REJECT xt_physdev xt_state
>>> iptable_filter ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4
>>> nf_conntrack nf_defrag_ipv4 ip_tables x_tables dm_mirror
>>> dm_region_hash dm_log dm_mod snd_hda_codec_analog btusb bluetooth
>>> virtio_net kvm_intel kvm arc4 ecb crypto_blkcipher cryptomgr aead
>>> crypto_algapi iwl3945 iwl_legacy snd_hda_intel snd_hda_codec usbhid
>>> snd_seq snd_seq_device mac80211 hid iTCO_wdt iTCO_vendor_support
>>> snd_pcm psmouse i2c_i801 serio_raw cfg80211 thinkpad_acpi snd_timer
>>> snd e1000e soundcore snd_page_alloc nvram wmi evdev i915
>>> drm_kms_helper drm i2c_algo_bit i2c_core uinput autofs4 pcmcia
>>> uhci_hcd ehci_hcd sdhci_pci sdhci sr_mod mmc_core yenta_socket cdrom
>>> usbcore video backlight [last unloaded: scsi_wait_scan]
>>> [   13.413340]
>>> [   13.413340] Pid: 815, comm: bluetoothd Not tainted
>>> 2.6.39-rc2-00144-gca71856 #121 LENOVO 6464CTO/6464CTO
>>> [   13.413340] RIP: 0010:[<ffffffff8109ae43>]  [<ffffffff8109ae43>]
>>> module_put+0x33/0x1b0
>>> [   13.413340] RSP: 0018:ffff8801389e1d68  EFLAGS: 00010296
>>> [   13.413340] RAX: ffffffffa04a32a6 RBX: 6b6b6b6b6b6b6b6b RCX: 0000000000000000
>>> [   13.413340] RDX: 0000000000000000 RSI: ffffffffa04a32a6 RDI: ffffffff8109ae43
>>> [   13.413340] RBP: ffff8801389e1d98 R08: 0000000000000000 R09: 0000000000000000
>>> [   13.413340] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88013b028590
>>> [   13.413340] R13: 00000000ffffffed R14: ffff8801390ac7b0 R15: 000000000000000a
>>> [   13.413340] FS:  00007fe99d67d720(0000) GS:ffff88013ba00000(0000)
>>> knlGS:0000000000000000
>>> [   13.413340] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>>> [   13.413340] CR2: 00007fe99d4902b0 CR3: 0000000134dea000 CR4: 00000000000006f0
>>> [   13.413340] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>>> [   13.413340] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
>>> [   13.413340] Process bluetoothd (pid: 815, threadinfo
>>> ffff8801389e0000, task ffff8801387d23a0)
>>> [   13.413340] Stack:
>>> [   13.413340]  ffff88013b028000 ffff88013b028000 ffff88013b028590
>>> 00000000ffffffed
>>> [   13.413340]  ffff8801390ac7b0 000000000000000a ffff8801389e1de8
>>> ffffffffa04a32a6
>>> [   13.413340]  ffff8801389e1db8 ffffffff8124f11a ffff8801389e1dd8
>>> 00000000400448c9
>>> [   13.413340] Call Trace:
>>> [   13.413340]  [<ffffffffa04a32a6>] hci_dev_open+0x96/0x3f0 [bluetooth]
>>> [   13.413340]  [<ffffffff8124f11a>] ? security_capable+0x2a/0x30
>>> [   13.413340]  [<ffffffffa04b0172>] hci_sock_ioctl+0x1e2/0x4b0 [bluetooth]
>>
>>> So - it looks like disabling BT in runtime is not enough  to avoid problems ;)
>>>
>>> So I've blacklisted  bluetooth & btusb -  and made quite several
>>> suspend/resume cycles  -
>>> and without  a single problem.
>>>
>>> So I'll keep an eye on this - but so far complete deactivation of BT
>>> either in BIOS or modules blacklisting solves the problem of weird
>>> USB deadlocking.
>>
>> Clearly there's something going wrong in the Bluetooth drivers.  You
>> should try posting some of this on the linux-bluetooth mailing list.
>
> I've created:
>
> https://bugzilla.kernel.org/show_bug.cgi?id=33062
>
> and I'm cc-ing linux-bluetooth.
>

In fact this Ooops might be related to:

http://marc.info/?l=linux-kernel&m=130207593728273&w=2

Zdenek

Re: Endless print of uhci_result_common: failed with status 440000

[Alan Stern]

On Mon, 11 Apr 2011, Zdenek Kabelac wrote:

> > I've created:
> >
> > https://bugzilla.kernel.org/show_bug.cgi?id=33062
> >
> > and I'm cc-ing linux-bluetooth.
> >
> 
> In fact this Ooops might be related to:
> 
> http://marc.info/?l=linux-kernel&m=130207593728273&w=2

It might be.  Did you try reverting the patch mentioned in that email?

Alan Stern

Re: Endless print of uhci_result_common: failed with status 440000

[Zdenek Kabelac]

2011/4/11 Alan Stern <stern@rowland.harvard.edu>:
> On Mon, 11 Apr 2011, Zdenek Kabelac wrote:
>
>> > I've created:
>> >
>> > https://bugzilla.kernel.org/show_bug.cgi?id=33062
>> >
>> > and I'm cc-ing linux-bluetooth.
>> >
>>
>> In fact this Ooops might be related to:
>>
>> http://marc.info/?l=linux-kernel&m=130207593728273&w=2
>
> It might be.  Did you try reverting the patch mentioned in that email?
>

Yep - it looks like the patch
http://marc.info/?l=linux-bluetooth&m=130230770920378&w=2
solved my problem with weird deadlocks.

Zdenek

Re: Endless print of uhci_result_common: failed with status 440000

[Alan Stern]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: TEXT/PLAIN; charset=UTF-8, Size: 647 bytes --]

On Tue, 12 Apr 2011, Zdenek Kabelac wrote:

> 2011/4/11 Alan Stern <stern@rowland.harvard.edu>:
> > On Mon, 11 Apr 2011, Zdenek Kabelac wrote:
> >
> >> > I've created:
> >> >
> >> > https://bugzilla.kernel.org/show_bug.cgi?id=33062
> >> >
> >> > and I'm cc-ing linux-bluetooth.
> >> >
> >>
> >> In fact this Ooops might be related to:
> >>
> >> http://marc.info/?l=linux-kernel&m=130207593728273&w=2
> >
> > It might be.  Did you try reverting the patch mentioned in that email?
> >
> 
> Yep - it looks like the patch
> http://marc.info/?l=linux-bluetooth&m=130230770920378&w=2
> solved my problem with weird deadlocks.

Okay, great!

Alan Stern

Re: Endless print of uhci_result_common: failed with status 440000

[Gustavo F. Padovan]

* Alan Stern <stern@rowland.harvard.edu> [2011-04-12 12:10:56 -0400]:

> On Tue, 12 Apr 2011, Zdenek Kabelac wrote:
> 
> > 2011/4/11 Alan Stern <stern@rowland.harvard.edu>:
> > > On Mon, 11 Apr 2011, Zdenek Kabelac wrote:
> > >
> > >> > I've created:
> > >> >
> > >> > https://bugzilla.kernel.org/show_bug.cgi?id=33062
> > >> >
> > >> > and I'm cc-ing linux-bluetooth.
> > >> >
> > >>
> > >> In fact this Ooops might be related to:
> > >>
> > >> http://marc.info/?l=linux-kernel&m=130207593728273&w=2
> > >
> > > It might be. ?Did you try reverting the patch mentioned in that email?
> > >
> > 
> > Yep - it looks like the patch
> > http://marc.info/?l=linux-bluetooth&m=130230770920378&w=2
> > solved my problem with weird deadlocks.

I pushed a patch that fixes this in a better way, it's on the bluetooth-2.6
tree (should arrive to linus tree in some days).

-- 
Gustavo F. Padovan
http://profusion.mobi

Re: Endless print of uhci_result_common: failed with status 440000

[Zdenek Kabelac]

2011/4/12 Gustavo F. Padovan <padovan@profusion.mobi>:
> * Alan Stern <stern@rowland.harvard.edu> [2011-04-12 12:10:56 -0400]:
>
>> On Tue, 12 Apr 2011, Zdenek Kabelac wrote:
>>
>> > 2011/4/11 Alan Stern <stern@rowland.harvard.edu>:
>> > > On Mon, 11 Apr 2011, Zdenek Kabelac wrote:
>> > >
>> > >> > I've created:
>> > >> >
>> > >> > https://bugzilla.kernel.org/show_bug.cgi?id=33062
>> > >> >
>> > >> > and I'm cc-ing linux-bluetooth.
>> > >> >
>> > >>
>> > >> In fact this Ooops might be related to:
>> > >>
>> > >> http://marc.info/?l=linux-kernel&m=130207593728273&w=2
>> > >
>> > > It might be. ?Did you try reverting the patch mentioned in that email?
>> > >
>> >
>> > Yep - it looks like the patch
>> > http://marc.info/?l=linux-bluetooth&m=130230770920378&w=2
>> > solved my problem with weird deadlocks.
>
> I pushed a patch that fixes this in a better way, it's on the bluetooth-2.6
> tree (should arrive to linus tree in some days).


hmm

Ok  - I assume you mean this patch:

http://git.kernel.org/?p=linux/kernel/git/padovan/bluetooth-2.6.git;a=commitdiff;h=b7d850641d2bc45b2320bfcb096f11406890ff3a

It seems to be detaching timer slightly differently as the one from
Keith probably.
Here is the trace I've got with older Keith's patch (which I've
believed was fine already)

iwl3945 0000:03:00.0: loaded firmware version 15.32.2.9
systemd[1]: Service bluetooth.target is not needed anymore. Stopping.
------------[ cut here ]------------
WARNING: at lib/list_debug.c:30 __list_add+0x8f/0xa0()
Hardware name: 6464CTO
list_add corruption. prev->next should be next (ffff88013b139390), but
was 2020203a6c61746f. (prev=ffff880137b63350).
Modules linked in: sunrpc ipt_REJECT xt_physdev xt_state
iptable_filter ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4
nf_conntrack nf_defrag_ipv4 ip_tables x_tables btusb bluetooth
snd_hda_codec_analog arc4 ecb crypto_blkcipher cryptomgr aead
crypto_algapi snd_hda_intel iwl3945 snd_hda_codec snd_seq iwl_legacy
snd_seq_device mac80211 snd_pcm thinkpad_acpi cfg80211 snd_timer
e1000e psmouse snd serio_raw wmi soundcore i2c_i801 snd_page_alloc
nvram iTCO_wdt iTCO_vendor_support evdev i915 dm_mirror dm_region_hash
dm_log dm_mod drm_kms_helper drm i2c_algo_bit i2c_core autofs4 usbhid
hid pcmcia sdhci_pci sdhci ehci_hcd uhci_hcd mmc_core sr_mod cdrom
yenta_socket usbcore video backlight
Pid: 44, comm: kworker/1:2 Not tainted 2.6.39-rc3-00236-g115ab9e #7
Call Trace:
 [<ffffffff810501df>] warn_slowpath_common+0x7f/0xc0
 [<ffffffff810502d6>] warn_slowpath_fmt+0x46/0x50
 [<ffffffff812988ef>] __list_add+0x8f/0xa0
 [<ffffffff810602f3>] internal_add_timer+0xb3/0x140
 [<ffffffff81062bd2>] mod_timer+0x152/0x450
 [<ffffffff81117bb6>] ? refresh_cpu_vm_stats+0x106/0x170
 [<ffffffff81062ee8>] add_timer+0x18/0x20
 [<ffffffff8106df4f>] queue_delayed_work_on+0xbf/0x140
 [<ffffffff8106f0d1>] queue_delayed_work+0x21/0x40
 [<ffffffff8106f10b>] schedule_delayed_work+0x1b/0x20
 [<ffffffff81117c71>] vmstat_update+0x51/0x60
 [<ffffffff81070c38>] process_one_work+0x1c8/0x6f0
 [<ffffffff81070bd7>] ? process_one_work+0x167/0x6f0
 [<ffffffff81493c44>] ? retint_restore_args+0xe/0xe
 [<ffffffff81117c20>] ? refresh_cpu_vm_stats+0x170/0x170
 [<ffffffff81071539>] worker_thread+0x159/0x340
 [<ffffffff810713e0>] ? rescuer_thread+0x240/0x240
 [<ffffffff810760fb>] kthread+0x9b/0xa0
 [<ffffffff8149b9d4>] kernel_thread_helper+0x4/0x10
 [<ffffffff810367a4>] ? finish_task_switch+0x74/0x110
 [<ffffffff8149367b>] ? _raw_spin_unlock_irq+0x3b/0x60
 [<ffffffff81493c44>] ? retint_restore_args+0xe/0xe
 [<ffffffff81076060>] ? __init_kthread_worker+0x70/0x70
 [<ffffffff8149b9d0>] ? gs_change+0xb/0xb
---[ end trace 9184dc8969677db3 ]---

I'll see whether new version will not show this warning.

Zdenek