kernel-packages team mailing list archive

Thread
Date
[Bug 1273629] Re: HSP fails on Ubuntu Touch [Bluetooth headset does not work]

To: kernel-packages@xxxxxxxxxxxxxxxxxxx
From: Julien Funk <julien.funk@xxxxxxxxxxxxx>
Date: Wed, 28 May 2014 15:13:05 -0000
Reply-to: Bug 1273629 <1273629@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Tags added: avengers

-- 
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to bluez in Ubuntu.
https://bugs.launchpad.net/bugs/1273629

Title:
  HSP fails on Ubuntu Touch [Bluetooth headset does not work]

Status in “bluez” package in Ubuntu:
  In Progress

Bug description:
  When on Ubuntu Touch, HSP consistently fails to route any audio to the
  paired audio device.

  bluez-test-device create <BT address>
  bluez-test-audio connect <BT address>

  The above should create and pair a detected (in discoverable mode)
  bluetooth device, by default setting it up for HSP.

  The following excerpt from syslog on my mako shows the issue, with a
  bluetooth headset device failing to bring up HSP -- pulseaudio can
  acquire the first transport, but never release it:

  Jan 28 09:47:41 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:start_inquiry() hci0 length 8
  Jan 28 09:47:41 ubuntu-phablet bluetoothd[4621]: Discovery session 0x41f77f98 with :1.132 activated
  Jan 28 09:47:41 ubuntu-phablet bluetoothd[4621]: src/adapter.c:session_ref() 0x41f77f98: ref=1
  Jan 28 09:47:41 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:set_state() hci0: new state 1
  Jan 28 09:47:49 ubuntu-phablet bluetoothd[4621]: src/adapter.c:session_remove() Discovery session 0x41f77f98 with :1.132 deactivated
  Jan 28 09:47:49 ubuntu-phablet bluetoothd[4621]: src/adapter.c:session_remove() Stopping discovery
  Jan 28 09:47:49 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:hciops_stop_discovery() index 0
  Jan 28 09:47:49 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:hciops_stop_inquiry() hci0
  Jan 28 09:47:49 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:set_state() hci0: new state 0
  Jan 28 09:47:54 ubuntu-phablet bluetoothd[4621]: src/adapter.c:create_device() 00:1A:7D:54:32:8D
  Jan 28 09:47:54 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_create_device() 00:1A:7D:54:32:8D
  Jan 28 09:47:54 ubuntu-phablet bluetoothd[4621]: src/device.c:device_create() Creating device /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:47:54 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_ref() 0x41f936e8: ref=1
  Jan 28 09:47:54 ubuntu-phablet bluetoothd[4621]: src/device.c:device_set_temporary() temporary 1
  Jan 28 09:47:54 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_ref() 0x41f936e8: ref=2
  Jan 28 09:47:54 ubuntu-phablet kernel: [ 3389.758613] l2cap_sock_connect: failed -115
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:conn_complete() status 0x00
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_version_information() hci0 status 0
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_features_information() hci0 status 0
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_name_information() hci0 status 0
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/device.c:device_probe_drivers() Probing drivers for 00:1A:7D:54:32:8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: serial/manager.c:serial_probe() path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: 00001108-0000-1000-8000-00805f9b34fb
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: serial/port.c:create_serial_device() Registered interface org.bluez.Serial on path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: serial/manager.c:serial_probe() path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: 0000111e-0000-1000-8000-00805f9b34fb
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: input/manager.c:headset_probe() path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_ref() 0x41f936e8: ref=3
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: input/device.c:input_device_new() Registered interface org.bluez.Input on path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_ref() 0x41f936e8: ref=4
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: audio/device.c:audio_device_register() Registered interface org.bluez.Audio on path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: audio/manager.c:handle_uuid() Found Headset record
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_init() Registered interface org.bluez.Headset on path /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: audio/manager.c:handle_uuid() Found Handsfree record
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/device.c:device_set_temporary() temporary 0
  Jan 28 09:47:55 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_unref() 0x41f936e8: ref=3
  Jan 28 09:47:56 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:__get_remote_version() hci0 handle 7
  Jan 28 09:47:56 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_version_information() hci0 status 0
  Jan 28 09:47:56 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_features_information() hci0 status 0
  Jan 28 09:47:59 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:disconn_complete() handle 7 status 0x00
  Jan 28 09:47:59 ubuntu-phablet bluetoothd[4621]: src/event.c:btd_event_disconn_complete() 
  Jan 28 09:47:59 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_remove_connection() 
  Jan 28 09:48:04 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_state() State changed /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECTING
  Jan 28 09:48:04 ubuntu-phablet bluetoothd[4621]: audio/media.c:headset_state_changed() 
  Jan 28 09:48:04 ubuntu-phablet bluetoothd[4621]: audio/media.c:media_endpoint_async_call() Calling SetConfiguration: name = :1.38 path = /MediaEndpoint/HFPAG
  Jan 28 09:48:04 ubuntu-phablet kernel: [ 3399.837081] l2cap_sock_connect: failed -115
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:conn_complete() status 0x00
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_version_information() hci0 status 0
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_features_information() hci0 status 0
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:remote_name_information() hci0 status 0
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_channel() Discovered Handsfree service on channel 2
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_connect() /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: Connecting to 00:1A:7D:54:32:8D channel 2
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:link_key_request() hci0 dba 00:1A:7D:54:32:8D
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:get_auth_info() hci0 dba 00:1A:7D:54:32:8D
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:link_key_request() kernel auth requirements = 0x04
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:link_key_request() Matching key not found
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:io_capa_request() hci0 IO capability request for 00:1A:7D:54:32:8D
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:get_auth_info() hci0 dba 00:1A:7D:54:32:8D
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:get_io_cap() initial authentication requirement is 0x04
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:get_io_cap() final authentication requirement is 0x04
  Jan 28 09:48:06 ubuntu-phablet kernel: [ 3401.199816] l2cap_sock_connect: failed -115
  Jan 28 09:48:06 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:io_capa_response() hci0 IO capability response from 00:1A:7D:54:32:8D
  Jan 28 09:48:11 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:user_confirm_request() hci0
  Jan 28 09:48:11 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:user_confirm_request() auto accept of confirmation
  Jan 28 09:48:11 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:hciops_confirm_reply() hci0 dba 00:1A:7D:54:32:8D success 1
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:simple_pairing_complete() hci0 status 0
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/event.c:btd_event_simple_pairing_complete() status=00
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:link_key_notify() hci0 dba 00:1A:7D:54:32:8D type 4
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:link_key_notify() key type 0x04 old key type 0xff
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:link_key_notify() local auth 0x04 and remote auth 0x04
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/event.c:btd_event_link_key_notify() storing link key of type 0x04
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/device.c:device_set_bonded() bonded 1
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:bonding_complete() status 0x00
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/device.c:device_bonding_complete() bonding (nil) status 0x00
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/device.c:device_bonding_complete() setting timer for reverse service discovery
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:auth_complete() hci0 status 0
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:bonding_complete() status 0x00
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/adapter.c:adapter_get_device() 00:1A:7D:54:32:8D
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: src/device.c:device_bonding_complete() bonding (nil) status 0x00
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_connect_cb() /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: Connected to 00:1A:7D:54:32:8D
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_io_cb() rfcomm_io_cb: io event: 1
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: audio/headset.c:handle_event() Received AT+BRSF=24
  Jan 28 09:48:12 ubuntu-phablet bluetoothd[4621]: audio/headset.c:print_hf_features() HFP HF features: "Voice recognition activation" "Remote volume control" 
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_io_cb() rfcomm_io_cb: io event: 1
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:handle_event() Received AT+CIND=?
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_io_cb() rfcomm_io_cb: io event: 1
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:handle_event() Received AT+CIND?
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_io_cb() rfcomm_io_cb: io event: 1
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:handle_event() Received AT+CMER=3,0,0,1
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:event_reporting() Event reporting (CMER): mode=3, ind=1
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:hfp_slc_complete() HFP Service Level Connection established
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/telephony.c:telephony_device_connected() telephony-dummy: device 0x41f90938 connected
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_state() State changed /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: HEADSET_STATE_CONNECTING -> HEADSET_STATE_CONNECTED
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/media.c:headset_state_changed() 
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_transport_acquire() Transport /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D/fd4: read lock acquired
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_transport_acquire() Transport /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D/fd4: write lock acquired
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_owner_create() Owner created: sender=:1.38 accesstype=rw
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_state() State changed /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/media.c:headset_state_changed() 
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_request_create() Request created: method=Acquire id=1
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_owner_add() Owner :1.38 Request Acquire
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_transport_add() Transport /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D/fd4 Owner :1.38
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:sco_connect_cb() SCO socket opened for headset /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:sco_connect_cb() SCO fd=28
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D/fd4: fd(28) ready
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_owner_remove() Owner :1.38 Request Acquire
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_state() State changed /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
  Jan 28 09:48:13 ubuntu-phablet bluetoothd[4621]: audio/media.c:headset_state_changed() 
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_gain() Ignoring no-change in speaker gain
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_gain() Ignoring no-change in microphone gain
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_io_cb() rfcomm_io_cb: io event: 1
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:handle_event() Received AT+VGS=15
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_gain() Ignoring no-change in speaker gain
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:rfcomm_io_cb() rfcomm_io_cb: io event: 1
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:handle_event() Received AT+VGM=15
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_set_gain() Ignoring no-change in microphone gain
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_ref() 0x41f936e8: ref=4
  Jan 28 09:48:14 ubuntu-phablet kernel: [ 3409.565877] l2cap_sock_connect: failed -115
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: src/device.c:search_cb() 00:1A:7D:54:32:8D: No service update
  Jan 28 09:48:14 ubuntu-phablet bluetoothd[4621]: src/device.c:btd_device_unref() 0x41f936e8: ref=3
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_suspend_stream() headset_suspend_stream: has SCO transport, needs to be shut down
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_suspend_stream() headset_suspend_stream: have socket 28
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_suspend_stream() headset_suspend_stream: could not close socket: 103
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: audio/headset.c:headset_suspend_stream() headset_suspend_stream: shutdown ret -1
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_request_create() Request created: method=Release id=2
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: audio/transport.c:media_owner_add() Owner :1.38 Request Release
  Jan 28 09:48:19 ubuntu-phablet bluetoothd[4621]: plugins/hciops.c:disconn_complete() handle 9 status 0x00
  Jan 28 09:48:44 ubuntu-phablet pulseaudio[1773]: [bluetooth] bluetooth-util.c: Failed to release transport /org/bluez/4621/hci0/dev_00_1A_7D_54_32_8D/fd4: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1273629/+subscriptions
References

[Bug 1273629] [NEW] HSP fails on Ubuntu Touch
From: Mathieu Trudel-Lapierre, 2014-01-28