All of lore.kernel.org
 help / color / mirror / Atom feed
* re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
@ 2011-02-28 22:29 Mikko Vinni
  2011-03-01  5:51 ` Justin Mattock
  2011-03-02 14:00 ` Johan Hedberg
  0 siblings, 2 replies; 25+ messages in thread
From: Mikko Vinni @ 2011-02-28 22:29 UTC (permalink / raw)
  To: linux-bluetooth
  Cc: Justin P. Mattock, Ed Tomlinson, Gustavo F. Padovan, Johan Hedberg

Hi all,

Just wondering what is the status of "bluetooth disabled with current 
2.6.38-rc4"
from Justin (http://www.spinics.net/lists/linux-bluetooth/msg10745.html) and
"[BUG] usb problems in .38-rc3+"" (http://marc.info/?t=129693396800003&r=1&w=2)
from Ed? (apologies for not being able to reply to those threads)

The first one because I think I see the same problem and the second one because
for me also "hciconfig -a" makes the bluetooth adapter work. Maybe they have
a common cause.

For me, reverting 23bb57633df ("Bluetooth: Fix __hci_request synchronization
for hci_open_dev"; suggested by Justin) on top of
2.6.38-rc6-166-g493f335 makes everything work as before.

bluez version and bluetooth adapter model:

[root@koni ~]# pacman -Qo /usr/sbin/bluetoothd
/usr/sbin/bluetoothd is owned by bluez 4.89-1
[root@koni ~]# lsusb | grep i.Tech
Bus 003 Device 002: ID 13dd:0001 i.Tech Dynamic Limited

Part of bluetoothd -d dump below. The printout only really got started when
I run "hciconfig -a" after 22:01:42 (hciconfig hci0 down and hciconfig hci0 up
can also be used to make it work):

[root@koni ~]# hciconfig
hci0:   Type: BR/EDR  Bus: USB
        BD Address: 00:0D:3C:38:xx:yy  ACL MTU: 384:8  SCO MTU: 64:8
        UP RUNNING
        RX bytes:356 acl:0 sco:0 events:13 errors:0
        TX bytes:53 acl:0 sco:0 commands:13 errors:0

[root@koni ~]# date
Mon Feb 28 22:01:42 EET 2011
[root@koni ~]# hciconfig -a
hci0:   Type: BR/EDR  Bus: USB
        BD Address: 00:0D:3C:38:xx:yy  ACL MTU: 384:8  SCO MTU: 64:8
        UP RUNNING
        RX bytes:356 acl:0 sco:0 events:13 errors:0
        TX bytes:53 acl:0 sco:0 commands:13 errors:0
        Features: 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
        Packet type: DM1 DH1 HV1
        Link policy:
        Link mode: SLAVE ACCEPT
        Name: 'CSR - bc4'
        Class: 0x000000
        Service Classes: Unspecified
        Device Class: Miscellaneous,
        HCI Version: 2.0 (0x3)  Revision: 0x7a6
        LMP Version: 2.0 (0x3)  Subversion: 0x7a6
        Manufacturer: Cambridge Silicon Radio (10)


Feb 28 21:55:39 koni bluetoothd[3256]: src/rfkill.c:rfkill_event() RFKILL event 
idx 0 type 1 op 0 soft 1 hard 0
Feb 28 21:55:39 koni bluetoothd[3256]: plugins/hciops.c:init_known_adapters() 
Feb 28 21:56:14 koni blueman-mechanism: Starting blueman-mechanism 
Feb 28 21:56:14 koni kernel: fuse init (API version 7.16)
Feb 28 21:56:14 koni blueman-mechanism: reload 0 0 
Feb 28 21:56:15 koni kernel: Bluetooth: RFCOMM TTY layer initialized
Feb 28 21:56:15 koni kernel: Bluetooth: RFCOMM socket layer initialized
Feb 28 21:56:15 koni kernel: Bluetooth: RFCOMM ver 1.11
Feb 28 21:56:28 koni kernel: usb 6-1: new full speed USB device using ohci_hcd 
and address 2
Feb 28 21:56:29 koni kernel: usb 6-1: New USB device found, idVendor=13dd, 
idProduct=0001
Feb 28 21:56:29 koni kernel: usb 6-1: New USB device strings: Mfr=1, Product=2, 
SerialNumber=0
Feb 28 21:56:29 koni kernel: usb 6-1: Product: BlueCON U2
Feb 28 21:56:29 koni kernel: usb 6-1: Manufacturer: i.Tech Dynamic
Feb 28 21:56:29 koni kernel: Bluetooth: Generic Bluetooth USB driver ver 0.6
Feb 28 21:56:29 koni bluetoothd[3256]: src/rfkill.c:rfkill_event() RFKILL event 
idx 1 type 2 op 0 soft 0 hard 0
Feb 28 21:56:29 koni bluetoothd[3256]: HCI dev 0 registered
Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:init_device() hci0
Feb 28 21:56:29 koni bluetoothd[3256]: Listening for HCI events on hci0
Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:init_device() child 3317 
forked
Feb 28 21:56:29 koni bluetoothd[3256]: src/rfkill.c:rfkill_event() RFKILL event 
idx 1 type 2 op 2 soft 0 hard 0
Feb 28 21:56:29 koni kernel: usbcore: registered new interface driver btusb
Feb 28 21:56:29 koni bluetoothd[3256]: 
plugins/hciops.c:read_local_version_complete() Got version for hci0
Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:read_bd_addr_complete() 
hci0 status 0
Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:read_bd_addr_complete() 
Got bdaddr for hci0
Feb 28 21:56:29 koni bluetoothd[3256]: 
plugins/hciops.c:read_local_name_complete() hci0 status 0
Feb 28 21:56:29 koni bluetoothd[3256]: 
plugins/hciops.c:read_local_name_complete() Got name for hci0
Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:child_exit() child 3317 
exited
Feb 28 21:56:29 koni bluetoothd[3256]: HCI dev 0 up
Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:device_devup_setup() 
hci0
Feb 28 21:56:44 koni blueman-mechanism: Exiting 
Feb 28 22:01:45 koni bluetoothd[3256]: 
plugins/hciops.c:read_local_name_complete() hci0 status 0
Feb 28 22:01:45 koni bluetoothd[3256]: 
plugins/hciops.c:read_local_name_complete() Got name for hci0
Feb 28 22:01:45 koni bluetoothd[3256]: 
plugins/hciops.c:read_local_features_complete() Got features for hci0
Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref() 
0x7f2d7b862e10: ref=1
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:hciops_read_bdaddr() 
hci0
Feb 28 22:01:45 koni bluetoothd[3256]: 
plugins/hciops.c:hciops_read_local_version() hci0
Feb 28 22:01:45 koni bluetoothd[3256]: 
plugins/hciops.c:hciops_read_local_features() hci0
Feb 28 22:01:45 koni bluetoothd[3256]: 
src/sdpd-database.c:sdp_init_services_list() 

Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:hciops_add_uuid() hci0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:update_service_classes() 
hci0 value 0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:hciops_add_uuid() hci0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:update_service_classes() 
hci0 value 0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:hciops_add_uuid() hci0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:update_service_classes() 
hci0 value 16
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:hciops_add_uuid() hci0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/hciops.c:update_service_classes() 
hci0 value 16
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/service.c:register_interface() 
path /org/bluez/3256/hci0
Feb 28 22:01:45 koni bluetoothd[3256]: plugins/service.c:register_interface() 
Registered interface org.bluez.Service on path /org/bluez/3256/hci0
Feb 28 22:01:45 koni bluetoothd[3256]: network/manager.c:network_server_probe() 
path /org/bluez/3256/hci0
Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref() 
0x7f2d7b862e10: ref=2
Feb 28 22:01:45 koni bluetoothd[3256]: network/server.c:server_register() 
Registered interface org.bluez.NetworkServer on path /org/bluez/3256/hci0
Feb 28 22:01:45 koni bluetoothd[3256]: serial/manager.c:proxy_probe() path 
/org/bluez/3256/hci0
Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref() 
0x7f2d7b862e10: ref=3
Feb 28 22:01:45 koni bluetoothd[3256]: serial/proxy.c:proxy_register() 
Registered interface org.bluez.SerialProxyManager on path /org/bluez/3256/hci0
Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref() 
0x7f2d7b862e10: ref=4
...

Mikko


      

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-02-28 22:29 re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+" Mikko Vinni
@ 2011-03-01  5:51 ` Justin Mattock
  2011-03-02 14:00 ` Johan Hedberg
  1 sibling, 0 replies; 25+ messages in thread
From: Justin Mattock @ 2011-03-01  5:51 UTC (permalink / raw)
  To: Mikko Vinni
  Cc: linux-bluetooth, Ed Tomlinson, Gustavo F. Padovan, Johan Hedberg


On Feb 28, 2011, at 2:29 PM, Mikko Vinni wrote:

> Hi all,
>
> Just wondering what is the status of "bluetooth disabled with current
> 2.6.38-rc4"
> from Justin (http://www.spinics.net/lists/linux-bluetooth/msg10745.html 
> ) and
> "[BUG] usb problems in .38-rc3+"" (http://marc.info/?t=129693396800003&r=1&w=2 
> )
> from Ed? (apologies for not being able to reply to those threads)
>
good im not going crazy!!!(thought I was the only one)

> The first one because I think I see the same problem and the second  
> one because
> for me also "hciconfig -a" makes the bluetooth adapter work. Maybe  
> they have
> a common cause.
>
> For me, reverting 23bb57633df ("Bluetooth: Fix __hci_request  
> synchronization
> for hci_open_dev"; suggested by Justin) on top of
> 2.6.38-rc6-166-g493f335 makes everything work as before.
>

thankfully the revert is not that big.. if/when I get time(in the  
process of relocating)
I would not mind going through that commit and plucking things to find  
exactly what's causing
the problem then go from there(if somebody gets to that before, Ill  
gladly supply info and/or test anything
for them!!)

> bluez version and bluetooth adapter model:
>
> [root@koni ~]# pacman -Qo /usr/sbin/bluetoothd
> /usr/sbin/bluetoothd is owned by bluez 4.89-1
> [root@koni ~]# lsusb | grep i.Tech
> Bus 003 Device 002: ID 13dd:0001 i.Tech Dynamic Limited
>
> Part of bluetoothd -d dump below. The printout only really got  
> started when
> I run "hciconfig -a" after 22:01:42 (hciconfig hci0 down and  
> hciconfig hci0 up
> can also be used to make it work):
>
> [root@koni ~]# hciconfig
> hci0:   Type: BR/EDR  Bus: USB
>        BD Address: 00:0D:3C:38:xx:yy  ACL MTU: 384:8  SCO MTU: 64:8
>        UP RUNNING
>        RX bytes:356 acl:0 sco:0 events:13 errors:0
>        TX bytes:53 acl:0 sco:0 commands:13 errors:0
>
> [root@koni ~]# date
> Mon Feb 28 22:01:42 EET 2011
> [root@koni ~]# hciconfig -a
> hci0:   Type: BR/EDR  Bus: USB
>        BD Address: 00:0D:3C:38:xx:yy  ACL MTU: 384:8  SCO MTU: 64:8
>        UP RUNNING
>        RX bytes:356 acl:0 sco:0 events:13 errors:0
>        TX bytes:53 acl:0 sco:0 commands:13 errors:0
>        Features: 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
>        Packet type: DM1 DH1 HV1
>        Link policy:
>        Link mode: SLAVE ACCEPT
>        Name: 'CSR - bc4'
>        Class: 0x000000
>        Service Classes: Unspecified
>        Device Class: Miscellaneous,
>        HCI Version: 2.0 (0x3)  Revision: 0x7a6
>        LMP Version: 2.0 (0x3)  Subversion: 0x7a6
>        Manufacturer: Cambridge Silicon Radio (10)
>
>
> Feb 28 21:55:39 koni bluetoothd[3256]: src/rfkill.c:rfkill_event()  
> RFKILL event
> idx 0 type 1 op 0 soft 1 hard 0
> Feb 28 21:55:39 koni bluetoothd[3256]: plugins/ 
> hciops.c:init_known_adapters()
> Feb 28 21:56:14 koni blueman-mechanism: Starting blueman-mechanism
> Feb 28 21:56:14 koni kernel: fuse init (API version 7.16)
> Feb 28 21:56:14 koni blueman-mechanism: reload 0 0
> Feb 28 21:56:15 koni kernel: Bluetooth: RFCOMM TTY layer initialized
> Feb 28 21:56:15 koni kernel: Bluetooth: RFCOMM socket layer  
> initialized
> Feb 28 21:56:15 koni kernel: Bluetooth: RFCOMM ver 1.11
> Feb 28 21:56:28 koni kernel: usb 6-1: new full speed USB device  
> using ohci_hcd
> and address 2
> Feb 28 21:56:29 koni kernel: usb 6-1: New USB device found,  
> idVendor=13dd,
> idProduct=0001
> Feb 28 21:56:29 koni kernel: usb 6-1: New USB device strings: Mfr=1,  
> Product=2,
> SerialNumber=0
> Feb 28 21:56:29 koni kernel: usb 6-1: Product: BlueCON U2
> Feb 28 21:56:29 koni kernel: usb 6-1: Manufacturer: i.Tech Dynamic
> Feb 28 21:56:29 koni kernel: Bluetooth: Generic Bluetooth USB driver  
> ver 0.6
> Feb 28 21:56:29 koni bluetoothd[3256]: src/rfkill.c:rfkill_event()  
> RFKILL event
> idx 1 type 2 op 0 soft 0 hard 0
> Feb 28 21:56:29 koni bluetoothd[3256]: HCI dev 0 registered
> Feb 28 21:56:29 koni bluetoothd[3256]: plugins/ 
> hciops.c:init_device() hci0
> Feb 28 21:56:29 koni bluetoothd[3256]: Listening for HCI events on  
> hci0
> Feb 28 21:56:29 koni bluetoothd[3256]: plugins/ 
> hciops.c:init_device() child 3317
> forked
> Feb 28 21:56:29 koni bluetoothd[3256]: src/rfkill.c:rfkill_event()  
> RFKILL event
> idx 1 type 2 op 2 soft 0 hard 0
> Feb 28 21:56:29 koni kernel: usbcore: registered new interface  
> driver btusb
> Feb 28 21:56:29 koni bluetoothd[3256]:
> plugins/hciops.c:read_local_version_complete() Got version for hci0
> Feb 28 21:56:29 koni bluetoothd[3256]: plugins/ 
> hciops.c:read_bd_addr_complete()
> hci0 status 0
> Feb 28 21:56:29 koni bluetoothd[3256]: plugins/ 
> hciops.c:read_bd_addr_complete()
> Got bdaddr for hci0
> Feb 28 21:56:29 koni bluetoothd[3256]:
> plugins/hciops.c:read_local_name_complete() hci0 status 0
> Feb 28 21:56:29 koni bluetoothd[3256]:
> plugins/hciops.c:read_local_name_complete() Got name for hci0
> Feb 28 21:56:29 koni bluetoothd[3256]: plugins/hciops.c:child_exit()  
> child 3317
> exited
> Feb 28 21:56:29 koni bluetoothd[3256]: HCI dev 0 up
> Feb 28 21:56:29 koni bluetoothd[3256]: plugins/ 
> hciops.c:device_devup_setup()
> hci0
> Feb 28 21:56:44 koni blueman-mechanism: Exiting
> Feb 28 22:01:45 koni bluetoothd[3256]:
> plugins/hciops.c:read_local_name_complete() hci0 status 0
> Feb 28 22:01:45 koni bluetoothd[3256]:
> plugins/hciops.c:read_local_name_complete() Got name for hci0
> Feb 28 22:01:45 koni bluetoothd[3256]:
> plugins/hciops.c:read_local_features_complete() Got features for hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref()
> 0x7f2d7b862e10: ref=1
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:hciops_read_bdaddr()
> hci0
> Feb 28 22:01:45 koni bluetoothd[3256]:
> plugins/hciops.c:hciops_read_local_version() hci0
> Feb 28 22:01:45 koni bluetoothd[3256]:
> plugins/hciops.c:hciops_read_local_features() hci0
> Feb 28 22:01:45 koni bluetoothd[3256]:
> src/sdpd-database.c:sdp_init_services_list()
>
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:hciops_add_uuid() hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:update_service_classes()
> hci0 value 0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:hciops_add_uuid() hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:update_service_classes()
> hci0 value 0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:hciops_add_uuid() hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:update_service_classes()
> hci0 value 16
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:hciops_add_uuid() hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> hciops.c:update_service_classes()
> hci0 value 16
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> service.c:register_interface()
> path /org/bluez/3256/hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: plugins/ 
> service.c:register_interface()
> Registered interface org.bluez.Service on path /org/bluez/3256/hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: network/ 
> manager.c:network_server_probe()
> path /org/bluez/3256/hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref()
> 0x7f2d7b862e10: ref=2
> Feb 28 22:01:45 koni bluetoothd[3256]: network/ 
> server.c:server_register()
> Registered interface org.bluez.NetworkServer on path /org/bluez/3256/ 
> hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: serial/ 
> manager.c:proxy_probe() path
> /org/bluez/3256/hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref()
> 0x7f2d7b862e10: ref=3
> Feb 28 22:01:45 koni bluetoothd[3256]: serial/proxy.c:proxy_register()
> Registered interface org.bluez.SerialProxyManager on path /org/bluez/ 
> 3256/hci0
> Feb 28 22:01:45 koni bluetoothd[3256]: src/adapter.c:btd_adapter_ref()
> 0x7f2d7b862e10: ref=4
> ...
>
> Mikko
>
>
>


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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-02-28 22:29 re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+" Mikko Vinni
  2011-03-01  5:51 ` Justin Mattock
@ 2011-03-02 14:00 ` Johan Hedberg
  2011-03-03 10:54   ` Mikko Vinni
  1 sibling, 1 reply; 25+ messages in thread
From: Johan Hedberg @ 2011-03-02 14:00 UTC (permalink / raw)
  To: Mikko Vinni
  Cc: linux-bluetooth, Justin P. Mattock, Ed Tomlinson, Gustavo F. Padovan

Hi,

On Mon, Feb 28, 2011, Mikko Vinni wrote:
> Just wondering what is the status of "bluetooth disabled with current 
> 2.6.38-rc4"
> from Justin (http://www.spinics.net/lists/linux-bluetooth/msg10745.html) and
> "[BUG] usb problems in .38-rc3+"" (http://marc.info/?t=129693396800003&r=1&w=2)
> from Ed? (apologies for not being able to reply to those threads)
> 
> The first one because I think I see the same problem and the second one because
> for me also "hciconfig -a" makes the bluetooth adapter work. Maybe they have
> a common cause.

I can't reproduce this issue with any of my Bluetooth adapters (I tested
with 6 different ones). Could you get us the hcidump of what happens
when bluetoothd tries to switch on the adapter for the very first time?
Probably you'll need to disable starting of bluetoothd when your system
boots so that you have the chance to run hcidump first. Additionally, if
possible, could you enable dynamic debug in your kernel and get the logs
from hci_core.c and hci_event.c? Typically you'd enable this with
something like:

echo 'file hci_event.c +p' > /sys/kernel/debug/dynamic_debug/control
echo 'file hci_core.c +p' > /sys/kernel/debug/dynamic_debug/control

Hopefully those logs will give some better idea of what's going on since
the logs provided so far aren't really helpful.

Johan

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-02 14:00 ` Johan Hedberg
@ 2011-03-03 10:54   ` Mikko Vinni
  2011-03-03 14:31     ` Johan Hedberg
  0 siblings, 1 reply; 25+ messages in thread
From: Mikko Vinni @ 2011-03-03 10:54 UTC (permalink / raw)
  To: Johan Hedberg
  Cc: linux-bluetooth, Justin P. Mattock, Ed Tomlinson, Gustavo F. Padovan

From: Johan Hedberg:

> 
> I can't reproduce this issue with any of my Bluetooth  adapters (I tested
> with 6 different ones). Could you get us the hcidump of  what happens
> when bluetoothd tries to switch on the adapter for the very  first time?
> Probably you'll need to disable starting of bluetoothd when your  system
> boots so that you have the chance to run hcidump first. Additionally,  if
> possible, could you enable dynamic debug in your kernel and get the  logs
> from hci_core.c and hci_event.c? Typically you'd enable this  with
> something like:
> 
> echo 'file hci_event.c +p' >  /sys/kernel/debug/dynamic_debug/control
> echo 'file hci_core.c +p' >  /sys/kernel/debug/dynamic_debug/control
> 
> Hopefully those logs will give  some better idea of what's going on since
> the logs provided so far aren't  really helpful.
> 

- Compiled the kernel (2.6.38-rc7 now) with dynamic debug
- Commented out the lines to start bluetoothd from /lib/udev/rules.d/
- Killed bluetoothd
- rmmod'ed all bluetooth modules and then modprobe'd rfcomm (which pulls
in all the others) (this resets the situation so that the bug appears -
when unplugging and plugging the adapter in the working state it keeps
on working)
- enabled dynamic debug for hci_core.c, hci_event.c, and rfcomm/core.c
- plugged in the bluetooth adapter
- hcidump -w hcidump_ddebug (parsed version below)
- bluetoothd -d
- run hciconfig (without parameters) a couple of times
- waited some minutes
- run hciconfig -a (around 08:18:37 in the logs)
- adapter led starts blinking (and e.g. blueman-applet sees it)
- messages from syslog further below

Do these help?

The commit we tried to revert (23bb57633df) changes when processes
are woken up. Is there any command which would show if some process
is waiting for a wake up?


Mikko


HCI sniffer - Bluetooth packet analyzer ver 2.0
btsnoop version: 1 datalink type: 1002
2011-03-03 08:14:38.386728 < HCI Command: Reset (0x03|0x0003) plen 0
2011-03-03 08:14:38.386759 > HCI Event: Command Status (0x0f) plen 4
    Unknown (0x00|0x0000) status 0x00 ncmd 1
2011-03-03 08:14:38.386810 < HCI Command: Read Local Supported Features 
(0x04|0x0003) plen 0
2011-03-03 08:14:38.524768 > HCI Event: Command Complete (0x0e) plen 4
    Reset (0x03|0x0003) ncmd 1
    status 0x00
2011-03-03 08:14:38.524819 < HCI Command: Read Local Version Information 
(0x04|0x0001) plen 0
2011-03-03 08:14:38.528758 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Version Information (0x04|0x0001) ncmd 1
    status 0x00
    HCI Version: 2.0 (0x3) HCI Revision: 0x7a6
    LMP Version: 2.0 (0x3) LMP Subversion: 0x7a6
    Manufacturer: Cambridge Silicon Radio (10)
2011-03-03 08:14:38.528806 < HCI Command: Read Buffer Size (0x04|0x0005) plen 0
2011-03-03 08:14:38.532764 > HCI Event: Command Complete (0x0e) plen 11
    Read Buffer Size (0x04|0x0005) ncmd 1
    status 0x00
    ACL MTU 384:8 SCO MTU 64:8
2011-03-03 08:14:38.532822 < HCI Command: Read BD ADDR (0x04|0x0009) plen 0
2011-03-03 08:14:38.535758 > HCI Event: Command Complete (0x0e) plen 10
    Read BD ADDR (0x04|0x0009) ncmd 1
    status 0x00 bdaddr 00:0D:3C:38:FA:B5
2011-03-03 08:14:38.535820 < HCI Command: Read Class of Device (0x03|0x0023) 
plen 0
2011-03-03 08:14:38.538765 > HCI Event: Command Complete (0x0e) plen 7
    Read Class of Device (0x03|0x0023) ncmd 1
    status 0x00 class 0x000000
2011-03-03 08:14:38.538818 < HCI Command: Read Local Name (0x03|0x0014) plen 0
2011-03-03 08:14:38.573755 > HCI Event: Command Complete (0x0e) plen 252
    Read Local Name (0x03|0x0014) ncmd 1
    status 0x00 name 'CSR - bc4'
2011-03-03 08:14:38.573808 < HCI Command: Read Voice Setting (0x03|0x0025) plen 
0
2011-03-03 08:14:38.576766 > HCI Event: Command Complete (0x0e) plen 6
    Read Voice Setting (0x03|0x0025) ncmd 1
    status 0x00 voice setting 0x0060
2011-03-03 08:14:38.576828 < HCI Command: Set Event Filter (0x03|0x0005) plen 1
    type 0 condition 0
    Clear all filters
2011-03-03 08:14:38.579757 > HCI Event: Command Complete (0x0e) plen 4
    Set Event Filter (0x03|0x0005) ncmd 1
    status 0x00
2011-03-03 08:14:38.579802 < HCI Command: Write Page Timeout (0x03|0x0018) plen 
2
    timeout 32768
2011-03-03 08:14:38.582766 > HCI Event: Command Complete (0x0e) plen 4
    Write Page Timeout (0x03|0x0018) ncmd 1
    status 0x00
2011-03-03 08:14:38.582829 < HCI Command: Write Connection Accept Timeout 
(0x03|0x0016) plen 2
    timeout 32000
2011-03-03 08:14:38.585770 > HCI Event: Command Complete (0x0e) plen 4
    Write Connection Accept Timeout (0x03|0x0016) ncmd 1
    status 0x00
2011-03-03 08:14:38.586767 < HCI Command: Write Page Timeout (0x03|0x0018) plen 
2
    timeout 8192
2011-03-03 08:14:38.589774 > HCI Event: Command Complete (0x0e) plen 4
    Write Page Timeout (0x03|0x0018) ncmd 1
    status 0x00
2011-03-03 08:14:38.589820 < HCI Command: Read Stored Link Key (0x03|0x000d) 
plen 7
    bdaddr 00:00:00:00:00:00 all 1
2011-03-03 08:14:38.593763 > HCI Event: Command Complete (0x0e) plen 8
    Read Stored Link Key (0x03|0x000d) ncmd 1
    status 0x00 max 16 num 0
2011-03-03 08:18:37.515128 < HCI Command: Read Local Name (0x03|0x0014) plen 0
2011-03-03 08:18:37.566070 > HCI Event: Command Complete (0x0e) plen 252
    Read Local Name (0x03|0x0014) ncmd 1
    status 0x00 name 'CSR - bc4'
2011-03-03 08:18:37.566326 < HCI Command: Read Local Supported Features 
(0x04|0x0003) plen 0
2011-03-03 08:18:37.569055 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Supported Features (0x04|0x0003) ncmd 1
    status 0x00
    Features: 0xff 0xff 0x8f 0xfe 0x9b 0xf9 0x00 0x80
2011-03-03 08:18:37.569121 < HCI Command: Read Class of Device (0x03|0x0023) 
plen 0
2011-03-03 08:18:37.572061 > HCI Event: Command Complete (0x0e) plen 7
    Read Class of Device (0x03|0x0023) ncmd 1
    status 0x00 class 0x000000
2011-03-03 08:18:37.572532 < HCI Command: Read Local Version Information 
(0x04|0x0001) plen 0
2011-03-03 08:18:37.576057 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Version Information (0x04|0x0001) ncmd 1
    status 0x00
    HCI Version: 2.0 (0x3) HCI Revision: 0x7a6
    LMP Version: 2.0 (0x3) LMP Subversion: 0x7a6
    Manufacturer: Cambridge Silicon Radio (10)
2011-03-03 08:18:37.618553 < HCI Command: Set Event Mask (0x03|0x0001) plen 8
    Mask: 0xfffffbff07180000
2011-03-03 08:18:37.621056 > HCI Event: Command Complete (0x0e) plen 4
    Set Event Mask (0x03|0x0001) ncmd 1
    status 0x00
...

syslog:
...
Mar  3 08:13:17 koni kernel: usb 6-1: new full speed USB device using ohci_hcd 
and address 2
Mar  3 08:13:17 koni kernel: usb 6-1: New USB device found, idVendor=13dd, 
idProduct=0001
Mar  3 08:13:17 koni kernel: usb 6-1: New USB device strings: Mfr=1, Product=2, 
SerialNumber=0
Mar  3 08:13:17 koni kernel: usb 6-1: Product: BlueCON U2
Mar  3 08:13:17 koni kernel: usb 6-1: Manufacturer: i.Tech Dynamic
Mar  3 08:13:17 koni kernel: Bluetooth: Generic Bluetooth USB driver ver 0.6
Mar  3 08:13:17 koni kernel: hci_register_dev: ffff88013c6b1000 name  bus 1 
owner ffffffffa038b7c0
Mar  3 08:13:17 koni kernel: hci_rfkill_set_block: ffff88013c6b1000 name hci0 
blocked 0
Mar  3 08:13:17 koni kernel: usbcore: registered new interface driver btusb
Mar  3 08:13:31 koni kernel: hci_dev_get: 0
Mar  3 08:13:37 koni kernel: hci_dev_get: 0
Mar  3 08:13:39 koni -- MARK --
Mar  3 08:14:04 koni kernel: hci_dev_get: 0
Mar  3 08:14:04 koni kernel: hci_dev_get: 0
Mar  3 08:14:04 koni kernel: hci_dev_get: 0
Mar  3 08:14:26 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni bluetoothd[3270]: Bluetooth deamon 4.89
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() parsing 
main.conf
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() discovto=0
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() pairto=0
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() pageto=8192
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() name=%h-%d
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() class=0x000100
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() 
discov_interval=0
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:parse_config() Key file does 
not have key 'DeviceID'
Mar  3 08:14:38 koni bluetoothd[3270]: Starting SDP server
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:plugin_init() Loading 
builtin plugins
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading audio 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading input 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading serial 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading network 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading service 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading hciops 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading mgmtops 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading 
formfactor plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:add_plugin() Loading storage 
plugin
Mar  3 08:14:38 koni bluetoothd[3270]: src/plugin.c:plugin_init() Loading 
plugins /usr/lib/bluetooth/plugins
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/service.c:register_interface() 
path /org/bluez/3270/any
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/service.c:register_interface() 
Registered interface org.bluez.Service on path /org/bluez/3270/any
Mar  3 08:14:38 koni bluetoothd[3270]: network/manager.c:read_config() 
/etc/bluetooth/network.conf: Key file does not have key 'DisableSecurity'
Mar  3 08:14:38 koni bluetoothd[3270]: network/manager.c:read_config() Config 
options: Security=true
Mar  3 08:14:38 koni bluetoothd[3270]: input/manager.c:input_manager_init() 
input.conf: Key file does not have key 'IdleTimeout'
Mar  3 08:14:38 koni kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Mar  3 08:14:38 koni bluetoothd[3270]: audio/manager.c:audio_manager_init() 
audio.conf: Key file does not have key 'AutoConnect'
Mar  3 08:14:38 koni bluetoothd[3270]: audio/unix.c:unix_init() Unix socket 
created: 8
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:hciops_init() 
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:hciops_setup() 
Mar  3 08:14:38 koni bluetoothd[3270]: src/main.c:main() Entering main loop
Mar  3 08:14:38 koni bluetoothd[3270]: src/rfkill.c:rfkill_event() RFKILL event 
idx 0 type 1 op 0 soft 0 hard 0
Mar  3 08:14:38 koni bluetoothd[3270]: src/rfkill.c:rfkill_event() RFKILL event 
idx 5 type 2 op 0 soft 0 hard 0
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:init_known_adapters() 
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:init_device() hci0
Mar  3 08:14:38 koni bluetoothd[3270]: Listening for HCI events on hci0
Mar  3 08:14:38 koni kernel: hci_register_proto: ffffffffa057b000 name SCO id 1
Mar  3 08:14:38 koni kernel: Bluetooth: SCO (Voice Link) ver 0.6
Mar  3 08:14:38 koni kernel: Bluetooth: SCO socket layer initialized
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:init_device() child 3275 
forked
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_dev_open: hci0 ffff88013c6b1000
Mar  3 08:14:38 koni kernel: __hci_request: hci0 start
Mar  3 08:14:38 koni kernel: hci_init_req: hci0 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc03 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0x1003 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0x1001 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0x1005 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0x1009 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc23 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc14 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc25 plen 0
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 3
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc05 plen 1
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 4
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc18 plen 2
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 5
Mar  3 08:14:38 koni kernel: hci_send_cmd: hci0 opcode 0xc16 plen 2
Mar  3 08:14:38 koni kernel: hci_send_cmd: skb len 5
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cmd_status_evt: hci0 opcode 0x0
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_reset: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_req_complete: hci0 command 0x0c03 result 0x00 
(last cmd 0x0c16)
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_read_local_version: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_cc_read_local_version: hci0 manufacturer 10 hci 
ver 3:1958
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni bluetoothd[3270]: 
plugins/hciops.c:read_local_version_complete() Got version for hci0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_read_buffer_size: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_cc_read_buffer_size: hci0 acl mtu 384:8 sco mtu 
64:8
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:read_bd_addr_complete() 
hci0 status 0
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:read_bd_addr_complete() 
Got bdaddr for hci0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_read_bd_addr: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_req_complete: hci0 command 0x1009 result 0x00 
(last cmd 0x0c16)
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_read_class_of_dev: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_cc_read_class_of_dev: hci0 class 0x000000
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni bluetoothd[3270]: 
plugins/hciops.c:read_local_name_complete() hci0 status 0
Mar  3 08:14:38 koni bluetoothd[3270]: 
plugins/hciops.c:read_local_name_complete() Got name for hci0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_read_local_name: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_read_voice_setting: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_cc_read_voice_setting: hci0 voice setting 
0x0060
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 4
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cmd_complete_evt: hci0 opcode 0xc05
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 5
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cmd_complete_evt: hci0 opcode 0xc18
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 5
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cc_write_ca_timeout: hci0 status 0x0
Mar  3 08:14:38 koni kernel: hci_req_complete: hci0 command 0x0c16 result 0x00 
(last cmd 0x0c16)
Mar  3 08:14:38 koni kernel: __hci_request: hci0 end: err 0
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:child_exit() child 3275 
exited
Mar  3 08:14:38 koni bluetoothd[3270]: HCI dev 0 up
Mar  3 08:14:38 koni bluetoothd[3270]: plugins/hciops.c:device_devup_setup() 
hci0
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 5
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 0
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cmd_complete_evt: hci0 opcode 0xc18
Mar  3 08:14:38 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:14:38 koni kernel: hci_send_frame: hci0 type 1 len 10
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:14:38 koni kernel: hci_rx_task: hci0
Mar  3 08:14:38 koni kernel: hci_cmd_complete_evt: hci0 opcode 0xc0d
Mar  3 08:14:38 koni kernel: hci_dev_get: 0
Mar  3 08:18:31 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:18:37 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:18:37 koni bluetoothd[3270]: 
plugins/hciops.c:read_local_name_complete() hci0 status 0
Mar  3 08:18:37 koni bluetoothd[3270]: 
plugins/hciops.c:read_local_name_complete() Got name for hci0
Mar  3 08:18:37 koni kernel: hci_rx_task: hci0
Mar  3 08:18:37 koni kernel: hci_cc_read_local_name: hci0 status 0x0
Mar  3 08:18:37 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:18:37 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:18:37 koni kernel: hci_cmd_task: hci0 cmd 0
Mar  3 08:18:37 koni bluetoothd[3270]: 
plugins/hciops.c:read_local_features_complete() Got features for hci0
Mar  3 08:18:37 koni bluetoothd[3270]: src/adapter.c:btd_adapter_ref() 
0x7f84c3257950: ref=1
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_read_bdaddr() 
hci0
Mar  3 08:18:37 koni bluetoothd[3270]: 
plugins/hciops.c:hciops_read_local_version() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: 
plugins/hciops.c:hciops_read_local_features() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: 
src/sdpd-database.c:sdp_init_services_list() 

Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 0
Mar  3 08:18:37 koni kernel: hci_rx_task: hci0
Mar  3 08:18:37 koni kernel: hci_cc_read_local_features: hci0 status 0x0
Mar  3 08:18:37 koni kernel: hci_cc_read_local_features: hci0 features 
0xffff8ffe9bf90080
Mar  3 08:18:37 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:18:37 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:18:37 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/service.c:register_interface() 
path /org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/service.c:register_interface() 
Registered interface org.bluez.Service on path /org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: network/manager.c:network_server_probe() 
path /org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: src/adapter.c:btd_adapter_ref() 
0x7f84c3257950: ref=2
Mar  3 08:18:37 koni bluetoothd[3270]: network/server.c:server_register() 
Registered interface org.bluez.NetworkServer on path /org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: serial/manager.c:proxy_probe() path 
/org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: src/adapter.c:btd_adapter_ref() 
0x7f84c3257950: ref=3
Mar  3 08:18:37 koni bluetoothd[3270]: serial/proxy.c:proxy_register() 
Registered interface org.bluez.SerialProxyManager on path /org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: src/adapter.c:btd_adapter_ref() 
0x7f84c3257950: ref=4
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:headset_server_probe() 
path /org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: src/adapter.c:btd_adapter_ref() 
0x7f84c3257950: ref=5
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:audio_adapter_ref() 
0x7f84c3258000: ref=1
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:headset_server_init() 
audio.conf: Key file does not have key 'Master'
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Adding record with handle 0x10000
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 0
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000003-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000100-0000-1000-8000-00805f9
Mar  3 08:18:37 koni kernel: rfcomm_dlc_clear_state: ffff88013ad69100
Mar  3 08:18:37 koni kernel: rfcomm_dlc_alloc: ffff88013ad69100
Mar  3 08:18:37 koni kernel: hci_rx_task: hci0
Mar  3 08:18:37 koni kernel: hci_cc_read_class_of_dev: hci0 status 0x0
Mar  3 08:18:37 koni kernel: hci_cc_read_class_of_dev: hci0 class 0x000000
Mar  3 08:18:37 koni kernel: hci_dev_get: 0
Mar  3 08:18:37 koni kernel: hci_cmd_task: hci0 cmd 1
Mar  3 08:18:37 koni kernel: hci_send_frame: hci0 type 1 len 3
Mar  3 08:18:37 koni kernel: rfcomm_dlc_clear_state: ffff88013c50c200
Mar  3 08:18:37 koni kernel: rfcomm_dlc_alloc: ffff88013c50c200
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001002-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001108-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001112-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001203-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: audio/headset.c:headset_config_init() 
audio.conf: Key file does not have key 'SCORouting'
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Adding record with handle 0x10001
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 64
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000003-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000100-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001002-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000111e-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000111f-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001203-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:state_changed() 
/org/bluez/3270/hci0 powered on
Mar  3 08:18:37 koni bluetoothd[3270]: audio/telephony.c:telephony_init() 
Mar  3 08:18:37 koni bluetoothd[3270]: audio/headset.c:telephony_ready_ind() 
Telephony plugin initialized
Mar  3 08:18:37 koni bluetoothd[3270]: audio/headset.c:print_ag_features() HFP 
AG features: "Ability to reject a call" "Enhanced call status" "Extended Error 
Result Codes" 

Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:a2dp_server_probe() path 
/org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:audio_adapter_ref() 
0x7f84c3258000: ref=2
Mar  3 08:18:37 koni bluetoothd[3270]: audio/a2dp.c:a2dp_register() audio.conf: 
Key file does not have key 'Enable'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/a2dp.c:a2dp_register() audio.conf: 
Key file does not have key 'Disable'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/a2dp.c:a2dp_register() audio.conf: 
Key file does not have group 'A2DP'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/a2dp.c:a2dp_register() audio.conf: 
Key file does not have group 'A2DP'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/a2dp.c:a2dp_register() audio.conf: 
Key file does not have group 'A2DP'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/a2dp.c:a2dp_register() audio.conf: 
Key file does not have group 'A2DP'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/avdtp.c:avdtp_init() audio.conf: 
Key file does not have key 'Master'
Mar  3 08:18:37 koni bluetoothd[3270]: audio/avdtp.c:avdtp_register_sep() SEP 
0x7f84c3259ad0 registered: type:0 codec:0 seid:1
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Adding record with handle 0x10002
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 72
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000019-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000100-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001002-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000110a-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000110d-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:avrcp_server_probe() path 
/org/bluez/3270/hci0
Mar  3 08:18:37 koni bluetoothd[3270]: audio/manager.c:audio_adapter_ref() 
0x7f84c3258000: ref=3
Mar  3 08:18:37 koni bluetoothd[3270]: audio/control.c:avrcp_register() 
audio.conf: Key file does not have key 'Master'
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Adding record with handle 0x10003
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 72
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000017-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000100-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001002-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000110c-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000110e-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Adding record with handle 0x10004
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_add_uuid() hci0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:update_service_classes() 
hci0 value 72
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000017-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00000100-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 00001002-0000-1000-8000-00805f9
Mar  3 08:18:37 koni bluetoothd[3270]: src/sdpd-service.c:add_record_to_server() 
Record pattern UUID 0000110e-0000-1000-8000-00805f9
Mar  3 08:18:37 koni kernel: hci_rx_task: hci0
Mar  3 08:18:37 koni kernel: hci_cc_read_local_version: hci0 status 0x0
Mar  3 08:18:37 koni kernel: hci_cc_read_local_version: hci0 manufacturer 10 hci 
ver 3:1958
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/formfactor.c:formfactor_probe() 
Setting 0x000100 for major/minor device class
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_set_dev_class() 
hci0 major 1 minor 0
Mar  3 08:18:37 koni bluetoothd[3270]: plugins/hciops.c:hciops_unblock_device() 
hci0 dba 00:00:00:00:00:00
Mar  3 08:18:37 koni bluetoothd[3270]: src/device.c:device_create() Creating 
device /org/bluez/3270/hci0/dev_00_11_24_68_xx_yy
Mar  3 08:18:37 koni bluetoothd[3270]: src/device.c:btd_device_ref() 
0x7f84c3280fc0: ref=1
Mar  3 08:18:37 koni bluetoothd[3270]: src/device.c:device_set_temporary() 
temporary 0
Mar  3 08:18:37 koni bluetoothd[3270]: src/device.c:device_probe_drivers() 
Probing drivers for 00:11:24:68:xx:yy
... (a lot of bluetooth stuff, all only after hciconfig -a)


      

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-03 10:54   ` Mikko Vinni
@ 2011-03-03 14:31     ` Johan Hedberg
  2011-03-04  4:47       ` Ville Tervo
  2011-03-07 19:50       ` Mikko Vinni
  0 siblings, 2 replies; 25+ messages in thread
From: Johan Hedberg @ 2011-03-03 14:31 UTC (permalink / raw)
  To: Mikko Vinni
  Cc: linux-bluetooth, Justin P. Mattock, Ed Tomlinson, Gustavo F. Padovan

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

Hi Mikko,

On Thu, Mar 03, 2011, Mikko Vinni wrote:
> > I can't reproduce this issue with any of my Bluetooth  adapters (I tested
> > with 6 different ones). Could you get us the hcidump of  what happens
> > when bluetoothd tries to switch on the adapter for the very  first time?
> > Probably you'll need to disable starting of bluetoothd when your  system
> > boots so that you have the chance to run hcidump first. Additionally,  if
> > possible, could you enable dynamic debug in your kernel and get the  logs
> > from hci_core.c and hci_event.c? Typically you'd enable this  with
> > something like:
> > 
> > echo 'file hci_event.c +p' >  /sys/kernel/debug/dynamic_debug/control
> > echo 'file hci_core.c +p' >  /sys/kernel/debug/dynamic_debug/control
> > 
> > Hopefully those logs will give  some better idea of what's going on since
> > the logs provided so far aren't  really helpful.
> > 
> 
> - Compiled the kernel (2.6.38-rc7 now) with dynamic debug
> - Commented out the lines to start bluetoothd from /lib/udev/rules.d/
> - Killed bluetoothd
> - rmmod'ed all bluetooth modules and then modprobe'd rfcomm (which pulls
> in all the others) (this resets the situation so that the bug appears -
> when unplugging and plugging the adapter in the working state it keeps
> on working)
> - enabled dynamic debug for hci_core.c, hci_event.c, and rfcomm/core.c
> - plugged in the bluetooth adapter
> - hcidump -w hcidump_ddebug (parsed version below)
> - bluetoothd -d
> - run hciconfig (without parameters) a couple of times
> - waited some minutes
> - run hciconfig -a (around 08:18:37 in the logs)
> - adapter led starts blinking (and e.g. blueman-applet sees it)
> - messages from syslog further below
> 
> Do these help?

They do indeed. However, the simplest short-term fix I can come up for
this is in user space and not the kernel.

> HCI sniffer - Bluetooth packet analyzer ver 2.0
> btsnoop version: 1 datalink type: 1002
> 2011-03-03 08:14:38.386728 < HCI Command: Reset (0x03|0x0003) plen 0
> 2011-03-03 08:14:38.386759 > HCI Event: Command Status (0x0f) plen 4
>     Unknown (0x00|0x0000) status 0x00 ncmd 1
> 2011-03-03 08:14:38.386810 < HCI Command: Read Local Supported Features 
> (0x04|0x0003) plen 0
> 2011-03-03 08:14:38.524768 > HCI Event: Command Complete (0x0e) plen 4
>     Reset (0x03|0x0003) ncmd 1
>     status 0x00

I'm not sure if this is correct. The command status for opcode 0 means
that we can start sending commands to the controller, however since
there's a pending reset command maybe we should be waiting for its
command complete event before sending the features command. Or should we
be sending the Reset command at all so early and instead wait for the
command status before sending it?

In any case what's happening is that there's never a command complete
for the local features. This is one of those commands that user space
tracks to determine that the adapter is initialized so if it never comes
the adapter remains uninitialized from a bluetoothd perspective. There
is supposed to be some work-around code in bluetoothd for this kind of
situations, but due to the patch you found in the kernel the code
doesn't get triggered since the "up" flag is not set when the situation
happens. The patch I've attached removed this check for the flag. Could
you try and see if it helps?

Meanwhile, it'd be nice to get some input from more knowledgeable
persons on whether the kernel is doing the right thing in not waiting
for the command status for opcode 0 before sending the HCI_Reset.

Johan

[-- Attachment #2: devup.patch --]
[-- Type: text/x-diff, Size: 477 bytes --]

diff --git a/plugins/hciops.c b/plugins/hciops.c
index fd19ef4..c46465a 100644
--- a/plugins/hciops.c
+++ b/plugins/hciops.c
@@ -1569,9 +1569,6 @@ static void read_local_name_complete(int index, read_local_name_rp *rp)
 
 	DBG("Got name for hci%d", index);
 
-	if (!dev->up)
-		return;
-
 	/* Even though it shouldn't happen (assuming the kernel behaves
 	 * properly) it seems like we might miss the very first
 	 * initialization commands that the kernel sends. So check for

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-03 14:31     ` Johan Hedberg
@ 2011-03-04  4:47       ` Ville Tervo
  2011-03-07 19:50       ` Mikko Vinni
  1 sibling, 0 replies; 25+ messages in thread
From: Ville Tervo @ 2011-03-04  4:47 UTC (permalink / raw)
  To: Mikko Vinni, linux-bluetooth, Justin P. Mattock, Ed Tomlinson,
	Gustavo F. Padovan

Hi,

On Thu, Mar 03, 2011 at 11:31:54AM -0300, ext Johan Hedberg wrote:
> Hi Mikko,
> 
> On Thu, Mar 03, 2011, Mikko Vinni wrote:
> > > I can't reproduce this issue with any of my Bluetooth  adapters (I tested
> > > with 6 different ones). Could you get us the hcidump of  what happens
> > > when bluetoothd tries to switch on the adapter for the very  first time?
> > > Probably you'll need to disable starting of bluetoothd when your  system
> > > boots so that you have the chance to run hcidump first. Additionally,  if
> > > possible, could you enable dynamic debug in your kernel and get the  logs
> > > from hci_core.c and hci_event.c? Typically you'd enable this  with
> > > something like:
> > > 
> > > echo 'file hci_event.c +p' >  /sys/kernel/debug/dynamic_debug/control
> > > echo 'file hci_core.c +p' >  /sys/kernel/debug/dynamic_debug/control
> > > 
> > > Hopefully those logs will give  some better idea of what's going on since
> > > the logs provided so far aren't  really helpful.
> > > 
> > 
> > - Compiled the kernel (2.6.38-rc7 now) with dynamic debug
> > - Commented out the lines to start bluetoothd from /lib/udev/rules.d/
> > - Killed bluetoothd
> > - rmmod'ed all bluetooth modules and then modprobe'd rfcomm (which pulls
> > in all the others) (this resets the situation so that the bug appears -
> > when unplugging and plugging the adapter in the working state it keeps
> > on working)
> > - enabled dynamic debug for hci_core.c, hci_event.c, and rfcomm/core.c
> > - plugged in the bluetooth adapter
> > - hcidump -w hcidump_ddebug (parsed version below)
> > - bluetoothd -d
> > - run hciconfig (without parameters) a couple of times
> > - waited some minutes
> > - run hciconfig -a (around 08:18:37 in the logs)
> > - adapter led starts blinking (and e.g. blueman-applet sees it)
> > - messages from syslog further below
> > 
> > Do these help?
> 
> They do indeed. However, the simplest short-term fix I can come up for
> this is in user space and not the kernel.
> 
> > HCI sniffer - Bluetooth packet analyzer ver 2.0
> > btsnoop version: 1 datalink type: 1002
> > 2011-03-03 08:14:38.386728 < HCI Command: Reset (0x03|0x0003) plen 0
> > 2011-03-03 08:14:38.386759 > HCI Event: Command Status (0x0f) plen 4
> >     Unknown (0x00|0x0000) status 0x00 ncmd 1
> > 2011-03-03 08:14:38.386810 < HCI Command: Read Local Supported Features 
> > (0x04|0x0003) plen 0
> > 2011-03-03 08:14:38.524768 > HCI Event: Command Complete (0x0e) plen 4
> >     Reset (0x03|0x0003) ncmd 1
> >     status 0x00
> 
> I'm not sure if this is correct. The command status for opcode 0 means
> that we can start sending commands to the controller, however since
> there's a pending reset command maybe we should be waiting for its
> command complete event before sending the features command. Or should we
> be sending the Reset command at all so early and instead wait for the
> command status before sending it?

No need to wait for NOP event. And after reset no other commands should be sent
before cmd complete.

At least according the spec. So reset should be handled in a special way.

> 
> In any case what's happening is that there's never a command complete
> for the local features. This is one of those commands that user space
> tracks to determine that the adapter is initialized so if it never comes
> the adapter remains uninitialized from a bluetoothd perspective. There
> is supposed to be some work-around code in bluetoothd for this kind of
> situations, but due to the patch you found in the kernel the code
> doesn't get triggered since the "up" flag is not set when the situation
> happens. The patch I've attached removed this check for the flag. Could
> you try and see if it helps?
> 
> Meanwhile, it'd be nice to get some input from more knowledgeable
> persons on whether the kernel is doing the right thing in not waiting
> for the command status for opcode 0 before sending the HCI_Reset.

It's doing wrong currently.

-- 
Ville

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-03 14:31     ` Johan Hedberg
  2011-03-04  4:47       ` Ville Tervo
@ 2011-03-07 19:50       ` Mikko Vinni
  2011-03-08 22:30         ` Justin P. Mattock
  2011-03-09 21:23         ` Justin P. Mattock
  1 sibling, 2 replies; 25+ messages in thread
From: Mikko Vinni @ 2011-03-07 19:50 UTC (permalink / raw)
  To: Johan Hedberg
  Cc: linux-bluetooth, Justin P. Mattock, Ed Tomlinson, Gustavo F. Padovan

Hi,

Johan Hedberg wrote:

> In any case what's happening is  that there's never a command complete
> for the local features. This is one of  those commands that user space
> tracks to determine that the adapter is  initialized so if it never comes
> the adapter remains uninitialized from a  bluetoothd perspective. There
> is supposed to be some work-around code in  bluetoothd for this kind of
> situations, but due to the patch you found in the  kernel the code
> doesn't get triggered since the "up" flag is not set when the  situation
> happens. The patch I've attached removed this check for the flag.  Could
> you try and see if it helps?


I compiled bluez 4.89-71-gdc920af from git, which seems to contain the
patch that was as an attachment (9bae9813abf29344cc3d84af2ee59efd9e9e78fc).

It sometimes helps, but not always. Maybe there are some alternative code
paths, races, or something. Below some logs for a case when it doesn't
help. Also, it doesn't seem to work when bluetoothd is started before
plugging in the adapter or if the adapter is unplugged and replugged.

adapter in; start hcidump; start self-compiled bluetoothd

hcidump log ("hcidump -a" ran around 21.27.30):

HCI sniffer - Bluetooth packet analyzer ver 2.0
btsnoop version: 1 datalink type: 1002
2011-03-07 21:27:08.891188 < HCI Command: Reset (0x03|0x0003) plen 0
2011-03-07 21:27:08.891722 > HCI Event: Command Status (0x0f) plen 4
    Unknown (0x00|0x0000) status 0x00 ncmd 1
2011-03-07 21:27:08.891747 < HCI Command: Read Local Supported Features 
(0x04|0x0003) plen 0
2011-03-07 21:27:09.029713 > HCI Event: Command Complete (0x0e) plen 4
    Reset (0x03|0x0003) ncmd 1
    status 0x00
2011-03-07 21:27:09.029785 < HCI Command: Read Local Version Information 
(0x04|0x0001) plen 0
2011-03-07 21:27:09.033720 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Version Information (0x04|0x0001) ncmd 1
    status 0x00
    HCI Version: 2.0 (0x3) HCI Revision: 0x7a6
    LMP Version: 2.0 (0x3) LMP Subversion: 0x7a6
    Manufacturer: Cambridge Silicon Radio (10)
2011-03-07 21:27:09.033767 < HCI Command: Read Buffer Size (0x04|0x0005) plen 0
2011-03-07 21:27:09.037700 > HCI Event: Command Complete (0x0e) plen 11
    Read Buffer Size (0x04|0x0005) ncmd 1
    status 0x00
    ACL MTU 384:8 SCO MTU 64:8
2011-03-07 21:27:09.037726 < HCI Command: Read BD ADDR (0x04|0x0009) plen 0
2011-03-07 21:27:09.040717 > HCI Event: Command Complete (0x0e) plen 10
    Read BD ADDR (0x04|0x0009) ncmd 1
    status 0x00 bdaddr 00:0D:3C:38:FA:B5
2011-03-07 21:27:09.040756 < HCI Command: Read Class of Device (0x03|0x0023) 
plen 0
2011-03-07 21:27:09.043704 > HCI Event: Command Complete (0x0e) plen 7
    Read Class of Device (0x03|0x0023) ncmd 1
    status 0x00 class 0x000000
2011-03-07 21:27:09.043741 < HCI Command: Read Local Name (0x03|0x0014) plen 0
2011-03-07 21:27:09.078711 > HCI Event: Command Complete (0x0e) plen 252
    Read Local Name (0x03|0x0014) ncmd 1
    status 0x00 name 'CSR - bc4'
2011-03-07 21:27:09.078749 < HCI Command: Read Voice Setting (0x03|0x0025) plen 
0
2011-03-07 21:27:09.081733 > HCI Event: Command Complete (0x0e) plen 6
    Read Voice Setting (0x03|0x0025) ncmd 1
    status 0x00 voice setting 0x0060
2011-03-07 21:27:09.081764 < HCI Command: Set Event Filter (0x03|0x0005) plen 1
    type 0 condition 0
    Clear all filters
2011-03-07 21:27:09.084712 > HCI Event: Command Complete (0x0e) plen 4
    Set Event Filter (0x03|0x0005) ncmd 1
    status 0x00
2011-03-07 21:27:09.084738 < HCI Command: Write Page Timeout (0x03|0x0018) plen 
2
    timeout 32768
2011-03-07 21:27:09.087703 > HCI Event: Command Complete (0x0e) plen 4
    Write Page Timeout (0x03|0x0018) ncmd 1
    status 0x00
2011-03-07 21:27:09.087726 < HCI Command: Write Connection Accept Timeout 
(0x03|0x0016) plen 2
    timeout 32000
2011-03-07 21:27:09.090699 > HCI Event: Command Complete (0x0e) plen 4
    Write Connection Accept Timeout (0x03|0x0016) ncmd 1
    status 0x00
2011-03-07 21:27:09.091818 < HCI Command: Write Page Timeout (0x03|0x0018) plen 
2
    timeout 8192
2011-03-07 21:27:09.094704 > HCI Event: Command Complete (0x0e) plen 4
    Write Page Timeout (0x03|0x0018) ncmd 1
    status 0x00
2011-03-07 21:27:09.094758 < HCI Command: Read Stored Link Key (0x03|0x000d) 
plen 7
    bdaddr 00:00:00:00:00:00 all 1
2011-03-07 21:27:09.098714 > HCI Event: Command Complete (0x0e) plen 8
    Read Stored Link Key (0x03|0x000d) ncmd 1
    status 0x00 max 16 num 0
2011-03-07 21:27:33.036962 < HCI Command: Read Local Name (0x03|0x0014) plen 0
2011-03-07 21:27:33.088144 > HCI Event: Command Complete (0x0e) plen 252
    Read Local Name (0x03|0x0014) ncmd 1
    status 0x00 name 'CSR - bc4'
2011-03-07 21:27:33.088386 < HCI Command: Read Class of Device (0x03|0x0023) 
plen 0
2011-03-07 21:27:33.091152 > HCI Event: Command Complete (0x0e) plen 7
    Read Class of Device (0x03|0x0023) ncmd 1
    status 0x00 class 0x000000
2011-03-07 21:27:33.091181 < HCI Command: Read Local Supported Features 
(0x04|0x0003) plen 0
2011-03-07 21:27:33.094151 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Supported Features (0x04|0x0003) ncmd 1
    status 0x00
    Features: 0xff 0xff 0x8f 0xfe 0x9b 0xf9 0x00 0x80
2011-03-07 21:27:33.094175 < HCI Command: Read Local Version Information 
(0x04|0x0001) plen 0
2011-03-07 21:27:33.098150 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Version Information (0x04|0x0001) ncmd 1
    status 0x00
    HCI Version: 2.0 (0x3) HCI Revision: 0x7a6
    LMP Version: 2.0 (0x3) LMP Subversion: 0x7a6
    Manufacturer: Cambridge Silicon Radio (10)
2011-03-07 21:27:33.150368 < HCI Command: Set Event Mask (0x03|0x0001) plen 8
    Mask: 0xfffffbff07180000
2011-03-07 21:27:33.153142 > HCI Event: Command Complete (0x0e) plen 4
    Set Event Mask (0x03|0x0001) ncmd 1
    status 0x00
2011-03-07 21:27:33.153176 < HCI Command: Write Inquiry Mode (0x03|0x0045) plen 
1
    mode 1
2011-03-07 21:27:33.156136 > HCI Event: Command Complete (0x0e) plen 4
    Write Inquiry Mode (0x03|0x0045) ncmd 1
    status 0x00
2011-03-07 21:27:33.156168 < HCI Command: Write Default Link Policy Settings 
(0x02|0x000f) plen 2
    policy 0x0f
    Link policy: RSWITCH HOLD SNIFF PARK 
2011-03-07 21:27:33.159136 > HCI Event: Command Complete (0x0e) plen 4
    Write Default Link Policy Settings (0x02|0x000f) ncmd 1
    status 0x00
2011-03-07 21:27:33.159163 < HCI Command: Write Local Name (0x03|0x0013) plen 
248
    name 'koni-0'
2011-03-07 21:27:33.162140 > HCI Event: Command Complete (0x0e) plen 4
    Write Local Name (0x03|0x0013) ncmd 1
    status 0x00
2011-03-07 21:27:33.162167 < HCI Command: Write Class of Device (0x03|0x0024) 
plen 3
    class 0x480100
2011-03-07 21:27:33.165143 > HCI Event: Command Complete (0x0e) plen 4
    Write Class of Device (0x03|0x0024) ncmd 1
    status 0x00
2011-03-07 21:27:33.165180 < HCI Command: Write Scan Enable (0x03|0x001a) plen 1
    enable 3
2011-03-07 21:27:33.169143 > HCI Event: Command Complete (0x0e) plen 4
    Write Scan Enable (0x03|0x001a) ncmd 1
    status 0x00
2011-03-07 21:27:33.169175 < HCI Command: Read Local Name (0x03|0x0014) plen 0
2011-03-07 21:27:33.190186 > HCI Event: Command Complete (0x0e) plen 252
    Read Local Name (0x03|0x0014) ncmd 1
    status 0x00 name 'koni-0'
2011-03-07 21:27:33.190246 < HCI Command: Read Scan Enable (0x03|0x0019) plen 0
2011-03-07 21:27:33.193155 > HCI Event: Command Complete (0x0e) plen 5
    Read Scan Enable (0x03|0x0019) ncmd 1
    status 0x00 enable 3
2011-03-07 21:27:50.114574 < HCI Command: Reset (0x03|0x0003) plen 0

syslog:

Mar  7 21:26:47 koni kernel: usb 5-3: New USB device found, idVendor=13dd, 
idProduct=0001
Mar  7 21:26:47 koni kernel: usb 5-3: New USB device strings: Mfr=1, Product=2, 
SerialNumber=0
Mar  7 21:26:47 koni kernel: usb 5-3: Product: BlueCON U2
Mar  7 21:26:47 koni kernel: usb 5-3: Manufacturer: i.Tech Dynamic
Mar  7 21:27:08 koni bluetoothd[18369]: Bluetooth deamon 4.89
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() parsing 
main.conf
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() discovto=0
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() pairto=0
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() pageto=8192
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() name=%h-%d
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() class=0x000100
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() 
discov_interval=0
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:parse_config() Key file does 
not have key 'DeviceID'
Mar  7 21:27:08 koni bluetoothd[18369]: Starting SDP server
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:plugin_init() Loading 
builtin plugins
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading audio 
plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading input 
plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading serial 
plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading 
network plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading 
service plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading attrib 
plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading health 
plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading hciops 
plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading 
mgmtops plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading 
formfactor plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:add_plugin() Loading 
storage plugin
Mar  7 21:27:08 koni bluetoothd[18369]: src/plugin.c:plugin_init() Loading 
plugins /usr/lib/bluetooth/plugins
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/service.c:register_interface() 
path /org/bluez/18369/any
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/service.c:register_interface() 
Registered interface org.bluez.Service on path /org/bluez/18369/any
Mar  7 21:27:08 koni bluetoothd[18369]: health/hdp.c:hdp_manager_start() 
Starting Health manager
Mar  7 21:27:08 koni bluetoothd[18369]: network/manager.c:read_config() 
/etc/bluetooth/network.conf: Key file does not have key 'DisableSecurity'
Mar  7 21:27:08 koni bluetoothd[18369]: network/manager.c:read_config() Config 
options: Security=true
Mar  7 21:27:08 koni bluetoothd[18369]: input/manager.c:input_manager_init() 
input.conf: Key file does not have key 'IdleTimeout'
Mar  7 21:27:08 koni bluetoothd[18369]: audio/manager.c:audio_manager_init() 
audio.conf: Key file does not have key 'AutoConnect'
Mar  7 21:27:08 koni bluetoothd[18369]: audio/unix.c:unix_init() Unix socket 
created: 8
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/hciops.c:hciops_init() 
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/hciops.c:hciops_setup() 
Mar  7 21:27:08 koni bluetoothd[18369]: src/main.c:main() Entering main loop
Mar  7 21:27:08 koni kernel: Bluetooth: SCO (Voice Link) ver 0.6
Mar  7 21:27:08 koni kernel: Bluetooth: SCO socket layer initialized
Mar  7 21:27:08 koni bluetoothd[18369]: src/rfkill.c:rfkill_event() RFKILL event 
idx 0 type 1 op 0 soft 0 hard 0
Mar  7 21:27:08 koni bluetoothd[18369]: src/rfkill.c:rfkill_event() RFKILL event 
idx 16 type 2 op 0 soft 0 hard 0
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/hciops.c:init_known_adapters() 
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/hciops.c:init_device() hci0
Mar  7 21:27:08 koni bluetoothd[18369]: Listening for HCI events on hci0
Mar  7 21:27:08 koni bluetoothd[18369]: plugins/hciops.c:init_device() child 
18372 forked
Mar  7 21:27:09 koni bluetoothd[18369]: 
plugins/hciops.c:read_local_version_complete() Got version for hci0
Mar  7 21:27:09 koni bluetoothd[18369]: plugins/hciops.c:read_bd_addr_complete() 
hci0 status 0
Mar  7 21:27:09 koni bluetoothd[18369]: plugins/hciops.c:read_bd_addr_complete() 
Got bdaddr for hci0
Mar  7 21:27:09 koni bluetoothd[18369]: 
plugins/hciops.c:read_local_name_complete() hci0 status 0
Mar  7 21:27:09 koni bluetoothd[18369]: 
plugins/hciops.c:read_local_name_complete() Got name for hci0
Mar  7 21:27:09 koni bluetoothd[18369]: plugins/hciops.c:child_exit() child 
18372 exited
Mar  7 21:27:09 koni bluetoothd[18369]: HCI dev 0 up
Mar  7 21:27:09 koni bluetoothd[18369]: plugins/hciops.c:device_devup_setup() 
hci0
Mar  7 21:27:33 koni bluetoothd[18369]: 
plugins/hciops.c:read_local_name_complete() hci0 status 0
Mar  7 21:27:33 koni bluetoothd[18369]: 
plugins/hciops.c:read_local_name_complete() Got name for hci0
Mar  7 21:27:33 koni bluetoothd[18369]: 
plugins/hciops.c:read_local_features_complete() Got features for hci0
Mar  7 21:27:33 koni bluetoothd[18369]: src/adapter.c:btd_adapter_ref() 
0x7f28f49b3800: ref=1
Mar  7 21:27:33 koni bluetoothd[18369]: plugins/hciops.c:hciops_read_bdaddr() 
hci0
...

Mikko


      

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-07 19:50       ` Mikko Vinni
@ 2011-03-08 22:30         ` Justin P. Mattock
  2011-03-09 21:23         ` Justin P. Mattock
  1 sibling, 0 replies; 25+ messages in thread
From: Justin P. Mattock @ 2011-03-08 22:30 UTC (permalink / raw)
  To: Mikko Vinni
  Cc: Johan Hedberg, linux-bluetooth, Ed Tomlinson, Gustavo F. Padovan

alright..

<------clip --------->

  finally had time to get online and look at this issue. from playing 
around(hopefully)I found the trouble spot in of which this is 
hitting(but could be wrong).

By doing the below:

 From ff80f03c351018b53a630de8f256137a7af8f00c Mon Sep 17 00:00:00 2001
From: Justin P. Mattock <justinmattock@gmail.com>
Date: Tue, 8 Mar 2011 13:28:22 -0800
Subject: [PATCH] test
  Signe-off-by: Justin P. Mattock <justinmattock@gmail.com>

---
  net/bluetooth/hci_core.c |    4 ++--
  1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 9c4541b..9b8f425 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -99,8 +99,8 @@ void hci_req_complete(struct hci_dev *hdev, __u16 cmd, 
int result)
  	 * command requests) check if the completed command matches
  	 * this, and if not just return. Single HCI command requests
  	 * typically leave req_last_cmd as 0 */
-	if (hdev->req_last_cmd && cmd != hdev->req_last_cmd)
-		return;
+	/*if (hdev->req_last_cmd && cmd != hdev->req_last_cmd)
+		return; */

  	if (hdev->req_status == HCI_REQ_PEND) {
  		hdev->req_result = result;
-- 
1.7.4.1


I am able to have a clean connect every reboot and hard shutdown/start.

strange thing with this, is I was able to have a clean connect on the 
current with nothing added or removed(but only one time out of 6 
restarts) with the above every time.

if you guys need any info let me know and/or if you want me to test 
anything out(keep in mind I am limited to intranet so I might take some 
time to respond)

Justin P. Mattock




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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-07 19:50       ` Mikko Vinni
  2011-03-08 22:30         ` Justin P. Mattock
@ 2011-03-09 21:23         ` Justin P. Mattock
  2011-03-10  2:54           ` Ed Tomlinson
  1 sibling, 1 reply; 25+ messages in thread
From: Justin P. Mattock @ 2011-03-09 21:23 UTC (permalink / raw)
  To: Mikko Vinni
  Cc: Johan Hedberg, linux-bluetooth, Ed Tomlinson, Gustavo F. Padovan


looking more into this issue I am noticing that it seems this might be a 
timing issue. I have tried adding msleep to the function but endedup 
having a system freeze(only because I am not sure how msleep 
works)udelay I have not played around with just yet.

the below patch gets everything working for me:


 From 8065e37b546cdf6e42a5de4277e08ebba0a18637 Mon Sep 17 00:00:00 2001
From: Justin P. Mattock <justinmattock@gmail.com>
Date: Tue, 8 Mar 2011 22:01:19 -0800
Subject: [PATCH] bluetooth_bug_fix_test_1
  Signed-off-by: Justin P. Mattock <justinmattock@gmail.com>

---
  net/bluetooth/hci_core.c |   11 +++++------
  1 files changed, 5 insertions(+), 6 deletions(-)

diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 9c4541b..f690eb5 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -95,18 +95,17 @@ void hci_req_complete(struct hci_dev *hdev, __u16 
cmd, int result)
  {
  	BT_DBG("%s command 0x%04x result 0x%2.2x", hdev->name, cmd, result);

+	if (hdev->req_status == HCI_REQ_PEND) {
+		hdev->req_result = result;
+		hdev->req_status = HCI_REQ_DONE;
+		wake_up_interruptible(&hdev->req_wait_q);
+	}
  	/* If the request has set req_last_cmd (typical for multi-HCI
  	 * command requests) check if the completed command matches
  	 * this, and if not just return. Single HCI command requests
  	 * typically leave req_last_cmd as 0 */
  	if (hdev->req_last_cmd && cmd != hdev->req_last_cmd)
  		return;
-
-	if (hdev->req_status == HCI_REQ_PEND) {
-		hdev->req_result = result;
-		hdev->req_status = HCI_REQ_DONE;
-		wake_up_interruptible(&hdev->req_wait_q);
-	}
  }

  static void hci_req_cancel(struct hci_dev *hdev, int err)
-- 
1.7.4.1


I have done multiple reboots warm/cold and the bluetooth connects 
everytime with the above. If this seems to be a good solution let me 
know, if its not then maybe udelay/msleep is better(or not!)

Justin P. Mattock

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-09 21:23         ` Justin P. Mattock
@ 2011-03-10  2:54           ` Ed Tomlinson
  2011-03-10  7:32             ` Johan Hedberg
  0 siblings, 1 reply; 25+ messages in thread
From: Ed Tomlinson @ 2011-03-10  2:54 UTC (permalink / raw)
  To: Justin P. Mattock
  Cc: Mikko Vinni, Johan Hedberg, linux-bluetooth, Gustavo F. Padovan

On Wednesday 09 March 2011 16:23:55 Justin P. Mattock wrote:
> 
> looking more into this issue I am noticing that it seems this might be a 
> timing issue. I have tried adding msleep to the function but endedup 
> having a system freeze(only because I am not sure how msleep 
> works)udelay I have not played around with just yet.
> 
> the below patch gets everything working for me:
> 
> 
>  From 8065e37b546cdf6e42a5de4277e08ebba0a18637 Mon Sep 17 00:00:00 2001
> From: Justin P. Mattock <justinmattock@gmail.com>
> Date: Tue, 8 Mar 2011 22:01:19 -0800
> Subject: [PATCH] bluetooth_bug_fix_test_1
>   Signed-off-by: Justin P. Mattock <justinmattock@gmail.com>
> 
> ---
>   net/bluetooth/hci_core.c |   11 +++++------
>   1 files changed, 5 insertions(+), 6 deletions(-)
> 
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index 9c4541b..f690eb5 100644
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -95,18 +95,17 @@ void hci_req_complete(struct hci_dev *hdev, __u16 
> cmd, int result)
>   {
>   	BT_DBG("%s command 0x%04x result 0x%2.2x", hdev->name, cmd, result);
> 
> +	if (hdev->req_status == HCI_REQ_PEND) {
> +		hdev->req_result = result;
> +		hdev->req_status = HCI_REQ_DONE;
> +		wake_up_interruptible(&hdev->req_wait_q);
> +	}
>   	/* If the request has set req_last_cmd (typical for multi-HCI
>   	 * command requests) check if the completed command matches
>   	 * this, and if not just return. Single HCI command requests
>   	 * typically leave req_last_cmd as 0 */
>   	if (hdev->req_last_cmd && cmd != hdev->req_last_cmd)
>   		return;
> -
> -	if (hdev->req_status == HCI_REQ_PEND) {
> -		hdev->req_result = result;
> -		hdev->req_status = HCI_REQ_DONE;
> -		wake_up_interruptible(&hdev->req_wait_q);
> -	}
>   }
> 
>   static void hci_req_cancel(struct hci_dev *hdev, int err)
> 

Works here too - bluetooth comes up enabled.  On to Linus?

Thanks
Ed

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-10  2:54           ` Ed Tomlinson
@ 2011-03-10  7:32             ` Johan Hedberg
  2011-03-10 18:02               ` Justin P. Mattock
  2011-03-12  1:33               ` Gustavo F. Padovan
  0 siblings, 2 replies; 25+ messages in thread
From: Johan Hedberg @ 2011-03-10  7:32 UTC (permalink / raw)
  To: Ed Tomlinson
  Cc: Justin P. Mattock, Mikko Vinni, linux-bluetooth, Gustavo F. Padovan

Hi,

On Wed, Mar 09, 2011, Ed Tomlinson wrote:
> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > index 9c4541b..f690eb5 100644
> > --- a/net/bluetooth/hci_core.c
> > +++ b/net/bluetooth/hci_core.c
> > @@ -95,18 +95,17 @@ void hci_req_complete(struct hci_dev *hdev, __u16 
> > cmd, int result)
> >   {
> >   	BT_DBG("%s command 0x%04x result 0x%2.2x", hdev->name, cmd, result);
> > 
> > +	if (hdev->req_status == HCI_REQ_PEND) {
> > +		hdev->req_result = result;
> > +		hdev->req_status = HCI_REQ_DONE;
> > +		wake_up_interruptible(&hdev->req_wait_q);
> > +	}
> >   	/* If the request has set req_last_cmd (typical for multi-HCI
> >   	 * command requests) check if the completed command matches
> >   	 * this, and if not just return. Single HCI command requests
> >   	 * typically leave req_last_cmd as 0 */
> >   	if (hdev->req_last_cmd && cmd != hdev->req_last_cmd)
> >   		return;
> > -
> > -	if (hdev->req_status == HCI_REQ_PEND) {
> > -		hdev->req_result = result;
> > -		hdev->req_status = HCI_REQ_DONE;
> > -		wake_up_interruptible(&hdev->req_wait_q);
> > -	}
> >   }
> > 
> >   static void hci_req_cancel(struct hci_dev *hdev, int err)
> > 
> 
> Works here too - bluetooth comes up enabled.  On to Linus?

All the patch does is it re-breaks the __hci_request function by
removing proper synchronization from it (again) and thereby hides the
real bug which is the kernel sending commands to the controller before
the HCI_Reset command has completed.

Johan

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-10  7:32             ` Johan Hedberg
@ 2011-03-10 18:02               ` Justin P. Mattock
  2011-03-12  1:33               ` Gustavo F. Padovan
  1 sibling, 0 replies; 25+ messages in thread
From: Justin P. Mattock @ 2011-03-10 18:02 UTC (permalink / raw)
  To: Ed Tomlinson, Mikko Vinni, linux-bluetooth, Gustavo F. Padovan

On 03/09/2011 11:32 PM, Johan Hedberg wrote:
> Hi,
>
> On Wed, Mar 09, 2011, Ed Tomlinson wrote:
>>> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
>>> index 9c4541b..f690eb5 100644
>>> --- a/net/bluetooth/hci_core.c
>>> +++ b/net/bluetooth/hci_core.c
>>> @@ -95,18 +95,17 @@ void hci_req_complete(struct hci_dev *hdev, __u16
>>> cmd, int result)
>>>    {
>>>    	BT_DBG("%s command 0x%04x result 0x%2.2x", hdev->name, cmd, result);
>>>
>>> +	if (hdev->req_status == HCI_REQ_PEND) {
>>> +		hdev->req_result = result;
>>> +		hdev->req_status = HCI_REQ_DONE;
>>> +		wake_up_interruptible(&hdev->req_wait_q);
>>> +	}
>>>    	/* If the request has set req_last_cmd (typical for multi-HCI
>>>    	 * command requests) check if the completed command matches
>>>    	 * this, and if not just return. Single HCI command requests
>>>    	 * typically leave req_last_cmd as 0 */
>>>    	if (hdev->req_last_cmd&&  cmd != hdev->req_last_cmd)
>>>    		return;
>>> -
>>> -	if (hdev->req_status == HCI_REQ_PEND) {
>>> -		hdev->req_result = result;
>>> -		hdev->req_status = HCI_REQ_DONE;
>>> -		wake_up_interruptible(&hdev->req_wait_q);
>>> -	}
>>>    }
>>>
>>>    static void hci_req_cancel(struct hci_dev *hdev, int err)
>>>
>>
>> Works here too - bluetooth comes up enabled.  On to Linus?
>
> All the patch does is it re-breaks the __hci_request function by
> removing proper synchronization from it (again) and thereby hides the
> real bug which is the kernel sending commands to the controller before
> the HCI_Reset command has completed.
>
> Johan
>


well, please send a patch my way and I will test it out!

Justin P. Mattock

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-10  7:32             ` Johan Hedberg
  2011-03-10 18:02               ` Justin P. Mattock
@ 2011-03-12  1:33               ` Gustavo F. Padovan
  2011-03-12 17:44                 ` Justin P. Mattock
  1 sibling, 1 reply; 25+ messages in thread
From: Gustavo F. Padovan @ 2011-03-12  1:33 UTC (permalink / raw)
  To: Ed Tomlinson, Justin P. Mattock, Mikko Vinni, linux-bluetooth

* Johan Hedberg <johan.hedberg@gmail.com> [2011-03-10 09:32:06 +0200]:

> Hi,
> 
> On Wed, Mar 09, 2011, Ed Tomlinson wrote:
> > > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > > index 9c4541b..f690eb5 100644
> > > --- a/net/bluetooth/hci_core.c
> > > +++ b/net/bluetooth/hci_core.c
> > > @@ -95,18 +95,17 @@ void hci_req_complete(struct hci_dev *hdev, __u16 
> > > cmd, int result)
> > >   {
> > >   	BT_DBG("%s command 0x%04x result 0x%2.2x", hdev->name, cmd, result);
> > > 
> > > +	if (hdev->req_status == HCI_REQ_PEND) {
> > > +		hdev->req_result = result;
> > > +		hdev->req_status = HCI_REQ_DONE;
> > > +		wake_up_interruptible(&hdev->req_wait_q);
> > > +	}
> > >   	/* If the request has set req_last_cmd (typical for multi-HCI
> > >   	 * command requests) check if the completed command matches
> > >   	 * this, and if not just return. Single HCI command requests
> > >   	 * typically leave req_last_cmd as 0 */
> > >   	if (hdev->req_last_cmd && cmd != hdev->req_last_cmd)
> > >   		return;
> > > -
> > > -	if (hdev->req_status == HCI_REQ_PEND) {
> > > -		hdev->req_result = result;
> > > -		hdev->req_status = HCI_REQ_DONE;
> > > -		wake_up_interruptible(&hdev->req_wait_q);
> > > -	}
> > >   }
> > > 
> > >   static void hci_req_cancel(struct hci_dev *hdev, int err)
> > > 
> > 
> > Works here too - bluetooth comes up enabled.  On to Linus?
> 
> All the patch does is it re-breaks the __hci_request function by
> removing proper synchronization from it (again) and thereby hides the
> real bug which is the kernel sending commands to the controller before
> the HCI_Reset command has completed.

I got an 1.1 Bluetooth dongle that can cause this issue, now I can test this
by myself. I'll work to fix this next week.

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

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

* Re: re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+"
  2011-03-12  1:33               ` Gustavo F. Padovan
@ 2011-03-12 17:44                 ` Justin P. Mattock
  2011-03-16 18:44                   ` [PATCH] Bluetooth: Fix HCI_RESET command syncronization Gustavo F. Padovan
  0 siblings, 1 reply; 25+ messages in thread
From: Justin P. Mattock @ 2011-03-12 17:44 UTC (permalink / raw)
  To: Ed Tomlinson, Mikko Vinni, linux-bluetooth

On 03/11/2011 05:33 PM, Gustavo F. Padovan wrote:
> * Johan Hedberg<johan.hedberg@gmail.com>  [2011-03-10 09:32:06 +0200]:
>
>> Hi,
>>
>> On Wed, Mar 09, 2011, Ed Tomlinson wrote:
>>>> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
>>>> index 9c4541b..f690eb5 100644
>>>> --- a/net/bluetooth/hci_core.c
>>>> +++ b/net/bluetooth/hci_core.c
>>>> @@ -95,18 +95,17 @@ void hci_req_complete(struct hci_dev *hdev, __u16
>>>> cmd, int result)
>>>>    {
>>>>    	BT_DBG("%s command 0x%04x result 0x%2.2x", hdev->name, cmd, result);
>>>>
>>>> +	if (hdev->req_status == HCI_REQ_PEND) {
>>>> +		hdev->req_result = result;
>>>> +		hdev->req_status = HCI_REQ_DONE;
>>>> +		wake_up_interruptible(&hdev->req_wait_q);
>>>> +	}
>>>>    	/* If the request has set req_last_cmd (typical for multi-HCI
>>>>    	 * command requests) check if the completed command matches
>>>>    	 * this, and if not just return. Single HCI command requests
>>>>    	 * typically leave req_last_cmd as 0 */
>>>>    	if (hdev->req_last_cmd&&  cmd != hdev->req_last_cmd)
>>>>    		return;
>>>> -
>>>> -	if (hdev->req_status == HCI_REQ_PEND) {
>>>> -		hdev->req_result = result;
>>>> -		hdev->req_status = HCI_REQ_DONE;
>>>> -		wake_up_interruptible(&hdev->req_wait_q);
>>>> -	}
>>>>    }
>>>>
>>>>    static void hci_req_cancel(struct hci_dev *hdev, int err)
>>>>
>>>
>>> Works here too - bluetooth comes up enabled.  On to Linus?
>>
>> All the patch does is it re-breaks the __hci_request function by
>> removing proper synchronization from it (again) and thereby hides the
>> real bug which is the kernel sending commands to the controller before
>> the HCI_Reset command has completed.
>
> I got an 1.1 Bluetooth dongle that can cause this issue, now I can test this
> by myself. I'll work to fix this next week.
>

cool... I am not going insane!!! let me know if you want me to test any 
patches out.

Justin P. Mattock

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

* [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-12 17:44                 ` Justin P. Mattock
@ 2011-03-16 18:44                   ` Gustavo F. Padovan
  2011-03-16 18:46                     ` Gustavo F. Padovan
  2011-03-17 10:35                     ` Szymon Janc
  0 siblings, 2 replies; 25+ messages in thread
From: Gustavo F. Padovan @ 2011-03-16 18:44 UTC (permalink / raw)
  To: linux-bluetooth; +Cc: mmvinni, justinmattock, edt

We can't send new commands before a cmd_complete for the HCI_RESET commnnd
shows up.

Reported-by: Mikko Vinni <mmvinni@yahoo.com>
Reported-by: Justin P. Mattock <justinmattock@gmail.com>
Reported-by: Ed Tomlinson <edt@aei.ca>
Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
---
 include/net/bluetooth/hci.h |    2 ++
 net/bluetooth/hci_core.c    |    3 +++
 net/bluetooth/hci_event.c   |    4 +++-
 3 files changed, 8 insertions(+), 1 deletions(-)

diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
index ec6acf2..2c0d309 100644
--- a/include/net/bluetooth/hci.h
+++ b/include/net/bluetooth/hci.h
@@ -84,6 +84,8 @@ enum {
 	HCI_SERVICE_CACHE,
 	HCI_LINK_KEYS,
 	HCI_DEBUG_KEYS,
+
+	HCI_RESET,
 };
 
 /* HCI ioctl defines */
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index b372fb8..32b82e2 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -534,6 +534,8 @@ int hci_dev_open(__u16 dev)
 		set_bit(HCI_INIT, &hdev->flags);
 		hdev->init_last_cmd = 0;
 
+		set_bit(HCI_RESET, &hdev->flags);
+
 		ret = __hci_request(hdev, hci_init_req, 0,
 					msecs_to_jiffies(HCI_INIT_TIMEOUT));
 
@@ -1074,6 +1076,7 @@ static void hci_cmd_timer(unsigned long arg)
 
 	BT_ERR("%s command tx timeout", hdev->name);
 	atomic_set(&hdev->cmd_cnt, 1);
+	clear_bit(HCI_RESET, &hdev->flags);
 	tasklet_schedule(&hdev->cmd_task);
 }
 
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index 3fbfa50..cebe7588 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -183,6 +183,8 @@ static void hci_cc_reset(struct hci_dev *hdev, struct sk_buff *skb)
 
 	BT_DBG("%s status 0x%x", hdev->name, status);
 
+	clear_bit(HCI_RESET, &hdev->flags);
+
 	hci_req_complete(hdev, HCI_OP_RESET, status);
 }
 
@@ -1847,7 +1849,7 @@ static inline void hci_cmd_status_evt(struct hci_dev *hdev, struct sk_buff *skb)
 	if (ev->opcode != HCI_OP_NOP)
 		del_timer(&hdev->cmd_timer);
 
-	if (ev->ncmd) {
+	if (ev->ncmd && !test_bit(HCI_RESET, &hdev->flags)) {
 		atomic_set(&hdev->cmd_cnt, 1);
 		if (!skb_queue_empty(&hdev->cmd_q))
 			tasklet_schedule(&hdev->cmd_task);
-- 
1.7.4.1


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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 18:44                   ` [PATCH] Bluetooth: Fix HCI_RESET command syncronization Gustavo F. Padovan
@ 2011-03-16 18:46                     ` Gustavo F. Padovan
  2011-03-16 18:48                       ` Anderson Lizardo
  2011-03-17 10:35                     ` Szymon Janc
  1 sibling, 1 reply; 25+ messages in thread
From: Gustavo F. Padovan @ 2011-03-16 18:46 UTC (permalink / raw)
  To: linux-bluetooth; +Cc: mmvinni, justinmattock, edt


* Gustavo F. Padovan <padovan@profusion.mobi> [2011-03-16 15:44:46 -0300]:

> We can't send new commands before a cmd_complete for the HCI_RESET commnnd
> shows up.
> 
> Reported-by: Mikko Vinni <mmvinni@yahoo.com>
> Reported-by: Justin P. Mattock <justinmattock@gmail.com>
> Reported-by: Ed Tomlinson <edt@aei.ca>
> Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
> ---
>  include/net/bluetooth/hci.h |    2 ++
>  net/bluetooth/hci_core.c    |    3 +++
>  net/bluetooth/hci_event.c   |    4 +++-
>  3 files changed, 8 insertions(+), 1 deletions(-)

It works for me, but can someone test this and then add a Tested-by line.
Thanks.

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

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 18:46                     ` Gustavo F. Padovan
@ 2011-03-16 18:48                       ` Anderson Lizardo
  2011-03-16 19:01                         ` Gustavo F. Padovan
  0 siblings, 1 reply; 25+ messages in thread
From: Anderson Lizardo @ 2011-03-16 18:48 UTC (permalink / raw)
  To: linux-bluetooth, mmvinni, justinmattock, edt; +Cc: Gustavo F. Padovan

Hi Gustavo,

On Wed, Mar 16, 2011 at 2:46 PM, Gustavo F. Padovan
<padovan@profusion.mobi> wrote:
>
> * Gustavo F. Padovan <padovan@profusion.mobi> [2011-03-16 15:44:46 -0300]:
>
>> We can't send new commands before a cmd_complete for the HCI_RESET commnnd
>> shows up.
>>
>> Reported-by: Mikko Vinni <mmvinni@yahoo.com>
>> Reported-by: Justin P. Mattock <justinmattock@gmail.com>
>> Reported-by: Ed Tomlinson <edt@aei.ca>
>> Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
>> ---
>>  include/net/bluetooth/hci.h |    2 ++
>>  net/bluetooth/hci_core.c    |    3 +++
>>  net/bluetooth/hci_event.c   |    4 +++-
>>  3 files changed, 8 insertions(+), 1 deletions(-)
>
> It works for me, but can someone test this and then add a Tested-by line.
> Thanks.

Which hardware is needed to test this?

I have a 1.1 dongle which doesn't work on current mainline tree, but
I'm not sure it is this same issue. I "fixed" it by upgrading the
firmware to support 1.2, but I can downgrade it to test if this is
related to 1.1 dongles.

Regards,
-- 
Anderson Lizardo
Instituto Nokia de Tecnologia - INdT
Manaus - Brazil

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 18:48                       ` Anderson Lizardo
@ 2011-03-16 19:01                         ` Gustavo F. Padovan
  2011-03-16 19:11                           ` Justin P. Mattock
  0 siblings, 1 reply; 25+ messages in thread
From: Gustavo F. Padovan @ 2011-03-16 19:01 UTC (permalink / raw)
  To: Anderson Lizardo; +Cc: linux-bluetooth, mmvinni, justinmattock, edt

Hi Anderson,

* Anderson Lizardo <anderson.lizardo@openbossa.org> [2011-03-16 14:48:31 -0400]:

> Hi Gustavo,
> 
> On Wed, Mar 16, 2011 at 2:46 PM, Gustavo F. Padovan
> <padovan@profusion.mobi> wrote:
> >
> > * Gustavo F. Padovan <padovan@profusion.mobi> [2011-03-16 15:44:46 -0300]:
> >
> >> We can't send new commands before a cmd_complete for the HCI_RESET commnnd
> >> shows up.
> >>
> >> Reported-by: Mikko Vinni <mmvinni@yahoo.com>
> >> Reported-by: Justin P. Mattock <justinmattock@gmail.com>
> >> Reported-by: Ed Tomlinson <edt@aei.ca>
> >> Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
> >> ---
> >>  include/net/bluetooth/hci.h |    2 ++
> >>  net/bluetooth/hci_core.c    |    3 +++
> >>  net/bluetooth/hci_event.c   |    4 +++-
> >>  3 files changed, 8 insertions(+), 1 deletions(-)
> >
> > It works for me, but can someone test this and then add a Tested-by line.
> > Thanks.
> 
> Which hardware is needed to test this?

I don't know, I have a dongle that can cause this issue. It's CSR 1.1.
I don't know which other dongles have a similar issue.

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

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 19:01                         ` Gustavo F. Padovan
@ 2011-03-16 19:11                           ` Justin P. Mattock
  2011-03-16 19:15                             ` Gustavo F. Padovan
  0 siblings, 1 reply; 25+ messages in thread
From: Justin P. Mattock @ 2011-03-16 19:11 UTC (permalink / raw)
  To: Anderson Lizardo, linux-bluetooth, mmvinni, edt

On 03/16/2011 12:01 PM, Gustavo F. Padovan wrote:
> Hi Anderson,
>
> * Anderson Lizardo<anderson.lizardo@openbossa.org>  [2011-03-16 14:48:31 -0400]:
>
>> Hi Gustavo,
>>
>> On Wed, Mar 16, 2011 at 2:46 PM, Gustavo F. Padovan
>> <padovan@profusion.mobi>  wrote:
>>>
>>> * Gustavo F. Padovan<padovan@profusion.mobi>  [2011-03-16 15:44:46 -0300]:
>>>
>>>> We can't send new commands before a cmd_complete for the HCI_RESET commnnd
>>>> shows up.
>>>>
>>>> Reported-by: Mikko Vinni<mmvinni@yahoo.com>
>>>> Reported-by: Justin P. Mattock<justinmattock@gmail.com>
>>>> Reported-by: Ed Tomlinson<edt@aei.ca>
>>>> Signed-off-by: Gustavo F. Padovan<padovan@profusion.mobi>
>>>> ---
>>>>   include/net/bluetooth/hci.h |    2 ++
>>>>   net/bluetooth/hci_core.c    |    3 +++
>>>>   net/bluetooth/hci_event.c   |    4 +++-
>>>>   3 files changed, 8 insertions(+), 1 deletions(-)
>>>
>>> It works for me, but can someone test this and then add a Tested-by line.
>>> Thanks.
>>
>> Which hardware is needed to test this?
>
> I don't know, I have a dongle that can cause this issue. It's CSR 1.1.
> I don't know which other dongles have a similar issue.
>

I started to test this out, but crapped out at hci_cmd_timer with the 
current Mainline do you have this for the current?

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 19:11                           ` Justin P. Mattock
@ 2011-03-16 19:15                             ` Gustavo F. Padovan
  2011-03-16 20:02                               ` Justin Mattock
  0 siblings, 1 reply; 25+ messages in thread
From: Gustavo F. Padovan @ 2011-03-16 19:15 UTC (permalink / raw)
  To: Justin P. Mattock; +Cc: Anderson Lizardo, linux-bluetooth, mmvinni, edt

Hi Justin,

* Justin P. Mattock <justinmattock@gmail.com> [2011-03-16 12:11:10 -0700]:

> On 03/16/2011 12:01 PM, Gustavo F. Padovan wrote:
> > Hi Anderson,
> >
> > * Anderson Lizardo<anderson.lizardo@openbossa.org>  [2011-03-16 14:48:31 -0400]:
> >
> >> Hi Gustavo,
> >>
> >> On Wed, Mar 16, 2011 at 2:46 PM, Gustavo F. Padovan
> >> <padovan@profusion.mobi>  wrote:
> >>>
> >>> * Gustavo F. Padovan<padovan@profusion.mobi>  [2011-03-16 15:44:46 -0300]:
> >>>
> >>>> We can't send new commands before a cmd_complete for the HCI_RESET commnnd
> >>>> shows up.
> >>>>
> >>>> Reported-by: Mikko Vinni<mmvinni@yahoo.com>
> >>>> Reported-by: Justin P. Mattock<justinmattock@gmail.com>
> >>>> Reported-by: Ed Tomlinson<edt@aei.ca>
> >>>> Signed-off-by: Gustavo F. Padovan<padovan@profusion.mobi>
> >>>> ---
> >>>>   include/net/bluetooth/hci.h |    2 ++
> >>>>   net/bluetooth/hci_core.c    |    3 +++
> >>>>   net/bluetooth/hci_event.c   |    4 +++-
> >>>>   3 files changed, 8 insertions(+), 1 deletions(-)
> >>>
> >>> It works for me, but can someone test this and then add a Tested-by line.
> >>> Thanks.
> >>
> >> Which hardware is needed to test this?
> >
> > I don't know, I have a dongle that can cause this issue. It's CSR 1.1.
> > I don't know which other dongles have a similar issue.
> >
> 
> I started to test this out, but crapped out at hci_cmd_timer with the 
> current Mainline do you have this for the current?

No, it's based on bluetooth-next (2.6.39). But you can drop the hci_cmd_timer
part while testing it. It's not needed unless you have and hci_reset cmd
timeout.

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

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 19:15                             ` Gustavo F. Padovan
@ 2011-03-16 20:02                               ` Justin Mattock
  2011-03-16 21:13                                 ` Mikko Vinni
  2011-03-16 22:33                                 ` Ed Tomlinson
  0 siblings, 2 replies; 25+ messages in thread
From: Justin Mattock @ 2011-03-16 20:02 UTC (permalink / raw)
  To: Justin P. Mattock, Anderson Lizardo, linux-bluetooth, mmvinni, edt
  Cc: Gustavo F. Padovan

> No, it's based on bluetooth-next (2.6.39). But you can drop the hci_cmd_timer
> part while testing it. It's not needed unless you have and hci_reset cmd
> timeout.
>
> --
> Gustavo F. Padovan
> http://profusion.mobi
>

o.k. works over here..
Tested-by: Justin P. Mattock <justinmattock@gmail.com>

here is an updated patch for the current Mainline if anybody needs it:

---
 include/net/bluetooth/hci.h |    1 +
 net/bluetooth/hci_core.c    |    1 +
 net/bluetooth/hci_event.c   |    4 +++-
 3 files changed, 5 insertions(+), 1 deletions(-)

diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
index 29a7a8c..c4f4c42 100644
--- a/include/net/bluetooth/hci.h
+++ b/include/net/bluetooth/hci.h
@@ -76,6 +76,7 @@ enum {
 	HCI_INQUIRY,

 	HCI_RAW,
+	HCI_RESET,
 };

 /* HCI ioctl defines */
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 9c4541b..07a1a4c 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -522,6 +522,7 @@ int hci_dev_open(__u16 dev)
 		atomic_set(&hdev->cmd_cnt, 1);
 		set_bit(HCI_INIT, &hdev->flags);

+		set_bit(HCI_RESET, &hdev->flags);	
 		//__hci_request(hdev, hci_reset_req, 0, HZ);
 		ret = __hci_request(hdev, hci_init_req, 0,
 					msecs_to_jiffies(HCI_INIT_TIMEOUT));
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index a290854..a63bcf0 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -183,6 +183,8 @@ static void hci_cc_reset(struct hci_dev *hdev,
struct sk_buff *skb)

 	BT_DBG("%s status 0x%x", hdev->name, status);

+	clear_bit(HCI_RESET, &hdev->flags);
+
 	hci_req_complete(hdev, HCI_OP_RESET, status);
 }

@@ -1464,7 +1466,7 @@ static inline void hci_cmd_status_evt(struct
hci_dev *hdev, struct sk_buff *skb)
 		break;
 	}

-	if (ev->ncmd) {
+	if (ev->ncmd && !test_bit(HCI_RESET, &hdev->flags)) {
 		atomic_set(&hdev->cmd_cnt, 1);
 		if (!skb_queue_empty(&hdev->cmd_q))
 			tasklet_schedule(&hdev->cmd_task);
-- 
1.7.4.1


-- 
Justin P. Mattock

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 20:02                               ` Justin Mattock
@ 2011-03-16 21:13                                 ` Mikko Vinni
  2011-03-16 22:33                                 ` Ed Tomlinson
  1 sibling, 0 replies; 25+ messages in thread
From: Mikko Vinni @ 2011-03-16 21:13 UTC (permalink / raw)
  To: Justin Mattock, Anderson Lizardo, linux-bluetooth, edt; +Cc: Gustavo F. Padovan

Justin Mattock wrote:

> o.k. works over here..
> Tested-by:  Justin P. Mattock <justinmattock@gmail.com>

Works for me too (tested with the (original) patch applied on top of 
bluetooth-next
merged on 2.6.38).

Tested-by: Mikko Vinni <mmvinni@yahoo.com>


Thanks for solving the problem!

Mikko


> 
> here  is an updated patch for the current Mainline if anybody needs  it:
> 
...


      

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 20:02                               ` Justin Mattock
  2011-03-16 21:13                                 ` Mikko Vinni
@ 2011-03-16 22:33                                 ` Ed Tomlinson
  1 sibling, 0 replies; 25+ messages in thread
From: Ed Tomlinson @ 2011-03-16 22:33 UTC (permalink / raw)
  To: Justin Mattock
  Cc: Anderson Lizardo, linux-bluetooth, mmvinni, Gustavo F. Padovan

On Wednesday 16 March 2011 16:02:17 Justin Mattock wrote:
> > No, it's based on bluetooth-next (2.6.39). But you can drop the hci_cmd_timer
> > part while testing it. It's not needed unless you have and hci_reset cmd
> > timeout.
> >
> > --
> > Gustavo F. Padovan
> > http://profusion.mobi
> >
> 
> o.k. works over here..
> Tested-by: Justin P. Mattock <justinmattock@gmail.com>

Works here too (Justin's varient on top of .38)
Tested-by: Ed Tomlinson <edt@aei.ca>

Thanks
Ed

> here is an updated patch for the current Mainline if anybody needs it:
> 
> ---
>  include/net/bluetooth/hci.h |    1 +
>  net/bluetooth/hci_core.c    |    1 +
>  net/bluetooth/hci_event.c   |    4 +++-
>  3 files changed, 5 insertions(+), 1 deletions(-)
> 
> diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
> index 29a7a8c..c4f4c42 100644
> --- a/include/net/bluetooth/hci.h
> +++ b/include/net/bluetooth/hci.h
> @@ -76,6 +76,7 @@ enum {
>  	HCI_INQUIRY,
> 
>  	HCI_RAW,
> +	HCI_RESET,
>  };
> 
>  /* HCI ioctl defines */
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index 9c4541b..07a1a4c 100644
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -522,6 +522,7 @@ int hci_dev_open(__u16 dev)
>  		atomic_set(&hdev->cmd_cnt, 1);
>  		set_bit(HCI_INIT, &hdev->flags);
> 
> +		set_bit(HCI_RESET, &hdev->flags);	
>  		//__hci_request(hdev, hci_reset_req, 0, HZ);
>  		ret = __hci_request(hdev, hci_init_req, 0,
>  					msecs_to_jiffies(HCI_INIT_TIMEOUT));
> diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> index a290854..a63bcf0 100644
> --- a/net/bluetooth/hci_event.c
> +++ b/net/bluetooth/hci_event.c
> @@ -183,6 +183,8 @@ static void hci_cc_reset(struct hci_dev *hdev,
> struct sk_buff *skb)
> 
>  	BT_DBG("%s status 0x%x", hdev->name, status);
> 
> +	clear_bit(HCI_RESET, &hdev->flags);
> +
>  	hci_req_complete(hdev, HCI_OP_RESET, status);
>  }
> 
> @@ -1464,7 +1466,7 @@ static inline void hci_cmd_status_evt(struct
> hci_dev *hdev, struct sk_buff *skb)
>  		break;
>  	}
> 
> -	if (ev->ncmd) {
> +	if (ev->ncmd && !test_bit(HCI_RESET, &hdev->flags)) {
>  		atomic_set(&hdev->cmd_cnt, 1);
>  		if (!skb_queue_empty(&hdev->cmd_q))
>  			tasklet_schedule(&hdev->cmd_task);
> 

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-16 18:44                   ` [PATCH] Bluetooth: Fix HCI_RESET command syncronization Gustavo F. Padovan
  2011-03-16 18:46                     ` Gustavo F. Padovan
@ 2011-03-17 10:35                     ` Szymon Janc
  2011-03-17 16:48                       ` Gustavo F. Padovan
  1 sibling, 1 reply; 25+ messages in thread
From: Szymon Janc @ 2011-03-17 10:35 UTC (permalink / raw)
  To: Gustavo F. Padovan; +Cc: linux-bluetooth, mmvinni, justinmattock, edt

> We can't send new commands before a cmd_complete for the HCI_RESET commnnd

Typo: comm*a*nd

> shows up.
> 
> Reported-by: Mikko Vinni <mmvinni@yahoo.com>
> Reported-by: Justin P. Mattock <justinmattock@gmail.com>
> Reported-by: Ed Tomlinson <edt@aei.ca>
> Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
> ---
>  include/net/bluetooth/hci.h |    2 ++
>  net/bluetooth/hci_core.c    |    3 +++
>  net/bluetooth/hci_event.c   |    4 +++-
>  3 files changed, 8 insertions(+), 1 deletions(-)
> 
> diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
> index ec6acf2..2c0d309 100644
> --- a/include/net/bluetooth/hci.h
> +++ b/include/net/bluetooth/hci.h
> @@ -84,6 +84,8 @@ enum {
>  	HCI_SERVICE_CACHE,
>  	HCI_LINK_KEYS,
>  	HCI_DEBUG_KEYS,
> +
> +	HCI_RESET,
>  };
>  
>  /* HCI ioctl defines */
> diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> index b372fb8..32b82e2 100644
> --- a/net/bluetooth/hci_core.c
> +++ b/net/bluetooth/hci_core.c
> @@ -534,6 +534,8 @@ int hci_dev_open(__u16 dev)
>  		set_bit(HCI_INIT, &hdev->flags);
>  		hdev->init_last_cmd = 0;
>  
> +		set_bit(HCI_RESET, &hdev->flags);

Does this work with HCI_QUIRK_NO_RESET enabled?
Shouldn't this bit be set only right before sending HCI_OP_RESET
(in hci_init_req and hci_reset_req) for doing what commit msg says?

Now it looks more like a workaround for initialization issue..

> +
>  		ret = __hci_request(hdev, hci_init_req, 0,
>  					msecs_to_jiffies(HCI_INIT_TIMEOUT));
>  
> @@ -1074,6 +1076,7 @@ static void hci_cmd_timer(unsigned long arg)
>  
>  	BT_ERR("%s command tx timeout", hdev->name);
>  	atomic_set(&hdev->cmd_cnt, 1);
> +	clear_bit(HCI_RESET, &hdev->flags);
>  	tasklet_schedule(&hdev->cmd_task);
>  }
>  
> diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> index 3fbfa50..cebe7588 100644
> --- a/net/bluetooth/hci_event.c
> +++ b/net/bluetooth/hci_event.c
> @@ -183,6 +183,8 @@ static void hci_cc_reset(struct hci_dev *hdev, struct sk_buff *skb)
>  
>  	BT_DBG("%s status 0x%x", hdev->name, status);
>  
> +	clear_bit(HCI_RESET, &hdev->flags);
> +
>  	hci_req_complete(hdev, HCI_OP_RESET, status);
>  }
>  
> @@ -1847,7 +1849,7 @@ static inline void hci_cmd_status_evt(struct hci_dev *hdev, struct sk_buff *skb)
>  	if (ev->opcode != HCI_OP_NOP)
>  		del_timer(&hdev->cmd_timer);
>  
> -	if (ev->ncmd) {
> +	if (ev->ncmd && !test_bit(HCI_RESET, &hdev->flags)) {
>  		atomic_set(&hdev->cmd_cnt, 1);
>  		if (!skb_queue_empty(&hdev->cmd_q))
>  			tasklet_schedule(&hdev->cmd_task);

Maybe use unlikely() here?

-- 
BR
Szymon Janc

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

* Re: [PATCH] Bluetooth: Fix HCI_RESET command syncronization
  2011-03-17 10:35                     ` Szymon Janc
@ 2011-03-17 16:48                       ` Gustavo F. Padovan
  0 siblings, 0 replies; 25+ messages in thread
From: Gustavo F. Padovan @ 2011-03-17 16:48 UTC (permalink / raw)
  To: Szymon Janc; +Cc: linux-bluetooth, mmvinni, justinmattock, edt

Hi Szymon,

* Szymon Janc <szymon.janc@tieto.com> [2011-03-17 11:35:20 +0100]:

> > We can't send new commands before a cmd_complete for the HCI_RESET commnnd
> 
> Typo: comm*a*nd
> 
> > shows up.
> > 
> > Reported-by: Mikko Vinni <mmvinni@yahoo.com>
> > Reported-by: Justin P. Mattock <justinmattock@gmail.com>
> > Reported-by: Ed Tomlinson <edt@aei.ca>
> > Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
> > ---
> >  include/net/bluetooth/hci.h |    2 ++
> >  net/bluetooth/hci_core.c    |    3 +++
> >  net/bluetooth/hci_event.c   |    4 +++-
> >  3 files changed, 8 insertions(+), 1 deletions(-)
> > 
> > diff --git a/include/net/bluetooth/hci.h b/include/net/bluetooth/hci.h
> > index ec6acf2..2c0d309 100644
> > --- a/include/net/bluetooth/hci.h
> > +++ b/include/net/bluetooth/hci.h
> > @@ -84,6 +84,8 @@ enum {
> >  	HCI_SERVICE_CACHE,
> >  	HCI_LINK_KEYS,
> >  	HCI_DEBUG_KEYS,
> > +
> > +	HCI_RESET,
> >  };
> >  
> >  /* HCI ioctl defines */
> > diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
> > index b372fb8..32b82e2 100644
> > --- a/net/bluetooth/hci_core.c
> > +++ b/net/bluetooth/hci_core.c
> > @@ -534,6 +534,8 @@ int hci_dev_open(__u16 dev)
> >  		set_bit(HCI_INIT, &hdev->flags);
> >  		hdev->init_last_cmd = 0;
> >  
> > +		set_bit(HCI_RESET, &hdev->flags);
> 
> Does this work with HCI_QUIRK_NO_RESET enabled?
> Shouldn't this bit be set only right before sending HCI_OP_RESET
> (in hci_init_req and hci_reset_req) for doing what commit msg says?
> 
> Now it looks more like a workaround for initialization issue..

Ah yes, I fixed this as well now.

> 
> > +
> >  		ret = __hci_request(hdev, hci_init_req, 0,
> >  					msecs_to_jiffies(HCI_INIT_TIMEOUT));
> >  
> > @@ -1074,6 +1076,7 @@ static void hci_cmd_timer(unsigned long arg)
> >  
> >  	BT_ERR("%s command tx timeout", hdev->name);
> >  	atomic_set(&hdev->cmd_cnt, 1);
> > +	clear_bit(HCI_RESET, &hdev->flags);
> >  	tasklet_schedule(&hdev->cmd_task);
> >  }
> >  
> > diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
> > index 3fbfa50..cebe7588 100644
> > --- a/net/bluetooth/hci_event.c
> > +++ b/net/bluetooth/hci_event.c
> > @@ -183,6 +183,8 @@ static void hci_cc_reset(struct hci_dev *hdev, struct sk_buff *skb)
> >  
> >  	BT_DBG("%s status 0x%x", hdev->name, status);
> >  
> > +	clear_bit(HCI_RESET, &hdev->flags);
> > +
> >  	hci_req_complete(hdev, HCI_OP_RESET, status);
> >  }
> >  
> > @@ -1847,7 +1849,7 @@ static inline void hci_cmd_status_evt(struct hci_dev *hdev, struct sk_buff *skb)
> >  	if (ev->opcode != HCI_OP_NOP)
> >  		del_timer(&hdev->cmd_timer);
> >  
> > -	if (ev->ncmd) {
> > +	if (ev->ncmd && !test_bit(HCI_RESET, &hdev->flags)) {
> >  		atomic_set(&hdev->cmd_cnt, 1);
> >  		if (!skb_queue_empty(&hdev->cmd_q))
> >  			tasklet_schedule(&hdev->cmd_task);
> 
> Maybe use unlikely() here?

We don't use this in Bluetooth.

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

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

end of thread, other threads:[~2011-03-17 16:48 UTC | newest]

Thread overview: 25+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2011-02-28 22:29 re "bluetooth disabled" and "[BUG] usb problems in .38-rc3+" Mikko Vinni
2011-03-01  5:51 ` Justin Mattock
2011-03-02 14:00 ` Johan Hedberg
2011-03-03 10:54   ` Mikko Vinni
2011-03-03 14:31     ` Johan Hedberg
2011-03-04  4:47       ` Ville Tervo
2011-03-07 19:50       ` Mikko Vinni
2011-03-08 22:30         ` Justin P. Mattock
2011-03-09 21:23         ` Justin P. Mattock
2011-03-10  2:54           ` Ed Tomlinson
2011-03-10  7:32             ` Johan Hedberg
2011-03-10 18:02               ` Justin P. Mattock
2011-03-12  1:33               ` Gustavo F. Padovan
2011-03-12 17:44                 ` Justin P. Mattock
2011-03-16 18:44                   ` [PATCH] Bluetooth: Fix HCI_RESET command syncronization Gustavo F. Padovan
2011-03-16 18:46                     ` Gustavo F. Padovan
2011-03-16 18:48                       ` Anderson Lizardo
2011-03-16 19:01                         ` Gustavo F. Padovan
2011-03-16 19:11                           ` Justin P. Mattock
2011-03-16 19:15                             ` Gustavo F. Padovan
2011-03-16 20:02                               ` Justin Mattock
2011-03-16 21:13                                 ` Mikko Vinni
2011-03-16 22:33                                 ` Ed Tomlinson
2011-03-17 10:35                     ` Szymon Janc
2011-03-17 16:48                       ` Gustavo F. Padovan

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.