Jan 26 16:53:03 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 26 16:53:03 volumio volumio[1364]: info: In handleBrowseUri, curUri=spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:03 volumio volumio[1364]: info: New access token = BQDkVAtoHzP_eN1FVyUXktK6F-mNYa9omhLdM-ue8lG9aJhIdEvwWHU71sUDlq8axeAaZrGPuW7LnMYQqL6u75GHfHclqu-xOYN3heNHLEFBxtborHmAN0yqk5r8aWqet2vchvMUlrex2hyUJQerT89TL22aSbL9Lljzu7Z5EpT31IG-DB-JpLd-xfVFHITL4ZZnx5xCu3ogEyL1RvNOeIdCGXY28wttHsYfumjsXSJH0_UEQuK9DYAT8wVpWIR3jMVtvSxJ_3w5j6oFjhfdhVdA6xx6ja8uXU0YRcIdMiNJOuso04nAa5pT Jan 26 16:53:04 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::ClearQueue Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::stop Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::stPlaybackTimer Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::serviceStop Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::serviceStop Jan 26 16:53:04 volumio volumio[1364]: info: ControllerMpd::stop Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::clearPlayQueue Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::addQueueItems Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::addQueueItems Jan 26 16:53:04 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:04 volumio volumio[1364]: info: Adding Item to queue: spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:04 volumio volumio[1364]: info: Exploding uri spotify:album:3Fcd4VzMAlE3RTsTgSVB83 in service spop Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:04 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:04 volumio volumio[1364]: info: Preloading song: spotify:track:5k5eOffciYSSg8ChIeP7tq Jan 26 16:53:04 volumio volumio[1364]: info: Preloading song: spotify:track:1QhclTOnnFi6Oy6iNqa81l Jan 26 16:53:04 volumio volumio[1364]: info: Preloading song: spotify:track:20nLzHYX1zVuK4472mQwID Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: info: Jan 26 16:53:04 volumio volumio[1364]: ---------------------------- MPD announces state update: player Jan 26 16:53:04 volumio volumio[1364]: info: sendMpdCommand stop took 98 milliseconds Jan 26 16:53:04 volumio volumio[1364]: info: ControllerMpd::getState Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::sendMpdCommand status Jan 26 16:53:04 volumio volumio[1364]: info: Jan 26 16:53:04 volumio volumio[1364]: ---------------------------- MPD announces state update: player Jan 26 16:53:04 volumio volumio[1364]: info: ControllerMpd::getState Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::sendMpdCommand status Jan 26 16:53:04 volumio volumio[1364]: info: Exploding uri spotify:track:5k5eOffciYSSg8ChIeP7tq in service spop Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:5k5eOffciYSSg8ChIeP7tq Jan 26 16:53:04 volumio volumio[1364]: info: sendMpdCommand status took 21 milliseconds Jan 26 16:53:04 volumio volumio[1364]: info: sendMpdCommand status took 20 milliseconds Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::parseState Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::parseState Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 16:53:04 volumio volumio[1364]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 26 16:53:04 volumio volumio[1364]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::parseTrackInfo Jan 26 16:53:04 volumio volumio[1364]: verbose: ControllerMpd::parseTrackInfo Jan 26 16:53:04 volumio volumio[1364]: info: ControllerMpd::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::servicePushState Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Giorgio by Moroder","artist":"Daft Punk","album":"Random Access Memories","uri":"NAS/music/Daft_Punk-Random_Access_Memories-24-88-WEB-FLAC-2013-OBZEN.1/03-daft_punk-giorgio_by_moroder-b249787a.flac","trackType":"flac"} Jan 26 16:53:04 volumio volumio[1364]: verbose: CURRENT POSITION 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::syncState stateService stop Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::syncState currentStatus stop Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: No code Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: ControllerMpd::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::servicePushState Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Giorgio by Moroder","artist":"Daft Punk","album":"Random Access Memories","uri":"NAS/music/Daft_Punk-Random_Access_Memories-24-88-WEB-FLAC-2013-OBZEN.1/03-daft_punk-giorgio_by_moroder-b249787a.flac","trackType":"flac"} Jan 26 16:53:04 volumio volumio[1364]: verbose: CURRENT POSITION 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::syncState stateService stop Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::syncState currentStatus stop Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: No code Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:53:04 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: ------------------------------ 125ms Jan 26 16:53:04 volumio volumio[1364]: info: ------------------------------ 114ms Jan 26 16:53:04 volumio volumio[1364]: info: Exploding uri spotify:track:1QhclTOnnFi6Oy6iNqa81l in service spop Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1QhclTOnnFi6Oy6iNqa81l Jan 26 16:53:04 volumio volumio[1364]: info: Exploding uri spotify:track:20nLzHYX1zVuK4472mQwID in service spop Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:20nLzHYX1zVuK4472mQwID Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 26 16:53:04 volumio volumio[1364]: info: CoreCommandRouter::volumioPlay Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::play index 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::stop Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::play index undefined Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: CoreStateMachine::startPlaybackTimer Jan 26 16:53:04 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:04 volumio volumio[1364]: info: [1769442784819] ControllerSpotify::clearAddPlayTrack Jan 26 16:53:04 volumio volumio[1364]: info: Sending Spotify command with payload to local API: /player/play Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5k5eOffciYSSg8ChIeP7tq","service":"spop","name":"Simié la limière","artist":"KAYA","album":"Mo la misik","type":"song","duration":200,"albumart":"https://i.scdn.co/image/ab67616d0000b27309ab6e9fd8d5746393399ae4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:20nLzHYX1zVuK4472mQwID","service":"spop","name":"Chante l'amour","artist":"KAYA","album":"Mo la misik","type":"song","duration":275,"albumart":"https://i.scdn.co/image/ab67616d0000b27309ab6e9fd8d5746393399ae4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:04 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1QhclTOnnFi6Oy6iNqa81l","service":"spop","name":"Ras kouyon","artist":"KAYA","album":"Mo la misik","type":"song","duration":467,"albumart":"https://i.scdn.co/image/ab67616d0000b27309ab6e9fd8d5746393399ae4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:05 volumio volumio[1364]: info: Executing endpoint getSimilarAlbums Jan 26 16:53:05 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jan 26 16:53:05 volumio volumio[1364]: info: Executing endpoint getSimilarAlbums Jan 26 16:53:05 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jan 26 16:53:05 volumio volumio[1364]: info: Executing endpoint metavolumio Jan 26 16:53:05 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 26 16:53:05 volumio volumio[1364]: info: Executing endpoint metavolumio Jan 26 16:53:05 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 26 16:53:05 volumio volumio[1364]: info: Executing endpoint metavolumio Jan 26 16:53:05 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 26 16:53:05 volumio volumio[1364]: info: Executing endpoint metavolumio Jan 26 16:53:05 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 26 16:53:08 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:08 volumio volumio[1364]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::ClearQueue Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::stop Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::clearPlayQueue Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:53:08 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::addQueueItems Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::addQueueItems Jan 26 16:53:08 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:08 volumio volumio[1364]: info: Adding Item to queue: spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:08 volumio volumio[1364]: info: Using cached record of: spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:08 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:53:08 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:08 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 26 16:53:08 volumio volumio[1364]: info: CoreCommandRouter::volumioPlay Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::play index 0 Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::stop Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::play index undefined Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:08 volumio volumio[1364]: info: CoreStateMachine::startPlaybackTimer Jan 26 16:53:08 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:08 volumio volumio[1364]: info: [1769442788064] ControllerSpotify::clearAddPlayTrack Jan 26 16:53:08 volumio volumio[1364]: info: Sending Spotify command with payload to local API: /player/play Jan 26 16:53:09 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:09 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:19 volumio volumio[1364]: info: CoreCommandRouter::volumioplayNextItems Jan 26 16:53:19 volumio volumio[1364]: info: CoreStateMachine::playNextItems Jan 26 16:53:19 volumio volumio[1364]: info: CorePlayQueue::addPlayNextItems Jan 26 16:53:19 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:19 volumio volumio[1364]: info: Adding Item to play next: spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:19 volumio volumio[1364]: info: Using cached record of: spotify:album:3Fcd4VzMAlE3RTsTgSVB83 Jan 26 16:53:19 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:53:19 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:53:19 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:53:19 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:53:19 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:19 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:19 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:19 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:29 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:29 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:33 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 26 16:53:33 volumio volumio[1364]: info: In handleBrowseUri, curUri=spotify/playlists Jan 26 16:53:33 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:37 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 26 16:53:37 volumio volumio[1364]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:0W4rcI1fk823oB1YZdHzu3 Jan 26 16:53:38 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:38 volumio volumio[1364]: info: Preloading song: spotify:track:6pW5qN3CaUUzS4gzBuhwgp Jan 26 16:53:38 volumio volumio[1364]: info: Preloading song: spotify:track:6xiBw5s8JrFnEjrkz3jpUO Jan 26 16:53:38 volumio volumio[1364]: info: Preloading song: spotify:track:18KVRtWqAqVrdHglsK0mLh Jan 26 16:53:38 volumio volumio[1364]: info: Preloading song: spotify:track:7D3AvJojWNdkEWoSIwFLiE Jan 26 16:53:38 volumio volumio[1364]: info: Preloading song: spotify:track:0WHGlVMA9L4EelsMEXgKiJ Jan 26 16:53:38 volumio volumio[1364]: info: Preloading song: spotify:track:7sHHmnHfUXeVDcYN3GKt7h Jan 26 16:53:38 volumio volumio[1364]: info: Exploding uri spotify:track:6pW5qN3CaUUzS4gzBuhwgp in service spop Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:6pW5qN3CaUUzS4gzBuhwgp Jan 26 16:53:38 volumio volumio[1364]: info: Exploding uri spotify:track:6xiBw5s8JrFnEjrkz3jpUO in service spop Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:6xiBw5s8JrFnEjrkz3jpUO Jan 26 16:53:38 volumio volumio[1364]: info: Exploding uri spotify:track:18KVRtWqAqVrdHglsK0mLh in service spop Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:18KVRtWqAqVrdHglsK0mLh Jan 26 16:53:38 volumio volumio[1364]: info: Exploding uri spotify:track:7D3AvJojWNdkEWoSIwFLiE in service spop Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7D3AvJojWNdkEWoSIwFLiE Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6pW5qN3CaUUzS4gzBuhwgp","service":"spop","name":"Off the Grid (feat. Khalid)","artist":"Alina Baraz","album":"It Was Divine","type":"song","duration":200,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec95596a5d5771ac871d339d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:38 volumio volumio[1364]: info: Exploding uri spotify:track:0WHGlVMA9L4EelsMEXgKiJ in service spop Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:0WHGlVMA9L4EelsMEXgKiJ Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:18KVRtWqAqVrdHglsK0mLh","service":"spop","name":"Down","artist":"Haute","album":"Nova Tunes 3.0","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b273fd59a1b55491c5275a884df7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:38 volumio volumio[1364]: info: Exploding uri spotify:track:7sHHmnHfUXeVDcYN3GKt7h in service spop Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7sHHmnHfUXeVDcYN3GKt7h Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6xiBw5s8JrFnEjrkz3jpUO","service":"spop","name":"Blame Me","artist":"Feder","album":"Blame Me","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b273568b5fd43acfacf0e301d879","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7D3AvJojWNdkEWoSIwFLiE","service":"spop","name":"Alone With You","artist":"Alina Baraz","album":"Alone With You","type":"song","duration":226,"albumart":"https://i.scdn.co/image/ab67616d0000b2733bc212b634c249bc0ff799ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0WHGlVMA9L4EelsMEXgKiJ","service":"spop","name":"Bleu Marine - A COLORS SHOW","artist":"Jewel Usain","album":"Bleu Marine - A COLORS SHOW","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b2736bf1128cae132865453fa516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:38 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7sHHmnHfUXeVDcYN3GKt7h","service":"spop","name":"Floating (feat. Khalid)","artist":"Alina Baraz","album":"The Color Of You","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b2733b82d56eae69108ac6c72201","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:53:39 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:39 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:39 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:39 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:45 volumio volumio[1364]: info: CoreCommandRouter::volumioplayNextItems Jan 26 16:53:45 volumio volumio[1364]: info: CoreStateMachine::playNextItems Jan 26 16:53:45 volumio volumio[1364]: info: CorePlayQueue::addPlayNextItems Jan 26 16:53:45 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:53:45 volumio volumio[1364]: info: Adding Item to play next: spotify:user:spotify:playlist:0W4rcI1fk823oB1YZdHzu3 Jan 26 16:53:45 volumio volumio[1364]: info: Exploding uri spotify:user:spotify:playlist:0W4rcI1fk823oB1YZdHzu3 in service spop Jan 26 16:53:45 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:0W4rcI1fk823oB1YZdHzu3 Jan 26 16:53:45 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:53:45 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:53:45 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:53:45 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:53:49 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:49 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:57 volumio volumio[1364]: verbose: New Socket.io Connection to 192.168.86.73:3000 from 192.168.86.43 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:57 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:57 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:57 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:57 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 26 16:53:57 volumio sudo[22808]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 26 16:53:57 volumio sudo[22808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:57 volumio sudo[22808]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:57 volumio sudo[22813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 26 16:53:57 volumio sudo[22813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:57 volumio sudo[22813]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:57 volumio sudo[22820]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 26 16:53:57 volumio sudo[22820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:57 volumio sudo[22820]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:57 volumio sudo[22826]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 26 16:53:57 volumio sudo[22826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:57 volumio sudo[22833]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 16:53:57 volumio sudo[22833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:57 volumio sudo[22826]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:57 volumio sudo[22833]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:57 volumio sudo[22836]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 16:53:57 volumio sudo[22836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:57 volumio sudo[22836]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:57 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:57 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:57 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:57 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:58 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:58 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:58 volumio volumio[1364]: verbose: New Socket.io Connection to 192.168.86.73:3000 from 192.168.86.43 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:58 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:58 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:58 volumio volumio[1364]: verbose: New Socket.io Connection to 192.168.86.73:3000 from 192.168.86.43 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:58 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:58 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:58 volumio volumio[1364]: verbose: New Socket.io Connection to 192.168.86.73:3000 from 192.168.86.43 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 26 16:53:58 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 26 16:53:58 volumio sudo[22840]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 16:53:58 volumio sudo[22840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:59 volumio sudo[22840]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:59 volumio sudo[22842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 16:53:59 volumio sudo[22842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:59 volumio sudo[22842]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:59 volumio volumio[1364]: verbose: New Socket.io Connection to 192.168.86.73 from 192.168.86.43 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Jan 26 16:53:59 volumio sudo[22846]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 16:53:59 volumio sudo[22846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:59 volumio sudo[22846]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:59 volumio sudo[22848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 16:53:59 volumio sudo[22848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:59 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:59 volumio sudo[22848]: pam_unix(sudo:session): session closed for user root Jan 26 16:53:59 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:59 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:59 volumio volumio[1364]: verbose: New Socket.io Connection to 192.168.86.73 from 192.168.86.43 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 11 Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::volumioGetVisibleSources Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:59 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 26 16:53:59 volumio volumio[1364]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 26 16:53:59 volumio volumio[1364]: info: Received Get System Info Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:53:59 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:59 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:53:59 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:53:59 volumio volumio[1364]: info: Listing playlists Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 26 16:53:59 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 26 16:54:01 volumio volumio[1364]: info: Received Get System Info Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:54:01 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:01 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:54:01 volumio volumio[1364]: info: CoreCommandRouter::volumioGetQueue Jan 26 16:54:01 volumio volumio[1364]: info: CoreStateMachine::getQueue Jan 26 16:54:01 volumio volumio[1364]: info: CorePlayQueue::getQueue Jan 26 16:54:02 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 26 16:54:02 volumio volumio[1364]: info: Received Get System Info Jan 26 16:54:02 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:54:02 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:54:02 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:54:02 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:02 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:02 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:54:09 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:09 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:09 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 26 16:54:11 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 26 16:54:11 volumio volumio[1364]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:37i9dQZF1E37w232EZ8Wrd Jan 26 16:54:14 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:0Psz3az3RIYfJpnsajBT8N Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:77Whq0zG4OqyKgUZq2FVCY Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:5HdUMBc7AhPFhlPDZUpSwf Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:0J1rfWxfvcmoFQnN1Z0iFf Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:4ffoWIfe9UWfyuJT5I0I7L Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7nZ9CzhiFRPhOQCn7eDSnn Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1Uhy2u2QxyEjd1pZlwaDTU Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7FAyIPD8YLpUQc5r0MSv60 Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:47zm2CR6vfWK9iRBJvAnGT Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1wX6FBlESW54Fr6bASY7UF Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2ZpC4XRsRSVpRUO3bZAwgq Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7ycuy5Mvd0ILPwkrpwdY9I Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:33F1mJbbdTdmZuSI5zxoSw Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:260V7huyJrXnyYe0dFv2Fa Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1m8nxmNtzdJMGPKi5R3aJ2 Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:3pr0y5h4MkBngy6gyozLDV Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1fsarPmsdYzQuEtgeqLusc Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:5yfHDmZHjMw2gLjbghG90V Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:4eP7VbswtkGd5Hlyj4E7Qx Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2GuIRSthEpYN5MO6PGD7Vx Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:6EZWwoSA0gaOM2Y9SVm6Gu Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:0jNFq59zT9PfahNqPJYzsu Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2SCLswvRP8hAYdIKsrLV6h Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7pAW3XGsByG4avvzn3BGYE Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7LqT7LqKsCh6epYR9UdAlP Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:4kJb2YFLIxCsEe6bz6JbmN Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2hqN3UpBkP8j2UT6yPvBh1 Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1GKrArph1YXfxMH49flYND Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:16HQun8B0yuXtErTUBwBsD Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:6gm6WkAymLg5rqDardxLj7 Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:0hNlr56UPvigGSyCVdAOMi Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:6GbWNeR3P9MTCmSyPVHgb1 Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7i5I4h7r2vkI2r9tgKjy0x Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:5exiWZkZho6AvCGkabEMeA Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1gg7VrHQD09dTZd8MzCsRA Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:5wTv501Kl9wLABLwHo11RJ Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:4UPNrU3SCxNxa4qXcM3oOs Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1D3Mw3Cnm7X7TVceFfrSx0 Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:1gWnuGAiTk3Q4yrIbwymUK Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:7Cv8DRBiNOPpftEFfDcGMs Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:6djHeQOMCeQUnX6rCvH8WW Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2HCgcgN4PA0xr2ZqtsBpPb Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2SCHvVxxf591F0EsSNCsRK Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:74ToqXbeAiYufreBsTUlEi Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:2MkExoMFzMUOsd9gjYmMLo Jan 26 16:54:14 volumio volumio[1364]: info: Preloading song: spotify:track:52Abbh6ppAZGOSl9HsJZLb Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:0Psz3az3RIYfJpnsajBT8N in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:0Psz3az3RIYfJpnsajBT8N Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:77Whq0zG4OqyKgUZq2FVCY in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:77Whq0zG4OqyKgUZq2FVCY Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:5HdUMBc7AhPFhlPDZUpSwf in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:5HdUMBc7AhPFhlPDZUpSwf Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:0J1rfWxfvcmoFQnN1Z0iFf in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:0J1rfWxfvcmoFQnN1Z0iFf Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Psz3az3RIYfJpnsajBT8N","service":"spop","name":"Nanã","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:4ffoWIfe9UWfyuJT5I0I7L in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:4ffoWIfe9UWfyuJT5I0I7L Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:77Whq0zG4OqyKgUZq2FVCY","service":"spop","name":"A l'aube","artist":"Feu! Chatterton","album":"Feu! Chatterton - EP","type":"song","duration":284,"albumart":"https://i.scdn.co/image/ab67616d0000b27303524263f66fff23e06dc7fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:7nZ9CzhiFRPhOQCn7eDSnn in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7nZ9CzhiFRPhOQCn7eDSnn Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:1Uhy2u2QxyEjd1pZlwaDTU in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1Uhy2u2QxyEjd1pZlwaDTU Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5HdUMBc7AhPFhlPDZUpSwf","service":"spop","name":"Prayer In C - Robin Schulz Remix - Radio Edit","artist":"Lilly Wood and The Prick","album":"Invincible Friends (Edition Robin Schulz Remix)","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b2734a2428589e34a44ee8844355","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0J1rfWxfvcmoFQnN1Z0iFf","service":"spop","name":"des bisous","artist":"Myra","album":"des bisous","type":"song","duration":172,"albumart":"https://i.scdn.co/image/ab67616d0000b2737efcf4d378b03bf43a96a01a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:7FAyIPD8YLpUQc5r0MSv60 in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7FAyIPD8YLpUQc5r0MSv60 Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:47zm2CR6vfWK9iRBJvAnGT in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:47zm2CR6vfWK9iRBJvAnGT Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:1wX6FBlESW54Fr6bASY7UF in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1wX6FBlESW54Fr6bASY7UF Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7nZ9CzhiFRPhOQCn7eDSnn","service":"spop","name":"Vanille fraise","artist":"L'Impératrice","album":"Vanille fraise","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b2734378e3b644f45841c3008454","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Uhy2u2QxyEjd1pZlwaDTU","service":"spop","name":"Plage isolée (soleil levant)","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:2ZpC4XRsRSVpRUO3bZAwgq in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2ZpC4XRsRSVpRUO3bZAwgq Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:7ycuy5Mvd0ILPwkrpwdY9I in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7ycuy5Mvd0ILPwkrpwdY9I Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4ffoWIfe9UWfyuJT5I0I7L","service":"spop","name":"Les mots bleus","artist":"Johan Papaconstantino","album":"Les mots bleus","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b2733cebc4b0dae0ed6a0a26d134","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7FAyIPD8YLpUQc5r0MSv60","service":"spop","name":"Photomaton","artist":"Jabberwocky","album":"Pola","type":"song","duration":280,"albumart":"https://i.scdn.co/image/ab67616d0000b2738bc58fe5577dd45266613b2d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:33F1mJbbdTdmZuSI5zxoSw in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:33F1mJbbdTdmZuSI5zxoSw Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:260V7huyJrXnyYe0dFv2Fa in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:260V7huyJrXnyYe0dFv2Fa Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1wX6FBlESW54Fr6bASY7UF","service":"spop","name":"Shut Me Down","artist":"Haute","album":"Haute","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b273bfdfe2c3fb3aec52b6c739ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:1m8nxmNtzdJMGPKi5R3aJ2 in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1m8nxmNtzdJMGPKi5R3aJ2 Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ZpC4XRsRSVpRUO3bZAwgq","service":"spop","name":"Tes petites fesses","artist":"LYNN","album":"Tes petites fesses","type":"song","duration":110,"albumart":"https://i.scdn.co/image/ab67616d0000b273a5f380bf01f6cfeadc8e8fe6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:3pr0y5h4MkBngy6gyozLDV in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:3pr0y5h4MkBngy6gyozLDV Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:47zm2CR6vfWK9iRBJvAnGT","service":"spop","name":"Lavender and Velvet","artist":"Alina Baraz","album":"Lavender and Velvet","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f2dfb5d9e4e7102eaf65bfa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ycuy5Mvd0ILPwkrpwdY9I","service":"spop","name":"Sous garantie","artist":"Malik Djoudi","album":"UN","type":"song","duration":173,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f4d35ce655cb92441a1054d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:1fsarPmsdYzQuEtgeqLusc in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1fsarPmsdYzQuEtgeqLusc Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:33F1mJbbdTdmZuSI5zxoSw","service":"spop","name":"Pluie fine - Polo & Pan Remix","artist":"Corine","album":"Fille de ta région remixée","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b27320a51927d7114cd0ce7bbca8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:14 volumio volumio[1364]: info: Exploding uri spotify:track:5yfHDmZHjMw2gLjbghG90V in service spop Jan 26 16:54:14 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:5yfHDmZHjMw2gLjbghG90V Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:260V7huyJrXnyYe0dFv2Fa","service":"spop","name":"Canopée","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":276,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:4eP7VbswtkGd5Hlyj4E7Qx in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:4eP7VbswtkGd5Hlyj4E7Qx Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1m8nxmNtzdJMGPKi5R3aJ2","service":"spop","name":"Headson","artist":"Kazy Lambist","album":"Headson","type":"song","duration":187,"albumart":"https://i.scdn.co/image/ab67616d0000b2739486f086e63b125d9d94ae47","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:2GuIRSthEpYN5MO6PGD7Vx in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2GuIRSthEpYN5MO6PGD7Vx Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3pr0y5h4MkBngy6gyozLDV","service":"spop","name":"Voodoo?","artist":"L'Impératrice","album":"Tako Tsubo","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b273389ffd99d51037a6f0a256f5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:6EZWwoSA0gaOM2Y9SVm6Gu in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:6EZWwoSA0gaOM2Y9SVm6Gu Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1fsarPmsdYzQuEtgeqLusc","service":"spop","name":"Fading Away","artist":"Adam Naas","album":"Adam Naas","type":"song","duration":247,"albumart":"https://i.scdn.co/image/ab67616d0000b27379983788f0bd493f087b95ba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:0jNFq59zT9PfahNqPJYzsu in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:0jNFq59zT9PfahNqPJYzsu Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5yfHDmZHjMw2gLjbghG90V","service":"spop","name":"Hot Hands","artist":"Darius","album":"Romance","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273f5c584384450e0e01356a9ac","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:2SCLswvRP8hAYdIKsrLV6h in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2SCLswvRP8hAYdIKsrLV6h Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4eP7VbswtkGd5Hlyj4E7Qx","service":"spop","name":"Nevada","artist":"Kerala Dust","album":"Late Sun","type":"song","duration":363,"albumart":"https://i.scdn.co/image/ab67616d0000b273a8683b0701eb2b1110695427","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:7pAW3XGsByG4avvzn3BGYE in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7pAW3XGsByG4avvzn3BGYE Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6EZWwoSA0gaOM2Y9SVm6Gu","service":"spop","name":"On You","artist":"Kazy Lambist","album":"On You - Single","type":"song","duration":197,"albumart":"https://i.scdn.co/image/ab67616d0000b2736a5c214353dbe7c783b49edd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:7LqT7LqKsCh6epYR9UdAlP in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7LqT7LqKsCh6epYR9UdAlP Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7LqT7LqKsCh6epYR9UdAlP Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:4kJb2YFLIxCsEe6bz6JbmN in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:4kJb2YFLIxCsEe6bz6JbmN Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2GuIRSthEpYN5MO6PGD7Vx","service":"spop","name":"Dorothy","artist":"Polo & Pan","album":"Dorothy","type":"song","duration":316,"albumart":"https://i.scdn.co/image/ab67616d0000b273fb53b46cb20009d264f2c0fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:2hqN3UpBkP8j2UT6yPvBh1 in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2hqN3UpBkP8j2UT6yPvBh1 Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0jNFq59zT9PfahNqPJYzsu","service":"spop","name":"More Than Enough","artist":"Alina Baraz","album":"It Was Divine","type":"song","duration":151,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec95596a5d5771ac871d339d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2SCLswvRP8hAYdIKsrLV6h","service":"spop","name":"The Finishing","artist":"Stavroz","album":"The Ginning","type":"song","duration":482,"albumart":"https://i.scdn.co/image/ab67616d0000b273a3172d3d600d4c70936852fa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:1GKrArph1YXfxMH49flYND in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1GKrArph1YXfxMH49flYND Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7pAW3XGsByG4avvzn3BGYE","service":"spop","name":"J'sais pas","artist":"Johan Papaconstantino","album":"Contre-jour","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b2736cf31e12ca2afa27f92f2feb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7LqT7LqKsCh6epYR9UdAlP","service":"spop","name":"Five Minutes","artist":"Her","album":"Her","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ce1f2205f2527e609156df7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:16HQun8B0yuXtErTUBwBsD in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:16HQun8B0yuXtErTUBwBsD Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4kJb2YFLIxCsEe6bz6JbmN","service":"spop","name":"Sur un volcan","artist":"La Maison Tellier","album":"Beauté pour tous","type":"song","duration":185,"albumart":"https://i.scdn.co/image/ab67616d0000b2735aed7b6e6b7fa207b5c8d762","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:6gm6WkAymLg5rqDardxLj7 in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:6gm6WkAymLg5rqDardxLj7 Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:0hNlr56UPvigGSyCVdAOMi in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:0hNlr56UPvigGSyCVdAOMi Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1GKrArph1YXfxMH49flYND","service":"spop","name":"Electric (feat. Khalid)","artist":"Alina Baraz","album":"The Color Of You","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b2733b82d56eae69108ac6c72201","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:6GbWNeR3P9MTCmSyPVHgb1 in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:6GbWNeR3P9MTCmSyPVHgb1 Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:7i5I4h7r2vkI2r9tgKjy0x in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7i5I4h7r2vkI2r9tgKjy0x Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2hqN3UpBkP8j2UT6yPvBh1","service":"spop","name":"Cœur croisé","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:16HQun8B0yuXtErTUBwBsD","service":"spop","name":"Paradis bleu","artist":"Revers Gagnant","album":"Premier Set","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b273b19d5c7fe399a050e2e9378b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:5exiWZkZho6AvCGkabEMeA in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:5exiWZkZho6AvCGkabEMeA Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6gm6WkAymLg5rqDardxLj7","service":"spop","name":"The Love","artist":"Adam Naas","album":"The Love Album","type":"song","duration":277,"albumart":"https://i.scdn.co/image/ab67616d0000b273e4857bee250f6a85ebadc415","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0hNlr56UPvigGSyCVdAOMi","service":"spop","name":"The Ginning","artist":"Stavroz","album":"The Ginning","type":"song","duration":391,"albumart":"https://i.scdn.co/image/ab67616d0000b273a3172d3d600d4c70936852fa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6GbWNeR3P9MTCmSyPVHgb1","service":"spop","name":"Taste","artist":"Rhye","album":"Blood","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ac4b6a8a567565ab20671ee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:1gg7VrHQD09dTZd8MzCsRA in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1gg7VrHQD09dTZd8MzCsRA Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:5wTv501Kl9wLABLwHo11RJ in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:5wTv501Kl9wLABLwHo11RJ Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7i5I4h7r2vkI2r9tgKjy0x","service":"spop","name":"Pays imaginaire","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":289,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:4UPNrU3SCxNxa4qXcM3oOs in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:4UPNrU3SCxNxa4qXcM3oOs Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5exiWZkZho6AvCGkabEMeA","service":"spop","name":"Pourquoi pas","artist":"Miel De Montagne","album":"Miel de Montagne","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b2739cccb0fa242f56e6e627875e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:15 volumio volumio[1364]: info: Exploding uri spotify:track:1D3Mw3Cnm7X7TVceFfrSx0 in service spop Jan 26 16:54:15 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1D3Mw3Cnm7X7TVceFfrSx0 Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:1gWnuGAiTk3Q4yrIbwymUK in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:1gWnuGAiTk3Q4yrIbwymUK Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1gg7VrHQD09dTZd8MzCsRA","service":"spop","name":"Dream","artist":"Husbands","album":"DREAM / OVERSEAS","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b273c4154f96e1bce83880e5aec1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:7Cv8DRBiNOPpftEFfDcGMs in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:7Cv8DRBiNOPpftEFfDcGMs Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:6djHeQOMCeQUnX6rCvH8WW in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:6djHeQOMCeQUnX6rCvH8WW Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1D3Mw3Cnm7X7TVceFfrSx0","service":"spop","name":"The Lighthouse","artist":"Applause","album":"Applause","type":"song","duration":208,"albumart":"https://i.scdn.co/image/ab67616d0000b2739244ce4abfe7fe588dbbf707","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5wTv501Kl9wLABLwHo11RJ","service":"spop","name":"Like A Fool","artist":"Crazy P","album":"Walk Dance Talk Sing","type":"song","duration":305,"albumart":"https://i.scdn.co/image/ab67616d0000b273be0cd4d2ffeb6228115f83de","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4UPNrU3SCxNxa4qXcM3oOs","service":"spop","name":"Ça fait du bien - Polo & Pan Remix","artist":"Antonin","album":"Ça fait 2x plus de bien","type":"song","duration":181,"albumart":"https://i.scdn.co/image/ab67616d0000b27362bd4d0a325cd97a3d730c71","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:2HCgcgN4PA0xr2ZqtsBpPb in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2HCgcgN4PA0xr2ZqtsBpPb Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1gWnuGAiTk3Q4yrIbwymUK","service":"spop","name":"Zoom Zoom","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:2SCHvVxxf591F0EsSNCsRK in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2SCHvVxxf591F0EsSNCsRK Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:74ToqXbeAiYufreBsTUlEi in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:74ToqXbeAiYufreBsTUlEi Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:2MkExoMFzMUOsd9gjYmMLo in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:2MkExoMFzMUOsd9gjYmMLo Jan 26 16:54:16 volumio volumio[1364]: info: Exploding uri spotify:track:52Abbh6ppAZGOSl9HsJZLb in service spop Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:track:52Abbh6ppAZGOSl9HsJZLb Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6djHeQOMCeQUnX6rCvH8WW","service":"spop","name":"I Want To Get You Close To Me","artist":"Adam Naas","album":"The Love Album","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b273e4857bee250f6a85ebadc415","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:74ToqXbeAiYufreBsTUlEi","service":"spop","name":"Blow Up","artist":"Kid Francescoli","album":"With Julia","type":"song","duration":315,"albumart":"https://i.scdn.co/image/ab67616d0000b27389035da917e1615f78af6a8d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2SCHvVxxf591F0EsSNCsRK","service":"spop","name":"Told You So","artist":"Cameo Culture","album":"Burning Bright","type":"song","duration":304,"albumart":"https://i.scdn.co/image/ab67616d0000b273910decb8bbcc06d4bd96d9e5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2HCgcgN4PA0xr2ZqtsBpPb","service":"spop","name":"On Our Knees (feat. R.O)","artist":"Konoba","album":"Smoke & Mirrors","type":"song","duration":277,"albumart":"https://i.scdn.co/image/ab67616d0000b2731aa87528c333f96a79a54b55","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2MkExoMFzMUOsd9gjYmMLo","service":"spop","name":"Choose the Heart - La Fine Equipe Remix","artist":"Madjo","album":"Choose the Heart (La Fine Equipe Remix)","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b273bbcfa5312949e430cdaf321d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7Cv8DRBiNOPpftEFfDcGMs","service":"spop","name":"Pom Pom","artist":"Myra","album":"Pom Pom","type":"song","duration":155,"albumart":"https://i.scdn.co/image/ab67616d0000b2736f3f4138411fd1258d3a27ae","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:16 volumio volumio[1364]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:52Abbh6ppAZGOSl9HsJZLb","service":"spop","name":"Kirghiz","artist":"Polo & Pan","album":"Caravelle","type":"song","duration":306,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ee9468123f381eb8d5e05bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 26 16:54:17 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 26 16:54:17 volumio volumio[1364]: info: CoreStateMachine::ClearQueue Jan 26 16:54:17 volumio volumio[1364]: info: CoreStateMachine::stop Jan 26 16:54:17 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:54:17 volumio volumio[1364]: info: CorePlayQueue::clearPlayQueue Jan 26 16:54:17 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:54:17 volumio volumio[1364]: info: CoreStateMachine::addQueueItems Jan 26 16:54:17 volumio volumio[1364]: info: CorePlayQueue::addQueueItems Jan 26 16:54:17 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:54:17 volumio volumio[1364]: info: Adding Item to queue: spotify:user:spotify:playlist:37i9dQZF1E37w232EZ8Wrd Jan 26 16:54:17 volumio volumio[1364]: info: Exploding uri spotify:user:spotify:playlist:37i9dQZF1E37w232EZ8Wrd in service spop Jan 26 16:54:17 volumio volumio[1364]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:37i9dQZF1E37w232EZ8Wrd Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 26 16:54:17 volumio volumio[1364]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 26 16:54:17 volumio volumio[1364]: info: Received Get System Version Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 16:54:17 volumio volumio[1364]: info: Received Get System Info Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 16:54:17 volumio volumio[1364]: info: Discovery: Getting this device information Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:17 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:17 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 16:54:18 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:54:18 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:54:18 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:54:18 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:18 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:18 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 26 16:54:18 volumio volumio[1364]: info: CoreCommandRouter::volumioPlay Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::play index 0 Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::stop Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::play index undefined Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:54:18 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:18 volumio volumio[1364]: info: CoreStateMachine::startPlaybackTimer Jan 26 16:54:18 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:18 volumio volumio[1364]: info: [1769442858209] ControllerSpotify::clearAddPlayTrack Jan 26 16:54:18 volumio volumio[1364]: info: Sending Spotify command with payload to local API: /player/play Jan 26 16:54:19 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:19 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:19 volumio volumio[1364]: info: Listing playlists Jan 26 16:54:19 volumio volumio[1364]: info: Listing playlists Jan 26 16:54:21 volumio volumio[1364]: info: CoreCommandRouter::volumioplayNextItems Jan 26 16:54:21 volumio volumio[1364]: info: CoreStateMachine::playNextItems Jan 26 16:54:21 volumio volumio[1364]: info: CorePlayQueue::addPlayNextItems Jan 26 16:54:21 volumio volumio[1364]: info: Preload queue cleared Jan 26 16:54:21 volumio volumio[1364]: info: Adding Item to play next: spotify:user:spotify:playlist:37i9dQZF1E37w232EZ8Wrd Jan 26 16:54:21 volumio volumio[1364]: info: Using cached record of: spotify:user:spotify:playlist:37i9dQZF1E37w232EZ8Wrd Jan 26 16:54:21 volumio volumio[1364]: info: CoreCommandRouter::volumioPushQueue Jan 26 16:54:21 volumio volumio[1364]: info: CorePlayQueue::saveQueue Jan 26 16:54:21 volumio volumio[1364]: info: CoreStateMachine::updateTrackBlock Jan 26 16:54:21 volumio volumio[1364]: info: CorePlayQueue::getTrackBlock Jan 26 16:54:27 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 26 16:54:27 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 26 16:54:27 volumio volumio[1364]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 26 16:54:29 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:29 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:30 volumio go-librespot[1953]: time="2026-01-26T16:54:30+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jan 26 16:54:30 volumio volumio[1364]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Jan 26 16:54:30 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 16:54:30 volumio volumio[1364]: Cannot find translation for source YouTube2 Jan 26 16:54:30 volumio volumio[1364]: info: Disabling plugin spop Jan 26 16:54:30 volumio volumio[1364]: info: Done. Jan 26 16:54:30 volumio sudo[22906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Jan 26 16:54:30 volumio volumio[1364]: info: Connection to go-librespot Websocket closed Jan 26 16:54:30 volumio sudo[22906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:54:30 volumio volumio[1364]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 26 16:54:30 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 16:54:30 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 16:54:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:30 volumio systemd[1]: go-librespot-daemon.service: Consumed 4min 22.656s CPU time. Jan 26 16:54:30 volumio 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. Jan 26 16:54:30 volumio 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. Jan 26 16:54:30 volumio 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. Jan 26 16:54:30 volumio 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. Jan 26 16:54:30 volumio sudo[22906]: pam_unix(sudo:session): session closed for user root Jan 26 16:54:36 volumio volumio[1364]: info: Enabling plugin spop Jan 26 16:54:36 volumio volumio[1364]: info: Loading plugin "spop"... Jan 26 16:54:36 volumio volumio[1364]: info: PLUGIN START: spop Jan 26 16:54:36 volumio volumio[1364]: info: Creating Spotify config file Jan 26 16:54:36 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 16:54:36 volumio volumio[1364]: info: Done. Jan 26 16:54:36 volumio volumio[1364]: info: Spotify config file written Jan 26 16:54:36 volumio volumio[1364]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 26 16:54:36 volumio volumio[1364]: info: No need to fix Spotify hosts Jan 26 16:54:36 volumio sudo[22925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 16:54:36 volumio sudo[22925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:54:36 volumio 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. Jan 26 16:54:36 volumio 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. Jan 26 16:54:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:36 volumio go-librespot[22927]: go-librespot daemon starting... Jan 26 16:54:36 volumio sudo[22925]: pam_unix(sudo:session): session closed for user root Jan 26 16:54:36 volumio go-librespot[22928]: time="2026-01-26T16:54:36+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 16:54:36 volumio go-librespot[22928]: time="2026-01-26T16:54:36+01:00" level=debug msg="app state loaded" Jan 26 16:54:36 volumio go-librespot[22928]: time="2026-01-26T16:54:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 16:54:36 volumio volumio[1364]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 16:54:36 volumio volumio[1364]: SPOTIFY: BQDPcmNBSvH2FWI8uhdZoGVdP4zOWdCSnUOU6Jwhe3WV37e3djdFS-cm6OqTNYxX_PP-kEAFqz0b6dvf2ijhyKBfiS0doKX50j6v1AGMve_l8PLxCugSCd4ms8Wf7xgY_35Bu63vi9FOj6yo91PAHGbcDBAybmbeDyzRFEMfPUc0WuOTqWOXqaVO-1i_UNjz4IQluiNljkEbTk3nuOprB-d9Y-W6M2pw_DQMcJwxEEfYJzggNjqCTlK9cVecSqKVdjVZLpCLXKJQegGd0066GAk1DNggWir5TrPbhvxA0XwyhxPAmUJw_LH1 Jan 26 16:54:36 volumio volumio[1364]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 16:54:36 volumio volumio[1364]: info: New Spotify access token = BQDPcmNBSvH2FWI8uhdZoGVdP4zOWdCSnUOU6Jwhe3WV37e3djdFS-cm6OqTNYxX_PP-kEAFqz0b6dvf2ijhyKBfiS0doKX50j6v1AGMve_l8PLxCugSCd4ms8Wf7xgY_35Bu63vi9FOj6yo91PAHGbcDBAybmbeDyzRFEMfPUc0WuOTqWOXqaVO-1i_UNjz4IQluiNljkEbTk3nuOprB-d9Y-W6M2pw_DQMcJwxEEfYJzggNjqCTlK9cVecSqKVdjVZLpCLXKJQegGd0066GAk1DNggWir5TrPbhvxA0XwyhxPAmUJw_LH1 Jan 26 16:54:36 volumio volumio[1364]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 16:54:36 volumio volumio[1364]: SPOTIFY: User informations: {"country":"FR","display_name":"Gary Soopin","email":"soopin@me.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/21iwmbfpqm7cn53tbmsjqqwbq"},"followers":{"href":null,"total":18},"href":"https://api.spotify.com/v1/users/21iwmbfpqm7cn53tbmsjqqwbq","id":"21iwmbfpqm7cn53tbmsjqqwbq","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=465948760205245&height=300&width=300&ext=1772018956&hash=AT9nH3T1kW_mNQGeTe_8Bbbt","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=465948760205245&height=50&width=50&ext=1772018956&hash=AT-LcPw07EKYPz0XDYZv5y1W","width":64}],"product":"premium","type":"user","uri":"spotify:user:21iwmbfpqm7cn53tbmsjqqwbq"} Jan 26 16:54:36 volumio volumio[1364]: info: Spotify Successfully logged in Jan 26 16:54:36 volumio volumio[1364]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 16:54:36 volumio volumio[1364]: info: [1769442876947] CoreMusicLibrary::Adding element Spotify Jan 26 16:54:36 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 16:54:36 volumio volumio[1364]: Cannot find translation for source YouTube2 Jan 26 16:54:36 volumio volumio[1364]: Cannot find translation for source Spotify Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01: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]" Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01: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]" Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01: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]" Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01:00" level=info msg="zeroconf server listening on port 37099" Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01:00" level=debug msg="obtained new client token: AABriwFm4JZYeQSVMK3yPudrxHNDEXwyGungtiAW3faQXaEKkRvgwjzgoNcmd3tJQt9mDXK8PKAQcPetumhc0cffiO0LkVJHmhQdV9p8p1hg4aG+1lsnD7br7S/2Mea9r1gn2scAb8IUME8YQobPH1KKsSHRK88ifEF/ZrPavvCO//USWOC414nJWGtnQsLCDWfCq4xqBKHwAkzTQ40f/cBpzS1C2i307RKAsEO2ruzHQNbjf99DTw==" Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 16:54:37 volumio go-librespot[22928]: time="2026-01-26T16:54:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 16:54:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 16:54:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 16:54:39 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:39 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:39 volumio volumio[1364]: info: Listing playlists Jan 26 16:54:39 volumio volumio[1364]: info: Listing playlists Jan 26 16:54:39 volumio volumio[1364]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 26 16:54:39 volumio volumio[1364]: info: go-librespot daemon successfully initialized Jan 26 16:54:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 16:54:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:40 volumio go-librespot[22935]: go-librespot daemon starting... Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=debug msg="app state loaded" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01: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]" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01: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]" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01: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]" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=info msg="zeroconf server listening on port 37939" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=debug msg="obtained new client token: AAB2Pf87v9BgHs/OiqTuE/nVihYcCIqyE2xkY2P4Sb3pRV5FF08X3sfEToUWYagV2h1k0eMIoAjyuMbqSnaOSxV0GCzRPMbAGUbcCa5awHQJ9OrfSeM7THqRbc/1f98x9jLglgCq7JhjhRprv8OfdefOEhe+uhqsMJh5fL42p3XXpPznARiIThlCtCi4hhRXSBiXvJgaeflEEXil7q202knkDZhhPXG5JRO+AMdIaqR9uo8P0Se77CD9" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 16:54:40 volumio go-librespot[22936]: time="2026-01-26T16:54:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 16:54:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 16:54:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 16:54:42 volumio volumio[1364]: info: Initializing connection to go-librespot Websocket Jan 26 16:54:42 volumio volumio[1364]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 16:54:43 volumio volumio[1364]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 26 16:54:43 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 26 16:54:43 volumio volumio[1364]: info: Creating Spotify config file Jan 26 16:54:43 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 16:54:43 volumio volumio[1364]: info: Spotify config file written Jan 26 16:54:43 volumio sudo[22948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 16:54:43 volumio sudo[22948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:54:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:43 volumio go-librespot[22950]: go-librespot daemon starting... Jan 26 16:54:43 volumio sudo[22948]: pam_unix(sudo:session): session closed for user root Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="app state loaded" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01: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]" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01: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]" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01: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]" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=info msg="zeroconf server listening on port 34571" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="obtained new client token: AABgAl5+T//HIjeS94ZNf+AAx3pO3ZqDfnS0krQbWkKV48HnFW6Vm99RVa2ROOpTW8HWd9K4FXY5eKZpompexvF4bMtyCpjQUEL4ErhuAEGpuK/xQvgqhnevW6S5+q/f3s1JijC839/t7ea5WGwZ7qrOxwRr2TB+XZZ0uRr+Rg7h0hSGsiCKeTNRcg7ekXBTG4inXSWPJbs2v2i+BBBiGmWDz0AW+q1rMNoH12k5BnRZQyA7Uc9NoDri" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="completed keyexchange" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="completed challenge" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=info msg="authenticated AP" username="21*********************bq" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=info msg="authenticated Login5" username="21*********************bq" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="initializing zeroconf session" username="21*********************bq" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="dealer connection opened" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=trace msg="starting accesspoint recv loop" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=trace msg="starting dealer recv loop" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=trace msg="received accesspoint ping" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=trace msg="received accesspoint pong ack" Jan 26 16:54:44 volumio go-librespot[22951]: time="2026-01-26T16:54:44+01:00" level=debug msg="received connection id: ZWU4MWU1ZjEtMDQ4...Q0JGQTBCMkMzMw==" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="handling transfer player command from 03f6c46af65af9251339ff2122eb2409f68635bb" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="resolved context of track" uri="spotify:user:21iwmbfpqm7cn53tbmsjqqwbq:collection" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=trace msg="fetched new page 0 with 1213 items (list: 1213)" uri="spotify:user:21iwmbfpqm7cn53tbmsjqqwbq:collection" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="shuffled context with seed 4145074397494895771 (len: 1213, keep: 1010)" uri="spotify:user:21iwmbfpqm7cn53tbmsjqqwbq:collection" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="loading track (paused: true, position: 47722ms)" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1452" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=trace msg="emitting websocket event: will_play" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="selected format OGG_VORBIS_320 (ade489f55fdd3b7c5b15754856efe27040db83e3)" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="requested aes key for file ade489f55fdd3b7c5b15754856efe27040db83e3, gid: 61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="fetched first chunk of 15, total size is 7616684 bytes" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio volumio[1364]: info: Initializing connection to go-librespot Websocket Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="new websocket client" Jan 26 16:54:45 volumio volumio[1364]: info: Connection to go-librespot Websocket established Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="fetched chunk 6/14, size: 524288" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="fetched chunk 5/14, size: 524288" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:45 volumio go-librespot[22951]: time="2026-01-26T16:54:45+01:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=trace msg="seek to 47722ms (diff: 81ms, samples: 2104540, bytes: 1877528)" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="created new output device" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=info msg="loaded track \"Lost In Paradise\" (paused: true, position: 47722ms, duration: 195366ms, prefetched: false)" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="fetched chunk 4/14, size: 524288" uri="spotify:track:61LDCF1gdHs1PMtRevdyU6" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=trace msg="emitting websocket event: metadata" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=trace msg="emitting websocket event: active" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="sending successful reply for dealer request" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:61LDCF1gdHs1PMtRevdyU6","name":"Lost In Paradise","artist_names":["Common Kings"],"album_name":"Lost In Paradise","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028faf4ffc1c8a2830c57ad77d","position":47722,"duration":195366,"release_date":"year:2017 month:2 day:3","track_number":1,"disc_number":1}} Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: received: {"type":"active","data":null} Jan 26 16:54:46 volumio volumio[1364]: info: Aligning Spotify Volume to Volumio Volume Jan 26 16:54:46 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:46 volumio volumio[1364]: info: CorePlayQueue::getTrack 0 Jan 26 16:54:46 volumio volumio[1364]: info: Setting Spotify Volume from Volumio: 100 Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 26 16:54:46 volumio go-librespot[22951]: time="2026-01-26T16:54:46+01:00" level=trace msg="emitting websocket event: paused" Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:user:21iwmbfpqm7cn53tbmsjqqwbq:collection","uri":"spotify:track:61LDCF1gdHs1PMtRevdyU6","play_origin":"collection/songs"}} Jan 26 16:54:46 volumio volumio[1364]: info: Spotify is playing in volatile mode Jan 26 16:54:46 volumio volumio[1364]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: UNSET VOLATILE Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":"100","dbVolume":null,"mute":false,"disableVolumeControl":false,"random":null,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: PUSH STATE SPOTIFY Jan 26 16:54:46 volumio volumio[1364]: SPOTIFY: {"status":"pause","service":"spop","title":"Lost In Paradise","artist":"Common Kings","album":"Lost In Paradise","albumart":"https://i.scdn.co/image/ab67616d00001e028faf4ffc1c8a2830c57ad77d","uri":"spotify:track:61LDCF1gdHs1PMtRevdyU6","trackType":"spotify","seek":47722,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 26 16:54:46 volumio volumio[1364]: info: CoreCommandRouter::servicePushState Jan 26 16:54:46 volumio volumio[1364]: info: CoreStateMachine::pushState Jan 26 16:54:46 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 16:54:46 volumio volumio[1364]: info: CoreCommandRouter::volumioPushState Jan 26 16:54:46 volumio volumio[1364]: info: MRS: Pushing multiroomSync output update for this device Jan 26 16:54:46 volumio volumio[1364]: info: MRS: Pushing multiroomSync output Jan 26 16:54:46 volumio volumio[1364]: info: CoreCommandRouter::volumioGetState Jan 26 16:54:46 volumio volumio[1364]: info: go-librespot daemon successfully initialized Jan 26 16:54:47 volumio volumio[1364]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jan 26 16:54:47 volumio volumio[1364]: info: Sending Spotify command with payload to local API: /player/volume Jan 26 16:54:47 volumio volumio[1364]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Jan 26 16:54:48 volumio volumio[1364]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 26 16:54:48 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 26 16:54:48 volumio volumio[1364]: info: Creating Spotify config file Jan 26 16:54:48 volumio volumio[1364]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 16:54:48 volumio volumio[1364]: info: Spotify config file written Jan 26 16:54:48 volumio sudo[22983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 16:54:48 volumio sudo[22983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 16:54:48 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 16:54:48 volumio systemd[1]: go-librespot-daemon.service: Killing process 22957 (go-librespot) with signal SIGKILL. Jan 26 16:54:48 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 16:54:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:48 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.494s CPU time. Jan 26 16:54:48 volumio volumio[1364]: info: Connection to go-librespot Websocket closed Jan 26 16:54:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 16:54:48 volumio sudo[22983]: pam_unix(sudo:session): session closed for user root Jan 26 16:54:48 volumio go-librespot[22985]: go-librespot daemon starting... Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=debug msg="app state loaded" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01: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-gae2.spotify.com:80]" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=info msg="zeroconf server listening on port 38967" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=debug msg="obtained new client token: AAAgrxrvFzHbFyRQkb3skNwSHjge5ggV+3ozoz9zKDPs3ZPWoOjBfqareJHepS1KUzuAQGU1aR142fEI3vewuNM4JzpWM2PdCcIpgE5TU2OnMUitLPQOAxZsoKP7J4tTXP8Gr/Dk6+obug33ndghQFU9hPhmTbpdfvkotI6ZP/bMK9A0OPS4RLcr8fc04zGfz69HL+6tktGb3ikIpkIlX+z+XFjNLJCNkpsq+04bBg5S1uI0AzGYOfpi" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 16:54:48 volumio go-librespot[22986]: time="2026-01-26T16:54:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 16:54:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 16:54:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 16:54:48 volumio volumio[1364]: info: Getting Spotify volume Jan 26 16:54:48 volumio volumio[1364]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 16:54:48 volumio volumio[1364]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 16:54:48 volumio volumio[1364]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 16:54:48 volumio volumio[1364]: errno: -111, Jan 26 16:54:48 volumio volumio[1364]: code: 'ECONNREFUSED', Jan 26 16:54:48 volumio volumio[1364]: syscall: 'connect', Jan 26 16:54:48 volumio volumio[1364]: address: '127.0.0.1', Jan 26 16:54:48 volumio volumio[1364]: port: 9879, Jan 26 16:54:48 volumio volumio[1364]: response: undefined Jan 26 16:54:48 volumio volumio[1364]: } Jan 26 16:54:48 volumio volumio[1364]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 16:54:49 volumio sudo[23006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 16:53' Jan 26 16:54:49 volumio sudo[23006]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"