webradio not playing, if the station url is a .pls playlist

sphh commented 6 years ago

I added a custom webradio to "My Web Radios" with the stream http://mp3stream2.apasf.apa.at:8000/listen.pls, then I added this web radio to the queue, switched to the queue, stopped the currently playing webradio and tried to play this stream. I get the notification that the radio is playing but it is not.

If I log into the volumio and call mpc I get error: Timeout. If I do a ps aux | grep mpd I get the following lines

mpd        607  2.4  8.2 143276 19248 ?        Ssl  20:23   0:07 /usr/bin/mpd --no-daemon
volumio    958  0.3  3.2  89316  7512 ?        Ssl  20:26   0:00 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf

I tried with another webradio with a .pls "stream" (http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls) and this works fine.

The logs are here: http://logs.volumio.org/volumio/SMx4T3j.html

xipmix commented 6 years ago

Looks like the parsing of the url you entered is incorrect, but see my question at the end.

Mar 04 20:26:05 volumio volumio[809]: info: Pushing Favourites {"service":"webradio","uri":"http://mp3stream2.apasf.apa.at:8000","favourite":false}

Then there's this...reformatted for readability. The uri is incorrect and the trackType is ... incorrect.

Mar 04 20:26:17 volumio volumio[809]: info: STATE SERVICE {
 "status":"play",
 "position":0,
 "seek":496,
 "duration":0,
 "samplerate":"44.1 KHz",
 "bitdepth":"24bit",
 "channels":2,
 "random":false,
 "updatedb":false,
 "repeat":false,
 "isStreaming":false,
 "title":"Let It Bleed - Rolling Stones",
 "artist":"Radio Wien",
 "album":null,
 "uri":"http://mp3stream2.apasf.apa.at:8000",
 "trackType":"at:8000"
}

But then a little later we get this:

Mar 04 20:26:47 volumio volumio[809]: ---------------------------- MPD announces system playlist update
Mar 04 20:26:47 volumio volumio[809]: info: Ignoring MPD Status Update
Mar 04 20:26:47 volumio volumio[809]: info: parsing response...
Mar 04 20:26:47 volumio volumio[809]: info: ControllerMpd::sendMpdCommand load "http://mp3stream2.apasf.apa.at:8000/listen.pls"
Mar 04 20:26:47 volumio volumio[809]: info: sending command...
Mar 04 20:26:47 volumio volumio[809]: info:
Mar 04 20:26:47 volumio volumio[809]: info: ------------------------------ 75ms

Did you first try with http://mp3stream2.apasf.apa.at:8000 and then with http://mp3stream2.apasf.apa.at:8000/listen.pls ?

sphh commented 6 years ago

Yes, you are right. The http://mp3stream2.apasf.apa.at:8000 was played, because I have the autoplay plugin installed (and this was the first item in the playlist).

Sorry for the confusion. Should I try to play http://mp3stream2.apasf.apa.at:8000/listen.pls without playing anything first?

xipmix commented 6 years ago

I tried to reproduce this and I got it to work. (I did an OTA update from 2.362 to 2.368, on pi2)

Browse->WebRadio->MyWebRadios_menuitem(+add webradio)


Mar 05 11:38:05 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: webradio , addMyWebRadio
Mar 05 11:38:05 volumio volumio[914]: info: {"name":"test1","uri":"http://mp3stream2.apasf.apa.at:8000/listen.pls"}

* visit the my web radios list

Mar 05 11:38:17 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri

* add it to the queue

Mar 05 11:38:22 volumio volumio[914]: info: CoreStateMachine::addQueueItems Mar 05 11:38:22 volumio volumio[914]: info: CorePlayQueue::addQueueItems Mar 05 11:38:22 volumio volumio[914]: info: Adding Item to queue: http://mp3stream2.apasf.apa.at:8000/listen.pls Mar 05 11:38:22 volumio volumio[914]: info: CorePlayQueue::saveQueue Mar 05 11:38:22 volumio volumio[914]: info: CoreCommandRouter::volumioPushQueue Mar 05 11:38:22 volumio volumio[914]: info: interfaceApi::pushQueue Mar 05 11:38:22 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 05 11:38:22 volumio volumio[914]: info: CorePlayQueue::getTrackBlock

No sound so far. But then I did this
 * Queue->Hover over 'test1' item->Click on it

Mar 05 11:39:47 volumio volumio[914]: info: CoreCommandRouter::volumioPlay Mar 05 11:39:47 volumio volumio[914]: UNSET VOLATILE Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::play index 1 Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::stop Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 05 11:39:47 volumio volumio[914]: UNSET VOLATILE Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::play index undefined Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 05 11:39:47 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:47 volumio volumio[914]: info: CoreStateMachine::startPlaybackTimer Mar 05 11:39:47 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:47 volumio volumio[914]: info: [1520249987653] ControllerWebradio::clearAddPlayTrack Mar 05 11:39:47 volumio volumio[914]: DEBUG: clearAddPlayTrack uri is "http://mp3stream2.apasf.apa.at:8000/listen.pls" Mar 05 11:39:47 volumio volumio[914]: info: ControllerMpd::sendMpdCommand stop Mar 05 11:39:47 volumio volumio[914]: info: sending command... Mar 05 11:39:47 volumio volumio[914]: info: parsing response... Mar 05 11:39:47 volumio volumio[914]: info: ControllerMpd::sendMpdCommand clear Mar 05 11:39:47 volumio volumio[914]: info: sending command... Mar 05 11:39:47 volumio volumio[914]: info: Mar 05 11:39:47 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 05 11:39:47 volumio volumio[914]: info: Ignoring MPD Status Update Mar 05 11:39:47 volumio volumio[914]: info: parsing response... Mar 05 11:39:47 volumio volumio[914]: info: ControllerMpd::sendMpdCommand load "http://mp3stream2.apasf.apa.at:8000/listen.pls" Mar 05 11:39:47 volumio volumio[914]: info: sending command... Mar 05 11:39:47 volumio volumio[914]: info: Mar 05 11:39:47 volumio volumio[914]: info: ------------------------------ 20ms Mar 05 11:39:49 volumio volumio[914]: info: parsing response... Mar 05 11:39:49 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 05 11:39:49 volumio volumio[914]: info: ControllerMpd::sendMpdCommand play Mar 05 11:39:49 volumio volumio[914]: info: sending command... Mar 05 11:39:49 volumio volumio[914]: info: Mar 05 11:39:49 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 05 11:39:49 volumio volumio[914]: info: Ignoring MPD Status Update Mar 05 11:39:49 volumio volumio[914]: info: parsing response... Mar 05 11:39:49 volumio volumio[914]: info: ------------------------------ 21ms Mar 05 11:39:53 volumio volumio[914]: info: Mar 05 11:39:53 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::getState Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::sendMpdCommand status Mar 05 11:39:53 volumio volumio[914]: info: sending command... Mar 05 11:39:53 volumio volumio[914]: info: Mar 05 11:39:53 volumio volumio[914]: ---------------------------- MPD announces system playlist update Mar 05 11:39:53 volumio volumio[914]: info: Ignoring MPD Status Update Mar 05 11:39:53 volumio volumio[914]: info: Mar 05 11:39:53 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::getState Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::sendMpdCommand status Mar 05 11:39:53 volumio volumio[914]: info: sending command... Mar 05 11:39:53 volumio volumio[914]: info: parsing response... Mar 05 11:39:53 volumio volumio[914]: info: ------------------------------ 23ms Mar 05 11:39:53 volumio volumio[914]: info: parsing response... Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::parseState Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::sendMpdCommand playlistinfo Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::parseState Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::sendMpdCommand playlistinfo Mar 05 11:39:53 volumio volumio[914]: info: sending command... Mar 05 11:39:53 volumio volumio[914]: info: sending command... Mar 05 11:39:53 volumio volumio[914]: info: parsing response... Mar 05 11:39:53 volumio volumio[914]: info: parsing response... Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::parseTrackInfo Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::parseTrackInfo Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::pushState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::syncState Mar 05 11:39:53 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:53 volumio volumio[914]: info: STATE SERVICE {"status":"play","position":0,"seek":481,"duration":0,"samplerate":"44.1 KHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":"California Dreamin' - Mamas & Papas","artist":"Radio Wien","album":null,"uri":"http://mp3stream2.apasf.apa.at:8000/","trackType":"at:8000/"} Mar 05 11:39:53 volumio volumio[914]: info: CURRENT POSITION 1 Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus stop Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::pushState Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::getState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 05 11:39:53 volumio volumio[914]: info: interfaceApi::pushState Mar 05 11:39:53 volumio volumio[914]: info: ControllerMpd::pushState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::syncState Mar 05 11:39:53 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:53 volumio volumio[914]: info: STATE SERVICE {"status":"play","position":0,"seek":481,"duration":0,"samplerate":"44.1 KHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":"California Dreamin' - Mamas & Papas","artist":"Radio Wien","album":null,"uri":"http://mp3stream2.apasf.apa.at:8000/","trackType":"at:8000/"} Mar 05 11:39:53 volumio volumio[914]: info: CURRENT POSITION 1 Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::syncState stateService play Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::syncState currentStatus play Mar 05 11:39:53 volumio volumio[914]: info: Received an update from plaugin. extracting info from payload Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::pushState Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::getState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 05 11:39:53 volumio volumio[914]: info: interfaceApi::pushState Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::pushState Mar 05 11:39:53 volumio volumio[914]: info: CoreStateMachine::getState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 05 11:39:53 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 05 11:39:53 volumio volumio[914]: info: interfaceApi::pushState Mar 05 11:39:53 volumio volumio[914]: info: ------------------------------ 264ms Mar 05 11:39:53 volumio volumio[914]: info: ------------------------------ 247ms Mar 05 11:39:53 volumio volumio[914]: info: Pushing Favourites {"service":"mpd","favourite":false} Mar 05 11:39:53 volumio volumio[914]: info: Pushing Favourites {"service":"webradio","uri":"http://mp3stream2.apasf.apa.at:8000/","favourite":false} Mar 05 11:39:53 volumio volumio[914]: info: Pushing Favourites {"service":"webradio","uri":"http://mp3stream2.apasf.apa.at:8000/","favourite":false} Mar 05 11:39:54 volumio volumio[914]: info: CoreCommandRouter::volumioStop Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::stop Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 05 11:39:54 volumio volumio[914]: UNSET VOLATILE Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::stPlaybackTimer Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::updateTrackBlock Mar 05 11:39:54 volumio volumio[914]: info: CorePlayQueue::getTrackBlock Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::pushState Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::getState Mar 05 11:39:54 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:54 volumio volumio[914]: info: CoreCommandRouter::volumioPushState Mar 05 11:39:54 volumio volumio[914]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 05 11:39:54 volumio volumio[914]: info: interfaceApi::pushState Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::serviceStop Mar 05 11:39:54 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:54 volumio volumio[914]: info: CoreCommandRouter::serviceStop Mar 05 11:39:54 volumio volumio[914]: info: [1520249994576] ControllerWebradio::stop Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::sendMpdCommand stop Mar 05 11:39:54 volumio volumio[914]: info: sending command... Mar 05 11:39:54 volumio volumio[914]: info: Pushing Favourites {"service":"webradio","uri":"http://mp3stream2.apasf.apa.at:8000/listen.pls","favourite":false} Mar 05 11:39:54 volumio volumio[914]: info: Mar 05 11:39:54 volumio volumio[914]: ---------------------------- MPD announces state update: player Mar 05 11:39:54 volumio volumio[914]: info: parsing response... Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::getState Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::sendMpdCommand status Mar 05 11:39:54 volumio volumio[914]: info: sending command... Mar 05 11:39:54 volumio volumio[914]: info: parsing response... Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::parseState Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::sendMpdCommand playlistinfo Mar 05 11:39:54 volumio volumio[914]: info: sending command... Mar 05 11:39:54 volumio volumio[914]: info: parsing response... Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::parseTrackInfo Mar 05 11:39:54 volumio volumio[914]: info: ControllerMpd::pushState Mar 05 11:39:54 volumio volumio[914]: info: CoreCommandRouter::servicePushState Mar 05 11:39:54 volumio volumio[914]: info: CoreStateMachine::syncState Mar 05 11:39:54 volumio volumio[914]: info: CorePlayQueue::getTrack 1 Mar 05 11:39:54 volumio volumio[914]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd


So I can get the webradio to play but there are some issues. The ```listen.pls``` is getting stripped somewhere and the ```trackType``` is incorrect.

It would help if you could generate one more log file:
 * remove ```http://mp3stream2.apasf.apa.at:8000/listen.pls``` from the custom web radios & play queue
 * reboot
 * add ```http://mp3stream2.apasf.apa.at:8000/listen.pls``` and try to play it
 * wait a minute or two to give a gap in the log
 * add ```http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls``` and try to play it
 * submit the log

xipmix commented 6 years ago

PS I don't have the autoplay plugin but I don't see it make an appearance in your log, so I don't think it matters at the moment.

xipmix commented 6 years ago

See also #581 and comments in #1116

sphh commented 6 years ago

Thank you @xipmix for looking into this. I don't think that #581 or #1116 are problems related to it.

I believe the problem lies with the mpd player. I de-installed the autoplay plug-in, logged into the freshly booted volumio and did the following:

Play http://mp3stream2.apasf.apa.at:8000/listen.pls

$ mpc status
volume: 40%   repeat: off   random: off   single: off   consume: off
$ mpc clear
volume: 40%   repeat: off   random: off   single: off   consume: off
$ mpc load http://mp3stream2.apasf.apa.at:8000/listen.pls
loading: http://mp3stream2.apasf.apa.at:8000/listen.pls
error: Timeout
$ mpc clear
error: Timeout
$ service mpd status
● mpd.service - Music Player Daemon
   Loaded: loaded (/lib/systemd/system/mpd.service; enabled)
   Active: active (running) since Mon 2018-03-05 17:53:31 UTC; 3min 56s ago
     Docs: man:mpd(1)
           man:mpd.conf(5)
 Main PID: 604 (mpd)
   CGroup: /system.slice/mpd.service
           └─604 /usr/bin/mpd --no-daemon

Mar 05 17:53:31 volumio systemd[1]: Started Music Player Daemon.
$ service mpd stop

[long wait]

$ service mpd status
● mpd.service - Music Player Daemon
   Loaded: loaded (/lib/systemd/system/mpd.service; enabled)
   Active: failed (Result: signal) since Mon 2018-03-05 17:59:48 UTC; 5s ago
     Docs: man:mpd(1)
           man:mpd.conf(5)
  Process: 604 ExecStart=/usr/bin/mpd --no-daemon (code=killed, signal=KILL)
 Main PID: 604 (code=killed, signal=KILL)

Mar 05 17:53:31 volumio systemd[1]: Started Music Player Daemon.
Mar 05 17:58:18 volumio systemd[1]: Stopping Music Player Daemon...
Mar 05 17:59:48 volumio systemd[1]: mpd.service stop-sigterm timed out. Killing.
Mar 05 17:59:48 volumio systemd[1]: mpd.service: main process exited, code=...LL
Mar 05 17:59:48 volumio systemd[1]: Stopped Music Player Daemon.
Mar 05 17:59:48 volumio systemd[1]: Unit mpd.service entered failed state.
Hint: Some lines were ellipsized, use -l to show in full.
$ ps aux | grep mpd
volumio    952  0.2  3.2  89316  7620 ?        Ssl  17:55   0:00 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf
volumio   1133  0.0  0.6   4148  1564 pts/0    S+   18:00   0:00 grep mpd

I restarted the volumio and did the same with http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls

$ mpc status
volume: 40%   repeat: off   random: off   single: off   consume: off
$ mpc clear
volume: 40%   repeat: off   random: off   single: off   consume: off
$ mpc load http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls
loading: http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls
$ mpc play
BBC World Service English Radio
[playing] #1/2   0:00/0:00 (0%)
volume: 40%   repeat: off   random: off   single: off   consume: off

This works flawlessly.

Does this help in any way?

sphh commented 6 years ago

I followed your procedure at the bottom of https://github.com/volumio/Volumio2/issues/1500#issuecomment-370395844

The logfile is at http://logs.volumio.org/volumio/KdVhOue.html.

xipmix commented 6 years ago

Thanks for taking the time to do the log. Unfortunately I'm unable to extract any new clues from it - there are no obvious errors being thrown, or warnings about unexpected/undefined values.

I'll paste the two log chunks here to make it easier for more expert eyes to compare.

add http://mp3stream2.apasf.apa.at:8000/listen.pls and try to play it

Mar 05 20:04:01 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Mar 05 20:04:01 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 05 20:04:35 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: webradio , addMyWebRadio
Mar 05 20:04:35 volumio volumio[802]: info: {"name":"ORF Radio Wien","uri":"http://mp3stream2.apasf.apa.at:8000/listen.pls"}
Mar 05 20:04:38 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Mar 05 20:04:56 volumio volumio[802]: info: CoreCommandRouter::volumioAddQueueItems
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::addQueueItems
Mar 05 20:04:56 volumio volumio[802]: info: CorePlayQueue::addQueueItems
Mar 05 20:04:56 volumio volumio[802]: info: Adding Item to queue: http://mp3stream2.apasf.apa.at:8000/listen.pls
Mar 05 20:04:56 volumio volumio[802]: info: CorePlayQueue::saveQueue
Mar 05 20:04:56 volumio volumio[802]: info: CoreCommandRouter::volumioPushQueue
Mar 05 20:04:56 volumio volumio[802]: info: interfaceApi::pushQueue
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::updateTrackBlock
Mar 05 20:04:56 volumio volumio[802]: info: CorePlayQueue::getTrackBlock
Mar 05 20:04:56 volumio volumio[802]: info: CoreCommandRouter::volumioPlay
Mar 05 20:04:56 volumio volumio[802]: UNSET VOLATILE
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::play index 6
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::stop
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 05 20:04:56 volumio volumio[802]: UNSET VOLATILE
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::play index undefined
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 05 20:04:56 volumio volumio[802]: info: CorePlayQueue::getTrack 6
Mar 05 20:04:56 volumio volumio[802]: info: CoreStateMachine::startPlaybackTimer
Mar 05 20:04:56 volumio volumio[802]: info: CorePlayQueue::getTrack 6
Mar 05 20:04:56 volumio volumio[802]: info: [1520280296469] ControllerWebradio::clearAddPlayTrack
Mar 05 20:04:56 volumio volumio[802]: info: ControllerMpd::sendMpdCommand stop
Mar 05 20:04:56 volumio volumio[802]: info: sending command...
Mar 05 20:04:56 volumio volumio[802]: info: parsing response...
Mar 05 20:04:56 volumio volumio[802]: info: ControllerMpd::sendMpdCommand clear
Mar 05 20:04:56 volumio volumio[802]: info: sending command...
Mar 05 20:04:56 volumio volumio[802]: info:
Mar 05 20:04:56 volumio volumio[802]: ---------------------------- MPD announces system playlist update
Mar 05 20:04:56 volumio volumio[802]: info: Ignoring MPD Status Update
Mar 05 20:04:56 volumio volumio[802]: info: parsing response...
Mar 05 20:04:56 volumio volumio[802]: info: ControllerMpd::sendMpdCommand load "http://mp3stream2.apasf.apa.at:8000/listen.pls"
Mar 05 20:04:56 volumio volumio[802]: info: sending command...
Mar 05 20:04:56 volumio volumio[802]: info:
Mar 05 20:04:56 volumio volumio[802]: info: ------------------------------ 117ms

add http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls and try to play it

Mar 05 20:07:25 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Mar 05 20:07:40 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: webradio , addMyWebRadio
Mar 05 20:07:40 volumio volumio[802]: info: {"name":"BBC World Service","uri":"http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls"}
Mar 05 20:07:42 volumio volumio[802]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Mar 05 20:07:47 volumio volumio[802]: info: CoreCommandRouter::volumioAddQueueItems
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::addQueueItems
Mar 05 20:07:47 volumio volumio[802]: info: CorePlayQueue::addQueueItems
Mar 05 20:07:47 volumio volumio[802]: info: Adding Item to queue: http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls
Mar 05 20:07:47 volumio volumio[802]: info: CorePlayQueue::saveQueue
Mar 05 20:07:47 volumio volumio[802]: info: CoreCommandRouter::volumioPushQueue
Mar 05 20:07:47 volumio volumio[802]: info: interfaceApi::pushQueue
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::updateTrackBlock
Mar 05 20:07:47 volumio volumio[802]: info: CorePlayQueue::getTrackBlock
Mar 05 20:07:47 volumio volumio[802]: info: CoreCommandRouter::volumioPlay
Mar 05 20:07:47 volumio volumio[802]: UNSET VOLATILE
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::play index 7
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::stop
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 05 20:07:47 volumio volumio[802]: UNSET VOLATILE
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::play index undefined
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 05 20:07:47 volumio volumio[802]: info: CorePlayQueue::getTrack 7
Mar 05 20:07:47 volumio volumio[802]: info: CoreStateMachine::startPlaybackTimer
Mar 05 20:07:47 volumio volumio[802]: info: CorePlayQueue::getTrack 7
Mar 05 20:07:47 volumio volumio[802]: info: [1520280467406] ControllerWebradio::clearAddPlayTrack
Mar 05 20:07:47 volumio volumio[802]: info: ControllerMpd::sendMpdCommand stop
Mar 05 20:07:47 volumio volumio[802]: info: sending command...
Mar 05 20:08:06 volumio volumio[802]: info: CoreCommandRouter::volumioGetState
Mar 05 20:08:06 volumio volumio[802]: info: CoreStateMachine::getState
Mar 05 20:08:06 volumio volumio[802]: info: CorePlayQueue::getTrack 7
Mar 05 20:08:06 volumio volumio[802]: info: CoreCommandRouter::volumioGetQueue
Mar 05 20:08:06 volumio volumio[802]: info: CoreStateMachine::getQueue
Mar 05 20:08:06 volumio volumio[802]: info: CorePlayQueue::getQueue

Not sure what to try next. The mpc failure you demonstrated is pretty clear. It probably needs someone to try that mpd binary with a debugger watching it, to see where it falls over. Does playing with mpc -v (verbose mode) give any clues?

It would be good to rule out the particular uri being problematic. Have you tried playing that uri with mpc on another linux box, or other streaming players?

sphh commented 6 years ago

I installed mpd/mpc packages on my Linux Mint box. The mpd version is 0.19.12:

$ mpd --version
Music Player Daemon 0.19.12

Copyright (C) 2003-2007 Warren Dukes <warren.dukes@gmail.com>
Copyright (C) 2008-2014 Max Kellermann <max@duempel.org>
This is free software; see the source for copying conditions.  There is NO
warranty; not even MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Database plugins:
 simple proxy upnp

Storage plugins:
 local smbclient nfs

Neighbor plugins:
 smbclient upnp

Decoders plugins:
 [mad] mp3 mp2
 [mpg123] mp3
 [vorbis] ogg oga
 [oggflac] ogg oga
 [flac] flac
 [opus] opus ogg oga
 [sndfile] wav aiff aif au snd paf iff svx sf voc w64 pvf xi htk caf sd2
 [audiofile] wav au aiff aif
 [dsdiff] dff
 [dsf] dsf
 [faad] aac
 [mpcdec] mpc
 [wavpack] wv
 [modplug] 669 amf ams dbm dfm dsm far it med mdl mod mtm mt2 okt s3m stm ult umx xm
 [mikmod] amf dsm far gdm imf it med mod mtm s3m stm stx ult uni xm
 [sidplay] sid mus str prg P00
 [wildmidi] mid
 [fluidsynth] mid
 [adplug] amd d00 hsc laa rad raw sa2
 [ffmpeg] 16sv 3g2 3gp 4xm 8svx aa3 aac ac3 afc aif aifc aiff al alaw amr anim apc ape asf atrac au aud avi avm2 avs bap bfi c93 cak cin cmv cpk daud dct divx dts dv dvd dxa eac3 film flac flc fli fll flx flv g726 gsm gxf iss m1v m2v m2t m2ts m4a m4b m4v mad mj2 mjpeg mjpg mka mkv mlp mm mmf mov mp+ mp1 mp2 mp3 mp4 mpc mpeg mpg mpga mpp mpu mve mvi mxf nc nsv nut nuv oga ogm ogv ogx oma ogg omg opus psp pva qcp qt r3d ra ram rl2 rm rmvb roq rpl rvc shn smk snd sol son spx str swf tgi tgq tgv thp ts tsp tta xa xvid uv uv2 vb vid vob voc vp6 vmd wav webm wma wmv wsaud wsvga wv wve
 [gme] ay gbs gym hes kss nsf nsfe sap spc vgm vgz
 [pcm]

Output plugins:
 shout null fifo pipe alsa roar ao oss openal pulse jack httpd recorder

Encoder plugins:
 null vorbis opus lame wave flac

Archive plugins:
 [bz2] bz2
 [zzip] zip
 [iso] iso

Input plugins:
 file alsa archive curl ffmpeg smbclient nfs mms cdio_paranoia

Playlist plugins:
 extm3u m3u pls xspf asx rss soundcloud cue embcue

Protocols:
 file:// http:// https:// mms:// mmsh:// mmst:// mmsu:// gopher:// rtp:// rtsp:// rtmp:// rtmpt:// rtmps:// smb:// nfs:// cdda:// alsa://

Playing the http://mp3stream2.apasf.apa.at:8000/listen.pls stream works without problem (so does http://www.bbc.co.uk/worldservice/meta/live/mp3/eneuk.pls). If you need it, I can post the output of mpd --version on my Raspberry Pi, when I get home.

xipmix commented 6 years ago

Nice work. So that confirms the stream is not 'funky'.

On volumio 2.368 I get 0.20.6 (19fa3c9) from mpd --version. I think we'll need help from @volumio here to get much further.

sphh commented 6 years ago

Same mpd version here.

I tried to compile the most recent mpd, but have dependency problems for the build environment (libupnp-dev : Depends: libupnp6-dev (>= 1:1.6.19+git20141001-1+deb8u1) but it is not going to be installed).

Has anybody access to a compiled mpd executable of its most recent variant? I could try to load this mischievous url in this mpd ...

xipmix commented 6 years ago

If you search the issues (maybe Build too) you should find some urls where people have downloaded from.

macmpi commented 6 years ago

FWIW, interim v2.330 contained a more recent mpd test build, but it had other shortcomings...

volumio / Volumio2

webradio not playing, if the station url is a .pls playlist #1500