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.

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

MPD server with bluez-alsa headless #74

Closed
drehren opened this issue Dec 30, 2017 · 5 comments
Closed

MPD server with bluez-alsa headless #74

drehren opened this issue Dec 30, 2017 · 5 comments

Comments

@drehren
Copy link

drehren commented Dec 30, 2017

Hi!
I currently have an Arch-powered RPi B as my MPD server, and I was using pulseaudio to get audio to Bluetooth speakers. I didn't like that setup very much, but managed to make it work somehow.
Today I saw this implementation and decided to give it a try.. and it worked! It also managed to drop the high cpu usage I had with the pulseaudio setup.
But there is one problem. If I power off the speaker, and then I power it on while MPD is playing music, then there will be no music output until MPD changes to the next song.

These are the logs when I power off the speaker:

bluealsa[11464]: /usr/bin/bluealsa: bluez.c:609: Endpoint method call: org.bluez.MediaEndpoint1.ClearConfiguration()
bluealsa[11464]: /usr/bin/bluealsa: transport.c:349: Freeing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: transport.c:839: Releasing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: Couldn't release transport: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Release" with signature "" on interface "org.bluez.MediaTransport1" doesn't exist
bluealsa[11464]: /usr/bin/bluealsa: transport.c:994: Exiting IO thread
bluealsa[11464]: /usr/bin/bluealsa: transport.c:839: Releasing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: Couldn't release transport: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Release" with signature "" on interface "org.bluez.MediaTransport1" doesn't exist
bluealsa[11464]: /usr/bin/bluealsa: transport.c:965: Cleaning PCM FIFO: /var/run/bluealsa/hci0-00:0C:8A:70:E8:7D-1-0
bluealsa[11464]: /usr/bin/bluealsa: transport.c:972: Closing PCM: 12
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:399: PCM close for 00:0C:8A:70:E8:7D type 1 stream 0
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:522: Client closed connection: 10
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-

When I power it on, the following appears:

bluealsa[11464]: /usr/bin/bluealsa: bluez.c:609: Endpoint method call: org.bluez.MediaEndpoint1.SetConfiguration()
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:541: A2DP Source (SBC) configured for device 00:0C:8A:70:E8:7D
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:543: Configuration: channels: 2, sampling: 44100
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 0 -> 0
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/MPEG24/Source/1
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/MPEG24/Sink/1
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/SBC/Source/2
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/SBC/Sink/1
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 0 -> 1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:813: New transport: 13 (MTU: R:672 W:895)
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 1 -> 2
bluealsa[11464]: /usr/bin/bluealsa: transport.c:105: Created new IO thread: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: io.c:55: Opening FIFO for reading: (null)
bluealsa[11464]: /usr/bin/bluealsa: Couldn't open FIFO: Bad address
bluealsa[11464]: /usr/bin/bluealsa: transport.c:839: Releasing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: transport.c:867: Closing BT: 13
bluealsa[11464]: /usr/bin/bluealsa: transport.c:994: Exiting IO thread
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 2 -> 0

And when the next song plays, the following is logged:

bluealsa[11464]: /usr/bin/bluealsa: ctl.c:551: New client accepted: 10
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:324: PCM requested for 00:0C:8A:70:E8:7D type 1 stream 0
bluealsa[11464]: /usr/bin/bluealsa: transport.c:813: New transport: 14 (MTU: R:672 W:895)
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 0 -> 2
bluealsa[11464]: /usr/bin/bluealsa: transport.c:105: Created new IO thread: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: io.c:55: Opening FIFO for reading: /var/run/bluealsa/hci0-00:0C:8A:70:E8:7D-1-0
bluealsa[11464]: /usr/bin/bluealsa: io.c:409: Starting IO loop: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 2 -> 2
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-

Thanks you for any help.

@arkq
Copy link
Owner

arkq commented Dec 31, 2017

Hi,

I'm not sure, if it will be possible what you are trying to achieve. ALSA is not PulseAudio. It is a simple interface to the underlying hardware. A lot of fancy things which are possible with PulseAudio is not possible with ALSA, or at least requires some tinkering (e.g. writing an ALSA plug-in). And this case (playing audio when a sound card is re-plugged) is one of those.

You might try something as follows (if you have or can borrow some USB sound card):

  • connect external USB sound card
  • configure MPD to use this external sound device
  • eject USB sound card
  • plug it back and see what happens

If MPD plays sound via the external sound card immediately, then it might be possible to achieve the same thing with bluez-alsa. However, if the sound is not played immediately, then you're out of luck (due to ALSA design and the MPD ALSA output implementation).

== SOME EXTRA ISSUE, BEYOND YOUR CASE ==

However, the case you've provided is kinda strange :| When you've powered on the BT speaker, in logs I can see transport.c:669: State transition: 0 -> 1 which should not appear if one is using BT speaker. This line is OK if one connects e.g. smartphone and starts to play music. Anyway, I'm not a MPD user, so it is rather hard for me to reproduce your case.

Which version of MPD, bluez and alsa-lib you are using? Also, is this case reproducible (e.g. every time you power cycle BT speaker, this case happens)? Could you provide logs from MPD (if it's possible)?

I've tried to reproduce it with my setup, and the behaviour was correct. When the headset (I do not have BT speaker) was powered off, player (mpv/mplayer and cmus) has stopped playback. So, when the headset was reconnected, I had to start playback manually.

What really concerns me is the line transport.c:669: State transition: 0 -> 1 in the logs. Could you also post here (or somewhere else, because there might be a lot of data) logs obtained with dbus-monitor --system (as root user). Be aware not to expose some private data (if there are any), I'm only interested in bluz <-> bluealsa communication.

@drehren
Copy link
Author

drehren commented Dec 31, 2017

Thanks for your answer! I know ALSA is not PulseAudio, and I wanted to try to see if this case could work.

I forgot to mention that I also have MPD streaming to http, this is what makes MPD not stop its playback when I disconnect the BT speaker. I disabled the http stream and I had the same behavior you mentioned (MPD stops playback when BT speaker is disconnected, need to start playback manually again).
The logs are always reproducible when I do the power cycle (with http output enabled).
MPD did not log anything extra.
D-Bus communication log: dbuscomm.txt

These are the versions I'm currently using:
MPD: 0.20.13-1
bluez-alsa: v1.2.0.r47.g564a092-1 (from aur)
alsa-lib: 1.1.5-1

These are the power cycle logs without http:
Power off:

bluealsa[11464]: /usr/bin/bluealsa: bluez.c:609: Endpoint method call: org.bluez.MediaEndpoint1.ClearConfiguration()
bluealsa[11464]: /usr/bin/bluealsa: transport.c:349: Freeing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: transport.c:839: Releasing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: Couldn't release transport: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Release" with signature "" on interface "org.bluez.MediaTransport1" doesn't exist
bluealsa[11464]: /usr/bin/bluealsa: transport.c:994: Exiting IO thread
bluealsa[11464]: /usr/bin/bluealsa: transport.c:839: Releasing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: Couldn't release transport: GDBus.Error:org.freedesktop.DBus.Error.UnknownObject: Method "Release" with signature "" on interface "org.bluez.MediaTransport1" doesn't exist
bluealsa[11464]: /usr/bin/bluealsa: transport.c:965: Cleaning PCM FIFO: /var/run/bluealsa/hci0-00:0C:8A:70:E8:7D-1-0
bluealsa[11464]: /usr/bin/bluealsa: transport.c:972: Closing PCM: 12
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:399: PCM close for 00:0C:8A:70:E8:7D type 1 stream 0
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:522: Client closed connection: 10
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-

Power on:

bluealsa[11464]: /usr/bin/bluealsa: bluez.c:609: Endpoint method call: org.bluez.MediaEndpoint1.SetConfiguration()
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:541: A2DP Source (SBC) configured for device 00:0C:8A:70:E8:7D
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:543: Configuration: channels: 2, sampling: 44100
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 0 -> 0
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/MPEG24/Source/1
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/MPEG24/Sink/1
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/SBC/Source/2
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:663: Endpoint already registered: /A2DP/SBC/Sink/1
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 0 -> 1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:813: New transport: 13 (MTU: R:672 W:895)
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 1 -> 2
bluealsa[11464]: /usr/bin/bluealsa: transport.c:105: Created new IO thread: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: io.c:55: Opening FIFO for reading: (null)
bluealsa[11464]: /usr/bin/bluealsa: Couldn't open FIFO: Bad address
bluealsa[11464]: /usr/bin/bluealsa: transport.c:839: Releasing transport: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: transport.c:867: Closing BT: 13
bluealsa[11464]: /usr/bin/bluealsa: transport.c:994: Exiting IO thread
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 2 -> 0

Play (in MPD, because it got paused)

bluealsa[11464]: /usr/bin/bluealsa: ctl.c:551: New client accepted: 10
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:324: PCM requested for 00:0C:8A:70:E8:7D type 1 stream 0
bluealsa[11464]: /usr/bin/bluealsa: transport.c:813: New transport: 14 (MTU: R:672 W:895)
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-
bluealsa[11464]: /usr/bin/bluealsa: bluez.c:1028: Signal: PropertiesChanged: org.bluez.MediaTransport1
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 0 -> 2
bluealsa[11464]: /usr/bin/bluealsa: transport.c:105: Created new IO thread: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: io.c:55: Opening FIFO for reading: /var/run/bluealsa/hci0-00:0C:8A:70:E8:7D-1-0
bluealsa[11464]: /usr/bin/bluealsa: io.c:409: Starting IO loop: A2DP Source (SBC)
bluealsa[11464]: /usr/bin/bluealsa: transport.c:669: State transition: 2 -> 2
bluealsa[11464]: /usr/bin/bluealsa: ctl.c:572: +-+-

@arkq
Copy link
Owner

arkq commented Jan 2, 2018

Many thanks for these logs. Could you also post version of used bluez (not bluez-alsa)?

I'm trying to "fix" errors visible in the logs you've provided (these errors might cause unexpected behaviour in a long run). However, it will not resolve your issue, sorry. I'm afraid that your case is beyond bluez-alsa capabilities.

EDIT:
Can you check dbus-quirk branch and see if there are no more Couldn't release transport: GDB... and Couldn't open FIFO: Bad address lines in the bluealsa logs?

@drehren
Copy link
Author

drehren commented Jan 3, 2018

You’re welcome.
Bluez version is 5.47-4. I’ll check the dbus-quirk branch during this week.
Thanks for your time checking this.

@arkq
Copy link
Owner

arkq commented Nov 25, 2019

Closing stale issue. Related issue #174.

@arkq arkq closed this as completed Nov 25, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants