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]