janvda / balena-pulseaudio

Is a balena application running a pulseaudio server and demonstrating how it can be used for playing and recording audio on a raspberry pi. It also supports bluetooth audio devices.
Eclipse Public License 2.0
6 stars 2 forks source link

can't set card profile of bluetooth device to a2dp_sink #7

Closed janvda closed 5 years ago

janvda commented 5 years ago

This problem is currently seen on my branch no_alpine_pulseaudio_image

The commands:

root@ba7c427:/# pactl list cards
xcb_connection_has_error() returned true
Card #0
        Name: bluez_card.A0_E9_DB_09_CF_FF
        Driver: module-bluez5-device.c
        Owner Module: 28
        Properties:
                device.description = "GEAR4 SPW"
                device.string = "A0:E9:DB:09:CF:FF"
                device.api = "bluez"
                device.class = "sound"
                device.bus = "bluetooth"
                device.form_factor = "headset"
                bluez.path = "/org/bluez/hci0/dev_A0_E9_DB_09_CF_FF"
                bluez.class = "0x240404"
                bluez.alias = "GEAR4 SPW"
                device.icon_name = "audio-headset-bluetooth"
                device.intended_roles = "phone"
        Profiles:
                headset_head_unit: Headset Head Unit (HSP/HFP) (sinks: 1, sources: 1, priority: 30, available: yes)
                a2dp_sink: High Fidelity Playback (A2DP Sink) (sinks: 1, sources: 0, priority: 40, available: no)
                off: Off (sinks: 0, sources: 0, priority: 0, available: yes)
        Active Profile: headset_head_unit
        Ports:
                headset-output: Headset (priority: 0, latency offset: 0 usec)
                        Part of profile(s): headset_head_unit, a2dp_sink
                headset-input: Headset (priority: 0, latency offset: 0 usec)
                        Part of profile(s): headset_head_unit
root@ba7c427:/# pactl set-card-profile 0 a2dp_sink
xcb_connection_has_error() returned true
Failure: Input/Output error
root@ba7c427:/# 

The following is seen in the log file:

02.09.19 08:30:59 (+0200)  pulseaudio-server  I: [pulseaudio] protocol-native.c: Application "pactl" requests card profile change. card = bluez_card.A0_E9_DB_09_CF_FF, profile = a2dp_sink
02.09.19 08:30:59 (+0200)  pulseaudio-server  W: [pulseaudio] module-bluez5-device.c: Refused to switch profile to a2dp_sink: Not connected
02.09.19 08:30:59 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Freed 8 "pactl"
02.09.19 08:30:59 (+0200)  pulseaudio-server  I: [pulseaudio] protocol-native.c: Connection died.
janvda commented 5 years ago

interesting links:

janvda commented 5 years ago

Note that I can set the card profile to off !

Rebooting and executing the following instructions didn't work:

pacmd set-card-profile 2 off
bluetoothctl
disconnect <mac address>
connect <mac address>     (allthough this connect doesn't seem needed as it automatifally reconnectes)
pacmd set-card-profile 3 a2dp_sink   ( card number got increased after disconnect)
janvda commented 5 years ago

Same problem when using branch alpine_pulseaudio_image

Strange enough setting the card profile to off or headset_head_unit works, but changing to a2dp_sink never works as you can see in the log below.

bash-5.0# pactl list cards | grep "Active Profile"
xcb_connection_has_error() returned true
        Active Profile: off
bash-5.0# pacmd set-card-profile 1 headset_head_unit
bash-5.0# pactl list cards | grep "Active Profile"
xcb_connection_has_error() returned true
        Active Profile: headset_head_unit
bash-5.0# pacmd set-card-profile 1 a2dp_sink
Failed to set card profile to 'a2dp_sink'.
bash-5.0# pactl list cards | grep "Active Profile"
xcb_connection_has_error() returned true
        Active Profile: headset_head_unit
bash-5.0# pacmd set-card-profile 1 off
bash-5.0# pactl list cards | grep "Active Profile"
xcb_connection_has_error() returned true
        Active Profile: off
bash-5.0# pacmd set-card-profile 1 a2dp_sink
Failed to set card profile to 'a2dp_sink'.
bash-5.0# pactl list cards | grep "Active Profile"
xcb_connection_has_error() returned true
        Active Profile: off
bash-5.0# pacmd set-card-profile 1 a2dp_sink
Failed to set card profile to 'a2dp_sink'.
bash-5.0# 

The following is logged when trying to set a2dp_sink :

03.09.19 08:49:28 (+0200)  pulseaudio-server  I: [pulseaudio] main.c: Got signal SIGUSR2.
03.09.19 08:49:28 (+0200)  pulseaudio-server  I: [pulseaudio] module.c: Loaded "module-cli-protocol-unix" (index: #30; argument: "").
03.09.19 08:49:29 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Created 7 "UNIX socket client"
03.09.19 08:49:29 (+0200)  pulseaudio-server  W: [pulseaudio] module-bluez5-device.c: Refused to switch profile to a2dp_sink: Not connected
03.09.19 08:49:29 (+0200)  pulseaudio-server  D: [pulseaudio] cli.c: CLI got EOF from user.
03.09.19 08:49:29 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Freed 7 "UNIX socket client"

The following is logged by pulseaudio-server when successfully setting to headset_head_unit:

03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Created 8 "UNIX socket client"
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-bluez5-device.c: Acquiring transport /org/bluez/hci0/dev_A0_E9_DB_09_CF_FF/fd43
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] backend-native.c: doing connect
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] module-bluez5-device.c: Transport /org/bluez/hci0/dev_A0_E9_DB_09_CF_FF/fd43 acquired: fd 17
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] bluez5-util.c: Transport /org/bluez/hci0/dev_A0_E9_DB_09_CF_FF/fd43 state: idle -> playing
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] card.c: Setting card bluez_card.A0_E9_DB_09_CF_FF profile headset_head_unit to availability status yes
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] device-port.c: Setting port headset-output to status yes
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] core-subscribe.c: Dropped redundant event due to change event.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] device-port.c: Setting port headset-input to status yes
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] core-subscribe.c: Dropped redundant event due to change event.
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c: Created sink 2 "bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit" with sample spec s16le 1ch 8000Hz and channel map mono
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     bluetooth.protocol = "headset_head_unit"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.intended_roles = "phone"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.description = "GEAR4 SPW"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.string = "A0:E9:DB:09:CF:FF"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.api = "bluez"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.class = "sound"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.bus = "bluetooth"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.form_factor = "headset"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     bluez.path = "/org/bluez/hci0/dev_A0_E9_DB_09_CF_FF"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     bluez.class = "0x240404"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     bluez.alias = "GEAR4 SPW"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] sink.c:     device.icon_name = "audio-headset-bluetooth"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c: Created source 3 "bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit.monitor" with sample spec s16le 1ch 8000Hz and channel map mono
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.description = "Monitor of GEAR4 SPW"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.class = "monitor"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.string = "A0:E9:DB:09:CF:FF"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.api = "bluez"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.bus = "bluetooth"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.form_factor = "headset"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluez.path = "/org/bluez/hci0/dev_A0_E9_DB_09_CF_FF"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluez.class = "0x240404"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluez.alias = "GEAR4 SPW"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.icon_name = "audio-headset-bluetooth"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.intended_roles = "phone"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c: Created source 4 "bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit" with sample spec s16le 1ch 8000Hz and channel map mono
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluetooth.protocol = "headset_head_unit"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.intended_roles = "phone"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.description = "GEAR4 SPW"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.string = "A0:E9:DB:09:CF:FF"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.api = "bluez"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.class = "sound"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.bus = "bluetooth"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.form_factor = "headset"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluez.path = "/org/bluez/hci0/dev_A0_E9_DB_09_CF_FF"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluez.class = "0x240404"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     bluez.alias = "GEAR4 SPW"
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] source.c:     device.icon_name = "audio-headset-bluetooth"
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [bluetooth] module-bluez5-device.c: IO Thread starting up
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [bluetooth] core-util.c: Failed to acquire real-time scheduling: Not supported
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [bluetooth] module-bluez5-device.c: Transport /org/bluez/hci0/dev_A0_E9_DB_09_CF_FF/fd43 resuming
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [bluetooth] module-bluez5-device.c: Stream properly set up, we're ready to roll!
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] sink.c: bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit: state: INIT -> IDLE
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] source.c: bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit.monitor: state: INIT -> IDLE
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-device-restore.c: Could not set format on sink bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-bluetooth-policy.c: Profile headset_head_unit cannot be selected for loopback
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-suspend-on-idle.c: Sink bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit becomes idle, timeout in 5 seconds.
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] core.c: configured_default_sink: alsa_output.default -> bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] core.c: default_sink: alsa_output.default -> bluez_sink.A0_E9_DB_09_CF_FF.headset_head_unit
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-switch-on-connect.c: No sink inputs to move away.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] source.c: bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit: state: INIT -> IDLE
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-bluetooth-policy.c: Profile headset_head_unit cannot be selected for loopback
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-suspend-on-idle.c: Source bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit becomes idle, timeout in 5 seconds.
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] core.c: configured_default_source: alsa_input.hw_1_0 -> bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] core.c: default_source: alsa_input.hw_1_0 -> bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] core-subscribe.c: Dropped redundant event due to change event.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] module-switch-on-connect.c: No source outputs to move away.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] backend-native.c: RFCOMM >> +VGM=15
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] card.c: Changed profile of card 0 "bluez_card.A0_E9_DB_09_CF_FF" to headset_head_unit
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] module-card-restore.c: Storing card profile for card bluez_card.A0_E9_DB_09_CF_FF.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] core-subscribe.c: Dropped redundant event due to change event.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [pulseaudio] cli.c: CLI got EOF from user.
03.09.19 08:50:39 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Freed 8 "UNIX socket client"
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [avahi-ml] module-zeroconf-publish.c: Successfully created entry group for root@ba7c427: GEAR4 SPW.
03.09.19 08:50:39 (+0200)  pulseaudio-server  D: [avahi-ml] module-zeroconf-publish.c: Successfully created entry group for root@ba7c427: GEAR4 SPW.
03.09.19 08:50:40 (+0200)  pulseaudio-server  I: [avahi-ml] module-zeroconf-publish.c: Successfully established service root@ba7c427: GEAR4 SPW.
03.09.19 08:50:40 (+0200)  pulseaudio-server  I: [avahi-ml] module-zeroconf-publish.c: Successfully established service root@ba7c427: GEAR4 SPW.
03.09.19 08:50:44 (+0200)  pulseaudio-server  I: [pulseaudio] module-suspend-on-idle.c: Source bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit idle for too long, suspending ...
03.09.19 08:50:44 (+0200)  pulseaudio-server  D: [pulseaudio] source.c: bluez_source.A0_E9_DB_09_CF_FF.headset_head_unit: suspend_cause: (none) -> IDLE
03.09.19 08:50:47 (+0200) Warning: Suppressed 17 message(s) due to slow reading
03.09.19 08:50:49 (+0200)  pulseaudio-server  I: [pulseaudio] module-card-restore.c: Synced.
janvda commented 5 years ago

To check

This file doesn't exist in my host OS.

janvda commented 5 years ago

I have switch on/off my bluetooth speaker and after that I succeeded in changing the profile to a2dp_sink

janvda commented 5 years ago

I close the issue. Switching the bluetooth speaker off/on fixed the issue. So it looks like the bluetooth speaker got in an incorrect state causing the issue.

janvda commented 5 years ago

This problem seems to be caused when doing a disconnect in a bluetoothctl session after the speaker has been connected.

So it is related to issue https://github.com/janvda/balena-pulseaudio/issues/5