search

volumio / Volumio2

Volumio 2 - Audiophile Music Player
http://volumio.org
Other
1.37k stars 315 forks source link

Can't Play User Created Playlists #509

Closed skikirkwood closed 8 years ago

skikirkwood commented 8 years ago

On RC2 Hotfix, I created a one song playlist and the file looks fine:

volumio@volumio2:/data/playlist$ ls Classic British Rock volumio@volumio2:/data/playlist$ more Classic\ British\ Rock [ { "service": "mpd", "uri": "/NAS/iTunes/801/Live/06 Baby's On Fire.m4a", "title": "Baby's On Fire", "artist": "801", "album": "Live", "albumart": "/albumart?web=801/Live/large&path=NAS%2FiTunes%2F801%2FLive%2F06%20Baby's%20On%20Fire.m4a" } ]

But it will not play, with the log file showing:

2016-07-02T00:20:49.195Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri 2016-07-02T00:20:49.196Z - info: [1467418849196] Listing playlists 2016-07-02T00:20:51.405Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri 2016-07-02T00:20:55.190Z - info: CoreCommandRouter::volumioAddQueueItems 2016-07-02T00:20:55.190Z - info: {"uri":"/NAS/iTunes/801/Live/06 Baby's On Fire.m4a","title":"Baby's On Fire","service":"mpd"} 2016-07-02T00:20:55.191Z - info: [1467418855190] CoreStateMachine::addQueueItems 2016-07-02T00:20:55.191Z - info: [1467418855191] CorePlayQueue::addQueueItems 2016-07-02T00:20:55.192Z - info: uri=/NAS/iTunes/801/Live/06 Baby's On Fire.m4a, title=Baby's On Fire, service=mpd 2016-07-02T00:20:55.192Z - info: First index is 0 2016-07-02T00:20:55.193Z - info: ADDING THIS ITEM TO QUEUE: {"uri":"/NAS/iTunes/801/Live/06 Baby's On Fire.m4a","title":"Baby's On Fire","service":"mpd"} 2016-07-02T00:20:55.193Z - info: Exploding uri /NAS/iTunes/801/Live/06 Baby's On Fire.m4a in service mpd 2016-07-02T00:20:55.194Z - info: ----------------------------/mnt//NAS/iTunes/801/Live/06 Baby's On Fire.m4a 2016-07-02T00:20:55.335Z - info: ----->>>>> {} 2016-07-02T00:20:55.336Z - info: [1467418855335] CorePlayQueue::saveQueue 2016-07-02T00:20:55.336Z - info: Adding item to queue: [] 2016-07-02T00:20:55.337Z - info: CoreCommandRouter::volumioPushQueue 2016-07-02T00:20:55.338Z - info: [1467418855337] InterfaceWebUI::pushQueue 2016-07-02T00:20:55.338Z - info: [] 2016-07-02T00:20:55.340Z - info: [1467418855340] CoreStateMachine::updateTrackBlock 2016-07-02T00:20:55.341Z - info: [1467418855340] CorePlayQueue::getTrackBlock 2016-07-02T00:20:55.343Z - info: An error occurred while exploding URI: TypeError: Cannot read property 'service' of undefined

xipmix commented 8 years ago

The problem seems to be the start of the URI. I tried the following experiment

Something seems to be broken in the way the URIs are constructed when adding tracks to playlists in some parts of the user interface. I notice that the working URIs start with 'mnt/', not '/mnt/', and wonder why. I would expect '/mnt/NAS' ie the actual on-disk path.

If it matters, my NAS is mounted with NFS, not CIFS.

xipmix commented 8 years ago

A related observation. When looking at the playlist in the 'Browse' window, the tracks with bad URIs do not show any album art; instead they show the name of the track in large font. This must be just a symptom, but it might help find the problem.

volumio commented 8 years ago

Yep, the tracks do have bad URI

skikirkwood commented 8 years ago

Oops, meant to close a Spotify playlist issue I reported instead of this issue.

xipmix commented 8 years ago

So I did some digging and it looks like things go wrong quite early, when reading the data back from the mpd plugin. I did the following:

patched app/plugins/music_service/mpd/index.js like so:

diff --git a/app/plugins/music_service/mpd/index.js b/app/plugins/music_service/mpd/index.js
index c350404..c43ef4d 100644
--- a/app/plugins/music_service/mpd/index.js
+++ b/app/plugins/music_service/mpd/index.js
@@ -1003,7 +1003,7 @@ ControllerMpd.prototype.lsInfo = function (uri) {
                            for (var i = 0; i < lines.length; i++) {
                                    var line = lines[i];

-                    //self.logger.info("LINE "+line);
+                    self.logger.info("app/plugins/music_service/mpd/index.js sendCommand LINE "+line);
                                    if (line.indexOf('directory:') === 0) {
                                            path = line.slice(11);
                                            name = path.split('/').pop();
@@ -1493,6 +1493,7 @@ ControllerMpd.prototype.handleBrowseUri = function (curUri) {
     var self = this;

     var response;
+    self.commandRouter.logger.info("app/plugins/music_service/mpd/index.js ControllerMpd.prototype.handleBrowseUri curUri='"+curUri+"'");

     if (curUri.startsWith('music-library')) {
         response = self.lsInfo(curUri);
@@ -1524,7 +1525,8 @@ ControllerMpd.prototype.explodeUri = function(uri) {

     if(uri.startsWith('search://'))
     {
-        //exploding search
+        self.commandRouter.logger.info("ControllerMpd.prototype.explodeUri search case, uri='"+uri+"'");
+         //exploding search
         var splitted=uri.split('/');

         var argument=splitted[2];
@@ -1601,6 +1603,9 @@ ControllerMpd.prototype.explodeUri = function(uri) {
                                 var name = path.split('/');
                                 var count = name.length;

+        self.commandRouter.logger.info("ControllerMpd.prototype.explodeUri search album, line='"+line+"'");
+        self.commandRouter.logger.info("ControllerMpd.prototype.explodeUri search album, path='"+path+"'");
+
                                 var artist = self.searchFor(lines, i + 1, 'Artist:');
                                 var album = self.searchFor(lines, i + 1, 'Album:');
                                 var title = self.searchFor(lines, i + 1, 'Title:');

What I see in the log is

info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
info: app/plugins/music_service/mpd/index.js ControllerMpd.prototype.handleBrowseUri        curUri='music-library'
info: app/plugins/music_service/mpd/index.js sendCommand LINE directory: NAS
info: app/plugins/music_service/mpd/index.js sendCommand LINE Last-Modified: 2015-05-24T10: 51:44Z
info: app/plugins/music_service/mpd/index.js sendCommand LINE
info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
info: app/plugins/music_service/mpd/index.js ControllerMpd.prototype.handleBrowseUri       curUri='music-library/NAS'
info: app/plugins/music_service/mpd/index.js sendCommand LINE directory: NAS/ABC_Kids
info: app/plugins/music_service/mpd/index.js sendCommand LINE Last-Modified: 2013-04-21T06: 25:39Z
...
info: app/plugins/music_service/mpd/index.js ControllerMpd.prototype.handleBrowseUri        curUri='music-library/NAS/ABC_Kids'

And here is where we have gone wrong. After this point the uri propagates in the form music-library/NAS/blabla instead of music-library/mnt/NAS/blabla.

I can't understand the code well enough to figure out where the /mnt should go in, but in another case it is added.

app/plugins/music_service/mpd/index.js
....
ControllerMpd.prototype.lsInfo = function (uri) { 
...
self.clientMpd.sendCommand(cmd(command, []), function (err, msg) {
...
else if (line.indexOf('playlist:') === 0) {
    path = line.slice(10);
    name = path.split('/').pop();
    if (path.endsWith('.cue')) {
        try {
             var cuesheet = parser.parse('/mnt/' + path);
volumio commented 8 years ago

Fixed

ScotchTape commented 8 years ago

For me it's not fixed. Did a git pull today: root@volumio:/volumio# git log -1 commit c3908e504f7c3d333d1a671db206d031283406fb

but when I try to create a new playlist from an album, mounted via NFS and try to play that list: Jul 23 13:31:02 volumio volumio[24193]: info: CoreCommandRouter::executeOnPlugin: mpd , getAlbumArt Jul 23 13:31:02 volumio volumio[24193]: info: Pushing Favourites {"uri":"NAS/Musik/Kraftwerk/Minimum Maximum","favourite":false} Jul 23 13:31:07 volumio volumio[24193]: --------------------------playlists Jul 23 13:31:07 volumio volumio[24193]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 23 13:31:07 volumio volumio[24193]: info: [1469280667861] Listing playlists Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671494] Play playlist minimax Jul 23 13:31:11 volumio volumio[24193]: info: CoreCommandRouter::volumioClearQueue Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671506] CoreStateMachine::ClearQueue Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671509] CoreStateMachine::stop Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671512] CoreStateMachine::setConsumeUpdateService undefined Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671514] CorePlayQueue::clearPlayQueue Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671517] CorePlayQueue::saveQueue Jul 23 13:31:11 volumio volumio[24193]: info: CoreCommandRouter::volumioPushQueue Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671523] InterfaceWebUI::pushQueue Jul 23 13:31:11 volumio volumio[24193]: info: [] Jul 23 13:31:11 volumio volumio[24193]: info: CoreCommandRouter::volumioAddQueueItems Jul 23 13:31:11 volumio volumio[24193]: info: [{"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-01 The Man Machine (Warsaw).m4a","service":"mpd"},{"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-02 Planet Of Visions (Ljubljana).m4a","s Jul 23 13:31:11 volumio volumio[24193]: mum Maximum/2-10 Music Non Stop (Moscow).m4a","service":"mpd"}] Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671534] CoreStateMachine::addQueueItems Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671539] CorePlayQueue::addQueueItems Jul 23 13:31:11 volumio volumio[24193]: info: uri=/NAS/Musik/Kraftwerk/Minimum Maximum/1-01 The Man Machine (Warsaw).m4a, service=mpd, uri=/NAS/Musik/Kraftwerk/Minimum Maximum/1-02 Planet Of Visions (Ljubljana).m4a, service=mpd, u Jul 23 13:31:11 volumio volumio[24193]: info: First index is 0 Jul 23 13:31:11 volumio volumio[24193]: info: ADDING THIS ITEM TO QUEUE: {"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-01 The Man Machine (Warsaw).m4a","service":"mpd"} Jul 23 13:31:11 volumio volumio[24193]: info: Exploding uri /NAS/Musik/Kraftwerk/Minimum Maximum/1-01 The Man Machine (Warsaw).m4a in service mpd Jul 23 13:31:11 volumio volumio[24193]: info: ----------------------------/mnt//NAS/Musik/Kraftwerk/Minimum Maximum/1-01 The Man Machine (Warsaw).m4a Jul 23 13:31:11 volumio volumio[24193]: info: ADDING THIS ITEM TO QUEUE: {"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-02 Planet Of Visions (Ljubljana).m4a","service":"mpd"} Jul 23 13:31:11 volumio volumio[24193]: info: Exploding uri /NAS/Musik/Kraftwerk/Minimum Maximum/1-02 Planet Of Visions (Ljubljana).m4a in service mpd Jul 23 13:31:11 volumio volumio[24193]: info: ----------------------------/mnt//NAS/Musik/Kraftwerk/Minimum Maximum/1-02 Planet Of Visions (Ljubljana).m4a Jul 23 13:31:11 volumio volumio[24193]: info: ADDING THIS ITEM TO QUEUE: {"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-03 Tour De France Etape One (Riga).m4a","service":"mpd"} Jul 23 13:31:11 volumio volumio[24193]: info: Exploding uri /NAS/Musik/Kraftwerk/Minimum Maximum/1-03 Tour De France Etape One (Riga).m4a in service mpd Jul 23 13:31:11 volumio volumio[24193]: info: ----------------------------/mnt//NAS/Musik/Kraftwerk/Minimum Maximum/1-03 Tour De France Etape One (Riga).m4a Jul 23 13:31:11 volumio volumio[24193]: info: ADDING THIS ITEM TO QUEUE: {"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-04 Chrono (Riga).m4a","service":"mpd"} Jul 23 13:31:11 volumio volumio[24193]: info: Exploding uri /NAS/Musik/Kraftwerk/Minimum Maximum/1-04 Chrono (Riga).m4a in service mpd Jul 23 13:31:11 volumio volumio[24193]: info: ----------------------------/mnt//NAS/Musik/Kraftwerk/Minimum Maximum/1-04 Chrono (Riga).m4a Jul 23 13:31:11 volumio volumio[24193]: info: ADDING THIS ITEM TO QUEUE: {"uri":"/NAS/Musik/Kraftwerk/Minimum Maximum/1-05 Tour De France Etape Two (Riga).m4a","service":"mpd"} Jul 23 13:31:11 volumio volumio[24193]: info: Exploding uri /NAS/Musik/Kraftwerk/Minimum Maximum/1-05 Tour De France Etape Two (Riga).m4a in service mpd [...] Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio volumio[24193]: info: ----->>>>> {} Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio mpd[482]: db: No such directory Jul 23 13:31:11 volumio mpd[482]: db: No such directory [...] Jul 23 13:31:11 volumio volumio[24193]: info: ----->>>>> {} Jul 23 13:31:11 volumio volumio[24193]: info: ----->>>>> {} Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671868] CorePlayQueue::saveQueue Jul 23 13:31:11 volumio volumio[24193]: info: Adding item to queue: [] Jul 23 13:31:11 volumio volumio[24193]: info: CoreCommandRouter::volumioPushQueue Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671876] InterfaceWebUI::pushQueue Jul 23 13:31:11 volumio volumio[24193]: info: [] Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671883] CoreStateMachine::updateTrackBlock Jul 23 13:31:11 volumio volumio[24193]: info: [1469280671885] CorePlayQueue::getTrackBlock Jul 23 13:31:11 volumio volumio[24193]: info: An error occurred while exploding URI: TypeError: Cannot read property 'service' of undefined

playlist: [ { "service": "mpd", "uri": "/NAS/Musik/Kraftwerk/Minimum Maximum/1-01 The Man Machine (Warsaw).m4a", "title": "The Man Machine (Warsaw)", "artist": "Kraftwerk", "album": "Minimum Maximum", "albumart": "/albumart?web=Kraftwerk/Minimum%20Maximum/large&path=NAS%2FMusik%2FKraftwerk%2FMinimum%20Maximum" }, { "service": "mpd", "uri": "/NAS/Musik/Kraftwerk/Minimum Maximum/1-02 Planet Of Visions (Ljubljana).m4a", "title": "Planet Of Visions (Ljubljana)", "artist": "Kraftwerk", "album": "Minimum Maximum", "albumart": "/albumart?web=Kraftwerk/Minimum%20Maximum/large&path=NAS%2FMusik%2FKraftwerk%2FMinimum%20Maximum" },

mount: OMV:/export/Musik on /mnt/NAS/Musik type nfs (ro,relatime,vers=3,rsize=131072,wsize=131072,namlen=255,soft,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=192.168.178.32,mountvers=3,mountport=38803,mountproto=udp,local_lock=none,addr=192.168.178.32)

playing a file from that album:Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352215] parsing response... Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352216] ControllerMpd::parseTrackInfo Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352218] ControllerMpd::pushState Jul 23 13:59:12 volumio volumio[24193]: info: CoreCommandRouter::servicePushState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352220] CoreStateMachine::syncState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352221] CorePlayQueue::getTrack 0 Jul 23 13:59:12 volumio volumio[24193]: info: STATE SERVICE {"status":"play","position":0,"seek":360,"duration":462,"samplerate":"44.1 KHz","bitdepth":"NaN bit","channels":2,"random":false,"updatedb":false,"repeat":false,"isStreami Jul 23 13:59:12 volumio volumio[24193]: info: CURRENT POSITION 0 Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352224] CoreStateMachine::syncState stateService play Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352225] CoreStateMachine::syncState currentStatus play Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352226] Received an update from plaugin. extracting info from payload Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352227] CoreStateMachine::pushState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352229] CoreStateMachine::getState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352230] CorePlayQueue::getTrack 0 Jul 23 13:59:12 volumio volumio[24193]: info: CoreCommandRouter::volumioPushState Jul 23 13:59:12 volumio volumio[24193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352233] InterfaceWebUI::pushState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352238] CoreStateMachine::pushState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352239] CoreStateMachine::getState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352240] CorePlayQueue::getTrack 0 Jul 23 13:59:12 volumio volumio[24193]: info: CoreCommandRouter::volumioPushState Jul 23 13:59:12 volumio volumio[24193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352244] InterfaceWebUI::pushState Jul 23 13:59:12 volumio volumio[24193]: info: [1469282352255] ------------------------------ 196ms Jul 23 13:59:12 volumio volumio[24193]: info: Pushing Favourites {"service":"mpd","uri":"mnt/NAS/Musik/Kraftwerk/Minimum Maximum/1-11 Radioactivity (Warsaw).m4a","favourite":false} Jul 23 13:59:12 volumio volumio[24193]: info: Pushing Favourites {"service":"mpd","uri":"mnt/NAS/Musik/Kraftwerk/Minimum Maximum/1-11 Radioactivity (Warsaw).m4a","favourite":false} Jul 23 13:59:12 volumio volumio[24193]: info: Pushing Favourites {"service":"mpd","uri":"mnt/NAS/Musik/Kraftwerk/Minimum Maximum/1-11 Radioactivity (Warsaw).m4a","favourite":false} Jul 23 13:59:12 volumio volumio[24193]: info: Pushing Favourites {"service":"mpd","uri":"mnt/NAS/Musik/Kraftwerk/Minimum Maximum/1-11 Radioactivity (Warsaw).m4a","favourite":false} Jul 23 13:59:13 volumio volumio[24193]: info: /mnt/NAS/Musik/Kraftwerk/Minimum Maximum Jul 23 13:59:13 volumio volumio[24193]: info: /data/albumart/folder/mnt/NAS/Musik/Kraftwerk/Minimum Maximum/extralarge.jpeg Jul 23 13:59:13 volumio volumio[24193]: info: Searching in folder /mnt/NAS/Musik/Kraftwerk/Minimum Maximum Jul 23 13:59:13 volumio volumio[24193]: info: Copying file to cache [/data/albumart/folder//mnt/NAS/Musik/Kraftwerk/Minimum Maximum/extralarge.jpeg] Jul 23 13:59:13 volumio volumio[24193]: info: Serving request took 43 milliseconds Jul 23 13:59:14 volumio volumio[24193]: info: Jul 23 13:59:14 volumio volumio[24193]: [1469282354573] ---------------------------- Client requests Volume 100 Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354575] VolumeController::SetAlsaVolume100 Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354596] ------------------------------ 23ms Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354630] VolumeController::Volume 100 Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354632] CoreStateMachine::pushState Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354633] CoreStateMachine::getState Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354633] CorePlayQueue::getTrack 0 Jul 23 13:59:14 volumio volumio[24193]: info: CoreCommandRouter::volumioPushState Jul 23 13:59:14 volumio volumio[24193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 23 13:59:14 volumio volumio[24193]: info: [1469282354639] InterfaceWebUI::pushState Jul 23 13:59:14 volumio volumio[24193]: info: Pushing Favourites {"service":"mpd","uri":"mnt/NAS/Musik/Kraftwerk/Minimum Maximum/1-11 Radioactivity (Warsaw).m4a","favourite":false

xipmix commented 8 years ago

The fix for this went into 'master' at 34267cc4475bc69cf565e4b04e6a26f43e9fcceb on Sun Jul 10 20:37:47 2016 +0000 but for some reason this has not propagated to 'dev', which is still at 'c3908e5 Fixed credentials for NFS' (Jul 7 12:04:10 2016 +0200). See #543 for some notes on how I updated my install.