Summary: | No audio stream from headset in HSP/HFP mode | ||
---|---|---|---|
Product: | PulseAudio | Reporter: | Fabian Köster <koesterreich> |
Component: | core | Assignee: | pulseaudio-bugs |
Status: | RESOLVED NOTOURBUG | QA Contact: | pulseaudio-bugs |
Severity: | normal | ||
Priority: | medium | CC: | bschaef14, cybercyst, lennart, paulr227 |
Version: | unspecified | ||
Hardware: | Other | ||
OS: | All | ||
Whiteboard: | |||
i915 platform: | i915 features: | ||
Attachments: |
Output of LANG=C pulseaudio -vvvv --log-time=1 > ~/pulseverbose.log 2>&1
Bluez and Pulseaudio logs. bluetoothd log supplemented with performed actions pulseaudio log with supplemented actions attachment-25830-0.html |
Description
Fabian Köster
2016-07-24 12:18:36 UTC
I have this exact same problem with the Jabra Move Wireless Fabian, you didn't really explain what the symptoms are. The log looks like HSP is working fine. (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> 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. 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. Created attachment 127040 [details]
Bluez and Pulseaudio logs.
(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! Created attachment 127046 [details]
bluetoothd log supplemented with performed actions
I performed the steps described by Tanu and created the requested log files.
Created attachment 127047 [details]
pulseaudio log with supplemented actions
Please let me know if you need more information! Forgot to mention, the software versions used to create those logs: Linux 4.7.6 Pulseaudio 9.0 Bluez 5.41 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. 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. 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! 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. (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 :) 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. 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 :)
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? > 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 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 And thanks again for your help Tanu and Brandon! Great that you got it working! I'll add a reference from our bluetooth wiki page's troubleshooting section to this bug. *** Bug 97316 has been marked as a duplicate of this bug. *** It has been reported that BCM4354 is another adapter that requires changing the SCO audio routing. Here's the command that does it: hcitool cmd 0x3F 0x01C 0x01 0x02 0x00 0x01 0x01 Apparently the bluetooth adapter (BCM43438) in Raspberry Pi 3 suffers from this issue too, and the same HCI command works as with BCM4354: hcitool cmd 0x3F 0x01C 0x01 0x02 0x00 0x01 0x01 Hi Tanu, This sounds like a problem we're observing with our BCM43438 device. Just to clarify - does this mean PulseAudio doesn't support SCO audio connections when routed by the BT chipset over a direct audio interface to ALSA (e.g. PCM, I2S, etc)? I.e. does PulseAudio only support SCO audio connection when routed over the HCI through BlueZ? Tia, Paul Yes, SCO audio is only supported over HCI. PulseAudio can of course use alsa devices too, but for things to actually work smoothly, the bluetooth and alsa modules would have to cooperate. Nokia N900 and N9 actually used pulseaudio with such a setup, but that was pretty hairy. (In reply to Tanu Kaskinen from comment #26) > Apparently the bluetooth adapter (BCM43438) in Raspberry Pi 3 suffers from > this issue too, and the same HCI command works as with BCM4354: > > hcitool cmd 0x3F 0x01C 0x01 0x02 0x00 0x01 0x01 I am using raspberry pi zero w. with PA 10.0 and Bluez 5.43. I have manage to use my headset in A2DP mode without problem. But when I change to HSP profile no sound heard or mic record. by using the above hcitool command, I was able to hear sound and record. But my problem is that the sound is very bad and slow like motion. I am suspecting it has something to do with the pi zero w chip(BCM2835) according to this link:https://www.raspberrypi.org/magpi/pi-zero-w/ can anyone help me with relevant hcitool command for this chip? Thanks in advance! Please don't reopen this bug. If you get sound with HSP but it's bad (even worse than the phone-quality sound that HSP anyway has), then that's a different bug. You could try getting in contact with the Raspberry Pi engineers and ask if they themselves have ever made HSP work, and if they have, how. Either they use something else for bluetooth audio than PulseAudio, or they have never actually made bluetooth audio work (otherwise I would expect it to work out of the box on Raspbian, without any hcitool commands). (In reply to Tanu Kaskinen from comment #31) > You could try getting in contact with the Raspberry Pi engineers and ask if > they themselves have ever made HSP work, and if they have, how. Either they > use something else for bluetooth audio than PulseAudio, or they have never > actually made bluetooth audio work (otherwise I would expect it to work out > of the box on Raspbian, without any hcitool commands). Thank you for the reply. I will give that a try |
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.