Information about stations not shown when loaded from playlist

BenediktO commented 4 years ago

I used the search function but did not find this bug yes. If I manually add stations to the queue via the webinterface everything is fine: 1queue_manual

After the list was saved as a playlist everything is still fine: 2saved_playlist

If this list is loaded (via the webinterface or the REST API) the station information is not shown anymore: 3queue_from_playlist

Note that only the information in the queue is affacted, the currently running station is still shown as expected. This behaviour is reflected in the REST API: The queue does not contain useful information:

{
    "queue": [{
        "uri": "http://addrad.io/444y3fj",
        "service": "webradio",
        "albumart": "/albumart",
        "samplerate": "",
        "bitdepth": "",
        "channels": 0,
        "trackType": "webradio"
    }, {
        "uri": "http://addrad.io/4WRLzh",
        "service": "webradio",
        "albumart": "/albumart",
        "samplerate": "",
        "bitdepth": 0,
        "channels": 0
    }, {
        "uri": "http://addrad.io/4WRLM9",
        "service": "webradio",
        "albumart": "/albumart",
        "samplerate": "",
        "bitdepth": 0,
        "channels": 0
    }]
}

The getState command yields useful information:

{
    "status": "play",
    "position": 0,
    "title": "Aus Kultur- und Sozialwissenschaften 03.09.2020, Dörte Hinrichs",
    "artist": "Deutschlandfunk",
    "album": null,
    "albumart": "/albumart?cacheid=288&web=Deutschlandfunk//extralarge",
    "uri": "http://addrad.io/444y3fj",
    "trackType": "webradio",
    "seek": 732492,
    "duration": 0,
    "samplerate": "",
    "bitdepth": "",
    "channels": 2,
    "bitrate": "128 Kbps",
    "random": false,
    "repeat": true,
    "repeatSingle": false,
    "consume": true,
    "volume": 45,
    "mute": false,
    "disableVolumeControl": false,
    "stream": true,
    "updatedb": false,
    "volatile": false,
    "service": "webradio"
}

The used volumio version is 2.806 from Wed Jul 29 2020 It runs on a Raspberry Pi using the latest image. I did not install any plugins.

xipmix commented 4 years ago

What a great bug report. Could you please add a couple of things to make debugging quicker

the contents of the playlist file? (paste between ``` marks)
the URL you used to query the REST interface?

BenediktO commented 4 years ago

The content of the playlist that I created in the screenshots above:

[{
    "service": "webradio",
    "uri": "http://addrad.io/444y3fj",
    "title": "Deutschlandfunk",
    "albumart": "http://cdn-profiles.tunein.com/s42828/images/logoq.png?t=1"
}, {
    "service": "webradio",
    "uri": "http://addrad.io/4WRLzh",
    "title": "SWR1 Baden-Württemberg",
    "albumart": "http://cdn-profiles.tunein.com/s20291/images/logoq.png?t=1"
}, {
    "service": "webradio",
    "uri": "http://addrad.io/4WRLM9",
    "title": "SWR3",
    "albumart": "http://cdn-profiles.tunein.com/s24896/images/logoq.png?t=1"
}]

Everything looks as expected.

For the REST requests I used the following URLs:

I used curl and a python3 script using requests both from the localhost on port 3000 and on another computer using volumio.local on port 80. It always yields the above content.

BenediktO commented 4 years ago

By the way this problem does not occur when using a playlist that only contains mp3 files from a NAS. I also did another test: I mixed radio stations (from different countries) and some mp3 files from the NAS. Every item that is of type webradio looses information, both using REST and the webinterface

xipmix commented 4 years ago

Yes the handling of webradios seems to have a few ... intricacies. Thanks for the updates, I shall try to reproduce.

xipmix commented 4 years ago

Well this is entertaining. I tested this against v2.777 and it seems to work ok.

I uploaded your playlist file and when I added the playlist to the queue, it was displayed correctly, with the name and icon.

$ cat /data/queue
[
  {
    "service": "webradio",
    "uri": "http://addrad.io/444y3fj",
    "name": "Deutschlandfunk",
    "albumart": "http://cdn-profiles.tunein.com/s42828/images/logoq.png?t=1",
    "samplerate": "",
    "bitdepth": 0,
    "channels": 0
  },
  {
    "service": "webradio",
    "uri": "http://addrad.io/4WRLzh",
    "name": "SWR1 Baden-Württemberg",
    "albumart": "http://cdn-profiles.tunein.com/s20291/images/logoq.png?t=1",
    "samplerate": "",
    "bitdepth": 0,
    "channels": 0
  },
  {
    "service": "webradio",
    "uri": "http://addrad.io/4WRLM9",
    "name": "SWR3",
    "albumart": "http://cdn-profiles.tunein.com/s24896/images/logoq.png?t=1",
    "samplerate": "",
    "bitdepth": 0,
    "channels": 0
  }
]

Notice the 'name' field.

Then I tried your REST 'queue' query. That returned this structure, which includes the 'name' and useful 'albumart' fields in it.

{"queue":
[
 {
  "service":"webradio",
  "uri":"http://addrad.io/444y3fj",
  "name":"Deutschlandfunk",
  "albumart":"http://cdn-profiles.tunein.com/s42828/images/logoq.png?t=1",
  "samplerate":"","bitdepth":0,"channels":0
 },{
  "service":"webradio",
  "uri":"http://addrad.io/4WRLzh",
  "name":"SWR1 Baden-Württemberg",
  "albumart":"http://cdn-profiles.tunein.com/s20291/images/logoq.png?t=1",
  "samplerate":"","bitdepth":0,"channels":0
 },{
  "service":"webradio",
  "uri":"http://addrad.io/4WRLM9",
  "name":"SWR3",
  "albumart":"http://cdn-profiles.tunein.com/s24896/images/logoq.png?t=1",
  "samplerate":"","bitdepth":0,"channels":0
 }
]
}

I fixed something rather similar to this issue in #1821 (merged as 75f2f10e6aebd9a18e7dba2792a52c79ad4bc0fe on 2020-02-22). The version I tested with was released on 2020-02-25 so it has that fix

$ cd /volumio; git log -1
commit 8583c814bdc88e8c28c10464bec8226bce2b0634
Author: Ash <ashthespy@users.noreply.github.com>
Date:   Mon May 25 17:51:57 2020 +0200

    Add an entry in the dev page to tail logs (#1974)

    * Add an entry in the dev page to tail logs

    * Use full path to bin, and fix code style

    * Fix bin path for spawn

    * Revert to non sudo journalctl invocation

    * Add better safeguards

    * Reduce noise in livelogs

Your version was released on 2020-07-29, as you say above.

So perhaps something has gone wrong in between, or this is a different corner case. I don't see anything in the changelog for the file my patch affected that was clearly a regression. I poked around all the commits between 8583c814bdc88e8c28c10464bec8226bce2b0634 and current HEAD and there's nothing obvious. The only commit I am a bit suspicious about is aeda3bc48238b4fd06e939d97a6781cb9aef861a because it tries to use the 'title' field which does not exist in queue items; there is a 'title' in a playlist item but in the queue it is 'name'. (edit... at least, for webradio items) If you are able to ssh into your volumio perhaps you could try this test:

volumio$ sudo journalctl -f

and in another window, run your 'getQueue' query again. What do you see in the log?

What I see is fairly boring

Sep 07 13:13:55 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue
Sep 07 13:13:55 volumio volumio[897]: info: CoreStateMachine::getQueue
Sep 07 13:13:55 volumio volumio[897]: info: CorePlayQueue::getQueue

If you are up for a bit of live patching, this might do it but it's a stab in the dark.

index f92f663..4f7744c 100755
--- a/app/plugins/music_service/webradio/index.js
+++ b/app/plugins/music_service/webradio/index.js
@@ -850,13 +850,13 @@ ControllerWebradio.prototype.search = function (data) {

   var search = data.value.normalize('NFKD').replace(/[\u0300-\u036F]/g, '').replace(/[' ']/g, '*').toLowerCase();
   var tuneInSerch = self.searchWithTuneIn(search).then(function (value) {
-    value.sort(dynamicSort('title'));
+    value.sort(dynamicSort('name'));

     return value;
   });

   var shoutcastSearch = self.searchWithShoutcast(search).then(function (value) {
-    value.sort(dynamicSort('title'));
+    value.sort(dynamicSort('name'));

     return value;
   });

BenediktO commented 4 years ago

I get the same log:

Sep 07 16:50:27 volumio volumio[770]: info: CoreCommandRouter::volumioGetQueue
Sep 07 16:50:27 volumio volumio[770]: info: CoreStateMachine::getQueue
Sep 07 16:50:27 volumio volumio[770]: info: CorePlayQueue::getQueue

The patch did not change anything, sadly. But I noticed that this only happens if I use replace queue in the GUI and playplaylist via the REST api. If I append the playlist to the queue using the GUI everything looks as expected, even without the patch. The commands executed are enqueue vs. replaceAndPlay using the Websockets api. The REST Api does not have something similar to enqueue, am I right? There is only addToQueue where I would have to post the whole playlist at once?

BenediktO commented 4 years ago

I hacked the missing command into the REST API and it works great. It's not pretty and just a proof that the enqueue command works as expected. I'm no Javascript expert at all...

diff --git a/app/plugins/user_interface/rest_api/playback.js b/app/plugins/user_interface/rest_api/playback.js
index f68e7b4e..511849c7 100644
--- a/app/plugins/user_interface/rest_api/playback.js
+++ b/app/plugins/user_interface/rest_api/playback.js
@@ -305,6 +305,19 @@ RESTApiPlayback.prototype.addToQueue = function (req, res) {
     });
 };

+RESTApiPlayback.prototype.enqueue = function (req, res) {
+  var self = this;
+
+  self.commandRouter.playListManager.enqueue(req.query.name)
+    .then(function () {
+      res.json({'response': 'success'});
+    })
+    .fail(function (e) {
+      return res.json({'error': e});
+    });
+};
+
 RESTApiPlayback.prototype.replaceAndPlay = function (req, res) {
   var self = this;

diff --git a/app/plugins/user_interface/rest_api/index.js b/app/plugins/user_interface/rest_api/index.js
index 37e17e70..6037667b 100644
--- a/app/plugins/user_interface/rest_api/index.js
+++ b/app/plugins/user_interface/rest_api/index.js
@@ -42,6 +42,7 @@ function interfaceApi (context) {
   api.get('/commands', this.playback.playbackCommands.bind(this.playback));
   api.get('/getState', this.playback.playbackGetState.bind(this.playback));
   api.get('/getQueue', this.playback.playbackGetQueue.bind(this.playback));
+  api.get('/enqueue', this.playback.enqueue.bind(this.playback));
   api.post('/addToQueue', this.playback.addToQueue.bind(this.playback));
   api.post('/addPlay', this.playback.addPlay.bind(this.playback));
   api.post('/replaceAndPlay', this.playback.replaceAndPlay.bind(this.playback));

BenediktO commented 4 years ago

The 2 lines in the patch seem not to be the problem. I commented them out and the bug is still present

xipmix commented 4 years ago

Thanks for the hint about 'clear and play'. That gives a reproducer (I see the 'undefined' names and default albumart in the Queue page) and a more interesting log.

First I cleared the queue, then went to playlists and selected 'clear and play' from the action menu on your playlist. The log starts on that last action.

Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::ClearQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::stop
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 08 04:11:21 volumio volumio[897]: UNSET VOLATILE
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::clearPlayQueue
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::saveQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue
Sep 08 04:11:21 volumio volumio[897]: info: Play playlist issue1998
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioClearQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::ClearQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::stop
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 08 04:11:21 volumio volumio[897]: UNSET VOLATILE
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::clearPlayQueue
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::saveQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioAddQueueItems
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::addQueueItems
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::addQueueItems
Sep 08 04:11:21 volumio volumio[897]: info: Adding Item to queue: http://addrad.io/444y3fj
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 08 04:11:21 volumio volumio[897]: info: Adding Item to queue: http://addrad.io/4WRLzh
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 08 04:11:21 volumio volumio[897]: info: Adding Item to queue: http://addrad.io/4WRLM9
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::saveQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::getTrackBlock
Sep 08 04:11:21 volumio volumio[897]: info: CoreCommandRouter::volumioPlay
Sep 08 04:11:21 volumio volumio[897]: UNSET VOLATILE
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::play index 0
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::stop
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 08 04:11:21 volumio volumio[897]: UNSET VOLATILE
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::play index undefined
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::getTrack 0
Sep 08 04:11:21 volumio volumio[897]: info: CoreStateMachine::startPlaybackTimer
Sep 08 04:11:21 volumio volumio[897]: info: CorePlayQueue::getTrack 0
Sep 08 04:11:21 volumio volumio[897]: info: [1599538281091] ControllerWebradio::clearAddPlayTrack
Sep 08 04:11:21 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop
Sep 08 04:11:21 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand clear
Sep 08 04:11:21 volumio volumio[897]: info:
Sep 08 04:11:21 volumio volumio[897]: ---------------------------- MPD announces system playlist update
Sep 08 04:11:21 volumio volumio[897]: info: Ignoring MPD Status Update
Sep 08 04:11:21 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand load "http://addrad.io/444y3fj"
Sep 08 04:11:21 volumio volumio[897]: error: updateQueue error: null
Sep 08 04:11:21 volumio volumio[897]: info: ------------------------------ 5ms
Sep 08 04:11:22 volumio volumio[897]: error: error
Sep 08 04:11:23 volumio volumio[897]: error: error
Sep 08 04:11:24 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand add "http://addrad.io/444y3fj"
Sep 08 04:11:24 volumio volumio[897]: info:
Sep 08 04:11:24 volumio volumio[897]: ---------------------------- MPD announces system playlist update
Sep 08 04:11:24 volumio volumio[897]: info: Ignoring MPD Status Update
Sep 08 04:11:24 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService mpd
Sep 08 04:11:24 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand play
Sep 08 04:11:24 volumio volumio[897]: info: ------------------------------ 8ms
Sep 08 04:11:25 volumio volumio[897]: error: error
Sep 08 04:11:25 volumio volumio[897]: error: error
Sep 08 04:11:25 volumio volumio[897]: info:
Sep 08 04:11:25 volumio volumio[897]: ---------------------------- MPD announces state update: player
Sep 08 04:11:25 volumio volumio[897]: info: ControllerMpd::getState
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status
Sep 08 04:11:25 volumio volumio[897]: info:
Sep 08 04:11:25 volumio volumio[897]: ---------------------------- MPD announces system playlist update
Sep 08 04:11:25 volumio volumio[897]: info: Ignoring MPD Status Update
Sep 08 04:11:25 volumio volumio[897]: info:
Sep 08 04:11:25 volumio volumio[897]: ---------------------------- MPD announces state update: player
Sep 08 04:11:25 volumio volumio[897]: info:
Sep 08 04:11:25 volumio volumio[897]: ---------------------------- MPD announces system playlist update
Sep 08 04:11:25 volumio volumio[897]: info: Ignoring MPD Status Update
Sep 08 04:11:25 volumio volumio[897]: info:
Sep 08 04:11:25 volumio volumio[897]: ---------------------------- MPD announces state update: player
Sep 08 04:11:25 volumio volumio[897]: info: ControllerMpd::getState
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status
Sep 08 04:11:25 volumio volumio[897]: info: ControllerMpd::getState
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::parseState
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 08 04:11:25 volumio volumio[897]: info: ------------------------------ 11ms
Sep 08 04:11:25 volumio volumio[897]: info: ------------------------------ 10ms
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::parseState
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::parseState
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo
Sep 08 04:11:25 volumio volumio[897]: info: ControllerMpd::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::servicePushState
Sep 08 04:11:25 volumio volumio[897]: info: CorePlayQueue::getTrack 0
Sep 08 04:11:25 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Get Along, Morcheeba","artist":"Deutschlandfunk","album":null,"uri":"http://addrad.io/444y3fj","trackType":"io/444y3fj"}
Sep 08 04:11:25 volumio volumio[897]: verbose: CURRENT POSITION 0
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::syncState   stateService play
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::syncState   currentStatus stop
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:25 volumio volumio[897]: info: ControllerMpd::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::servicePushState
Sep 08 04:11:25 volumio volumio[897]: info: CorePlayQueue::getTrack 0
Sep 08 04:11:25 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Get Along, Morcheeba","artist":"Deutschlandfunk","album":null,"uri":"http://addrad.io/444y3fj","trackType":"io/444y3fj"}
Sep 08 04:11:25 volumio volumio[897]: verbose: CURRENT POSITION 0
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::syncState   stateService play
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::syncState   currentStatus play
Sep 08 04:11:25 volumio volumio[897]: info: Received an update from plugin. extracting info from payload
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:25 volumio volumio[897]: info: ------------------------------ 74ms
Sep 08 04:11:25 volumio volumio[897]: info: ------------------------------ 61ms
Sep 08 04:11:25 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo
Sep 08 04:11:25 volumio volumio[897]: info: ControllerMpd::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::servicePushState
Sep 08 04:11:25 volumio volumio[897]: info: CorePlayQueue::getTrack 0
Sep 08 04:11:25 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Get Along, Morcheeba","artist":"Deutschlandfunk","album":null,"uri":"http://addrad.io/444y3fj","trackType":"io/444y3fj"}
Sep 08 04:11:25 volumio volumio[897]: verbose: CURRENT POSITION 0
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::syncState   stateService play
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::syncState   currentStatus play
Sep 08 04:11:25 volumio volumio[897]: info: Received an update from plugin. extracting info from payload
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:25 volumio volumio[897]: info: CoreStateMachine::pushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::volumioPushState
Sep 08 04:11:25 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 08 04:11:25 volumio volumio[897]: info: ------------------------------ 102ms
... had not quite started playing yet

Lots of undefined variables there and whatever is filing the 'tracktype' field needs to be educated about webradios.

$ wget 'http://localhost:3000/api/v1/getQueue' -O -
{"queue":
[
  {"uri":"http://addrad.io/444y3fj","service":"webradio","albumart":"/albumart","samplerate":"","bitdepth":"","channels":0,"trackType":"webradio"},
  {"uri":"http://addrad.io/4WRLzh","service":"webradio","albumart":"/albumart","samplerate":"","bitdepth":0,"channels":0},
  {"uri":"http://addrad.io/4WRLM9","service":"webradio","albumart":"/albumart","samplerate":"","bitdepth":0,"channels":0}
]
}

$ cat /data/queue
[
  {
    "uri": "http://addrad.io/444y3fj",
    "service": "webradio",
    "albumart": "/albumart",
    "samplerate": "",
    "bitdepth": 0,
    "channels": 0
  },
  {
    "uri": "http://addrad.io/4WRLzh",
    "service": "webradio",
    "albumart": "/albumart",
    "samplerate": "",
    "bitdepth": 0,
    "channels": 0
  },
  {
    "uri": "http://addrad.io/4WRLM9",
    "service": "webradio",
    "albumart": "/albumart",
    "samplerate": "",
    "bitdepth": 0,
    "channels": 0
  }
]

BenediktO commented 4 years ago

I traced down which functions get called: PlaylistManager.prototype.enqueue and PlaylistManager.prototype.commonPlayPlaylist

The first one works, the second doesn't. I have a working patch:

diff --git a/app/playlistManager.js b/app/playlistManager.js
index ccb23acf..0a8393b9 100755
--- a/app/playlistManager.js
+++ b/app/playlistManager.js
@@ -702,7 +702,20 @@ PlaylistManager.prototype.commonPlayPlaylist = function (folder, name) {

             if (data[i].service === undefined) { service = 'mpd'; } else service = data[i].service;

-            uris.push({uri: uri, service: service});
+            var item = {
+              service: service,
+              uri: uri,
+              albumart: data[i].albumart
+            };
+
+            var title = data[i].title;
+            if (data[i].service === 'webradio') {
+              item.name = title;
+            }
+            else {
+              item.title = title;
+            }
+            uris.push(item);
           }

           self.commandRouter.addQueueItems(uris)

Previously only the uri and the service parameters survived, now the title/name and the albumart gets passed too. I don't have any clue why this works with service != webradio, but they still work with my patch.

This bug seem to exists for a long time: https://github.com/volumio/Volumio2/blob/b77d6a465a08399929fd75038f2d360516d04a83/app/playlistManager.js#L576

xipmix commented 4 years ago

I've tested your patch and it works, nice job. I tweaked it a little further

--- playlistManager.js.orig 2020-09-09 07:34:48.000000000 +0000
+++ playlistManager.js  2020-09-09 07:35:33.000000000 +0000
@@ -686,7 +686,17 @@

             if (data[i].service === undefined) { service = 'mpd'; } else service = data[i].service;

-            uris.push({uri: uri, service: service});
+            var item = {
+              service: service,
+              uri: uri,
+              albumart: data[i].albumart,
+              title: data[i].title
+            };
+
+            if (data[i].service === 'webradio') {
+              item.name = data[i].title;
+            }
+            uris.push(item);
           }

           self.commandRouter.addQueueItems(uris)

I also did two other quick tests

adding music from a NAS
adding a playlist of music from a NAS, with 'clear and play' which seem to work ok.

Could you make a pull request for your fix? You can add 'tested-by: xipmix@users.noreply.github.com'

BenediktO commented 4 years ago

This very file changed yesterday and I did not test this version yet. It might be fixed by now: https://github.com/volumio/Volumio2/commit/16f9aa120251ecf705fc6b47a12407c50796b245

xipmix commented 4 years ago

Actually one question: why add the 'albumart' field here? The original code didn't pass that field so I'm not sure why it should now. I can see it is more consistent with what 'enqueue' does.

xipmix commented 4 years ago

Just saw your comment - yes it looks like @volumio has fixed the issue, in a slightly different way

volumio commented 4 years ago

Yep, I just missed this conversation. My bad... Was there anything else you think I should've added?

xipmix commented 4 years ago

I should go back and check to see if 'tracktype' is handled correctly for webradios, but otherwise I think we're good.

BenediktO commented 4 years ago

Actually one question: why add the 'albumart' field here? The original code didn't pass that field so I'm not sure why it should now. I can see it is more consistent with what 'enqueue' does.

The albumart did not show up for radiostations if I didn't.

xipmix commented 4 years ago

I finally found a bit of time to check on the tracktype thing. I applied volumio's patches and tested with clear&play. Similar result but the queue does show the station name and icon correctly which is good.

I'll open a separate issue for this, because ReplaceandPlayItems has seen some work recently too - I will need to test with a more recent release.

Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioReplaceandPlayItems
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::ClearQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::stop
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 10 11:19:36 volumio volumio[10778]: UNSET VOLATILE
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::clearPlayQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::saveQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioPushQueue
Sep 10 11:19:36 volumio volumio[10778]: info: Play playlist issue1998
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioClearQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::ClearQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::stop
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 10 11:19:36 volumio volumio[10778]: UNSET VOLATILE
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::clearPlayQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::saveQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioPushQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioAddQueueItems
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::addQueueItems
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::addQueueItems
Sep 10 11:19:36 volumio volumio[10778]: info: Adding Item to queue: http://addrad.io/444y3fj
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 10 11:19:36 volumio volumio[10778]: info: Adding Item to queue: http://addrad.io/4WRLzh
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 10 11:19:36 volumio volumio[10778]: info: Adding Item to queue: http://addrad.io/4WRLM9
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::saveQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioPushQueue
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::updateTrackBlock
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::getTrackBlock
Sep 10 11:19:36 volumio volumio[10778]: info: CoreCommandRouter::volumioPlay
Sep 10 11:19:36 volumio volumio[10778]: UNSET VOLATILE
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::play index 0
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::stop
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 10 11:19:36 volumio volumio[10778]: UNSET VOLATILE
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::play index undefined
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::getTrack 0
Sep 10 11:19:36 volumio volumio[10778]: info: CoreStateMachine::startPlaybackTimer
Sep 10 11:19:36 volumio volumio[10778]: info: CorePlayQueue::getTrack 0
Sep 10 11:19:36 volumio volumio[10778]: info: [1599736776304] ControllerWebradio::clearAddPlayTrack
Sep 10 11:19:36 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand stop
Sep 10 11:19:36 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand clear
Sep 10 11:19:36 volumio volumio[10778]: info:
Sep 10 11:19:36 volumio volumio[10778]: ---------------------------- MPD announces system playlist update
Sep 10 11:19:36 volumio volumio[10778]: info: Ignoring MPD Status Update
Sep 10 11:19:36 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand load "http://addrad.io/444y3fj"
Sep 10 11:19:36 volumio volumio[10778]: error: updateQueue error: null
Sep 10 11:19:36 volumio volumio[10778]: info: ------------------------------ 13ms
Sep 10 11:19:39 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand add "http://addrad.io/444y3fj"
Sep 10 11:19:39 volumio volumio[10778]: info:
Sep 10 11:19:39 volumio volumio[10778]: ---------------------------- MPD announces system playlist update
Sep 10 11:19:39 volumio volumio[10778]: info: Ignoring MPD Status Update
Sep 10 11:19:39 volumio volumio[10778]: info: CoreStateMachine::setConsumeUpdateService mpd
Sep 10 11:19:39 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand play
Sep 10 11:19:39 volumio volumio[10778]: info: ------------------------------ 15ms
Sep 10 11:19:39 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 10 11:19:41 volumio volumio[10778]: info:
Sep 10 11:19:41 volumio volumio[10778]: ---------------------------- MPD announces state update: player
Sep 10 11:19:41 volumio volumio[10778]: info: ControllerMpd::getState
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand status
Sep 10 11:19:41 volumio volumio[10778]: info:
Sep 10 11:19:41 volumio volumio[10778]: ---------------------------- MPD announces state update: player
Sep 10 11:19:41 volumio volumio[10778]: info:
Sep 10 11:19:41 volumio volumio[10778]: ---------------------------- MPD announces system playlist update
Sep 10 11:19:41 volumio volumio[10778]: info: Ignoring MPD Status Update
Sep 10 11:19:41 volumio volumio[10778]: info: ControllerMpd::getState
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand status
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::parseState
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 10 11:19:41 volumio volumio[10778]: info:
Sep 10 11:19:41 volumio volumio[10778]: ---------------------------- MPD announces system playlist update
Sep 10 11:19:41 volumio volumio[10778]: info: Ignoring MPD Status Update
Sep 10 11:19:41 volumio volumio[10778]: info:
Sep 10 11:19:41 volumio volumio[10778]: ---------------------------- MPD announces state update: player
Sep 10 11:19:41 volumio volumio[10778]: info: ControllerMpd::getState
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand status
Sep 10 11:19:41 volumio volumio[10778]: info: ------------------------------ 32ms
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::parseState
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::parseTrackInfo
Sep 10 11:19:41 volumio volumio[10778]: info: ControllerMpd::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::servicePushState
Sep 10 11:19:41 volumio volumio[10778]: info: CorePlayQueue::getTrack 0
Sep 10 11:19:41 volumio volumio[10778]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Corona-Reisewarnungen ausgeweitet, Volker Finthammer","artist":"Deutschlandfunk","album":null,"uri":"http://addrad.io/444y3fj","trackType":"io/444y3fj"}
Sep 10 11:19:41 volumio volumio[10778]: verbose: CURRENT POSITION 0
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::syncState   stateService play
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::syncState   currentStatus stop
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:41 volumio volumio[10778]: info: ------------------------------ 105ms
Sep 10 11:19:41 volumio volumio[10778]: info: ------------------------------ 65ms
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::parseState
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::parseTrackInfo
Sep 10 11:19:41 volumio volumio[10778]: info: ControllerMpd::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::servicePushState
Sep 10 11:19:41 volumio volumio[10778]: info: CorePlayQueue::getTrack 0
Sep 10 11:19:41 volumio volumio[10778]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Corona-Reisewarnungen ausgeweitet, Volker Finthammer","artist":"Deutschlandfunk","album":null,"uri":"http://addrad.io/444y3fj","trackType":"io/444y3fj"}
Sep 10 11:19:41 volumio volumio[10778]: verbose: CURRENT POSITION 0
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::syncState   stateService play
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::syncState   currentStatus play
Sep 10 11:19:41 volumio volumio[10778]: info: Received an update from plugin. extracting info from payload
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:41 volumio volumio[10778]: info: ------------------------------ 144ms
Sep 10 11:19:41 volumio volumio[10778]: verbose: ControllerMpd::parseTrackInfo
Sep 10 11:19:41 volumio volumio[10778]: info: ControllerMpd::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::servicePushState
Sep 10 11:19:41 volumio volumio[10778]: info: CorePlayQueue::getTrack 0
Sep 10 11:19:41 volumio volumio[10778]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Corona-Reisewarnungen ausgeweitet, Volker Finthammer","artist":"Deutschlandfunk","album":null,"uri":"http://addrad.io/444y3fj","trackType":"io/444y3fj"}
Sep 10 11:19:41 volumio volumio[10778]: verbose: CURRENT POSITION 0
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::syncState   stateService play
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::syncState   currentStatus play
Sep 10 11:19:41 volumio volumio[10778]: info: Received an update from plugin. extracting info from payload
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:41 volumio volumio[10778]: info: CoreStateMachine::pushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::volumioPushState
Sep 10 11:19:41 volumio volumio[10778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 10 11:19:41 volumio volumio[10778]: info: ------------------------------ 175ms

volumio / Volumio2

Information about stations not shown when loaded from playlist #1998