A few days ago that using the Radioparadise plugin in flac, plays one or two songs and then stops doing it. It happens to you?
I’m using Volumio V2.513 and I never had this problem.
regard
It would be great if you could ssh into your volumio machine, then type sudo journalctl -f
and then start the flac stream afterwards. Copy/Paste the log output here after the stream stopped/interrupted.
I‘m away from home and a raspberry pi until January 3rd.
login as: volumio
volumio@192.168.0.25’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 Wed 2018-12-26 14:29:21 UTC. –
Dec 26 19:44:19 volumio systemd[7007]: Starting Basic System.
Dec 26 19:44:19 volumio systemd[7007]: Reached target Basic System.
Dec 26 19:44:19 volumio systemd[7007]: Starting Default.
Dec 26 19:44:19 volumio systemd[7007]: Reached target Default.
Dec 26 19:44:19 volumio systemd[7007]: Startup finished in 40ms.
Dec 26 19:44:19 volumio systemd[1]: Started User Manager for UID 1000.
Dec 26 19:44:19 volumio sshd[6887]: lastlog_openseek: Couldn’t stat /var/log/lastlog: No such file or directory
Dec 26 19:44:19 volumio sshd[6887]: lastlog_openseek: Couldn’t stat /var/log/lastlog: No such file or directory
Dec 26 19:44:38 volumio sudo[7157]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Dec 26 19:44:38 volumio sudo[7157]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPlay
Dec 26 19:44:53 volumio volumio[1066]: UNSET VOLATILE
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::play index 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::stop
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 26 19:44:53 volumio volumio[1066]: UNSET VOLATILE
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::updateTrackBlock
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrackBlock
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::stPlaybackTimer
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::serviceStop
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::serviceStop
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::stop
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand stop
Dec 26 19:44:53 volumio sudo[7265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:53 volumio volumio[1066]: info: sending command…
Dec 26 19:44:53 volumio volumio[1066]: info:
Dec 26 19:44:53 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:44:53 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:53 volumio sudo[7265]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:53 volumio sudo[7265]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: STATE SERVICE {“status”:“stop”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B0006ZXJ3E.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1790198-1790206.flac?src=alexa”,“name”:"Thievery Corporation - Wires And Watchtowers (Feat Sista Pat)”,“title”:“Wires And Watchtowers (Feat Sista Pat)”,“artist”:“Radio Paradise”,“album”:“Cosmic Game”,“streaming”:true,“disableUiControls”:true,“duration”:254,“seek”:31838,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Dec 26 19:44:53 volumio volumio[1066]: info: CURRENT POSITION 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::syncState stateService stop
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus stop
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:53 volumio sudo[7273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:53 volumio sudo[7273]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:53 volumio volumio[1066]: info: No code
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio sudo[7273]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:53 volumio sudo[7280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:53 volumio volumio[1066]: info: sending command…
Dec 26 19:44:53 volumio sudo[7280]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::play index undefined
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::startPlaybackTimer
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio sudo[7287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:53 volumio sudo[7280]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:53 volumio volumio[1066]: info: [1545853493392] [RadioParadise] getStream started with url api.radioparadise.com/api/get_b … &info=true
Dec 26 19:44:53 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:53 volumio sudo[7287]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand playlistinfo
Dec 26 19:44:53 volumio volumio[1066]: info: sending command…
Dec 26 19:44:53 volumio volumio[1066]: info:
Dec 26 19:44:53 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:44:53 volumio volumio[1066]: info: sending command…
Dec 26 19:44:53 volumio sudo[7287]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:53 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:53 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::parseTrackInfo
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand playlistinfo
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:44:53 volumio volumio[1066]: info: sending command…
Dec 26 19:44:53 volumio volumio[1066]: info: ------------------------------ 166ms
Dec 26 19:44:53 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::parseTrackInfo
Dec 26 19:44:53 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:53 volumio sudo[7303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:53 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:53 volumio sudo[7303]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:53 volumio sudo[7303]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:53 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:53 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:44:53 volumio volumio[1066]: info: ------------------------------ 93ms
Dec 26 19:44:53 volumio sudo[7309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:53 volumio sudo[7309]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:53 volumio sudo[7309]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:54 volumio volumio[1066]: info: [1545853494107] [RadioParadise] received new event with id 1790199 containing 7 songs.
Dec 26 19:44:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand stop
Dec 26 19:44:54 volumio volumio[1066]: info: sending command…
Dec 26 19:44:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand clear
Dec 26 19:44:54 volumio volumio[1066]: info: sending command…
Dec 26 19:44:54 volumio volumio[1066]: info:
Dec 26 19:44:54 volumio volumio[1066]: ---------------------------- MPD announces system playlist update
Dec 26 19:44:54 volumio volumio[1066]: info: Ignoring MPD Status Update
Dec 26 19:44:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand consume 1
Dec 26 19:44:54 volumio volumio[1066]: info: sending command…
Dec 26 19:44:54 volumio volumio[1066]: info:
Dec 26 19:44:54 volumio volumio[1066]: ---------------------------- MPD announces system playlist update
Dec 26 19:44:54 volumio volumio[1066]: info: Ignoring MPD Status Update
Dec 26 19:44:54 volumio volumio[1066]: info:
Dec 26 19:44:54 volumio volumio[1066]: info:
Dec 26 19:44:54 volumio volumio[1066]: info: ------------------------------ 6ms
Dec 26 19:44:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:54 volumio volumio[1066]: info: ------------------------------ 3ms
Dec 26 19:44:54 volumio volumio[1066]: info: [1545853494119] [RadioParadise] set to consume mode, adding url: audio-3.radioparadise.com/blocks … ?src=alexa
Dec 26 19:44:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand add “http://audio-3.radioparadise.com/blocks/chan/0/4/1790199-1790206.flac?src=alexa”
Dec 26 19:44:54 volumio volumio[1066]: info: sending command…
Dec 26 19:44:54 volumio volumio[1066]: info:
Dec 26 19:44:54 volumio volumio[1066]: ---------------------------- MPD announces system playlist update
Dec 26 19:44:54 volumio volumio[1066]: info: Ignoring MPD Status Update
Dec 26 19:44:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand play
Dec 26 19:44:54 volumio volumio[1066]: info: sending command…
Dec 26 19:44:54 volumio volumio[1066]: info:
Dec 26 19:44:54 volumio volumio[1066]: ---------------------------- MPD announces system playlist update
Dec 26 19:44:54 volumio volumio[1066]: info: Ignoring MPD Status Update
Dec 26 19:44:54 volumio volumio[1066]: info: ------------------------------ 8ms
Dec 26 19:44:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:54 volumio volumio[1066]: info: ------------------------------ 3ms
Dec 26 19:44:54 volumio volumio[1066]: info: [1545853494130] [RadioParadise] Pushing the next song state: Joan Osborne - Mongrels
Dec 26 19:44:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:54 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:54 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:54 volumio volumio[1066]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B00ILAWIMY.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1790199-1790206.flac?src=alexa”,“name”:"Joan Osborne - Mongrels”,“title”:“Mongrels”,“artist”:“Radio Paradise”,“album”:“Love & Hate”,“streaming”:true,“disableUiControls”:true,“duration”:241,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Dec 26 19:44:54 volumio volumio[1066]: info: CURRENT POSITION 0
Dec 26 19:44:54 volumio volumio[1066]: info: CoreStateMachine::syncState stateService play
Dec 26 19:44:54 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus stop
Dec 26 19:44:54 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:44:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:44:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:54 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:44:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:44:54 volumio sudo[7329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:44:54 volumio sudo[7329]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:44:54 volumio sudo[7329]: pam_unix(sudo:session): session closed for user root
Dec 26 19:44:55 volumio volumio[1066]: info:
Dec 26 19:44:55 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info:
Dec 26 19:44:55 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info:
Dec 26 19:44:55 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand playlistinfo
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand playlistinfo
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info:
Dec 26 19:44:55 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand playlistinfo
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseTrackInfo
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseTrackInfo
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:55 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:55 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:55 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:55 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:44:55 volumio volumio[1066]: info: ------------------------------ 31ms
Dec 26 19:44:55 volumio volumio[1066]: info: ------------------------------ 28ms
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand playlistinfo
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseTrackInfo
Dec 26 19:44:55 volumio volumio[1066]: info: sending command…
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:55 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:55 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:44:55 volumio volumio[1066]: info: ------------------------------ 30ms
Dec 26 19:44:55 volumio volumio[1066]: info: parsing response…
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::parseTrackInfo
Dec 26 19:44:55 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:44:55 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:44:55 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:44:55 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:44:55 volumio volumio[1066]: info: ------------------------------ 21ms
Dec 26 19:47:43 volumio kernel: CIFS VFS: Free previous auth_key.response = b7e47900
Dec 26 19:47:59 volumio sudo[8641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:47:59 volumio sudo[8641]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:47:59 volumio sudo[8641]: pam_unix(sudo:session): session closed for user root
Dec 26 19:47:59 volumio sudo[8645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:47:59 volumio sudo[8645]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:47:59 volumio sudo[8645]: pam_unix(sudo:session): session closed for user root
Dec 26 19:48:49 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:48:49 volumio volumio[1066]: info: CorePlayQueue::getTrack 1
Dec 26 19:48:54 volumio volumio[1066]: info: [1545853734568] [RadioParadise] Pushing the next song state: Elvis Presley - Hound Dog
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:48:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:48:54 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:48:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:48:54 volumio volumio[1066]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B0006TL9C8.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1790199-1790206.flac?src=alexa”,“name”:"Elvis Presley - Hound Dog”,“title”:“Hound Dog”,“artist”:“Radio Paradise”,“album”:“Elvis Presley”,“streaming”:true,“disableUiControls”:true,“duration”:134,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Dec 26 19:48:54 volumio volumio[1066]: info: CURRENT POSITION 0
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::syncState stateService play
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus play
Dec 26 19:48:54 volumio volumio[1066]: info: Received an update from plugin. extracting info from payload
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:48:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:48:54 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:48:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:48:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:48:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:48:54 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:48:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:48:54 volumio sudo[9045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:48:54 volumio sudo[9045]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:48:54 volumio sudo[9045]: pam_unix(sudo:session): session closed for user root
Dec 26 19:48:54 volumio sudo[9050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:48:54 volumio sudo[9050]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:48:54 volumio sudo[9050]: pam_unix(sudo:session): session closed for user root
Dec 26 19:51:03 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:51:03 volumio volumio[1066]: info: CorePlayQueue::getTrack 1
Dec 26 19:51:08 volumio volumio[1066]: info: [1545853868029] [RadioParadise] Pushing the next song state: Allman Brothers - Stand Back
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:51:08 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:51:08 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:51:08 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:51:08 volumio volumio[1066]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B000003CMC.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1790199-1790206.flac?src=alexa”,“name”:"Allman Brothers - Stand Back”,“title”:“Stand Back”,“artist”:“Radio Paradise”,“album”:“Eat A Peach”,“streaming”:true,“disableUiControls”:true,“duration”:198,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Dec 26 19:51:08 volumio volumio[1066]: info: CURRENT POSITION 0
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::syncState stateService play
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus play
Dec 26 19:51:08 volumio volumio[1066]: info: Received an update from plugin. extracting info from payload
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:51:08 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:51:08 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:51:08 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:51:08 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:51:08 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:51:08 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:51:08 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:51:08 volumio sudo[10006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:51:08 volumio sudo[10006]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:51:08 volumio sudo[10006]: pam_unix(sudo:session): session closed for user root
Dec 26 19:51:08 volumio sudo[10012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:51:08 volumio sudo[10012]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:51:08 volumio sudo[10012]: pam_unix(sudo:session): session closed for user root
Dec 26 19:52:00 volumio sudo[10394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:52:00 volumio sudo[10394]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:52:00 volumio sudo[10394]: pam_unix(sudo:session): session closed for user root
Dec 26 19:52:00 volumio sudo[10398]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:52:00 volumio sudo[10398]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:52:00 volumio sudo[10398]: pam_unix(sudo:session): session closed for user root
Dec 26 19:52:54 volumio volumio[1066]: info:
Dec 26 19:52:54 volumio volumio[1066]: ---------------------------- MPD announces system playlist update
Dec 26 19:52:54 volumio volumio[1066]: info: Ignoring MPD Status Update
Dec 26 19:52:54 volumio volumio[1066]: info:
Dec 26 19:52:54 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:52:54 volumio volumio[1066]: info: sending command…
Dec 26 19:52:54 volumio volumio[1066]: info:
Dec 26 19:52:54 volumio volumio[1066]: ---------------------------- MPD announces system playlist update
Dec 26 19:52:54 volumio volumio[1066]: info: Ignoring MPD Status Update
Dec 26 19:52:54 volumio volumio[1066]: info:
Dec 26 19:52:54 volumio volumio[1066]: ---------------------------- MPD announces state update: player
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::getState
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::sendMpdCommand status
Dec 26 19:52:54 volumio volumio[1066]: info: sending command…
Dec 26 19:52:54 volumio volumio[1066]: info:
Dec 26 19:52:54 volumio volumio[1066]: info:
Dec 26 19:52:54 volumio volumio[1066]: info: ------------------------------ 6ms
Dec 26 19:52:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:52:54 volumio volumio[1066]: info: ------------------------------ 4ms
Dec 26 19:52:54 volumio volumio[1066]: info: parsing response…
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::parseState
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:52:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:52:54 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:52:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:52:54 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:52:54 volumio volumio[1066]: info: ControllerMpd::pushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:52:54 volumio sudo[10797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:52:54 volumio sudo[10797]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:52:54 volumio sudo[10797]: pam_unix(sudo:session): session closed for user root
Dec 26 19:52:54 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:52:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:52:54 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:52:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:52:54 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:52:54 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Dec 26 19:52:54 volumio sudo[10803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:52:54 volumio volumio[1066]: info: ------------------------------ 73ms
Dec 26 19:52:54 volumio volumio[1066]: info: ------------------------------ 72ms
Dec 26 19:52:54 volumio sudo[10803]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:52:54 volumio sudo[10803]: pam_unix(sudo:session): session closed for user root
Dec 26 19:54:13 volumio sudo[11365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:54:13 volumio sudo[11365]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:54:13 volumio sudo[11369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:54:13 volumio sudo[11365]: pam_unix(sudo:session): session closed for user root
Dec 26 19:54:13 volumio sudo[11369]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:54:13 volumio sudo[11369]: pam_unix(sudo:session): session closed for user root
Dec 26 19:54:21 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:54:21 volumio volumio[1066]: info: CorePlayQueue::getTrack 1
Dec 26 19:54:26 volumio volumio[1066]: info: [1545854066094] [RadioParadise] Pushing the next song state: Patty Griffin - Boston
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:54:26 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:54:26 volumio volumio[1066]: info: CoreCommandRouter::servicePushState
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::syncState
Dec 26 19:54:26 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:54:26 volumio volumio[1066]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B00E0P8VQQ.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1790199-1790206.flac?src=alexa”,“name”:"Patty Griffin - Boston”,“title”:“Boston”,“artist”:“Radio Paradise”,“album”:“Silver Bell”,“streaming”:true,“disableUiControls”:true,“duration”:228,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Dec 26 19:54:26 volumio volumio[1066]: info: CURRENT POSITION 0
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::syncState stateService play
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus play
Dec 26 19:54:26 volumio volumio[1066]: info: Received an update from plugin. extracting info from payload
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:54:26 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:54:26 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:54:26 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::pushState
Dec 26 19:54:26 volumio volumio[1066]: info: CoreStateMachine::getState
Dec 26 19:54:26 volumio volumio[1066]: info: CorePlayQueue::getTrack 0
Dec 26 19:54:26 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState
Dec 26 19:54:26 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 19:54:26 volumio sudo[11469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:54:26 volumio sudo[11469]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:54:26 volumio sudo[11469]: pam_unix(sudo:session): session closed for user root
Dec 26 19:54:26 volumio sudo[11473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 26 19:54:26 volumio sudo[11473]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 19:54:26 volumio sudo[11473]: pam_unix(sudo:session): session closed for user root
sudo journalctl -fsudo journalctl -f
[i]Here are the logs for the last instance that my RP FLAC stream stopped, as per your instruction to the OP. I’ve been having a similar problem with the FLAC stream, but the time can vary from a few songs, to an hour.
See my original post here : radio-paradise-flac-playback-t11404.html
I’ve deleted the first few minutes of the logs, because of the character number limits for posts.
I should also point out… after the audio stream stops, the volumio player still shows the stream timer counting and it updates the track information when songs change.
Logs follow:[/i]
login as: volumio
volumio@192.168.0.87’s password:
___
{“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B07DKWYV64.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792382-1792390.flac?src=alexa”,“name”:"Death Cab for Cutie - I Dreamt We Spoke Again”,“title”:“I Dreamt We Spoke Again”,“artist”:“Radio Paradise”,“album”:“Thank You for Today”,“streaming”:true,“disableUiControls”:true,“duration”:182,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:20:52 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:20:52 allo-digi-one sudo[21647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:20:52 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:20:52 allo-digi-one sudo[21647]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:20:52 allo-digi-one sudo[21647]: pam_unix(sudo:session): session closed for user root
Jan 01 05:20:52 allo-digi-one sudo[21653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:20:52 allo-digi-one sudo[21653]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:20:52 allo-digi-one sudo[21653]: pam_unix(sudo:session): session closed for user root
Jan 01 05:23:48 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:23:48 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:23:53 allo-digi-one volumio[837]: info: [1546320233277] [RadioParadise] Pushing the next song state: Ray LaMontagne - Forever My Friend
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:23:53 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B0002S947K.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792382-1792390.flac?src=alexa”,“name”:"Ray LaMontagne - Forever My Friend”,“title”:“Forever My Friend”,“artist”:“Radio Paradise”,“album”:“Trouble”,“streaming”:true,“disableUiControls”:true,“duration”:336,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:23:53 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:23:53 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:23:53 allo-digi-one sudo[21678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:23:53 allo-digi-one sudo[21678]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:23:53 allo-digi-one sudo[21678]: pam_unix(sudo:session): session closed for user root
Jan 01 05:23:53 allo-digi-one sudo[21687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:23:53 allo-digi-one sudo[21687]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:23:53 allo-digi-one sudo[21687]: pam_unix(sudo:session): session closed for user root
Jan 01 05:29:24 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:29:24 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:29:29 allo-digi-one volumio[837]: info: [1546320569358] [RadioParadise] Pushing the next song state: The Who - I’m One
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:29:29 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B000059N1S.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792382-1792390.flac?src=alexa”,“name”:"The Who - I’m One”,“title”:“I’m One”,“artist”:“Radio Paradise”,“album”:“Quadrophenia”,“streaming”:true,“disableUiControls”:true,“duration”:154,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:29:29 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:29:29 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:29:29 allo-digi-one sudo[21719]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:29:29 allo-digi-one sudo[21719]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:29:29 allo-digi-one sudo[21719]: pam_unix(sudo:session): session closed for user root
Jan 01 05:29:29 allo-digi-one sudo[21727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:29:29 allo-digi-one sudo[21727]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:29:29 allo-digi-one sudo[21727]: pam_unix(sudo:session): session closed for user root
Jan 01 05:31:58 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:31:58 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:32:03 allo-digi-one volumio[837]: info: [1546320723433] [RadioParadise] Pushing the next song state: Sonny Boy Williamson - Bring It On Home
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:32:03 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B000005KQN.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792382-1792390.flac?src=alexa”,“name”:"Sonny Boy Williamson - Bring It On Home”,“title”:“Bring It On Home”,“artist”:“Radio Paradise”,“album”:“His Best”,“streaming”:true,“disableUiControls”:true,“duration”:144,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:32:03 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:32:03 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:32:03 allo-digi-one sudo[21749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:32:03 allo-digi-one sudo[21749]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:32:03 allo-digi-one sudo[21749]: pam_unix(sudo:session): session closed for user root
Jan 01 05:32:03 allo-digi-one sudo[21758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:32:03 allo-digi-one sudo[21758]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:32:03 allo-digi-one sudo[21758]: pam_unix(sudo:session): session closed for user root
Jan 01 05:34:22 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:34:22 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:34:27 allo-digi-one volumio[837]: info: [1546320867012] [RadioParadise] Pushing the next song state: Jack White - Love Interruption
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:34:27 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B007CKNX28.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792382-1792390.flac?src=alexa”,“name”:"Jack White - Love Interruption”,“title”:“Love Interruption”,“artist”:“Radio Paradise”,“album”:“Blunderbuss”,“streaming”:true,“disableUiControls”:true,“duration”:153,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:34:27 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:34:27 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:34:27 allo-digi-one sudo[21777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:34:27 allo-digi-one sudo[21777]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:34:27 allo-digi-one sudo[21777]: pam_unix(sudo:session): session closed for user root
Jan 01 05:34:27 allo-digi-one volumio[837]: info: [1546320867092] [RadioParadise] Prefetching next event.
Jan 01 05:34:27 allo-digi-one volumio[837]: info: [1546320867092] [RadioParadise] getStream started with url api.radioparadise.com/api/get_b … nt=1792390
Jan 01 05:34:27 allo-digi-one sudo[21785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:34:27 allo-digi-one sudo[21785]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:34:27 allo-digi-one sudo[21785]: pam_unix(sudo:session): session closed for user root
Jan 01 05:34:28 allo-digi-one volumio[837]: info: [1546320868067] [RadioParadise] received new event with id 1792391 containing 1 songs.
Jan 01 05:34:28 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand add “http://audio-3.radioparadise.com/blocks/chan/0/4/5006451.flac?src=alexa”
Jan 01 05:34:28 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:34:28 allo-digi-one volumio[837]: info:
Jan 01 05:34:28 allo-digi-one volumio[837]: ---------------------------- MPD announces system playlist update
Jan 01 05:34:28 allo-digi-one volumio[837]: info: Ignoring MPD Status Update
Jan 01 05:34:28 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:34:28 allo-digi-one volumio[837]: info: ------------------------------ 4ms
Jan 01 05:36:54 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:36:54 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:36:59 allo-digi-one volumio[837]: info: [1546321019791] [RadioParadise] Calling playNextTrack to start next event.
Jan 01 05:36:59 allo-digi-one volumio[837]: info: [1546321019792] [RadioParadise] Pushing the next song state: Commercial-free - Listener-supported
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:36:59 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/101.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/5006451.flac?src=alexa”,“name”:"Commercial-free - Listener-supported”,“title”:“Listener-supported”,“artist”:“Radio Paradise”,“streaming”:true,“disableUiControls”:true,“duration”:19,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:36:59 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:36:59 allo-digi-one sudo[21811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:36:59 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:36:59 allo-digi-one sudo[21811]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:36:59 allo-digi-one sudo[21811]: pam_unix(sudo:session): session closed for user root
Jan 01 05:36:59 allo-digi-one volumio[837]: info: [1546321019866] [RadioParadise] Prefetching next event.
Jan 01 05:36:59 allo-digi-one volumio[837]: info: [1546321019867] [RadioParadise] getStream started with url api.radioparadise.com/api/get_b … nt=1792391
Jan 01 05:36:59 allo-digi-one sudo[21818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:36:59 allo-digi-one sudo[21818]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:36:59 allo-digi-one sudo[21818]: pam_unix(sudo:session): session closed for user root
Jan 01 05:37:00 allo-digi-one volumio[837]: info: [1546321020583] [RadioParadise] received new event with id 1792392 containing 5 songs.
Jan 01 05:37:00 allo-digi-one volumio[837]: info: [1546321020583] [RadioParadise] End Event id is 1792397 but last song event is 1792396. There is a spoken part at the end.
Jan 01 05:37:00 allo-digi-one volumio[837]: info: [1546321020584] [RadioParadise] Adding 8008ms to last song: J.J. Cale - Ridin’ Home
Jan 01 05:37:00 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand add “http://audio-3.radioparadise.com/blocks/chan/0/4/1792392-1792397.flac?src=alexa”
Jan 01 05:37:00 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:37:00 allo-digi-one volumio[837]: info:
Jan 01 05:37:00 allo-digi-one volumio[837]: ---------------------------- MPD announces system playlist update
Jan 01 05:37:00 allo-digi-one volumio[837]: info: Ignoring MPD Status Update
Jan 01 05:37:00 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:37:00 allo-digi-one volumio[837]: info: ------------------------------ 4ms
Jan 01 05:37:02 allo-digi-one volumio[837]: info:
Jan 01 05:37:02 allo-digi-one volumio[837]: ---------------------------- MPD announces system playlist update
Jan 01 05:37:02 allo-digi-one volumio[837]: info: Ignoring MPD Status Update
Jan 01 05:37:02 allo-digi-one volumio[837]: info:
Jan 01 05:37:02 allo-digi-one volumio[837]: ---------------------------- MPD announces state update: player
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ControllerMpd::getState
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand status
Jan 01 05:37:02 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ------------------------------ 4ms
Jan 01 05:37:02 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ControllerMpd::parseState
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand playlistinfo
Jan 01 05:37:02 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:37:02 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ControllerMpd::parseTrackInfo
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ControllerMpd::pushState
Jan 01 05:37:02 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:37:02 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:37:02 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:02 allo-digi-one volumio[837]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Jan 01 05:37:02 allo-digi-one volumio[837]: info: ------------------------------ 11ms
Jan 01 05:37:13 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:13 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:37:18 allo-digi-one volumio[837]: info: [1546321038156] [RadioParadise] Calling playNextTrack to start next event.
Jan 01 05:37:18 allo-digi-one volumio[837]: info: [1546321038157] [RadioParadise] Pushing the next song state: Tori Amos - I’m On Fire
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:18 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B000002J9H.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792392-1792397.flac?src=alexa”,“name”:"Tori Amos - I’m On Fire”,“title”:“I’m On Fire”,“artist”:“Radio Paradise”,“album”:“VH1 Crossroads”,“streaming”:true,“disableUiControls”:true,“duration”:184,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:37:18 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:37:18 allo-digi-one sudo[21830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:37:18 allo-digi-one sudo[21830]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:37:18 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:37:18 allo-digi-one sudo[21830]: pam_unix(sudo:session): session closed for user root
Jan 01 05:37:18 allo-digi-one sudo[21839]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:37:18 allo-digi-one sudo[21839]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:37:18 allo-digi-one sudo[21839]: pam_unix(sudo:session): session closed for user root
Jan 01 05:37:21 allo-digi-one volumio[837]: info:
Jan 01 05:37:21 allo-digi-one volumio[837]: ---------------------------- MPD announces system playlist update
Jan 01 05:37:21 allo-digi-one volumio[837]: info: Ignoring MPD Status Update
Jan 01 05:37:21 allo-digi-one volumio[837]: info:
Jan 01 05:37:21 allo-digi-one volumio[837]: ---------------------------- MPD announces state update: player
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ControllerMpd::getState
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand status
Jan 01 05:37:21 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ------------------------------ 4ms
Jan 01 05:37:21 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ControllerMpd::parseState
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand playlistinfo
Jan 01 05:37:21 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:37:21 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ControllerMpd::parseTrackInfo
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ControllerMpd::pushState
Jan 01 05:37:21 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:37:21 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:37:21 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:37:21 allo-digi-one volumio[837]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Jan 01 05:37:21 allo-digi-one volumio[837]: info: ------------------------------ 10ms
Jan 01 05:40:17 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:40:17 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:40:22 allo-digi-one volumio[837]: info: [1546321222235] [RadioParadise] Pushing the next song state: Lucinda Williams - Rescue
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:40:22 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B000LXHGFI.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792392-1792397.flac?src=alexa”,“name”:"Lucinda Williams - Rescue”,“title”:“Rescue”,“artist”:“Radio Paradise”,“album”:“West”,“streaming”:true,“disableUiControls”:true,“duration”:329,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:40:22 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:40:22 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:40:22 allo-digi-one sudo[21860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:40:22 allo-digi-one sudo[21860]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:40:22 allo-digi-one sudo[21860]: pam_unix(sudo:session): session closed for user root
Jan 01 05:40:22 allo-digi-one sudo[21867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:40:22 allo-digi-one sudo[21867]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:40:22 allo-digi-one sudo[21867]: pam_unix(sudo:session): session closed for user root
Jan 01 05:45:46 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:45:46 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:45:51 allo-digi-one volumio[837]: info: [1546321551312] [RadioParadise] Pushing the next song state: Seven Lions - Leaving Earth
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:45:51 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B01D5HSYPM.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792392-1792397.flac?src=alexa”,“name”:"Seven Lions - Leaving Earth”,“title”:“Leaving Earth”,“artist”:“Radio Paradise”,“album”:“Creation”,“streaming”:true,“disableUiControls”:true,“duration”:370,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:45:51 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:45:51 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:45:51 allo-digi-one sudo[21901]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:45:51 allo-digi-one sudo[21901]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:45:51 allo-digi-one sudo[21901]: pam_unix(sudo:session): session closed for user root
Jan 01 05:45:51 allo-digi-one sudo[21909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:45:51 allo-digi-one sudo[21909]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:45:51 allo-digi-one sudo[21909]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:14 allo-digi-one volumio[837]: info: CoreCommandRouter::getUIConfigOnPlugin
Jan 01 05:49:14 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork
Jan 01 05:49:14 allo-digi-one sudo[21937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0
Jan 01 05:49:14 allo-digi-one sudo[21937]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:14 allo-digi-one sudo[21937]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:15 allo-digi-one sudo[21950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
Jan 01 05:49:15 allo-digi-one sudo[21950]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:15 allo-digi-one sudo[21950]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:15 allo-digi-one sudo[21964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
Jan 01 05:49:15 allo-digi-one sudo[21964]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:15 allo-digi-one sudo[21964]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:15 allo-digi-one sudo[21975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
Jan 01 05:49:15 allo-digi-one sudo[21975]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:15 allo-digi-one sudo[21975]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:16 allo-digi-one sudo[21988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jan 01 05:49:16 allo-digi-one sudo[21988]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:16 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks
Jan 01 05:49:16 allo-digi-one sudo[21988]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:16 allo-digi-one sudo[21994]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:49:16 allo-digi-one sudo[21994]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:16 allo-digi-one sudo[21994]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:16 allo-digi-one sudo[22008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jan 01 05:49:16 allo-digi-one sudo[22008]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:16 allo-digi-one sudo[22008]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:16 allo-digi-one volumio[837]: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Jan 01 05:49:16 allo-digi-one volumio[837]: wlan0 Interface doesn’t support scanning : Network is down
Jan 01 05:49:16 allo-digi-one volumio[837]: Cannot use regular scanning, forcing with ap-force
Jan 01 05:49:16 allo-digi-one sudo[22017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Jan 01 05:49:16 allo-digi-one sudo[22017]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:49:16 allo-digi-one sudo[22017]: pam_unix(sudo:session): session closed for user root
Jan 01 05:49:16 allo-digi-one volumio[837]: command failed: Network is down (-100)
Jan 01 05:49:16 allo-digi-one volumio[837]: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
Jan 01 05:49:16 allo-digi-one volumio[837]: command failed: Network is down (-100)
Jan 01 05:50:04 allo-digi-one kernel: eth0: hw csum failure
Jan 01 05:50:04 allo-digi-one kernel: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G C 4.14.71-v7+ #1145
Jan 01 05:50:04 allo-digi-one kernel: Hardware name: BCM2835
Jan 01 05:50:04 allo-digi-one kernel: [<8010ffd4>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24)
Jan 01 05:50:04 allo-digi-one kernel: [<8010c240>] (show_stack) from [<80787f24>] (dump_stack+0xd4/0x118)
Jan 01 05:50:04 allo-digi-one kernel: [<80787f24>] (dump_stack) from [<8068e20c>] (netdev_rx_csum_fault+0x44/0x48)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e20c>] (netdev_rx_csum_fault) from [<80680ae0>] (__skb_checksum_complete+0xbc/0xc0)
Jan 01 05:50:04 allo-digi-one kernel: [<80680ae0>] (__skb_checksum_complete) from [<80732b04>] (nf_ip_checksum+0xd4/0x130)
Jan 01 05:50:04 allo-digi-one kernel: [<80732b04>] (nf_ip_checksum) from [<7f6af454>] (tcp_error+0x1d0/0x21c [nf_conntrack])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6af454>] (tcp_error [nf_conntrack]) from [<7f6a9994>] (nf_conntrack_in+0xec/0x560 [nf_conntrack])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6a9994>] (nf_conntrack_in [nf_conntrack]) from [<7f6f32dc>] (ipv4_conntrack_in+0x28/0x2c [nf_conntrack_ipv4])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6f32dc>] (ipv4_conntrack_in [nf_conntrack_ipv4]) from [<806cfe38>] (nf_hook_slow+0x4c/0xd0)
Jan 01 05:50:04 allo-digi-one kernel: [<806cfe38>] (nf_hook_slow) from [<806d8750>] (ip_rcv+0x460/0x514)
Jan 01 05:50:04 allo-digi-one kernel: [<806d8750>] (ip_rcv) from [<8068b7e8>] (__netif_receive_skb_core+0x340/0xc84)
Jan 01 05:50:04 allo-digi-one kernel: [<8068b7e8>] (__netif_receive_skb_core) from [<8068e380>] (__netif_receive_skb+0x20/0x7c)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e380>] (__netif_receive_skb) from [<8068e474>] (process_backlog+0x98/0x148)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e474>] (process_backlog) from [<8069278c>] (net_rx_action+0x2e8/0x45c)
Jan 01 05:50:04 allo-digi-one kernel: [<8069278c>] (net_rx_action) from [<80101694>] (__do_softirq+0x18c/0x3d8)
Jan 01 05:50:04 allo-digi-one kernel: [<80101694>] (__do_softirq) from [<80123870>] (irq_exit+0x108/0x164)
Jan 01 05:50:04 allo-digi-one kernel: [<80123870>] (irq_exit) from [<80175984>] (__handle_domain_irq+0x70/0xc4)
Jan 01 05:50:04 allo-digi-one kernel: [<80175984>] (__handle_domain_irq) from [<80101504>] (bcm2836_arm_irqchip_handle_irq+0xa8/0xac)
Jan 01 05:50:04 allo-digi-one kernel: [<80101504>] (bcm2836_arm_irqchip_handle_irq) from [<807a3abc>] (__irq_svc+0x5c/0x7c)
Jan 01 05:50:04 allo-digi-one kernel: Exception stack(0x80c01ef0 to 0x80c01f38)
Jan 01 05:50:04 allo-digi-one kernel: 1ee0: 00000000 3bcff740 3c35f000 00000000
Jan 01 05:50:04 allo-digi-one kernel: 1f00: 80c00000 80c03dcc 80c03d68 80c885b2 00000001 80b60a30 bd7ff780 80c01f4c
Jan 01 05:50:04 allo-digi-one kernel: 1f20: 80c04174 80c01f40 80108a4c 80108a50 60000013 ffffffff
Jan 01 05:50:04 allo-digi-one kernel: [<807a3abc>] (__irq_svc) from [<80108a50>] (arch_cpu_idle+0x34/0x4c)
Jan 01 05:50:04 allo-digi-one kernel: [<80108a50>] (arch_cpu_idle) from [<807a323c>] (default_idle_call+0x34/0x48)
Jan 01 05:50:04 allo-digi-one kernel: [<807a323c>] (default_idle_call) from [<80161494>] (do_idle+0xd8/0x150)
Jan 01 05:50:04 allo-digi-one kernel: [<80161494>] (do_idle) from [<801617a8>] (cpu_startup_entry+0x28/0x2c)
Jan 01 05:50:04 allo-digi-one kernel: [<801617a8>] (cpu_startup_entry) from [<8079cf64>] (rest_init+0xbc/0xc0)
Jan 01 05:50:04 allo-digi-one kernel: [<8079cf64>] (rest_init) from [<80b00df8>] (start_kernel+0x3d4/0x3e0)
Jan 01 05:50:04 allo-digi-one kernel: eth0: hw csum failure
Jan 01 05:50:04 allo-digi-one kernel: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G C 4.14.71-v7+ #1145
Jan 01 05:50:04 allo-digi-one kernel: Hardware name: BCM2835
Jan 01 05:50:04 allo-digi-one kernel: [<8010ffd4>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24)
Jan 01 05:50:04 allo-digi-one kernel: [<8010c240>] (show_stack) from [<80787f24>] (dump_stack+0xd4/0x118)
Jan 01 05:50:04 allo-digi-one kernel: [<80787f24>] (dump_stack) from [<8068e20c>] (netdev_rx_csum_fault+0x44/0x48)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e20c>] (netdev_rx_csum_fault) from [<80680ae0>] (__skb_checksum_complete+0xbc/0xc0)
Jan 01 05:50:04 allo-digi-one kernel: [<80680ae0>] (__skb_checksum_complete) from [<80732b04>] (nf_ip_checksum+0xd4/0x130)
Jan 01 05:50:04 allo-digi-one kernel: [<80732b04>] (nf_ip_checksum) from [<7f6af454>] (tcp_error+0x1d0/0x21c [nf_conntrack])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6af454>] (tcp_error [nf_conntrack]) from [<7f6a9994>] (nf_conntrack_in+0xec/0x560 [nf_conntrack])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6a9994>] (nf_conntrack_in [nf_conntrack]) from [<7f6f32dc>] (ipv4_conntrack_in+0x28/0x2c [nf_conntrack_ipv4])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6f32dc>] (ipv4_conntrack_in [nf_conntrack_ipv4]) from [<806cfe38>] (nf_hook_slow+0x4c/0xd0)
Jan 01 05:50:04 allo-digi-one kernel: [<806cfe38>] (nf_hook_slow) from [<806d8750>] (ip_rcv+0x460/0x514)
Jan 01 05:50:04 allo-digi-one kernel: [<806d8750>] (ip_rcv) from [<8068b7e8>] (__netif_receive_skb_core+0x340/0xc84)
Jan 01 05:50:04 allo-digi-one kernel: [<8068b7e8>] (__netif_receive_skb_core) from [<8068e380>] (__netif_receive_skb+0x20/0x7c)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e380>] (__netif_receive_skb) from [<8068e474>] (process_backlog+0x98/0x148)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e474>] (process_backlog) from [<8069278c>] (net_rx_action+0x2e8/0x45c)
Jan 01 05:50:04 allo-digi-one kernel: [<8069278c>] (net_rx_action) from [<80101694>] (__do_softirq+0x18c/0x3d8)
Jan 01 05:50:04 allo-digi-one kernel: [<80101694>] (__do_softirq) from [<80123870>] (irq_exit+0x108/0x164)
Jan 01 05:50:04 allo-digi-one kernel: [<80123870>] (irq_exit) from [<80175984>] (__handle_domain_irq+0x70/0xc4)
Jan 01 05:50:04 allo-digi-one kernel: [<80175984>] (__handle_domain_irq) from [<80101504>] (bcm2836_arm_irqchip_handle_irq+0xa8/0xac)
Jan 01 05:50:04 allo-digi-one kernel: [<80101504>] (bcm2836_arm_irqchip_handle_irq) from [<807a3abc>] (__irq_svc+0x5c/0x7c)
Jan 01 05:50:04 allo-digi-one kernel: Exception stack(0x80c01ef0 to 0x80c01f38)
Jan 01 05:50:04 allo-digi-one kernel: 1ee0: 00000000 3bcff740 3c35f000 00000000
Jan 01 05:50:04 allo-digi-one kernel: 1f00: 80c00000 80c03dcc 80c03d68 80c885b2 00000001 80b60a30 bd7ff780 80c01f4c
Jan 01 05:50:04 allo-digi-one kernel: 1f20: 80c04174 80c01f40 80108a4c 80108a50 60000013 ffffffff
Jan 01 05:50:04 allo-digi-one kernel: [<807a3abc>] (__irq_svc) from [<80108a50>] (arch_cpu_idle+0x34/0x4c)
Jan 01 05:50:04 allo-digi-one kernel: [<80108a50>] (arch_cpu_idle) from [<807a323c>] (default_idle_call+0x34/0x48)
Jan 01 05:50:04 allo-digi-one kernel: [<807a323c>] (default_idle_call) from [<80161494>] (do_idle+0xd8/0x150)
Jan 01 05:50:04 allo-digi-one kernel: [<80161494>] (do_idle) from [<801617a8>] (cpu_startup_entry+0x28/0x2c)
Jan 01 05:50:04 allo-digi-one kernel: [<801617a8>] (cpu_startup_entry) from [<8079cf64>] (rest_init+0xbc/0xc0)
Jan 01 05:50:04 allo-digi-one kernel: [<8079cf64>] (rest_init) from [<80b00df8>] (start_kernel+0x3d4/0x3e0)
Jan 01 05:50:04 allo-digi-one kernel: eth0: hw csum failure
Jan 01 05:50:04 allo-digi-one kernel: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G C 4.14.71-v7+ #1145
Jan 01 05:50:04 allo-digi-one kernel: Hardware name: BCM2835
Jan 01 05:50:04 allo-digi-one kernel: [<8010ffd4>] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24)
Jan 01 05:50:04 allo-digi-one kernel: [<8010c240>] (show_stack) from [<80787f24>] (dump_stack+0xd4/0x118)
Jan 01 05:50:04 allo-digi-one kernel: [<80787f24>] (dump_stack) from [<8068e20c>] (netdev_rx_csum_fault+0x44/0x48)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e20c>] (netdev_rx_csum_fault) from [<80680ae0>] (__skb_checksum_complete+0xbc/0xc0)
Jan 01 05:50:04 allo-digi-one kernel: [<80680ae0>] (__skb_checksum_complete) from [<80732b04>] (nf_ip_checksum+0xd4/0x130)
Jan 01 05:50:04 allo-digi-one kernel: [<80732b04>] (nf_ip_checksum) from [<7f6af454>] (tcp_error+0x1d0/0x21c [nf_conntrack])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6af454>] (tcp_error [nf_conntrack]) from [<7f6a9994>] (nf_conntrack_in+0xec/0x560 [nf_conntrack])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6a9994>] (nf_conntrack_in [nf_conntrack]) from [<7f6f32dc>] (ipv4_conntrack_in+0x28/0x2c [nf_conntrack_ipv4])
Jan 01 05:50:04 allo-digi-one kernel: [<7f6f32dc>] (ipv4_conntrack_in [nf_conntrack_ipv4]) from [<806cfe38>] (nf_hook_slow+0x4c/0xd0)
Jan 01 05:50:04 allo-digi-one kernel: [<806cfe38>] (nf_hook_slow) from [<806d8750>] (ip_rcv+0x460/0x514)
Jan 01 05:50:04 allo-digi-one kernel: [<806d8750>] (ip_rcv) from [<8068b7e8>] (__netif_receive_skb_core+0x340/0xc84)
Jan 01 05:50:04 allo-digi-one kernel: [<8068b7e8>] (__netif_receive_skb_core) from [<8068e380>] (__netif_receive_skb+0x20/0x7c)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e380>] (__netif_receive_skb) from [<8068e474>] (process_backlog+0x98/0x148)
Jan 01 05:50:04 allo-digi-one kernel: [<8068e474>] (process_backlog) from [<8069278c>] (net_rx_action+0x2e8/0x45c)
Jan 01 05:50:04 allo-digi-one kernel: [<8069278c>] (net_rx_action) from [<80101694>] (__do_softirq+0x18c/0x3d8)
Jan 01 05:50:04 allo-digi-one kernel: [<80101694>] (__do_softirq) from [<80123870>] (irq_exit+0x108/0x164)
Jan 01 05:50:04 allo-digi-one kernel: [<80123870>] (irq_exit) from [<80175984>] (__handle_domain_irq+0x70/0xc4)
Jan 01 05:50:04 allo-digi-one kernel: [<80175984>] (__handle_domain_irq) from [<80101504>] (bcm2836_arm_irqchip_handle_irq+0xa8/0xac)
Jan 01 05:50:04 allo-digi-one kernel: [<80101504>] (bcm2836_arm_irqchip_handle_irq) from [<807a3abc>] (__irq_svc+0x5c/0x7c)
Jan 01 05:50:04 allo-digi-one kernel: Exception stack(0x80c01ef0 to 0x80c01f38)
Jan 01 05:50:04 allo-digi-one kernel: 1ee0: 00000000 3bcff740 3c35f000 00000000
Jan 01 05:50:04 allo-digi-one kernel: 1f00: 80c00000 80c03dcc 80c03d68 80c885b2 00000001 80b60a30 bd7ff780 80c01f4c
Jan 01 05:50:04 allo-digi-one kernel: 1f20: 80c04174 80c01f40 80108a4c 80108a50 60000013 ffffffff
Jan 01 05:50:04 allo-digi-one kernel: [<807a3abc>] (__irq_svc) from [<80108a50>] (arch_cpu_idle+0x34/0x4c)
Jan 01 05:50:04 allo-digi-one kernel: [<80108a50>] (arch_cpu_idle) from [<807a323c>] (default_idle_call+0x34/0x48)
Jan 01 05:50:04 allo-digi-one kernel: [<807a323c>] (default_idle_call) from [<80161494>] (do_idle+0xd8/0x150)
Jan 01 05:50:04 allo-digi-one kernel: [<80161494>] (do_idle) from [<801617a8>] (cpu_startup_entry+0x28/0x2c)
Jan 01 05:50:04 allo-digi-one kernel: [<801617a8>] (cpu_startup_entry) from [<8079cf64>] (rest_init+0xbc/0xc0)
Jan 01 05:50:04 allo-digi-one kernel: [<8079cf64>] (rest_init) from [<80b00df8>] (start_kernel+0x3d4/0x3e0)
Jan 01 05:51:56 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:51:56 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 46
Jan 01 05:52:01 allo-digi-one volumio[837]: info: [1546321921392] [RadioParadise] Pushing the next song state: Dire Straits - Follow Me Home
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:52:01 allo-digi-one volumio[837]: info: STATE SERVICE {“status”:“play”,“service”:“radio_paradise”,“type”:“track”,“trackType”:“flac”,“radioType”:“rparadise”,“albumart”:“http://img.radioparadise.com/covers/l/B00004Y6NT.jpg",“uri”:“http://audio-3.radioparadise.com/blocks/chan/0/4/1792392-1792397.flac?src=alexa”,“name”:"Dire Straits - Follow Me Home”,“title”:“Follow Me Home”,“artist”:“Radio Paradise”,“album”:“Communiqué”,“streaming”:true,“disableUiControls”:true,“duration”:338,“seek”:0,“samplerate”:“44.1 KHz”,“bitdepth”:“16 bit”,“channels”:2}
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CURRENT POSITION 45
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::syncState stateService play
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::syncState currentStatus play
Jan 01 05:52:01 allo-digi-one volumio[837]: info: Received an update from plugin. extracting info from payload
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:52:01 allo-digi-one sudo[22040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:52:01 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:52:01 allo-digi-one sudo[22040]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:52:01 allo-digi-one sudo[22040]: pam_unix(sudo:session): session closed for user root
Jan 01 05:52:01 allo-digi-one sudo[22045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:52:01 allo-digi-one sudo[22045]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:52:01 allo-digi-one sudo[22045]: pam_unix(sudo:session): session closed for user root
Jan 01 05:53:39 allo-digi-one volumio[837]: info:
Jan 01 05:53:39 allo-digi-one volumio[837]: ---------------------------- MPD announces system playlist update
Jan 01 05:53:39 allo-digi-one volumio[837]: info: Ignoring MPD Status Update
Jan 01 05:53:39 allo-digi-one volumio[837]: info:
Jan 01 05:53:39 allo-digi-one volumio[837]: ---------------------------- MPD announces state update: player
Jan 01 05:53:39 allo-digi-one volumio[837]: info: ControllerMpd::getState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: ControllerMpd::sendMpdCommand status
Jan 01 05:53:39 allo-digi-one volumio[837]: info: sending command…
Jan 01 05:53:39 allo-digi-one volumio[837]: info:
Jan 01 05:53:39 allo-digi-one volumio[837]: info: ------------------------------ 7ms
Jan 01 05:53:39 allo-digi-one volumio[837]: info: parsing response…
Jan 01 05:53:39 allo-digi-one volumio[837]: info: ControllerMpd::parseState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: ControllerMpd::pushState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CoreCommandRouter::servicePushState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CoreStateMachine::syncState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CoreStateMachine::pushState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CoreStateMachine::getState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CoreCommandRouter::volumioPushState
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 01 05:53:39 allo-digi-one volumio[837]: info: CorePlayQueue::getTrack 45
Jan 01 05:53:39 allo-digi-one volumio[837]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
Jan 01 05:53:39 allo-digi-one volumio[837]: info: ------------------------------ 40ms
Jan 01 05:53:39 allo-digi-one sudo[22066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 01 05:53:39 allo-digi-one sudo[22066]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 01 05:53:39 allo-digi-one sudo[22066]: pam_unix(sudo:session): session closed for user root
OK, I think I figured out what the problem might be. I could reproduce this behaviour and together with your logs above I think this happens each time there is a single flac track which just contains spoken promotion of Radio Paradise (15-20 seconds) named “Commercial-free - Listener-supported”.
I try to fix this and I will also switch all urls (flac, image etc.) to https as they seem to be deactivating plain http support.
STATE SERVICE {"status":"play","service":"radio_paradise","type":"track","trackType":"flac","radioType":"rparadise","albumart":"http://img.radioparadise.com/covers/l/102.jpg","uri":"http://audio-3.radioparadise.com/blocks/chan/0/4/5006457.flac?src=alexa","name":"Commercial-free - Listener-supported","title":"Listener-supported","artist":"Radio Paradise","streaming":true,"disableUiControls":true,"duration":19,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2}Here is a possible quick fix for this problem.
Could anybody with ssh/bash knowledge try to test it?
Instructions:
- ssh into your volumio machine
- cd /data/plugins/music_service/radio_paradise
- mv index.js index.js.old
wget -O index.js https://raw.githubusercontent.com/marco79cgn/volumio-plugins/radio-paradise-103/plugins/music_service/radio_paradise/index.js- reboot
I’m looking forward for your feedback.
Just download and re-booting. Will update with my results later.
***** Update *****
Tailing the log, I see it finding and then skipping one of the “single flac track” blocks:
2019-01-04T01:37:01.275Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:37:01.276Z - info: CorePlayQueue::getTrack 1
2019-01-04T01:37:06.236Z - info: [1546565826236] [RadioParadise] Pushing the next song state: X Ambassadors - Renegades
2019-01-04T01:37:06.237Z - info: CoreStateMachine::getState
2019-01-04T01:37:06.248Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:37:06.248Z - info: CoreCommandRouter::servicePushState
2019-01-04T01:37:06.249Z - info: CoreStateMachine::syncState
2019-01-04T01:37:06.250Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:37:06.250Z - info: STATE SERVICE {"status":"play","service":"radio_paradise","type":"track","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B00XI057FM.jpg","uri":"https://audio-3.radioparadise.com/blocks/chan/0/4/1793531-1793537.flac?src=alexa","name":"X Ambassadors - Renegades","title":"Renegades","artist":"Radio Paradise","album":"VHS","streaming":true,"disableUiControls":true,"duration":194,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2}
2019-01-04T01:37:06.251Z - info: CURRENT POSITION 0
2019-01-04T01:37:06.251Z - info: CoreStateMachine::syncState stateService play
2019-01-04T01:37:06.252Z - info: CoreStateMachine::syncState currentStatus play
2019-01-04T01:37:06.253Z - info: Received an update from plugin. extracting info from payload
2019-01-04T01:37:06.254Z - info: CoreStateMachine::pushState
2019-01-04T01:37:06.254Z - info: CoreStateMachine::getState
2019-01-04T01:37:06.255Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:37:06.255Z - info: CoreCommandRouter::volumioPushState
2019-01-04T01:37:06.256Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T01:37:06.278Z - info: CoreStateMachine::pushState
2019-01-04T01:37:06.279Z - info: CoreStateMachine::getState
2019-01-04T01:37:06.279Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:37:06.280Z - info: CoreCommandRouter::volumioPushState
2019-01-04T01:37:06.281Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T01:37:06.318Z - info: [1546565826317] [RadioParadise] Prefetching next event.
2019-01-04T01:37:06.318Z - info: [1546565826318] [RadioParadise] getStream started with url https://api.radioparadise.com/api/get_block?bitrate=4&info=true&event=1793537
2019-01-04T01:37:06.523Z - info: [1546565826523] [RadioParadise] received new event with id 1793538 containing 1 songs.
2019-01-04T01:37:06.525Z - info: [1546565826524] [RadioParadise] received ONLY ONE event with id undefined. Checking if it is a commercial.
2019-01-04T01:37:06.525Z - info: [1546565826525] [RadioParadise] FOUND RADIO-PARADISE commercial event. Skipping this commercial.
2019-01-04T01:37:06.526Z - info: [1546565826525] [RadioParadise] Prefetching next event.
2019-01-04T01:37:06.526Z - info: [1546565826526] [RadioParadise] getStream started with url https://api.radioparadise.com/api/get_block?bitrate=4&info=true&event=1793538
2019-01-04T01:37:06.671Z - info: [1546565826671] [RadioParadise] received new event with id 1793539 containing 5 songs.
2019-01-04T01:37:06.673Z - info: ControllerMpd::sendMpdCommand add "https://audio-3.radioparadise.com/blocks/chan/0/4/1793539-1793543.flac?src=alexa"
2019-01-04T01:37:06.674Z - info: sending command...
2019-01-04T01:37:06.676Z - info:
---------------------------- MPD announces system playlist update
2019-01-04T01:37:06.677Z - info: Ignoring MPD Status Update
2019-01-04T01:37:06.678Z - info: parsing response...
2019-01-04T01:37:06.680Z - info: ------------------------------ 4ms
2019-01-04T01:40:15.322Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:40:15.322Z - info: CorePlayQueue::getTrack 1
2019-01-04T01:40:20.318Z - info: [1546566020317] [RadioParadise] Calling playNextTrack to start next event.
2019-01-04T01:40:20.321Z - info: [1546566020319] [RadioParadise] Pushing the next song state: Sonny Landreth - Soldier of Fortune
2019-01-04T01:40:20.323Z - info: CoreStateMachine::getState
2019-01-04T01:40:20.325Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:40:20.327Z - info: CoreCommandRouter::servicePushState
2019-01-04T01:40:20.328Z - info: CoreStateMachine::syncState
2019-01-04T01:40:20.330Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:40:20.332Z - info: STATE SERVICE {"status":"play","service":"radio_paradise","type":"track","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B00000098T.jpg","uri":"https://audio-3.radioparadise.com/blocks/chan/0/4/1793539-1793543.flac?src=alexa","name":"Sonny Landreth - Soldier of Fortune","title":"Soldier of Fortune","artist":"Radio Paradise","album":"Outward Bound","streaming":true,"disableUiControls":true,"duration":274,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2}
2019-01-04T01:40:20.332Z - info: CURRENT POSITION 0
2019-01-04T01:40:20.333Z - info: CoreStateMachine::syncState stateService play
2019-01-04T01:40:20.333Z - info: CoreStateMachine::syncState currentStatus play
2019-01-04T01:40:20.334Z - info: Received an update from plugin. extracting info from payload
2019-01-04T01:40:20.334Z - info: CoreStateMachine::pushState
2019-01-04T01:40:20.334Z - info: CoreStateMachine::getState
2019-01-04T01:40:20.335Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:40:20.335Z - info: CoreCommandRouter::volumioPushState
2019-01-04T01:40:20.336Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T01:40:20.361Z - info: CoreStateMachine::pushState
2019-01-04T01:40:20.363Z - info: CoreStateMachine::getState
2019-01-04T01:40:20.365Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:40:20.367Z - info: CoreCommandRouter::volumioPushState
2019-01-04T01:40:20.368Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T01:40:23.613Z - info:
---------------------------- MPD announces system playlist update
2019-01-04T01:40:23.614Z - info: Ignoring MPD Status Update
2019-01-04T01:40:23.614Z - info:
---------------------------- MPD announces state update: player
2019-01-04T01:40:23.615Z - info: ControllerMpd::getState
2019-01-04T01:40:23.616Z - info: ControllerMpd::sendMpdCommand status
2019-01-04T01:40:23.617Z - info: sending command...
2019-01-04T01:40:23.620Z - info: ------------------------------ 7ms
2019-01-04T01:40:23.620Z - info: parsing response...
2019-01-04T01:40:23.621Z - info: ControllerMpd::parseState
2019-01-04T01:40:23.622Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-04T01:40:23.623Z - info: sending command...
2019-01-04T01:40:23.625Z - info: parsing response...
2019-01-04T01:40:23.626Z - info: ControllerMpd::parseTrackInfo
2019-01-04T01:40:23.627Z - info: ControllerMpd::pushState
2019-01-04T01:40:23.627Z - info: CoreCommandRouter::servicePushState
2019-01-04T01:40:23.628Z - info: CoreStateMachine::syncState
2019-01-04T01:40:23.628Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:40:23.629Z - info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
2019-01-04T01:40:23.629Z - info: ------------------------------ 15ms
Cheers.
No Marco, it does not work. I do not think the problem is with the announcement “Radio Paradise …”, this time he did it in the middle of the second song he played after the announcement.
Here’s a trace on another issue reported. There was a station break between tracks, where the next track was announced. However, the time-counter for the next track track started and ran during the voice part, so now the time-counter, title, and album art are ahead of the actual music. The next time this happens, the time difference will grow even more.
2019-01-04T01:58:48.623Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:58:48.624Z - info: CorePlayQueue::getTrack 1
2019-01-04T01:58:53.680Z - info: [1546567133679] [RadioParadise] Pushing the next song state: The War On Drugs - Thinking Of A Place
2019-01-04T01:58:53.681Z - info: CoreStateMachine::getState
2019-01-04T01:58:53.681Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:58:53.682Z - info: CoreCommandRouter::servicePushState
2019-01-04T01:58:53.683Z - info: CoreStateMachine::syncState
2019-01-04T01:58:53.683Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:58:53.684Z - info: STATE SERVICE {"status":"play","service":"radio_paradise","type":"track","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B071FL9473.jpg","uri":"https://audio-3.radioparadise.com/blocks/chan/0/4/1793539-1793543.flac?src=alexa","name":"The War On Drugs - Thinking Of A Place","title":"Thinking Of A Place","artist":"Radio Paradise","album":"A Deeper Understanding","streaming":true,"disableUiControls":true,"duration":666,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2}
2019-01-04T01:58:53.684Z - info: CURRENT POSITION 0
2019-01-04T01:58:53.685Z - info: CoreStateMachine::syncState stateService play
2019-01-04T01:58:53.685Z - info: CoreStateMachine::syncState currentStatus play
2019-01-04T01:58:53.686Z - info: Received an update from plugin. extracting info from payload
2019-01-04T01:58:53.686Z - info: CoreStateMachine::pushState
2019-01-04T01:58:53.687Z - info: CoreStateMachine::getState
2019-01-04T01:58:53.688Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:58:53.688Z - info: CoreCommandRouter::volumioPushState
2019-01-04T01:58:53.689Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T01:58:53.715Z - info: CoreStateMachine::pushState
2019-01-04T01:58:53.716Z - info: CoreStateMachine::getState
2019-01-04T01:58:53.716Z - info: CorePlayQueue::getTrack 0
2019-01-04T01:58:53.717Z - info: CoreCommandRouter::volumioPushState
2019-01-04T01:58:53.717Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T01:58:53.754Z - info: [1546567133753] [RadioParadise] Prefetching next event.
2019-01-04T01:58:53.754Z - info: [1546567133754] [RadioParadise] getStream started with url https://api.radioparadise.com/api/get_block?bitrate=4&info=true&event=1793543
2019-01-04T01:58:53.957Z - info: [1546567133957] [RadioParadise] received new event with id 1793544 containing 5 songs.
2019-01-04T01:58:53.958Z - info: [1546567133958] [RadioParadise] Event id is 1793544 but first song event is 1793545. There is a spoken part at the beginning.
2019-01-04T01:58:53.959Z - info: [1546567133959] [RadioParadise] Adding 4044ms to first song: Steven Wilson - Perfect Life
2019-01-04T01:58:53.960Z - info: ControllerMpd::sendMpdCommand add "https://audio-3.radioparadise.com/blocks/chan/0/4/1793544-1793549.flac?src=alexa"
2019-01-04T01:58:53.961Z - info: sending command...
2019-01-04T01:58:53.965Z - info:
---------------------------- MPD announces system playlist update
2019-01-04T01:58:53.966Z - info: Ignoring MPD Status Update
2019-01-04T01:58:53.967Z - info: parsing response...
2019-01-04T01:58:53.970Z - info: ------------------------------ 5ms
2019-01-04T02:00:11.034Z - info: CoreCommandRouter::volumioGetQueue
2019-01-04T02:00:11.035Z - info: CoreStateMachine::getQueue
2019-01-04T02:00:11.036Z - info: CorePlayQueue::getQueue
2019-01-04T02:09:54.929Z - info: CorePlayQueue::getTrack 0
2019-01-04T02:09:54.931Z - info: CorePlayQueue::getTrack 1
2019-01-04T02:09:59.752Z - info: [1546567799752] [RadioParadise] Calling playNextTrack to start next event.
2019-01-04T02:09:59.753Z - info: [1546567799752] [RadioParadise] Pushing the next song state: Steven Wilson - Perfect Life
2019-01-04T02:09:59.754Z - info: CoreStateMachine::getState
2019-01-04T02:09:59.754Z - info: CorePlayQueue::getTrack 0
2019-01-04T02:09:59.755Z - info: CoreCommandRouter::servicePushState
2019-01-04T02:09:59.755Z - info: CoreStateMachine::syncState
2019-01-04T02:09:59.756Z - info: CorePlayQueue::getTrack 0
2019-01-04T02:09:59.756Z - info: STATE SERVICE {"status":"play","service":"radio_paradise","type":"track","trackType":"flac","radioType":"rparadise","albumart":"https://img.radioparadise.com/covers/l/B00QW4QWYQ.jpg","uri":"https://audio-3.radioparadise.com/blocks/chan/0/4/1793544-1793549.flac?src=alexa","name":"Steven Wilson - Perfect Life","title":"Perfect Life","artist":"Radio Paradise","album":"Hand. Cannot. Erase.","streaming":true,"disableUiControls":true,"duration":279,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2}
2019-01-04T02:09:59.765Z - info: CURRENT POSITION 0
2019-01-04T02:09:59.766Z - info: CoreStateMachine::syncState stateService play
2019-01-04T02:09:59.767Z - info: CoreStateMachine::syncState currentStatus play
2019-01-04T02:09:59.767Z - info: Received an update from plugin. extracting info from payload
2019-01-04T02:09:59.768Z - info: CoreStateMachine::pushState
2019-01-04T02:09:59.768Z - info: CoreStateMachine::getState
2019-01-04T02:09:59.769Z - info: CorePlayQueue::getTrack 0
2019-01-04T02:09:59.769Z - info: CoreCommandRouter::volumioPushState
2019-01-04T02:09:59.770Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T02:09:59.792Z - info: CoreStateMachine::pushState
2019-01-04T02:09:59.792Z - info: CoreStateMachine::getState
2019-01-04T02:09:59.793Z - info: CorePlayQueue::getTrack 0
2019-01-04T02:09:59.794Z - info: CoreCommandRouter::volumioPushState
2019-01-04T02:09:59.794Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-04T02:10:07.763Z - info:
---------------------------- MPD announces system playlist update
2019-01-04T02:10:07.764Z - info: Ignoring MPD Status Update
2019-01-04T02:10:07.764Z - info:
---------------------------- MPD announces state update: player
2019-01-04T02:10:07.766Z - info: ControllerMpd::getState
2019-01-04T02:10:07.766Z - info: ControllerMpd::sendMpdCommand status
2019-01-04T02:10:07.767Z - info: sending command...
2019-01-04T02:10:07.769Z - info: ------------------------------ 7ms
2019-01-04T02:10:07.770Z - info: parsing response...
2019-01-04T02:10:07.771Z - info: ControllerMpd::parseState
2019-01-04T02:10:07.772Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-04T02:10:07.772Z - info: sending command...
2019-01-04T02:10:07.774Z - info: parsing response...
2019-01-04T02:10:07.775Z - info: ControllerMpd::parseTrackInfo
2019-01-04T02:10:07.777Z - info: ControllerMpd::pushState
2019-01-04T02:10:07.777Z - info: CoreCommandRouter::servicePushState
2019-01-04T02:10:07.778Z - info: CoreStateMachine::syncState
2019-01-04T02:10:07.778Z - info: CorePlayQueue::getTrack 0
2019-01-04T02:10:07.779Z - info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
2019-01-04T02:10:07.779Z - info: ------------------------------ 15ms
Cheers.
I can‘t reproduce this behaviour. It‘s running for hours on my Pi. I did a fresh installation yesterday with the latest Volumio Version 2.522 (30 Dec 2018) running on a Pi Zero W with HiFiBerry DAC. Not a single outage in the middle of a track.
The Radio Paradise API returns events. Each event contains one flac file that includes up to 7 songs. There might be spoken parts at the beginning, at the end, both or none at all. One has to guess where they are and therefore the exact timing of the metadata might be a bit off. This should automatically go back in sync with the next flac file/song block.
But please let‘s first try to focus on the bug where the music stops playing in Volumio even though the metadata continues refreshing. I can‘t really reproduce this whereas danielfelix seems to have this problem immediatelly. What about the others? When does it happen and which version are you running?
Not what I see. The sync slowly seems to drift over time, which has been reported earlier in this thread.
I have no problem with that. It was just that this thread seemed to cover all issues with the plug-in, not just this particular one, hence my report.
With regard to the stream stopping playing/muting. Since rebooting over 8 hours ago, it’s still playing fine for me, which was not the case prior to this fix.
Currently running Volumio 2.513 and Radio Paradise 1.0.2 with marco79cgn’s fix from a few posts earlier.
Cheers.
Cool, thanks for clarification! I have the same behaviour, it’s playing flawless for several hours now without muting/interruption.
Yes it is, no offense. It’s just really hard to find/fix multiple bugs at the same time. And muting/interruption is a show stopper for me.
I also had a look on this issue. Which display/browser/app are you using for Volumio? In my case it’s the Safari Browser on macOS. If the Volumio tab is in the background and I come back to it minutes/hours later, I can see that the time is wrong. But it will resync with a simple site refresh in the browser (CMD + R). Did you try that as well? The reason for this is that tabs in the background get suspended in Safari due to reduce energy consumption. Same thing with Firefox btw, not sure about Chrome. On my machine it’s running for +4hrs now and the timing is still accurate (+/- 3seconds).
I checked that the correct index.js is working.
The sound emission is interrupted shortly after starting and the metadata continues to refresh.
Use Volumio 2.552
Do you need a capture with journalctl?
Sorry, I think I can’t help you with this issue. My machine is running for more than 18 hours without probs. Since it’s also working for EddieA with the fix, I think you have another problem with your setup. I can’t see something suspicious in your logs. Maybe wait for the bugfix release, uninstall and then try again.
Hmmmm. Not sure when it died, as I turned off the speakers last night after the stream had been playing for about 8 hours. But turning them back on just now, around 24 hours, no sound. But the time display and album art were continuing to update.
Hitting play, on the Queue screen, skipped back one song and started playing again.
Will try and keep a closer eye on it over the weekend.
Cheers.
OK, I know this is going to be really confusing, mixing 2 issues like this still. But on to the slow out-of-sync problem.
I restarted the stream about 5 or 6 hours ago, see post above and still playing great. At that time both the app on my Android tablet and both a Chrome and Firefox browser were all in sync and as the track time flipped to zero, the album art changed and the new track started to play.
Now, 5 or 6 hours later, the Android app, Chrome and Firefox still all are in sync with regard to the track-time and the album art.
BUT, the track-time clock hits zero and the album art changes about 30 seconds before the new track actually starts to play.
Not sure what I can capture to show this. Maybe I can re-route my speakers to where my PC is and video the Volumio display, a “tail” of the log, together with the audio in the background. Or is there something else ?? ?? ??
Cheers, and BTW a very belated THANK YOU for introducing my to Radio Paradise.
Are you sure that your internet connection hasn’t been cut off in these 24 hours? Here in germany it’s quite normal that the internet provider cuts the connection every 24 hours. In this case, the stream would break in Volumio. The metadata might still continue because the refresh of the metadata is all about timers.
The implementation of this special kind of flac stream of Radio Paradise inside Volumio (which is also quite special) was a kind of hack/workaround from the beginning. Basically it works with timers after which the metadata in the GUI is refreshed.
The plugin works like this in an endless loop:
Call RP api > get result of first flac file containing e.g. 5 songs > play the flac file, show first song and start timer with the length of the first song, e.g. 4m30s > after 4m30s show second song info while still playling the same flac file > … > when the fifth song starts (last one of the first flac file), get the next flac file from RP api and already put it in the play queue (to ensure gapless playing) > and so on…
It does not work for me.
I have in / data / plugins / music_service / radio_paradise an index.js of 23.664Kb and an index.js.old of 22764kb, which tells me that the patch is well installed.
It works well one or five songs and it is cut in the middle of the reproduction. The metadata continues to flow.
While it works, there is no apparent desynchronization.
Reinstalled Volumio 2.552 using “Factory Reset”
I do not want to mix the themes, but it’s funny that with this version of Volumio, I also have problems with the Simple Equalizer Plugin, in some web stations I get an error “failed to open alsa …”, I had to uninstall it.
It would not be a good idea to try a previous version of Volumio?
Absolutley not a bad idea! Your problems sound like there are some incompatibilities in any way (hardware, dac, volumio,…). I think it’s worth a try. The radio paradise plugin should work even with really old volumio2 versions.
… I see to install Volumio 2.502 (31-10-2018)