May 26 20:23:00 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 26 20:23:00 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 26 20:23:01 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:02 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 26 20:23:02 volumio volumio[1172]: info: Getting webradio selection May 26 20:23:02 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:02 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 26 20:23:03 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::serviceStop May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::serviceStop May 26 20:23:03 volumio volumio[1172]: info: Spotify Stop May 26 20:23:03 volumio volumio[1172]: SPOTIFY: SPOTIFY STOP May 26 20:23:03 volumio volumio[1172]: SPOTIFY: {"status":"play","title":"Aviv","artist":"Shye Ben Tzur, Jonny Greenwood, The Rajasthan Express","album":"Ranjha","albumart":"https://i.scdn.co/image/ab67616d00001e02cabdfdda240645af5d3e4351","uri":"spotify:track:5YG0TsHWSKtWku8C3fM28W","trackType":"spotify","codec":"ogg","seek":31001,"duration":261,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":10,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} May 26 20:23:03 volumio volumio[1172]: info: Sending Spotify command to local API: /player/pause May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:03 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:03 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::stPlaybackTimer May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::serviceStop May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::serviceStop May 26 20:23:03 volumio volumio[1172]: info: [1779819783427] ControllerWebradio::stop May 26 20:23:03 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:03 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:03.430Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_STOPPED positionMs=0 volume=10 May 26 20:23:03 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:03.431Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:03 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:03 volumio volumio[1172]: info: sendMpdCommand stop took 12 milliseconds May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:03 volumio volumio[1172]: info: [1779819783444] ControllerWebradio::clearAddPlayTrack May 26 20:23:03 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:03 volumio go-librespot[2719]: time="2026-05-26T20:23:03+02:00" level=debug msg="pause track at 139158ms" May 26 20:23:03 volumio volumio[1172]: info: sendMpdCommand stop took 2 milliseconds May 26 20:23:03 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:03 volumio volumio[1172]: info: May 26 20:23:03 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:03 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:03 volumio volumio[1172]: info: sendMpdCommand clear took 2 milliseconds May 26 20:23:03 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:03 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:03 volumio volumio[1172]: info: ------------------------------ 4ms May 26 20:23:03 volumio go-librespot[2719]: time="2026-05-26T20:23:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 26 20:23:03 volumio go-librespot[2719]: time="2026-05-26T20:23:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 26 20:23:03 volumio go-librespot[2719]: time="2026-05-26T20:23:03+02:00" level=trace msg="emitting websocket event: paused" May 26 20:23:03 volumio volumio[1172]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:0J2LzthCjjSrl2TnAef2Pu","uri":"spotify:track:5YG0TsHWSKtWku8C3fM28W","play_origin":"album"}} May 26 20:23:03 volumio volumio[1172]: info: Spotify is playing in volatile mode May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:03 volumio volumio[1172]: SPOTIFY: UNSET VOLATILE May 26 20:23:03 volumio volumio[1172]: SPOTIFY: {"status":"stop","position":0,"title":"Absolut Radio","artist":"","albumart":"https://radio-directory.firebaseapp.com/volumio/src/images/radio-thumbnails/Absolut Radio.jpg","uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":"webradio","seek":0,"samplerate":"","bitdepth":"","channels":0,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":10,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"webradio","volatile":false,"service":"webradio"} May 26 20:23:03 volumio volumio[1172]: SPOTIFY: PUSH STATE SPOTIFY May 26 20:23:03 volumio volumio[1172]: SPOTIFY: {"status":"pause","service":"spop","title":"Aviv","artist":"Shye Ben Tzur, Jonny Greenwood, The Rajasthan Express","album":"Ranjha","albumart":"https://i.scdn.co/image/ab67616d00001e02cabdfdda240645af5d3e4351","uri":"spotify:track:5YG0TsHWSKtWku8C3fM28W","trackType":"spotify","seek":139001,"duration":261,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:03 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:03.613Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PAUSED positionMs=139001 volume=10 May 26 20:23:03 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:03.614Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=spotify:track:5YG0TsHWSKtWku8C3fM28W title=Aviv May 26 20:23:03 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::serviceStop May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::serviceStop May 26 20:23:03 volumio volumio[1172]: info: Spotify Stop May 26 20:23:03 volumio volumio[1172]: SPOTIFY: SPOTIFY STOP May 26 20:23:03 volumio volumio[1172]: SPOTIFY: {"status":"stop","position":0,"title":"Absolut Radio","artist":"","albumart":"https://radio-directory.firebaseapp.com/volumio/src/images/radio-thumbnails/Absolut Radio.jpg","uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":"webradio","seek":0,"samplerate":"","bitdepth":"","channels":0,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":10,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"webradio","volatile":false,"service":"webradio"} May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:03 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:03 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. May 26 20:23:03 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:03 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::stPlaybackTimer May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:03 volumio volumio[1172]: info: CoreStateMachine::serviceStop May 26 20:23:03 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:03 volumio volumio[1172]: info: CoreCommandRouter::serviceStop May 26 20:23:03 volumio volumio[1172]: info: [1779819783651] ControllerWebradio::stop May 26 20:23:03 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:03 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:03.654Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_STOPPED positionMs=0 volume=10 May 26 20:23:03 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:03.655Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:03 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:03 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:04 volumio volumio[1172]: info: sendMpdCommand stop took 1286 milliseconds May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:04 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:04 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:04 volumio volumio[1172]: info: [1779819784939] ControllerWebradio::clearAddPlayTrack May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:04 volumio volumio[1172]: info: May 26 20:23:04 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:04 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:04 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 2 milliseconds May 26 20:23:04 volumio volumio[1172]: info: sendMpdCommand stop took 1 milliseconds May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:04 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:04 volumio volumio[1172]: info: sendMpdCommand play took 2 milliseconds May 26 20:23:04 volumio volumio[1172]: info: May 26 20:23:04 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:04 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:04 volumio volumio[1172]: info: May 26 20:23:04 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:04 volumio volumio[1172]: info: sendMpdCommand clear took 5 milliseconds May 26 20:23:04 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:04 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:04 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:04 volumio volumio[1172]: info: sendMpdCommand status took 12 milliseconds May 26 20:23:04 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:04 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:04 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:04 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:04 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:04 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:04 volumio volumio[1172]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 26 20:23:04 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::syncState stateService stop May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus stop May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:04 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:04 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:04 volumio volumio[1172]: info: No code May 26 20:23:04 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:04 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.970Z level=WARN msg="received unknown player status" component=volumio status="" May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.971Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_STOPPED positionMs=0 volume=10 May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.971Z level=WARN msg="received unknown player status" component=volumio status="" May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.971Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_STOPPED positionMs=0 volume=10 May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.972Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id= title= May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.972Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id= title= May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.973Z level=WARN msg="received unknown player status" component=volumio status="" May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.973Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_STOPPED positionMs=0 volume=10 May 26 20:23:04 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:04.974Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id= title= May 26 20:23:04 volumio volumio[1172]: info: ------------------------------ 41ms May 26 20:23:04 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:04 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:04 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:05 volumio volumio[1172]: info: May 26 20:23:05 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:05 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:05 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 1 milliseconds May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:05 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:05 volumio volumio[1172]: info: sendMpdCommand play took 2 milliseconds May 26 20:23:05 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:05 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:05 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:05 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:05 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:05 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:05 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:05 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:05 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:05 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:05 volumio volumio[1172]: info: [1779819785757] ControllerWebradio::clearAddPlayTrack May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:05 volumio volumio[1172]: info: May 26 20:23:05 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:05 volumio volumio[1172]: info: sendMpdCommand stop took 104 milliseconds May 26 20:23:05 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:05 volumio volumio[1172]: info: May 26 20:23:05 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:05 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:05 volumio volumio[1172]: info: sendMpdCommand status took 1 milliseconds May 26 20:23:05 volumio volumio[1172]: info: sendMpdCommand clear took 1 milliseconds May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:05 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:05 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:05 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:23:05 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:05 volumio volumio[1172]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 26 20:23:05 volumio volumio[1172]: info: ------------------------------ 5ms May 26 20:23:06 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:06 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:06 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:06 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:06 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:06 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:06 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:06 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:06 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:06 volumio volumio[1172]: info: [1779819786796] ControllerWebradio::clearAddPlayTrack May 26 20:23:06 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:06 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:06 volumio volumio[1172]: info: sendMpdCommand stop took 154 milliseconds May 26 20:23:06 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:06 volumio volumio[1172]: info: May 26 20:23:06 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:06 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:06 volumio volumio[1172]: info: May 26 20:23:06 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:06 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:06 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 1 milliseconds May 26 20:23:06 volumio volumio[1172]: info: sendMpdCommand clear took 1 milliseconds May 26 20:23:06 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:06 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:06 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:06 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:06 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:06 volumio volumio[1172]: info: ------------------------------ 3ms May 26 20:23:06 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:06 volumio volumio[1172]: info: sendMpdCommand play took 2 milliseconds May 26 20:23:07 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:07 volumio volumio[1172]: info: May 26 20:23:07 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:07 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:07 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 1 milliseconds May 26 20:23:07 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:07 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:07 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:07 volumio volumio[1172]: info: sendMpdCommand play took 1 milliseconds May 26 20:23:08 volumio volumio[1172]: info: May 26 20:23:08 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:08 volumio volumio[1172]: info: May 26 20:23:08 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand status took 17 milliseconds May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand status took 4 milliseconds May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 3 milliseconds May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:08 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:08 volumio volumio[1172]: 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":"mp3","artist":null,"album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:08 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus stop May 26 20:23:08 volumio volumio[1172]: info: ------------------------------ 30ms May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 9 milliseconds May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:08 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:08 volumio volumio[1172]: 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":"mp3","artist":null,"album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:08 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:23:08 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:08 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.598Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.599Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.599Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.599Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:08 volumio volumio[1172]: info: ------------------------------ 34ms May 26 20:23:08 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:08 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:08 volumio volumio[1172]: info: May 26 20:23:08 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:08 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:08 volumio volumio[1172]: info: May 26 20:23:08 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:08 volumio volumio[1172]: info: May 26 20:23:08 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:08 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:08 volumio volumio[1172]: info: May 26 20:23:08 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:08 volumio volumio[1172]: info: ------------------------------ 3ms May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand status took 2 milliseconds May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:08 volumio volumio[1172]: info: ------------------------------ 3ms May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand status took 2 milliseconds May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:08 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:08 volumio volumio[1172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":863,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:08 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:23:08 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.632Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.633Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)" May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.634Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.634Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)" May 26 20:23:08 volumio volumio[1172]: info: ------------------------------ 27ms May 26 20:23:08 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 21 milliseconds May 26 20:23:08 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:08 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:08 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:08 volumio volumio[1172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":863,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:08 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:23:08 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:08 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:08 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.652Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.652Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)" May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.654Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:08 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:08.654Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)" May 26 20:23:08 volumio volumio[1172]: info: ------------------------------ 48ms May 26 20:23:08 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:08 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:08 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:08 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:10 volumio go-librespot[2719]: time="2026-05-26T20:23:10+02:00" level=trace msg="sent dealer ping" May 26 20:23:10 volumio go-librespot[2719]: time="2026-05-26T20:23:10+02:00" level=trace msg="received dealer pong" May 26 20:23:14 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::stPlaybackTimer May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::serviceStop May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::serviceStop May 26 20:23:14 volumio volumio[1172]: info: [1779819794078] ControllerWebradio::stop May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:14 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:14 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:14 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:14.081Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_STOPPED positionMs=0 volume=10 May 26 20:23:14 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:14.082Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:14 volumio volumio[1172]: info: [1779819794096] ControllerWebradio::clearAddPlayTrack May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:14 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:14 volumio volumio[1172]: info: sendMpdCommand stop took 42 milliseconds May 26 20:23:14 volumio volumio[1172]: info: May 26 20:23:14 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:14 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:14 volumio volumio[1172]: info: sendMpdCommand stop took 25 milliseconds May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:14 volumio volumio[1172]: info: May 26 20:23:14 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:14 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:14 volumio volumio[1172]: info: sendMpdCommand status took 1 milliseconds May 26 20:23:14 volumio volumio[1172]: info: sendMpdCommand clear took 1 milliseconds May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:14 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:14 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:14 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:14 volumio volumio[1172]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 26 20:23:14 volumio volumio[1172]: info: ------------------------------ 3ms May 26 20:23:14 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:14 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:14 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:14 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:14 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:14 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:14 volumio volumio[1172]: info: [1779819794752] ControllerWebradio::clearAddPlayTrack May 26 20:23:14 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:15 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:15 volumio volumio[1172]: info: sendMpdCommand stop took 601 milliseconds May 26 20:23:15 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:15 volumio volumio[1172]: info: May 26 20:23:15 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:15 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:15 volumio volumio[1172]: info: May 26 20:23:15 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:15 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:15 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 2 milliseconds May 26 20:23:15 volumio volumio[1172]: info: sendMpdCommand clear took 1 milliseconds May 26 20:23:15 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:15 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:15 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:15 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:15 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:15 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:15 volumio volumio[1172]: info: ------------------------------ 2ms May 26 20:23:15 volumio volumio[1172]: info: sendMpdCommand play took 1 milliseconds May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:16 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 1 milliseconds May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:16 volumio volumio[1172]: info: May 26 20:23:16 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:16 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:16 volumio volumio[1172]: info: sendMpdCommand play took 1 milliseconds May 26 20:23:16 volumio volumio[1172]: info: ------------------------------ 1ms May 26 20:23:16 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:16 volumio volumio[1172]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::ClearQueue May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::clearPlayQueue May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:16 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::addQueueItems May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::addQueueItems May 26 20:23:16 volumio volumio[1172]: info: Preload queue cleared May 26 20:23:16 volumio volumio[1172]: info: Adding Item to queue: https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 May 26 20:23:16 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 26 20:23:16 volumio volumio[1172]: info: CoreCommandRouter::volumioPushQueue May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::saveQueue May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::updateTrackBlock May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::getTrackBlock May 26 20:23:16 volumio volumio[1172]: info: CoreCommandRouter::volumioPlay May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::play index 0 May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::stop May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::play index undefined May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:16 volumio volumio[1172]: info: CoreStateMachine::startPlaybackTimer May 26 20:23:16 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:16 volumio volumio[1172]: info: [1779819796697] ControllerWebradio::clearAddPlayTrack May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand stop May 26 20:23:16 volumio volumio[1172]: info: May 26 20:23:16 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:16 volumio volumio[1172]: info: sendMpdCommand stop took 4 milliseconds May 26 20:23:16 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand clear May 26 20:23:16 volumio volumio[1172]: info: May 26 20:23:16 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:16 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:16 volumio volumio[1172]: info: sendMpdCommand status took 1 milliseconds May 26 20:23:16 volumio volumio[1172]: info: sendMpdCommand clear took 1 milliseconds May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:16 volumio volumio[1172]: error: updateQueue error: null May 26 20:23:16 volumio volumio[1172]: info: ------------------------------ 5ms May 26 20:23:16 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:23:16 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:16 volumio volumio[1172]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 26 20:23:16 volumio volumio[1172]: info: ------------------------------ 7ms May 26 20:23:17 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" May 26 20:23:17 volumio volumio[1172]: info: May 26 20:23:17 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:17 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:17 volumio volumio[1172]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 1 milliseconds May 26 20:23:17 volumio volumio[1172]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 20:23:17 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand play May 26 20:23:17 volumio volumio[1172]: info: ------------------------------ 1ms May 26 20:23:17 volumio volumio[1172]: info: sendMpdCommand play took 1 milliseconds May 26 20:23:18 volumio volumio[1172]: info: May 26 20:23:18 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:18 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:18 volumio volumio[1172]: info: May 26 20:23:18 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:18 volumio volumio[1172]: info: sendMpdCommand status took 19 milliseconds May 26 20:23:18 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:18 volumio volumio[1172]: info: sendMpdCommand status took 3 milliseconds May 26 20:23:18 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 2 milliseconds May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:18 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:18 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:18 volumio volumio[1172]: 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":"mp3","artist":null,"album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:18 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus stop May 26 20:23:18 volumio volumio[1172]: info: ------------------------------ 29ms May 26 20:23:18 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:18 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:18 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:18 volumio volumio[1172]: 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":"mp3","artist":null,"album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:18 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:23:18 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:18 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.657Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.657Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.658Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.658Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio" May 26 20:23:18 volumio volumio[1172]: info: ------------------------------ 41ms May 26 20:23:18 volumio volumio[1172]: info: May 26 20:23:18 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:18 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:18 volumio volumio[1172]: info: May 26 20:23:18 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:18 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:18 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:18 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:18 volumio volumio[1172]: info: ------------------------------ 7ms May 26 20:23:18 volumio volumio[1172]: info: sendMpdCommand status took 6 milliseconds May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:18 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 0 milliseconds May 26 20:23:18 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:18 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:18 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:18 volumio volumio[1172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":854,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:18 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:23:18 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:18 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:18 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.692Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.692Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=0 volume=10 May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.693Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)" May 26 20:23:18 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:18.693Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="DJ ANTOINE, TIMATI - WELCOME TO ST. TROPEZ (DJ ANTOINE VS MAD MARK)" May 26 20:23:18 volumio volumio[1172]: info: ------------------------------ 32ms May 26 20:23:18 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:18 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:19 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:23:23 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 26 20:23:23 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 26 20:23:25 volumio volumio[1172]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 20:23:40 volumio go-librespot[2719]: time="2026-05-26T20:23:40+02:00" level=trace msg="sent dealer ping" May 26 20:23:40 volumio go-librespot[2719]: time="2026-05-26T20:23:40+02:00" level=trace msg="received dealer pong" May 26 20:23:42 volumio volumio[1172]: verbose: New Socket.io Connection to 192.168.1.80 from 192.168.1.75 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.5 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 8 May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::volumioGetVisibleSources May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 26 20:23:43 volumio volumio[1172]: info: Received Get System Info May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 20:23:43 volumio volumio[1172]: info: Discovery: Getting this device information May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:23:43 volumio volumio[1172]: info: Listing playlists May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::volumioGetQueue May 26 20:23:43 volumio volumio[1172]: info: CoreStateMachine::getQueue May 26 20:23:43 volumio volumio[1172]: info: CorePlayQueue::getQueue May 26 20:23:43 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 26 20:23:57 volumio volumio[1172]: info: May 26 20:23:57 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:23:57 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:23:57 volumio volumio[1172]: info: May 26 20:23:57 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:23:57 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:23:57 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:23:57 volumio volumio[1172]: info: ------------------------------ 3ms May 26 20:23:57 volumio volumio[1172]: info: sendMpdCommand status took 2 milliseconds May 26 20:23:57 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:23:57 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:23:57 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:23:57 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:23:57 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:23:57 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:23:57 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:23:57 volumio volumio[1172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39731,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI - der erste Stream von künstlicher Intelligenz","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:23:57 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:23:57 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:23:57 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:23:57 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:23:57 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:57 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:23:57 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:57 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:23:57 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:23:57 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:57.372Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=38716 volume=10 May 26 20:23:57 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:57.373Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio AI - der erste Stream von künstlicher Intelligenz" May 26 20:23:57 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:57.374Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=38716 volume=10 May 26 20:23:57 volumio volumio5-onboarding[1374]: time=2026-05-26T18:23:57.374Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="Absolut Radio AI - der erste Stream von künstlicher Intelligenz" May 26 20:23:57 volumio volumio[1172]: info: ------------------------------ 24ms May 26 20:23:57 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:23:57 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:24:07 volumio volumio[1172]: info: May 26 20:24:07 volumio volumio[1172]: ---------------------------- MPD announces system playlist update May 26 20:24:07 volumio volumio[1172]: info: Ignoring MPD Status Update May 26 20:24:07 volumio volumio[1172]: info: May 26 20:24:07 volumio volumio[1172]: ---------------------------- MPD announces state update: player May 26 20:24:07 volumio volumio[1172]: info: ControllerMpd::getState May 26 20:24:07 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand status May 26 20:24:07 volumio volumio[1172]: info: ------------------------------ 1ms May 26 20:24:07 volumio volumio[1172]: info: sendMpdCommand status took 5 milliseconds May 26 20:24:07 volumio volumio[1172]: verbose: ControllerMpd::parseState May 26 20:24:07 volumio volumio[1172]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 20:24:07 volumio volumio[1172]: info: sendMpdCommand playlistinfo took 1 milliseconds May 26 20:24:07 volumio volumio[1172]: verbose: ControllerMpd::parseTrackInfo May 26 20:24:07 volumio volumio[1172]: info: ControllerMpd::pushState May 26 20:24:07 volumio volumio[1172]: info: CoreCommandRouter::servicePushState May 26 20:24:07 volumio volumio[1172]: info: CorePlayQueue::getTrack 0 May 26 20:24:07 volumio volumio[1172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49491,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MAROON 5 & CARDI B - GIRLS LIKE YOU","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} May 26 20:24:07 volumio volumio[1172]: verbose: CURRENT POSITION 0 May 26 20:24:07 volumio volumio[1172]: info: CoreStateMachine::syncState stateService play May 26 20:24:07 volumio volumio[1172]: info: CoreStateMachine::syncState currentStatus play May 26 20:24:07 volumio volumio[1172]: info: Received an update from plugin. extracting info from payload May 26 20:24:07 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:24:07 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 20:24:07 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:24:07 volumio volumio[1172]: info: CoreStateMachine::pushState May 26 20:24:07 volumio volumio[1172]: info: CoreCommandRouter::volumioPushState May 26 20:24:07 volumio volumio5-onboarding[1374]: time=2026-05-26T18:24:07.115Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=48480 volume=10 May 26 20:24:07 volumio volumio5-onboarding[1374]: time=2026-05-26T18:24:07.116Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" state=STATUS_PLAYING positionMs=48480 volume=10 May 26 20:24:07 volumio volumio5-onboarding[1374]: time=2026-05-26T18:24:07.117Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="MAROON 5 & CARDI B - GIRLS LIKE YOU" May 26 20:24:07 volumio volumio5-onboarding[1374]: time=2026-05-26T18:24:07.118Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.76:50253,00:00:00:00:00:00%04 @ 0x2b93c50" id=https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3 title="MAROON 5 & CARDI B - GIRLS LIKE YOU" May 26 20:24:07 volumio volumio[1172]: info: ------------------------------ 26ms May 26 20:24:07 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:24:07 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:24:08 volumio volumio[1172]: info: Received OAUTH Data May 26 20:24:08 volumio volumio[1172]: info: Executing Spotify Oauth Login May 26 20:24:08 volumio volumio[1172]: info: Saving Spotify Refresh Token May 26 20:24:09 volumio volumio[1172]: info: New Spotify access tokenBQCub8EGGc... May 26 20:24:09 volumio volumio[1172]: info: Spotify credentials grant success - running version from March 24, 2019 May 26 20:24:09 volumio volumio[1172]: SPOTIFY: User informations: {"country":"PL","display_name":"andrzej.kolodynski","email":"andrzej.kolodynski@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/andrzej.kolodynski"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/andrzej.kolodynski","id":"andrzej.kolodynski","images":[],"product":"premium","type":"user","uri":"spotify:user:andrzej.kolodynski"} May 26 20:24:09 volumio volumio[1172]: info: Creating Spotify config file May 26 20:24:09 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 20:24:09 volumio volumio[1172]: info: Spotify config file written May 26 20:24:09 volumio sudo[5402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 20:24:09 volumio sudo[5402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:09 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 20:24:09 volumio systemd[1]: go-librespot-daemon.service: Killing process 2742 (go-librespot) with signal SIGKILL. May 26 20:24:09 volumio volumio[1172]: info: Connection to go-librespot Websocket closed May 26 20:24:09 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 20:24:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:09 volumio systemd[1]: go-librespot-daemon.service: Consumed 18.883s CPU time. May 26 20:24:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:09 volumio go-librespot[5404]: go-librespot daemon starting... May 26 20:24:09 volumio sudo[5402]: pam_unix(sudo:session): session closed for user root May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=info msg="running go-librespot 0.7.1" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="app state loaded" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="stored credentials not found" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=info msg="zeroconf server listening on port 41861" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="obtained new client token: AABYf6jEmRCmq94VpDBvIsB9J56WkTLTxs7p/jgu9MooPxDGGEGQZHCL5AmxVWypUj5nCqbQPcN2pIDrChSVWUH6SJzj8QoAzIFCvpp1NbuK8PIoyky5MQ6H6c+DbuxZjjkrD2u2rbpg1dSYEemkR7CvdnIaYNjhdqrL3HswsJLebzeDjDNQhuMJGSn398Wl/n45CMOVHkrQwncAAkwewYJvnAw5z10F9fpa2l4t0UHgRuZfwcpeUA8Q" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="completed keyexchange" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="completed challenge" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=info msg="authenticated AP" username="an**************ki" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=info msg="authenticated Login5" username="an**************ki" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="stored credentials" username="an**************ki" May 26 20:24:09 volumio go-librespot[5407]: time="2026-05-26T20:24:09+02:00" level=debug msg="initializing zeroconf session" username="an**************ki" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="dealer connection opened" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=trace msg="starting accesspoint recv loop" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=trace msg="starting dealer recv loop" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=trace msg="received accesspoint ping" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="received connection id: MmNmZjU5NjgtYzEw...OEM4MzFFNDM0OQ==" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=trace msg="received accesspoint pong ack" May 26 20:24:10 volumio go-librespot[5407]: time="2026-05-26T20:24:10+02:00" level=debug msg="put connect state because NEW_DEVICE" May 26 20:24:10 volumio volumio[1172]: info: New Spotify access tokenBQAZ3QWeFm... May 26 20:24:10 volumio volumio[1172]: info: Spotify credentials grant success - running version from March 24, 2019 May 26 20:24:10 volumio volumio[1172]: SPOTIFY: User informations: {"country":"PL","display_name":"andrzej.kolodynski","email":"andrzej.kolodynski@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/andrzej.kolodynski"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/andrzej.kolodynski","id":"andrzej.kolodynski","images":[],"product":"premium","type":"user","uri":"spotify:user:andrzej.kolodynski"} May 26 20:24:10 volumio volumio[1172]: info: Spotify Successfully logged in May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 26 20:24:10 volumio volumio[1172]: info: [1779819850389] CoreMusicLibrary::Adding element Spotify May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 26 20:24:10 volumio volumio[1172]: Cannot find translation for source Spotify May 26 20:24:10 volumio sudo[5418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 26 20:24:10 volumio sudo[5418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:10 volumio sudo[5418]: pam_unix(sudo:session): session closed for user root May 26 20:24:10 volumio sudo[5420]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 26 20:24:10 volumio sudo[5420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:10 volumio sudo[5420]: pam_unix(sudo:session): session closed for user root May 26 20:24:10 volumio volumio[1172]: verbose: New Socket.io Connection to 192.168.1.80 from 192.168.1.75 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.5 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 8 May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::volumioGetVisibleSources May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 26 20:24:10 volumio volumio[1172]: info: Received Get System Info May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 20:24:10 volumio volumio[1172]: info: Discovery: Getting this device information May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:10 volumio volumio[1172]: info: Listing playlists May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 26 20:24:10 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 26 20:24:12 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 26 20:24:12 volumio volumio[1172]: info: Initializing connection to go-librespot Websocket May 26 20:24:12 volumio go-librespot[5407]: time="2026-05-26T20:24:12+02:00" level=debug msg="new websocket client" May 26 20:24:12 volumio volumio[1172]: info: Connection to go-librespot Websocket established May 26 20:24:12 volumio volumio[1172]: info: go-librespot daemon successfully initialized May 26 20:24:12 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 26 20:24:12 volumio volumio[1172]: info: Received Get System Info May 26 20:24:12 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 20:24:12 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 20:24:12 volumio volumio[1172]: info: Discovery: Getting this device information May 26 20:24:12 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:12 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 20:24:13 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 26 20:24:13 volumio volumio[1172]: info: Received Get System Info May 26 20:24:13 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 20:24:13 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 20:24:13 volumio volumio[1172]: info: Discovery: Getting this device information May 26 20:24:13 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:13 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 20:24:14 volumio volumio[1172]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 20:24:14 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 20:24:14 volumio volumio[1172]: info: Creating Spotify config file May 26 20:24:14 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 20:24:14 volumio volumio[1172]: info: Spotify config file written May 26 20:24:14 volumio sudo[5439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 20:24:14 volumio sudo[5439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:14 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 20:24:14 volumio systemd[1]: go-librespot-daemon.service: Killing process 5412 (go-librespot) with signal SIGKILL. May 26 20:24:14 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 20:24:14 volumio volumio[1172]: info: Connection to go-librespot Websocket closed May 26 20:24:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:14 volumio sudo[5439]: pam_unix(sudo:session): session closed for user root May 26 20:24:14 volumio go-librespot[5441]: go-librespot daemon starting... May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=info msg="running go-librespot 0.7.1" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="app state loaded" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=info msg="zeroconf server listening on port 40167" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="obtained new client token: AAChysQq+SPacBeKv9AS4n0hJTOlqKGWv3UkEwx3BcSZZChL5UKdcqPVD9LwDmDQSm9nhqB1qnGiEYAhL1Ao3PirAQLpcYc8n5gpqKQzChevBzdv8WlrLBYKafj3cxRjoPBQvr05nLJcqkUzs8z+8NDY3a2bp2BH6nuj94y4q22vLGcc942+JiO6iqie6ZWuaNjM8eXPNQYKqVUkIQR8hGKymoN/O4gXgjM6bm7jxsQ569pr7RIgTq+l" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="completed keyexchange" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="completed challenge" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=info msg="authenticated AP" username="an**************ki" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=info msg="authenticated Login5" username="an**************ki" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="initializing zeroconf session" username="an**************ki" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="dealer connection opened" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=trace msg="starting accesspoint recv loop" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=trace msg="starting dealer recv loop" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=trace msg="received accesspoint ping" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=debug msg="received connection id: NDZlZDYzNTMtMDgx...Qjc1RDY4RTk4OQ==" May 26 20:24:14 volumio go-librespot[5442]: time="2026-05-26T20:24:14+02:00" level=trace msg="received accesspoint pong ack" May 26 20:24:15 volumio go-librespot[5442]: time="2026-05-26T20:24:15+02:00" level=debug msg="put connect state because NEW_DEVICE" May 26 20:24:15 volumio volumio[1172]: info: Getting Spotify volume May 26 20:24:15 volumio volumio[1172]: info: Spotify volume: 100 May 26 20:24:15 volumio volumio[1172]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 26 20:24:15 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:15 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:24:15 volumio volumio[1172]: SPOTIFY: SPOTIFY VOLUME 100 May 26 20:24:15 volumio volumio[1172]: SPOTIFY: VOLUMIO VOLUME 10 May 26 20:24:15 volumio volumio[1172]: SPOTIFY: DELTA VOLUME ENOUGH: true May 26 20:24:15 volumio volumio[1172]: info: Setting Spotify Volume from Volumio: 10 May 26 20:24:15 volumio volumio[1172]: info: Initializing connection to go-librespot Websocket May 26 20:24:15 volumio go-librespot[5442]: time="2026-05-26T20:24:15+02:00" level=debug msg="new websocket client" May 26 20:24:15 volumio volumio[1172]: info: Connection to go-librespot Websocket established May 26 20:24:15 volumio volumio[1172]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 20:24:15 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 20:24:15 volumio volumio[1172]: info: Creating Spotify config file May 26 20:24:15 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 20:24:15 volumio volumio[1172]: info: Spotify config file written May 26 20:24:15 volumio sudo[5453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 20:24:15 volumio sudo[5453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 20:24:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 20:24:15 volumio volumio[1172]: info: Connection to go-librespot Websocket closed May 26 20:24:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:15 volumio go-librespot[5455]: go-librespot daemon starting... May 26 20:24:15 volumio sudo[5453]: pam_unix(sudo:session): session closed for user root May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=info msg="running go-librespot 0.7.1" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="app state loaded" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=info msg="zeroconf server listening on port 35447" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="obtained new client token: AADrEqLXnQlnPw2loVIe16gfx3ynN6AKX9ccEd+WpFlMouCzCmgVwkINb+ZW2EeC7/7iKdONancpoDor+vK4VppFIrsqHJNHSSwGIyAjq9PEi+jbvb/7yVthIII+CACpqi504whvyfCmbFo1Pvg4zDiJlHo0lZbloAMopAeWPadXlC2G0RKu/r4oHFNceLRrgSQHoKqo2Ut5tojwnx5I9igRC/0BS70FeqDa0nIN/oeXtsb+SESKtQ==" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="completed keyexchange" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="completed challenge" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=info msg="authenticated AP" username="an**************ki" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=info msg="authenticated Login5" username="an**************ki" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="initializing zeroconf session" username="an**************ki" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="dealer connection opened" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=trace msg="starting accesspoint recv loop" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=trace msg="starting dealer recv loop" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=trace msg="received accesspoint ping" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="received connection id: ZGQxNjg2NzEtMjhm...NEM3MDQxNzBGQQ==" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="put connect state because NEW_DEVICE" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=trace msg="received accesspoint pong ack" May 26 20:24:16 volumio volumio[1172]: SPOTIFY: SETTING SPOTIFY VOLUME 10 May 26 20:24:16 volumio volumio[1172]: info: Sending Spotify command with payload to local API: /player/volume May 26 20:24:16 volumio go-librespot[5456]: time="2026-05-26T20:24:16+02:00" level=debug msg="update volume requested to 6553/65535" May 26 20:24:17 volumio go-librespot[5456]: time="2026-05-26T20:24:17+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 26 20:24:17 volumio go-librespot[5456]: time="2026-05-26T20:24:17+02:00" level=trace msg="emitting websocket event: volume" May 26 20:24:17 volumio volumio[1172]: info: go-librespot daemon successfully initialized May 26 20:24:18 volumio volumio[1172]: info: Getting Spotify volume May 26 20:24:18 volumio volumio[1172]: info: Spotify volume: 10 May 26 20:24:18 volumio volumio[1172]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 26 20:24:18 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:18 volumio volumio[1172]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 May 26 20:24:18 volumio volumio[1172]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 20:24:18 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 20:24:18 volumio volumio[1172]: info: Creating Spotify config file May 26 20:24:18 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 20:24:18 volumio volumio[1172]: info: Spotify config file written May 26 20:24:18 volumio sudo[5466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 20:24:18 volumio sudo[5466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 20:24:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 20:24:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:18 volumio go-librespot[5468]: go-librespot daemon starting... May 26 20:24:18 volumio sudo[5466]: pam_unix(sudo:session): session closed for user root May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=info msg="running go-librespot 0.7.1" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="app state loaded" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=info msg="zeroconf server listening on port 38161" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="obtained new client token: AAAKvkCJgqtE/lRsW5E1a3sdpUeVAYGSSdn2NJPTqn9gKX7Q94afQ5tfH/U9MsmiT1//HdTyHXFgh961bEaKdJMni6lm12S+sgZT3yobKDqTL1MZ4Ylww9Yyd7oD2Wtgcs4c8D+la+FO0rzMinDFEhsVOd7gzMU8uPoFaWAD4sM2PVJwpgcMPX8UVZMt8QDSZp2xu6EF8CQy6gNWyunrYKwV+KBz+Ql/2lxdIVYZoH45W7jSDxlRQ30B" May 26 20:24:18 volumio volumio[1172]: info: Initializing connection to go-librespot Websocket May 26 20:24:18 volumio volumio[1172]: info: Connection to go-librespot Websocket established May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="new websocket client" May 26 20:24:18 volumio volumio[1172]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 20:24:18 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 20:24:18 volumio volumio[1172]: info: Creating Spotify config file May 26 20:24:18 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 20:24:18 volumio volumio[1172]: info: Spotify config file written May 26 20:24:18 volumio go-librespot[5469]: time="2026-05-26T20:24:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 26 20:24:18 volumio sudo[5479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 20:24:18 volumio sudo[5479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 20:24:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 20:24:18 volumio volumio[1172]: info: Connection to go-librespot Websocket closed May 26 20:24:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:18 volumio volumio[1172]: info: go-librespot daemon successfully initialized May 26 20:24:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:19 volumio sudo[5479]: pam_unix(sudo:session): session closed for user root May 26 20:24:19 volumio go-librespot[5481]: go-librespot daemon starting... May 26 20:24:19 volumio go-librespot[5482]: time="2026-05-26T20:24:19+02:00" level=info msg="running go-librespot 0.7.1" May 26 20:24:19 volumio go-librespot[5482]: time="2026-05-26T20:24:19+02:00" level=debug msg="app state loaded" May 26 20:24:19 volumio go-librespot[5482]: time="2026-05-26T20:24:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 20:24:19 volumio volumio[1172]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 20:24:19 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 20:24:19 volumio volumio[1172]: info: Creating Spotify config file May 26 20:24:19 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 20:24:19 volumio volumio[1172]: info: Spotify config file written May 26 20:24:19 volumio sudo[5491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 20:24:19 volumio sudo[5491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 20:24:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 20:24:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 20:24:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:19 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. May 26 20:24:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. May 26 20:24:19 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. May 26 20:24:19 volumio sudo[5491]: pam_unix(sudo:session): session closed for user root May 26 20:24:19 volumio volumio[1172]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service May 26 20:24:19 volumio volumio[1172]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. May 26 20:24:19 volumio volumio[1172]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. May 26 20:24:19 volumio volumio[1172]: To force a start use "systemctl reset-failed go-librespot-daemon.service" May 26 20:24:19 volumio volumio[1172]: followed by "systemctl start go-librespot-daemon.service" again. May 26 20:24:19 volumio volumio[1172]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service May 26 20:24:19 volumio volumio[1172]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. May 26 20:24:19 volumio volumio[1172]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. May 26 20:24:19 volumio volumio[1172]: To force a start use "systemctl reset-failed go-librespot-daemon.service" May 26 20:24:19 volumio volumio[1172]: followed by "systemctl start go-librespot-daemon.service" again. May 26 20:24:20 volumio volumio[1172]: info: Initializing connection to go-librespot Websocket May 26 20:24:20 volumio volumio[1172]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 26 20:24:20 volumio volumio[1172]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 26 20:24:21 volumio volumio[1172]: info: CoreCommandRouter::volumioGetState May 26 20:24:21 volumio volumio[1172]: info: go-librespot daemon successfully initialized May 26 20:24:21 volumio volumio[1172]: info: Getting Spotify volume May 26 20:24:21 volumio volumio[1172]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 20:24:21 volumio volumio[1172]: Error: connect ECONNREFUSED 127.0.0.1:9879 May 26 20:24:21 volumio volumio[1172]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { May 26 20:24:21 volumio volumio[1172]: errno: -111, May 26 20:24:21 volumio volumio[1172]: code: 'ECONNREFUSED', May 26 20:24:21 volumio volumio[1172]: syscall: 'connect', May 26 20:24:21 volumio volumio[1172]: address: '127.0.0.1', May 26 20:24:21 volumio volumio[1172]: port: 9879, May 26 20:24:21 volumio volumio[1172]: response: undefined May 26 20:24:21 volumio volumio[1172]: } May 26 20:24:21 volumio volumio[1172]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 20:24:22 volumio sudo[5522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-26 20:23' May 26 20:24:22 volumio sudo[5522]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"