snapcast icon indicating copy to clipboard operation
snapcast copied to clipboard

meta_mpd.py loses stable connection with MPD

Open jaedb opened this issue 2 years ago • 9 comments

Describe the bug Initial startup works fine and track information (and artwork 🤩) is beautifully plucked from MPD and added to the stream metadata. I can see the meta_mpd.py is interacting well with the Mopidy Docker instance.

However after ~10 minutes, track metadata is no longer being updated from the MPD/Mopidy connection.

Control commands still appear to work, but the result of the command is not reflected in the stream. Again, it seems information is not being fed BACK to Snapserver. Here is a sample command being sent to the Snapserver API:

{
  "jsonrpc": "2.0",
  "id": "1745128051013136",
  "method": "Stream.Control",
  "params": {
    "id": "Default",
    "command": "pause"
  }
}

Steps to Reproduce

  1. Startup Snapserver with a stream configured to use the pre-packaged meta_mpd.py
  2. Observe stream information is being sent correctly. Play a playlist with no interaction for ~10 minutes.
  3. Stream is no longer being updated from MPD
  4. Observe error around chunk = fd.read() in meta_mpd.py

Environment details

  • OS: Docker (https://github.com/jaedb/snapserver)
  • Snapcast version 0.26.0
  • Installed from a package as supplied in Releases
  • Running in conjunction with Mopidy-Iris

Attach logfile if applicable

snapserver_1      | 2022-03-04 09-18-21.331 [Info] (Script) Sending request: {"id":7,"jsonrpc":"2.0","method":"Plugin.Stream.Player.GetProperties"}
snapserver_1      | 2022-03-04 09-18-21.331 [Info] (PcmStream) Stream: Default, message: 2022-03-04 09:18:21,331 meta_mpd INFO: Received: {"id":7,"jsonrpc":"2.0","method":"Plugin.Stream.Player.GetProperties"}
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message: 2022-03-04 09:18:21,334 meta_mpd INFO: Snapstatus: {'volume': 24, 'loopStatus': 'none', 'shuffle': False, 'playbackStatus': 'playing', 'position': 0.092, 'canGoNext': True, 'canGoPrevious': True, 'canPlay': True, 'canPause': True, 'canSeek': False, 'canControl': True}
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (Script) Response: {"id":7,"jsonrpc":"2.0","result":{"canControl":true,"canGoNext":true,"canGoPrevious":true,"canPause":true,"canPlay":true,"canSeek":false,"loopStatus":"none","playbackStatus":"playing","position":0.092,"shuffle":false,"volume":24}}, id: 7
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Response for Plugin.Stream.Player.GetProperties: {"id":7,"jsonrpc":"2.0","result":{"canControl":true,"canGoNext":true,"canGoPrevious":true,"canPause":true,"canPlay":true,"canSeek":false,"loopStatus":"none","playbackStatus":"playing","position":0.092,"shuffle":false,"volume":24}}
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message: Traceback (most recent call last):
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message:   File "/usr/local/lib/python3.10/site-packages/gi/overrides/GLib.py", line 671, in <lambda>
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message:     func_fdtransform = lambda _, cond, *data: callback(channel, cond, *data)
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message:   File "/usr/share/snapserver/plug-ins/meta_mpd.py", line 454, in io_callback
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message:     chunk = fd.read()
snapserver_1      | 2022-03-04 09-18-21.334 [Info] (PcmStream) Stream: Default, message:   File "/usr/local/lib/python3.10/codecs.py", line 321, in decode
snapserver_1      | 2022-03-04 09-18-21.335 [Info] (PcmStream) Stream: Default, message:     data = self.buffer + input
snapserver_1      | 2022-03-04 09-18-21.335 [Info] (PcmStream) Stream: Default, message: TypeError: can't concat NoneType to bytes
snapserver_1      | 2022-03-04 09-18-29.219 [Info] (PcmStream) Stream: Default, message: 2022-03-04 09:18:29,218 meta_mpd INFO: new status: {'volume': '24', 'repeat': '0', 'random': '0', 'single': '0', 'consume': '1', 'playlist': '34', 'playlistlength': '93', 'xfade': '0', 'state': 'play', 'song': '0', 'songid': '102', 'nextsong': '1', 'nextsongid': '9', 'time': '7:281', 'elapsed': '7.986', 'bitrate': '160'}, changed_status: {'time': ['0:281', '7:281'], 'elapsed': ['0.092', '7.986']}, changed_song: {}
snapserver_1      | 2022-03-04 09-18-33.217 [Warn] (PcmStream) Stream: Secondary, message: 2022-03-04 09:18:33,217 meta_mpd_secondary WARNING: _update_properties: failed to get current song
snapserver_1      | 2022-03-04 09-18-44.224 [Info] (PcmStream) Stream: Default, message: 2022-03-04 09:18:44,223 meta_mpd INFO: new status: {'volume': '24', 'repeat': '0', 'random': '0', 'single': '0', 'consume': '1', 'playlist': '34', 'playlistlength': '93', 'xfade': '0', 'state': 'play', 'song': '0', 'songid': '102', 'nextsong': '1', 'nextsongid': '9', 'time': '22:281', 'elapsed': '22.987', 'bitrate': '160'}, changed_status: {'time': ['7:281', '22:281'], 'elapsed': ['7.986', '22.987']}, changed_song: {}

jaedb avatar Mar 04 '22 09:03 jaedb

Can you please try the meta_mpd.py script from the develop branch, it should catch exceptions and return true in the handler, which means that the handler should not be removed, see commit fd4d8212

badaix avatar Jul 01 '22 10:07 badaix

To reproduce this issue, I've installed Mopidy and as a front end I've installed Iris. I must admit that this was my first Iris installation. Thanks for this great project, it looks great on the desktop as well as on the mobile! I was so excited about Iris that I didn't continue to install the Mopidy-MPD extension, but took a look at Mopidy's excellent HTTP JSON-RPC API, which exposes the Mopidy core API. So I've decided to create meta_mopidy.py, which I guess is more stable, since it doesn't need the additional MPD layer. Overall the script is more simple than the meta_mpd.py script

The script works well, there are two issues:

  1. When the track changes, the script requests the image urls core.library.get_images. Sometimes the images are not completely loaded when using snapcast_mpris.py on my cinnamon desktop or in Snapweb. I've put a sleep of 100ms into the script before reporting the image URL to Snapserver. This workaround helps, I don't know if Mopidy didn't flush the image to disk when reporting the URL. Did you stumble upon this with Iris?
  2. Snapcast's stream meta API doesn't support mute yet, I will add this tomorrow

I would appreciate if you could test the new script. It's really just a drop in replacement for meta_mpd.py and should make the Iris/Snapcast experience even greater :)

badaix avatar Jul 11 '22 17:07 badaix

@badaix thanks heaps for the effort here. I've been running your updated meta_mpd.py for a week to give it a real-world test, but I'll switch to meta_mopidy.py and let you know how it goes.

I did have to install a few additional dependencies but it was all pretty self explanatory; thanks for pointing them out in the script.

jaedb avatar Jul 12 '22 09:07 jaedb

@jaedb Nice, sounds like the issue in meta_mpd.py can be considered fixed. FYI: I did some investigation on the cover art issue and it seems that both, Chrome's MediaSession and Cinnamon's MPRIS applet are having problems with frequent updates. The script was collecting the necessary information in a single JSON RPC batch request, sent the result to Snapcast, who broadcasts the metadata to all listeners, followed by a separate JSON RPC request for the cover art and another update broadcast, just a few milliseconds later, with the same metadata plus the cover art URL. The script is now refactored to collect and send all information at once (including the cover art). I'm continuing testing it.

badaix avatar Jul 12 '22 19:07 badaix

Cool, I'll update and test too.

One thing I've noticed is that if Mopidy provides a foreign artwork URL, the host:port string concatenation creates an invalid URL.

For example, this track from Youtube:

          "metadata": {
            "album": "Line of Fire",
            "artUrl": "http://localhost:6680https://lh3.googleusercontent.com/gQY4A0jSyG_JvlX_edZVugSoQIYy7i8C51fn9kymSJSJdo-KHcgzhTFbL6Hyc9SwrvUPQCUU4BonzXM=w544-h544-l90-rj",
            "artist": [
              "Booka Shade"
            ],
            ...
          },

jaedb avatar Jul 13 '22 03:07 jaedb

The artUrl issue should be fixed now, although I don't have a clean and generic solution for local URLs. localhost comes from the mopidy-host command line parameter, which defaults to localhost, so Snapcast clients running on other hosts will not be able to download the image. Also I've noticed that it's not really possible to add script parameters for a controlscript in Snapserver's stream source configuration, hence I've added the parameter controlscriptparameter, so that one can configure e.g. &controlscript=meta_mopidy.py&controlscriptparams=--mopidy-host=192.168.0.38%20--debug. Snapserver is also aware of the configuration parameter [http] host=<hostname> and will substitute it with the actual hostname if it is unconfigured. This hostname is passed as --snapcast-host to the control script. Maybe some similar magic could be applied in meta_mopidy.py: if mopidy-host is not configured, try to figure out the local host name or use the --snapcast-host parameter. This could work in most cases, but will be hard to debug if it's not working.

badaix avatar Jul 13 '22 12:07 badaix

We've actually hit a very similar problem in Mopidy-MPD and didn't yet resolve it. We should probably "fix" Mopidy-Local to provide absolute image URLs but it's not as simple as it sounds.

kingosticks avatar Jul 13 '22 12:07 kingosticks

Update: I've installed Mopidy on my server and running meta_mpd.py from 3d072dbbb6367 for the last two days without any issues so far, using a mix of mopidy-local and mopidy-tunein.

badaix avatar Jul 16 '22 12:07 badaix

I've just updated to the latest version and images are working 👌 on Mopidy-Youtube now too.

I'm going to give the parameters configuration a whirl now to use a network-known hostname. This will make sure that Mopidy-Local images are accessible within the local domain. This should solve the issue where http://localhost:6680/images/... is only available to the machine actually running Mopidy (and not other machines).

jaedb avatar Jul 20 '22 18:07 jaedb

Fixed in snapcast v0.27.0

badaix avatar Feb 05 '23 12:02 badaix