Bug 97064 - No audio stream from headset in HSP/HFP mode
Summary: No audio stream from headset in HSP/HFP mode
Status: RESOLVED INVALID
Alias: None
Product: PulseAudio
Classification: Unclassified
Component: core (show other bugs)
Version: unspecified
Hardware: Other All
: medium normal
Assignee: pulseaudio-bugs
QA Contact: pulseaudio-bugs
URL:
Whiteboard:
Keywords:
: 97316 (view as bug list)
Depends on:
Blocks:
 
Reported: 2016-07-24 12:18 UTC by Fabian Köster
Modified: 2016-10-17 10:18 UTC (History)
3 users (show)

See Also:
i915 platform:
i915 features:


Attachments
Output of LANG=C pulseaudio -vvvv --log-time=1 > ~/pulseverbose.log 2>&1 (665.03 KB, text/plain)
2016-07-24 12:18 UTC, Fabian Köster
Details
Bluez and Pulseaudio logs. (90.07 KB, text/plain)
2016-10-05 22:17 UTC, bschaef14
Details
bluetoothd log supplemented with performed actions (60.73 KB, text/plain)
2016-10-06 08:35 UTC, Fabian Köster
Details
pulseaudio log with supplemented actions (301.05 KB, text/plain)
2016-10-06 08:35 UTC, Fabian Köster
Details
attachment-25830-0.html (960 bytes, text/html)
2016-10-07 18:39 UTC, bschaef14
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Fabian Köster 2016-07-24 12:18:36 UTC
Created attachment 125285 [details]
Output of LANG=C pulseaudio -vvvv --log-time=1 > ~/pulseverbose.log 2>&1

I have the bluetooth headset Sennheiser MB Pro 2 why I would like to use in headset mode (record and output audio).

I am using bluez5 (5.39) and I can successfully pair and connect the device.
bluetoothctl shows the following information:

Device 00:16:94:15:49:C8
        Name: Sennheiser MB Pro 2
        Alias: Sennheiser MB Pro 2
        Class: 0x240404
        Icon: audio-card
        Paired: yes
        Trusted: yes
        Blocked: no
        Connected: no
        LegacyPairing: no
        UUID: Headset                   (00001108-0000-1000-8000-00805f9b34fb)
        UUID: Audio Sink                (0000110b-0000-1000-8000-00805f9b34fb)
        UUID: Handsfree                 (0000111e-0000-1000-8000-00805f9b34fb)
        UUID: Vendor specific           (1ddce62a-ecb1-4455-8153-0743c87aec9f)

bluetoothd logs the following:

bluetoothd[2591]: Endpoint registered: sender=:1.98 path=/MediaEndpoint/A2DPSource
bluetoothd[2591]: Endpoint registered: sender=:1.98 path=/MediaEndpoint/A2DPSink

The device works fine in A2DP mode and also in HSP/HFP mode under Windows 10 without any special drivers.

In /etc/pulse/default.pa I added the argument "headset=auto" to the line
"load-module module-bluetooth-discover" as suggested in https://bugs.freedesktop.org/show_bug.cgi?id=73325#c52 to be able to switch to the HSP/HFP  profile at all (previously it jumped right back to A2DP).

I already tried different versions of bluez5 like the up2date 5.40 and different versions of pulseaudio like the previous 8.0 without any difference.

Currently I am using the current master of pulseaudio (commit )

I also tried compiling in ofono support but if I understood correctly it is only useful for the opposite direction, connecting a PC _as headset_ to an other device like a smartphone.

Currently I have only enabled the native-headset support, as you can see in my Gentoo package settings:

media-sound/pulseaudio-9999::x-portage was built with the following:
USE="X alsa alsa-plugin asyncns bluetooth caps dbus gdbm glib gnome gtk ipv6 native-headset orc qt4 ssl systemd tcpd udev webrtc-aec zeroconf -doc -equalizer -jack -libressl -libsamplerate -lirc (-neon) -ofono-headset (-oss) -realtime (-selinux) -sox (-system-wide) -test -xen" ABI_X86="32 64 -x32"

I cannot see anything suspicious in the log file (see attachment).

I am really willing to make this setup work and can provide more information, test different versions (also from git or sth), apply experimental patches or what ever you need to fix this bug.

----
Plasma 5.7 with phonon-vlc
Gentoo Linux
Kernel 4.4.12
Comment 1 Forrest Loomis 2016-08-10 14:13:39 UTC
I have this exact same problem with the Jabra Move Wireless
Comment 2 Tanu Kaskinen 2016-08-10 15:04:14 UTC
Fabian, you didn't really explain what the symptoms are. The log looks like HSP is working fine.
Comment 3 Fabian Köster 2016-08-15 07:18:15 UTC
(In reply to Tanu Kaskinen from comment #2)
> Fabian, you didn't really explain what the symptoms are. The log looks like
> HSP is working fine.

Oh, you are right, sorry :D

The symptoms are:

When switching the headset to hsp/hfp mode using pavucontrol, a new capture device appears in pulseaudio. But the signal meter in pavucontrol does not show any amplitude. Furthermore, when trying to record from this capture device for example using Audacity, the stream seams to be stuck.

When I list the sources with "pacmd list-sources":

    index: 4
        name: <bluez_sink.00_16_94_15_49_C8.monitor>
        driver: <module-bluez5-device.c>
        flags: DECIBEL_VOLUME LATENCY 
        state: RUNNING
        suspend cause: 
        priority: 1030
        volume: mono: 65536 / 100% / 0,00 dB
                balance 0,00
        base volume: 65536 / 100% / 0,00 dB
        volume steps: 65537
        muted: no
        current latency: 0,00 ms
        max rewind: 0 KiB
        sample spec: s16le 1ch 8000Hz
        channel map: mono
                     Mono
        used by: 1
        linked by: 1
        fixed latency: 128,00 ms
        monitor_of: 2
        card: 2 <bluez_card.00_16_94_15_49_C8>
        module: 31
        properties:
                device.description = "Monitor of Sennheiser MB Pro 2"
                device.class = "monitor"
                device.string = "00:16:94:15:49:C8"
                device.api = "bluez"
                device.bus = "bluetooth"
                device.form_factor = "headset"
                bluez.path = "/org/bluez/hci0/dev_00_16_94_15_49_C8"
                bluez.class = "0x240404"
                bluez.alias = "Sennheiser MB Pro 2"
                device.icon_name = "audio-headset-bluetooth"
                device.intended_roles = "phone"
    index: 5
        name: <bluez_source.00_16_94_15_49_C8>
        driver: <module-bluez5-device.c>
        flags: HARDWARE HW_VOLUME_CTRL LATENCY 
        state: RUNNING
        suspend cause: 
        priority: 9030
        volume: mono: 65536 / 100%
                balance 0,00
        base volume: 65536 / 100%
        volume steps: 16
        muted: no
        current latency: 25,00 ms
        max rewind: 0 KiB
        sample spec: s16le 1ch 8000Hz
        channel map: mono
                     Mono
        used by: 1
        linked by: 1
        fixed latency: 28,00 ms
        card: 2 <bluez_card.00_16_94_15_49_C8>
        module: 31
        properties:
                bluetooth.protocol = "headset_head_unit"
                device.intended_roles = "phone"
                device.description = "Sennheiser MB Pro 2"
                device.string = "00:16:94:15:49:C8"
                device.api = "bluez"
                device.class = "sound"
                device.bus = "bluetooth"
                device.form_factor = "headset"
                bluez.path = "/org/bluez/hci0/dev_00_16_94_15_49_C8"
                bluez.class = "0x240404"
                bluez.alias = "Sennheiser MB Pro 2"
                device.icon_name = "audio-headset-bluetooth"
        ports:
                headset-input: Headset (priority 0, latency offset 0 usec, available: unknown)
                        properties:

        active port: <headset-input>
Comment 4 Tanu Kaskinen 2016-08-15 19:50:36 UTC
I would guess that this isn't a pulseaudio bug, the device (or the kernel driver) is probably just not producing any audio for some reason. But we can try to get some more information from logs.

First, prevent automatic starting of pulseaudio and bluetoothd. For pulseaudio, I'm not sure if gentoo uses systemd or not to manage pulseaudio. If it does, then run commands

systemctl --user disable pulseaudio.service pulseaudio.socket
systemctl --user stop pulseaudio.service pulseaudio.socket

To undo this later, use these commands:

systemctl --user enable pulseaudio.socket
systemctl --user start pulseaudio.socket

If gentoo doesn't use systemd with pulseaudio, put "autospawn = no" to ~/.config/pulse/client.conf. (To undo this later, remove that setting.) Then, run "killall pulseaudio".

Now pulseaudio shouldn't be running, and "pactl info" should say "Connection refused".

To disable bluetoothd, I think these commands should do the trick:

sudo systemctl disable bluetooth.service
sudo systemctl stop bluetooth.service

To undo this later, use these commands:

sudo systemctl enable bluetooth.service
sudo systemctl start bluetooth.service

Now bluetoothd shouldn't be running.

Next, start the daemons in terminals. First, start bluetoothd with

sudo /usr/lib/bluetooth/bluetoothd --debug --nodetach

(The path might also start with /usr/lib64, I'm not familiar with the gentoo file system layout.)

Then, start pulseaudio in another terminal with

LANG=C pulseaudio --log-time -vv

Then, connect the headset, and set the profile to "off" with this command:

pactl set-card-profile bluez_card.00_16_94_15_49_C8 off

Now, hit enter a few times in the bluetoothd and pulseaudio terminals. This helps with visually separating the interesting parts.

Then, switch to the HSP profile:

pactl set-card-profile bluez_card.00_16_94_15_49_C8 headset_head_unit

Hit enter again a few times in the bluetoothd and pulseaudio terminals.

Then, try to record something with parecord:

parecord -v --device=bluez_source.00_16_94_15_49_C8 /dev/null

Hit enter again a few times in the bluetoothd and pulseaudio terminals.

Normally, parecord should update the time and latency that are shown on the last line, but I guess in this case both stay at zero?

Now the experiments are done. You can stop parecord with ctrl-c, and bluetoothd and pulseaudio likewise. Copy the bluetoothd and pulseaudio logs from the terminals to files and attach the files to this bug.
Comment 5 bschaef14 2016-10-05 22:16:11 UTC
Was this ever resolved? I'm seeing a very similar issue where my headset can play audio as A2DP but fails to play anything when setup as headset_head_unit.
I understand it's probably not an issue with pulseaudio, but not sure whats incorrect where I can't play audio with HSP/HFP.

I did notice when attempting to play audio using pacat that time was never updated, as you thought might be the issue.

Attached are my logs.. I'm happy to provide any extra info that could help.
Comment 6 bschaef14 2016-10-05 22:17:22 UTC
Created attachment 127040 [details]
Bluez and Pulseaudio logs.
Comment 7 Fabian Köster 2016-10-06 07:19:30 UTC
(In reply to bschaef14 from comment #5)
> Was this ever resolved?

No, the issue was not resolved. But I also did not try to reproduce it for some time.

@Tanu

I am so sorry that I did not respond to your message! The email notification must have slipped through somehow. So embarrassing :-/

I will follow Tanu's instructions and report back later today, promise!
Comment 8 Fabian Köster 2016-10-06 08:35:20 UTC
Created attachment 127046 [details]
bluetoothd log supplemented with performed actions

I performed the steps described by Tanu and created the requested log files.
Comment 9 Fabian Köster 2016-10-06 08:35:41 UTC
Created attachment 127047 [details]
pulseaudio log with supplemented actions
Comment 10 Fabian Köster 2016-10-06 08:36:20 UTC
Please let me know if you need more information!
Comment 11 Fabian Köster 2016-10-06 08:38:10 UTC
Forgot to mention, the software versions used to create those logs:

Linux 4.7.6
Pulseaudio 9.0
Bluez 5.41
Comment 12 Tanu Kaskinen 2016-10-06 12:06:39 UTC
bschaef, I inspected your logs, and it looks that bluetoothd didn't send a D-Bus message that it should have sent. The lack of the message in itself doesn't cause the breakage, but it indicates that something went wrong during the setup of the audio connection.

If you search the logs for "state changed from", you'll find the places where transport objects change their state between "disconnected", "idle" and "playing". When you connect the headset, the HSP transport changes state from disconnected to idle, and this triggers the procedure where pulseaudio loads module-bluez5-device and creates the sink and source. During the sink setup, pulseaudio "aqcuires" the transport, and as a result pulseaudio gets the file descriptor that it uses to send audio to the headset. The "acquire" operation looks like it succeeds without problems, but I think the transport state should have changed at this point from idle to playing, but there's no "state changed from idle to playing" message in the log (except when you use A2DP). The information about the transport state change is sent through D-Bus with the "PropertiesChanged" signal on the "MediaTransport1" interface, so that's why I said there's a D-Bus message missing.

I don't have any ideas why the message isn't sent, but that should provide you some information for continuing the debugging.
Comment 13 Tanu Kaskinen 2016-10-06 12:38:08 UTC
Fabian, your log also doesn't show a "state changed from idle to playing" despite that acquiring the transport seemed to succeed.

When you connected your headset, the bluetoothd log showed something that looked strange to me (but I'm no expert in reading bluetoothd logs):

src/device.c:connect_profiles() /org/bluez/hci0/dev_00_16_94_15_49_C8 (all), client :1.57

src/service.c:btd_service_ref() 0x5565d46788d0: ref=2

src/service.c:change_state() 0x5565d46788d0: device 00:16:94:15:49:C8 profile Headset Voice gateway state changed: disconnected -> connecting (0)

src/adapter.c:connected_callback() hci0 device 00:16:94:15:49:C8 connected eir_len 21

src/profile.c:ext_connect() Headset Voice gateway connected to 00:16:94:15:49:C8

src/service.c:change_state() 0x5565d46788d0: device 00:16:94:15:49:C8 profile Headset Voice gateway state changed: connecting -> connected (0)

src/device.c:device_profile_connected() Headset Voice gateway Success (0)

src/service.c:btd_service_ref() 0x5565d468c2a0: ref=2

src/service.c:change_state() 0x5565d468c2a0: device 00:16:94:15:49:C8 profile Headset Voice gateway state changed: disconnected -> connecting (0)

src/service.c:btd_service_ref() 0x5565d46788d0: ref=3

plugins/policy.c:service_cb() Added Headset Voice gateway reconnect 0

Unable to get connect data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)

src/service.c:change_state() 0x5565d468c2a0: device 00:16:94:15:49:C8 profile Headset Voice gateway state changed: connecting -> disconnected (-111)

src/device.c:device_profile_connected() Headset Voice gateway Connection refused (111)


It looks as if bluetoothd tried connecting HSP on the same device twice, and the first attempt succeeded and the second one failed. There are two things, identified as "0x5565d46788d0" and "0x5565d468c2a0", and whatever those things are, they seem to have separate connection states.
Comment 14 Fabian Köster 2016-10-06 13:34:29 UTC
Tanu, thank you very much for your quick analysis!

So if I understand you correctly, the bug appears to not be in PulseAudio but in bluetoothd and the symptom being that the dbus event "state changed to playing" is not sent from bluetoothd to PulseAudio, right?

Would you then recommend asking for help on the linux-bluetooth mailing list? Furthermore, do you have any more ideas on how to debug this thing?

Thanks again!
Comment 15 Tanu Kaskinen 2016-10-06 13:52:49 UTC
Yes, the linux-bluetooth list seems like a good place to ask.

As for debugging advice, I don't think I have much to contribute. If this happened on my machine and I was determined to figure it out by myself, I'd study the bluetoothd code to figure out what would have to happen in order to get the PropertiesChanged D-Bus signal sent, and then add extra logging there until I found out what exactly goes wrong.
Comment 16 Fabian Köster 2016-10-06 15:12:13 UTC
(In reply to Tanu Kaskinen from comment #15)
> Yes, the linux-bluetooth list seems like a good place to ask.

Alrighty! Will do that then.

> As for debugging advice, I don't think I have much to contribute. If this
> happened on my machine and I was determined to figure it out by myself, I'd
> study the bluetoothd code to figure out what would have to happen in order
> to get the PropertiesChanged D-Bus signal sent, and then add extra logging
> there until I found out what exactly goes wrong.

Thanks, that already helps me :)
Comment 17 Tanu Kaskinen 2016-10-07 10:15:18 UTC
Brandon brought this up on linux-bluetooth: https://marc.info/?t=147579093700002&r=1&w=2&n=2

It seems that I was wrong about the missing D-Bus signal. Apparently it's expected behaviour that bluetoothd sends no state updates for the transport object, and in fact the whole transport object is fiction created by PulseAudio in order to make A2DP and HSP look more similar. I don't see anything else in Brandon's logs that would give any clues, so the only hint is now what Luiz said on the linux-bluetooth thread: "perhaps your controller is not set for HCI routing?"

I don't know what "set for HCI routing" means.
Comment 18 bschaef14 2016-10-07 18:39:58 UTC
Created attachment 127121 [details]
attachment-25830-0.html

Hey Tanu,

So I've made what I think to be good progress in the last day.. My BT
chipset is configured by default to use syncronous audio interface (sai) to
send PCM data for HSP/HFP profiles and A2DP uses HCI to send audio data.
After conversing with some others, it seems like PCM lines weren't
configured in device tree/kernel/wherever so that's why no audio was being
sent.

Once I configured BT chipset to send HSP/HFP audio over HCI interface, I
did receive audio (although it was terrible, sounded like bad slow-mo
editing).

So it looks like nothing was configured incorrectly from a PA or bluez
perspective at least! Still got some work to do to make it usable.

Thanks a ton for your help

Still new to mailing lists; so I'll play it safe and send a separate email
to linux-bluetooth with similar information :)
Comment 19 Fabian Köster 2016-10-07 19:22:43 UTC
Hi Brandon,

(In reply to bschaef14 from comment #18)
> So I've made what I think to be good progress in the last day.. My BT
> chipset is configured by default to use syncronous audio interface (sai) to
> send PCM data for HSP/HFP profiles and A2DP uses HCI to send audio data.
> After conversing with some others, it seems like PCM lines weren't
> configured in device tree/kernel/wherever so that's why no audio was being
> sent.

good to hear there are new insights! Can you tell me which BT chipset you are using?

Mine is:
0a5c:21e8 Broadcom Corp. BCM20702A0 Bluetooth 4.0

> Once I configured BT chipset to send HSP/HFP audio over HCI interface, I
> did receive audio (although it was terrible, sounded like bad slow-mo
> editing).

Can you elaborate on how to configure it like that?
Comment 20 bschaef14 2016-10-07 19:58:46 UTC
> good to hear there are new insights! Can you tell me which BT chipset you
> are
> using?
>
> Mine is:
> 0a5c:21e8 Broadcom Corp. BCM20702A0 Bluetooth 4.0

For sure if it might help you: WL1837 from TI:
http://www.ti.com/product/WL1837MOD

> Can you elaborate on how to configure it like that?

The commands I needed to do were vendor specific, so they may not
correlate directly to your chipset.
Also, although we started with similar symptoms (no audio via headset
profile), the cause of my issue could be quite different from yours.
As Tanu pointed out you had issues with the headset profile remaining
connected.

HCI command issued: HCI_VS_Write_SCO_Configuration
# hcitool cmd 0x3F 0x0210 0x01 120 511 0xFF
< HCI Command: ogf 0x3f, ocf 0x0210, plen 4
  01 20 11 FF

Documentation on this command:
http://processors.wiki.ti.com/index.php/CC256x_VS_HCI_Commands#HCI_VS_Write_SCO_Configuration_.280xFE10.29
Comment 21 Fabian Köster 2016-10-07 20:37:44 UTC
I solved my issue!!

Turned out I needed an extra proprietary piece of software for my Broadcom BT chipset, which is also not distributed directly from Broadcom *facepalm*.

I was not expecting for any hardware or firmware issues because it was working just fine fore other BT profiles and Plugable, the vendor of my Bluetooth Adapter, promotes it with Linux support. But when I looked into dmesg output, I suddenly saw this line:

hci0: BCM: Patch brcm/BCM20702A1-0a5c-21e8.hcd not found

I googled it and found a blog post from - again - Plugable: [1]

It tells you to download the firmware file from some Amazon server (!?) and put it into your firmware directory at this location:

/lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd

And it actually works! First tests show that HSP/HFP is now finally working as expected :)

It is a shame for Broadcom though, that they do not distribute this firmware over the linux-firmware project [2] like they do with their other firmware files.

Just for the record (and for SEO) some checksums of the firmware file:

$ md5sum /lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd
7ba1f3084a61a4bcf7b8c8396e8a4201  /lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd
$ sha1sum /lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd
221639ead9313a96dcf89315d25364da12302fef  /lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd
$ sha256sum /lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd
d699c13fe1e20c068a8a88dbbed49edc12527b0ceeeaac3411e3298573451536  /lib/firmware/brcm/BCM20702A1-0a5c-21e8.hcd

(In reply to bschaef14 from comment #20)
> For sure if it might help you: WL1837 from TI:
> http://www.ti.com/product/WL1837MOD

It certainly helps distinguishing between similar but not identical bugs.

So I guess my original bug is solved and as Brandon does not see any issue in PA this report should be closed.

If there will occur new issues within the scope of PA, we should therefore open new bug reports.

[1] http://plugable.com/2014/06/23/plugable-usb-bluetooth-adapter-solving-hfphsp-profile-issues-on-linux/
[2] https://git.kernel.org/cgit/linux/kernel/git/firmware/linux-firmware.git
Comment 22 Fabian Köster 2016-10-07 20:38:35 UTC
And thanks again for your help Tanu and Brandon!
Comment 23 Tanu Kaskinen 2016-10-10 08:45:36 UTC
Great that you got it working! I'll add a reference from our bluetooth wiki page's troubleshooting section to this bug.
Comment 24 Tanu Kaskinen 2016-10-17 10:18:34 UTC
*** Bug 97316 has been marked as a duplicate of this bug. ***


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct.