Oct 26 15:52:01 volumio go-librespot[1994]: time="2025-10-26T15:52:01Z" level=debug msg="fetched chunk 20/22, size: 524288" uri="spotify:track:4XeAabTFPEEQEHiWj4ELMk" Oct 26 15:52:03 volumio go-librespot[1994]: time="2025-10-26T15:52:03Z" level=trace msg="sent dealer ping" Oct 26 15:52:03 volumio go-librespot[1994]: time="2025-10-26T15:52:03Z" level=trace msg="received dealer pong" Oct 26 15:52:09 volumio volumio[1379]: Searching plugin music_service/spop Oct 26 15:52:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 26 15:52:10 volumio volumio[1379]: info: All search sources collected, pushing search results Oct 26 15:52:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:52:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:52:13 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:52:13 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:52:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 4 Oct 26 15:52:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:52:14 volumio go-librespot[1994]: time="2025-10-26T15:52:14Z" level=debug msg="fetched chunk 21/22, size: 524288" uri="spotify:track:4XeAabTFPEEQEHiWj4ELMk" Oct 26 15:52:14 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 26 15:52:14 volumio volumio[1379]: info: In handleBrowseUri, curUri=spotify:artist:4Bd2FG9SrckBCVDvqqbyCz Oct 26 15:52:16 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:7jKKyLuAIh3msmHSe1YE3D Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:46gAu97W3J4aZ6nwJYTCoP Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:3fsP9d652GIbhBhETg6gdH Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:0i4seThjaX7Y9Mz45XBgGy Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:3hkuEpd8STFxo1ojW3iXXT Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:0vFOk9wwf2cfHXlkB0iTkW Oct 26 15:52:16 volumio volumio[1379]: info: Preloading song: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:16 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:16 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:16 volumio volumio[1379]: info: No valid Plugin REST Endpoint Oct 26 15:52:26 volumio go-librespot[1994]: time="2025-10-26T15:52:26Z" level=debug msg="fetched chunk 22/22, size: 364516" uri="spotify:track:4XeAabTFPEEQEHiWj4ELMk" Oct 26 15:52:33 volumio go-librespot[1994]: time="2025-10-26T15:52:33Z" level=trace msg="received accesspoint ping" Oct 26 15:52:33 volumio go-librespot[1994]: time="2025-10-26T15:52:33Z" level=trace msg="received accesspoint pong ack" Oct 26 15:52:33 volumio go-librespot[1994]: time="2025-10-26T15:52:33Z" level=trace msg="sent dealer ping" Oct 26 15:52:33 volumio go-librespot[1994]: time="2025-10-26T15:52:33Z" level=trace msg="received dealer pong" Oct 26 15:52:43 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:52:43 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:52:43 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:52:43 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:52:43 volumio volumio[1379]: info: CorePlayQueue::getTrack 4 Oct 26 15:52:43 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:52:44 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 26 15:52:44 volumio volumio[1379]: info: In handleBrowseUri, curUri=spotify:artist:03zlfknOWpwiArESMLlvdZ Oct 26 15:52:45 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:45 volumio volumio[1379]: info: Preloading song: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:45 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:45 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:46 volumio volumio[1379]: info: No valid Plugin REST Endpoint Oct 26 15:52:48 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:48 volumio volumio[1379]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::ClearQueue Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::stPlaybackTimer Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:48 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:48 volumio volumio[1379]: info: CorePlayQueue::getTrack 4 Oct 26 15:52:48 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:48 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::serviceStop Oct 26 15:52:48 volumio volumio[1379]: info: CorePlayQueue::getTrack 4 Oct 26 15:52:48 volumio volumio[1379]: info: CoreCommandRouter::serviceStop Oct 26 15:52:48 volumio volumio[1379]: info: Spotify Stop Oct 26 15:52:48 volumio volumio[1379]: SPOTIFY: SPOTIFY STOP Oct 26 15:52:48 volumio volumio[1379]: SPOTIFY: {"status":"play","position":4,"title":"Viata e ca o ruleta","artist":"Florin Cercel","album":"Viata e ca o ruleta","albumart":"https://i.scdn.co/image/ab67616d0000b273ec48397869a3908c43abd682","uri":"spotify:track:4XeAabTFPEEQEHiWj4ELMk","trackType":"spotify","codec":"ogg","seek":0,"duration":274,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 26 15:52:48 volumio volumio[1379]: info: Sending Spotify command to local API: /player/pause Oct 26 15:52:48 volumio volumio[1379]: info: CorePlayQueue::clearPlayQueue Oct 26 15:52:48 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:48 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:48 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:52:48 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:52:48 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:48 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:48 volumio volumio[1379]: info: Exploding uri spotify:track:3TLkNHur8ZVsBqWbpJoYFb in service spop Oct 26 15:52:48 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:48 volumio go-librespot[1994]: time="2025-10-26T15:52:48Z" level=debug msg="pause track at 252855ms" Oct 26 15:52:48 volumio go-librespot[1994]: time="2025-10-26T15:52:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","service":"spop","name":"NU-MI DA DOAMNE BANI CU SACUL","artist":"KARMA","album":"NU-MI DA DOAMNE BANI CU SACUL","type":"song","duration":241,"albumart":"https://i.scdn.co/image/ab67616d0000b273c8ba4c580342ca7f91a951f2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=trace msg="emitting websocket event: paused" Oct 26 15:52:49 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:49 volumio volumio[1379]: info: CoreCommandRouter::volumioPlay Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::play index 0 Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:52:49 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:1idrfGrjYVeXsaCdRhMN5O in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:35d0PCcEkaZ4O3sPuBwUBZ in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:0A1vmw0MEyAJLkviXGDgeK in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:3RhHeLYmHFFVbkccEwRJxy in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:0zjshX4HfVn3rL7jwNSEhP in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:0pjkyru6ZySo7nQIxpgGmK in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:49 volumio volumio[1379]: info: Adding Item to queue: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:49 volumio volumio[1379]: info: Exploding uri spotify:track:5PDR6njGkRbQ5OwJ02tJPt in service spop Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::play index undefined Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::startPlaybackTimer Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:49 volumio volumio[1379]: info: [1761493969052] ControllerSpotify::clearAddPlayTrack Oct 26 15:52:49 volumio volumio[1379]: info: Sending Spotify command with payload to local API: /player/play Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:4XeAabTFPEEQEHiWj4ELMk","uri":"spotify:track:4XeAabTFPEEQEHiWj4ELMk","play_origin":"go-librespot"}} Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:49 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:49 volumio volumio[1379]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:49 volumio volumio[1379]: verbose: CURRENT POSITION 0 Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::syncState stateService pause Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:49 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:49 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=debug msg="resolved context of track" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=trace msg="emitting websocket event: will_play" Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","play_origin":"go-librespot"}} Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","service":"spop","name":"Nici un doctor nu repara inima invidioasa","artist":"KARMA","album":"Nici un doctor nu repara inima invidioasa","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b2737b6b8e658dc212fc83fe10a5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=debug msg="selected format OGG_VORBIS_320 (37967fd39af30906e0e3edde5ece7fd74639edc5)" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=debug msg="requested aes key for file 37967fd39af30906e0e3edde5ece7fd74639edc5, gid: 3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","service":"spop","name":"DOAR EU SI CU MINE","artist":"KARMA","album":"DOAR EU SI CU MINE","type":"song","duration":290,"albumart":"https://i.scdn.co/image/ab67616d0000b273deb1432c94975005dbebe733","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ","service":"spop","name":"Hai Noroc Mai Nasule","artist":"George Nicoloiu","album":"Nasu' Si Nasu'","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2738f58ca2067091ca4dc869dc4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","service":"spop","name":"Ce bine le dai","artist":"Marius De La Focsani","album":"Un prieten si un dusman","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b2730c603b5a066559131a514042","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw","service":"spop","name":"Eu sunt băiatu lu tata","artist":"Marius De La Focsani","album":"Am o mândră tânără","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b273771feee24365eedfab44d8ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0pjkyru6ZySo7nQIxpgGmK","service":"spop","name":"Tot la omul necajit","artist":"KARMA","album":"Tot la omul necajit","type":"song","duration":410,"albumart":"https://i.scdn.co/image/ab67616d0000b27322d54d8d3e095d0884ee26e5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0A1vmw0MEyAJLkviXGDgeK","service":"spop","name":"DACA AS PUTEA VEDEA","artist":"KARMA","album":"DACA AS PUTEA VEDEA","type":"song","duration":329,"albumart":"https://i.scdn.co/image/ab67616d0000b27381964777c96ca07639699cad","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0zjshX4HfVn3rL7jwNSEhP","service":"spop","name":"COD DE BARE","artist":"KARMA","album":"COD DE BARE","type":"song","duration":285,"albumart":"https://i.scdn.co/image/ab67616d0000b273ffec83e32198aeef6c07401c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio go-librespot[1994]: time="2025-10-26T15:52:49Z" level=trace msg="found 2 cdn urls" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:49 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5PDR6njGkRbQ5OwJ02tJPt","service":"spop","name":"Iartă-mă","artist":"Marius De La Focsani","album":"A opta minune a lumii","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b273c1ceac7c21a88d527ef0f758","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:52:49 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:49 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:49 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="fetched first chunk of 20, total size is 10130784 bytes" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 46439 us, period size = 2048 frames, buffer time = 185759 us, buffer size = 8192 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=info msg="loaded track \"NU-MI DA DOAMNE BANI CU SACUL\" (paused: false, position: 0ms, duration: 241917ms, prefetched: false)" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=trace msg="scheduling prefetch in 212s" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=trace msg="emitting websocket event: metadata" Oct 26 15:52:50 volumio volumio[1379]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","name":"NU-MI DA DOAMNE BANI CU SACUL","artist_names":["KARMA","Marius De La Focsani"],"album_name":"NU-MI DA DOAMNE BANI CU SACUL","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c8ba4c580342ca7f91a951f2","position":0,"duration":241917,"release_date":"year:2025 month:8 day:9","track_number":1,"disc_number":1}} Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=trace msg="emitting websocket event: playing" Oct 26 15:52:50 volumio volumio[1379]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","resume":false,"play_origin":"go-librespot"}} Oct 26 15:52:50 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:50 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"NU-MI DA DOAMNE BANI CU SACUL","artist":"KARMA, Marius De La Focsani","album":"NU-MI DA DOAMNE BANI CU SACUL","albumart":"https://i.scdn.co/image/ab67616d00001e02c8ba4c580342ca7f91a951f2","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:50 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:50 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:50 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"NU-MI DA DOAMNE BANI CU SACUL","artist":"KARMA, Marius De La Focsani","album":"NU-MI DA DOAMNE BANI CU SACUL","albumart":"https://i.scdn.co/image/ab67616d00001e02c8ba4c580342ca7f91a951f2","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:50 volumio volumio[1379]: verbose: CURRENT POSITION 0 Oct 26 15:52:50 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:52:50 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:50 volumio go-librespot[1994]: time="2025-10-26T15:52:50Z" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:3TLkNHur8ZVsBqWbpJoYFb" Oct 26 15:52:50 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:50 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"NU-MI DA DOAMNE BANI CU SACUL","artist":"KARMA, Marius De La Focsani","album":"NU-MI DA DOAMNE BANI CU SACUL","albumart":"https://i.scdn.co/image/ab67616d00001e02c8ba4c580342ca7f91a951f2","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:50 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:50 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:50 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"NU-MI DA DOAMNE BANI CU SACUL","artist":"KARMA, Marius De La Focsani","album":"NU-MI DA DOAMNE BANI CU SACUL","albumart":"https://i.scdn.co/image/ab67616d00001e02c8ba4c580342ca7f91a951f2","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:50 volumio volumio[1379]: verbose: CURRENT POSITION 0 Oct 26 15:52:50 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:52:50 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus play Oct 26 15:52:50 volumio volumio[1379]: info: Received an update from plugin. extracting info from payload Oct 26 15:52:50 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:50 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:50 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:50 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:50 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:50 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:50 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:55 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::ClearQueue Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::stPlaybackTimer Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::serviceStop Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::serviceStop Oct 26 15:52:55 volumio volumio[1379]: info: Spotify Stop Oct 26 15:52:55 volumio volumio[1379]: SPOTIFY: SPOTIFY STOP Oct 26 15:52:55 volumio volumio[1379]: SPOTIFY: {"status":"play","position":0,"title":"NU-MI DA DOAMNE BANI CU SACUL","artist":"KARMA","album":"NU-MI DA DOAMNE BANI CU SACUL","albumart":"https://i.scdn.co/image/ab67616d0000b273c8ba4c580342ca7f91a951f2","uri":"spotify:track:3TLkNHur8ZVsBqWbpJoYFb","trackType":"spotify","codec":"ogg","seek":0,"duration":241,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 26 15:52:55 volumio volumio[1379]: info: Sending Spotify command to local API: /player/pause Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::clearPlayQueue Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:52:55 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::volumioPlay Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::play index 1 Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:52:55 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:55 volumio volumio[1379]: info: Adding Item to queue: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:55 volumio volumio[1379]: info: Using cached record of: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:55 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::play index undefined Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:55 volumio volumio[1379]: info: CoreStateMachine::startPlaybackTimer Oct 26 15:52:55 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:55 volumio volumio[1379]: info: [1761493975408] ControllerSpotify::clearAddPlayTrack Oct 26 15:52:55 volumio volumio[1379]: info: Sending Spotify command with payload to local API: /player/play Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="pause track at 5133ms" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="resolved context of track" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=trace msg="emitting websocket event: will_play" Oct 26 15:52:55 volumio volumio[1379]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","play_origin":"go-librespot"}} Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="selected format OGG_VORBIS_320 (9234bf3b06cd3744434547b2b4e69f3541f175a0)" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="requested aes key for file 9234bf3b06cd3744434547b2b4e69f3541f175a0, gid: 1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=trace msg="found 2 cdn urls" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="fetched first chunk of 22, total size is 11489500 bytes" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 46439 us, period size = 2048 frames, buffer time = 185759 us, buffer size = 8192 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 26 15:52:55 volumio go-librespot[1994]: time="2025-10-26T15:52:55Z" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=info msg="loaded track \"DOAR EU SI CU MINE\" (paused: false, position: 1ms, duration: 290052ms, prefetched: false)" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=trace msg="scheduling prefetch in 260s" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=trace msg="emitting websocket event: metadata" Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","name":"DOAR EU SI CU MINE","artist_names":["KARMA","Marius De La Focsani"],"album_name":"DOAR EU SI CU MINE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","position":1,"duration":290052,"release_date":"year:2025 month:6 day:23","track_number":1,"disc_number":1}} Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=trace msg="emitting websocket event: paused" Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","play_origin":"go-librespot"}} Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: {"status":"pause","service":"spop","title":"DOAR EU SI CU MINE","artist":"KARMA, Marius De La Focsani","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","seek":1,"duration":290,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:56 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:56 volumio volumio[1379]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"DOAR EU SI CU MINE","artist":"KARMA, Marius De La Focsani","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","seek":1,"duration":290,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:56 volumio volumio[1379]: verbose: CURRENT POSITION 1 Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::syncState stateService pause Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:56 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=trace msg="emitting websocket event: playing" Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","resume":false,"play_origin":"go-librespot"}} Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"DOAR EU SI CU MINE","artist":"KARMA, Marius De La Focsani","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","seek":1,"duration":290,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:56 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:56 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DOAR EU SI CU MINE","artist":"KARMA, Marius De La Focsani","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","seek":1,"duration":290,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:56 volumio volumio[1379]: verbose: CURRENT POSITION 1 Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:52:56 volumio go-librespot[1994]: time="2025-10-26T15:52:56Z" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:1idrfGrjYVeXsaCdRhMN5O" Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:56 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"DOAR EU SI CU MINE","artist":"KARMA, Marius De La Focsani","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","seek":1,"duration":290,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:56 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:56 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DOAR EU SI CU MINE","artist":"KARMA, Marius De La Focsani","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d00001e02deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","seek":1,"duration":290,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:56 volumio volumio[1379]: verbose: CURRENT POSITION 1 Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus play Oct 26 15:52:56 volumio volumio[1379]: info: Received an update from plugin. extracting info from payload Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:56 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:56 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:56 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:56 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:58 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::ClearQueue Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::stPlaybackTimer Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::serviceStop Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrack 1 Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::serviceStop Oct 26 15:52:58 volumio volumio[1379]: info: Spotify Stop Oct 26 15:52:58 volumio volumio[1379]: SPOTIFY: SPOTIFY STOP Oct 26 15:52:58 volumio volumio[1379]: SPOTIFY: {"status":"play","position":1,"title":"DOAR EU SI CU MINE","artist":"KARMA","album":"DOAR EU SI CU MINE","albumart":"https://i.scdn.co/image/ab67616d0000b273deb1432c94975005dbebe733","uri":"spotify:track:1idrfGrjYVeXsaCdRhMN5O","trackType":"spotify","codec":"ogg","seek":1,"duration":290,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 26 15:52:58 volumio volumio[1379]: info: Sending Spotify command to local API: /player/pause Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::clearPlayQueue Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:52:58 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::volumioPlay Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::play index 3 Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:52:58 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:52:58 volumio volumio[1379]: info: Adding Item to queue: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:58 volumio volumio[1379]: info: Using cached record of: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:58 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::play index undefined Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:52:58 volumio volumio[1379]: info: CoreStateMachine::startPlaybackTimer Oct 26 15:52:58 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:52:58 volumio volumio[1379]: info: [1761493978038] ControllerSpotify::clearAddPlayTrack Oct 26 15:52:58 volumio volumio[1379]: info: Sending Spotify command with payload to local API: /player/play Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="pause track at 2127ms" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="resolved context of track" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=trace msg="emitting websocket event: will_play" Oct 26 15:52:58 volumio volumio[1379]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","play_origin":"go-librespot"}} Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="selected format OGG_VORBIS_320 (a9ae8d1d9cc6e92319d7967ece3ba68f9a1782d9)" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=debug msg="requested aes key for file a9ae8d1d9cc6e92319d7967ece3ba68f9a1782d9, gid: 35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:58 volumio go-librespot[1994]: time="2025-10-26T15:52:58Z" level=trace msg="found 2 cdn urls" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="fetched first chunk of 13, total size is 6592869 bytes" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 46439 us, period size = 2048 frames, buffer time = 185759 us, buffer size = 8192 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=info msg="loaded track \"Ce bine le dai\" (paused: false, position: 0ms, duration: 232838ms, prefetched: false)" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=trace msg="scheduling prefetch in 203s" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=trace msg="emitting websocket event: metadata" Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","name":"Ce bine le dai","artist_names":["Marius De La Focsani","Denisa"],"album_name":"Un prieten si un dusman","album_cover_url":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","position":0,"duration":232838,"release_date":"year:2006 month:11 day:18","track_number":30,"disc_number":1}} Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=trace msg="emitting websocket event: paused" Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","play_origin":"go-librespot"}} Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: {"status":"pause","service":"spop","title":"Ce bine le dai","artist":"Marius De La Focsani, Denisa","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:59 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:59 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:52:59 volumio volumio[1379]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Ce bine le dai","artist":"Marius De La Focsani, Denisa","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:59 volumio volumio[1379]: verbose: CURRENT POSITION 3 Oct 26 15:52:59 volumio volumio[1379]: info: CoreStateMachine::syncState stateService pause Oct 26 15:52:59 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:52:59 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:52:59 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:52:59 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:52:59 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:35d0PCcEkaZ4O3sPuBwUBZ" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:52:59 volumio go-librespot[1994]: time="2025-10-26T15:52:59Z" level=trace msg="emitting websocket event: playing" Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","resume":false,"play_origin":"go-librespot"}} Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:52:59 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"Ce bine le dai","artist":"Marius De La Focsani, Denisa","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:59 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:52:59 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:52:59 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Ce bine le dai","artist":"Marius De La Focsani, Denisa","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:52:59 volumio volumio[1379]: verbose: CURRENT POSITION 3 Oct 26 15:52:59 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:52:59 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:53:00 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:00 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"Ce bine le dai","artist":"Marius De La Focsani, Denisa","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:00 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:00 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:53:00 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Ce bine le dai","artist":"Marius De La Focsani, Denisa","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d00001e020c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:00 volumio volumio[1379]: verbose: CURRENT POSITION 3 Oct 26 15:53:00 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:53:00 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus play Oct 26 15:53:00 volumio volumio[1379]: info: Received an update from plugin. extracting info from payload Oct 26 15:53:00 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:00 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:53:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:00 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:00 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:00 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:53:00 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:03 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::ClearQueue Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::stPlaybackTimer Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::serviceStop Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrack 3 Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::serviceStop Oct 26 15:53:03 volumio volumio[1379]: info: Spotify Stop Oct 26 15:53:03 volumio volumio[1379]: SPOTIFY: SPOTIFY STOP Oct 26 15:53:03 volumio volumio[1379]: SPOTIFY: {"status":"play","position":3,"title":"Ce bine le dai","artist":"Marius De La Focsani","album":"Un prieten si un dusman","albumart":"https://i.scdn.co/image/ab67616d0000b2730c603b5a066559131a514042","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","trackType":"spotify","codec":"ogg","seek":0,"duration":232,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 26 15:53:03 volumio volumio[1379]: info: Sending Spotify command to local API: /player/pause Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::clearPlayQueue Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:53:03 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:3TLkNHur8ZVsBqWbpJoYFb Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:1idrfGrjYVeXsaCdRhMN5O Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:2fADfJ1Mi0sDuwiGvHGBhJ Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:35d0PCcEkaZ4O3sPuBwUBZ Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:0A1vmw0MEyAJLkviXGDgeK Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:3RhHeLYmHFFVbkccEwRJxy Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::volumioPlay Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::play index 5 Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:53:03 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:1FDNgpEVj3DU8TEmVCZ2Bw Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:0zjshX4HfVn3rL7jwNSEhP Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:0pjkyru6ZySo7nQIxpgGmK Oct 26 15:53:03 volumio volumio[1379]: info: Adding Item to queue: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:53:03 volumio volumio[1379]: info: Using cached record of: spotify:track:5PDR6njGkRbQ5OwJ02tJPt Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:03 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::play index undefined Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:03 volumio volumio[1379]: info: CoreStateMachine::startPlaybackTimer Oct 26 15:53:03 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:03 volumio volumio[1379]: info: [1761493983904] ControllerSpotify::clearAddPlayTrack Oct 26 15:53:03 volumio volumio[1379]: info: Sending Spotify command with payload to local API: /player/play Oct 26 15:53:03 volumio go-librespot[1994]: time="2025-10-26T15:53:03Z" level=debug msg="pause track at 4303ms" Oct 26 15:53:03 volumio go-librespot[1994]: time="2025-10-26T15:53:03Z" level=trace msg="sent dealer ping" Oct 26 15:53:03 volumio go-librespot[1994]: time="2025-10-26T15:53:03Z" level=trace msg="received dealer pong" Oct 26 15:53:03 volumio go-librespot[1994]: time="2025-10-26T15:53:03Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=trace msg="emitting websocket event: paused" Oct 26 15:53:04 volumio volumio[1379]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","uri":"spotify:track:35d0PCcEkaZ4O3sPuBwUBZ","play_origin":"go-librespot"}} Oct 26 15:53:04 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:04 volumio volumio[1379]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:04 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:04 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:04 volumio volumio[1379]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:04 volumio volumio[1379]: verbose: CURRENT POSITION 5 Oct 26 15:53:04 volumio volumio[1379]: info: CoreStateMachine::syncState stateService pause Oct 26 15:53:04 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:53:04 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:04 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:04 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:04 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=debug msg="resolved context of track" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=trace msg="emitting websocket event: will_play" Oct 26 15:53:04 volumio volumio[1379]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","play_origin":"go-librespot"}} Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=debug msg="selected format OGG_VORBIS_320 (68fd81d7721379cf21e2c5559400354e3f2ab4b7)" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=debug msg="requested aes key for file 68fd81d7721379cf21e2c5559400354e3f2ab4b7, gid: 3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:04 volumio go-librespot[1994]: time="2025-10-26T15:53:04Z" level=trace msg="found 2 cdn urls" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=debug msg="fetched first chunk of 18, total size is 9253154 bytes" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 46439 us, period size = 2048 frames, buffer time = 185759 us, buffer size = 8192 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=info msg="loaded track \"Nici un doctor nu repara inima invidioasa\" (paused: false, position: 0ms, duration: 232527ms, prefetched: false)" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=trace msg="scheduling prefetch in 202s" Oct 26 15:53:05 volumio go-librespot[1994]: time="2025-10-26T15:53:05Z" level=trace msg="emitting websocket event: metadata" Oct 26 15:53:05 volumio volumio[1379]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","name":"Nici un doctor nu repara inima invidioasa","artist_names":["KARMA","Marius De La Focsani"],"album_name":"Nici un doctor nu repara inima invidioasa","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","position":0,"duration":232527,"release_date":"year:2025 month:7 day:24","track_number":1,"disc_number":1}} Oct 26 15:53:06 volumio go-librespot[1994]: time="2025-10-26T15:53:06Z" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:06 volumio go-librespot[1994]: time="2025-10-26T15:53:06Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:06 volumio go-librespot[1994]: time="2025-10-26T15:53:06Z" level=trace msg="emitting websocket event: playing" Oct 26 15:53:06 volumio volumio[1379]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","resume":false,"play_origin":"go-librespot"}} Oct 26 15:53:06 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:06 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA, Marius De La Focsani","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:06 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:06 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:06 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA, Marius De La Focsani","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:06 volumio volumio[1379]: verbose: CURRENT POSITION 5 Oct 26 15:53:06 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:53:06 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:53:06 volumio go-librespot[1994]: time="2025-10-26T15:53:06Z" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:3RhHeLYmHFFVbkccEwRJxy" Oct 26 15:53:06 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:06 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA, Marius De La Focsani","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:06 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:06 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:06 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA, Marius De La Focsani","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","seek":0,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:06 volumio volumio[1379]: verbose: CURRENT POSITION 5 Oct 26 15:53:06 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:53:06 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus play Oct 26 15:53:06 volumio volumio[1379]: info: Received an update from plugin. extracting info from payload Oct 26 15:53:06 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:06 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:06 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:06 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:06 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:06 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:06 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:11 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 26 15:53:11 volumio volumio[1379]: info: In handleBrowseUri, curUri=spotify:album:1R7Wn0Fj8QIpkP3c18Fa1n Oct 26 15:53:12 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:53:12 volumio volumio[1379]: info: Preloading song: spotify:track:6ij1in7ibsXJ78pK5byyd9 Oct 26 15:53:12 volumio volumio[1379]: info: Exploding uri spotify:track:6ij1in7ibsXJ78pK5byyd9 in service spop Oct 26 15:53:12 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:track:6ij1in7ibsXJ78pK5byyd9 Oct 26 15:53:12 volumio volumio[1379]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","service":"spop","name":"HOPA CINE MA SUNA","artist":"Marius De La Focsani","album":"HOPA CINE MA SUNA","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b2737d9eb46c17d3340ba537a78d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 26 15:53:12 volumio volumio[1379]: info: No valid Plugin REST Endpoint Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:53:13 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:53:13 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::ClearQueue Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::stPlaybackTimer Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::serviceStop Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::serviceStop Oct 26 15:53:13 volumio volumio[1379]: info: Spotify Stop Oct 26 15:53:13 volumio volumio[1379]: SPOTIFY: SPOTIFY STOP Oct 26 15:53:13 volumio volumio[1379]: SPOTIFY: {"status":"play","position":5,"title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d0000b2737b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","codec":"ogg","seek":0,"duration":232,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 26 15:53:13 volumio volumio[1379]: info: Sending Spotify command to local API: /player/pause Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::clearPlayQueue Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::addQueueItems Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::addQueueItems Oct 26 15:53:13 volumio volumio[1379]: info: Preload queue cleared Oct 26 15:53:13 volumio volumio[1379]: info: Adding Item to queue: spotify:album:1R7Wn0Fj8QIpkP3c18Fa1n Oct 26 15:53:13 volumio volumio[1379]: info: Exploding uri spotify:album:1R7Wn0Fj8QIpkP3c18Fa1n in service spop Oct 26 15:53:13 volumio volumio[1379]: SPOTIFY: EXPLODING URI:spotify:album:1R7Wn0Fj8QIpkP3c18Fa1n Oct 26 15:53:13 volumio go-librespot[1994]: time="2025-10-26T15:53:13Z" level=debug msg="pause track at 8064ms" Oct 26 15:53:13 volumio go-librespot[1994]: time="2025-10-26T15:53:13Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:13 volumio go-librespot[1994]: time="2025-10-26T15:53:13Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:13 volumio go-librespot[1994]: time="2025-10-26T15:53:13Z" level=trace msg="emitting websocket event: paused" Oct 26 15:53:13 volumio volumio[1379]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","play_origin":"go-librespot"}} Oct 26 15:53:13 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:13 volumio volumio[1379]: SPOTIFY: {"status":"pause","service":"spop","title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA, Marius De La Focsani","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","seek":7000,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:13 volumio volumio[1379]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Nici un doctor nu repara inima invidioasa","artist":"KARMA, Marius De La Focsani","album":"Nici un doctor nu repara inima invidioasa","albumart":"https://i.scdn.co/image/ab67616d00001e027b6b8e658dc212fc83fe10a5","uri":"spotify:track:3RhHeLYmHFFVbkccEwRJxy","trackType":"spotify","seek":7000,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:13 volumio volumio[1379]: verbose: CURRENT POSITION 5 Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::syncState stateService pause Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 5 Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPushQueue Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::saveQueue Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Oct 26 15:53:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPlay Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::play index 0 Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::stop Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::play index undefined Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:13 volumio volumio[1379]: info: CoreStateMachine::startPlaybackTimer Oct 26 15:53:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:13 volumio volumio[1379]: info: [1761493993990] ControllerSpotify::clearAddPlayTrack Oct 26 15:53:13 volumio volumio[1379]: info: Sending Spotify command with payload to local API: /player/play Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=debug msg="resolved context of track" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=debug msg="loading track (paused: false, position: 2ms)" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=trace msg="emitting websocket event: will_play" Oct 26 15:53:14 volumio volumio[1379]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","play_origin":"go-librespot"}} Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=debug msg="selected format OGG_VORBIS_320 (ca60af021e03f38f9e7ab4db9c28524fc86d021e)" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=debug msg="requested aes key for file ca60af021e03f38f9e7ab4db9c28524fc86d021e, gid: 6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:14 volumio go-librespot[1994]: time="2025-10-26T15:53:14Z" level=trace msg="found 2 cdn urls" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=debug msg="fetched first chunk of 22, total size is 11428441 bytes" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=trace msg="seek to 2ms (diff: 2ms, samples: 88, bytes: 0)" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 46439 us, period size = 2048 frames, buffer time = 185759 us, buffer size = 8192 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=info msg="loaded track \"HOPA CINE MA SUNA\" (paused: false, position: 2ms, duration: 279600ms, prefetched: false)" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=trace msg="scheduling prefetch in 249s" Oct 26 15:53:15 volumio go-librespot[1994]: time="2025-10-26T15:53:15Z" level=trace msg="emitting websocket event: metadata" Oct 26 15:53:15 volumio volumio[1379]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","name":"HOPA CINE MA SUNA","artist_names":["Marius De La Focsani"],"album_name":"HOPA CINE MA SUNA","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027d9eb46c17d3340ba537a78d","position":2,"duration":279600,"release_date":"year:2025 month:9 day:25","track_number":1,"disc_number":1}} Oct 26 15:53:16 volumio go-librespot[1994]: time="2025-10-26T15:53:16Z" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:16 volumio go-librespot[1994]: time="2025-10-26T15:53:16Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 15:53:16 volumio go-librespot[1994]: time="2025-10-26T15:53:16Z" level=trace msg="emitting websocket event: playing" Oct 26 15:53:16 volumio volumio[1379]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","resume":false,"play_origin":"go-librespot"}} Oct 26 15:53:16 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:16 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"HOPA CINE MA SUNA","artist":"Marius De La Focsani","album":"HOPA CINE MA SUNA","albumart":"https://i.scdn.co/image/ab67616d00001e027d9eb46c17d3340ba537a78d","uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","trackType":"spotify","seek":2,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:16 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:16 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:16 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"HOPA CINE MA SUNA","artist":"Marius De La Focsani","album":"HOPA CINE MA SUNA","albumart":"https://i.scdn.co/image/ab67616d00001e027d9eb46c17d3340ba537a78d","uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","trackType":"spotify","seek":2,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:16 volumio volumio[1379]: verbose: CURRENT POSITION 0 Oct 26 15:53:16 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:53:16 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus stop Oct 26 15:53:16 volumio go-librespot[1994]: time="2025-10-26T15:53:16Z" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:16 volumio volumio[1379]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 15:53:16 volumio volumio[1379]: SPOTIFY: {"status":"play","service":"spop","title":"HOPA CINE MA SUNA","artist":"Marius De La Focsani","album":"HOPA CINE MA SUNA","albumart":"https://i.scdn.co/image/ab67616d00001e027d9eb46c17d3340ba537a78d","uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","trackType":"spotify","seek":2,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:16 volumio volumio[1379]: info: CoreCommandRouter::servicePushState Oct 26 15:53:16 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:16 volumio volumio[1379]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"HOPA CINE MA SUNA","artist":"Marius De La Focsani","album":"HOPA CINE MA SUNA","albumart":"https://i.scdn.co/image/ab67616d00001e027d9eb46c17d3340ba537a78d","uri":"spotify:track:6ij1in7ibsXJ78pK5byyd9","trackType":"spotify","seek":2,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 26 15:53:16 volumio volumio[1379]: verbose: CURRENT POSITION 0 Oct 26 15:53:16 volumio volumio[1379]: info: CoreStateMachine::syncState stateService play Oct 26 15:53:16 volumio volumio[1379]: info: CoreStateMachine::syncState currentStatus play Oct 26 15:53:16 volumio volumio[1379]: info: Received an update from plugin. extracting info from payload Oct 26 15:53:16 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:16 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:16 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 15:53:16 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:16 volumio volumio[1379]: info: CoreStateMachine::pushState Oct 26 15:53:16 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:16 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Oct 26 15:53:19 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:19 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:19 volumio sudo[95137]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 26 15:53:19 volumio sudo[95137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 26 15:53:19 volumio sudo[95139]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 26 15:53:19 volumio sudo[95139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 26 15:53:19 volumio sudo[95137]: pam_unix(sudo:session): session closed for user root Oct 26 15:53:19 volumio sudo[95139]: pam_unix(sudo:session): session closed for user root Oct 26 15:53:20 volumio volumio[1379]: verbose: New Socket.io Connection to 192.168.100.244 from 192.168.100.24 UA: Mozilla/5.0 (Linux; Android 15; CPH2663 Build/UKQ1.231108.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/141.0.7390.97 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Oct 26 15:53:20 volumio sudo[95143]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 26 15:53:20 volumio sudo[95143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 26 15:53:20 volumio sudo[95143]: pam_unix(sudo:session): session closed for user root Oct 26 15:53:20 volumio sudo[95145]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 26 15:53:20 volumio sudo[95145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 26 15:53:20 volumio sudo[95145]: pam_unix(sudo:session): session closed for user root Oct 26 15:53:20 volumio volumio[1379]: verbose: New Socket.io Connection to 192.168.100.244 from 192.168.100.24 UA: Mozilla/5.0 (Linux; Android 15; CPH2663 Build/UKQ1.231108.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/141.0.7390.97 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::volumioGetVisibleSources Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:20 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::volumioGetQueue Oct 26 15:53:20 volumio volumio[1379]: info: CoreStateMachine::getQueue Oct 26 15:53:20 volumio volumio[1379]: info: CorePlayQueue::getQueue Oct 26 15:53:20 volumio volumio[1379]: info: Listing playlists Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 26 15:53:20 volumio volumio[1379]: info: Received Get System Info Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:53:20 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:20 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:20 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 26 15:53:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 26 15:53:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 26 15:53:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 26 15:53:22 volumio volumio[1379]: info: Received Get System Info Oct 26 15:53:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:53:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:53:22 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:53:22 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:22 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:53:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 26 15:53:23 volumio volumio[1379]: info: Received Get System Info Oct 26 15:53:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:53:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:53:23 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:53:23 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:23 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:53:26 volumio volumio[1379]: Searching plugin music_service/spop Oct 26 15:53:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 26 15:53:26 volumio volumio[1379]: info: All search sources collected, pushing search results Oct 26 15:53:27 volumio volumio[1379]: Searching plugin music_service/spop Oct 26 15:53:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 26 15:53:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 26 15:53:27 volumio volumio[1379]: info: Received Get System Info Oct 26 15:53:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 15:53:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 15:53:27 volumio volumio[1379]: info: Discovery: Getting this device information Oct 26 15:53:27 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Oct 26 15:53:27 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Oct 26 15:53:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 15:53:28 volumio volumio[1379]: info: All search sources collected, pushing search results Oct 26 15:53:28 volumio go-librespot[1994]: time="2025-10-26T15:53:28Z" level=debug msg="fetched chunk 4/21, size: 524288" uri="spotify:track:6ij1in7ibsXJ78pK5byyd9" Oct 26 15:53:29 volumio volumio[1379]: Searching plugin music_service/spop Oct 26 15:53:29 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 26 15:53:29 volumio volumio[1379]: info: All search sources collected, pushing search results Oct 26 15:53:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 26 15:53:31 volumio volumio[1379]: Searching plugin music_service/spop Oct 26 15:53:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 26 15:53:32 volumio volumio[1379]: info: All search sources collected, pushing search results Oct 26 15:53:33 volumio go-librespot[1994]: time="2025-10-26T15:53:33Z" level=trace msg="sent dealer ping" Oct 26 15:53:33 volumio go-librespot[1994]: time="2025-10-26T15:53:33Z" level=trace msg="received dealer pong" Oct 26 15:53:36 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 26 15:53:36 volumio volumio[1379]: info: In handleBrowseUri, curUri=spotify:artist:1RNezj0YMlyMErtT86iWwg Oct 26 15:53:37 volumio volumio[1379]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 15:53:37 volumio volumio[1379]: TypeError: Cannot read properties of undefined (reading 'url') Oct 26 15:53:37 volumio volumio[1379]: at /data/plugins/music_service/spop/index.js:2449:60 Oct 26 15:53:37 volumio volumio[1379]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Oct 26 15:53:37 volumio volumio[1379]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 15:53:37 volumio sudo[95206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-26 15:52' Oct 26 15:53:37 volumio sudo[95206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5ef3d56f987d109f3e21bfa246dbbb723cf6a917" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="7840f283c310c38bfe939a4c485727a6ff6a0ce1" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Oct 9 18:33:08 UTC 2025" VOLUMIO_VERSION="4.062" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="434a4f7d2e5f6acafabfcca26b8e5834"