-- Logs begin at Fri 2025-05-23 08:57:27 MST, end at Fri 2025-05-23 12:04:36 MST. -- May 23 12:03:00 volumiojls volumio[1074]: info: Preload queue cleared May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::volumioReplaceandPlayItems May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::ClearQueue May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::stop May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::stPlaybackTimer May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::updateTrackBlock May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrackBlock May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::serviceStop May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::serviceStop May 23 12:03:00 volumiojls volumio[1074]: info: Spotify Stop May 23 12:03:00 volumiojls volumio[1074]: SPOTIFY: SPOTIFY STOP May 23 12:03:00 volumiojls volumio[1074]: SPOTIFY: {"status":"play","position":0,"title":"Summertime Sadness","artist":"LexMorris","album":"Summertime Sadness","albumart":"https://i.scdn.co/image/ab67616d0000b2730b066fff1090dd96c6d94ddb","uri":"spotify:track:6AAi8tL7pqRG5YGorPyKxU","trackType":"spotify","codec":"ogg","seek":0,"duration":161,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} May 23 12:03:00 volumiojls volumio[1074]: info: Sending Spotify command to local API: /player/pause May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::clearPlayQueue May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::saveQueue May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushQueue May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::addQueueItems May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::addQueueItems May 23 12:03:00 volumiojls volumio[1074]: info: Preload queue cleared May 23 12:03:00 volumiojls volumio[1074]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s95882 May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 23 12:03:00 volumiojls go-librespot[1278]: time="2025-05-23T12:03:00-07:00" level=debug msg="pause track at 23217ms" May 23 12:03:00 volumiojls go-librespot[1278]: time="2025-05-23T12:03:00-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 23 12:03:00 volumiojls go-librespot[1278]: time="2025-05-23T12:03:00-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 23 12:03:00 volumiojls go-librespot[1278]: time="2025-05-23T12:03:00-07:00" level=trace msg="emitting websocket event: paused" May 23 12:03:00 volumiojls volumio[1074]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6AAi8tL7pqRG5YGorPyKxU","play_origin":"go-librespot"}} May 23 12:03:00 volumiojls volumio[1074]: SPOTIFY: PUSH STATE SPOTIFY May 23 12:03:00 volumiojls volumio[1074]: SPOTIFY: {"status":"pause","service":"spop","title":"Summertime Sadness","artist":"LexMorris, HALUNA, Deep Mage","album":"Summertime Sadness","albumart":"https://i.scdn.co/image/ab67616d00001e020b066fff1090dd96c6d94ddb","uri":"spotify:track:6AAi8tL7pqRG5YGorPyKxU","trackType":"spotify","seek":23000,"duration":161,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:00 volumiojls volumio[1074]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Summertime Sadness","artist":"LexMorris, HALUNA, Deep Mage","album":"Summertime Sadness","albumart":"https://i.scdn.co/image/ab67616d00001e020b066fff1090dd96c6d94ddb","uri":"spotify:track:6AAi8tL7pqRG5YGorPyKxU","trackType":"spotify","seek":23000,"duration":161,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 23 12:03:00 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService pause May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus stop May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushQueue May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::saveQueue May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::updateTrackBlock May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrackBlock May 23 12:03:00 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPlay May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::play index 0 May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::stop May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::play index undefined May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:00 volumiojls volumio[1074]: info: CoreStateMachine::startPlaybackTimer May 23 12:03:00 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:00 volumiojls volumio[1074]: info: [1748026980516] ControllerWebradio::clearAddPlayTrack May 23 12:03:00 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand stop May 23 12:03:00 volumiojls volumio[1074]: info: sendMpdCommand stop took 2 milliseconds May 23 12:03:00 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand clear May 23 12:03:00 volumiojls volumio[1074]: info: sendMpdCommand clear took 0 milliseconds May 23 12:03:00 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand load "http://s8.mediastreaming.it:7050" May 23 12:03:00 volumiojls volumio[1074]: info: May 23 12:03:00 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:00 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:00 volumiojls volumio[1074]: info: May 23 12:03:00 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:00 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:00 volumiojls volumio[1074]: info: May 23 12:03:00 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:00 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:00 volumiojls volumio[1074]: error: Upnp client error: Error: This socket has been ended by the other party May 23 12:03:01 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand add "http://s8.mediastreaming.it:7050" May 23 12:03:01 volumiojls volumio[1074]: error: updateQueue error: null May 23 12:03:01 volumiojls volumio[1074]: error: updateQueue error: null May 23 12:03:01 volumiojls volumio[1074]: error: updateQueue error: null May 23 12:03:01 volumiojls volumio[1074]: info: May 23 12:03:01 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:01 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:01 volumiojls volumio[1074]: info: ------------------------------ 1381ms May 23 12:03:01 volumiojls volumio[1074]: info: ------------------------------ 1379ms May 23 12:03:01 volumiojls volumio[1074]: info: ------------------------------ 1378ms May 23 12:03:01 volumiojls volumio[1074]: info: sendMpdCommand add "http://s8.mediastreaming.it:7050" took 2 milliseconds May 23 12:03:01 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService mpd May 23 12:03:01 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand play May 23 12:03:01 volumiojls volumio[1074]: info: May 23 12:03:01 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:01 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:01 volumiojls volumio[1074]: info: May 23 12:03:01 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:01 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:01 volumiojls volumio[1074]: info: ------------------------------ 4ms May 23 12:03:01 volumiojls volumio[1074]: info: sendMpdCommand play took 2 milliseconds May 23 12:03:01 volumiojls volumio[1074]: info: ------------------------------ 2ms May 23 12:03:01 volumiojls volumio[1074]: info: ------------------------------ 1ms May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 3 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 5 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 3 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 3 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 3 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: 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":"s8.mediastreaming.it:7050","artist":null,"album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus stop May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: 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":"s8.mediastreaming.it:7050","artist":null,"album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: 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":"s8.mediastreaming.it:7050","artist":null,"album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 18ms May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 21ms May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 20ms May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 14 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 12 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 12 milliseconds May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: 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":"s8.mediastreaming.it:7050","artist":null,"album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: 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":"s8.mediastreaming.it:7050","artist":null,"album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: 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":"s8.mediastreaming.it:7050","artist":null,"album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 32ms May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 29ms May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 29ms May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:02 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:02 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 3ms May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 2ms May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 1 milliseconds May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces system playlist update May 23 12:03:02 volumiojls volumio[1074]: info: Ignoring MPD Status Update May 23 12:03:02 volumiojls volumio[1074]: info: May 23 12:03:02 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 1 milliseconds May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 1ms May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: verbose: STATE SERVICE {"status":"play","position":0,"seek":860,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio Salento","artist":"RADIO SALENTO","album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: verbose: STATE SERVICE {"status":"play","position":0,"seek":860,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio Salento","artist":"RADIO SALENTO","album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 16ms May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 15ms May 23 12:03:02 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 12 milliseconds May 23 12:03:02 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:02 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:02 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:02 volumiojls volumio[1074]: verbose: STATE SERVICE {"status":"play","position":0,"seek":860,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio Salento","artist":"RADIO SALENTO","album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:02 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:02 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:02 volumiojls volumio[1074]: info: ------------------------------ 19ms May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:02 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:05 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:05 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:08 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:09 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:10 volumiojls go-librespot[1278]: time="2025-05-23T12:03:10-07:00" level=trace msg="sent dealer ping" May 23 12:03:10 volumiojls go-librespot[1278]: time="2025-05-23T12:03:10-07:00" level=trace msg="received dealer pong" May 23 12:03:11 volumiojls volumio[1074]: Searching all installed plugins May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: , search May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: last_100 , search May 23 12:03:11 volumiojls volumio[1074]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: pandora , search May 23 12:03:11 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: spop , search May 23 12:03:12 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:12 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:12 volumiojls volumio[1074]: info: All search sources collected, pushing search results May 23 12:03:15 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:15 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:18 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:18 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:21 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:21 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:24 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:24 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:26 volumiojls volumio[1074]: info: Preload queue cleared May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioReplaceandPlayItems May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::ClearQueue May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::stPlaybackTimer May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::updateTrackBlock May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrackBlock May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::serviceStop May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::serviceStop May 23 12:03:26 volumiojls volumio[1074]: info: [1748027006715] ControllerWebradio::stop May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand stop May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::clearPlayQueue May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::saveQueue May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushQueue May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::addQueueItems May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::addQueueItems May 23 12:03:26 volumiojls volumio[1074]: info: Preload queue cleared May 23 12:03:26 volumiojls volumio[1074]: info: Adding Item to queue: spotify:track:41R2bEqF0LBPAsp70uzT8M May 23 12:03:26 volumiojls volumio[1074]: info: Exploding uri spotify:track:41R2bEqF0LBPAsp70uzT8M in service spop May 23 12:03:26 volumiojls volumio[1074]: SPOTIFY: EXPLODING URI:spotify:track:41R2bEqF0LBPAsp70uzT8M May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand stop took 33 milliseconds May 23 12:03:26 volumiojls volumio[1074]: info: May 23 12:03:26 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:26 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:26 volumiojls volumio[1074]: info: May 23 12:03:26 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:26 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:26 volumiojls volumio[1074]: info: May 23 12:03:26 volumiojls volumio[1074]: ---------------------------- MPD announces state update: player May 23 12:03:26 volumiojls volumio[1074]: info: ControllerMpd::getState May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand status May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand status took 3 milliseconds May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand status took 2 milliseconds May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand status took 1 milliseconds May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::parseState May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 1 milliseconds May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 1 milliseconds May 23 12:03:26 volumiojls volumio[1074]: info: sendMpdCommand playlistinfo took 2 milliseconds May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:26 volumiojls volumio[1074]: verbose: ControllerMpd::parseTrackInfo May 23 12:03:26 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: 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":"Radio Salento","artist":"RADIO SALENTO","album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:26 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: No code May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: 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":"Radio Salento","artist":"RADIO SALENTO","album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:26 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: No code May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: ControllerMpd::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: 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":"Radio Salento","artist":"RADIO SALENTO","album":null,"uri":"http://s8.mediastreaming.it:7050","trackType":"it:7050"} May 23 12:03:26 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: No code May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:26 volumiojls volumio[1074]: info: ------------------------------ 26ms May 23 12:03:26 volumiojls volumio[1074]: info: ------------------------------ 26ms May 23 12:03:26 volumiojls volumio[1074]: info: ------------------------------ 25ms May 23 12:03:26 volumiojls volumio[1074]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","service":"spop","name":"CLOVER","artist":"IDK","album":"CLOVER","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b273a997c49b862ac6c9a509072c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushQueue May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::saveQueue May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::updateTrackBlock May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrackBlock May 23 12:03:26 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPlay May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::play index 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::stop May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::play index undefined May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::setConsumeUpdateService undefined May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: CoreStateMachine::startPlaybackTimer May 23 12:03:26 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:26 volumiojls volumio[1074]: info: [1748027006928] ControllerSpotify::clearAddPlayTrack May 23 12:03:26 volumiojls volumio[1074]: info: Sending Spotify command with payload to local API: /player/play May 23 12:03:26 volumiojls go-librespot[1278]: time="2025-05-23T12:03:26-07:00" level=debug msg="resolved context of track" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:26 volumiojls go-librespot[1278]: time="2025-05-23T12:03:26-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:26 volumiojls go-librespot[1278]: time="2025-05-23T12:03:26-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=trace msg="emitting websocket event: will_play" May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","play_origin":"go-librespot"}} May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="selected format OGG_VORBIS_320 (f4288d353054e9727b12301b4a5e3cd20702fbff)" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="requested aes key for file f4288d353054e9727b12301b4a5e3cd20702fbff, gid: 41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="fetched first chunk of 16, total size is 8052209 bytes" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=info msg="loaded track \"CLOVER\" (paused: false, position: 0ms, duration: 190003ms, prefetched: false)" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=trace msg="scheduling prefetch in 160s" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=trace msg="emitting websocket event: metadata" May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","name":"CLOVER","artist_names":["IDK","Joey Valence \u0026 Brae"],"album_name":"CLOVER","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a997c49b862ac6c9a509072c","position":0,"duration":190003,"release_date":"year:2025 month:3 day:21","track_number":1,"disc_number":1}} May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=trace msg="emitting websocket event: playing" May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","play_origin":"go-librespot"}} May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: PUSH STATE SPOTIFY May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: {"status":"play","service":"spop","title":"CLOVER","artist":"IDK, Joey Valence & Brae","album":"CLOVER","albumart":"https://i.scdn.co/image/ab67616d00001e02a997c49b862ac6c9a509072c","uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","trackType":"spotify","seek":0,"duration":190,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 23 12:03:27 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:27 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:27 volumiojls volumio[1074]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"CLOVER","artist":"IDK, Joey Valence & Brae","album":"CLOVER","albumart":"https://i.scdn.co/image/ab67616d00001e02a997c49b862ac6c9a509072c","uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","trackType":"spotify","seek":0,"duration":190,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 23 12:03:27 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:27 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:27 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus stop May 23 12:03:27 volumiojls go-librespot[1278]: time="2025-05-23T12:03:27-07:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: PUSH STATE SPOTIFY May 23 12:03:27 volumiojls volumio[1074]: SPOTIFY: {"status":"play","service":"spop","title":"CLOVER","artist":"IDK, Joey Valence & Brae","album":"CLOVER","albumart":"https://i.scdn.co/image/ab67616d00001e02a997c49b862ac6c9a509072c","uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","trackType":"spotify","seek":0,"duration":190,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 23 12:03:27 volumiojls volumio[1074]: info: CoreCommandRouter::servicePushState May 23 12:03:27 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:27 volumiojls volumio[1074]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"CLOVER","artist":"IDK, Joey Valence & Brae","album":"CLOVER","albumart":"https://i.scdn.co/image/ab67616d00001e02a997c49b862ac6c9a509072c","uri":"spotify:track:41R2bEqF0LBPAsp70uzT8M","trackType":"spotify","seek":0,"duration":190,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 23 12:03:27 volumiojls volumio[1074]: verbose: CURRENT POSITION 0 May 23 12:03:27 volumiojls volumio[1074]: info: CoreStateMachine::syncState stateService play May 23 12:03:27 volumiojls volumio[1074]: info: CoreStateMachine::syncState currentStatus play May 23 12:03:27 volumiojls volumio[1074]: info: Received an update from plugin. extracting info from payload May 23 12:03:27 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:27 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:27 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 12:03:27 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:27 volumiojls volumio[1074]: info: CoreStateMachine::pushState May 23 12:03:27 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:27 volumiojls volumio[1074]: info: CoreCommandRouter::volumioPushState May 23 12:03:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:29 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:29 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:29 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:29 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:29 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:29 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:29 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:29 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:29 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:31 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:31 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:31 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:31 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:31 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:31 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:31 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:32 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:32 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:32 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:32 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:32 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:33 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:33 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:33 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:33 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:33 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:33 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:34 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:34 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:34 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:34 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:34 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:34 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:35 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:35 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:35 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:35 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:35 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:36 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:36 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:36 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:36 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:36 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:37 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:37 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:37 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:37 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:37 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:39 volumiojls go-librespot[1278]: time="2025-05-23T12:03:39-07:00" level=debug msg="fetched chunk 4/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:39 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:39 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:39 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:39 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:39 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:39 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:39 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:03:39 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:03:39 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:03:40 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:40 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:40 volumiojls go-librespot[1278]: time="2025-05-23T12:03:40-07:00" level=trace msg="sent dealer ping" May 23 12:03:40 volumiojls go-librespot[1278]: time="2025-05-23T12:03:40-07:00" level=trace msg="received dealer pong" May 23 12:03:43 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:43 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:46 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:46 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:49 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:49 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:52 volumiojls go-librespot[1278]: time="2025-05-23T12:03:52-07:00" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:03:52 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:52 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:55 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:55 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:03:58 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:03:58 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:01 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:01 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:04 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:04 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:05 volumiojls go-librespot[1278]: time="2025-05-23T12:04:05-07:00" level=debug msg="fetched chunk 6/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:04:07 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:07 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:10 volumiojls go-librespot[1278]: time="2025-05-23T12:04:10-07:00" level=trace msg="received accesspoint ping" May 23 12:04:10 volumiojls go-librespot[1278]: time="2025-05-23T12:04:10-07:00" level=trace msg="received accesspoint pong ack" May 23 12:04:10 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:10 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:10 volumiojls go-librespot[1278]: time="2025-05-23T12:04:10-07:00" level=trace msg="sent dealer ping" May 23 12:04:10 volumiojls go-librespot[1278]: time="2025-05-23T12:04:10-07:00" level=trace msg="received dealer pong" May 23 12:04:13 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:13 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:16 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:16 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:17 volumiojls go-librespot[1278]: time="2025-05-23T12:04:17-07:00" level=debug msg="fetched chunk 7/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:04:19 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:19 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:22 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:22 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:25 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:25 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:27 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:27 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:27 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:04:27 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:04:27 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:28 volumiojls volumio[1074]: info: Listing playlists May 23 12:04:28 volumiojls volumio[1074]: info: Listing playlists May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:04:28 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:28 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:28 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:29 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:29 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:29 volumiojls go-librespot[1278]: time="2025-05-23T12:04:29-07:00" level=debug msg="fetched chunk 8/15, size: 524288" uri="spotify:track:41R2bEqF0LBPAsp70uzT8M" May 23 12:04:30 volumiojls sudo[10742]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 23 12:04:30 volumiojls sudo[10742]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 12:04:30 volumiojls sudo[10742]: pam_unix(sudo:session): session closed for user root May 23 12:04:30 volumiojls sudo[10746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 12:04:30 volumiojls sudo[10746]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 12:04:30 volumiojls sudo[10746]: pam_unix(sudo:session): session closed for user root May 23 12:04:30 volumiojls volumio[1074]: verbose: New Socket.io Connection to 192.168.4.30 from 192.168.4.218 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Mobile Safari/537.36 Total Clients: 7 May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:30 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:04:30 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:04:30 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetVisibleSources May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:30 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:04:30 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:04:30 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:04:30 volumiojls volumio[1074]: info: Listing playlists May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 23 12:04:30 volumiojls volumio[1074]: info: Received Get System Info May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 12:04:30 volumiojls volumio[1074]: info: Discovery: Getting this device information May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:30 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:30 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 23 12:04:30 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 23 12:04:31 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 23 12:04:31 volumiojls volumio[1074]: info: Received Get System Info May 23 12:04:31 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 12:04:31 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 12:04:31 volumiojls volumio[1074]: info: Discovery: Getting this device information May 23 12:04:31 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:31 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:31 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 12:04:32 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:32 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:32 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 23 12:04:32 volumiojls volumio[1074]: info: Received Get System Info May 23 12:04:32 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 12:04:32 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 12:04:32 volumiojls volumio[1074]: info: Discovery: Getting this device information May 23 12:04:32 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:32 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:32 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 12:04:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:33 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:33 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:33 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:33 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetQueue May 23 12:04:33 volumiojls volumio[1074]: info: CoreStateMachine::getQueue May 23 12:04:33 volumiojls volumio[1074]: info: CorePlayQueue::getQueue May 23 12:04:35 volumiojls volumio[1074]: info: CoreCommandRouter::volumioGetState May 23 12:04:35 volumiojls volumio[1074]: info: CorePlayQueue::getTrack 0 May 23 12:04:35 volumiojls volumio[1074]: info: CoreCommandRouter::executeOnPlugin: metavolumio , superSearch May 23 12:04:35 volumiojls volumio[1074]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 12:04:35 volumiojls volumio[1074]: TypeError: Cannot read property 'then' of undefined May 23 12:04:35 volumiojls volumio[1074]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:470:20) May 23 12:04:35 volumiojls volumio[1074]: at Socket.emit (events.js:315:20) May 23 12:04:35 volumiojls volumio[1074]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 23 12:04:35 volumiojls volumio[1074]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 23 12:04:35 volumiojls volumio[1074]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 12:04:36 volumiojls sudo[10779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-23 12:03 May 23 12:04:36 volumiojls sudo[10779]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"