2009-04-05 12:02:21

by Stuart Pook

[permalink] [raw]
Subject: bluez 4.34 + Linksys USBBT100 + hcitool scan -> core dump

hello

I normally use a Belkin F8T017 Bluetooth Adapter (for audio) which works ok but its range is rather limited.

I have a Linksys (Cisco) USBBT100 Bluetooth 1.1 Adapter which has a 1.2 dBi antenna. I used to use it with Bluez 3 and it had a better range than my Belkin F8T017. It used to work (but not for audio) with older versions of bluez 4. I tried it again with bluez 4.34 and now a simple "hcitool scan" makes bluetoothd core dump.

Bluetoothd does not crash when I swap my USBBT100 for my F8T017. A hcitool scan does however find fewer hosts.

It would be great if my USBBT100 worked again. Please let me know if I can send any more information.

thanks
Stuart

: root; valgrind /usr/local/sbin/bluetoothd -dn
==9799== Memcheck, a memory error detector.
==9799== Copyright (C) 2002-2008, and GNU GPL'd, by Julian Seward et al.
==9799== Using LibVEX rev 1884, a library for dynamic binary translation.
==9799== Copyright (C) 2004-2008, and GNU GPL'd, by OpenWorks LLP.
==9799== Using valgrind-3.4.1-Debian, a dynamic binary instrumentation framework.
==9799== Copyright (C) 2000-2008, and GNU GPL'd, by Julian Seward et al.
==9799== For more details, rerun with: -v
==9799==
bluetoothd[9799]: Bluetooth daemon 4.34
bluetoothd[9799]: Enabling debug information
bluetoothd[9799]: parsing main.conf
bluetoothd[9799]: discovto=0
bluetoothd[9799]: Key file does not have key 'PairableTimeout'
bluetoothd[9799]: pageto=8192
bluetoothd[9799]: name=%h-%d
bluetoothd[9799]: class=0x000100
bluetoothd[9799]: inqmode=0
bluetoothd[9799]: Key file does not have key 'InitiallyPowered'
bluetoothd[9799]: Key file does not have key 'RememberPowered'
bluetoothd[9799]: Key file does not have key 'DeviceID'
bluetoothd[9799]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[9799]: Starting SDP server
bluetoothd[9799]: Loading plugins /usr/local/lib/bluetooth/plugins
bluetoothd[9799]: register_interface: path /org/bluez/9799/any
bluetoothd[9799]: Registered interface org.bluez.Service on path /org/bluez/9799/any
bluetoothd[9799]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[9799]: Unix socket created: 11
bluetoothd[9799]: Telephony plugin initialized
bluetoothd[9799]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[9799]: HCI dev 0 registered
bluetoothd[9799]: child 9802 forked
bluetoothd[9799]: HCI dev 0 already up
bluetoothd[9799]: Starting security manager 0
bluetoothd[9799]: periodic_inquiry_exit at adapter startup
bluetoothd[9799]: register_interface: path /org/bluez/9799/hci0
bluetoothd[9799]: Registered interface org.bluez.Service on path /org/bluez/9799/hci0
bluetoothd[9799]: headset_server_probe: path /org/bluez/9799/hci0
bluetoothd[9799]: Adding record with handle 0x10000
bluetoothd[9799]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[9799]: Adding record with handle 0x10001
bluetoothd[9799]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[9799]: a2dp_server_probe: path /org/bluez/9799/hci0
bluetoothd[9799]: SEP 0x4b526f0 registered: type:0 codec:0 seid:1
bluetoothd[9799]: Adding record with handle 0x10002
bluetoothd[9799]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[9799]: avrcp_server_probe: path /org/bluez/9799/hci0
bluetoothd[9799]: Adding record with handle 0x10003
bluetoothd[9799]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[9799]: Adding record with handle 0x10004
bluetoothd[9799]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[9799]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_1A_45_2F_49_98
bluetoothd[9799]: Probe drivers for /org/bluez/9799/hci0/dev_00_1A_45_2F_49_98
bluetoothd[9799]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[9799]: Registered interface org.bluez.Audio on path /org/bluez/9799/hci0/dev_00_1A_45_2F_49_98
bluetoothd[9799]: Found Headset record
bluetoothd[9799]: Discovered Headset service on RFCOMM channel 2
bluetoothd[9799]: Registered interface org.bluez.Headset on path /org/bluez/9799/hci0/dev_00_1A_45_2F_49_98
bluetoothd[9799]: Found Handsfree record
bluetoothd[9799]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_03_89_FE_E6_19
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_17_E5_16_88_6C
bluetoothd[9799]: Creating device /org/bluez/9799/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[9799]: Changing service classes to 0x480104
==9799== Syscall param ioctl(generic) points to unaddressable byte(s)
==9799== at 0x40007F2: (within /lib/ld-2.9.so)
==9799== by 0x121A6F: adapter_start (in /usr/local/stow/bluez-4.34/sbin/bluetoothd)
==9799== by 0x11C560: manager_start_adapter (in /usr/local/stow/bluez-4.34/sbin/bluetoothd)
==9799== by 0x111DED: device_devup_setup (in /usr/local/stow/bluez-4.34/sbin/bluetoothd)
==9799== by 0x11280D: main (in /usr/local/stow/bluez-4.34/sbin/bluetoothd)
==9799== Address 0x0 is not stack'd, malloc'd or (recently) free'd
bluetoothd[9802]: Can't set link policy on hci0: No such device (19)
==9802== Syscall param ioctl(generic) points to unaddressable byte(s)
==9802== at 0x40007F2: (within /lib/ld-2.9.so)
==9802== by 0x1127DB: main (in /usr/local/stow/bluez-4.34/sbin/bluetoothd)
==9802== Address 0x0 is not stack'd, malloc'd or (recently) free'd
bluetoothd[9799]: Adapter /org/bluez/9799/hci0 has been enabled
bluetoothd[9799]: Stopping security manager 0
bluetoothd[9799]: Changing service classes to 0x480104
==9802==
bluetoothd[9799]: Entering main loop
==9802== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 45 from 3)
==9802== malloc/free: in use at exit: 29,123 bytes in 329 blocks.
==9802== malloc/free: 641 allocs, 312 frees, 250,062 bytes allocated.
==9802== For counts of detected errors, rerun with: -v
==9802== searching for pointers to 329 not-freed blocks.
==9802== checked 114,644 bytes.
==9802==
==9802== LEAK SUMMARY:
==9802== definitely lost: 0 bytes in 0 blocks.
==9802== possibly lost: 744 bytes in 3 blocks.
==9802== still reachable: 28,379 bytes in 326 blocks.
==9802== suppressed: 0 bytes in 0 blocks.
==9802== Rerun with --leak-check=full to see details of leaked memory.
bluetoothd[9799]: child 9802 exited
bluetoothd[9799]: HCI dev 0 down
bluetoothd[9799]: Adapter /org/bluez/9799/hci0 has been disabled
bluetoothd[9799]: HCI dev 0 up
bluetoothd[9799]: Starting security manager 0
==9799== Stack overflow in thread 1: can't grow stack to 0xbe534fc4
==9799==
==9799== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==9799== Access not within mapped region at address 0xBE534FC4
==9799== at 0x4A1B3BA: __xstat (in /lib/i686/cmov/libc-2.9.so)
==9799== If you believe this happened as a result of a stack overflow in your
==9799== program's main thread (unlikely but possible), you can try to increase
==9799== the size of the main thread stack using the --main-stacksize= flag.
==9799== The main thread stack size used in this run was 8388608.
==9799== Stack overflow in thread 1: can't grow stack to 0xbe534fc0
==9799==
==9799== Process terminating with default action of signal 11 (SIGSEGV)
==9799== Access not within mapped region at address 0xBE534FC0
==9799== at 0x48203EC: _vgnU_freeres (vg_preloaded.c:56)
==9799== If you believe this happened as a result of a stack overflow in your
==9799== program's main thread (unlikely but possible), you can try to increase
==9799== the size of the main thread stack using the --main-stacksize= flag.
==9799== The main thread stack size used in this run was 8388608.
==9799==
==9799== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 45 from 3)
==9799== malloc/free: in use at exit: 44,018 bytes in 679 blocks.
==9799== malloc/free: 176,416 allocs, 175,737 frees, 1,525,621 bytes allocated.
==9799== For counts of detected errors, rerun with: -v
==9799== searching for pointers to 679 not-freed blocks.
==9799== checked 5,245,628 bytes.
==9799==
==9799== LEAK SUMMARY:
==9799== definitely lost: 0 bytes in 0 blocks.
==9799== possibly lost: 744 bytes in 3 blocks.
==9799== still reachable: 43,274 bytes in 676 blocks.
==9799== suppressed: 0 bytes in 0 blocks.
==9799== Rerun with --leak-check=full to see details of leaked memory.
Segmentation fault


:; hcitool scan
Scanning ...
00:19:B7:49:C5:76 n/a
00:03:C9:D4:34:E9 Wanadoo_f3ed
00:16:AE:4C:A3:2C Livebox-A328

:; lsusb -d 0a12:0001
Bus 003 Device 006: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
: root; lsusb -vd 0a12:0001

Bus 003 Device 006: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 1.10
bDeviceClass 224 Wireless
bDeviceSubClass 1 Radio Frequency
bDeviceProtocol 1 Bluetooth
bMaxPacketSize0 64
idVendor 0x0a12 Cambridge Silicon Radio, Ltd
idProduct 0x0001 Bluetooth Dongle (HCI mode)
bcdDevice 5.25
iManufacturer 0
iProduct 0
iSerial 0
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 193
bNumInterfaces 3
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xc0
Self Powered
MaxPower 0mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 3
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 3
Transfer Type Interrupt
Synch Type None
Usage Type Data
wMaxPacketSize 0x0010 1x 16 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x02 EP 2 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0000 1x 0 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0000 1x 0 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 1
bNumEndpoints 2
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0009 1x 9 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0009 1x 9 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 2
bNumEndpoints 2
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0011 1x 17 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0011 1x 17 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 3
bNumEndpoints 2
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0019 1x 25 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0019 1x 25 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 4
bNumEndpoints 2
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0021 1x 33 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0021 1x 33 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 5
bNumEndpoints 2
bInterfaceClass 224 Wireless
bInterfaceSubClass 1 Radio Frequency
bInterfaceProtocol 1 Bluetooth
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0031 1x 49 bytes
bInterval 1
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 1
Transfer Type Isochronous
Synch Type None
Usage Type Data
wMaxPacketSize 0x0031 1x 49 bytes
bInterval 1
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 2
bAlternateSetting 0
bNumEndpoints 0
bInterfaceClass 254 Application Specific Interface
bInterfaceSubClass 1 Device Firmware Update
bInterfaceProtocol 0
iInterface 0
** UNRECOGNIZED: 07 21 07 88 13 ff 03
Device Status: 0x0001
Self Powered

:; uname -a
Linux kooka 2.6.28-1-686 #1 SMP Mon Feb 23 03:13:24 UTC 2009 i686 GNU/Linux

--
If the From address bounces, please see http://www.pook.it/.


2009-04-20 17:45:31

by Stuart Pook

[permalink] [raw]
Subject: Re: bluez git + Linksys USBBT100 + 2.6.30-rc2 -> Segmentation fault

hi Johan

On 19/04/09 23:38, Johan Hedberg wrote:
> Could you please run bluetoothd through valgrind to get a proper
> backtrace.

I tested the bluetoothd from git and aplay with the alsa libs from bluez 4.36. I ran play 1451 times. It worked once. valgrind didn't say anything. I guess the errors below are more or less normal because my headset's battery went flat. I don't think that the "Too short" message from aplay is normal (even if the headset is off).

Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
ALSA lib pcm_bluetooth.c:1607:(audioservice_expect) BT_START_STREAM failed : Success(0)
ALSA lib pcm_bluetooth.c:1566:(audioservice_recv) Too short (1 bytes) IPC packet from bluetoothd
aplay: set_params:1022: Unable to install hw params:
ACCESS: RW_INTERLEAVED
FORMAT: S16_LE
SUBFORMAT: STD
SAMPLE_BITS: 16
FRAME_BITS: 16
CHANNELS: 1
RATE: 8000
PERIOD_TIME: 125000
PERIOD_SIZE: 1000
PERIOD_BYTES: 2000
PERIODS: 4
BUFFER_TIME: 500000
BUFFER_SIZE: 4000
BUFFER_BYTES: 8000
TICK_TIME: [0 0]

bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Unable to get a SCO fd
bluetoothd[1851]: headset_resume_complete: resume failed
bluetoothd[1851]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Unix client disconnected (fd=13)
bluetoothd[1851]: Accepted new client connection on unix socket (fd=13)
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[1851]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Unable to get a SCO fd
bluetoothd[1851]: headset_resume_complete: resume failed
bluetoothd[1851]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Unix client disconnected (fd=13)
bluetoothd[1851]: Accepted new client connection on unix socket (fd=13)
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[1851]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Unable to get a SCO fd
bluetoothd[1851]: headset_resume_complete: resume failed
bluetoothd[1851]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Unix client disconnected (fd=13)
bluetoothd[1851]: Accepted new client connection on unix socket (fd=13)
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[1851]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Unable to get a SCO fd
bluetoothd[1851]: headset_resume_complete: resume failed
bluetoothd[1851]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Unix client disconnected (fd=13)
bluetoothd[1851]: Accepted new client connection on unix socket (fd=13)
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[1851]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Unable to get a SCO fd
bluetoothd[1851]: headset_resume_complete: resume failed
bluetoothd[1851]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Unix client disconnected (fd=13)
bluetoothd[1851]: Accepted new client connection on unix socket (fd=13)
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[1851]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Unable to get service record: Host is down (112)
bluetoothd[1851]: Unable to get a SCO fd
bluetoothd[1851]: headset_resume_complete: resume failed
bluetoothd[1851]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Unix client disconnected (fd=13)



--
If the From address bounces, please see http://www.pook.it/.

2009-04-19 22:05:19

by Stuart Pook

[permalink] [raw]
Subject: Re: bluez git + Linksys USBBT100 + 2.6.30-rc2 -> Segmentation fault

hi Johan

On 19/04/09 23:38, Johan Hedberg wrote:
> On Sun, Apr 19, 2009, Stuart Pook wrote:
>> I did get one error that I had never seen before "Refusing headset":
>
> That comes if a headset is trying to connect to you and there's already
> max_connected_headsets headsets connected

I don't that that is the case. I only have 2 headsets and the other has never been
connected to the PC. Weird.

>> bluetoothd[32401]: Unix client disconnected (fd=13)
>> bluetoothd[32401]: Unable to get service record: Connection timed out
>> (110)
>> Segmentation fault
>
> Could you please run bluetoothd through valgrind to get a proper
> backtrace.

bluetoothd doesn't seg fault very often now but I'll leave a loop running aplay
and bluetoothd from git overnight.

:; ok=0;total=0; while sleep 15; do if aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav; then ok=$(($ok + 1)); fi; total=$(($total + 1)); echo ok=$ok total=$total; done

> Once we have the valgrind
> trace I'd also be interested in seeing the output of hcidump for the
> "Connection timed out" situation.

You mean when bluetoothd says "Unable to get service record: Connection timed out (110)"?

I get "aplay: pcm_write:1442: write error: Input/output error" a lot more often
but bluetoothd doesn't say anything special.

bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
bluetoothd[1851]: Accepted new client connection on unix socket (fd=13)
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[1851]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[1851]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[1851]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[1851]: /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[1851]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[1851]: kernel auth requirements = 0x00
bluetoothd[1851]: stored link key type = 0x00
bluetoothd[1851]: /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[1851]: Received AT+BRSF=27
bluetoothd[1851]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[1851]: Received AT+CIND=?
bluetoothd[1851]: Received AT+CIND?
bluetoothd[1851]: Received AT+CMER=3, 0, 0, 1
bluetoothd[1851]: Event reporting (CMER): mode=3, ind=1
bluetoothd[1851]: HFP Service Level Connection established
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 connected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[1851]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[1851]: Received AT+VGS=00
bluetoothd[1851]: SCO socket opened for headset /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98
bluetoothd[1851]: SCO fd=20
bluetoothd[1851]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[1851]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[1851]: Unix client disconnected (fd=13)
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[1851]: No matching connection found for handle 41
bluetoothd[1851]: telephony-dummy: device 0x4b90d40 disconnected
bluetoothd[1851]: State changed /org/bluez/1851/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED


>> In fact I get the "Too short (1 bytes) IPC packet from bluetoothd" error
>> even from bluetoothd 4.36.
> If this isn't caused by a bug the only possible reason I can think of as
> a cause for it is a mismatch between the alsa plugin and bluetoothd
> versions.

I have installed bluetoothd and the alsa plugin together so that shouldn't happen.
When I switch from bluez 4.3x to bluez 4.19 (for example) I seem to switch both the plug
and the daemon together.

> Btw, you might want to consider trying out pulseaudio 0.9.15. It's
> worked pretty flawlessly for me with bluez 4.34 and later versions

I only use my headset to do VoIP and I use twinkle to do VoIP (SIP). Twinkle
only understands alsa and OSS. I don't have to use twinkle I suppose.

thanks
Stuart

--
If the From address bounces, please see http://www.pook.it/.

2009-04-19 21:38:37

by Johan Hedberg

[permalink] [raw]
Subject: Re: bluez git + Linksys USBBT100 + 2.6.30-rc2 -> Segmentation fault

Hi Stuart,

On Sun, Apr 19, 2009, Stuart Pook wrote:
> I did get one error that I had never seen before "Refusing headset":

That comes if a headset is trying to connect to you and there's already
max_connected_headsets headsets connected (this variable defaults to 1 and
can be overrided with the MaxConnected parameter in audio.conf.

> bluetoothd[32401]: Audio API: BT_REQUEST <- BT_START_STREAM
> bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
> bluetoothd[32401]: Unable to get service record: Connection timed out (110)
> bluetoothd[32401]: Unable to get a SCO fd
> bluetoothd[32401]: headset_resume_complete: resume failed
> bluetoothd[32401]: Audio API: BT_ERROR -> BT_START_STREAM
> bluetoothd[32401]: telephony-dummy: device 0xb8f2c550 disconnected
> bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
> bluetoothd[32401]: Unix client disconnected (fd=13)
> bluetoothd[32401]: Unable to get service record: Connection timed out (110)
> Segmentation fault

Could you please run bluetoothd through valgrind to get a proper
backtrace. This time it should hopefully be more useful than the one we
got from the infinite recursion case (with some luck a fix should be just
a few minutes away from getting the log). Once we have the valgrind trace
I'd also be interested in seeing the output of hcidump for the "Connection
timed out" situation.

> In fact I get the "Too short (1 bytes) IPC packet from bluetoothd" error
> even from bluetoothd 4.36.

If this isn't caused by a bug the only possible reason I can think of as a
cause for it is a mismatch between the alsa plugin and bluetoothd versions.

Btw, you might want to consider trying out pulseaudio 0.9.15. It's worked
pretty flawlessly for me with bluez 4.34 and later versions (though I
haven't actually tested the mono profiles very much with it).

Johan

2009-04-19 21:12:34

by Stuart Pook

[permalink] [raw]
Subject: Re: bluez git + Linksys USBBT100 + 2.6.30-rc2 -> Segmentation fault

hi Johan

On 19/04/09 22:05, Johan Hedberg wrote:
> On Sun, Apr 19, 2009, Stuart Pook wrote:
>> I guess that this is why my USBBT100 never (?) worked with bluez.

I should have said "bluez 4" because it did work with bluez 3.

> Yep. The reason is that you have somehow managed to get "onmode off" to
> your config file.

I might have put it there. I think that I was trying to only allow
outgoing connections. How do I only allow outgoing connections (and
make my PC as invisible as possible)?

> I've just pushed a fix to git which falls back to the default "connectable"
> mode if the stored onmode if for some reason "off". This should prevent
> the infinite recursion of adapter_up:

I just pulled the new version and put back the bad config file. Bluetoothd now
works (mostly) and has corrected the config file.

:; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
mode connectable
class 0x480104
onmode connectable
discovto 60

I guess that I can use bluez-4.36 with the corrected config file.

I did get one error that I had never seen before "Refusing headset":

bluetoothd[30969]: HCI dev 0 up
bluetoothd[30969]: Starting security manager 0
bluetoothd[30969]: Adapter /org/bluez/30969/hci0 has been enabled
bluetoothd[30969]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[30969]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[30969]: kernel auth requirements = 0x00
bluetoothd[30969]: stored link key type = 0x00
bluetoothd[30969]: hcid_dbus_bonding_process_complete: status=00
bluetoothd[30969]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[30969]: hcid_dbus_bonding_process_complete: no pending auth request
bluetoothd[30969]: Refusing headset: too many existing connections
bluetoothd[30969]: Accepted new client connection on unix socket (fd=13)

I unplugged the USBBT100 and ran the bluetoothd from bluez-4.36. I plugged the
USBBT100 in and had to run aplay 8 times before it worked. (I prefer using my
installed version of bluetoothd because then I know that it matches the
libraries installed in /usr/lib/alsa-lib.)

:; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
mode connectable
class 0x000104
onmode connectable
discovto 60
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#+ | 00%aplay: pcm_write:1442: write error: Input/output error
:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
#############+ | 24%


: root; bluetoothd -dn
bluetoothd[31228]: Bluetooth daemon 4.36
bluetoothd[31228]: Enabling debug information
bluetoothd[31228]: parsing main.conf
bluetoothd[31228]: discovto=0
bluetoothd[31228]: Key file does not have key 'PairableTimeout'
bluetoothd[31228]: pageto=8192
bluetoothd[31228]: name=%h-%d
bluetoothd[31228]: class=0x000100
bluetoothd[31228]: inqmode=0
bluetoothd[31228]: Key file does not have key 'InitiallyPowered'
bluetoothd[31228]: Key file does not have key 'RememberPowered'
bluetoothd[31228]: Key file does not have key 'DeviceID'
bluetoothd[31228]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[31228]: Starting SDP server
bluetoothd[31228]: Loading plugins /usr/local/lib/bluetooth/plugins
bluetoothd[31228]: register_interface: path /org/bluez/31228/any
bluetoothd[31228]: Registered interface org.bluez.Service on path /org/bluez/31228/any
bluetoothd[31228]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[31228]: Unix socket created: 11
bluetoothd[31228]: Telephony plugin initialized
bluetoothd[31228]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[31228]: Entering main loop
bluetoothd[31228]: HCI dev 0 registered
bluetoothd[31228]: child 31231 forked
bluetoothd[31228]: child 31231 exited
bluetoothd[31228]: HCI dev 0 up
bluetoothd[31228]: Starting security manager 0
bluetoothd[31228]: Adapter /org/bluez/31228/hci0 without an address
bluetoothd[31228]: register_interface: path /org/bluez/31228/hci0
bluetoothd[31228]: Registered interface org.bluez.Service on path /org/bluez/31228/hci0
bluetoothd[31228]: headset_server_probe: path /org/bluez/31228/hci0
bluetoothd[31228]: Adding record with handle 0x10000
bluetoothd[31228]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[31228]: Adding record with handle 0x10001
bluetoothd[31228]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[31228]: a2dp_server_probe: path /org/bluez/31228/hci0
bluetoothd[31228]: SEP 0xb9a070c0 registered: type:0 codec:0 seid:1
bluetoothd[31228]: Adding record with handle 0x10002
bluetoothd[31228]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[31228]: avrcp_server_probe: path /org/bluez/31228/hci0
bluetoothd[31228]: Adding record with handle 0x10003
bluetoothd[31228]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[31228]: Adding record with handle 0x10004
bluetoothd[31228]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[31228]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: Probe drivers for /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[31228]: Registered interface org.bluez.Audio on path /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: Found Headset record
bluetoothd[31228]: Registered interface org.bluez.Headset on path /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: Found Handsfree record
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_03_89_FE_E6_19
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_17_E5_16_88_6C
bluetoothd[31228]: Creating device /org/bluez/31228/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[31228]: Changing service classes to 0x480100
bluetoothd[31228]: Adapter /org/bluez/31228/hci0 has been enabled
bluetoothd[31228]: Computer is classified as desktop
bluetoothd[31228]: Current device class is 0x480100
bluetoothd[31228]: Setting 0x000104 for major/minor device class
bluetoothd[31228]: Changing major/minor class to 0x480104
bluetoothd[31228]: Agent registered for hci0 at :1.24:/org/bluez/agent/hci0
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[31228]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[31228]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[31228]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[31228]: kernel auth requirements = 0x00
bluetoothd[31228]: stored link key type = 0x00
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[31228]: Received AT+BRSF=27
bluetoothd[31228]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[31228]: Received AT+CIND=?
bluetoothd[31228]: Received AT+CIND?
bluetoothd[31228]: Received AT+CMER=3, 0, 0, 1
bluetoothd[31228]: Event reporting (CMER): mode=3, ind=1
bluetoothd[31228]: HFP Service Level Connection established
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 connected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: Received AT+VGS=00
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=20
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 44
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=18
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 46
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 disconnected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[31228]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[31228]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[31228]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[31228]: kernel auth requirements = 0x00
bluetoothd[31228]: stored link key type = 0x00
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[31228]: Received AT+BRSF=27
bluetoothd[31228]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[31228]: Received AT+CIND=?
bluetoothd[31228]: Received AT+CIND?
bluetoothd[31228]: Received AT+CMER=3, 0, 0, 1
bluetoothd[31228]: Event reporting (CMER): mode=3, ind=1
bluetoothd[31228]: HFP Service Level Connection established
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 connected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: Received AT+VGS=00
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=20
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 49
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 disconnected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[31228]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[31228]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[31228]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[31228]: kernel auth requirements = 0x00
bluetoothd[31228]: stored link key type = 0x00
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[31228]: Received AT+BRSF=27
bluetoothd[31228]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[31228]: Received AT+CIND=?
bluetoothd[31228]: Received AT+CIND?
bluetoothd[31228]: Received AT+CMER=3, 0, 0, 1
bluetoothd[31228]: Event reporting (CMER): mode=3, ind=1
bluetoothd[31228]: HFP Service Level Connection established
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 connected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: Received AT+VGS=00
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=20
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 41
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=18
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 49
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 disconnected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[31228]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[31228]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[31228]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[31228]: kernel auth requirements = 0x00
bluetoothd[31228]: stored link key type = 0x00
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[31228]: Received AT+BRSF=27
bluetoothd[31228]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[31228]: Received AT+CIND=?
bluetoothd[31228]: Received AT+CIND?
bluetoothd[31228]: Received AT+CMER=3, 0, 0, 1
bluetoothd[31228]: Event reporting (CMER): mode=3, ind=1
bluetoothd[31228]: HFP Service Level Connection established
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 connected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: Received AT+VGS=00
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=20
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 41
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 disconnected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[31228]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[31228]: Received AT+BRSF=27
bluetoothd[31228]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[31228]: Received AT+CIND=?
bluetoothd[31228]: Received AT+CIND?
bluetoothd[31228]: Received AT+CMER=3, 0, 0, 1
bluetoothd[31228]: Event reporting (CMER): mode=3, ind=1
bluetoothd[31228]: HFP Service Level Connection established
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 connected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: Received AT+VGS=00
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=20
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[31228]: Unix client disconnected (fd=13)
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: No matching connection found for handle 49
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 disconnected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
bluetoothd[31228]: Accepted new client connection on unix socket (fd=13)
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[31228]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[31228]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[31228]: /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[31228]: Received AT+BRSF=27
bluetoothd[31228]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[31228]: Received AT+CIND=?
bluetoothd[31228]: Received AT+CIND?
bluetoothd[31228]: Received AT+CMER=3, 0, 0, 1
bluetoothd[31228]: Event reporting (CMER): mode=3, ind=1
bluetoothd[31228]: HFP Service Level Connection established
bluetoothd[31228]: telephony-dummy: device 0xb9a084b8 connected
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[31228]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[31228]: Received AT+VGS=00
bluetoothd[31228]: SCO socket opened for headset /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98
bluetoothd[31228]: SCO fd=20
bluetoothd[31228]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[31228]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[31228]: State changed /org/bluez/31228/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING

after this successfull connection I once again got
aplay: pcm_write:1442: write error: Input/output error

Once I got a bad connection and the music was very distorted (bluez 4.36).
When I'm using twinkle I sometimes get bad connections in the other direction;
ie the sound being recorded is very very distorted.

arecord | aplay works about 1 time in 10 (though it used to work more often)
:; arecord -v -D JX10 -f S16_LE | aplay -vv -D JX10 -f S16_LE
Recording WAVE 'stdin' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : CAPTURE
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 1
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
Playing WAVE 'stdin' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
Bluetooth Audio Device
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 1
rate : 8000
exact rate : 8000 (8000/1)
msbits : 16
buffer_size : 4000
period_size : 1000
period_time : 125000
tstamp_mode : NONE
period_step : 1
avail_min : 1000
period_event : 0
start_threshold : 4000
stop_threshold : 4000
silence_threshold: 0
silence_size : 0
boundary : 2097152000
##################################################+| 99%aplay: pcm_write:1442: write error: Input/output error

I just get a very brief noise before the correction dies.

The git version of bluetoothd is not any better but the errors are different
(another Segmentation fault). This time I left the USBBT100 plugged in.

:; aplay -vv -D JX10 /home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav
Playing WAVE '/home/stuart/ws/music_test/Rebecca_Pidgeon-You_Got_Me-8000-mono.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
ALSA lib pcm_bluetooth.c:1607:(audioservice_expect) BT_START_STREAM failed : Success(0)
ALSA lib pcm_bluetooth.c:1566:(audioservice_recv) Too short (1 bytes) IPC packet from bluetoothd
aplay: set_params:1022: Unable to install hw params:
ACCESS: RW_INTERLEAVED
FORMAT: S16_LE
SUBFORMAT: STD
SAMPLE_BITS: 16
FRAME_BITS: 16
CHANNELS: 1
RATE: 8000
PERIOD_TIME: 125000
PERIOD_SIZE: 1000
PERIOD_BYTES: 2000
PERIODS: 4
BUFFER_TIME: 500000
BUFFER_SIZE: 4000
BUFFER_BYTES: 8000
TICK_TIME: [0 0]

: root; src/bluetoothd -dn
bluetoothd[32401]: Bluetooth daemon 4.36
bluetoothd[32401]: Enabling debug information
bluetoothd[32401]: parsing main.conf
bluetoothd[32401]: discovto=0
bluetoothd[32401]: Key file does not have key 'PairableTimeout'
bluetoothd[32401]: pageto=8192
bluetoothd[32401]: name=%h-%d
bluetoothd[32401]: class=0x000100
bluetoothd[32401]: inqmode=0
bluetoothd[32401]: Key file does not have key 'InitiallyPowered'
bluetoothd[32401]: Key file does not have key 'RememberPowered'
bluetoothd[32401]: Key file does not have key 'DeviceID'
bluetoothd[32401]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[32401]: Starting SDP server
bluetoothd[32401]: Loading plugins /home/stuart/ws/install/bluez/git/bluez/plugins
bluetoothd[32401]: register_interface: path /org/bluez/32401/any
bluetoothd[32401]: Registered interface org.bluez.Service on path /org/bluez/32401/any
bluetoothd[32401]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[32401]: Unix socket created: 11
bluetoothd[32401]: Telephony plugin initialized
bluetoothd[32401]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[32401]: HCI dev 0 registered
bluetoothd[32401]: child 32421 forked
bluetoothd[32401]: Entering main loop
bluetoothd[32401]: child 32421 exited
bluetoothd[32401]: HCI dev 0 up
bluetoothd[32401]: Starting security manager 0
bluetoothd[32401]: register_interface: path /org/bluez/32401/hci0
bluetoothd[32401]: Registered interface org.bluez.Service on path /org/bluez/32401/hci0
bluetoothd[32401]: headset_server_probe: path /org/bluez/32401/hci0
bluetoothd[32401]: Adding record with handle 0x10000
bluetoothd[32401]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[32401]: Adding record with handle 0x10001
bluetoothd[32401]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[32401]: a2dp_server_probe: path /org/bluez/32401/hci0
bluetoothd[32401]: SEP 0xb8f2b158 registered: type:0 codec:0 seid:1
bluetoothd[32401]: Adding record with handle 0x10002
bluetoothd[32401]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[32401]: avrcp_server_probe: path /org/bluez/32401/hci0
bluetoothd[32401]: Adding record with handle 0x10003
bluetoothd[32401]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[32401]: Adding record with handle 0x10004
bluetoothd[32401]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[32401]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98
bluetoothd[32401]: Probe drivers for /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98
bluetoothd[32401]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[32401]: Registered interface org.bluez.Audio on path /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98
bluetoothd[32401]: Found Headset record
bluetoothd[32401]: Registered interface org.bluez.Headset on path /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98
bluetoothd[32401]: Found Handsfree record
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_03_89_FE_E6_19
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_17_E5_16_88_6C
bluetoothd[32401]: Creating device /org/bluez/32401/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[32401]: Changing service classes to 0x480104
bluetoothd[32401]: Adapter /org/bluez/32401/hci0 has been enabled
bluetoothd[32401]: Computer is classified as desktop
bluetoothd[32401]: Current device class is 0x480104
bluetoothd[32401]: Setting 0x000104 for major/minor device class
bluetoothd[32401]: Changing major/minor class to 0x480104
bluetoothd[32401]: Agent registered for hci0 at :1.24:/org/bluez/agent/hci0
bluetoothd[32401]: Accepted new client connection on unix socket (fd=13)
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[32401]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[32401]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[32401]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[32401]: /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[32401]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[32401]: kernel auth requirements = 0x00
bluetoothd[32401]: stored link key type = 0x00
bluetoothd[32401]: /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[32401]: Received AT+BRSF=27
bluetoothd[32401]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd[32401]: Received AT+CIND=?
bluetoothd[32401]: Received AT+CIND?
bluetoothd[32401]: Received AT+CMER=3, 0, 0, 1
bluetoothd[32401]: Event reporting (CMER): mode=3, ind=1
bluetoothd[32401]: HFP Service Level Connection established
bluetoothd[32401]: telephony-dummy: device 0xb8f2c550 connected
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[32401]: Received AT+VGS=00
bluetoothd[32401]: SCO socket opened for headset /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98
bluetoothd[32401]: SCO fd=18
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_START_STREAM
bluetoothd[32401]: Audio API: BT_INDICATION -> BT_NEW_STREAM
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
bluetoothd[32401]: Unix client disconnected (fd=13)
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
bluetoothd[32401]: Accepted new client connection on unix socket (fd=13)
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[32401]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[32401]: Unix client disconnected (fd=13)
bluetoothd[32401]: telephony-dummy: device 0xb8f2c550 disconnected
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[32401]: Accepted new client connection on unix socket (fd=13)
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[32401]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[32401]: No matching connection found for handle 44
bluetoothd[32401]: Unix client disconnected (fd=13)
bluetoothd[32401]: telephony-dummy: device 0xb8f2c550 disconnected
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[32401]: Accepted new client connection on unix socket (fd=13)
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_OPEN
bluetoothd[32401]: open sco - object=ANY source=ANY destination=00:1A:45:2F:49:98 lock=write
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_OPEN
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_SET_CONFIGURATION
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[32401]: Unable to get service record: Connection timed out (110)
bluetoothd[32401]: Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION
bluetoothd[32401]: telephony-dummy: device 0xb8f2c550 disconnected
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[32401]: Audio API: BT_REQUEST <- BT_START_STREAM
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[32401]: Unable to get service record: Connection timed out (110)
bluetoothd[32401]: Unable to get a SCO fd
bluetoothd[32401]: headset_resume_complete: resume failed
bluetoothd[32401]: Audio API: BT_ERROR -> BT_START_STREAM
bluetoothd[32401]: telephony-dummy: device 0xb8f2c550 disconnected
bluetoothd[32401]: State changed /org/bluez/32401/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
bluetoothd[32401]: Unix client disconnected (fd=13)
bluetoothd[32401]: Unable to get service record: Connection timed out (110)
Segmentation fault

: root; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
class 0x480104

In fact I get the "Too short (1 bytes) IPC packet from bluetoothd" error
even from bluetoothd 4.36.

Twinkle 1.4.1 & 1.4.2 are able to open the headset almost everytime
(once I turned the "Validate devices before usage" option off).
http://www.twinklephone.com/

--
If the From address bounces, please see http://www.pook.it/.

2009-04-19 20:05:28

by Johan Hedberg

[permalink] [raw]
Subject: Re: bluez git + Linksys USBBT100 + 2.6.30-rc2 -> Segmentation fault

Hi Stuart,

On Sun, Apr 19, 2009, Stuart Pook wrote:
> :; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
> mode off
> class 0x080104
> onmode off
> discovto 60
<snip>
> I guess that if you have read this far then you have found the solution
> as I did
> mv /var/lib/bluetooth/00:0C:41:E1:FF:30/config /var/lib/bluetooth/00:0C:41:E1:FF:30/config.old
>
> /var/lib/bluetooth/00:0C:41:E1:FF:30/config was recreated containing
>
> : root; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
> class 0x480104
>
> I guess that this is why my USBBT100 never (?) worked with bluez.

Yep. The reason is that you have somehow managed to get "onmode off" to
your config file. There's just one place (in storage.c) where the value of
onmode gets written and it looks like
if (strcmp(mode, "off") != 0)
textfile_put(filename, "onmode", mode);
so it should be impossible for the value "off" to be stored. Maybe some old
bluez version has been buggy and allowed it or then the file has been
modified manually.

Anyway, if you look at the adapter_up function (in src/adapter.c) you'll
see that it calls itself recursively in the case that the last mode was
"off", but copies "onmode" to the previously stored mode before that. So,
if the stored "onmode" is actually "off" the adapter_up function will keep
calling itself indefinitely (until the daemon crashes).

I've just pushed a fix to git which falls back to the default "connectable"
mode if the stored onmode if for some reason "off". This should prevent
the infinite recursion of adapter_up:
http://git.kernel.org/?p=bluetooth/bluez.git;a=commitdiff;h=e40a1ccc50d87981b20d3ab0f1bec4209fee4247

Johan

2009-04-19 19:19:44

by Stuart Pook

[permalink] [raw]
Subject: Re: bluez git + Linksys USBBT100 + 2.6.30-rc2 -> Segmentation fault

On 05/04/09 19:22, Johan Hedberg wrote:

> I don't know about the kernel, but there's a known bug with 4.34 that can make
> bluetoothd crash when unpluging/repluging adapters. This was fixed in git
> already several days ago with commit 457056310229911e820357470ee8fb30c82516da
> ("Fix org.bluez.Audio unregistration") so you might want to try if it helps.

I just did a git pull to get the latest bluez and bluetoothd still gets a
Segmentation fault when I use my Linksys USBBT100 bluetooth adapter.
I used to use my USBBT100 with bluez 3. I was already using bluez 4 when
I bought my Belkin F8T017 bluetooth adapter.

I start bluetoothd without the USBBT100. When I plug it in the interface is down.
When I do hciconfig hci0 up the CPU usage goes up to 100% for 8 seconds and then
bluetoothd gets a segmentation fault.

If the USBBT100 is already plugged in when I start bluetoothd then bluetoothd crashes
6.3 seconds later having used 5.9 seconds of CPU time.

Neither valgrind nor gdb show anything of any interest.

I have installed bluez-4.36 and it has the same problem. I have a 2.6.30-rc2 kernel.
My Belkin F8T017 bluetooth adapter works fine.

strace -f on bluetoothd shows that it is looping as shown below.

:; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
mode off
class 0x080104
onmode off
discovto 60

open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDONLY) = 18
flock(18, LOCK_SH) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ, MAP_SHARED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
close(18) = 0
umask(022) = 022
stat64("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDWR|O_CREAT, 0644) = 18
close(18) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDONLY) = 18
flock(18, LOCK_SH) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ, MAP_SHARED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
close(18) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDONLY) = 18
flock(18, LOCK_SH) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ, MAP_SHARED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
close(18) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDONLY) = 18
flock(18, LOCK_SH) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ, MAP_SHARED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
close(18) = 0
umask(022) = 022
stat64("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDWR|O_CREAT, 0644) = 18
close(18) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDWR) = 18
flock(18, LOCK_EX) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_LOCKED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
fdatasync(18) = 0
close(18) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDONLY) = 18
flock(18, LOCK_SH) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ, MAP_SHARED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
close(18) = 0
open("/var/lib/bluetooth/00:0C:41:E1:FF:30/config", O_RDONLY) = 18
flock(18, LOCK_SH) = 0
fstat64(18, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap2(NULL, 47, PROT_READ, MAP_SHARED, 18, 0) = 0xb7f76000
munmap(0xb7f76000, 47) = 0
flock(18, LOCK_UN) = 0
close(18) = 0
umask(022) = 022
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
+++ killed by SIGSEGV +++


: root; time src/bluetoothd -dn
bluetoothd[20646]: Bluetooth daemon 4.36
bluetoothd[20646]: Enabling debug information
bluetoothd[20646]: parsing main.conf
bluetoothd[20646]: discovto=0
bluetoothd[20646]: Key file does not have key 'PairableTimeout'
bluetoothd[20646]: pageto=8192
bluetoothd[20646]: name=%h-%d
bluetoothd[20646]: class=0x000100
bluetoothd[20646]: inqmode=0
bluetoothd[20646]: Key file does not have key 'InitiallyPowered'
bluetoothd[20646]: Key file does not have key 'RememberPowered'
bluetoothd[20646]: Key file does not have key 'DeviceID'
bluetoothd[20646]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[20646]: Starting SDP server
bluetoothd[20646]: Loading plugins /home/stuart/ws/install/bluez/git/bluez/plugins
bluetoothd[20646]: register_interface: path /org/bluez/20646/any
bluetoothd[20646]: Registered interface org.bluez.Service on path /org/bluez/20646/any
bluetoothd[20646]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[20646]: Unix socket created: 11
bluetoothd[20646]: Telephony plugin initialized
bluetoothd[20646]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[20646]: HCI dev 0 registered
bluetoothd[20646]: child 20661 forked
bluetoothd[20646]: HCI dev 0 already up
bluetoothd[20646]: Starting security manager 0
bluetoothd[20646]: periodic_inquiry_exit at adapter startup
bluetoothd[20646]: register_interface: path /org/bluez/20646/hci0
bluetoothd[20646]: Registered interface org.bluez.Service on path /org/bluez/20646/hci0
bluetoothd[20646]: headset_server_probe: path /org/bluez/20646/hci0
bluetoothd[20646]: Adding record with handle 0x10000
bluetoothd[20646]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[20646]: Adding record with handle 0x10001
bluetoothd[20646]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[20646]: a2dp_server_probe: path /org/bluez/20646/hci0
bluetoothd[20646]: SEP 0xb85bb140 registered: type:0 codec:0 seid:1
bluetoothd[20646]: Adding record with handle 0x10002
bluetoothd[20646]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[20646]: avrcp_server_probe: path /org/bluez/20646/hci0
bluetoothd[20646]: Adding record with handle 0x10003
bluetoothd[20646]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[20646]: Adding record with handle 0x10004
bluetoothd[20646]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20646]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20646]: Probe drivers for /org/bluez/20646/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20646]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[20646]: Registered interface org.bluez.Audio on path /org/bluez/20646/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20646]: Found Headset record
bluetoothd[20646]: Registered interface org.bluez.Headset on path /org/bluez/20646/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20646]: Found Handsfree record
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_03_89_FE_E6_19
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_17_E5_16_88_6C
bluetoothd[20646]: Creating device /org/bluez/20646/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[20646]: Changing service classes to 0x480104
bluetoothd[20661]: Can't set link policy on hci0: No such device (19)
bluetoothd[20646]: Adapter /org/bluez/20646/hci0 has been enabled
bluetoothd[20646]: Stopping security manager 0
bluetoothd[20646]: Changing service classes to 0x480104
bluetoothd[20646]: Entering main loop
bluetoothd[20646]: child 20661 exited
bluetoothd[20646]: HCI dev 0 down
bluetoothd[20646]: Adapter /org/bluez/20646/hci0 has been disabled
bluetoothd[20646]: HCI dev 0 up
bluetoothd[20646]: Starting security manager 0
Segmentation fault

real 0m6.383s
user 0m1.608s
sys 0m4.316s

: root; time valgrind src/.libs/bluetoothd -dn
==20666== Memcheck, a memory error detector.
==20666== Copyright (C) 2002-2008, and GNU GPL'd, by Julian Seward et al.
==20666== Using LibVEX rev 1884, a library for dynamic binary translation.
==20666== Copyright (C) 2004-2008, and GNU GPL'd, by OpenWorks LLP.
==20666== Using valgrind-3.4.1-Debian, a dynamic binary instrumentation framework.
==20666== Copyright (C) 2000-2008, and GNU GPL'd, by Julian Seward et al.
==20666== For more details, rerun with: -v
==20666==
bluetoothd[20666]: Bluetooth daemon 4.36
bluetoothd[20666]: Enabling debug information
bluetoothd[20666]: parsing main.conf
bluetoothd[20666]: discovto=0
bluetoothd[20666]: Key file does not have key 'PairableTimeout'
bluetoothd[20666]: pageto=8192
bluetoothd[20666]: name=%h-%d
bluetoothd[20666]: class=0x000100
bluetoothd[20666]: inqmode=0
bluetoothd[20666]: Key file does not have key 'InitiallyPowered'
bluetoothd[20666]: Key file does not have key 'RememberPowered'
bluetoothd[20666]: Key file does not have key 'DeviceID'
bluetoothd[20666]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[20666]: Starting SDP server
bluetoothd[20666]: Loading plugins /home/stuart/ws/install/bluez/git/bluez/plugins
bluetoothd[20666]: register_interface: path /org/bluez/20666/any
bluetoothd[20666]: Registered interface org.bluez.Service on path /org/bluez/20666/any
bluetoothd[20666]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[20666]: Unix socket created: 11
bluetoothd[20666]: Telephony plugin initialized
bluetoothd[20666]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[20666]: HCI dev 0 registered
bluetoothd[20666]: child 20669 forked
bluetoothd[20666]: HCI dev 0 already up
bluetoothd[20666]: Starting security manager 0
bluetoothd[20666]: periodic_inquiry_exit at adapter startup
bluetoothd[20666]: register_interface: path /org/bluez/20666/hci0
bluetoothd[20666]: Registered interface org.bluez.Service on path /org/bluez/20666/hci0
bluetoothd[20666]: headset_server_probe: path /org/bluez/20666/hci0
bluetoothd[20666]: Adding record with handle 0x10000
bluetoothd[20666]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[20666]: Adding record with handle 0x10001
bluetoothd[20666]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[20666]: a2dp_server_probe: path /org/bluez/20666/hci0
bluetoothd[20666]: SEP 0x4b532c8 registered: type:0 codec:0 seid:1
bluetoothd[20666]: Adding record with handle 0x10002
bluetoothd[20666]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[20666]: avrcp_server_probe: path /org/bluez/20666/hci0
bluetoothd[20666]: Adding record with handle 0x10003
bluetoothd[20666]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[20666]: Adding record with handle 0x10004
bluetoothd[20666]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20666]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20666]: Probe drivers for /org/bluez/20666/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20666]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[20666]: Registered interface org.bluez.Audio on path /org/bluez/20666/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20666]: Found Headset record
bluetoothd[20666]: Registered interface org.bluez.Headset on path /org/bluez/20666/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20666]: Found Handsfree record
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_03_89_FE_E6_19
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_17_E5_16_88_6C
bluetoothd[20666]: Creating device /org/bluez/20666/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[20666]: Changing service classes to 0x480104
==20666== Syscall param ioctl(generic) points to unaddressable byte(s)
==20666== at 0x40007F2: (within /lib/ld-2.9.so)
==20666== by 0x123D77: adapter_start (adapter.c:2201)
==20666== by 0x11F0A1: manager_start_adapter (manager.c:474)
==20666== by 0x112642: device_devup_setup (main.c:502)
==20666== by 0x1127A9: init_all_devices (main.c:537)
==20666== by 0x113073: main (main.c:779)
==20666== Address 0x0 is not stack'd, malloc'd or (recently) free'd
bluetoothd[20669]: Can't set link policy on hci0: No such device (19)
==20669== Syscall param ioctl(generic) points to unaddressable byte(s)
==20669== at 0x40007F2: (within /lib/ld-2.9.so)
==20669== by 0x1125AC: device_devreg_setup (main.c:484)
==20669== by 0x112777: init_all_devices (main.c:534)
==20669== by 0x113073: main (main.c:779)
==20669== Address 0x0 is not stack'd, malloc'd or (recently) free'd
bluetoothd[20666]: Adapter /org/bluez/20666/hci0 has been enabled
bluetoothd[20666]: Stopping security manager 0
bluetoothd[20666]: Changing service classes to 0x480104
bluetoothd[20666]: Entering main loop
==20669==
==20669== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 63 from 3)
==20669== malloc/free: in use at exit: 29,243 bytes in 329 blocks.
==20669== malloc/free: 641 allocs, 312 frees, 250,226 bytes allocated.
==20669== For counts of detected errors, rerun with: -v
==20669== searching for pointers to 329 not-freed blocks.
==20669== checked 114,888 bytes.
==20669==
==20669== LEAK SUMMARY:
==20669== definitely lost: 0 bytes in 0 blocks.
==20669== possibly lost: 744 bytes in 3 blocks.
==20669== still reachable: 28,499 bytes in 326 blocks.
==20669== suppressed: 0 bytes in 0 blocks.
==20669== Rerun with --leak-check=full to see details of leaked memory.
bluetoothd[20666]: child 20669 exited
bluetoothd[20666]: HCI dev 0 down
bluetoothd[20666]: Adapter /org/bluez/20666/hci0 has been disabled
bluetoothd[20666]: HCI dev 0 up
bluetoothd[20666]: Starting security manager 0
==20666== Stack overflow in thread 1: can't grow stack to 0xbe3c2fdc
==20666==
==20666== Process terminating with default action of signal 11 (SIGSEGV)
==20666== Access not within mapped region at address 0xBE3C2FDC
==20666== at 0x4A1C3BA: __xstat (in /lib/i686/cmov/libc-2.9.so)
==20666== If you believe this happened as a result of a stack overflow in your
==20666== program's main thread (unlikely but possible), you can try to increase
==20666== the size of the main thread stack using the --main-stacksize= flag.
==20666== The main thread stack size used in this run was 8388608.
==20666== Stack overflow in thread 1: can't grow stack to 0xbe3c2fd8
==20666==
==20666== Process terminating with default action of signal 11 (SIGSEGV)
==20666== Access not within mapped region at address 0xBE3C2FD8
==20666== at 0x48203EC: _vgnU_freeres (vg_preloaded.c:56)
==20666== If you believe this happened as a result of a stack overflow in your
==20666== program's main thread (unlikely but possible), you can try to increase
==20666== the size of the main thread stack using the --main-stacksize= flag.
==20666== The main thread stack size used in this run was 8388608.
==20666==
==20666== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 63 from 3)
==20666== malloc/free: in use at exit: 44,508 bytes in 682 blocks.
==20666== malloc/free: 263,612 allocs, 262,930 frees, 1,828,692 bytes allocated.
==20666== For counts of detected errors, rerun with: -v
==20666== searching for pointers to 682 not-freed blocks.
==20666== checked 5,711,256 bytes.
==20666==
==20666== LEAK SUMMARY:
==20666== definitely lost: 0 bytes in 0 blocks.
==20666== possibly lost: 744 bytes in 3 blocks.
==20666== still reachable: 43,764 bytes in 679 blocks.
==20666== suppressed: 0 bytes in 0 blocks.
==20666== Rerun with --leak-check=full to see details of leaked memory.
Segmentation fault

real 1m5.017s
user 0m48.763s
sys 0m15.225s

: root; gdb --args src/.libs/bluetoothd -dn
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...
(gdb) run
Starting program: /disks/cleartext/stuart/install/bluez/git/bluez/src/.libs/bluetoothd -dn
bluetoothd[20695]: Bluetooth daemon 4.36
bluetoothd[20695]: Enabling debug information
bluetoothd[20695]: parsing main.conf
bluetoothd[20695]: discovto=0
bluetoothd[20695]: Key file does not have key 'PairableTimeout'
bluetoothd[20695]: pageto=8192
bluetoothd[20695]: name=%h-%d
bluetoothd[20695]: class=0x000100
bluetoothd[20695]: inqmode=0
bluetoothd[20695]: Key file does not have key 'InitiallyPowered'
bluetoothd[20695]: Key file does not have key 'RememberPowered'
bluetoothd[20695]: Key file does not have key 'DeviceID'
bluetoothd[20695]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[20695]: Starting SDP server
bluetoothd[20695]: Loading plugins /home/stuart/ws/install/bluez/git/bluez/plugins
bluetoothd[20695]: register_interface: path /org/bluez/20695/any
bluetoothd[20695]: Registered interface org.bluez.Service on path /org/bluez/20695/any
bluetoothd[20695]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[20695]: Unix socket created: 13
bluetoothd[20695]: Telephony plugin initialized
bluetoothd[20695]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[20695]: HCI dev 0 registered
bluetoothd[20695]: child 20698 forked
bluetoothd[20695]: HCI dev 0 already up
bluetoothd[20695]: Starting security manager 0
bluetoothd[20695]: periodic_inquiry_exit at adapter startup
bluetoothd[20695]: register_interface: path /org/bluez/20695/hci0
bluetoothd[20695]: Registered interface org.bluez.Service on path /org/bluez/20695/hci0
bluetoothd[20695]: headset_server_probe: path /org/bluez/20695/hci0
bluetoothd[20695]: Adding record with handle 0x10000
bluetoothd[20695]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[20695]: Adding record with handle 0x10001
bluetoothd[20695]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[20695]: a2dp_server_probe: path /org/bluez/20695/hci0
bluetoothd[20695]: SEP 0xb8e9b120 registered: type:0 codec:0 seid:1
bluetoothd[20695]: Adding record with handle 0x10002
bluetoothd[20695]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[20695]: avrcp_server_probe: path /org/bluez/20695/hci0
bluetoothd[20695]: Adding record with handle 0x10003
bluetoothd[20695]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[20695]: Adding record with handle 0x10004
bluetoothd[20695]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[20695]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20695]: Probe drivers for /org/bluez/20695/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20695]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[20695]: Registered interface org.bluez.Audio on path /org/bluez/20695/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20695]: Found Headset record
bluetoothd[20695]: Registered interface org.bluez.Headset on path /org/bluez/20695/hci0/dev_00_1A_45_2F_49_98
bluetoothd[20695]: Found Handsfree record
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_03_89_FE_E6_19
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_17_E5_16_88_6C
bluetoothd[20695]: Creating device /org/bluez/20695/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[20695]: Changing service classes to 0x480104
bluetoothd[20698]: Can't set link policy on hci0: No such device (19)
bluetoothd[20695]: Adapter /org/bluez/20695/hci0 has been enabled
bluetoothd[20695]: Stopping security manager 0
bluetoothd[20695]: Changing service classes to 0x480104
bluetoothd[20695]: Entering main loop
bluetoothd[20695]: child 20698 exited
bluetoothd[20695]: HCI dev 0 down
bluetoothd[20695]: Adapter /org/bluez/20695/hci0 has been disabled
bluetoothd[20695]: HCI dev 0 up
bluetoothd[20695]: Starting security manager 0

Program received signal SIGSEGV, Segmentation fault.
0xb7db03ba in ?? ()
(gdb) bt
#0 0xb7db03ba in ?? ()
Cannot access memory at address 0xbf4b1ff0
(gdb) bt full
#0 0xb7db03ba in ?? ()
No symbol table info available.
Cannot access memory at address 0xbf4b1ff0
(gdb) info registers
eax 0xbf4b315f -1085591201
ecx 0x0 0
edx 0xbf4b315f -1085591201
ebx 0xb7fb2144 -1208278716
esp 0xbf4b1ff0 0xbf4b1ff0
ebp 0xbf4b2060 0xbf4b2060
esi 0xb8e991d0 -1192652336
edi 0xb7f8989a -1208444774
eip 0xb7db03ba 0xb7db03ba
eflags 0x10286 [ PF SF IF RF ]
cs 0x73 115
ss 0x7b 123
ds 0x7b 123
es 0x7b 123
fs 0x0 0
gs 0x33 51
(gdb) thread apply all backtrace
(gdb) quit
The program is running. Exit anyway? (y or n) y

I guess that if you have read this far then you have found the solution as I did
mv /var/lib/bluetooth/00:0C:41:E1:FF:30/config /var/lib/bluetooth/00:0C:41:E1:FF:30/config.old

/var/lib/bluetooth/00:0C:41:E1:FF:30/config was recreated containing

: root; cat /var/lib/bluetooth/00:0C:41:E1:FF:30/config
class 0x480104

I guess that this is why my USBBT100 never (?) worked with bluez.
--
If the From address bounces, please see http://www.pook.it/.

2009-04-06 21:20:05

by Stuart Pook

[permalink] [raw]
Subject: Re: bluez 4.34 + Linksys USBBT100 + hcitool scan -> core dump

hi Johan

On 05/04/09 19:19, Johan Hedberg wrote:
> On Sun, Apr 05, 2009, Stuart Pook wrote:
>> I have a Linksys (Cisco) USBBT100 Bluetooth 1.1 Adapter which has a 1.2 dBi
>> antenna. I used to use it with Bluez 3 and it had a better range than my
>> Belkin F8T017. It used to work (but not for audio) with older versions of
>> bluez 4. I tried it again with bluez 4.34 and now a simple "hcitool scan"
>> makes bluetoothd core dump.

> Could you try and see if
> this is reproducable with the latest git? You don't necessarily need to install
> it, just compile with "./bootstrap-configure && make" and run the compiled
> bluetoothd directly from the tree.

It appears that you need to run ./src/.libs/bluetoothd with valgrind. This is with the latest version from git.

It didn't crash with "hcitool scan" but rather when I tried to open an audio device or run obexftp. I have never managed to open an audio device or run obexftp using my USBBT100. bluetoothd always crashes. I have no problems when I use my F8T017.

: root; valgrind ./src/.libs/bluetoothd -dn
==15350== Memcheck, a memory error detector.
==15350== Copyright (C) 2002-2008, and GNU GPL'd, by Julian Seward et al.
==15350== Using LibVEX rev 1884, a library for dynamic binary translation.
==15350== Copyright (C) 2004-2008, and GNU GPL'd, by OpenWorks LLP.
==15350== Using valgrind-3.4.1-Debian, a dynamic binary instrumentation framework.
==15350== Copyright (C) 2000-2008, and GNU GPL'd, by Julian Seward et al.
==15350== For more details, rerun with: -v
==15350==
bluetoothd[15350]: Bluetooth daemon 4.34
bluetoothd[15350]: Enabling debug information
bluetoothd[15350]: parsing main.conf
bluetoothd[15350]: discovto=0
bluetoothd[15350]: Key file does not have key 'PairableTimeout'
bluetoothd[15350]: pageto=8192
bluetoothd[15350]: name=%h-%d
bluetoothd[15350]: class=0x000100
bluetoothd[15350]: inqmode=0
bluetoothd[15350]: Key file does not have key 'InitiallyPowered'
bluetoothd[15350]: Key file does not have key 'RememberPowered'
bluetoothd[15350]: Key file does not have key 'DeviceID'
bluetoothd[15350]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[15350]: Starting SDP server
bluetoothd[15350]: Loading plugins /home/stuart/ws/install/bluez/git/bluez/plugins
bluetoothd[15350]: register_interface: path /org/bluez/15350/any
bluetoothd[15350]: Registered interface org.bluez.Service on path /org/bluez/15350/any
bluetoothd[15350]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[15350]: Unix socket created: 11
bluetoothd[15350]: Telephony plugin initialized
bluetoothd[15350]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[15350]: HCI dev 0 registered
bluetoothd[15350]: child 15352 forked
bluetoothd[15350]: HCI dev 0 already up
bluetoothd[15350]: Starting security manager 0
bluetoothd[15350]: periodic_inquiry_exit at adapter startup
bluetoothd[15350]: register_interface: path /org/bluez/15350/hci0
bluetoothd[15350]: Registered interface org.bluez.Service on path /org/bluez/15350/hci0
bluetoothd[15350]: headset_server_probe: path /org/bluez/15350/hci0
bluetoothd[15350]: Adding record with handle 0x10000
bluetoothd[15350]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[15350]: Adding record with handle 0x10001
bluetoothd[15350]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[15350]: a2dp_server_probe: path /org/bluez/15350/hci0
bluetoothd[15350]: SEP 0x4b527b8 registered: type:0 codec:0 seid:1
bluetoothd[15350]: Adding record with handle 0x10002
bluetoothd[15350]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[15350]: avrcp_server_probe: path /org/bluez/15350/hci0
bluetoothd[15350]: Adding record with handle 0x10003
bluetoothd[15350]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[15350]: Adding record with handle 0x10004
bluetoothd[15350]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15350]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15350]: Probe drivers for /org/bluez/15350/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15350]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[15350]: Registered interface org.bluez.Audio on path /org/bluez/15350/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15350]: Found Headset record
bluetoothd[15350]: Discovered Headset service on RFCOMM channel 2
bluetoothd[15350]: Registered interface org.bluez.Headset on path /org/bluez/15350/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15350]: Found Handsfree record
bluetoothd[15350]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_03_89_FE_E6_19
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_17_E5_16_88_6C
bluetoothd[15350]: Creating device /org/bluez/15350/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[15350]: Changing service classes to 0x480104
==15350== Syscall param ioctl(generic) points to unaddressable byte(s)
==15350== at 0x40007F2: (within /lib/ld-2.9.so)
==15350== by 0x123C7E: adapter_start (adapter.c:2191)
==15350== by 0x11F0BD: manager_start_adapter (manager.c:520)
==15350== by 0x1124E2: device_devup_setup (main.c:502)
==15350== by 0x112649: init_all_devices (main.c:537)
==15350== by 0x112F13: main (main.c:779)
==15350== Address 0x0 is not stack'd, malloc'd or (recently) free'd
bluetoothd[15352]: Can't set link policy on hci0: No such device (19)
==15352== Syscall param ioctl(generic) points to unaddressable byte(s)
==15352== at 0x40007F2: (within /lib/ld-2.9.so)
==15352== by 0x11244C: device_devreg_setup (main.c:484)
==15352== by 0x112617: init_all_devices (main.c:534)
==15352== by 0x112F13: main (main.c:779)
==15352== Address 0x0 is not stack'd, malloc'd or (recently) free'd
bluetoothd[15350]: Adapter /org/bluez/15350/hci0 has been enabled
bluetoothd[15350]: Stopping security manager 0
bluetoothd[15350]: Changing service classes to 0x480104
==15352==
==15352== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 63 from 3)
==15352== malloc/free: in use at exit: 29,244 bytes in 329 blocks.
==15352== malloc/free: 641 allocs, 312 frees, 250,227 bytes allocated.
==15352== For counts of detected errors, rerun with: -v
==15352== searching for pointers to 329 not-freed blocks.
==15352== checked 114,812 bytes.
==15352==
==15352== LEAK SUMMARY:
==15352== definitely lost: 0 bytes in 0 blocks.
==15352== possibly lost: 744 bytes in 3 blocks.
==15352== still reachable: 28,500 bytes in 326 blocks.
==15352== suppressed: 0 bytes in 0 blocks.
==15352== Rerun with --leak-check=full to see details of leaked memory.
bluetoothd[15350]: Can't write class of device: Unknown error 4294967186 (-110)
bluetoothd[15350]: Entering main loop
bluetoothd[15350]: child 15352 exited
bluetoothd[15350]: HCI dev 0 down
bluetoothd[15350]: Adapter /org/bluez/15350/hci0 has been disabled
bluetoothd[15350]: HCI dev 0 up
bluetoothd[15350]: Starting security manager 0

==15350== Stack overflow in thread 1: can't grow stack to 0xbe447fcc
==15350==
==15350== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==15350== Access not within mapped region at address 0xBE447FCC
==15350== at 0x4A1B3BA: __xstat (in /lib/i686/cmov/libc-2.9.so)
==15350== If you believe this happened as a result of a stack overflow in your
==15350== program's main thread (unlikely but possible), you can try to increase
==15350== the size of the main thread stack using the --main-stacksize= flag.
==15350== The main thread stack size used in this run was 8388608.
==15350== Stack overflow in thread 1: can't grow stack to 0xbe447fc8
==15350==
==15350== Process terminating with default action of signal 11 (SIGSEGV)
==15350== Access not within mapped region at address 0xBE447FC8
==15350== at 0x48203EC: _vgnU_freeres (vg_preloaded.c:56)
==15350== If you believe this happened as a result of a stack overflow in your
==15350== program's main thread (unlikely but possible), you can try to increase
==15350== the size of the main thread stack using the --main-stacksize= flag.
==15350== The main thread stack size used in this run was 8388608.
==15350==
==15350== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 63 from 3)
==15350== malloc/free: in use at exit: 45,177 bytes in 680 blocks.
==15350== malloc/free: 263,627 allocs, 262,947 frees, 1,855,386 bytes allocated.
==15350== For counts of detected errors, rerun with: -v
==15350== searching for pointers to 680 not-freed blocks.
==15350== checked 5,710,988 bytes.
==15350==
==15350== LEAK SUMMARY:
==15350== definitely lost: 0 bytes in 0 blocks.
==15350== possibly lost: 744 bytes in 3 blocks.
==15350== still reachable: 44,433 bytes in 677 blocks.
==15350== suppressed: 0 bytes in 0 blocks.
==15350== Rerun with --leak-check=full to see details of leaked memory.
Segmentation fault

This time "hcitool scan" did crash bluetoothd. It has been a long time since I last used gdb. Is there something I should do to get a better backtrace?

: root; gdb ./src/.libs/bluetoothd
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...
(gdb) handle SIG33 pass nostop noprint
Signal Stop Print Pass to program Description
SIG33 No No Yes Real-time event 33
(gdb) set pagination 0
(gdb) run -dn
Starting program: /disks/cleartext/stuart/install/bluez/git/bluez/src/.libs/bluetoothd -dn
bluetoothd[15533]: Bluetooth daemon 4.34
bluetoothd[15533]: Enabling debug information
bluetoothd[15533]: parsing main.conf
bluetoothd[15533]: discovto=0
bluetoothd[15533]: Key file does not have key 'PairableTimeout'
bluetoothd[15533]: pageto=8192
bluetoothd[15533]: name=%h-%d
bluetoothd[15533]: class=0x000100
bluetoothd[15533]: inqmode=0
bluetoothd[15533]: Key file does not have key 'InitiallyPowered'
bluetoothd[15533]: Key file does not have key 'RememberPowered'
bluetoothd[15533]: Key file does not have key 'DeviceID'
bluetoothd[15533]: Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[15533]: Starting SDP server
bluetoothd[15533]: Loading plugins /home/stuart/ws/install/bluez/git/bluez/plugins
bluetoothd[15533]: register_interface: path /org/bluez/15533/any
bluetoothd[15533]: Registered interface org.bluez.Service on path /org/bluez/15533/any
bluetoothd[15533]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
bluetoothd[15533]: Unix socket created: 13
bluetoothd[15533]: Telephony plugin initialized
bluetoothd[15533]: HFP AG features: "Ability to reject a call" "Enhanced call status" "Extended Error Result Codes"
bluetoothd[15533]: HCI dev 0 registered
bluetoothd[15533]: child 15536 forked
bluetoothd[15533]: HCI dev 0 already up
bluetoothd[15533]: Starting security manager 0
bluetoothd[15533]: periodic_inquiry_exit at adapter startup
bluetoothd[15533]: register_interface: path /org/bluez/15533/hci0
bluetoothd[15533]: Registered interface org.bluez.Service on path /org/bluez/15533/hci0
bluetoothd[15533]: headset_server_probe: path /org/bluez/15533/hci0
bluetoothd[15533]: Adding record with handle 0x10000
bluetoothd[15533]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001108-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001112-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[15533]: Adding record with handle 0x10001
bluetoothd[15533]: Record pattern UUID 00000003-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000111e-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000111f-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001203-0000-1000-8000-00805f9
bluetoothd[15533]: a2dp_server_probe: path /org/bluez/15533/hci0
bluetoothd[15533]: SEP 0xb848d120 registered: type:0 codec:0 seid:1
bluetoothd[15533]: Adding record with handle 0x10002
bluetoothd[15533]: Record pattern UUID 00000019-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000110a-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000110d-0000-1000-8000-00805f9
bluetoothd[15533]: avrcp_server_probe: path /org/bluez/15533/hci0
bluetoothd[15533]: Adding record with handle 0x10003
bluetoothd[15533]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[15533]: Adding record with handle 0x10004
bluetoothd[15533]: Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[15533]: Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15533]: Probe drivers for /org/bluez/15533/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15533]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[15533]: Registered interface org.bluez.Audio on path /org/bluez/15533/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15533]: Found Headset record
bluetoothd[15533]: Discovered Headset service on RFCOMM channel 2
bluetoothd[15533]: Registered interface org.bluez.Headset on path /org/bluez/15533/hci0/dev_00_1A_45_2F_49_98
bluetoothd[15533]: Found Handsfree record
bluetoothd[15533]: Discovered Handsfree service on RFCOMM channel 1
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_14_A7_74_D3_AF
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_03_89_B7_F8_D3
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_0A_94_94_4F_B3
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_03_89_DC_5C_9F
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_03_89_DC_FC_EC
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_03_89_FE_E6_19
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_0E_6D_8F_91_6A
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_17_E5_E6_25_AB
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_17_E5_16_88_6C
bluetoothd[15533]: Creating device /org/bluez/15533/hci0/dev_00_17_E5_0C_EA_70
bluetoothd[15533]: Changing service classes to 0x480104
bluetoothd[15536]: Can't set link policy on hci0: No such device (19)
bluetoothd[15533]: Adapter /org/bluez/15533/hci0 has been enabled
bluetoothd[15533]: Stopping security manager 0
bluetoothd[15533]: Changing service classes to 0x480104
bluetoothd[15533]: Can't write class of device: Unknown error 4294967186 (-110)
bluetoothd[15533]: Entering main loop
bluetoothd[15533]: child 15536 exited
bluetoothd[15533]: HCI dev 0 down
bluetoothd[15533]: Adapter /org/bluez/15533/hci0 has been disabled
bluetoothd[15533]: HCI dev 0 up
bluetoothd[15533]: Starting security manager 0
bluetoothd[15533]: inquiry_cancel at adapter startup

Program received signal SIGSEGV, Segmentation fault.
0xb7dd73ba in ?? ()
(gdb) backtrace full
#0 0xb7dd73ba in ?? ()
No symbol table info available.
Cannot access memory at address 0xbf5d7fc0
(gdb) info registers
eax 0xbf5d912f -1084387025
ecx 0x0 0
edx 0xbf5d912f -1084387025
ebx 0xb7fd8144 -1208123068
esp 0xbf5d7fc0 0xbf5d7fc0
ebp 0xbf5d8030 0xbf5d8030
esi 0xb848b1d0 -1203195440
edi 0xb7faf73a -1208289478
eip 0xb7dd73ba 0xb7dd73ba
eflags 0x210286 [ PF SF IF RF ID ]
cs 0x73 115
ss 0x7b 123
ds 0x7b 123
es 0x7b 123
fs 0x0 0
gs 0x33 51
(gdb) thread apply all backtrace
(gdb) quit

There are some interesting messages in /var/log/kern.log

Apr 6 22:48:23 kooka kernel: [1295911.574520] lt-bluetoothd[15189]: segfault at bf080fdc ip b7d7d3ba sp bf080fe0 error 6 in libc-2.9.so[b7cab000+15a000]
Apr 6 22:49:52 kooka kernel: [1296000.431677] lt-bluetoothd[15264]: segfault at bf228fec ip b7e253ba sp bf228ff0 error 6 in libc-2.9.so[b7d53000+15a000]
Apr 6 22:50:26 kooka kernel: [1296033.880910] lt-bluetoothd[15273]: segfault at bf309fcc ip b7d073ba sp bf309fd0 error 6 in libc-2.9.so[b7c35000+15a000]

--
If the From address bounces, please see http://www.pook.it/.

2009-04-05 17:22:12

by Johan Hedberg

[permalink] [raw]
Subject: Re: bluez 4.34 + Linksys USBBT100 + hcitool scan -> core dump

On Sun, Apr 05, 2009, Stuart Pook wrote:
> here I am replying to myself
>
> On 05/04/09 14:02, Stuart Pook wrote:
>> I tried it again with bluez 4.34 and now a simple "hcitool scan" makes
>> bluetoothd core dump.
>
> I have just noticed that I've been getting kernel errors with all this
> plugging and unplugging of Bluetooth adapters.

I don't know about the kernel, but there's a known bug with 4.34 that can make
bluetoothd crash when unpluging/repluging adapters. This was fixed in git
already several days ago with commit 457056310229911e820357470ee8fb30c82516da
("Fix org.bluez.Audio unregistration") so you might want to try if it helps.

Johan

2009-04-05 17:19:36

by Johan Hedberg

[permalink] [raw]
Subject: Re: bluez 4.34 + Linksys USBBT100 + hcitool scan -> core dump

Hi Stuart,

On Sun, Apr 05, 2009, Stuart Pook wrote:
> I have a Linksys (Cisco) USBBT100 Bluetooth 1.1 Adapter which has a 1.2 dBi
> antenna. I used to use it with Bluez 3 and it had a better range than my
> Belkin F8T017. It used to work (but not for audio) with older versions of
> bluez 4. I tried it again with bluez 4.34 and now a simple "hcitool scan"
> makes bluetoothd core dump.
>
> Bluetoothd does not crash when I swap my USBBT100 for my F8T017. A hcitool
> scan does however find fewer hosts.
>
> It would be great if my USBBT100 worked again. Please let me know if I can
> send any more information.

Thanks for the report! Unfortunately the valgrind report doesn't give too much
clues (except that this might be a stack overflow). Could you try and see if
this is reproducable with the latest git? You don't necessarily need to install
it, just compile with "./bootstrap-configure && make" and run the compiled
bluetoothd directly from the tree. Also, if you still don't manage to make
valgrind give you something sensible you could also try with gdb to see if it
works better in producing backtrace.

Johan

2009-04-05 17:04:10

by Stuart Pook

[permalink] [raw]
Subject: Re: bluez 4.34 + Linksys USBBT100 + hcitool scan -> core dump

here I am replying to myself

On 05/04/09 14:02, Stuart Pook wrote:
> I tried it again with bluez 4.34 and now a simple
> "hcitool scan" makes bluetoothd core dump.

I have just noticed that I've been getting kernel errors with all this plugging and unplugging of Bluetooth adapters.

The first one happened after I sent my email so it perhaps not the cause of the bluetoothd core dumps. All the other kernel errors have the same message ('hci0:6' can not be created).

Apr 5 12:14:39 kooka kernel: [1171487.385852] ------------[ cut here ]------------
Apr 5 12:14:39 kooka kernel: [1171487.385855] WARNING: at fs/sysfs/dir.c:462 sysfs_add_one+0x27/0x2f()
Apr 5 12:14:39 kooka kernel: [1171487.385857] sysfs: duplicate filename 'hci0:6' can not be created
Apr 5 12:14:39 kooka kernel: [1171487.385858] Modules linked in: battery hfs hfsplus udf crc_itu_t usblp snd_seq_dummy snd_seq_oss snd_seq_midi snd_seq_midi_event snd_seq rfcomm nls_iso8859_1 sco l2cap tun binfmt_misc kvm_intel kvm bridge stp ip6t_LOG nf_conntrack_ipv6 ipt_REJECT xt_limit nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack xt_comment ts_bm xt_string xt_length xt_tcpudp xt_physdev ipt_LOG ip6table_filter ip6_tables iptable_filter ip_tables x_tables ipv6 ext4 jbd2 crc16 nls_utf8 nls_cp437 vfat fat isofs nls_base zlib_inflate sha256_generic aes_i586 aes_generic cbc dm_crypt coretemp it87 hwmon_vid hid_dell hid_pl hid_cypress hid_zpff hid_gyration hid_bright hid_sony hid_samsung hid_microsoft hid_tmff hid_monterey hid_ezkey hid_apple hid_a4tech hid_logitech ff_memless snd_hda_intel snd_usb_audio hid_cherry snd_usb_lib i2c_i801 snd_mixer_oss hid_sunplus snd_rawmidi evdev serio_raw pcspkr i2c_core snd_pcm iTCO_wdt hid_petalynx snd_seq_device snd_timer hid_belki
n parport_pc usbhid snd_page_alloc snd_hwdep snd soundcore hid_chicony btusb bluetooth hid intel_agp agpgart button parport usb_storage ext3 jbd mbcache dm_mirror dm_region_hash dm_log dm_snapshot dm_mod ide_cd_mod cdrom sd_mod crc_t10dif ide_gd_mod ata_generic ide_pci_generic ahci uhci_hcd pdc202xx_new jmicron r8169 mii libata ide_core scsi_mod ehci_hcd usbcore thermal processor fan thermal_sys
Apr 5 12:14:39 kooka kernel: [1171487.385961] Pid: 1738, comm: btaddconn Tainted: G W 2.6.28-1-686 #1
Apr 5 12:14:39 kooka kernel: [1171487.385963] Call Trace:
Apr 5 12:14:39 kooka kernel: [1171487.385967] [<c0126d7a>] warn_slowpath+0x5a/0x79
Apr 5 12:14:39 kooka kernel: [1171487.385970] [<c011de3f>] enqueue_entity+0x6b/0x112
Apr 5 12:14:39 kooka kernel: [1171487.385974] [<c01f8c0e>] idr_get_empty_slot+0x145/0x202
Apr 5 12:14:39 kooka kernel: [1171487.385976] [<c01f8d9f>] ida_get_new_above+0xd4/0x178
Apr 5 12:14:39 kooka kernel: [1171487.385980] [<c01953d6>] find_inode+0x1b/0x56
Apr 5 12:14:39 kooka kernel: [1171487.385982] [<c01c25c4>] sysfs_ilookup_test+0x0/0xd
Apr 5 12:14:39 kooka kernel: [1171487.385985] [<c01954d5>] ifind+0x3a/0x73
Apr 5 12:14:39 kooka kernel: [1171487.385987] [<c01c2777>] sysfs_find_dirent+0x13/0x23
Apr 5 12:14:39 kooka kernel: [1171487.385990] [<c01c28f3>] sysfs_add_one+0x27/0x2f
Apr 5 12:14:39 kooka kernel: [1171487.385992] [<c01c2d73>] create_dir+0x3c/0x6c
Apr 5 12:14:39 kooka kernel: [1171487.386010] [<f90f9585>] add_conn+0x0/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386013] [<c01c2dcc>] sysfs_create_dir+0x29/0x3b
Apr 5 12:14:39 kooka kernel: [1171487.386016] [<c01f95b2>] kobject_get+0xf/0x13
Apr 5 12:14:39 kooka kernel: [1171487.386019] [<c01f96c4>] kobject_add_internal+0xb6/0x14f
Apr 5 12:14:39 kooka kernel: [1171487.386033] [<f90f9585>] add_conn+0x0/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386035] [<c01f986e>] kobject_add+0x44/0x47
Apr 5 12:14:39 kooka kernel: [1171487.386038] [<c0259d54>] device_add+0x7b/0x455
Apr 5 12:14:39 kooka kernel: [1171487.386041] [<c01f860c>] __next_cpu+0x12/0x21
Apr 5 12:14:39 kooka kernel: [1171487.386054] [<f90f9585>] add_conn+0x0/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386068] [<f90f959c>] add_conn+0x17/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386071] [<c0133f6b>] run_workqueue+0x89/0x10e
Apr 5 12:14:39 kooka kernel: [1171487.386073] [<c01340a6>] worker_thread+0xb6/0xc2
Apr 5 12:14:39 kooka kernel: [1171487.386077] [<c0136cce>] autoremove_wake_function+0x0/0x2d
Apr 5 12:14:39 kooka kernel: [1171487.386079] [<c0133ff0>] worker_thread+0x0/0xc2
Apr 5 12:14:39 kooka kernel: [1171487.386081] [<c0136a0f>] kthread+0x38/0x5d
Apr 5 12:14:39 kooka kernel: [1171487.386084] [<c01369d7>] kthread+0x0/0x5d
Apr 5 12:14:39 kooka kernel: [1171487.386087] [<c0104773>] kernel_thread_helper+0x7/0x10
Apr 5 12:14:39 kooka kernel: [1171487.386089] ---[ end trace 1bc6cd22ec210d33 ]---
Apr 5 12:14:39 kooka kernel: [1171487.386091] kobject_add_internal failed for hci0:6 with -EEXIST, don't try to register things with the same name in the same directory.
Apr 5 12:14:39 kooka kernel: [1171487.386094] Pid: 1738, comm: btaddconn Tainted: G W 2.6.28-1-686 #1
Apr 5 12:14:39 kooka kernel: [1171487.386096] Call Trace:
Apr 5 12:14:39 kooka kernel: [1171487.386098] [<c01f974d>] kobject_add_internal+0x13f/0x14f
Apr 5 12:14:39 kooka kernel: [1171487.386112] [<f90f9585>] add_conn+0x0/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386115] [<c01f986e>] kobject_add+0x44/0x47
Apr 5 12:14:39 kooka kernel: [1171487.386117] [<c0259d54>] device_add+0x7b/0x455
Apr 5 12:14:39 kooka kernel: [1171487.386130] [<c01f860c>] __next_cpu+0x12/0x21
Apr 5 12:14:39 kooka kernel: [1171487.386142] [<f90f9585>] add_conn+0x0/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386154] [<f90f959c>] add_conn+0x17/0x2f [bluetooth]
Apr 5 12:14:39 kooka kernel: [1171487.386157] [<c0133f6b>] run_workqueue+0x89/0x10e
Apr 5 12:14:39 kooka kernel: [1171487.386159] [<c01340a6>] worker_thread+0xb6/0xc2
Apr 5 12:14:39 kooka kernel: [1171487.386162] [<c0136cce>] autoremove_wake_function+0x0/0x2d
Apr 5 12:14:39 kooka kernel: [1171487.386165] [<c0133ff0>] worker_thread+0x0/0xc2
Apr 5 12:14:39 kooka kernel: [1171487.386167] [<c0136a0f>] kthread+0x38/0x5d
Apr 5 12:14:39 kooka kernel: [1171487.386170] [<c01369d7>] kthread+0x0/0x5d
Apr 5 12:14:39 kooka kernel: [1171487.386172] [<c0104773>] kernel_thread_helper+0x7/0x10
Apr 5 12:14:39 kooka kernel: [1171487.386174] add_conn: Failed to register connection device

--
If the From address bounces, please see http://www.pook.it/.