I have a Pi 3b+ with the latest headless Stretch release. The Pis internal bluetooth is deactivated, as I need its Pins for another device that is plugged to them. Instead I am using an Edimax Wifi/Bluetooth-USB-Dongle.
On the system I manually compiled and updated bluez/bluetoothd to v5.50 and bluealsa to version 1.3.1.
When the system is booting everything looks fine in the logs. journalctl | grep blue returns:
Feb 12 13:24:54 raspberrypi kernel: bluetooth hci0: Direct firmware load for rtl_bt/rtl8723b_config.bin failed with error -2
Feb 12 13:24:55 raspberrypi bluetoothd[336]: Bluetooth daemon 5.50
Feb 12 13:24:55 raspberrypi bluetoothd[336]: Starting SDP server
Feb 12 13:24:55 raspberrypi systemd[1]: Started Raspberry Pi bluetooth helper.
Feb 12 13:24:55 raspberrypi bluetoothd[336]: Bluetooth management interface 1.14 initialized
Feb 12 13:24:55 raspberrypi bluetoothd[336]: Failed to set privacy: Rejected (0x0b)
Feb 12 13:24:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:571: Starting controller loop
Feb 12 13:24:56 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:675: Registering endpoint: /A2DP/SBC/Source/1
Feb 12 13:24:56 raspberrypi bluetoothd[336]: Endpoint registered: sender=:1.6 path=/A2DP/SBC/Source/1
Feb 12 13:24:56 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:910: Registering profile: /HSP/AudioGateway
Feb 12 13:24:56 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:910: Registering profile: /HFP/AudioGateway
Feb 12 13:24:56 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/main.c:302: Starting main dispatching loop
As far as I was able to find out the line Feb 12 13:24:55 raspberrypi bluetoothd[336]: Failed to set privacy: Rejected (0x0b) can be ignored.
I am able to connect to the device using
sudo bluetoothctl
scan on
pair XYZ
trust XYZ
connect XYZ
The device info looks like it correctly detected the device:
Device 00:23:01:04:95:CC (public)
Name: Voice-BoomBox
Alias: Voice-BoomBox
Class: 0x00240404
Icon: audio-card
Paired: yes
Trusted: yes
Blocked: no
Connected: yes
LegacyPairing: no
UUID: Headset (00001108-0000-1000-8000-00805f9b34fb)
UUID: Audio Sink (0000110b-0000-1000-8000-00805f9b34fb)
UUID: Advanced Audio Distribu.. (0000110d-0000-1000-8000-00805f9b34fb)
UUID: Handsfree (0000111e-0000-1000-8000-00805f9b34fb)
Afterwards I still cannot find anything suspicious in the logs:
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:857: Profile method call: org.bluez.Profile1.NewConnection()
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:688: State transition: 0 -> 2
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:104: Created new IO thread: HFP Audio Gateway
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:797: HFP Audio Gateway configured for device 00:23:01:04:95:CC
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:688: State transition: 0 -> 2
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:104: Created new IO thread: HFP Audio Gateway
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/io.c:1195: Starting IO loop: HFP Audio Gateway
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:573: Starting RFCOMM loop: HFP Audio Gateway
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: SET: command:+BRSF, value:59
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:+BRSF, value:992
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:OK
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:114: HFP state transition: 0 -> 2
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: TEST: command:+CIND, value:(null)
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:+CIND, value:("call",(0,1)),("callsetup",(0-3)),("service",(0-1)),("signal",(0-5)),("roam",(0-1)),("battchg",(0-5)),("callheld",(0-2))
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:OK
Feb 12 13:26:28 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:114: HFP state transition: 2 -> 5
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: GET: command:+CIND, value:(null)
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:+CIND, value:0,0,0,0,0,0,0
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:OK
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:114: HFP state transition: 5 -> 7
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: SET: command:+CMER, value:3, 0, 0, 1
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:OK
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:114: HFP state transition: 7 -> 8
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:114: HFP state transition: 8 -> 9
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:114: HFP state transition: 9 -> 13
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: SET: command:+VGS, value:15
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:OK
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: GET: command:+BTRH, value:(null)
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:OK
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: CMD: command:+CLCC, value:(null)
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: Unsupported AT message: CMD: command:+CLCC, value:(null)
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:ERROR
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/at.c:160: AT message: SET: command:+CSRSF, value:0,0,0,1,0,0,0
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: Unsupported AT message: SET: command:+CSRSF, value:0,0,0,1,0,0,0
Feb 12 13:26:29 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/rfcomm.c:96: Sending AT message: RESP: command:(null), value:ERROR
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:608: Endpoint method call: org.bluez.MediaEndpoint1.SelectConfiguration()
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:608: Endpoint method call: org.bluez.MediaEndpoint1.SetConfiguration()
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:540: A2DP Source (SBC) configured for device 00:23:01:04:95:CC
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:542: Configuration: channels: 2, sampling: 48000
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:688: State transition: 0 -> 0
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/bluez.c:675: Registering endpoint: /A2DP/SBC/Source/2
Feb 12 13:26:30 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:26:30 raspberrypi bluetoothd[336]: Endpoint registered: sender=:1.6 path=/A2DP/SBC/Source/2
When playing sound via aplay (aplay -D bluealsa:HCI=hci0,DEV=00:23:01:04:95:CC,PROFILE=a2dp test16.wav) the sound plays correctly.
Now I want to record sound via arecord. I tried:
arecord -D bluealsa:HCI=hci0,DEV=00:23:01:04:95:CC,PROFILE=sco record.wav
arecord -f S16_LE -D bluealsa:HCI=hci0,DEV=00:23:01:04:95:CC,PROFILE=sco record.wav
sudo arecord -f cd -D bluealsa:HCI=hci0,DEV=00:23:01:04:95:CC,PROFILE=sco record.wav
But none of it recorded anything. But still there is nothing suspicious in my logs.
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:638: Received new connection: 17
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:651: New client accepted: 17
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:353: PCM requested for 00:23:01:04:95:CC type 2 stream 1
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:688: State transition: 2 -> 2
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:27:42 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:948: New SCO link: 18 (MTU: R:48 W:48)
Feb 12 13:27:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:455: PCM close for 00:23:01:04:95:CC type 2 stream 1
Feb 12 13:27:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:981: Closing PCM: 19
Feb 12 13:27:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Feb 12 13:27:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/transport.c:958: Closing SCO: 18
Feb 12 13:27:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:605: Client closed connection: 17
Feb 12 13:27:55 raspberrypi bluealsa[373]: /usr/bin/bluealsa: ../../src/ctl.c:675: +-+-
Does someone have any hints what goes wrong here?
In case anyone steps above my question in the future, here is how my problem got solved:
For bluetooth I was using an Edimax BT/WiFi-Dongle (EW-7611ULB). Edimax itself say that you need to compile the firmware for newer Linux Kernels (>v3.19). They also provide a tutorial for it here. I followed those steps and afterwards also inspected my jornal/logs. There everything looked good and as playing audio was working when using the dongle, I assumed, that the firmware was working correctly.
I really got out of ideas and already was thinking about giving pulseaudio a try, but then I used another BT-dongle that was lying arround (something from LogiLink) and instantly recording voice was possible.