Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

/usr/share/dbus-1/system-services/org.bluealsa.service doesn't exist #306

Closed
StuartIanNaylor opened this issue Mar 10, 2020 · 5 comments
Closed

/usr/share/dbus-1/system-services/org.bluealsa.service doesn't exist #306

StuartIanNaylor opened this issue Mar 10, 2020 · 5 comments

Comments

@StuartIanNaylor
Copy link

StuartIanNaylor commented Mar 10, 2020 •
edited
Loading

Dunno if its just the wiki or needed but on a make install that service file isn't created.

Should it?

https://github.com/Arkq/bluez-alsa/wiki/Systemd-integration
@StuartIanNaylor
Copy link
Author

StuartIanNaylor commented Mar 11, 2020 •
edited
Loading

PS just thought I would post syslog of boot, nothing to do with above.
Just a question when it sets up as HFP-AG thats bluealsa that is the audiogateway?
Presuming so as makes little sense for this speaker/mic to be so?

Mar 11 00:18:21 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/adapter.c:connected_callback() hci0 device 9B:FD:D5:6E:01:CA connected eir_len 10
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/profile.c:ext_confirm() incoming connect from 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:btd_service_ref() 0x29e840: ref=2
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/profile.c:ext_confirm() HFP Audio Gateway authorizing connection from 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/profile.c:ext_auth() 9B:FD:D5:6E:01:CA authorized to connect to HFP Audio Gateway
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/profile.c:ext_connect() HFP Audio Gateway connected to 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:change_state() 0x29e840: device 9B:FD:D5:6E:01:CA profile HFP Audio Gateway state changed: disconnected -> connecting (0)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.523673248: D: ../../src/bluez.c:1104: Called: org.bluez.Profile1.NewConnection()
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.524574785: D: ../../src/ba-rfcomm.c:1261: Created new RFCOMM thread [ba-rfcomm]: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.524741063: D: ../../src/ba-rfcomm.c:878: Starting RFCOMM loop: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:1104: Called: org.bluez.Profile1.NewConnection()
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.526055118: D: ../../src/sco.c:206: Created SCO dispatcher [ba-sco-dispatch]: hci0
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.526346933: D: ../../src/bluez.c:1029: HFP Audio Gateway (CVSD) configured for device 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.526445248: D: ../../src/ba-transport.c:698: State transition: 0 -> 2
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.526601655: D: ../../src/sco.c:79: Starting SCO dispatcher loop: hci0
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.526921377: D: ../../src/ba-transport.c:972: Created new thread [ba-sco]: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.527652044: D: ../../src/sco.c:247: Starting SCO loop: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:1261: Created new RFCOMM thread [ba-rfcomm]: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:878: Starting RFCOMM loop: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/sco.c:206: Created SCO dispatcher [ba-sco-dispatch]: hci0
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.532776933: D: ../../src/at.c:161: AT message: SET: command:+BRSF, value:023
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.532886063: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:+BRSF, value:2272
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.533083859: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.533250933: D: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 0 -> 2
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:1029: HFP Audio Gateway (CVSD) configured for device 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-transport.c:698: State transition: 0 -> 2
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/sco.c:79: Starting SCO dispatcher loop: hci0
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-transport.c:972: Created new thread [ba-sco]: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/sco.c:247: Starting SCO loop: HFP Audio Gateway (CVSD)
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:change_state() 0x29e840: device 9B:FD:D5:6E:01:CA profile HFP Audio Gateway state changed: connecting -> connected (0)
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/device.c:device_profile_connected() HFP Audio Gateway Success (0)
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:btd_service_ref() 0x29e840: ref=3
Mar 11 00:18:22 raspberrypi bluetoothd[467]: plugins/policy.c:service_cb() Added HFP Audio Gateway reconnect 0
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+BRSF, value:023
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:+BRSF, value:2272
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.541930211: D: ../../src/at.c:161: AT message: TEST: command:+CIND, value:(null)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.542033563: D: ../../src/ba-rfcomm.c:108: 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))
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.542213544: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.542379100: D: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 2 -> 5
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 0 -> 2
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:confirm_cb() AVDTP: incoming connect from 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: TEST: command:+CIND, value:(null)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: 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))
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 2 -> 5
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA: SINK_STATE_DISCONNECTED -> SINK_STATE_CONNECTING
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP: connected signaling channel to 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP imtu=672, omtu=716
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: GET: command:+CIND, value:(null)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:+CIND, value:0,0,0,0,0,0,5
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.550140081: D: ../../src/at.c:161: AT message: GET: command:+CIND, value:(null)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.550182063: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:+CIND, value:0,0,0,0,0,0,5
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.550253729: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.550322063: D: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 5 -> 7
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 5 -> 7
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:session_cb() 
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_parse_cmd() Received DISCOVER_CMD
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+CMER, value:3,0,0,1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.558896970: D: ../../src/at.c:161: AT message: SET: command:+CMER, value:3,0,0,1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.558937729: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.559005618: D: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 7 -> 8
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.559043081: D: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 8 -> 9
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 7 -> 8
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:127: RFCOMM: HFP Audio Gateway (CVSD) state transition: 8 -> 9
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:session_cb() 
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_parse_cmd() Received  GET_CAPABILITIES_CMD
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:endpoint_getcap_ind() Source 0x297480: Get_Capability_Ind
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: TEST: command:+CHLD, value:(null)
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: Unsupported AT message: TEST: command:+CHLD, value:(null)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.563931563: D: ../../src/at.c:161: AT message: TEST: command:+CHLD, value:(null)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.563971951: W: Unsupported AT message: TEST: command:+CHLD, value:(null)
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.564008526: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:session_cb() 
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_parse_cmd() Received  GET_CAPABILITIES_CMD
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:endpoint_getcap_ind() Source 0x293298: Get_Capability_Ind
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+CMEE, value:1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: Unsupported AT message: SET: command:+CMEE, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.570138785: D: ../../src/at.c:161: AT message: SET: command:+CMEE, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.570179285: W: Unsupported AT message: SET: command:+CMEE, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.570215229: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:session_cb() 
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_parse_cmd() Received SET_CONFIGURATION_CMD
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:endpoint_setconf_ind() Source 0x293298: Set_Configuration_Ind
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_ref() 0x2a2370: ref=1
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_ref() 0x2a2a98: ref=1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.573615285: D: ../../src/bluez.c:1322: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.573817859: D: ../../src/bluez.c:780: Called: org.bluez.MediaEndpoint1.SetConfiguration()
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.573942655: D: ../../src/bluez.c:553: Configuration: Selected A2DP SBC bit-pool range: [2, 53]
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_ref() 0x2a2a98: ref=2
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.574258063: D: ../../src/bluez.c:701: A2DP Source (SBC) configured for device 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.574301007: D: ../../src/bluez.c:703: Configuration: channels: 2, sampling: 48000
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.574341063: D: ../../src/ba-transport.c:698: State transition: 0 -> 0
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.574481803: D: ../../src/bluez.c:825: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/Source/3
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.574538563: D: ../../src/bluez.c:854: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/Source/3
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/media.c:media_endpoint_async_call() Calling SetConfiguration: name = :1.4 path = /org/bluez/hci0/A2DP/SBC/Source/2
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.575253988: D: ../../src/at.c:161: AT message: SET: command:+CLIP, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.575301377: W: Unsupported AT message: SET: command:+CLIP, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.575340322: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:1322: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:780: Called: org.bluez.MediaEndpoint1.SetConfiguration()
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:553: Configuration: Selected A2DP SBC bit-pool range: [2, 53]
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:701: A2DP Source (SBC) configured for device 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:703: Configuration: channels: 2, sampling: 48000
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-transport.c:698: State transition: 0 -> 0
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:825: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/Source/3
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:854: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/Source/3
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_ref() 0x2a2370: ref=2
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: IDLE -> CONFIGURED
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_unref() 0x2a2a98: ref=1
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_unref() 0x2a2a98: ref=0
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_free() 0x2a2a98
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_unref() 0x2a2370: ref=1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+CLIP, value:1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: Unsupported AT message: SET: command:+CLIP, value:1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_register_sep() SEP 0x2a2b08 registered: type:0 codec:0 seid:5
Mar 11 00:18:22 raspberrypi bluetoothd[467]: Endpoint registered: sender=:1.4 path=/org/bluez/hci0/A2DP/SBC/Source/3
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avctp.c:avctp_confirm_cb() AVCTP: incoming connect from 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avctp.c:avctp_set_state() AVCTP Connecting
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:session_cb() 
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_parse_cmd() Received OPEN_CMD
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:open_ind() Source 0x293298: Open_Ind
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_ref() 0x2a2370: ref=2
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_ref() 0x2a2df0: ref=1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+CCWA, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.582684229: D: ../../src/at.c:161: AT message: SET: command:+CCWA, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.582726396: W: Unsupported AT message: SET: command:+CCWA, value:1
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.582762674: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: Unsupported AT message: SET: command:+CCWA, value:1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avctp.c:avctp_connect_cb() AVCTP: connected to 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+NREC, value:0
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.590264674: D: ../../src/at.c:161: AT message: SET: command:+NREC, value:0
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.590309711: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:ERROR
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+VGS, value:15
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.596434322: D: ../../src/at.c:161: AT message: SET: command:+VGS, value:15
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.596482470: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avctp.c:init_uinput() AVRCP: uinput initialized for 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avrcp.c:controller_init() 0x29e568 version 0x0000
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:change_state() 0x2988e8: device 9B:FD:D5:6E:01:CA profile audio-avrcp-target state changed: disconnected -> connected (0)
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avrcp.c:target_init() 0x29e530 version 0x0100
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:change_state() 0x298830: device 9B:FD:D5:6E:01:CA profile avrcp-controller state changed: disconnected -> connected (0)
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avctp.c:avctp_set_state() AVCTP Connected
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:confirm_cb() AVDTP: incoming connect from 9B:FD:D5:6E:01:CA
Mar 11 00:18:22 raspberrypi kernel: [   18.606539] input: 9B:FD:D5:6E:01:CA as /devices/virtual/input/input4
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+VGM, value:15
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.602706285: D: ../../src/at.c:161: AT message: SET: command:+VGM, value:15
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.602753377: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:handle_transport_connect() Flushable packets enabled
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:handle_transport_connect() sk 29, omtu 716, send buffer size 81920
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: CONFIGURED -> OPEN
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:change_state() 0x298fb0: device 9B:FD:D5:6E:01:CA profile a2dp-sink state changed: disconnected -> connected (0)
Mar 11 00:18:22 raspberrypi bluetoothd[467]: src/service.c:btd_service_ref() 0x298fb0: ref=3
Mar 11 00:18:22 raspberrypi bluetoothd[467]: plugins/policy.c:service_cb() Added a2dp-sink reconnect 0
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA: SINK_STATE_CONNECTING -> SINK_STATE_CONNECTED
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA/fd0 State=TRANSPORT_STATE_IDLE Playing=0
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_unref() 0x2a2df0: ref=0
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/a2dp.c:setup_free() 0x2a2df0
Mar 11 00:18:22 raspberrypi bluetoothd[467]: profiles/audio/avdtp.c:avdtp_unref() 0x2a2370: ref=1
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+XAPL, value:ABCD-1234-0100,10
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:+XAPL=BlueALSA,6
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.609003470: D: ../../src/at.c:161: AT message: SET: command:+XAPL, value:ABCD-1234-0100,10
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.609084729: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:+XAPL=BlueALSA,6
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.609356322: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/at.c:161: AT message: SET: command:+IPHONEACCEV, value:1,1,9
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.618929988: D: ../../src/at.c:161: AT message: SET: command:+IPHONEACCEV, value:1,1,9
Mar 11 00:18:22 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 18.619436544: D: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi /usr/bin/bluealsa: ../../src/ba-rfcomm.c:108: Sending AT message: RESP: command:(null), value:OK
Mar 11 00:18:22 raspberrypi systemd-udevd[625]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Mar 11 00:18:22 raspberrypi dhcpcd[575]: eth0: fe80::1 is reachable again
Mar 11 00:18:22 raspberrypi dhcpcd[575]: eth0: fe80::1 is reachable again
Mar 11 00:18:23 raspberrypi bluetoothd[467]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU 0x10, company 0x001958 len 0x0001
Mar 11 00:18:23 raspberrypi bluetoothd[467]: profiles/audio/avrcp.c:avrcp_handle_get_capabilities() id=3
Mar 11 00:18:23 raspberrypi bluetoothd[467]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU 0x31, company 0x001958 len 0x0005

pi@raspberrypi:~ $ aplay -D bluealsa:DEV=9B:FD:D5:6E:01:CA,PROFILE=sco pcm1608m.wav
279.409299629: D: ../../../src/asound/bluealsa-pcm.c:671: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Setting constraints
Playing WAVE 'pcm1608m.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
279.412699463: D: ../../../src/asound/bluealsa-pcm.c:368: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Initializing HW
279.415538777: D: ../../../src/asound/bluealsa-pcm.c:394: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: FIFO buffer size: 4096
279.415623166: D: ../../../src/asound/bluealsa-pcm.c:400: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Selected HW buffer: 4 periods x 2000 bytes == 8000 bytes
279.415697722: D: ../../../src/asound/bluealsa-pcm.c:415: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Initializing SW
279.415804796: D: ../../../src/asound/bluealsa-pcm.c:415: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Initializing SW
279.415873111: D: ../../../src/asound/bluealsa-pcm.c:437: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Prepared
279.415934833: D: ../../../src/asound/bluealsa-pcm.c:415: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Initializing SW
279.416387777: D: ../../../src/asound/bluealsa-pcm.c:285: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Starting
279.417211352: D: ../../../src/asound/bluealsa-pcm.c:143: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Starting IO loop: 8
^CAborted by signal Interrupt...
aplay: pcm_write:2053: write error: Interrupted system call
316.348055941: D: ../../../src/asound/bluealsa-pcm.c:327: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Stopping
316.349071200: D: ../../../src/asound/bluealsa-pcm.c:111: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: IO thread cleanup
316.349680589: D: ../../../src/asound/bluealsa-pcm.c:407: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Freeing HW
316.349813089: D: ../../../src/asound/bluealsa-pcm.c:357: /org/bluealsa/hci0/dev_9B_FD_D5_6E_01_CA/hfpag/sink: Closing

Mar 11 00:22:54 raspberrypi /usr/bin/bluealsa: ../../src/bluealsa-dbus.c:172: Called: org.bluealsa.Manager1.GetPCMs()
Mar 11 00:22:54 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 279.401448574: D: ../../src/bluealsa-dbus.c:172: Called: org.bluealsa.Manager1.GetPCMs()
Mar 11 00:22:54 raspberrypi /usr/bin/bluealsa: ../../src/bluealsa-dbus.c:373: Called: org.bluealsa.PCM1.Open()
Mar 11 00:22:54 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 279.414051407: D: ../../src/bluealsa-dbus.c:373: Called: org.bluealsa.PCM1.Open()
Mar 11 00:22:54 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 279.415505463: E: Couldn't establish SCO link: Protocol not supported
Mar 11 00:22:54 raspberrypi /usr/bin/bluealsa: Couldn't establish SCO link: Protocol not supported
Mar 11 00:22:54 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 279.416756963: D: ../../src/ba-transport.c:698: State transition: 2 -> 2
Mar 11 00:22:54 raspberrypi /usr/bin/bluealsa: ../../src/ba-transport.c:698: State transition: 2 -> 2
Mar 11 00:23:31 raspberrypi /usr/bin/bluealsa: ../../src/ba-transport.c:945: Closing PCM: 17
Mar 11 00:23:31 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 316.349976367: D: ../../src/ba-transport.c:945: Closing PCM: 17
Mar 11 00:23:31 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 316.350223978: D: ../../src/a2dp.c:123: PCM read buffer flushed: 2000
Mar 11 00:23:31 raspberrypi bluealsa[365]: /usr/bin/bluealsa: 316.350356181: D: ../../src/sco.c:337: Releasing SCO due to PCM inactivity
Mar 11 00:23:31 raspberrypi /usr/bin/bluealsa: ../../src/a2dp.c:123: PCM read buffer flushed: 2000
Mar 11 00:23:31 raspberrypi /usr/bin/bluealsa: ../../src/sco.c:337: Releasing SCO due to PCM inactivity

If I try and force with just -p hfp-hf

Mar 11 00:50:33 raspberrypi bluetoothd[466]: src/device.c:connect_profiles() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA (all), client :1.16
Mar 11 00:50:33 raspberrypi bluetoothd[466]: profiles/audio/a2dp.c:a2dp_sink_connect() path /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:50:33 raspberrypi bluetoothd[466]: a2dp-sink profile connect failed for 9B:FD:D5:6E:01:CA: Protocol not available
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/device.c:btd_device_set_temporary() temporary 1
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/device.c:device_remove() Removing device /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:change_state() 0x189c830: device 9B:FD:D5:6E:01:CA profile avrcp-controller state changed: disconnected -> unavailable (0)
Mar 11 00:50:44 raspberrypi bluetoothd[466]: profiles/audio/control.c:path_unregister() Unregistered interface org.bluez.MediaControl1 on path /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:btd_service_unref() 0x189c8e8: ref=1
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:btd_service_unref() 0x189c830: ref=1
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:btd_service_unref() 0x189c830: ref=0
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:change_state() 0x189c8e8: device 9B:FD:D5:6E:01:CA profile audio-avrcp-target state changed: disconnected -> unavailable (0)
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:btd_service_unref() 0x189c8e8: ref=0
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:change_state() 0x189cfb0: device 9B:FD:D5:6E:01:CA profile a2dp-sink state changed: disconnected -> unavailable (0)
Mar 11 00:50:44 raspberrypi bluetoothd[466]: profiles/audio/sink.c:sink_unregister() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:btd_service_unref() 0x189cfb0: ref=1
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/service.c:btd_service_unref() 0x189cfb0: ref=0
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/device.c:device_free() 0x189cd48
Mar 11 00:50:44 raspberrypi bluetoothd[466]: src/adapter.c:remove_whitelist_complete() 9B:FD:D5:6E:01:CA removed from kernel whitelist
Mar 11 00:50:44 raspberrypi bluealsa[349]: /usr/bin/bluealsa: 73.367582678: D: ../../src/bluez.c:1365: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved()
Mar 11 00:50:44 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:1365: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved()
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery() sender :1.16
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:update_discovery_filter() 
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:discovery_filter_to_mgmt_cp() 
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:trigger_start_discovery() 
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:cancel_passive_scanning() 
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_timeout() 
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 0
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_complete() status 0x00
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 0
Mar 11 00:50:49 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 9C:8C:6E:B2:E1:CC, rssi -71 flags 0x0004 eir_len 28
Mar 11 00:50:53 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 54:54:54:E0:9B:29, rssi -77 flags 0x0004 eir_len 38
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 9B:FD:D5:6E:01:CA, rssi -53 flags 0x0000 eir_len 19
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/device.c:device_create() dst 9B:FD:D5:6E:01:CA
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/device.c:device_new() address 9B:FD:D5:6E:01:CA
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/device.c:device_set_legacy() legacy 0
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/device.c:device_set_rssi_with_delta() rssi -53
Mar 11 00:50:57 raspberrypi bluetoothd[466]: src/device.c:device_set_class() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA 0x240404
Mar 11 00:50:57 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:1322: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Mar 11 00:50:57 raspberrypi bluealsa[349]: /usr/bin/bluealsa: 86.336845374: D: ../../src/bluez.c:1322: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Mar 11 00:51:00 raspberrypi bluetoothd[466]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 0
Mar 11 00:51:00 raspberrypi bluetoothd[466]: src/adapter.c:trigger_start_discovery() 
Mar 11 00:51:00 raspberrypi bluetoothd[466]: src/adapter.c:cancel_passive_scanning() 
Mar 11 00:51:05 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_timeout() 
Mar 11 00:51:05 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 0
Mar 11 00:51:05 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_complete() status 0x00
Mar 11 00:51:05 raspberrypi bluetoothd[466]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 0
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 54:54:54:E0:9B:29, rssi -75 flags 0x0004 eir_len 28
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 9C:8C:6E:B2:E1:CC, rssi -72 flags 0x0004 eir_len 28
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/device.c:btd_device_set_temporary() temporary 0
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/agent.c:agent_ref() 0x189f3d0: ref=2
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/device.c:bonding_request_new() Requesting bonding for 9B:FD:D5:6E:01:CA
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/agent.c:agent_ref() 0x189f3d0: ref=3
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/agent.c:agent_unref() 0x189f3d0: ref=2
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:suspend_discovery() 
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:adapter_bonding_attempt() hci0 bdaddr 9B:FD:D5:6E:01:CA type 0 io_cap 0x04
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:add_whitelist_complete() 9B:FD:D5:6E:01:CA added to kernel whitelist
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:suspend_discovery_complete() status 0x00
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 0
Mar 11 00:51:06 raspberrypi bluetoothd[466]: src/adapter.c:connected_callback() hci0 device 9B:FD:D5:6E:01:CA connected eir_len 10
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:new_link_key_callback() hci0 new key for 9B:FD:D5:6E:01:CA type 4 pin_len 0 store_hint 1
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/device.c:device_set_bonded() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/device.c:device_bonding_complete() bonding 0x189cbe0 status 0x00
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/device.c:device_bonding_complete() Proceeding with service discovery
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/agent.c:agent_unref() 0x189f3d0: ref=1
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:resume_discovery() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:trigger_start_discovery() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:cancel_passive_scanning() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:pair_device_complete() Success (0x00)
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 9B:FD:D5:6E:01:CA type 0 status 0x0
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/device.c:device_bonding_complete() bonding (nil) status 0x00
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:resume_discovery() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:trigger_start_discovery() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/adapter.c:cancel_passive_scanning() 
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/device.c:device_probe_profiles() Probing profiles for device 9B:FD:D5:6E:01:CA
Mar 11 00:51:07 raspberrypi bluetoothd[466]: profiles/audio/avrcp.c:avrcp_controller_probe() path /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:51:07 raspberrypi bluetoothd[466]: profiles/audio/control.c:control_init() Registered interface org.bluez.MediaControl1 on path /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/service.c:btd_service_ref() 0x189cfb0: ref=2
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/service.c:change_state() 0x189cfb0: device 9B:FD:D5:6E:01:CA profile avrcp-controller state changed: unavailable -> disconnected (0)
Mar 11 00:51:07 raspberrypi bluealsa[349]: /usr/bin/bluealsa: 95.658909609: D: ../../src/bluez.c:1322: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Mar 11 00:51:07 raspberrypi bluetoothd[466]: profiles/audio/a2dp.c:a2dp_sink_probe() path /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:51:07 raspberrypi bluetoothd[466]: profiles/audio/sink.c:sink_init() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/service.c:btd_service_ref() 0x189a618: ref=2
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/service.c:change_state() 0x189a618: device 9B:FD:D5:6E:01:CA profile a2dp-sink state changed: unavailable -> disconnected (0)
Mar 11 00:51:07 raspberrypi bluetoothd[466]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA err 0
Mar 11 00:51:07 raspberrypi /usr/bin/bluealsa: ../../src/bluez.c:1322: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/adapter.c:dev_disconnected() Device 9B:FD:D5:6E:01:CA disconnected, reason 2
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/adapter.c:adapter_remove_connection() 
Mar 11 00:51:11 raspberrypi bluetoothd[466]: plugins/policy.c:disconnect_cb() reason 2
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 9B:FD:D5:6E:01:CA type 0 status 0xe
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/device.c:device_bonding_failed() status 14
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/adapter.c:resume_discovery() 
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/adapter.c:trigger_start_discovery() 
Mar 11 00:51:11 raspberrypi bluetoothd[466]: src/adapter.c:cancel_passive_scanning() 
Mar 11 00:51:16 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_timeout() 
Mar 11 00:51:16 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_timeout() adapter->current_discovery_filter == 0
Mar 11 00:51:16 raspberrypi bluetoothd[466]: src/adapter.c:start_discovery_complete() status 0x00
Mar 11 00:51:16 raspberrypi bluetoothd[466]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1 method 0
Mar 11 00:51:16 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 9C:8C:6E:B2:E1:CC, rssi -81 flags 0x0004 eir_len 28
Mar 11 00:51:16 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 54:54:54:E0:9B:29, rssi -78 flags 0x0004 eir_len 38
Mar 11 00:51:18 raspberrypi bluetoothd[466]: src/device.c:btd_device_set_trusted() trusted 1
Mar 11 00:51:24 raspberrypi bluetoothd[466]: src/adapter.c:device_found_callback() hci0 addr 9B:FD:D5:6E:01:CA, rssi -61 flags 0x0000 eir_len 19
Mar 11 00:51:24 raspberrypi bluetoothd[466]: src/device.c:device_set_legacy() legacy 0
Mar 11 00:51:24 raspberrypi bluetoothd[466]: src/device.c:device_set_rssi_with_delta() rssi -61 delta 8
Mar 11 00:51:25 raspberrypi bluetoothd[466]: src/device.c:connect_profiles() /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA (all), client :1.16
Mar 11 00:51:25 raspberrypi bluetoothd[466]: profiles/audio/a2dp.c:a2dp_sink_connect() path /org/bluez/hci0/dev_9B_FD_D5_6E_01_CA
Mar 11 00:51:25 raspberrypi bluetoothd[466]: a2dp-sink profile connect failed for 9B:FD:D5:6E:01:CA: Protocol not available
Mar 11 00:51:27 raspberrypi bluetoothd[466]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method 0
Mar 11 00:51:27 raspberrypi bluetoothd[466]: src/adapter.c:trigger_start_discovery() 
Mar 11 00:51:27 raspberrypi bluetoothd[466]: src/adapter.c:cancel_passive_scanning() 
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/agent.c:agent_disconnect() Agent :1.16 disconnected
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/agent.c:agent_destroy() agent :1.16
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/agent.c:agent_unref() 0x189f3d0: ref=0
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/adapter.c:discovery_disconnect() owner :1.16
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/adapter.c:discovery_remove() owner :1.16
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/device.c:device_set_rssi_with_delta() rssi 0
Mar 11 00:51:30 raspberrypi bluetoothd[466]: src/adapter.c:trigger_passive_scanning()

@borine
Copy link
Collaborator

borine commented Mar 11, 2020

From the wiki page

To manage bluealsa with systemd, create the following two files:
/etc/systemd/system/bluealsa.service
/usr/share/dbus-1/system-services/org.bluealsa.service

So, no, make install does not create them for you.

@StuartIanNaylor
Copy link
Author

StuartIanNaylor commented Mar 11, 2020 •
edited
Loading

Yeah it was /usr/share/dbus-1/system-services/org.bluealsa.service I notice I was missing and just thought I would ask as things seem much the same even when added a2dp works without and wasn't sure if required.
I had copied the service from arch AUR which is absent of the /usr/share/dbus-1/system-services/org.bluealsa.service

[Unit]
Description=BluezAlsa proxy
Requires=bluetooth.service
After=bluetooth.service

[Service]
Type=simple
EnvironmentFile=/etc/conf.d/bluealsa
#User=bluealsa
#Group=audio
ExecStart=/usr/bin/bluealsa $BLUEALSA_CONF

[Install]
WantedBy=multi-user.target

But using the wiki version now but both seem to work.

Apols on the length of the logs but thought will just give you the lot as wouldn't know what is a normal AT operation or error.
My question on the HFP-AG is that bluealsa side or device side? I expected to see HFP-HF in there but I am thinking of the device and guess bluealsa needs to be the HFP-AG device that connects a HFP-HF device but didn't see that in the logs, just HFP-AG?

[Edit] checked on windows and that seems to setup up as HFP-AG also the ASUS USB-BT400
turned up, BT5 and another cheapo 4.2 still to arrive and Bt5 speaker/mic that might be dual a2dp as if so then things are rosy.
I will give em a go and see what occurs

@StuartIanNaylor
Copy link
Author

Just tried a new clean install of arch this time with the asus bt dongle.

Same but did follow https://github.com/Arkq/bluez-alsa/wiki/Systemd-integration to the T

@StuartIanNaylor
Copy link
Author

Next BT 5 :)

@StuartIanNaylor StuartIanNaylor mentioned this issue Mar 12, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@StuartIanNaylor @borine