Fails to set the HSP/HFP profile with Ford New Fiesta Sedan 2014 (Brazil)

[Gustavo Pichorim Boiko]

Car: Ford New Fiesta Sedan 2014 (the one sold in Brazil)
Image: RTM 239
Device: krillin

I paired the device, and tried to start a call but noticed there was no audio, so with help from Salveti we figured out switching to the hsp profile is faling, so the attached syslog is after running the following command:

pactl set-card-profile bluez_card.00_21_CC_E9_02_39 hsp

[Ricardo Salveti (rsalveti)]

The useful piece from the log:

Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] client.c: Created 7 "Native client (UNIX socket client)"
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Client added for object /org/pulseaudio/core1/client7
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: Protocol version: remote 28, local 28
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: Got credentials: uid=32011 gid=32011 success=1
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: SHM possible: yes
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: Negotiated SHM: yes
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] module-augment-properties.c: Looking for .desktop file for pactl
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Device removed from object /org/pulseaudio/core1/sink2
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Sink removed from object /org/pulseaudio/core1/sink2
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.DevicePort removed from object /org/pulseaudio/core1/sink2/port0
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] module-suspend-on-idle.c: Sink bluez_sink.00_21_CC_E9_02_39 becomes idle, timeout in 5 seconds.
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [bluetooth] sink.c: Requesting rewind due to started move
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: Requested tlength=250,00 ms, minreq=20,00 ms
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: Traditional mode enabled, modifying sink usec only for compat with minreq.
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-native.c: Requested latency=210,00 ms, Received latency=210,00 ms
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] sink-input.c: Successfully moved sink input 0 to sink.primary.
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] module-rescue-streams.c: Successfully moved sink input 0 "QtPulseAudio:2505" to sink.primary.
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Device removed from object /org/pulseaudio/core1/source4
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Source removed from object /org/pulseaudio/core1/source4
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] module-rescue-streams.c: No source outputs to move away.
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [bluetooth] module-bluetooth-device.c: IO thread shutdown requested, stopping cleanly
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [bluetooth] module-bluetooth-device.c: IO thread shutting down
Feb 18 17:16:19 ubuntu-phablet pulseaudio[2122]: [pulseaudio] module-bluetooth-device.c: Acquiring transport /org/bluez/859/hci0/dev_00_21_CC_E...

[Ricardo Salveti (rsalveti)]

Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/headset.c:headset_set_state() State changed /org/bluez/859/hci0/dev_00_21_CC_E9_02_39: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/media.c:headset_state_changed()
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_request_create() Request created: method=Acquire id=1
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_owner_add() Owner :1.46 Request Acquire
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_transport_add() Transport /org/bluez/859/hci0/dev_00_21_CC_E9_02_39/fd0 Owner :1.46
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: Operation not supported (95)
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_transport_remove() Transport /org/bluez/859/hci0/dev_00_21_CC_E9_02_39/fd0 Owner :1.46
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_transport_release() Transport /org/bluez/859/hci0/dev_00_21_CC_E9_02_39/fd0: read lock released
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_transport_release() Transport /org/bluez/859/hci0/dev_00_21_CC_E9_02_39/fd0: write lock released
Feb 18 17:16:19 ubuntu-phablet bluetoothd[859]: audio/transport.c:media_request_reply() Request Acquire Reply Input/output error

^^^

So it basically failed on request acquire, with a bad input/output error from the driver side. Could be a combination of kernel/driver/hardware, so it might need so further investigation on the kernel side.

[John McAleely (john.mcaleely)]

we've had multiple reports of failures with carkits:

bug #1421096
bug #1383575 https://bugs.launchpad.net/barajas/+bug/1383575/comments/7

[Ricardo Salveti (rsalveti)]

I this case it's different though, as the device is paired already (the issue is when enabling HSP/HFP).

[Julia Palandri (julia-palandri)]

@boiko, are you still able to reproduce this with the latest silo made available for this? if so, would you please comment on the public bugs, so we can keep better track?

THanks,

[John McAleely (john.mcaleely)]

I moved the bug to the public bluez project for better tracking.

[Daniel van Vugt (vanvugt)]

Ubuntu Touch is no longer supported.