search

arkq / bluez-alsa

Bluetooth Audio ALSA Backend
MIT License
862 stars 189 forks source link

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

Closed tyzbit closed 3 years ago

tyzbit commented 4 years ago

I hate to open multiple issues at once, but I'm at the limit of what I can do to troubleshoot.

As part of troubleshooting for issue https://github.com/Arkq/bluez-alsa/issues/337, I upgraded to Ubuntu 20.04. Now when I try to connect my headset, it logs this error and sco profiles do not work to play sounds at all using aplay:

May 29 19:22:48 sen bluetoothd[118979]: Unable to get connect data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)

I enabled debug mode in bluealsa, and this is what it logged when it connected:

Expand 
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:1121: Called: org.bluez.Profile1.NewConnection()
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:1262: Created new RFCOMM thread [ba-rfcomm]: HFP Audio Gateway
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:880: Starting RFCOMM loop: HFP Audio Gateway
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: sco.c:202: Created SCO dispatcher [ba-sco-dispatch]: hci0
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:1044: HFP Audio Gateway configured for device 00:16:94:47:B6:F4
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-transport.c:701: State transition: 0 -> 2
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: sco.c:79: Starting SCO dispatcher loop: hci0
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-transport.c:975: Created new thread [ba-sco]: HFP Audio Gateway
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: sco.c:243: Starting SCO loop: HFP Audio Gateway
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+BRSF, value:155
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:+BRSF, value:2784
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:126: RFCOMM: HFP Audio Gateway state transition: 0 -> 2
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+BAC, value:1,2
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:126: RFCOMM: HFP Audio Gateway state transition: 2 -> 3
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:1346: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:1424: Adding new Stream End-Point: 00:16:94:47:B6:F4: SBC
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: TEST: command:+CIND, value:(null)
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:+CIND, value:("service",(0-1)),("call",(0,1)),("callsetup",(0-3)),("callheld",(0-2)),("signal",(0-5)),("roam",(0-1)),("battchg",(0-5))
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:126: RFCOMM: HFP Audio Gateway state transition: 3 -> 5
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:796: Called: org.bluez.MediaEndpoint1.SelectConfiguration()
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: GET: command:+CIND, value:(null)
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:+CIND, value:0,0,0,0,0,0,5
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:126: RFCOMM: HFP Audio Gateway state transition: 5 -> 7
May 29 19:22:48 sen bluetoothd[118979]: Unable to get connect data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:1346: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:796: Called: org.bluez.MediaEndpoint1.SetConfiguration()
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:565: Configuration: Selected A2DP SBC bit-pool range: [2, 53]
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:715: A2DP Source (SBC) configured for device 00:16:94:47:B6:F4
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:718: Configuration: channels: 2, sampling: 48000
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-transport.c:701: State transition: 0 -> 0
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:842: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/Source/3
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: bluez.c:871: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/Source/3
May 29 19:22:48 sen bluetoothd[118979]: Endpoint registered: sender=:1.864 path=/org/bluez/hci0/A2DP/SBC/Source/3
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+CMER, value:3, 0, 0, 1
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:126: RFCOMM: HFP Audio Gateway state transition: 7 -> 8
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:126: RFCOMM: HFP Audio Gateway state transition: 8 -> 9
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+BIA, value:0,1,1,1,0,0,0
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+XAPL, value:1395-000b-1110,3
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:+XAPL=BlueALSA,6
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+IPHONEACCEV, value:1,1,9
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+IPHONEACCEV, value:1,2,0
May 29 19:22:48 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK
May 29 19:22:51 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:1085: RFCOMM poll timeout
May 29 19:22:51 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:724: RFCOMM: HFP Audio Gateway setting codec: mSBC
May 29 19:22:51 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:+BCS, value:2
May 29 19:22:51 sen bluealsa[119196]: /usr/bin/bluealsa: D: at.c:161: AT message: SET: command:+BCS, value:2
May 29 19:22:51 sen bluealsa[119196]: /usr/bin/bluealsa: D: ba-rfcomm.c:107: Sending AT message: RESP: command:(null), value:OK

Curiously, so long as I run bluealsa either with no profiles explicitly selected or with a2dp selected, aplay is able to play .wavs just fine. It just seems like the Headset Voice Gateway profile has stopped working.

Hopefully if this issue gets resolved then the other issue will be resolved shortly as well.

arkq commented 4 years ago

If your BT transceiver is connected via USB, please configure bluez-alsa without mSBC support. HFP mSBC codec is highly experimental. Even if your SoC uses UART connected, I recommend disabling mSBC. For more information read this issue #268

tyzbit commented 4 years ago

I have recompiled bluez-alsa without msbc support with the same results. I also recompiled many of the supporting libraries like ldacBT without any change.

borine commented 4 years ago

In #337, you are using HFP ("hands free") not HSP ("Headset") profile. The error message you report here is for the HSP-AG profile. What happens when you start bluealsa as:

sudo bluealsa -p a2dp-source -p hfp-ag

That should give you all you need to fully interact with your headphone speakers and microphone. (Note you do not need HFP-HF as that is for implementing a handsfree unit, not for connecting to one).

If that stiil fails, try removing the device with bluetoothctl, then repeat the pairing process, with the above bluealsa command running while you pair.

tyzbit commented 4 years ago

When I use the hfp-ag profile (with or without the a2dp-source profile), the error message goes away but there is still no audio. It makes a small amount of noise like it's connected when I play the file but it is just silence. I have tried unpairing and repairing the headset using both bluetoothctl and GNOME's bluetooth manager.

tyzbit commented 4 years ago

I have discovered that by upgrading Ubuntu, I've upgraded Alsa to 1.1.7 (I was on a previous version, not sure which). I confirmed the correct files are in /etc/alsa/conf.d/. I'm not sure if I should pursue downgrading ALSA or upgrading and building from source.

arkq commented 4 years ago

Please, configure bluez-alsa with --enable-hcitop, then when you launch aplay, run hcitop in a separate terminal and check whether there is TX/s and RX/s activity. There might be a case where your headset requires RFCOMM configuration prior to transmuting/receiving audio. If there is TX but no RX, then try to connect headset with HSP (not HFP) - bluealsa -p hsp-ag. This profile does not require special RFCOMM "activation" before playing audio. If there is RX and TX (with HFP), please use bluealsa-aplay --profile-sco 00:00:00:00:00:00 to confirm whether there is an audible incoming audio from headset microphone. If there is mic audio, but you can not hear sound send by aplay, there might be a problem with SCO....

In order to be conformant with HFP specification, audio gateway is obliged to notify headset about incoming call. It complicates things a little bit... but can be done with bluealsa-rfcomm tool. I will guide you what command shall be send if you confirm that with HFP profile there is TX but no RX(I will have to look into the HFP specification, because I don't remember the exact command :D).

Also there is a possibility, that your Bluetooth chip is configured in a wrong way - it sent/read audio to chip's PCM interface, but bluealsa requires audio on HCI interface. Bluealsa configures this only for Broadcom chips, but there are other chips with different manufacturer ID, but require the same treatment.

tyzbit commented 4 years ago

hcitop results:

bluealsa-aplay activates the headset but no actual audio is heard. hcitop shows ~0 RX and TX*

*(by 0 RX/TX I mean 0 most of the time but short bursts of bytes in the dozens or hundreds of bytes range)

borine commented 4 years ago

@tyzbit if you are still working on this, please can you post the output of:

hciconfig -a revision

and

lsusb

There are a number of possible reasons why the sco RX count is 0, and you may be experiencing issues similar to #347, in particular see comments https://github.com/Arkq/bluez-alsa/issues/347#issuecomment-670583184, https://github.com/Arkq/bluez-alsa/issues/347#issuecomment-670644240, and https://github.com/Arkq/bluez-alsa/issues/347#issuecomment-673041677

tyzbit commented 4 years ago
hciconfig output 
~|⇒  hciconfig -a revision
hci0:   Type: Primary  Bus: USB
    BD Address: 14:F6:D8:46:C6:97  ACL MTU: 1021:4  SCO MTU: 96:6
    UP RUNNING 
    RX bytes:35221 acl:54 sco:0 events:4146 errors:0
    TX bytes:1193545 acl:532 sco:0 commands:3494 errors:0
    Features: 0xbf 0xfe 0x0f 0xfe 0xdb 0xff 0x7b 0x87
    Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3 
    Link policy: RSWITCH SNIFF 
    Link mode: SLAVE ACCEPT 
    Name: 'sen'
    Class: 0x1c010c
    Service Classes: Rendering, Capturing, Object Transfer
    Device Class: Computer, Laptop
    HCI Version: 5.1 (0xa)  Revision: 0x100
    LMP Version: 5.1 (0xa)  Subversion: 0x100
    Manufacturer: Intel Corp. (2)
lsusb output 
~|⇒  lsusb
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 8087:0029 Intel Corp. 
Bus 001 Device 002: ID 0c45:6723 Microdia Integrated_Webcam_HD
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

I have disabled power saving before, but I'm not sure I modified usbcore.autosuspend.

borine commented 4 years ago

Bus 001 Device 003: ID 8087:0029 Intel Corp. Bus 001 Device 002: ID 0c45:6723 Microdia Integrated_Webcam_HD Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

Although these components are not the same as mine, the USB tree is the same - webcam and bluetooth sharing the same bus. So it is possible that the usb autosuspend issue is also affecting your laptop. However, I can't see how upgrading the OS would have changed that, so i'm not confident that this is the issue. I would still give it a try, but watch out for other side effects as the change will disable autosuspend on all usb devices.

Full support for your intel bt adapter was first added in Linux 5.0 - what kernel were you using in your previous OS installation?

tyzbit commented 4 years ago

I'm not sure, though I still have 4.15 on my system so it could have been that. Here's my current uname:

Linux sen 5.4.0-42-generic #46-Ubuntu SMP Fri Jul 10 00:24:02 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

I just checked /etc/default/grub and found usbcore.autosuspend=-1 is there already so I must have tried it already while troubleshooting.

borine commented 4 years ago

It seems Ubuntu kernels have the Intel USB BT patches back-ported to 4.15, so that does not explain the different behavior you see between Ubuntu 18.04 and 20.04. I'll keep looking for other possible causes,

mirh commented 3 years ago

https://bugzilla.kernel.org/show_bug.cgi?id=204629 According to out lord and savior pali, this might have been addressed in bluez 5.55.

borine commented 3 years ago

This issue has been idle for some time, and it is believed that many USB related SCO issues have been fixed in recent kernels. Please see #400 for latest status on USB BT as it impacts to bluealsa.

senthamil333 commented 3 years ago

Sep 02 11:15:55 kali bluetoothd[6658]: sap-server: Operation not permitted (1) Sep 02 11:15:55 kali bluetoothd[6658]: Endpoint registered: sender=:1.30 path=/MediaEndpoint/A2DPSink/sbc Sep 02 11:15:55 kali bluetoothd[6658]: Endpoint registered: sender=:1.30 path=/MediaEndpoint/A2DPSource/sbc Sep 02 11:16:18 kali bluetoothd[6658]: profiles/audio/a2dp.c:load_remote_sep() Unable to load LastUsed: lseid 4 not found Sep 02 11:16:18 kali bluetoothd[6658]: /org/bluez/hci1/dev_1C_52_16_14_2B_71/sep1/fd0: fd(75) ready Sep 02 11:32:31 kali bluetoothd[6658]: src/profile.c:ext_io_disconnected() Unable to get io data for Headset Voice gateway: getpeername: Transport endpo…nnected (107) Sep 02 11:32:54 kali bluetoothd[6658]: src/profile.c:ext_io_disconnected() Unable to get io data for Headset Voice gateway: getpeername: Transport endpo…nnected (107) Sep 02 11:35:26 kali bluetoothd[6658]: /org/bluez/hci1/dev_1C_52_16_14_2B_71/sep1/fd1: fd(72) ready Sep 02 12:02:05 kali bluetoothd[6658]: src/profile.c:ext_io_disconnected() Unable to get io data for Headset Voice gateway: getpeername: Transport endpo…nnected (107) Sep 02 14:12:38 kali bluetoothd[6658]: /org/bluez/hci1/dev_1C_52_16_14_2B_71/sep1/fd2: fd(72) ready Hint: Some lines were ellipsized, use -l to show in full. how to fix it someone help me

TGLuong commented 11 months ago 
Nov 30 18:04:35 raspberrypi bluetoothd[654]: Endpoint registered: sender=:1.31 path=/MediaEndpoint/A2DPSink/sbc
Nov 30 18:04:35 raspberrypi bluetoothd[654]: Endpoint registered: sender=:1.31 path=/MediaEndpoint/A2DPSource/sbc
Nov 30 18:04:35 raspberrypi bluetoothd[654]: src/profile.c:ext_start_servers() RFCOMM server failed for Headset Voice gateway: rfcomm_bind: Address already in use (98)
Nov 30 18:04:35 raspberrypi bluetoothd[654]: src/profile.c:ext_start_servers() RFCOMM server failed for Headset Voice gateway: rfcomm_bind: Address already in use (98)
Nov 30 18:04:39 raspberrypi bluetoothd[654]: src/adv_monitor.c:btd_adv_monitor_power_down() Unexpected NULL btd_adv_monitor_manager object upon power down
Dec 01 04:19:35 raspberrypi bluetoothd[654]: /org/bluez/hci0/dev_F3_DA_EC_7B_74_C9/fd0: fd(47) ready
Dec 01 04:47:45 raspberrypi bluetoothd[654]: src/profile.c:ext_io_disconnected() Unable to get io data for Hands-Free Voice gateway: getpeername: Transport endpoint is not connected (107)
Dec 01 04:56:57 raspberrypi bluetoothd[654]: /org/bluez/hci0/dev_F3_DA_EC_7B_74_C9/fd1: fd(47) ready
Dec 01 05:02:13 raspberrypi bluetoothd[654]: src/profile.c:ext_io_disconnected() Unable to get io data for Hands-Free Voice gateway: getpeername: Transport endpoint is not connected (107)
Dec 01 07:10:04 raspberrypi bluetoothd[654]: /org/bluez/hci0/dev_F3_DA_EC_7B_74_C9/fd2: fd(47) ready

I have same probleam with usb BT UB500, but the on board BT work well with sco profile

borine commented 11 months ago

The problem with posting to closed issues is that we have no idea what versions of BlueALSA or any other relevant software you are using. It is better to open a new issue from where you can reference this closed one if you wish. A new issue would have given you a template showing you exactly what information we need to be able to help you.

However, I have done some research- it appears that your BT UB500 is a TP-Link device - is that correct? If so then it is using the Realtek RTL8761BU chipset, which is the same as the one I am using on my own laptop. For me SCO with this chipset works fine with the latest BlueALSA code, but has problems with BlueALSA release 4.1.1 and earlier. The errors in the log you posted suggest that you are also having firmware, and possibly driver problems.

TGLuong commented 11 months ago

i found that with BlueALSA 4.1.1, i enable --enable-rfcomm --enable-rfcomm feature, and SCO work well