mopidy-jellyfin icon indicating copy to clipboard operation
mopidy-jellyfin copied to clipboard

Weirdness with Playlists

Open jgoerzen opened this issue 1 year ago • 10 comments

Hello,

Thank you for this extension!

I have two issues with it, which I'm not sure are related:

  1. When using the Mopidy web interface (I'm using Muse), nothing at all shows up on the Playlists tab (it says "loading" forever)
  2. When casting to Mopidy from the Jellyfin web interface, when I ask to play a playlist, it appears to play tracks in a random order on the Mopidy side (even though Shuffle was never enabled there). This does not happen when I ask Mopidy to play an album. When I look at the track list in the Mopidy web interface, they are listed in a random order there as well.

A possibly-related niggle: when I ask Jellyfin to cast an album to Mopidy, it doesn't clear Mopidy's play queue, just adds to it. Also the "Clear queue" command from Jellyfin does nothing.

Thank you!

jgoerzen avatar Dec 09 '22 20:12 jgoerzen

Multiple different issues that are almost surely not related. But given that most of them can't be helped here, we can handle them all in one issue.

For the first one, I can't replicate it. I'm not sure how you're accessing Muse or how that client specifically retrieves data from the mopidy instance (I don't see any relevant information in the network inspector), but it appears to be working just fine for me when I'm accessing it directly over http://localhost:6680/muse.

2022-12-09-163802_1334x990_scrot

The second issue I believe you've already narrowed it down to being a server side issue, not client side. We just play whatever the server hands us in that case.

Play queue not clearing when something else is chosen to play - I've gone back and forth on this. It probably makes more sense to clear the play queue unless the "play next" or "add to queue" buttons are clicked.

"Clear queue" button - This appears to be by design(?). I don't receive any commands from the server, nor do I see any api calls happening when that button gets clicked, so I suspect it only applies to the queue in the web player. ie: it's entirely client side to web and doesn't go through the server at all, so it can't control remote controlled clients.

mcarlton00 avatar Dec 09 '22 21:12 mcarlton00

Thanks for the reply! Is there anything I can do to capture debugging info for the first issue, or to help track it down? For what it's worth, the behavior has now changed; instead of permanently loading, I now also have a [Radio Streams] item listed there -- but nothing else. The behavior is also the same with the Iris frontend, both before with nothing listed, and now with only Radio Streams.

Agreed on clearing the queue unless "play next" or "add to queue" are clicked. That would be in line with other players.

I also forgot to mention that the repeat button in Jellyfin doesn't propagate to Mopidy. But that may be a similar situation to the Clear Queue button.

jgoerzen avatar Dec 10 '22 03:12 jgoerzen

You can get more logging by running mopidy -v. I'm not sure if that will give you a good idea of where it's failing to pick up playlists, but might be a good starting point. It's also worth noting that you need to have actually created playlists in Jellyfin for them to show up. For example, seeing the "Playlists" library at the top of the screen with the rest of your libraries, or along the top bar of the music library. Obvious perhaps, but it has come up in the past.

Both Shuffle and Repeat from the web interface don't send any commands that I can pick up on the client side.

mcarlton00 avatar Dec 10 '22 14:12 mcarlton00

Hi,

I do indeed have playlists visible in Jellyfin. Quite a few of them, in fact. They work, subject to the ordering problem I described when casted. They were imported from m3u files from a previous system.

I tried this in my mopidy.conf which should produce even more output:

[logging]
verbosity=4

Now, when clicking on the playlists tab, I get:

Dec 10 08:38:26 mopidy mopidy[1661]: INFO     [HttpServer] tornado.access 200 GET /muse/client/index.5e2c11ef.js (172.19.0.1) 2.88ms
Dec 10 08:38:26 mopidy mopidy[1661]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 172.19.0.1: '{"method":"core.playlists.as_list","jsonrpc":"2.0","id":11}'
Dec 10 08:38:26 mopidy mopidy[1661]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 172.19.0.1: '{"jsonrpc": "2.0", "id": 11, "result": [{"__model__": "Ref", "uri": "m3u:%5BRadio%20Streams%5D.m3u8", "name": "[Radio Streams]", "type": "playlist"}]}'
Dec 10 08:38:26 mopidy mopidy[1661]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 172.19.0.1: '{"method":"core.playlists.lookup","params":["m3u:%5BRadio%20Streams%5D.m3u8"],"jsonrpc":"2.0","id":12}'
Dec 10 08:38:26 mopidy mopidy[1661]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 172.19.0.1: '{"jsonrpc": "2.0", "id": 12, "result": {"__model__": "Playlist", "uri": "m3u:%5BRadio%20Streams%5D.m3u8", "name": "[Radio Streams]", "last_modified": 1670616866622}}'

Weird, I thought. Something must be cached, since I restarted Mopidy. /var/cache/mopidy had only jellyfin/token which didn't seem like a likely culprit. I found /var/lib/mopidy/m3u/[Radio Streams].m3u8, which was 0 bytes. I deleted it, and restarted mopidy.

Now clicking on the Playlists tab caused the same "loading..." as before. The log after clicking is this:

Dec 10 08:42:09 mopidy mopidy[1698]: INFO     [HttpServer] tornado.access 304 GET /muse/client/index.5e2c11ef.js (172.19.0.1) 2.16ms
Dec 10 08:42:09 mopidy mopidy[1698]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 172.19.0.1: '{"method":"core.playlists.as_list","jsonrpc":"2.0","id":11}'
Dec 10 08:42:09 mopidy mopidy[1698]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 172.19.0.1: '{"jsonrpc": "2.0", "id": 11, "result": []}'

Not very helpful, it seems. I'm not seeing anything here about communication back to Jellyfin.

So I thought I'd see what would happen if I'd go to Browse->Jellyfin. There I saw:

Dec 10 08:43:09 mopidy mopidy[1698]: DEBUG    [JellyfinBackend-3] urllib3.connectionpool http://10.200.0.73:8096 "GET /Users/cbc6629b0c3b4b17874f932096209823/Views?format=json HTTP/1.1" 200 None
Dec 10 08:43:09 mopidy mopidy[1698]: DEBUG    [JellyfinBackend-3] mopidy_jellyfin.http {'Items': [{'Name': 'Music', 'ServerId': 'c47850261adb4d3dafda412656c2f1c9', 'Id': '7e64e319657a9516ec78490da03edccb', 'Etag': '8fa897c6c79334683aa6ff6861261d8a', 'DateCreated': '2022-12-06T20:01:21.9928936Z', 'CanDelete': False, 'CanDownload': False, 'SortName': 'music', 'ExternalUrls': [], 'Path': '/config/root/default/Music', 'EnableMediaSourceDisplay': True, 'ChannelId': None, 'Taglines': [], 'Genres': [], 'PlayAccess': 'Full', 'RemoteTrailers': [], 'ProviderIds': {}, 'IsFolder': True, 'ParentId': 'e9d5075a555c1cbc394eec4cef295274', 'Type': 'CollectionFolder', 'People': [], 'Studios': [], 'GenreItems': [], 'LocalTrailerCount': 0, 'UserData': {'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '7e64e319-657a-9516-ec78-490da03edccb'}, 'ChildCount': 9, 'SpecialFeatureCount': 0, 'DisplayPreferencesId': '7e64e319657a9516ec78490da03edccb', 'Tags': [], 'PrimaryImageAspectRatio': 1.7777777777777777, 'CollectionType': 'music', 'ImageTags': {'Primary': '968e4ab3603b7e942da845e0686a9a71'}, 'BackdropImageTags': [], 'ImageBlurHashes': {'Primary': {'968e4ab3603b7e942da845e0686a9a71': 'WB97Y1Rj00fkj]t7D%t7xaRjt6f6D%Rk-;t7M{WBs:Rjt7ozRjj['}}, 'LocationType': 'FileSystem', 'LockedFields': [], 'LockData': False}], 'TotalRecordCount': 1, 'StartIndex': 0}

10.200.0.73 is my Jellyfin server, so there was a hit back to the Jellyfin system. So perhaps the Playlist tab isn't actually hooked up to do anything?

jgoerzen avatar Dec 10 '22 14:12 jgoerzen

So perhaps the Playlist tab isn't actually hooked up to do anything?

Except it's working for me, so there's something specific to your setup that's causing this to not work.

Playlists are loaded from the server immediately upon mopidy starting, and periodically refreshed. So basically right after you start mopidy you should see output of it requesting data from the server (like you're seeing in that last code block while browsing. Anything with mopidy_jellyfin.http is an api call). But you won't see it while browsing to the playlists tab because it's already loaded in memory. So either it doesn't think you have any playlists at all, or it thinks your playlists are empty/don't contain any audio files in them. If you want to find where the files are located on your filesystem then we can add some custom logging to find out which it is.

Run pip show mopidy-jellyfin. It should give you a location of where your files are installed to. For example, mine is /home/matt/.local/lib/python3.10/site-packages.

From there we can get into the extension files themselves. Edit {/your/install/location}/mopidy_jellyfin/playlists.py and add some extra logging lines to the refresh() function that starts at line 52. Some examples here (don't need the long string of # obviously, just highlighting the changes I made):

    raw_playlists = self.backend.remote.get_playlists()
    logger.info(f'raw_playlists: {raw_playlists}')  ############################ NEW LOG LINE
    if raw_playlists:
        for playlist in raw_playlists:
            logger.info(f'Working on {playlist.get("Name")}')   ################ NEW LOG LINE
            playlist_id = playlist.get('Id')
            playlist_uri = 'jellyfin:playlist:%s' % playlist.get('Id')
            contents = self.backend.remote.get_playlist_contents(
                playlist_id
            )
            # Create local Mopidy tracks for audio and book files
            tracks = [
                self.backend.remote.create_track(track)
                for track in contents if track['Type'] in ['Audio', 'Book']
            ]
            # Only create a playlist if it has valid tracks
            if tracks:
                logger.info('Found tracks')   ################################## NEW LOG LINE
                playlists[playlist_uri] = Playlist(
                    uri='jellyfin:playlist:%s' % playlist.get('Id'),
                    name=playlist.get('Name'),
                    tracks=tracks
                )
            else:   ############################################################ NEW LOG LINE
                logger.info('Playlist has no audio tracks')   ################## NEW LOG LINE
    else:   #################################################################### NEW LOG LINE
        logger.info('No Playlists found in the server')   ###################### NEW LOG LINE

Remove your extra verbosity in the config file and restart mopidy. If it finds any playlists in the server, this will tell us.

mcarlton00 avatar Dec 10 '22 15:12 mcarlton00

Interesting. I made the change, and:

Dec 10 13:08:10 mopidy mopidy[3273]: INFO     [MainThread] mopidy_jellyfin.playlists raw_playlists: []
Dec 10 13:08:10 mopidy mopidy[3273]: INFO     [MainThread] mopidy_jellyfin.playlists No Playlists found in the server

So I instrumented remote.py:get_playlists() a bit.

I saw this:

Dec 10 13:17:17 mopidy mopidy[3387]: INFO     [MainThread] mopidy_jellyfin.remote self.http.get(http://10.200.0.73:8096/Users/cbc6629b0c3b4b17874f932096209823/Views?format=json) = {'Items': [{'Name': 'Music', 'ServerId': 'c47850261adb4d3dafda412656c2f1c9', 'Id': '7e64e319657a9516ec78490da03edccb', 'Etag': '8fa897c6c79334683aa6ff6861261d8a', 'DateCreated': '2022-12-06T20:01:21.9928936Z', 'CanDelete': False, 'CanDownload': False, 'SortName': 'music', 'ExternalUrls': [], 'Path': '/config/root/default/Music', 'EnableMediaSourceDisplay': True, 'ChannelId': None, 'Taglines': [], 'Genres': [], 'PlayAccess': 'Full', 'RemoteTrailers': [], 'ProviderIds': {}, 'IsFolder': True, 'ParentId': 'e9d5075a555c1cbc394eec4cef295274', 'Type': 'CollectionFolder', 'People': [], 'Studios': [], 'GenreItems': [], 'LocalTrailerCount': 0, 'UserData': {'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '7e64e319-657a-9516-ec78-490da03edccb'}, 'ChildCount': 2, 'SpecialFeatureCount': 0, 'DisplayPreferencesId': '7e64e319657a9516ec78490da03edccb', 'Tags': [], 'PrimaryImageAspectRatio': 1.7777777777777777, 'CollectionType': 'music', 'ImageTags': {'Primary': '968e4ab3603b7e942da845e0686a9a71'}, 'BackdropImageTags': [], 'ImageBlurHashes': {'Primary': {'968e4ab3603b7e942da845e0686a9a71': 'WB97Y1Rj00fkj]t7D%t7xaRjt6f6D%Rk-;t7M{WBs:Rjt7ozRjj['}}, 'LocationType': 'FileSystem', 'LockedFields': [], 'LockData': False}], 'TotalRecordCount': 1, 'StartIndex': 0}
Dec 10 13:17:17 mopidy mopidy[3387]: INFO     [MainThread] mopidy_jellyfin.remote library_id = []
Dec 10 13:17:17 mopidy mopidy[3387]: INFO     [MainThread] mopidy_jellyfin.playlists raw_playlists: []
Dec 10 13:17:17 mopidy mopidy[3387]: INFO     [MainThread] mopidy_jellyfin.playlists No Playlists found in the server

So, I wondered, why does jellycli get the playlists when talking to the same server with the same user?

Over at https://github.com/tryffel/jellycli/blob/master/api/jellyfin/item.go#L356 I see it is requesting /Users/%s/Items rather than /Users/{}/Views as mopidy-jellyfin is doing. I'm not finding info on the differences between Items and Views but I speculate perhaps that is the issue here? That still doesn't explain why it works for you and not me (are you also on Jellyfin 10.8.8?), but maybe it's a lead?

jgoerzen avatar Dec 10 '22 19:12 jgoerzen

So, it sounds like the root of the issue here is that you have plenty of playlist objects, but don't have a playlists library yet. For some reason importing m3u files doesn't actually create the library/give you full access to it. You have to create/modify a playlist in the UI for it to appear. I suspect you also don't have Playlists on your home screen along the top with all your other libraries (I mentioned this previously), which would be the main sign of this being true.

There's no real reason I can't change the code here to look strictly for playlist objects instead of a playlists library, it just haven't been an issue and this way made sense when I was writing it initially.

mcarlton00 avatar Dec 11 '22 14:12 mcarlton00

Thank you! I guess I misunderstood what you meant. I created a new playlist in Jellyfin and now I do have a Playlists item under My Media, next to Music. (in addition to the Playlists tab at the top of the Music screen, which is what I thought you meant). My apologies for misunderstanding. It is seeing the playlists now!

I need to do some more testing, but initially it seems like it may have also improved the out-of-order issue.

jgoerzen avatar Dec 11 '22 22:12 jgoerzen

One new item: when refreshing playlists in Iris, I get a bunch of these logged:

Dec 11 18:05:09 mopidy mopidy[4518]: INFO     [JellyfinBackend-3] mopidy_jellyfin.library Unknown Jellyfin lookup URI: jellyfin:playlist:2c407785d1a95f09eaeaf525c6d351dc
Dec 11 18:05:09 mopidy mopidy[4518]: INFO     [JellyfinBackend-3] mopidy_jellyfin.library Unknown Jellyfin lookup URI: jellyfin:playlist:649bce36d1f41f9292c1001fc270e320
Dec 11 18:05:09 mopidy mopidy[4518]: INFO     [JellyfinBackend-3] mopidy_jellyfin.library Unknown Jellyfin lookup URI: jellyfin:playlist:76c6d7dd6c85765a03266b914a7e7662
Dec 11 18:05:09 mopidy mopidy[4518]: INFO     [JellyfinBackend-3] mopidy_jellyfin.library Unknown Jellyfin lookup URI: jellyfin:playlist:7170ae1c6293fc4227ac916e82b4427e
Dec 11 18:05:09 mopidy mopidy[4518]: INFO     [JellyfinBackend-3] mopidy_jellyfin.library Unknown Jellyfin lookup URI: jellyfin:playlist:a39a961ff0cf2403d27a708e625d1257
Dec 11 18:05:09 mopidy mopidy[4518]: INFO     [JellyfinBackend-3] mopidy_jellyfin.library Unknown Jellyfin lookup URI: jellyfin:playlist:45ccfdc92de619e3f18048df2bd386a0

The playlists all show up, and initially show up with 0 tracks, but when opening a playlist, everything loads OK.

So to summarize, the things I'm seeing that would still be helpful:

  • Clearing the playlist on certain cast events
  • Not sure if these logged messages are relevant.

THANKS again for all your work on this & help!

jgoerzen avatar Dec 12 '22 00:12 jgoerzen

The URI log messages appear to be (another) quirk of how Iris uses the api and requests data. The seem to be querying each individual playlist instead of asking for all of them at one time. I can make another special case for them which should make the log messages go away and the client work slightly nicer.

mcarlton00 avatar Dec 17 '22 22:12 mcarlton00