Issues switching from Local playback < > Spotify

First of all I want to thank all the contributors to the Volumio project for the wonderful piece of software they’ve created.

Unfortunately, I keep running into a rather annoying problem:
After a reboot, if I keep on listening to either local music (NAS) or Spotify, everything is fine.
But as soon as I switch from one to the other, the audio either stops or I get “Failed to open audio output” errors.

This is my setup:

  • Raspberry Pi 3
  • Pifi Dac+ V2.0

You can find my playback settings below.

Here are the logs I managed to capture while trying to switch from Spotify to local playback:

[code]login as: volumio
volumio@192.168.2.233’s password:
___
/_ \ __
__ __ //\ \ __ __ ___ ___ /_\ ___
/\ /\ \ / __\\ \ \ /\ \/\ \ /' __ __\/\ \ / __
\ \ _/ |/\ \L\ \
\ _\ \ _\ /\ /\ /\ \ \ /\ \L\
\ _
/ \ _//_\ _/\ _\ _\ _\ _\ _/
// // // // /////////___/

         Free Audiophile Linux Music Player - Version 2.0

      C 2015 Michelangelo Guarise - Volumio Team - Volumio.org

Volumio Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
volumio@volumio:~$ sudo journalctl -f
– Logs begin at Tue 2017-02-21 20:39:35 UTC. –
Feb 21 20:42:02 volumio systemd[983]: Starting Basic System.
Feb 21 20:42:02 volumio systemd[983]: Reached target Basic System.
Feb 21 20:42:02 volumio systemd[983]: Starting Default.
Feb 21 20:42:02 volumio systemd[983]: Reached target Default.
Feb 21 20:42:02 volumio systemd[983]: Startup finished in 32ms.
Feb 21 20:42:02 volumio systemd[1]: Started User Manager for UID 1000.
Feb 21 20:42:02 volumio sshd[977]: lastlog_openseek: Couldn’t stat /var/log/last log: No such file or directory
Feb 21 20:42:02 volumio sshd[977]: lastlog_openseek: Couldn’t stat /var/log/last log: No such file or directory
Feb 21 20:42:05 volumio sudo[996]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USE R=root ; COMMAND=/bin/journalctl -f
Feb 21 20:42:05 volumio sudo[996]: pam_unix(sudo:session): session opened for us er root by volumio(uid=0)
Feb 21 20:42:06 volumio volumio[894]: 2017-02-21 20:42:06 [SPTF] 20:42:06.548 E [ap:4210] ChannelError(0, 0, playlist)
Feb 21 20:42:27 volumio volumio[792]: info:
Feb 21 20:42:27 volumio volumio[792]: [1487709747851] ---------------------------- Client requests Volumio play
Feb 21 20:42:27 volumio volumio[792]: info: CoreCommandRouter::volumioPlay
Feb 21 20:42:27 volumio volumio[792]: UNSET VOLATILE
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747860] CoreStateMachine::play
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747862] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747866] CorePlayQueue::getTrack 0
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747868] CoreStateMachine::startPlaybackTimer
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747872] CorePlayQueue::getTrack 0
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747875] ControllerSpop::clearAddPlayTrack
Feb 21 20:42:27 volumio volumio[792]: info: {“service”:“spop”,“type”:“song”,“name”:“Ab Ovo”,“title”:“Ab Ovo”,“artist”:“Joep Bev ing”,“album”:“Ab Ovo”,“uri”:“spotify:track:02mkkozonPEDCenOhuWwLc”,“samplerate”:“320Kbps”,“bitdepth”:“16 bit”,“trackType”:“spot ify”,“albumart”:“https://i.scdn.co/image/b57c4f9adf16f486882dc8f45afa02cca6fe1803","duration”:288}
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747880] ControllerSpop::sendSpopCommand
Feb 21 20:42:27 volumio volumio[792]: info: ADDING DEFER FOR COMMAND uplay
Feb 21 20:42:27 volumio volumio[792]: info: [1487709747902] ------------------------------ 51ms
Feb 21 20:42:28 volumio volumio[792]: info: STATUS
Feb 21 20:42:28 volumio volumio[792]: info: {
Feb 21 20:42:28 volumio volumio[792]: “status” : “playing”,
Feb 21 20:42:28 volumio volumio[792]: “repeat” : false,
Feb 21 20:42:28 volumio volumio[792]: “shuffle” : false,
Feb 21 20:42:28 volumio volumio[792]: “total_tracks” : 1,
Feb 21 20:42:28 volumio volumio[792]: “current_track” : 1,
Feb 21 20:42:28 volumio volumio[792]: “artist” : “Joep Beving”,
Feb 21 20:42:28 volumio volumio[792]: “title” : “Ab Ovo”,
Feb 21 20:42:28 volumio volumio[792]: “album” : “Ab Ovo”,
Feb 21 20:42:28 volumio volumio[792]: “duration” : 288000,
Feb 21 20:42:28 volumio volumio[792]: “position” : 0,
Feb 21 20:42:28 volumio volumio[792]: “uri” : “spotify:track:02mkkozonPEDCenOhuWwLc”,
Feb 21 20:42:28 volumio volumio[792]: “popularity” : 44
Feb 21 20:42:28 volumio volumio[792]: }
Feb 21 20:42:28 volumio volumio[792]: info:
Feb 21 20:42:28 volumio volumio[792]: [1487709748123] ---------------------------- Spop announces state update
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748126] ControllerSpop::parseState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748128] ControllerSpop::pushState
Feb 21 20:42:28 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748130] CoreStateMachine::syncState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748130] CorePlayQueue::getTrack 0
Feb 21 20:42:28 volumio volumio[792]: info: STATE SERVICE {“status”:“play”,“position”:0,“seek”:0,“duration”:288000,“samplerate” :“320Kbps”,“bitdepth”:null,“channels”:null,“artist”:“Joep Beving”,“title”:“Ab Ovo”,“album”:“Ab Ovo”}
Feb 21 20:42:28 volumio volumio[792]: info: CURRENT POSITION 0
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748139] CoreStateMachine::syncState stateService play
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748141] CoreStateMachine::syncState currentStatus stop
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748143] CoreStateMachine::pushState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748145] CoreStateMachine::getState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748147] CorePlayQueue::getTrack 0
Feb 21 20:42:28 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:42:28 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748154] interfaceApi::pushState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748156] InterfaceWebUI::pushState
Feb 21 20:42:28 volumio volumio[792]: info: [1487709748180] ------------------------------ 71ms
Feb 21 20:42:28 volumio volumio[792]: info: FIRST BRANCH
Feb 21 20:42:28 volumio volumio[792]: info: BEFORE: SPOP HAS 1 PROMISE IN STACK
Feb 21 20:42:28 volumio volumio[792]: info: AFTER: SPOP HAS 0 PROMISE IN STACK
Feb 21 20:42:28 volumio volumio[792]: info: Pushing Favourites {“service”:“spop”,“uri”:“spotify:track:02mkkozonPEDCenOhuWwLc”," favourite":false}
Feb 21 20:42:28 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Feb 21 20:42:30 volumio volumio[894]: 2017-02-21 20:42:30 [SPTF] 20:42:30.044 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:42:30 volumio volumio[894]: 2017-02-21 20:42:30 [SPTF] 20:42:30.822 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:42:34 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Feb 21 20:42:34 volumio volumio[792]: info: CURURI: music-library
Feb 21 20:42:38 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Feb 21 20:42:38 volumio volumio[792]: info: CURURI: playlists
Feb 21 20:42:38 volumio volumio[792]: info: [1487709758133] Listing playlists
Feb 21 20:42:40 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Feb 21 20:42:40 volumio volumio[792]: radio
Feb 21 20:42:41 volumio volumio[894]: 2017-02-21 20:42:41 [SPTF] 20:42:41.198 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:42:46 volumio volumio[894]: 2017-02-21 20:42:46 [SPTF] 20:42:46.299 E [ap:4210] ChannelError(0, 0, playlist)
Feb 21 20:42:55 volumio volumio[894]: 2017-02-21 20:42:55 [SPTF] 20:42:55.324 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:43:09 volumio volumio[894]: 2017-02-21 20:43:09 [SPTF] 20:43:09.514 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:43:14 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Feb 21 20:43:14 volumio volumio[792]: radio/myWebRadio
Feb 21 20:43:15 volumio volumio[792]: info: CoreCommandRouter::volumioAddQueueItems
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795502] CoreStateMachine::addQueueItems
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795504] CorePlayQueue::addQueueItems
Feb 21 20:43:15 volumio volumio[792]: info: uri=http://stream.fmbrussel.be, title=Bruzz FM, service=webradio
Feb 21 20:43:15 volumio volumio[792]: info: First index is 119
Feb 21 20:43:15 volumio volumio[792]: info: ADDING THIS ITEM TO QUEUE: {“uri”:“http://stream.fmbrussel.be”,“title”:“Bruzz FM”,“service”:“webradio”}
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795512] CorePlayQueue::saveQueue
Feb 21 20:43:15 volumio volumio[792]: info: Adding item to queue: {“uri”:“http://stream.fmbrussel.be”,“title”:“Bruzz FM”,“service”:“webradio”,“name”:“Bruzz FM”,“albumart”:"/albumart",“samplerate”:"",“bitdepth”:0,“channels”:0}
Feb 21 20:43:15 volumio volumio[792]: info: CoreCommandRouter::volumioPushQueue
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795528] interfaceApi::pushQueue
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795529] InterfaceWebUI::pushQueue
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795551] CoreStateMachine::updateTrackBlock
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795553] CorePlayQueue::getTrackBlock
Feb 21 20:43:15 volumio volumio[792]: info: CoreCommandRouter::volumioPlay
Feb 21 20:43:15 volumio volumio[792]: UNSET VOLATILE
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795557] CoreStateMachine::play
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795558] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795560] CoreStateMachine::stop
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795561] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795562] CoreStateMachine::stPlaybackTimer
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795563] CoreStateMachine::updateTrackBlock
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795564] CorePlayQueue::getTrackBlock
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795565] CoreStateMachine::pushState
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795566] CoreStateMachine::getState
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795567] CorePlayQueue::getTrack 119
Feb 21 20:43:15 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:43:15 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795573] interfaceApi::pushState
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795574] InterfaceWebUI::pushState
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795590] CoreStateMachine::serviceStop
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795590] CorePlayQueue::getTrack 119
Feb 21 20:43:15 volumio volumio[792]: info: CoreCommandRouter::serviceStop
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795593] ControllerWebradio::stop
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795595] ControllerMpd::sendMpdCommand stop
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795598] sending command…
Feb 21 20:43:15 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://stream.fmbrussel.be”,“favourite”:false}
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795613] parsing response…
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795616] CoreStateMachine::play
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795617] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795619] CorePlayQueue::getTrack 119
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795620] CoreStateMachine::startPlaybackTimer
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795621] CorePlayQueue::getTrack 119
Feb 21 20:43:15 volumio volumio[792]: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa[object Object]
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795624] ControllerWebradio::clearAddPlayTrack
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795625] ControllerMpd::sendMpdCommand stop
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795627] sending command…
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795642] parsing response…
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795644] ControllerMpd::sendMpdCommand clear
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795645] sending command…
Feb 21 20:43:15 volumio volumio[792]: info:
Feb 21 20:43:15 volumio volumio[792]: [1487709795647] ---------------------------- MPD announces system state update
Feb 21 20:43:15 volumio volumio[792]: info: Mpd Status Update: playlist
Feb 21 20:43:15 volumio volumio[792]: info:
Feb 21 20:43:15 volumio volumio[792]: [1487709795651] ---------------------------- MPD announces state update
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795653] parsing response…
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795655] ControllerMpd::getState
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795656] ControllerMpd::sendMpdCommand status
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795657] ControllerMpd::sendMpdCommand load “http://stream.fmbrussel.be
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795659] sending command…
Feb 21 20:43:15 volumio volumio[792]: info: [1487709795660] sending command…
Feb 21 20:43:15 volumio nmbd[666]: [2017/02/21 20:43:15.733049, 0] …/lib/util/debug.c:603(reopen_logs_internal)
Feb 21 20:43:15 volumio nmbd[666]: Unable to open new log file ‘/var/log/samba/log.nmbd’: No such file or directory
Feb 21 20:43:16 volumio volumio[894]: 2017-02-21 20:43:16 [SPTF] 20:43:16.107 E [ap:4210] ChannelError(0, 1, playlist)
Feb 21 20:43:17 volumio mpd[558]: playlist: No such playlist
Feb 21 20:43:17 volumio volumio[792]: info:
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797268] ------------------------------ 1621ms
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797269] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797271] ControllerMpd::sendMpdCommand add “http://stream.fmbrussel.be
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797274] ControllerMpd::parseState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797275] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797276] ControllerMpd::pushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797278] CoreStateMachine::syncState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797279] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797280] Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797281] ------------------------------ 1631ms
Feb 21 20:43:17 volumio volumio[792]: info:
Feb 21 20:43:17 volumio volumio[792]: [1487709797283] ---------------------------- MPD announces system state update
Feb 21 20:43:17 volumio volumio[792]: info: Mpd Status Update: playlist
Feb 21 20:43:17 volumio volumio[792]: info:
Feb 21 20:43:17 volumio volumio[792]: [1487709797285] ---------------------------- MPD announces state update
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797286] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797287] ControllerMpd::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797288] ControllerMpd::sendMpdCommand status
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797290] CoreStateMachine::setConsumeUpdateService mpd
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797291] ControllerMpd::sendMpdCommand play
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797292] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797293] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797326] ------------------------------ 43ms
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797327] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797327] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797328] ControllerMpd::parseState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797329] ControllerMpd::pushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797331] CoreStateMachine::syncState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797332] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Feb 21 20:43:17 volumio volumio[792]: info: CURRENT POSITION 119
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797335] CoreStateMachine::syncState stateService stop
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797336] CoreStateMachine::syncState currentStatus stop
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797341] CoreStateMachine::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797342] CoreStateMachine::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797342] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797348] interfaceApi::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797349] InterfaceWebUI::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797366] No code
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797368] CoreStateMachine::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797369] CoreStateMachine::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797370] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797373] interfaceApi::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797374] InterfaceWebUI::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797394] ------------------------------ 110ms
Feb 21 20:43:17 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://stream.fmbrussel.be”,“favourite”:false}
Feb 21 20:43:17 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://stream.fmbrussel.be”,“favourite”:false}
Feb 21 20:43:17 volumio mpd[558]: alsa_output: Failed to open “alsa” [alsa]: Failed to open ALSA device “hw:1,0”: Device or resource busy
Feb 21 20:43:17 volumio mpd[558]: output: Failed to open audio output
Feb 21 20:43:17 volumio mpd[558]: player: problems opening audio device while playing “http://stream.fmbrussel.be
Feb 21 20:43:17 volumio volumio[792]: info: Mpd Status Update: player
Feb 21 20:43:17 volumio volumio[792]: info:
Feb 21 20:43:17 volumio volumio[792]: [1487709797489] ---------------------------- MPD announces state update
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797490] ControllerMpd::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797491] ControllerMpd::sendMpdCommand status
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797492] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: Mpd Status Update: player
Feb 21 20:43:17 volumio volumio[792]: info:
Feb 21 20:43:17 volumio volumio[792]: [1487709797494] ---------------------------- MPD announces state update
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797495] ControllerMpd::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797496] ControllerMpd::sendMpdCommand status
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797497] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797533] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797543] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797551] ControllerMpd::parseState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797558] ControllerMpd::sendMpdCommand playlistinfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797560] ControllerMpd::parseState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797563] ControllerMpd::sendMpdCommand playlistinfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797565] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797568] sending command…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797571] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797574] ControllerMpd::parseTrackInfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797578] ControllerMpd::pushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797581] CoreStateMachine::syncState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797583] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: STATE SERVICE {“status”:“pause”,“position”:0,“seek”:0,“duration”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“stream.fmbrussel.be”,“artist”:null,“album”:null,“uri”:“http://stream.fmbrussel.be”,“trackType”:“be”}
Feb 21 20:43:17 volumio volumio[792]: info: CURRENT POSITION 119
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797597] CoreStateMachine::syncState stateService pause
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797599] CoreStateMachine::syncState currentStatus stop
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797601] CoreStateMachine::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797604] CoreStateMachine::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797606] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797613] interfaceApi::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797615] InterfaceWebUI::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797640] ------------------------------ 152ms
Feb 21 20:43:17 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://stream.fmbrussel.be”,“favourite”:false}
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797681] parsing response…
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797682] ControllerMpd::parseTrackInfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797684] ControllerMpd::pushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797685] CoreStateMachine::syncState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797685] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: STATE SERVICE {“status”:“pause”,“position”:0,“seek”:0,“duration”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“stream.fmbrussel.be”,“artist”:null,“album”:null,“uri”:“http://stream.fmbrussel.be”,“trackType”:“be”}
Feb 21 20:43:17 volumio volumio[792]: info: CURRENT POSITION 119
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797690] CoreStateMachine::syncState stateService pause
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797691] CoreStateMachine::syncState currentStatus stop
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797692] CoreStateMachine::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797693] CoreStateMachine::getState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797694] CorePlayQueue::getTrack 119
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:43:17 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797701] interfaceApi::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797703] InterfaceWebUI::pushState
Feb 21 20:43:17 volumio volumio[792]: info: [1487709797725] ------------------------------ 231ms
Feb 21 20:43:17 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://stream.fmbrussel.be”,“favourite”:false}
Feb 21 20:43:23 volumio volumio[894]: 2017-02-21 20:43:23 [SPTF] 20:43:23.902 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:43:38 volumio volumio[894]: 2017-02-21 20:43:38 [SPTF] 20:43:38.063 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:43:52 volumio volumio[894]: 2017-02-21 20:43:52 [SPTF] 20:43:52.478 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:43:53 volumio volumio[894]: 2017-02-21 20:43:53 [SPTF] 20:43:53.802 E [ap:4210] ChannelError(0, 0, playlist)
Feb 21 20:44:06 volumio volumio[894]: 2017-02-21 20:44:06 [SPTF] 20:44:06.674 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:44:20 volumio volumio[894]: 2017-02-21 20:44:20 [SPTF] 20:44:20.693 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:44:25 volumio volumio[792]: info: CoreCommandRouter::volumioAddQueueItems
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865666] CoreStateMachine::addQueueItems
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865667] CorePlayQueue::addQueueItems
Feb 21 20:44:25 volumio volumio[792]: info: uri=http://radio.intergalacticfm.com/5.m3u, title=Intergalactic FM - The Garden, service=webradio
Feb 21 20:44:25 volumio volumio[792]: info: First index is 120
Feb 21 20:44:25 volumio volumio[792]: info: ADDING THIS ITEM TO QUEUE: {“uri”:“http://radio.intergalacticfm.com/5.m3u",“title”:"Intergalactic FM - The Garden”,“service”:“webradio”}
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865672] CorePlayQueue::saveQueue
Feb 21 20:44:25 volumio volumio[792]: info: Adding item to queue: {“uri”:“http://radio.intergalacticfm.com/5.m3u",“title”:"Intergalactic FM - The Garden”,“service”:“webradio”,“name”:“Intergalactic FM - The Garden”,“albumart”:"/albumart",“samplerate”:"",“bitdepth”:0,“channels”:0}
Feb 21 20:44:25 volumio volumio[792]: info: CoreCommandRouter::volumioPushQueue
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865684] interfaceApi::pushQueue
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865686] InterfaceWebUI::pushQueue
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865698] CoreStateMachine::updateTrackBlock
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865698] CorePlayQueue::getTrackBlock
Feb 21 20:44:25 volumio volumio[792]: info: CoreCommandRouter::volumioPlay
Feb 21 20:44:25 volumio volumio[792]: UNSET VOLATILE
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865701] CoreStateMachine::play
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865702] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865703] CoreStateMachine::stop
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865705] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865706] CoreStateMachine::play
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865707] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865708] CorePlayQueue::getTrack 120
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865709] CoreStateMachine::startPlaybackTimer
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865710] CorePlayQueue::getTrack 120
Feb 21 20:44:25 volumio volumio[792]: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa[object Object]
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865711] ControllerWebradio::clearAddPlayTrack
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865712] ControllerMpd::sendMpdCommand stop
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865714] sending command…
Feb 21 20:44:25 volumio mpd[558]: player: played “http://stream.fmbrussel.be
Feb 21 20:44:25 volumio volumio[792]: info: Mpd Status Update: player
Feb 21 20:44:25 volumio volumio[792]: info:
Feb 21 20:44:25 volumio volumio[792]: [1487709865721] ---------------------------- MPD announces state update
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865722] parsing response…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865723] ControllerMpd::getState
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865724] ControllerMpd::sendMpdCommand status
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865725] ControllerMpd::sendMpdCommand clear
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865739] sending command…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865740] sending command…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865762] parsing response…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865765] parsing response…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865766] ControllerMpd::parseState
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865767] ControllerMpd::sendMpdCommand playlistinfo
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865768] ControllerMpd::sendMpdCommand load “http://radio.intergalacticfm.com/5.m3u
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865769] sending command…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865770] sending command…
Feb 21 20:44:25 volumio volumio[792]: info:
Feb 21 20:44:25 volumio volumio[792]: [1487709865772] ---------------------------- MPD announces system state update
Feb 21 20:44:25 volumio volumio[792]: info: Mpd Status Update: playlist
Feb 21 20:44:25 volumio volumio[792]: info:
Feb 21 20:44:25 volumio volumio[792]: [1487709865774] ---------------------------- MPD announces state update
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865775] ControllerMpd::getState
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865776] ControllerMpd::sendMpdCommand status
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865777] parsing response…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865778] sending command…
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865780] ControllerMpd::parseTrackInfo
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865781] ControllerMpd::pushState
Feb 21 20:44:25 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865782] CoreStateMachine::syncState
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865783] CorePlayQueue::getTrack 120
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865784] Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd
Feb 21 20:44:25 volumio volumio[792]: info: [1487709865785] ------------------------------ 65ms
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866412] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866413] ------------------------------ 641ms
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866414] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866418] CoreStateMachine::setConsumeUpdateService mpd
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866419] ControllerMpd::sendMpdCommand play
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866419] ControllerMpd::parseState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866421] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866425] ControllerMpd::pushState
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866427] CoreStateMachine::syncState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866428] CorePlayQueue::getTrack 120
Feb 21 20:44:26 volumio volumio[792]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Feb 21 20:44:26 volumio volumio[792]: info: CURRENT POSITION 120
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866430] CoreStateMachine::syncState stateService stop
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866431] CoreStateMachine::syncState currentStatus stop
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866433] CoreStateMachine::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866434] CoreStateMachine::getState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866435] CorePlayQueue::getTrack 120
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866440] interfaceApi::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866441] InterfaceWebUI::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866459] No code
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866460] CoreStateMachine::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866463] CoreStateMachine::getState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866463] CorePlayQueue::getTrack 120
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866467] interfaceApi::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866468] InterfaceWebUI::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866498] ------------------------------ 725ms
Feb 21 20:44:26 volumio volumio[792]: info:
Feb 21 20:44:26 volumio volumio[792]: [1487709866508] ---------------------------- MPD announces system state update
Feb 21 20:44:26 volumio volumio[792]: info: Mpd Status Update: playlist
Feb 21 20:44:26 volumio volumio[792]: info:
Feb 21 20:44:26 volumio volumio[792]: [1487709866510] ---------------------------- MPD announces state update
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866515] ControllerMpd::getState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866516] ControllerMpd::sendMpdCommand status
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866517] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866520] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://radio.intergalacticfm.com/5.m3u","favourite”:false}
Feb 21 20:44:26 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://radio.intergalacticfm.com/5.m3u","favourite”:false}
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866541] ------------------------------ 33ms
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866552] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866554] ControllerMpd::parseState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866555] ControllerMpd::sendMpdCommand playlistinfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866556] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866558] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866559] ControllerMpd::parseTrackInfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866560] ControllerMpd::pushState
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866561] CoreStateMachine::syncState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866562] CorePlayQueue::getTrack 120
Feb 21 20:44:26 volumio volumio[792]: info: STATE SERVICE {“status”:“play”,“position”:0,“seek”:0,“duration”:0,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“5”,“artist”:null,“album”:null,“uri”:“http://5.79.70.19:80/5",“trackType”:"19:80/5”}
Feb 21 20:44:26 volumio volumio[792]: info: CURRENT POSITION 120
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866565] CoreStateMachine::syncState stateService play
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866566] CoreStateMachine::syncState currentStatus stop
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866567] CoreStateMachine::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866568] CoreStateMachine::getState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866569] CorePlayQueue::getTrack 120
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866572] interfaceApi::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866573] InterfaceWebUI::pushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866593] ------------------------------ 84ms
Feb 21 20:44:26 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://radio.intergalacticfm.com/5.m3u","favourite”:false}
Feb 21 20:44:26 volumio mpd[558]: alsa_output: Failed to open “alsa” [alsa]: Failed to open ALSA device “hw:1,0”: Device or resource busy
Feb 21 20:44:26 volumio mpd[558]: output: Failed to open audio output
Feb 21 20:44:26 volumio mpd[558]: player: problems opening audio device while playing “http://5.79.70.19:80/5
Feb 21 20:44:26 volumio volumio[792]: info: Mpd Status Update: player
Feb 21 20:44:26 volumio volumio[792]: info:
Feb 21 20:44:26 volumio volumio[792]: [1487709866898] ---------------------------- MPD announces state update
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866899] ControllerMpd::getState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866900] ControllerMpd::sendMpdCommand status
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866901] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: Mpd Status Update: player
Feb 21 20:44:26 volumio volumio[792]: info:
Feb 21 20:44:26 volumio volumio[792]: [1487709866904] ---------------------------- MPD announces state update
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866905] ControllerMpd::getState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866906] ControllerMpd::sendMpdCommand status
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866911] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866945] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866951] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866956] ControllerMpd::parseState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866958] ControllerMpd::sendMpdCommand playlistinfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866961] ControllerMpd::parseState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866963] ControllerMpd::sendMpdCommand playlistinfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866966] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866969] sending command…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866975] parsing response…
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866978] ControllerMpd::parseTrackInfo
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866982] ControllerMpd::pushState
Feb 21 20:44:26 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866987] CoreStateMachine::syncState
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866989] CorePlayQueue::getTrack 120
Feb 21 20:44:26 volumio volumio[792]: info: STATE SERVICE {“status”:“pause”,“position”:0,“seek”:0,“duration”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“5”,“artist”:null,“album”:null,“uri”:“http://5.79.70.19:80/5",“trackType”:"19:80/5”}
Feb 21 20:44:26 volumio volumio[792]: info: CURRENT POSITION 120
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866995] CoreStateMachine::syncState stateService pause
Feb 21 20:44:26 volumio volumio[792]: info: [1487709866996] CoreStateMachine::syncState currentStatus play
Feb 21 20:44:27 volumio volumio[792]: info: [1487709866997] CoreStateMachine::pushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709866999] CoreStateMachine::getState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867000] CorePlayQueue::getTrack 120
Feb 21 20:44:27 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:44:27 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867003] interfaceApi::pushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867004] InterfaceWebUI::pushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867026] ------------------------------ 129ms
Feb 21 20:44:27 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://radio.intergalacticfm.com/5.m3u","favourite”:false}
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867041] parsing response…
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867042] ControllerMpd::parseTrackInfo
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867043] ControllerMpd::pushState
Feb 21 20:44:27 volumio volumio[792]: info: CoreCommandRouter::servicePushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867044] CoreStateMachine::syncState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867045] CorePlayQueue::getTrack 120
Feb 21 20:44:27 volumio volumio[792]: info: STATE SERVICE {“status”:“pause”,“position”:0,“seek”:0,“duration”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“5”,“artist”:null,“album”:null,“uri”:“http://5.79.70.19:80/5",“trackType”:"19:80/5”}
Feb 21 20:44:27 volumio volumio[792]: info: CURRENT POSITION 120
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867047] CoreStateMachine::syncState stateService pause
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867048] CoreStateMachine::syncState currentStatus play
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867049] CoreStateMachine::pushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867050] CoreStateMachine::getState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867051] CorePlayQueue::getTrack 120
Feb 21 20:44:27 volumio volumio[792]: info: CoreCommandRouter::volumioPushState
Feb 21 20:44:27 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867054] interfaceApi::pushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867055] InterfaceWebUI::pushState
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867083] ------------------------------ 180ms
Feb 21 20:44:27 volumio volumio[792]: info: Pushing Favourites {“service”:“webradio”,“uri”:“http://radio.intergalacticfm.com/5.m3u","favourite”:false}
Feb 21 20:44:27 volumio volumio[792]: info: CALLMETHOD: audio_interface upnp stopUpnpPlayback [object Object]
Feb 21 20:44:27 volumio volumio[792]: info: CoreCommandRouter::executeOnPlugin: upnp , stopUpnpPlayback
Feb 21 20:44:27 volumio volumio[792]: info: Stopping playback through UPNP
Feb 21 20:44:27 volumio volumio[792]: info: [1487709867515] CoreStateMachine::setConsumeUpdateService undefined
Feb 21 20:44:34 volumio volumio[894]: 2017-02-21 20:44:34 [SPTF] 20:44:34.884 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:44:48 volumio volumio[894]: 2017-02-21 20:44:48 [SPTF] 20:44:48.877 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:45:03 volumio volumio[894]: 2017-02-21 20:45:03 [SPTF] 20:45:03.133 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:45:03 volumio volumio[894]: 2017-02-21 20:45:03 [SPTF] 20:45:03.923 E [ap:4210] ChannelError(0, 1, playlist)
Feb 21 20:45:17 volumio volumio[894]: 2017-02-21 20:45:17 [SPTF] 20:45:17.083 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:45:31 volumio volumio[894]: 2017-02-21 20:45:31 [SPTF] 20:45:31.072 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:45:45 volumio volumio[894]: 2017-02-21 20:45:45 [SPTF] 20:45:45.175 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
Feb 21 20:45:59 volumio volumio[894]: 2017-02-21 20:45:59 [SPTF] 20:45:59.125 I [file_streamer_simple.cpp:769] Request for file 3806923bcf4fed000ff47f7fbe349560ae9241c7 complete (code: 0)
[/code]
settings.png

There have been issues reported elsewhere on changing sources involving Spotify. No solution, just letting you know that it is known.

Thank you for the quick feedback, chsims1.
I’m already glad that this is a known problem, and not something that’s linked to my particular setup.

If anyone has been able to find a workaround, I’m of course always open for suggestions!