Aug 29 23:48:03 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:48:03 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:48:03 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:48:13 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:48:16 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetQueue Aug 29 23:48:16 volumiopc volumio[1111]: info: CoreStateMachine::getQueue Aug 29 23:48:16 volumiopc volumio[1111]: info: CorePlayQueue::getQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: Preload queue cleared Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::ClearQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::stop Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::stPlaybackTimer Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::updateTrackBlock Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::getTrackBlock Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::pushState Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushState Aug 29 23:48:18 volumiopc volumio[1111]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::serviceStop Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::serviceStop Aug 29 23:48:18 volumiopc volumio[1111]: info: [1788036498902] ControllerWebradio::stop Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::clearPlayQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::saveQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::addQueueItems Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::addQueueItems Aug 29 23:48:18 volumiopc volumio[1111]: info: Preload queue cleared Aug 29 23:48:18 volumiopc volumio[1111]: info: Adding Item to queue: https://live.radiosun.ro/sunlove Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Aug 29 23:48:18 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:18.911+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" state=STATUS_STOPPED positionMs=0 volume=50 Aug 29 23:48:18 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:18.912+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" id=https://live.radiosun.ro/sunlove title="Sun Love" Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::saveQueue Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::updateTrackBlock Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::getTrackBlock Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPlay Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::play index 0 Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::stop Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::play index undefined Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:18 volumiopc volumio[1111]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:48:18 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:18 volumiopc volumio[1111]: info: [1788036498929] ControllerWebradio::clearAddPlayTrack Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 23:48:18 volumiopc volumio[1111]: info: Display-configuration --- Volumio status=stop timeout=120 noifplay=true screensavertype=dpms Aug 29 23:48:18 volumiopc volumio[1111]: info: Aug 29 23:48:18 volumiopc volumio[1111]: ---------------------------- MPD announces state update: player Aug 29 23:48:18 volumiopc volumio[1111]: info: sendMpdCommand stop took 37 milliseconds Aug 29 23:48:18 volumiopc volumio[1111]: info: ControllerMpd::getState Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand status Aug 29 23:48:18 volumiopc volumio[1111]: info: sendMpdCommand stop took 11 milliseconds Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand clear Aug 29 23:48:18 volumiopc volumio[1111]: info: sendMpdCommand status took 17 milliseconds Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::parseState Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 23:48:18 volumiopc volumio[1111]: info: Aug 29 23:48:18 volumiopc volumio[1111]: ---------------------------- MPD announces system playlist update Aug 29 23:48:18 volumiopc volumio[1111]: info: Ignoring MPD Status Update Aug 29 23:48:18 volumiopc volumio[1111]: info: sendMpdCommand clear took 15 milliseconds Aug 29 23:48:18 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand load "https://live.radiosun.ro/sunlove" Aug 29 23:48:19 volumiopc volumio[1111]: error: updateQueue error: null Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand playlistinfo took 257 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: info: ------------------------------ 256ms Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand add "https://live.radiosun.ro/sunlove" Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::parseTrackInfo Aug 29 23:48:19 volumiopc volumio[1111]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 29 23:48:19 volumiopc volumio[1111]: info: ------------------------------ 280ms Aug 29 23:48:19 volumiopc volumio[1111]: info: Aug 29 23:48:19 volumiopc volumio[1111]: ---------------------------- MPD announces system playlist update Aug 29 23:48:19 volumiopc volumio[1111]: info: Ignoring MPD Status Update Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand add "https://live.radiosun.ro/sunlove" took 4 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand play Aug 29 23:48:19 volumiopc volumio[1111]: info: ------------------------------ 2ms Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand play took 2 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: info: Aug 29 23:48:19 volumiopc volumio[1111]: ---------------------------- MPD announces state update: player Aug 29 23:48:19 volumiopc volumio[1111]: info: ControllerMpd::getState Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand status Aug 29 23:48:19 volumiopc volumio[1111]: info: Aug 29 23:48:19 volumiopc volumio[1111]: ---------------------------- MPD announces state update: player Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand status took 7 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: info: ControllerMpd::getState Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand status Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::parseState Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 23:48:19 volumiopc volumio[1111]: info: Aug 29 23:48:19 volumiopc volumio[1111]: ---------------------------- MPD announces system playlist update Aug 29 23:48:19 volumiopc volumio[1111]: info: Ignoring MPD Status Update Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand status took 1 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: info: ------------------------------ 1ms Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::parseState Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::parseTrackInfo Aug 29 23:48:19 volumiopc volumio[1111]: info: ControllerMpd::pushState Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreCommandRouter::servicePushState Aug 29 23:48:19 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:19 volumiopc volumio[1111]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"48 Kbps","isStreaming":false,"title":"sunlove","artist":"Radio Sun Love Romania","album":null,"uri":"https://live.radiosun.ro/sunlove","trackType":"ro/sunlove"} Aug 29 23:48:19 volumiopc volumio[1111]: verbose: CURRENT POSITION 0 Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::syncState stateService play Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::syncState currentStatus stop Aug 29 23:48:19 volumiopc volumio[1111]: info: ------------------------------ 10ms Aug 29 23:48:19 volumiopc volumio[1111]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 29 23:48:19 volumiopc volumio[1111]: verbose: ControllerMpd::parseTrackInfo Aug 29 23:48:19 volumiopc volumio[1111]: info: ControllerMpd::pushState Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreCommandRouter::servicePushState Aug 29 23:48:19 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:19 volumiopc volumio[1111]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"48 Kbps","isStreaming":false,"title":"sunlove","artist":"Radio Sun Love Romania","album":null,"uri":"https://live.radiosun.ro/sunlove","trackType":"ro/sunlove"} Aug 29 23:48:19 volumiopc volumio[1111]: verbose: CURRENT POSITION 0 Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::syncState stateService play Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::syncState currentStatus play Aug 29 23:48:19 volumiopc volumio[1111]: info: Received an update from plugin. extracting info from payload Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::pushState Aug 29 23:48:19 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushState Aug 29 23:48:19 volumiopc volumio[1111]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreStateMachine::pushState Aug 29 23:48:19 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushState Aug 29 23:48:19 volumiopc volumio[1111]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 23:48:19 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:19.330+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" state=STATUS_PLAYING positionMs=0 volume=50 Aug 29 23:48:19 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:19.331+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" id=https://live.radiosun.ro/sunlove title="Sun Love" Aug 29 23:48:19 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:19.330+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" state=STATUS_PLAYING positionMs=0 volume=50 Aug 29 23:48:19 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:19.331+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" id=https://live.radiosun.ro/sunlove title="Sun Love" Aug 29 23:48:19 volumiopc volumio[1111]: info: ------------------------------ 6ms Aug 29 23:48:19 volumiopc volumio[1111]: info: Display-configuration --- Volumio status=play timeout=120 noifplay=true screensavertype=dpms Aug 29 23:48:19 volumiopc volumio[1111]: info: Display-configuration --- → Wakeup triggered Aug 29 23:48:19 volumiopc volumio[1111]: info: Display-configuration --- Volumio status=play timeout=120 noifplay=true screensavertype=dpms Aug 29 23:48:19 volumiopc volumio[1111]: info: Display-configuration --- → Wakeup triggered Aug 29 23:48:19 volumiopc volumio[1111]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 29 23:48:19 volumiopc volumio[1111]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 29 23:48:23 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:48:23 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:48:23 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:48:25 volumiopc volumio[1111]: info: Preload queue cleared Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::ClearQueue Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::stop Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::stPlaybackTimer Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::updateTrackBlock Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrackBlock Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::pushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushState Aug 29 23:48:25 volumiopc volumio[1111]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::serviceStop Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::serviceStop Aug 29 23:48:25 volumiopc volumio[1111]: info: [1788036505296] ControllerWebradio::stop Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::clearPlayQueue Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::saveQueue Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::addQueueItems Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::addQueueItems Aug 29 23:48:25 volumiopc volumio[1111]: info: Preload queue cleared Aug 29 23:48:25 volumiopc volumio[1111]: info: Adding Item to queue: https://live.radiosun.ro/sunlove Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Aug 29 23:48:25 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:25.299+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" state=STATUS_STOPPED positionMs=0 volume=50 Aug 29 23:48:25 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:25.299+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" id=https://live.radiosun.ro/sunlove title="Sun Love" Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::saveQueue Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::updateTrackBlock Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrackBlock Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPlay Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::play index 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::stop Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::play index undefined Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: [1788036505305] ControllerWebradio::clearAddPlayTrack Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- Volumio status=stop timeout=120 noifplay=true screensavertype=dpms Aug 29 23:48:25 volumiopc volumio[1111]: info: Aug 29 23:48:25 volumiopc volumio[1111]: ---------------------------- MPD announces state update: player Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand stop took 18 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: info: ControllerMpd::getState Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand status Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand stop took 9 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand clear Aug 29 23:48:25 volumiopc volumio[1111]: info: Aug 29 23:48:25 volumiopc volumio[1111]: ---------------------------- MPD announces system playlist update Aug 29 23:48:25 volumiopc volumio[1111]: info: Ignoring MPD Status Update Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand status took 3 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand clear took 4 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::parseState Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand load "https://live.radiosun.ro/sunlove" Aug 29 23:48:25 volumiopc volumio[1111]: error: updateQueue error: null Aug 29 23:48:25 volumiopc volumio[1111]: info: ------------------------------ 5ms Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::parseTrackInfo Aug 29 23:48:25 volumiopc volumio[1111]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 29 23:48:25 volumiopc volumio[1111]: info: ------------------------------ 10ms Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand add "https://live.radiosun.ro/sunlove" Aug 29 23:48:25 volumiopc volumio[1111]: info: Aug 29 23:48:25 volumiopc volumio[1111]: ---------------------------- MPD announces system playlist update Aug 29 23:48:25 volumiopc volumio[1111]: info: Ignoring MPD Status Update Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand add "https://live.radiosun.ro/sunlove" took 0 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand play Aug 29 23:48:25 volumiopc volumio[1111]: info: ------------------------------ 0ms Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand play took 1 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: info: Aug 29 23:48:25 volumiopc volumio[1111]: ---------------------------- MPD announces state update: player Aug 29 23:48:25 volumiopc volumio[1111]: info: ControllerMpd::getState Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand status Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand status took 14 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::parseState Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 23:48:25 volumiopc volumio[1111]: info: Aug 29 23:48:25 volumiopc volumio[1111]: ---------------------------- MPD announces state update: player Aug 29 23:48:25 volumiopc volumio[1111]: info: ControllerMpd::getState Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand status Aug 29 23:48:25 volumiopc volumio[1111]: info: Aug 29 23:48:25 volumiopc volumio[1111]: ---------------------------- MPD announces system playlist update Aug 29 23:48:25 volumiopc volumio[1111]: info: Ignoring MPD Status Update Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand status took 1 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::parseTrackInfo Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::parseState Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 23:48:25 volumiopc volumio[1111]: info: ControllerMpd::pushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::servicePushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"47 Kbps","isStreaming":false,"title":"sunlove","artist":"Radio Sun Love Romania","album":null,"uri":"https://live.radiosun.ro/sunlove","trackType":"ro/sunlove"} Aug 29 23:48:25 volumiopc volumio[1111]: verbose: CURRENT POSITION 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::syncState stateService play Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::syncState currentStatus stop Aug 29 23:48:25 volumiopc volumio[1111]: info: ------------------------------ 18ms Aug 29 23:48:25 volumiopc volumio[1111]: info: ------------------------------ 2ms Aug 29 23:48:25 volumiopc volumio[1111]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 29 23:48:25 volumiopc volumio[1111]: verbose: ControllerMpd::parseTrackInfo Aug 29 23:48:25 volumiopc volumio[1111]: info: ControllerMpd::pushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::servicePushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"47 Kbps","isStreaming":false,"title":"sunlove","artist":"Radio Sun Love Romania","album":null,"uri":"https://live.radiosun.ro/sunlove","trackType":"ro/sunlove"} Aug 29 23:48:25 volumiopc volumio[1111]: verbose: CURRENT POSITION 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::syncState stateService play Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::syncState currentStatus play Aug 29 23:48:25 volumiopc volumio[1111]: info: Received an update from plugin. extracting info from payload Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::pushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CorePlayQueue::getTrack 0 Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushState Aug 29 23:48:25 volumiopc volumio[1111]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreStateMachine::pushState Aug 29 23:48:25 volumiopc volumio[1111]: info: CoreCommandRouter::volumioPushState Aug 29 23:48:25 volumiopc volumio[1111]: info: Stylish Player: pushState → fmt=s16le rate=44100 isDSD=false Aug 29 23:48:25 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:25.509+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" state=STATUS_PLAYING positionMs=0 volume=50 Aug 29 23:48:25 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:25.509+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" id=https://live.radiosun.ro/sunlove title="Sun Love" Aug 29 23:48:25 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:25.509+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" state=STATUS_PLAYING positionMs=0 volume=50 Aug 29 23:48:25 volumiopc volumio5-onboarding[2039]: time=2026-08-29T23:48:25.509+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:42650 @ 0xc00018eb10" id=https://live.radiosun.ro/sunlove title="Sun Love" Aug 29 23:48:25 volumiopc volumio[1111]: info: ------------------------------ 15ms Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- Volumio status=play timeout=120 noifplay=true screensavertype=dpms Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- → Wakeup triggered Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- Volumio status=play timeout=120 noifplay=true screensavertype=dpms Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- → Wakeup triggered Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 29 23:48:25 volumiopc volumio[1111]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 29 23:48:33 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:48:37 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:48:37 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 23:48:42 volumiopc volumio[1111]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 23:48:43 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:48:43 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:48:43 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:48:50 volumiopc volumio[1111]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 29 23:48:50 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 29 23:48:50 volumiopc volumio[1111]: info: Creating Spotify config file Aug 29 23:48:50 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:48:50 volumiopc volumio[1111]: info: Spotify config file written Aug 29 23:48:50 volumiopc sudo[2567453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:48:50 volumiopc sudo[2567453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:48:50 volumiopc systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:48:50 volumiopc systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:48:50 volumiopc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:48:50 volumiopc sudo[2567453]: pam_unix(sudo:session): session closed for user root Aug 29 23:48:50 volumiopc go-librespot[2567455]: go-librespot daemon starting... Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="app state loaded" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=info msg="zeroconf server listening on port 42319" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="obtained new client token: AAG4of0LuUQIgVCxeTAskPJ1c+BxmmQToDht8PGBBsVIrPvZieY7tMekA9snJsDcTQCceueYSZAOewuTAyA83edMOCPwU5IYpF6v5N+VuNcA1Q/mywgSwzhjyngqGWsFWVeGxDdS4cij8+aYemCT5281TPJhf3Iv8ms5CzF96ukSdwuecw2KbRxfs9PuzBiE6ZNhJKevuDRKI1RezK41Ee3IMwj/W6u58nZo48kHMbHlLMBqQkwY+igL" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="completed keyexchange" Aug 29 23:48:50 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:50+03:00" level=debug msg="completed challenge" Aug 29 23:48:51 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:51+03:00" level=info msg="authenticated AP" username="31************************zq" Aug 29 23:48:51 volumiopc go-librespot[2567456]: time="2026-08-29T23:48:51+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:48:51 volumiopc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:48:51 volumiopc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:48:52 volumiopc volumio[1111]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 29 23:48:52 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 29 23:48:52 volumiopc volumio[1111]: info: Creating Spotify config file Aug 29 23:48:52 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:48:52 volumiopc volumio[1111]: info: Spotify config file written Aug 29 23:48:52 volumiopc sudo[2567470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:48:52 volumiopc sudo[2567470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:48:53 volumiopc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:48:53 volumiopc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:48:53 volumiopc go-librespot[2567473]: go-librespot daemon starting... Aug 29 23:48:53 volumiopc sudo[2567470]: pam_unix(sudo:session): session closed for user root Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="app state loaded" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=info msg="zeroconf server listening on port 41517" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="obtained new client token: AAEcvkXsC3AVVKpe7FL+5d9cd/vUXYMvVqUrKQnPhi5lvmOc43wLKQGFV5TLHIMA3TZMHHsXhc/gM4io2hwJeo8bT/Frj/X+oyLJNENDryMmzzsA2OVM5WP0yaK6zck3f1NWruCkKdHhC915EJvTxlwtxrpF6bi/fl8WNqUkmmUfmgpN/q+rct+Mmkq2UqsfKbJvMgoX5o+T+8BBx3R+bCtSx/DG4xdkkykVzj0WsbIJd0jHq1b5G+J4" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="completed keyexchange" Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=debug msg="completed challenge" Aug 29 23:48:53 volumiopc volumio[1111]: info: go-librespot daemon successfully initialized Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=info msg="authenticated AP" username="31************************zq" Aug 29 23:48:53 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:48:53 volumiopc go-librespot[2567474]: time="2026-08-29T23:48:53+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:48:53 volumiopc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:48:53 volumiopc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:48:56 volumiopc volumio[1111]: info: go-librespot daemon successfully initialized Aug 29 23:48:56 volumiopc volumio[1111]: info: Initializing connection to go-librespot Websocket Aug 29 23:48:56 volumiopc volumio[1111]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:48:56 volumiopc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 23:48:56 volumiopc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:48:56 volumiopc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:48:56 volumiopc go-librespot[2567504]: go-librespot daemon starting... Aug 29 23:48:56 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:56+03:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:48:56 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:56+03:00" level=debug msg="app state loaded" Aug 29 23:48:56 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:56+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=info msg="zeroconf server listening on port 34975" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="obtained new client token: AAEHpVMBsCNSMEmUOZdjbk8kyU5sbrYM0HU05hxo1ZAUFptDp9d8IEdc+SrdnBT69dZ3+np2Hc9Mzebmet3Obj6VMG9f8LJibLUQjRKAc1c8JSYw+idOkPGT1ugq8sxSU5SZo0vZ9niNGgAbq7PXZatVrEoCXxApH50i16D0P3yIHhAAZxkDyb6+QXyy1ptWiSfNg1f3dKs3SaPXbyRGx7P7YjBzPBQsAhtwPw3jBMKuDgN05ho/2g==" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="completed keyexchange" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=debug msg="completed challenge" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=info msg="authenticated AP" username="31************************zq" Aug 29 23:48:57 volumiopc go-librespot[2567505]: time="2026-08-29T23:48:57+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:48:57 volumiopc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:48:57 volumiopc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:48:59 volumiopc volumio[1111]: info: Initializing connection to go-librespot Websocket Aug 29 23:48:59 volumiopc volumio[1111]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:48:59 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:48:59 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 23:49:00 volumiopc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 23:49:00 volumiopc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:49:00 volumiopc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:49:00 volumiopc go-librespot[2567518]: go-librespot daemon starting... Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=debug msg="app state loaded" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=info msg="zeroconf server listening on port 38409" Aug 29 23:49:00 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:00+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:49:01 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:01+03:00" level=debug msg="obtained new client token: AAEN0zAdwVy4eTnZQlgahM78z8SQaAzlgroOeQe5AzwT8RRSr5OWDG0uSf74vomnC2WBSHQnyp7ATk3sFVB9PE/AgQb65b6Ob7gCv5kaFleH/1ZeHQyfBIpswRzIctn4gBWpRVNDR4FgidjH/k/aYTBB0QmookvlDIQqj6Gy8dT3FDB2yCLwjZEimv8FIeLVcBdMFwGWWT9i33uZNLQAqtXJcExe0obgZXduK363fO/rvaQBLNqgnw==" Aug 29 23:49:01 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:01+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 23:49:01 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:01+03:00" level=debug msg="completed keyexchange" Aug 29 23:49:01 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:01+03:00" level=debug msg="completed challenge" Aug 29 23:49:01 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:01+03:00" level=info msg="authenticated AP" username="31************************zq" Aug 29 23:49:01 volumiopc go-librespot[2567519]: time="2026-08-29T23:49:01+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:49:01 volumiopc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:49:01 volumiopc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:49:02 volumiopc volumio[1111]: info: Initializing connection to go-librespot Websocket Aug 29 23:49:02 volumiopc volumio[1111]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:49:03 volumiopc volumio[1111]: info: CoreCommandRouter::volumioGetState Aug 29 23:49:03 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:49:03 volumiopc volumio[1111]: info: Listing playlists Aug 29 23:49:04 volumiopc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 23:49:04 volumiopc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:49:04 volumiopc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:49:04 volumiopc go-librespot[2567532]: go-librespot daemon starting... Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="app state loaded" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=info msg="zeroconf server listening on port 38289" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="obtained new client token: AAHzQkgjlj0ovUmxYPK+78AG3SjFTahGIr9pwmYoacXHRdhGUp3I9ebJgHNJJ983TWYB6a8VWYI6Jqdyv1Hh0YBsVU9i24LnJX7Fte8hZoCJcFQv+dacll5iffIo9HH+hJzvbiWDsgM6r3aOdRFhBmUgqto4Ob/feJe8+6k1KDqvkwqE2oP9xDcpg8LhfROso1EZMemgdE4NEH4FyQBipOtIfSKUm9LoHs79S9OCUL7eC9vvWfZ24CLy" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="completed keyexchange" Aug 29 23:49:04 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:04+03:00" level=debug msg="completed challenge" Aug 29 23:49:05 volumiopc volumio[1111]: info: Enabling plugin spop Aug 29 23:49:05 volumiopc volumio[1111]: info: Loading plugin "spop"... Aug 29 23:49:05 volumiopc volumio[1111]: info: PLUGIN START: spop Aug 29 23:49:05 volumiopc volumio[1111]: info: Creating Spotify config file Aug 29 23:49:05 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:49:05 volumiopc volumio[1111]: info: Done. Aug 29 23:49:05 volumiopc volumio[1111]: info: Initializing connection to go-librespot Websocket Aug 29 23:49:05 volumiopc volumio[1111]: info: Spotify config file written Aug 29 23:49:05 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:05+03:00" level=info msg="authenticated AP" username="31************************zq" Aug 29 23:49:05 volumiopc go-librespot[2567533]: time="2026-08-29T23:49:05+03:00" level=debug msg="new websocket client" Aug 29 23:49:05 volumiopc volumio[1111]: info: No need to fix Spotify hosts Aug 29 23:49:05 volumiopc volumio[1111]: info: Connection to go-librespot Websocket established Aug 29 23:49:05 volumiopc sudo[2567545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:49:05 volumiopc sudo[2567545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:49:05 volumiopc systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 23:49:05 volumiopc volumio[1111]: info: Connection to go-librespot Websocket closed Aug 29 23:49:05 volumiopc systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 23:49:05 volumiopc systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:49:05 volumiopc systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:49:05 volumiopc go-librespot[2567547]: go-librespot daemon starting... Aug 29 23:49:05 volumiopc sudo[2567545]: pam_unix(sudo:session): session closed for user root Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="app state loaded" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=info msg="zeroconf server listening on port 33181" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:49:05 volumiopc volumio[1111]: info: New Spotify access tokenBQBcm8Gb6l... Aug 29 23:49:05 volumiopc volumio[1111]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="obtained new client token: AAFjpViXKo6tERJ4YOfRMlo0gqm/VeTjkW6/dGnDtIgb2tZWJ8hHpKK6wEYuAXsoBMEMXj8AqnClgoNrt+41WywZYOJtFV/UaardB2WLAtJCqTZr0XlXrLRo2NY60Dpdq/Hdn2T6iwzrMhnCtN+S93bPU9ho891CTin5/FjZuc7Kw4Owq2cw5p30ODyOWqOIpLOLlZCCx2EFssyH0+UFA9NNIGQB70fnGBNG9wzsn0vWmCjCoCWLQLZd" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="completed keyexchange" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=debug msg="completed challenge" Aug 29 23:49:05 volumiopc volumio[1111]: SPOTIFY: User informations: {"account_id":"V8buDAOFoO","country":"RO","display_name":"Lukacs Zsolt","email":"bigmaczsolt@gmail.com","explicit_content":{"filter_enabled":true,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31fok36ixj4jqxfc472isjs2pmzq"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31fok36ixj4jqxfc472isjs2pmzq","id":"31fok36ixj4jqxfc472isjs2pmzq","images":[],"product":"free","type":"user","uri":"spotify:user:31fok36ixj4jqxfc472isjs2pmzq"} Aug 29 23:49:05 volumiopc volumio[1111]: info: Spotify Successfully logged in Aug 29 23:49:05 volumiopc volumio[1111]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:49:05 volumiopc volumio[1111]: info: [1788036545712] CoreMusicLibrary::Adding element Spotify Aug 29 23:49:05 volumiopc volumio[1111]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:49:05 volumiopc volumio[1111]: Cannot find translation for source YouTube Music Aug 29 23:49:05 volumiopc volumio[1111]: Cannot find translation for source Spotify Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=info msg="authenticated AP" username="31************************zq" Aug 29 23:49:05 volumiopc go-librespot[2567548]: time="2026-08-29T23:49:05+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:49:05 volumiopc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:49:05 volumiopc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:49:08 volumiopc volumio[1111]: info: Getting Spotify volume Aug 29 23:49:08 volumiopc volumio[1111]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 23:49:08 volumiopc volumio[1111]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:49:08 volumiopc volumio[1111]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 23:49:08 volumiopc volumio[1111]: errno: -111, Aug 29 23:49:08 volumiopc volumio[1111]: code: 'ECONNREFUSED', Aug 29 23:49:08 volumiopc volumio[1111]: syscall: 'connect', Aug 29 23:49:08 volumiopc volumio[1111]: address: '127.0.0.1', Aug 29 23:49:08 volumiopc volumio[1111]: port: 9879, Aug 29 23:49:08 volumiopc volumio[1111]: response: undefined Aug 29 23:49:08 volumiopc volumio[1111]: } Aug 29 23:49:08 volumiopc volumio[1111]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 23:49:08 volumiopc sudo[2567588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 23:48' Aug 29 23:49:08 volumiopc sudo[2567588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="f107261a9bd5157ff5c5bbfacc2d3aef88ae641e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="7f1bd9e83b67dc80eb7e0d85089b6e1994df1be5" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Apr 21 10:46:40 UTC 2026" VOLUMIO_VERSION="4.143" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="60cbb92254e29470ae425bda0da9f4c8"