Bug 458575

Summary: hcid crashes when trying to connect to a paired Bluetooth headset
Product: [Fedora] Fedora Reporter: Vladimir Mencl <mencl>
Component: bluez-utilsAssignee: David Woodhouse <dwmw2>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: medium    
Version: 9CC: bnocera
Target Milestone: ---   
Target Release: ---   
Hardware: i386   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-07-14 14:08:08 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
gdb output from running hcid inside gdb while it crashes none

Description Vladimir Mencl 2008-08-10 07:37:04 UTC
Description of problem:

hcid crashes when trying to connect to a paired Bluetooth headset
Version-Release number of selected component (if applicable):
bluez-utils-3.32-1.fc9.i386
(tried also bluez-utils-3.35-3.fc9.i386 from updates-testing, same result)


How reproducible:

Steps to Reproduce:
1. start hcid (service bluetooth start)
2. connect and pair a Jabra BT-135 headset with the system.
3. mplayer -ao alsa:device=bluetooth myfile.mp3
  
Actual results:

hcid crashes:

Aug  9 19:35:14 bragi kernel: hcid[19200]: segfault at 10 ip 004037ea sp bfdd1830 error 6 in libaudio.so[3f9000+22000]

mplayer fails to play audio to the headset:
[AO_ALSA] alsa-lib: pcm_bluetooth.c:1505:(audioservice_recv) Error receiving data from audio service: Success(0)
[AO_ALSA] alsa-lib: pcm_bluetooth.c:1521:(audioservice_expect) Bogus message BT_SETCONFIGURATION_REQ received while BT_SETCONFIGURATION_RSP was expected
[AO_ALSA] Unable to set hw-parameters: Invalid argument
Could not open/initialize audio device -> no sound.


Expected results:
mplayer playing audio to the headset, hcid running

Additional info:
Package versions:
rpm -qa bluez\* glib\* libcap\* libselinux\* dbus\* | sort -u
bluez-gnome-0.26-1.fc9.i386
bluez-libs-3.32-1.fc9.i386
bluez-libs-debuginfo-3.32-1.fc9.i386
bluez-libs-devel-3.32-1.fc9.i386
bluez-utils-3.32-1.fc9.i386
bluez-utils-alsa-3.32-1.fc9.i386
bluez-utils-debuginfo-3.32-1.fc9.i386
bluez-utils-gstreamer-3.32-1.fc9.i386
dbus-1.2.1-1.fc9.i386
dbus-debuginfo-1.2.1-1.fc9.i386
dbus-devel-1.2.1-1.fc9.i386
dbus-glib-0.74-8.fc9.i386
dbus-glib-devel-0.74-8.fc9.i386
dbus-libs-1.2.1-1.fc9.i386
dbus-python-0.82.4-2.fc9.i386
dbus-sharp-0.63-9.fc9.i386
dbus-x11-1.2.1-1.fc9.i386
glib-1.2.10-29.fc9.i386
glib2-2.16.5-1.fc9.i386
glib2-debuginfo-2.16.5-1.fc9.i386
glib2-devel-2.16.5-1.fc9.i386
glibc-2.8-8.i686
glibc-common-2.8-8.i386
glibc-debuginfo-2.8-8.i686
glibc-debuginfo-common-2.8-8.i386
glibc-devel-2.8-8.i386
glibc-headers-2.8-8.i386
glib-java-0.2.6-12.fc9.i386
glibmm24-2.16.2-1.fc9.i386
libcap-2.06-4.fc9.i386
libcap-debuginfo-2.06-4.fc9.i386
libcap-devel-2.06-4.fc9.i386
libselinux-2.0.67-4.fc9.i386
libselinux-debuginfo-2.0.67-4.fc9.i386
libselinux-devel-2.0.67-4.fc9.i386
libselinux-python-2.0.67-4.fc9.i386
libselinux-ruby-2.0.67-4.fc9.i386

hcid output and stack trace:
root@bragi:/home/mencl#gdb hcid
GNU gdb Fedora (6.8-17.fc9)
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 "i386-redhat-linux-gnu"...
(gdb) set args -n -d -s
(gdb) run
Starting program: /usr/sbin/hcid -n -d -s
hcid[6917]: Bluetooth HCI daemon
hcid[6917]: Enabling debug information
hcid[6917]: Parsing /etc/bluetooth/main.conf failed: No such file or directory
hcid[6917]: HCI dev 0 registered
Detaching after fork from child process 6921.
hcid[6917]: HCI dev 0 already up
hcid[6917]: Device hci0 has been added
Detaching after fork from child process 6923.
hcid[6917]: Starting security manager 0
hcid[6917]: Device hci0 has been activated
hcid[6917]: Starting SDP server
hcid[6917]: Adding rec : 0xb8acf568
hcid[6917]: with handle : 0x1
hcid[6917]: Adding rec : 0xb8acfb38
hcid[6917]: with handle : 0x0
hcid[6917]: Service classes 0x00
hcid[6917]: Loading plugins /usr/lib/bluetooth/plugins
hcid[6917]: /usr/lib/bluetooth/plugins/libaudio.so
hcid[6917]: Unix socket created: 15
hcid[6917]: audio.conf: Key file does not have key 'Master'
hcid[6917]: Couldn't find record for : 0x10000
hcid[6917]: Adding record with handle 0x10000
hcid[6917]: Adding rec : 0xb8ad1738
hcid[6917]: with handle : 0x10000
hcid[6917]: Service classes 0x00
hcid[6917]: audio.conf: Key file does not have key 'SCORouting'
hcid[6917]: audio.conf: Key file does not have key 'Disable'
hcid[6917]: audio.conf: Key file does not have group 'A2DP'
hcid[6917]: audio.conf: Key file does not have group 'A2DP'
hcid[6917]: audio.conf: Key file does not have group 'A2DP'
hcid[6917]: audio.conf: Key file does not have group 'A2DP'
hcid[6917]: audio.conf: Key file does not have key 'Master'
hcid[6917]: SEP 0xb8ad1e00 registered: type:0 codec:0 seid:1
hcid[6917]: Couldn't find record for : 0x10001
hcid[6917]: Adding record with handle 0x10001
hcid[6917]: Adding rec : 0xb8ad1e20
hcid[6917]: with handle : 0x10001
hcid[6917]: Service classes 0x08
hcid[6917]: audio.conf: Key file does not have key 'Master'
hcid[6917]: Couldn't find record for : 0x10002
hcid[6917]: Adding record with handle 0x10002
hcid[6917]: Adding rec : 0xb8ad1b88
hcid[6917]: with handle : 0x10002
hcid[6917]: Service classes 0x08
hcid[6917]: Couldn't find record for : 0x10003
hcid[6917]: Adding record with handle 0x10003
hcid[6917]: Adding rec : 0xb8ad20b8
hcid[6917]: with handle : 0x10003
hcid[6917]: Service classes 0x08
hcid[6917]: Registered manager path:/org/bluez/audio
hcid[6917]: Loading device 00:1A:45:6C:60:53 (headset )
hcid[6917]: Selecting default device
hcid[6917]: Setting 00:1A:45:6C:60:53 as default device
hcid[6917]: Registering service object: audio (/org/bluez/service_audio)
hcid[6917]: /usr/lib/bluetooth/plugins/libinput.so
hcid[6917]: Parsing /etc/bluetooth/input.conf failed: No such file or directory
hcid[6917]: Registered input manager path:/org/bluez/input
hcid[6917]: Created input device: /org/bluez/input/pointing0
hcid[6917]: Created input device: /org/bluez/input/keyboard1
hcid[6917]: Created input device: /org/bluez/input/pointing2
hcid[6917]: Registering service object: input (/org/bluez/service_input)
hcid[6917]: /usr/lib/bluetooth/plugins/libnetwork.so
hcid[6917]: /etc/bluetooth/network.conf: Key file does not have key 'Disable'
hcid[6917]: /etc/bluetooth/network.conf: Key file does not have key 'DisableSecurity'
hcid[6917]: /etc/bluetooth/network.conf: Key file does not have key 'Interface'
hcid[6917]: /etc/bluetooth/network.conf: Key file does not have key 'Interface'
hcid[6917]: /etc/bluetooth/network.conf: Key file does not have key 'Interface'
hcid[6917]: Config options: InterfacePrefix=bnep%d, PANU_Script=avahi-autoipd, GN_Script=avahi-autoipd, NAP_Script=dhclient, GN_Interface=pan0, NAP_Interface=pan1, Security=true
hcid[6917]: Can't create GN bridge
hcid[6917]: Registered manager path:/org/bluez/network
hcid[6917]: Registered server path:/org/bluez/network/nap
hcid[6917]: Registered server path:/org/bluez/network/gn
hcid[6917]: Registered server path:/org/bluez/network/panu
hcid[6917]: Registering service object: network (/org/bluez/service_network)
hcid[6917]: /usr/lib/bluetooth/plugins/libserial.so
hcid[6917]: Registered manager path:/org/bluez/serial
hcid[6917]: Registering service object: serial (/org/bluez/service_serial)
hcid[6917]: /usr/lib/bluetooth/plugins/libstorage.so
hcid[6917]: child 6921 exited
hcid[6917]: child 6923 exited
hcid[6917]: Default passkey agent (:1.58736, /org/bluez/passkey) registered
hcid[6917]: Default authorization agent (:1.58736, /org/bluez/auth) registered
hcid[6917]: link_key_request (sba=00:14:A4:DA:F0:D3, dba=00:1A:45:6C:60:53)
hcid[6917]: Got a svc srch attr req
hcid[6917]: Seq type : 53
hcid[6917]: Data size : 5
hcid[6917]: Data type: 0x1a
hcid[6917]: No of elements : 1
hcid[6917]: Bytes scanned: 7
hcid[6917]: Max Attr expected: 38
hcid[6917]: Seq type : 53
hcid[6917]: Data size : 3
hcid[6917]: Data type: 0x09
hcid[6917]: No of elements : 1
hcid[6917]: Continuation State size : 0
hcid[6917]: Sending rsp. status 0
hcid[6917]: Bytes Sent : 10
hcid[6917]: Got a svc srch attr req
hcid[6917]: Seq type : 53
hcid[6917]: Data size : 5
hcid[6917]: Data type: 0x1a
hcid[6917]: No of elements : 1
hcid[6917]: Bytes scanned: 7
hcid[6917]: Max Attr expected: 38
hcid[6917]: Seq type : 53
hcid[6917]: Data size : 3
hcid[6917]: Data type: 0x09
hcid[6917]: No of elements : 1
hcid[6917]: Continuation State size : 0
hcid[6917]: Entries in attr seq : 1
hcid[6917]: AttrDataType : 9
hcid[6917]: Response count : 1
hcid[6917]: Local PDU size : 19
hcid[6917]: Net PDU size : 21
hcid[6917]: Sending rsp. status 0
hcid[6917]: Bytes Sent : 29
hcid[6917]: Requesting authorization for device 00:1A:45:6C:60:53, UUID 0000111F-0000-1000-8000-00805F9B34FB
hcid[6917]: Accepted headset connection from 00:1A:45:6C:60:53 for /org/bluez/audio/device0
hcid[6917]: State changed /org/bluez/audio/device0: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECTED
hcid[6917]: link_key_notify (sba=00:14:A4:DA:F0:D3, dba=00:1A:45:6C:60:53)
hcid[6917]: Received AT+CKPD=200
hcid[6917]: Accepted new client connection on unix socket (fd=25)
hcid[6917]: Audio API: received BT_GETCAPABILITIES_REQ
hcid[6917]: Audio API: sending BT_GETCAPABILITIES_RSP
hcid[6917]: Audio API: received BT_SETCONFIGURATION_REQ
hcid[6917]: config sco - device = 00:1A:45:6C:60:53 access_mode = 2
hcid[6917]: connect: Socket operation on non-socket (88)

Program received signal SIGSEGV, Segmentation fault.
0x004037ea in headset_request_stream (dev=0xb8ad1790, cb=0x4047b4 <headset_setup_complete>, user_data=0xb8ad51d0) at headset.c:1716
1716            hs->pending->target_state = HEADSET_STATE_PLAYING;
(gdb) bt
#0  0x004037ea in headset_request_stream (dev=0xb8ad1790, cb=0x4047b4 <headset_setup_complete>, user_data=0xb8ad51d0) at headset.c:1716
#1  0x004056e2 in start_config (dev=0xb8ad1790, client=0xb8ad51d0) at unix.c:624
#2  0x0040620b in handle_setconfiguration_req (client=0xb8ad51d0, req=0xbfa3c0cc) at unix.c:938
#3  0x0040662c in client_cb (chan=0xb8acebb8, cond=G_IO_IN, data=0xb8ad51d0) at unix.c:1041
#4  0x001a5a7d in g_io_unix_dispatch (source=<value optimized out>, callback=<value optimized out>, user_data=Could not find the frame base for "g_io_unix_dispatch".
) at giounix.c:162
#5  0x0016f0d8 in IA__g_main_context_dispatch (context=<value optimized out>) at gmain.c:2012
#6  0x00172783 in g_main_context_iterate (context=<value optimized out>, block=<value optimized out>, dispatch=<value optimized out>, self=Could not find the frame base for "g_main_context_iterate".
) at gmain.c:2645
#7  0x00172ca2 in IA__g_main_loop_run (loop=<value optimized out>) at gmain.c:2853
#8  0xb7efb591 in main (argc=4, argv=0xbfa3c424) at main.c:946
(gdb)  print *hs
$1 = {hsp_handle = 0, hfp_handle = 0, rfcomm_ch = -1, rfcomm = 0xb8acd720, tmp_rfcomm = 0x0, sco = 0x0, sco_id = 0, auto_dc = 0, ring_timer = 0, dc_timer = 0,
  buf = "AT+CKPD=200", '\0' <repeats 1012 times>, data_start = 0, data_length = 0, hfp_active = 1, search_hfp = 0, cli_active = 0, ph_number = 0x0, type = 0,
  state = HEADSET_STATE_CONNECTED, pending = 0x0, sp_gain = -1, mic_gain = -1, hfp_features = 0, lock = 0}

Comment 1 Vladimir Mencl 2008-08-10 07:38:37 UTC
Created attachment 313888 [details]
gdb output from running hcid inside gdb while it crashes

Comment 2 Bug Zapper 2009-06-10 02:25:04 UTC
This message is a reminder that Fedora 9 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 9.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '9'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 9's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 9 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 3 Vladimir Mencl 2009-06-10 02:59:00 UTC
Works for me now in Fedora 10 - probably got fixed upstream in the meantime.

Comment 4 Bug Zapper 2009-07-14 14:08:08 UTC
Fedora 9 changed to end-of-life (EOL) status on 2009-07-10. Fedora 9 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.