May 23 13:54:03 raspbmusic volumio[923]: info: Saving local item radio-favourites May 23 13:54:03 raspbmusic volumio[923]: info: Pushing Favourites {"uri":"http://opml.radiotime.com/Tune.ashx?id=s291934","favourite":false} May 23 13:54:04 raspbmusic volumio[923]: info: Preload queue cleared May 23 13:54:04 raspbmusic volumio[923]: info: CoreCommandRouter::volumioReplaceandPlayItems May 23 13:54:04 raspbmusic volumio[923]: info: CoreStateMachine::ClearQueue May 23 13:54:04 raspbmusic volumio[923]: info: CoreStateMachine::stop May 23 13:54:04 raspbmusic volumio[923]: info: CoreStateMachine::serviceStop May 23 13:54:04 raspbmusic volumio[923]: info: CoreCommandRouter::serviceStop May 23 13:54:04 raspbmusic volumio[923]: info: Spotify Stop May 23 13:54:04 raspbmusic volumio[923]: SPOTIFY: SPOTIFY STOP May 23 13:54:04 raspbmusic volumio[923]: SPOTIFY: {"status":"pause","title":"Maybe It Was Me","artist":"Windows","album":"Sometimes I Feel Happy, Sometimes Sad","albumart":"https://i.scdn.co/image/ab67616d00001e02d173ee91828548c0b1a059a6","uri":"spotify:track:6bF6PDNQJ9haO3YhwLxHm4","trackType":"spotify","codec":"ogg","seek":365139,"duration":436,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} May 23 13:54:04 raspbmusic volumio[923]: info: Sending Spotify command to local API: /player/pause May 23 13:54:04 raspbmusic volumio[923]: info: CorePlayQueue::clearPlayQueue May 23 13:54:04 raspbmusic volumio[923]: info: CorePlayQueue::saveQueue May 23 13:54:04 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushQueue May 23 13:54:04 raspbmusic volumio[923]: info: CoreStateMachine::addQueueItems May 23 13:54:04 raspbmusic volumio[923]: info: CorePlayQueue::addQueueItems May 23 13:54:04 raspbmusic volumio[923]: info: Preload queue cleared May 23 13:54:04 raspbmusic volumio[923]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s291934 May 23 13:54:04 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 23 13:54:05 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushQueue May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::saveQueue May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::updateTrackBlock May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::getTrackBlock May 23 13:54:05 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPlay May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::play index 0 May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::stop May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::updateTrackBlock May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::getTrackBlock May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::stPlaybackTimer May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:05 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:05 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::serviceStop May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:05 raspbmusic volumio[923]: info: CoreCommandRouter::serviceStop May 23 13:54:05 raspbmusic volumio[923]: info: [1747997645559] ControllerWebradio::stop May 23 13:54:05 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand stop May 23 13:54:05 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:05 raspbmusic volumio[923]: info: sendMpdCommand stop took 64 milliseconds May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::play index undefined May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:05 raspbmusic volumio[923]: info: CoreStateMachine::startPlaybackTimer May 23 13:54:05 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:05 raspbmusic volumio[923]: info: [1747997645657] ControllerWebradio::clearAddPlayTrack May 23 13:54:05 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand stop May 23 13:54:05 raspbmusic volumio[923]: info: sendMpdCommand stop took 1 milliseconds May 23 13:54:05 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clear May 23 13:54:05 raspbmusic volumio[923]: info: May 23 13:54:05 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:05 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:05 raspbmusic volumio[923]: info: sendMpdCommand clear took 12 milliseconds May 23 13:54:05 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand load "https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3" May 23 13:54:05 raspbmusic volumio[923]: info: May 23 13:54:05 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:05 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:05 raspbmusic volumio[923]: info: May 23 13:54:05 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:05 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:05 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:05 raspbmusic volumio[923]: info: ------------------------------ 36ms May 23 13:54:06 raspbmusic mpd[1260]: exception: No such playlist May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand add "https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3" May 23 13:54:06 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:06 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:06 raspbmusic volumio[923]: info: ------------------------------ 992ms May 23 13:54:06 raspbmusic volumio[923]: info: ------------------------------ 991ms May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:06 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand add "https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3" took 24 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService mpd May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand play May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:06 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:06 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:06 raspbmusic volumio[923]: info: ------------------------------ 26ms May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand play took 25 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: ------------------------------ 26ms May 23 13:54:06 raspbmusic volumio[923]: info: ------------------------------ 14ms May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand status took 17 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand status took 15 milliseconds May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:06 raspbmusic volumio[923]: info: May 23 13:54:06 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand status took 24 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand status took 22 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 20 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 20 milliseconds May 23 13:54:06 raspbmusic volumio[923]: info: sendMpdCommand status took 6 milliseconds May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:06 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:06 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:06 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:06 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:06 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:06 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:06 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:06 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:54:06 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:06 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: ------------------------------ 145ms May 23 13:54:07 raspbmusic volumio[923]: info: ------------------------------ 234ms May 23 13:54:07 raspbmusic volumio[923]: info: sendMpdCommand status took 200 milliseconds May 23 13:54:07 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 196 milliseconds May 23 13:54:07 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 164 milliseconds May 23 13:54:07 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 161 milliseconds May 23 13:54:07 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:07 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:07 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:07 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:07 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:07 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:07 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:54:07 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:07 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:54:07 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:07 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:54:07 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: ------------------------------ 526ms May 23 13:54:07 raspbmusic volumio[923]: info: ------------------------------ 552ms May 23 13:54:07 raspbmusic volumio[923]: info: ------------------------------ 549ms May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 522 milliseconds May 23 13:54:07 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:07 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:07 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:54:07 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:07 raspbmusic volumio[923]: info: ------------------------------ 856ms May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:07 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:10 raspbmusic systemd[1]: systemd-timedated.service: Deactivated successfully. May 23 13:54:14 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:24 raspbmusic volumio[923]: info: Preload queue cleared May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioReplaceandPlayItems May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::ClearQueue May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::stPlaybackTimer May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::updateTrackBlock May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrackBlock May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::serviceStop May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::serviceStop May 23 13:54:24 raspbmusic volumio[923]: info: [1747997664477] ControllerWebradio::stop May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand stop May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::clearPlayQueue May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::saveQueue May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushQueue May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::addQueueItems May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::addQueueItems May 23 13:54:24 raspbmusic volumio[923]: info: Preload queue cleared May 23 13:54:24 raspbmusic volumio[923]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s104870 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 23 13:54:24 raspbmusic mpd[1260]: player: played "https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3" May 23 13:54:24 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:24 raspbmusic volumio[923]: info: May 23 13:54:24 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand stop took 294 milliseconds May 23 13:54:24 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:24 raspbmusic volumio[923]: info: May 23 13:54:24 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:24 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:24 raspbmusic volumio[923]: info: May 23 13:54:24 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:24 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand status took 26 milliseconds May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand status took 25 milliseconds May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand status took 23 milliseconds May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 40 milliseconds May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 40 milliseconds May 23 13:54:24 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 40 milliseconds May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:24 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:24 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:24 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: No code May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:24 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: No code May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"rdu.mp3","artist":null,"album":null,"uri":"https://radio.radiodeepunderground.com/listen/radio_deep_underground/rdu.mp3","trackType":"mp3"} May 23 13:54:24 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:24 raspbmusic volumio[923]: info: No code May 23 13:54:24 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:24 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:24 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:25 raspbmusic volumio[923]: info: ------------------------------ 561ms May 23 13:54:25 raspbmusic volumio[923]: info: ------------------------------ 561ms May 23 13:54:25 raspbmusic volumio[923]: info: ------------------------------ 560ms May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:25 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushQueue May 23 13:54:25 raspbmusic volumio[923]: info: CorePlayQueue::saveQueue May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::updateTrackBlock May 23 13:54:25 raspbmusic volumio[923]: info: CorePlayQueue::getTrackBlock May 23 13:54:25 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPlay May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::play index 0 May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::stop May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::play index undefined May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:25 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:25 raspbmusic volumio[923]: info: CoreStateMachine::startPlaybackTimer May 23 13:54:25 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:25 raspbmusic volumio[923]: info: [1747997665718] ControllerWebradio::clearAddPlayTrack May 23 13:54:25 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand stop May 23 13:54:25 raspbmusic volumio[923]: info: sendMpdCommand stop took 22 milliseconds May 23 13:54:25 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clear May 23 13:54:25 raspbmusic volumio[923]: info: May 23 13:54:25 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:25 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:25 raspbmusic volumio[923]: info: sendMpdCommand clear took 12 milliseconds May 23 13:54:25 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand load "https://online.kissfm.ua/KissFM" May 23 13:54:25 raspbmusic volumio[923]: info: May 23 13:54:25 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:25 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:25 raspbmusic volumio[923]: info: May 23 13:54:25 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:25 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:25 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:25 raspbmusic volumio[923]: info: ------------------------------ 53ms May 23 13:54:26 raspbmusic mpd[1260]: exception: No such playlist May 23 13:54:26 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:26 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:26 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand add "https://online.kissfm.ua/KissFM" May 23 13:54:26 raspbmusic volumio[923]: info: ------------------------------ 1141ms May 23 13:54:26 raspbmusic volumio[923]: info: ------------------------------ 1140ms May 23 13:54:26 raspbmusic volumio[923]: info: May 23 13:54:26 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:26 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:26 raspbmusic volumio[923]: info: sendMpdCommand add "https://online.kissfm.ua/KissFM" took 17 milliseconds May 23 13:54:26 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService mpd May 23 13:54:26 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand play May 23 13:54:26 raspbmusic volumio[923]: info: May 23 13:54:26 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:26 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:26 raspbmusic volumio[923]: info: May 23 13:54:26 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:54:26 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:54:26 raspbmusic volumio[923]: info: ------------------------------ 39ms May 23 13:54:26 raspbmusic volumio[923]: info: sendMpdCommand play took 39 milliseconds May 23 13:54:26 raspbmusic volumio[923]: info: ------------------------------ 45ms May 23 13:54:26 raspbmusic volumio[923]: info: ------------------------------ 44ms May 23 13:54:27 raspbmusic volumio[923]: info: May 23 13:54:27 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:27 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:27 raspbmusic mpd[1260]: exception: Failed to open "default detected output" (sndio); Requested audio params cannot be satisfied May 23 13:54:27 raspbmusic volumio[923]: info: May 23 13:54:27 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:27 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:27 raspbmusic mpd[1260]: exception: Failed to open "default detected output" (sndio); Requested audio params cannot be satisfied May 23 13:54:27 raspbmusic mpd[1260]: player: problems opening audio device while playing "https://online.kissfm.ua/KissFM" May 23 13:54:27 raspbmusic volumio[923]: info: May 23 13:54:27 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:27 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:27 raspbmusic volumio[923]: info: May 23 13:54:27 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:27 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:27 raspbmusic volumio[923]: info: May 23 13:54:27 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:27 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:27 raspbmusic volumio[923]: info: May 23 13:54:27 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clearerror May 23 13:54:27 raspbmusic volumio[923]: info: sendMpdCommand status took 96 milliseconds May 23 13:54:27 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clearerror May 23 13:54:27 raspbmusic volumio[923]: info: sendMpdCommand status took 102 milliseconds May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clearerror May 23 13:54:27 raspbmusic volumio[923]: info: sendMpdCommand status took 97 milliseconds May 23 13:54:27 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clearerror May 23 13:54:27 raspbmusic volumio[923]: info: sendMpdCommand status took 98 milliseconds May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clearerror May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand status took 226 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand clearerror took 169 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand status took 168 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand clearerror took 172 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand clearerror took 160 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand clearerror took 156 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 74 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 67 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 66 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 60 milliseconds May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:28 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:28 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:28 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:54:28 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService pause May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:28 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:28 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:28 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:54:28 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService pause May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:28 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:28 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:28 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:54:28 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService pause May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:28 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:28 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:28 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:54:28 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService pause May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:28 raspbmusic volumio[923]: info: ------------------------------ 544ms May 23 13:54:28 raspbmusic volumio[923]: info: ------------------------------ 542ms May 23 13:54:28 raspbmusic volumio[923]: info: ------------------------------ 541ms May 23 13:54:28 raspbmusic volumio[923]: info: ------------------------------ 534ms May 23 13:54:28 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:28 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:28 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:28 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand clearerror took 333 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 297 milliseconds May 23 13:54:28 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 296 milliseconds May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:28 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:54:28 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:28 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:28 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:54:28 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService pause May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:28 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:54:28 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:28 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:54:28 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService pause May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:54:28 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:28 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:28 raspbmusic volumio[923]: info: ------------------------------ 608ms May 23 13:54:28 raspbmusic volumio[923]: info: ------------------------------ 616ms May 23 13:54:28 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:28 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:35 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 23 13:54:39 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 23 13:54:44 raspbmusic volumio[923]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 23 13:54:44 raspbmusic volumio[923]: info: Preparing to save Alsa Options, stopping services first May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::volumioStop May 23 13:54:44 raspbmusic volumio[923]: info: CoreStateMachine::stop May 23 13:54:44 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:54:44 raspbmusic volumio[923]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 23 13:54:44 raspbmusic volumio[923]: info: Found match in Cards Database: setting mixer PCM for card Headphones May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 23 13:54:44 raspbmusic volumio[923]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 23 13:54:44 raspbmusic volumio[923]: info: Disabling external Volume Control May 23 13:54:44 raspbmusic volumio[923]: info: CoreCommandRouter::getUIConfigOnPlugin May 23 13:54:44 raspbmusic volumio[923]: info: Preparing to generate the ALSA configuration file May 23 13:54:44 raspbmusic volumio[923]: info: Asound.conf file unchanged, so no further update is needed May 23 13:54:44 raspbmusic volumio[923]: info: Output device has changed, restarting MPD May 23 13:54:45 raspbmusic volumio[923]: info: Output device has changed, restarting Shairport Sync May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 13:54:45 raspbmusic sudo[1880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 13:54:45 raspbmusic sudo[1880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:54:45 raspbmusic volumio[923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 13:54:45 raspbmusic sudo[1879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 13:54:45 raspbmusic sudo[1879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:54:45 raspbmusic sudo[1879]: pam_unix(sudo:session): session closed for user root May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 23 13:54:45 raspbmusic systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 23 13:54:45 raspbmusic systemd[1]: Stopping mpd.service - Music Player Daemon... May 23 13:54:45 raspbmusic mpd[1260]: player: played "https://online.kissfm.ua/KissFM" May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 23 13:54:45 raspbmusic dbus-daemon[554]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.23' (uid=0 pid=1893 comm="timedatectl show --property=NTPSynchronized --valu") May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 23 13:54:45 raspbmusic systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 23 13:54:45 raspbmusic volumio[923]: info: MPD Permissions set May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:45 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:45 raspbmusic volumio[923]: info: VolumeController:: Volume=100 Mute =false May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:45 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:45 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:45 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:45 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:45 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic systemd[1]: mpd.service: Deactivated successfully. May 23 13:54:46 raspbmusic systemd[1]: Stopped mpd.service - Music Player Daemon. May 23 13:54:46 raspbmusic systemd[1]: mpd.service: Consumed 14.702s CPU time. May 23 13:54:46 raspbmusic systemd[1]: mpd.socket: Deactivated successfully. May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 23 13:54:46 raspbmusic systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 23 13:54:46 raspbmusic systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 23 13:54:46 raspbmusic systemd[1]: Starting mpd.service - Music Player Daemon... May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:46 raspbmusic volumio[923]: error: [ytcr] Error connecting MPD: May 23 13:54:46 raspbmusic volumio[923]: (Error) read ECONNRESET May 23 13:54:46 raspbmusic volumio[923]: Error: read ECONNRESET May 23 13:54:46 raspbmusic volumio[923]: at Pipe.onStreamRead (node:internal/stream_base_commons:217:20) May 23 13:54:46 raspbmusic volumio[923]: Retrying in 5 seconds... May 23 13:54:46 raspbmusic dbus-daemon[554]: [system] Successfully activated service 'org.freedesktop.timedate1' May 23 13:54:46 raspbmusic systemd[1]: Started systemd-timedated.service - Time & Date Service. May 23 13:54:46 raspbmusic setdatetime-helper.sh[1890]: Time is not synchronized. Attempting to sync... May 23 13:54:46 raspbmusic volumio[923]: info: Starting Shairport Sync May 23 13:54:46 raspbmusic sudo[1909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 13:54:46 raspbmusic sudo[1909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:54:46 raspbmusic sudo[1899]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 13:54:46 raspbmusic sudo[1899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 13:54:46 raspbmusic sudo[1912]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 23 13:54:46 raspbmusic sudo[1899]: pam_unix(sudo:session): session closed for user root May 23 13:54:46 raspbmusic sudo[1913]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Fri, 23 May 2025 10:54:46 GMT#015' May 23 13:54:46 raspbmusic sudo[1913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 13:54:46 raspbmusic setdatetime-helper.sh[1915]: Fri May 23 13:54:46 EEST 2025 May 23 13:54:46 raspbmusic setdatetime-helper.sh[1890]: Time synchronized successfully. May 23 13:54:46 raspbmusic systemd-journald[337]: Time jumped backwards, rotating. May 23 13:54:46 raspbmusic sudo[1913]: pam_unix(sudo:session): session closed for user root May 23 13:54:46 raspbmusic systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 23 13:54:46 raspbmusic systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 23 13:54:46 raspbmusic systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 23 13:54:46 raspbmusic systemd[1]: shairport-sync.service: Deactivated successfully. May 23 13:54:46 raspbmusic systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 23 13:54:46 raspbmusic systemd[1]: shairport-sync.service: Consumed 2.666s CPU time. May 23 13:54:46 raspbmusic systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 23 13:54:46 raspbmusic sudo[1909]: pam_unix(sudo:session): session closed for user root May 23 13:54:46 raspbmusic volumio[923]: info: Shairport-Sync Started May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 23 13:54:48 raspbmusic volumio[923]: info: CoreStateMachine::getcurrentVolume May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioRetrievevolume May 23 13:54:48 raspbmusic volumio[923]: info: VolumeController:: Volume=100 Mute =false May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:48 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:48 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:48 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:48 raspbmusic volumio[923]: info: CoreStateMachine::updateTrackBlock May 23 13:54:48 raspbmusic volumio[923]: info: CorePlayQueue::getTrackBlock May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioRetrievevolume May 23 13:54:48 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:48 raspbmusic volumio[923]: info: VolumeController:: Volume=100 Mute =false May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:48 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:48 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:54:48 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:54:48 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:54:48 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:54:50 raspbmusic mpd[1914]: 2025-05-23T13:54:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 23 13:54:50 raspbmusic systemd[1]: Started mpd.service - Music Player Daemon. May 23 13:54:50 raspbmusic sudo[1880]: pam_unix(sudo:session): session closed for user root May 23 13:54:50 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:54:53 raspbmusic volumio[923]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic sudo[1953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 13:54:53 raspbmusic sudo[1953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:54:53 raspbmusic sudo[1953]: pam_unix(sudo:session): session closed for user root May 23 13:54:53 raspbmusic sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 13:54:53 raspbmusic sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 13:54:53 raspbmusic volumio[923]: info: MPD Permissions set May 23 13:54:53 raspbmusic systemd[1]: Stopping mpd.service - Music Player Daemon... May 23 13:54:53 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:54:53 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:54:53 raspbmusic systemd[1]: mpd.service: Deactivated successfully. May 23 13:54:53 raspbmusic systemd[1]: Stopped mpd.service - Music Player Daemon. May 23 13:54:53 raspbmusic systemd[1]: mpd.service: Consumed 4.651s CPU time. May 23 13:54:53 raspbmusic systemd[1]: mpd.socket: Deactivated successfully. May 23 13:54:53 raspbmusic volumio[923]: error: [ytcr] Error connecting MPD: May 23 13:54:53 raspbmusic volumio[923]: (Error) read ECONNRESET May 23 13:54:53 raspbmusic volumio[923]: Error: read ECONNRESET May 23 13:54:53 raspbmusic volumio[923]: at Pipe.onStreamRead (node:internal/stream_base_commons:217:20) May 23 13:54:53 raspbmusic volumio[923]: Retrying in 5 seconds... May 23 13:54:53 raspbmusic systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 23 13:54:53 raspbmusic systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 23 13:54:53 raspbmusic systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 23 13:54:53 raspbmusic systemd[1]: Starting mpd.service - Music Player Daemon... May 23 13:54:53 raspbmusic sudo[1964]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 13:54:53 raspbmusic sudo[1964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 13:54:53 raspbmusic sudo[1964]: pam_unix(sudo:session): session closed for user root May 23 13:54:58 raspbmusic mpd[1966]: 2025-05-23T13:54:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 23 13:54:58 raspbmusic systemd[1]: Started mpd.service - Music Player Daemon. May 23 13:54:58 raspbmusic sudo[1955]: pam_unix(sudo:session): session closed for user root May 23 13:54:58 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:55:05 raspbmusic sudo[1986]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 23 13:55:05 raspbmusic sudo[1986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:55:05 raspbmusic sudo[1986]: pam_unix(sudo:session): session closed for user root May 23 13:55:05 raspbmusic sudo[1988]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 13:55:05 raspbmusic sudo[1988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 13:55:05 raspbmusic sudo[1988]: pam_unix(sudo:session): session closed for user root May 23 13:55:05 raspbmusic volumio[923]: verbose: New Socket.io Connection to 192.168.32.114 from 192.168.33.178 UA: Mozilla/5.0 (X11; Linux x86_64; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 5 May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetVisibleSources May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:55:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 23 13:55:06 raspbmusic volumio[923]: info: Received Get System Info May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 13:55:06 raspbmusic volumio[923]: info: Discovery: Getting this device information May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:55:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:55:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:06 raspbmusic volumio[923]: info: Listing playlists May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 23 13:55:06 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:55:06 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 23 13:55:07 raspbmusic volumio[923]: info: Received Get System Info May 23 13:55:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 13:55:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 13:55:07 raspbmusic volumio[923]: info: Discovery: Getting this device information May 23 13:55:07 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:55:07 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 13:55:07 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 23 13:55:08 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 23 13:55:08 raspbmusic volumio[923]: info: Received Get System Info May 23 13:55:08 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 13:55:08 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 13:55:08 raspbmusic volumio[923]: info: Discovery: Getting this device information May 23 13:55:08 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetState May 23 13:55:08 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:08 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 13:55:08 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPlay May 23 13:55:08 raspbmusic volumio[923]: info: CoreStateMachine::play index undefined May 23 13:55:08 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 13:55:08 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:08 raspbmusic volumio[923]: info: CoreStateMachine::startPlaybackTimer May 23 13:55:08 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:08 raspbmusic volumio[923]: info: [1747997708900] ControllerWebradio::clearAddPlayTrack May 23 13:55:08 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand stop May 23 13:55:08 raspbmusic volumio[923]: info: sendMpdCommand stop took 15 milliseconds May 23 13:55:08 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand clear May 23 13:55:08 raspbmusic volumio[923]: info: May 23 13:55:08 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:55:08 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:55:08 raspbmusic volumio[923]: info: sendMpdCommand clear took 14 milliseconds May 23 13:55:08 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand load "https://online.kissfm.ua/KissFM" May 23 13:55:08 raspbmusic volumio[923]: error: updateQueue error: null May 23 13:55:08 raspbmusic volumio[923]: info: ------------------------------ 37ms May 23 13:55:09 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand add "https://online.kissfm.ua/KissFM" May 23 13:55:09 raspbmusic volumio[923]: info: sendMpdCommand add "https://online.kissfm.ua/KissFM" took 1 milliseconds May 23 13:55:09 raspbmusic volumio[923]: info: CoreStateMachine::setConsumeUpdateService mpd May 23 13:55:09 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand play May 23 13:55:09 raspbmusic volumio[923]: info: May 23 13:55:09 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:55:09 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:55:09 raspbmusic volumio[923]: info: sendMpdCommand play took 9 milliseconds May 23 13:55:09 raspbmusic volumio[923]: info: ------------------------------ 11ms May 23 13:55:10 raspbmusic volumio[923]: info: May 23 13:55:10 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:55:10 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:55:10 raspbmusic volumio[923]: info: May 23 13:55:10 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:55:10 raspbmusic volumio[923]: info: sendMpdCommand status took 32 milliseconds May 23 13:55:10 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:55:10 raspbmusic volumio[923]: info: sendMpdCommand status took 23 milliseconds May 23 13:55:10 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 24 milliseconds May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:55:10 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:55:10 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:55:10 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:10 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":null,"album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:55:10 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:55:10 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:55:10 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus stop May 23 13:55:10 raspbmusic volumio[923]: info: ------------------------------ 77ms May 23 13:55:10 raspbmusic volumio[923]: info: May 23 13:55:10 raspbmusic volumio[923]: ---------------------------- MPD announces system playlist update May 23 13:55:10 raspbmusic volumio[923]: info: Ignoring MPD Status Update May 23 13:55:10 raspbmusic volumio[923]: info: May 23 13:55:10 raspbmusic volumio[923]: ---------------------------- MPD announces state update: player May 23 13:55:10 raspbmusic volumio[923]: info: ControllerMpd::getState May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand status May 23 13:55:10 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 26 milliseconds May 23 13:55:10 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:55:10 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:55:10 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:55:10 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:10 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"KissFM","artist":"Kiss FM","album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:55:10 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:55:10 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:55:10 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:55:10 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:55:10 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:55:10 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:10 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:55:10 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:55:10 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:55:10 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:55:11 raspbmusic volumio[923]: info: ------------------------------ 256ms May 23 13:55:11 raspbmusic volumio[923]: info: ------------------------------ 248ms May 23 13:55:11 raspbmusic volumio[923]: info: sendMpdCommand status took 237 milliseconds May 23 13:55:11 raspbmusic volumio[923]: verbose: ControllerMpd::parseState May 23 13:55:11 raspbmusic volumio[923]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 13:55:11 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:55:11 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:55:11 raspbmusic volumio[923]: info: sendMpdCommand playlistinfo took 128 milliseconds May 23 13:55:11 raspbmusic volumio[923]: verbose: ControllerMpd::parseTrackInfo May 23 13:55:11 raspbmusic volumio[923]: info: ControllerMpd::pushState May 23 13:55:11 raspbmusic volumio[923]: info: CoreCommandRouter::servicePushState May 23 13:55:11 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:11 raspbmusic volumio[923]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"KissFM","artist":"Kiss FM","album":null,"uri":"https://online.kissfm.ua/KissFM","trackType":"ua/KissFM"} May 23 13:55:11 raspbmusic volumio[923]: verbose: CURRENT POSITION 0 May 23 13:55:11 raspbmusic volumio[923]: info: CoreStateMachine::syncState stateService play May 23 13:55:11 raspbmusic volumio[923]: info: CoreStateMachine::syncState currentStatus play May 23 13:55:11 raspbmusic volumio[923]: info: Received an update from plugin. extracting info from payload May 23 13:55:11 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:55:11 raspbmusic volumio[923]: info: CorePlayQueue::getTrack 0 May 23 13:55:11 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 13:55:11 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:55:11 raspbmusic volumio[923]: info: CoreStateMachine::pushState May 23 13:55:11 raspbmusic volumio[923]: info: CoreCommandRouter::volumioPushState May 23 13:55:11 raspbmusic volumio[923]: info: ------------------------------ 646ms May 23 13:55:11 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:55:11 raspbmusic volumio[923]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 13:55:14 raspbmusic volumio[923]: info: CoreCommandRouter::volumioGetQueue May 23 13:55:14 raspbmusic volumio[923]: info: CoreStateMachine::getQueue May 23 13:55:14 raspbmusic volumio[923]: info: CorePlayQueue::getQueue May 23 13:55:15 raspbmusic systemd[1]: systemd-timedated.service: Deactivated successfully. May 23 13:55:15 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 23 13:55:17 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 23 13:55:17 raspbmusic volumio[923]: info: Preload queue cleared May 23 13:55:20 raspbmusic volumio[923]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 23 13:55:21 raspbmusic volumio[923]: Use XMLElement.setAttribute instead May 23 13:55:21 raspbmusic volumio[923]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 13:55:21 raspbmusic volumio[923]: TypeError: children[i].attr(...).value is not a function May 23 13:55:21 raspbmusic volumio[923]: at /volumio/app/plugins/music_service/webradio/index.js:428:46 May 23 13:55:21 raspbmusic volumio[923]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) May 23 13:55:21 raspbmusic volumio[923]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 13:55:26 raspbmusic sudo[2040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-23 13:54' May 23 13:55:26 raspbmusic sudo[2040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025" VOLUMIO_VERSION="0.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"