Dec 17 18:03:05 volumio go-librespot[6609]: time="2025-12-17T18:03:05+02:00" level=trace msg="sent dealer ping" Dec 17 18:03:05 volumio go-librespot[6609]: time="2025-12-17T18:03:05+02:00" level=trace msg="received dealer pong" Dec 17 18:03:16 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 17 18:03:16 volumio volumio[6287]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:6g3T2EFknUdvtQCgji767k Dec 17 18:03:17 volumio volumio[6287]: info: Preload queue cleared Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:1AU8s5RMGA6mzHsFn06Iaa Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:52X67Yzy5Bn0JKwzRWDEAs Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:0a9mUPCyu1R2kxRqDoO9Q3 Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:5ykXsKJqx0GE0dsogxjylG Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:2ZBvf57sMPjEhIOLQqQx9Z Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:3weNRklVDqb4Rr5MhKBR3D Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:7wGx08b8HOKxnppqcoq4ea Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:7ilWEHob3AYG3lAJlKEpDR Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:2clBSTWalrt4Hi61E5Di9e Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:3cYHFvUYDVY9loQQ0LalJc Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:6tJpiGyRnjIXaoUm2Sb4i7 Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:1EkpzEzd3JUvSm4UMC9YLK Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:5UwohijVkmiUQf049Onfqy Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:1AU8s5RMGA6mzHsFn06Iaa Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:0Evb6PwsuROuKZPYCpFy7x Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:6D3rGir5Owv547fttKWhOH Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:1s4hDcjbLUddDakw5bY0M2 Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:0KnSKxjFG3av8TkJyFFOmd Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:5SXcK7CYayh56VgR0Q5E0u Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:06rt8Zkk3M1L5lRRNYxQRU Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:2kLw0p31p5efs0I2X6qjTJ Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:557FSHMvfvWtieHruwjnCL Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:5iqqeUrXyjNT0gbCYkYKR4 Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:5voIoFpbuy0frbhBzqenqC Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:4vavlNjDSlQTxpdPXC9n7D Dec 17 18:03:17 volumio volumio[6287]: info: Preloading song: spotify:track:77PEklpJ5g4lzsUrYMjDqn Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:1AU8s5RMGA6mzHsFn06Iaa in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:1AU8s5RMGA6mzHsFn06Iaa Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:52X67Yzy5Bn0JKwzRWDEAs in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:52X67Yzy5Bn0JKwzRWDEAs Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:0a9mUPCyu1R2kxRqDoO9Q3 in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:0a9mUPCyu1R2kxRqDoO9Q3 Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:5ykXsKJqx0GE0dsogxjylG in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:5ykXsKJqx0GE0dsogxjylG Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:2ZBvf57sMPjEhIOLQqQx9Z in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:2ZBvf57sMPjEhIOLQqQx9Z Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","service":"spop","name":"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846","artist":"Daniel Barenboim","album":"Bach, JS : Well-Tempered Clavier Books 1 & 2","type":"song","duration":100,"albumart":"https://i.scdn.co/image/ab67616d0000b27333173321aabf16f0bf6f0d31","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:3weNRklVDqb4Rr5MhKBR3D in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:3weNRklVDqb4Rr5MhKBR3D Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:52X67Yzy5Bn0JKwzRWDEAs","service":"spop","name":"My One and Only Love","artist":"Yo-Yo Ma","album":"Songs of Joy & Peace","type":"song","duration":247,"albumart":"https://i.scdn.co/image/ab67616d0000b27379ec2e43bb9b837f07063e08","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:7wGx08b8HOKxnppqcoq4ea in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:7wGx08b8HOKxnppqcoq4ea Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0a9mUPCyu1R2kxRqDoO9Q3","service":"spop","name":"Preludes: La colombe (The Dove)","artist":"Olivier Messiaen","album":"Messiaen: Preludes / 4 Rhythmic Studies / Canteyodjaya","type":"song","duration":124,"albumart":"https://i.scdn.co/image/ab67616d0000b2735069b30e5c43031a11934112","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:7ilWEHob3AYG3lAJlKEpDR in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:7ilWEHob3AYG3lAJlKEpDR Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5ykXsKJqx0GE0dsogxjylG","service":"spop","name":"Near Light","artist":"Ólafur Arnalds","album":"Living Room Songs","type":"song","duration":208,"albumart":"https://i.scdn.co/image/5741c5f8c54e042e4f8a6535293e564f6726467f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:2clBSTWalrt4Hi61E5Di9e in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:2clBSTWalrt4Hi61E5Di9e Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ZBvf57sMPjEhIOLQqQx9Z","service":"spop","name":"Paying The Cost To Be The Boss","artist":"B.B. King","album":"Deuces Wild","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b273aa0e3e3c1336034ba671b994","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:3cYHFvUYDVY9loQQ0LalJc in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:3cYHFvUYDVY9loQQ0LalJc Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:6tJpiGyRnjIXaoUm2Sb4i7 in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:6tJpiGyRnjIXaoUm2Sb4i7 Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3weNRklVDqb4Rr5MhKBR3D","service":"spop","name":"Nuvole Bianche","artist":"Ludovico Einaudi","album":"Una Mattina","type":"song","duration":357,"albumart":"https://i.scdn.co/image/ab67616d0000b273c0c021c0ac135d923b3a0ddc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7wGx08b8HOKxnppqcoq4ea","service":"spop","name":"Watermelon Man","artist":"Herbie Hancock","album":"Triple Best Of","type":"song","duration":428,"albumart":"https://i.scdn.co/image/ab67616d0000b273fd54ef98f422df91e43dee49","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:1EkpzEzd3JUvSm4UMC9YLK in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:1EkpzEzd3JUvSm4UMC9YLK Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ilWEHob3AYG3lAJlKEpDR","service":"spop","name":"Baby I'm A Fool","artist":"Melody Gardot","album":"My One And Only Thrill","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec50fbe7963bb2b511416841","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2clBSTWalrt4Hi61E5Di9e","service":"spop","name":"Syeeda's Song Flute","artist":"John Coltrane","album":"Giant Steps","type":"song","duration":427,"albumart":"https://i.scdn.co/image/ab67616d0000b2735338900b7f02a7805f53a7f8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:5UwohijVkmiUQf049Onfqy in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:5UwohijVkmiUQf049Onfqy Dec 17 18:03:17 volumio volumio[6287]: info: Using cached record of: spotify:track:1AU8s5RMGA6mzHsFn06Iaa Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3cYHFvUYDVY9loQQ0LalJc","service":"spop","name":"Blue Rondo à la Turk","artist":"Dave Brubeck","album":"Dave Brubeck's Greatest Hits","type":"song","duration":403,"albumart":"https://i.scdn.co/image/ab67616d0000b2736ca90aff3927a8b212258770","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:17 volumio volumio[6287]: info: Exploding uri spotify:track:0Evb6PwsuROuKZPYCpFy7x in service spop Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:0Evb6PwsuROuKZPYCpFy7x Dec 17 18:03:17 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6tJpiGyRnjIXaoUm2Sb4i7","service":"spop","name":"Born To Be Blue","artist":"Grant Green","album":"Born To Be Blue (Expanded Edition)","type":"song","duration":294,"albumart":"https://i.scdn.co/image/ab67616d0000b2738a454ea3c3d6860a05277c2a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:6D3rGir5Owv547fttKWhOH in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:6D3rGir5Owv547fttKWhOH Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1EkpzEzd3JUvSm4UMC9YLK","service":"spop","name":"Benjamin","artist":"Yo-Yo Ma","album":"October Road (Special Edition)","type":"song","duration":208,"albumart":"https://i.scdn.co/image/ab67616d0000b273873e0e6e58041c9232602db0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5UwohijVkmiUQf049Onfqy","service":"spop","name":"New York Minute","artist":"Lang Lang","album":"New York Rhapsody","type":"song","duration":401,"albumart":"https://i.scdn.co/image/ab67616d0000b2731fd72aee7673d77066a1bfab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:1s4hDcjbLUddDakw5bY0M2 in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:1s4hDcjbLUddDakw5bY0M2 Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:0KnSKxjFG3av8TkJyFFOmd in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:0KnSKxjFG3av8TkJyFFOmd Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:5SXcK7CYayh56VgR0Q5E0u in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:5SXcK7CYayh56VgR0Q5E0u Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:06rt8Zkk3M1L5lRRNYxQRU in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:06rt8Zkk3M1L5lRRNYxQRU Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Evb6PwsuROuKZPYCpFy7x","service":"spop","name":"Look What I Found","artist":"Chris Thile","album":"Bass & Mandolin","type":"song","duration":350,"albumart":"https://i.scdn.co/image/ab67616d0000b273abe598b65941fb5c91b88ae4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6D3rGir5Owv547fttKWhOH","service":"spop","name":"I Cover the Waterfront","artist":"Chris Thile","album":"Chris Thile & Brad Mehldau","type":"song","duration":420,"albumart":"https://i.scdn.co/image/ab67616d0000b2737a2358b47feab5e9340e61ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:2kLw0p31p5efs0I2X6qjTJ in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:2kLw0p31p5efs0I2X6qjTJ Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1s4hDcjbLUddDakw5bY0M2","service":"spop","name":"Empire State Of Mind","artist":"Lang Lang","album":"New York Rhapsody","type":"song","duration":323,"albumart":"https://i.scdn.co/image/ab67616d0000b2731fd72aee7673d77066a1bfab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0KnSKxjFG3av8TkJyFFOmd","service":"spop","name":"Traveling Music","artist":"Silkroad Ensemble","album":"The Vietnam War: A Film By Ken Burns & Lynn Novick","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b273839adf6870783d36b9f52d99","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:557FSHMvfvWtieHruwjnCL in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:557FSHMvfvWtieHruwjnCL Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:5iqqeUrXyjNT0gbCYkYKR4 in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:5iqqeUrXyjNT0gbCYkYKR4 Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5SXcK7CYayh56VgR0Q5E0u","service":"spop","name":"Brahms: Symphony No. 3 in F Major, Op. 90: III. Poco allegretto","artist":"Johannes Brahms","album":"Brahms: Symphonies Nos 1 - 4","type":"song","duration":384,"albumart":"https://i.scdn.co/image/ab67616d0000b273c8b2b27872c3ab2639b552ac","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:5voIoFpbuy0frbhBzqenqC in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:5voIoFpbuy0frbhBzqenqC Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:06rt8Zkk3M1L5lRRNYxQRU","service":"spop","name":"The Watcher","artist":"Chris Thile","album":"Chris Thile & Brad Mehldau","type":"song","duration":327,"albumart":"https://i.scdn.co/image/ab67616d0000b2737a2358b47feab5e9340e61ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:4vavlNjDSlQTxpdPXC9n7D in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:4vavlNjDSlQTxpdPXC9n7D Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2kLw0p31p5efs0I2X6qjTJ","service":"spop","name":"Krakow","artist":"Hilary Hahn","album":"Silfra","type":"song","duration":160,"albumart":"https://i.scdn.co/image/ab67616d0000b2736779402e33341034e5717656","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: info: Exploding uri spotify:track:77PEklpJ5g4lzsUrYMjDqn in service spop Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:track:77PEklpJ5g4lzsUrYMjDqn Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:557FSHMvfvWtieHruwjnCL","service":"spop","name":"O Virgo splendens (monodic)","artist":"Jordi Savall","album":"Llibre Vermell de Montserrat","type":"song","duration":131,"albumart":"https://i.scdn.co/image/ab67616d0000b273217c831926e54b768b8b551f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5iqqeUrXyjNT0gbCYkYKR4","service":"spop","name":"Goat Rodeo","artist":"Yo-Yo Ma","album":"The Goat Rodeo Sessions","type":"song","duration":258,"albumart":"https://i.scdn.co/image/ab67616d0000b273e750cc63147f2f4001f0daa2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5voIoFpbuy0frbhBzqenqC","service":"spop","name":"Scarlet Town","artist":"Chris Thile","album":"Chris Thile & Brad Mehldau","type":"song","duration":363,"albumart":"https://i.scdn.co/image/ab67616d0000b2737a2358b47feab5e9340e61ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4vavlNjDSlQTxpdPXC9n7D","service":"spop","name":"The Wounded Soldier","artist":"Silkroad Ensemble","album":"The Vietnam War: A Film By Ken Burns & Lynn Novick","type":"song","duration":194,"albumart":"https://i.scdn.co/image/ab67616d0000b273839adf6870783d36b9f52d99","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:18 volumio volumio[6287]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:77PEklpJ5g4lzsUrYMjDqn","service":"spop","name":"Your Heart is as Black as Night","artist":"Sylvia Brooks","album":"Signature","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b2731a6079964cdd098cc551a5dd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 17 18:03:26 volumio volumio[6287]: info: Preload queue cleared Dec 17 18:03:26 volumio volumio[6287]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 17 18:03:26 volumio volumio[6287]: info: CoreStateMachine::ClearQueue Dec 17 18:03:26 volumio volumio[6287]: info: CoreStateMachine::stop Dec 17 18:03:26 volumio volumio[6287]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 17 18:03:26 volumio volumio[6287]: info: CorePlayQueue::clearPlayQueue Dec 17 18:03:26 volumio volumio[6287]: info: CorePlayQueue::saveQueue Dec 17 18:03:26 volumio volumio[6287]: info: CoreCommandRouter::volumioPushQueue Dec 17 18:03:26 volumio volumio[6287]: info: CoreStateMachine::addQueueItems Dec 17 18:03:26 volumio volumio[6287]: info: CorePlayQueue::addQueueItems Dec 17 18:03:26 volumio volumio[6287]: info: Preload queue cleared Dec 17 18:03:26 volumio volumio[6287]: info: Adding Item to queue: spotify:user:spotify:playlist:6g3T2EFknUdvtQCgji767k Dec 17 18:03:26 volumio volumio[6287]: info: Exploding uri spotify:user:spotify:playlist:6g3T2EFknUdvtQCgji767k in service spop Dec 17 18:03:26 volumio volumio[6287]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:6g3T2EFknUdvtQCgji767k Dec 17 18:03:27 volumio volumio[6287]: info: CoreCommandRouter::volumioPushQueue Dec 17 18:03:27 volumio volumio[6287]: info: CorePlayQueue::saveQueue Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::updateTrackBlock Dec 17 18:03:27 volumio volumio[6287]: info: CorePlayQueue::getTrackBlock Dec 17 18:03:27 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:27 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:27 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 17 18:03:27 volumio volumio[6287]: info: CoreCommandRouter::volumioPlay Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::play index 0 Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::stop Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::play index undefined Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 17 18:03:27 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::startPlaybackTimer Dec 17 18:03:27 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:27 volumio volumio[6287]: info: [1765987407090] ControllerSpotify::clearAddPlayTrack Dec 17 18:03:27 volumio volumio[6287]: info: Sending Spotify command with payload to local API: /player/play Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="resolved context of track" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=warning msg="failed getting output device delay" error="ALSA error at snd_pcm_delay: Input/output error" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=trace msg="emitting websocket event: will_play" Dec 17 18:03:27 volumio volumio[6287]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","play_origin":"go-librespot"}} Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="selected format OGG_VORBIS_320 (b807c9cb9409dd157bf175a88dc5b1e8633c1d74)" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="requested aes key for file b807c9cb9409dd157bf175a88dc5b1e8633c1d74, gid: 1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="fetched first chunk of 7, total size is 3187608 bytes" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=info msg="loaded track \"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846\" (paused: false, position: 0ms, duration: 100760ms, prefetched: false)" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=warning msg="failed getting output device delay" error="ALSA error at snd_pcm_delay: Input/output error" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=trace msg="scheduling prefetch in 71s" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=trace msg="emitting websocket event: metadata" Dec 17 18:03:27 volumio volumio[6287]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","name":"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846","artist_names":["Daniel Barenboim"],"album_name":"Bach, JS : Well-Tempered Clavier Books 1 \u0026 2","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0233173321aabf16f0bf6f0d31","position":0,"duration":100760,"release_date":"year:2004","track_number":1,"disc_number":1}} Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=trace msg="emitting websocket event: playing" Dec 17 18:03:27 volumio volumio[6287]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","resume":false,"play_origin":"go-librespot"}} Dec 17 18:03:27 volumio volumio[6287]: SPOTIFY: PUSH STATE SPOTIFY Dec 17 18:03:27 volumio volumio[6287]: SPOTIFY: {"status":"play","service":"spop","title":"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846","artist":"Daniel Barenboim","album":"Bach, JS : Well-Tempered Clavier Books 1 & 2","albumart":"https://i.scdn.co/image/ab67616d00001e0233173321aabf16f0bf6f0d31","uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","trackType":"spotify","seek":0,"duration":100,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 17 18:03:27 volumio volumio[6287]: info: CoreCommandRouter::servicePushState Dec 17 18:03:27 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:27 volumio volumio[6287]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846","artist":"Daniel Barenboim","album":"Bach, JS : Well-Tempered Clavier Books 1 & 2","albumart":"https://i.scdn.co/image/ab67616d00001e0233173321aabf16f0bf6f0d31","uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","trackType":"spotify","seek":0,"duration":100,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 17 18:03:27 volumio volumio[6287]: verbose: CURRENT POSITION 0 Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::syncState stateService play Dec 17 18:03:27 volumio volumio[6287]: info: CoreStateMachine::syncState currentStatus stop Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="fetched chunk 1/6, size: 524288" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="fetched chunk 3/6, size: 524288" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:27 volumio go-librespot[6609]: time="2025-12-17T18:03:27+02:00" level=debug msg="fetched chunk 2/6, size: 524288" uri="spotify:track:1AU8s5RMGA6mzHsFn06Iaa" Dec 17 18:03:28 volumio volumio[6287]: SPOTIFY: PUSH STATE SPOTIFY Dec 17 18:03:28 volumio volumio[6287]: SPOTIFY: {"status":"play","service":"spop","title":"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846","artist":"Daniel Barenboim","album":"Bach, JS : Well-Tempered Clavier Books 1 & 2","albumart":"https://i.scdn.co/image/ab67616d00001e0233173321aabf16f0bf6f0d31","uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","trackType":"spotify","seek":0,"duration":100,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 17 18:03:28 volumio volumio[6287]: info: CoreCommandRouter::servicePushState Dec 17 18:03:28 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:28 volumio volumio[6287]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Bach, JS : Well-Tempered Clavier Book 1 : Prelude No.1 in C major BWV846","artist":"Daniel Barenboim","album":"Bach, JS : Well-Tempered Clavier Books 1 & 2","albumart":"https://i.scdn.co/image/ab67616d00001e0233173321aabf16f0bf6f0d31","uri":"spotify:track:1AU8s5RMGA6mzHsFn06Iaa","trackType":"spotify","seek":0,"duration":100,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 17 18:03:28 volumio volumio[6287]: verbose: CURRENT POSITION 0 Dec 17 18:03:28 volumio volumio[6287]: info: CoreStateMachine::syncState stateService play Dec 17 18:03:28 volumio volumio[6287]: info: CoreStateMachine::syncState currentStatus play Dec 17 18:03:28 volumio volumio[6287]: info: Received an update from plugin. extracting info from payload Dec 17 18:03:28 volumio volumio[6287]: info: CoreStateMachine::pushState Dec 17 18:03:28 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:28 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 17 18:03:28 volumio volumio[6287]: info: CoreCommandRouter::volumioPushState Dec 17 18:03:28 volumio volumio[6287]: info: MRS: Pushing multiroomSync output update for this device Dec 17 18:03:28 volumio volumio[6287]: info: MRS: Pushing multiroomSync output Dec 17 18:03:28 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:28 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:28 volumio volumio[6287]: info: CoreStateMachine::pushState Dec 17 18:03:28 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:28 volumio volumio[6287]: info: CoreCommandRouter::volumioPushState Dec 17 18:03:28 volumio volumio[6287]: info: MRS: Pushing multiroomSync output update for this device Dec 17 18:03:28 volumio volumio[6287]: info: MRS: Pushing multiroomSync output Dec 17 18:03:28 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:28 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:28 volumio volumio[6287]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 17 18:03:28 volumio volumio[6287]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 17 18:03:28 volumio sudo[7078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 17 18:03:28 volumio sudo[7078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:03:28 volumio volumio[6287]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 17 18:03:28 volumio volumio[6287]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 17 18:03:28 volumio sudo[7080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 17 18:03:28 volumio sudo[7080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:03:28 volumio volumio[6287]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 17 18:03:28 volumio systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon. Dec 17 18:03:28 volumio sudo[7078]: pam_unix(sudo:session): session closed for user root Dec 17 18:03:28 volumio sudo[7080]: pam_unix(sudo:session): session closed for user root Dec 17 18:03:28 volumio volumio[6287]: info: peppymeterbasic Daemon Started Dec 17 18:03:28 volumio volumio[6287]: info: peppymeterbasic Daemon Started Dec 17 18:03:29 volumio volumio[7087]: libpng warning: iCCP: known incorrect sRGB profile Dec 17 18:03:29 volumio volumio[7087]: libpng warning: iCCP: known incorrect sRGB profile Dec 17 18:03:35 volumio go-librespot[6609]: time="2025-12-17T18:03:35+02:00" level=trace msg="sent dealer ping" Dec 17 18:03:35 volumio go-librespot[6609]: time="2025-12-17T18:03:35+02:00" level=trace msg="received dealer pong" Dec 17 18:03:40 volumio volumio[6287]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 17 18:03:41 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 17 18:03:50 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 17 18:03:50 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 17 18:03:50 volumio sudo[7146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 17 18:03:50 volumio sudo[7146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:03:50 volumio sudo[7148]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 17 18:03:50 volumio sudo[7148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:03:50 volumio sudo[7148]: pam_unix(sudo:session): session closed for user root Dec 17 18:03:50 volumio sudo[7146]: pam_unix(sudo:session): session closed for user root Dec 17 18:03:51 volumio volumio[6287]: verbose: New Socket.io Connection to 192.168.1.2 from 192.168.1.5 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 11 Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 17 18:03:51 volumio sudo[7154]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 17 18:03:51 volumio sudo[7154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:03:51 volumio sudo[7154]: pam_unix(sudo:session): session closed for user root Dec 17 18:03:51 volumio sudo[7152]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 17 18:03:51 volumio sudo[7152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:03:51 volumio sudo[7152]: pam_unix(sudo:session): session closed for user root Dec 17 18:03:51 volumio volumio[6287]: verbose: New Socket.io Connection to 192.168.1.2 from 192.168.1.5 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 11 Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::volumioGetVisibleSources Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:51 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 17 18:03:51 volumio volumio[6287]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 17 18:03:51 volumio volumio[6287]: info: Received Get System Info Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 17 18:03:51 volumio volumio[6287]: info: Discovery: Getting this device information Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:51 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:51 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:51 volumio volumio[6287]: info: Listing playlists Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 17 18:03:51 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 17 18:03:52 volumio volumio[6287]: verbose: New Socket.io Connection to 192.168.1.2 from 192.168.1.5 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 12 Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::volumioGetVisibleSources Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:52 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 17 18:03:52 volumio volumio[6287]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 17 18:03:52 volumio volumio[6287]: info: Received Get System Info Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 17 18:03:52 volumio volumio[6287]: info: Discovery: Getting this device information Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:52 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:52 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:52 volumio volumio[6287]: info: Listing playlists Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 17 18:03:52 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 17 18:03:53 volumio volumio[6287]: info: Received Get System Info Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 17 18:03:53 volumio volumio[6287]: info: Discovery: Getting this device information Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:53 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 17 18:03:53 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 17 18:03:55 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 17 18:03:55 volumio volumio[6287]: info: Received Get System Info Dec 17 18:03:55 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 17 18:03:55 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 17 18:03:55 volumio volumio[6287]: info: Discovery: Getting this device information Dec 17 18:03:55 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:03:55 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:03:55 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 17 18:03:56 volumio volumio[6287]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 17 18:04:01 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 17 18:04:05 volumio go-librespot[6609]: time="2025-12-17T18:04:05+02:00" level=trace msg="received accesspoint ping" Dec 17 18:04:05 volumio go-librespot[6609]: time="2025-12-17T18:04:05+02:00" level=trace msg="received accesspoint pong ack" Dec 17 18:04:05 volumio go-librespot[6609]: time="2025-12-17T18:04:05+02:00" level=trace msg="sent dealer ping" Dec 17 18:04:05 volumio go-librespot[6609]: time="2025-12-17T18:04:05+02:00" level=trace msg="received dealer pong" Dec 17 18:04:08 volumio volumio[6287]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 17 18:04:08 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 17 18:04:08 volumio volumio[6287]: info: Creating Spotify config file Dec 17 18:04:08 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 17 18:04:08 volumio volumio[6287]: info: Spotify config file written Dec 17 18:04:08 volumio sudo[7194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 17 18:04:08 volumio sudo[7194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:04:08 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 17 18:04:08 volumio systemd[1]: go-librespot-daemon.service: Killing process 6639 (go-librespot) with signal SIGKILL. Dec 17 18:04:08 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 17 18:04:08 volumio volumio[6287]: info: Connection to go-librespot Websocket closed Dec 17 18:04:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 17 18:04:08 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.338s CPU time. Dec 17 18:04:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 17 18:04:08 volumio go-librespot[7196]: go-librespot daemon starting... Dec 17 18:04:08 volumio sudo[7194]: pam_unix(sudo:session): session closed for user root Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=info msg="running go-librespot 0.4.0" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=debug msg="app state loaded" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=info msg="zeroconf server listening on port 42869" Dec 17 18:04:08 volumio go-librespot[7197]: time="2025-12-17T18:04:08+02:00" level=debug msg="obtained new client token: AACpBMQH3Ms1ReJON+fVwCUucp6VqCHkNTMd/71Xn9NvdpPTIvULjJa0U+BlYulRau26jwyPPVqYUJWWQn1ErNl/pp/oTXNkav+HCbGyYhFZAkRhbeO9V6Xzj6dH2KwWGnNpm87lBhPpRlslyfSGpjJLW+pjwjZqLaUuHkHGVIbpJe60EORWgAuKTwamhiEwJyYKLFRz65IYsXZbuumXNQIlbT56vQtBL751Y+bWfoMqMXyoH6h/wydYHA==" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="completed keyexchange" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="completed challenge" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=info msg="authenticated AP" username="fi*****sg" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=info msg="authenticated Login5" username="fi*****sg" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="initializing zeroconf session" username="fi*****sg" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="dealer connection opened" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=trace msg="starting accesspoint recv loop" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=trace msg="starting dealer recv loop" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=trace msg="received accesspoint ping" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="received connection id: ZDA4YTZkZDktMGNh...NkZBNkEyNDJENA==" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=trace msg="received accesspoint pong ack" Dec 17 18:04:09 volumio go-librespot[7197]: time="2025-12-17T18:04:09+02:00" level=debug msg="put connect state because NEW_DEVICE" Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 17 18:04:10 volumio volumio[6287]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 17 18:04:10 volumio volumio[6287]: info: Received Get System Version Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 17 18:04:10 volumio volumio[6287]: info: Received Get System Info Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 17 18:04:10 volumio volumio[6287]: info: Discovery: Getting this device information Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:04:10 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:04:10 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 17 18:04:11 volumio volumio[6287]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 17 18:04:11 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 17 18:04:11 volumio volumio[6287]: info: Creating Spotify config file Dec 17 18:04:11 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 17 18:04:11 volumio volumio[6287]: info: Spotify config file written Dec 17 18:04:11 volumio sudo[7207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 17 18:04:11 volumio sudo[7207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:04:11 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 17 18:04:11 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 17 18:04:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 17 18:04:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 17 18:04:11 volumio go-librespot[7209]: go-librespot daemon starting... Dec 17 18:04:11 volumio sudo[7207]: pam_unix(sudo:session): session closed for user root Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=info msg="running go-librespot 0.4.0" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="app state loaded" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 17 18:04:11 volumio volumio[6287]: info: Initializing connection to go-librespot Websocket Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="new websocket client" Dec 17 18:04:11 volumio volumio[6287]: info: Connection to go-librespot Websocket established Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=info msg="zeroconf server listening on port 35587" Dec 17 18:04:11 volumio volumio[6287]: info: go-librespot daemon successfully initialized Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="obtained new client token: AABtRLWjElDgMT3BSKEjRumwxf827CqmREQw1fiVjr5pptRIe9XuMQqQfEHjVq1/umNFDFJd5NLp2ekBjqt8aAov7i9f8yWoHMCW6jqTrBTSfMstOCEFbUjA8UGwp55Za0BhpYLJ+4f3drsQpFxpGdHYxVZ04MpBNVWy4cdB0OVlVguJAL+FXBgM8I//Y+7xJMZEslsmFEy8p9MO3N3Hs43kHTt32lGdNSq0nLS6F0Dajc0PilDqq28f7w==" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="completed keyexchange" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=debug msg="completed challenge" Dec 17 18:04:11 volumio go-librespot[7210]: time="2025-12-17T18:04:11+02:00" level=info msg="authenticated AP" username="fi*****sg" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=info msg="authenticated Login5" username="fi*****sg" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="initializing zeroconf session" username="fi*****sg" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="dealer connection opened" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=trace msg="starting accesspoint recv loop" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=trace msg="starting dealer recv loop" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=trace msg="received accesspoint ping" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="received connection id: ODY1ZTBjN2MtNzhh...MEJGOTA4MjdCQw==" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="put connect state because NEW_DEVICE" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 17 18:04:12 volumio go-librespot[7210]: time="2025-12-17T18:04:12+02:00" level=trace msg="received accesspoint pong ack" Dec 17 18:04:14 volumio volumio[6287]: info: go-librespot daemon successfully initialized Dec 17 18:04:14 volumio volumio[6287]: info: Getting Spotify volume Dec 17 18:04:14 volumio volumio[6287]: info: Spotify volume: 100 Dec 17 18:04:14 volumio volumio[6287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 17 18:04:14 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:04:14 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:04:14 volumio volumio[6287]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 17 18:04:14 volumio volumio[6287]: SPOTIFY: SPOTIFY VOLUME 100 Dec 17 18:04:14 volumio volumio[6287]: SPOTIFY: VOLUMIO VOLUME 86 Dec 17 18:04:14 volumio volumio[6287]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 17 18:04:14 volumio volumio[6287]: info: Setting Spotify Volume from Volumio: 86 Dec 17 18:04:14 volumio volumio[6287]: info: Initializing connection to go-librespot Websocket Dec 17 18:04:14 volumio go-librespot[7210]: time="2025-12-17T18:04:14+02:00" level=debug msg="new websocket client" Dec 17 18:04:14 volumio volumio[6287]: info: Connection to go-librespot Websocket established Dec 17 18:04:15 volumio volumio[6287]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 17 18:04:15 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 17 18:04:15 volumio volumio[6287]: info: Creating Spotify config file Dec 17 18:04:15 volumio volumio[6287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 17 18:04:15 volumio volumio[6287]: info: Spotify config file written Dec 17 18:04:15 volumio sudo[7218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 17 18:04:15 volumio sudo[7218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:04:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 17 18:04:15 volumio volumio[6287]: info: Connection to go-librespot Websocket closed Dec 17 18:04:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 17 18:04:15 volumio volumio[6287]: info: Connection to go-librespot Websocket closed Dec 17 18:04:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 17 18:04:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 17 18:04:15 volumio go-librespot[7220]: go-librespot daemon starting... Dec 17 18:04:15 volumio sudo[7218]: pam_unix(sudo:session): session closed for user root Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=info msg="running go-librespot 0.4.0" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=debug msg="app state loaded" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=info msg="zeroconf server listening on port 42329" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=debug msg="obtained new client token: AAAPfJN3/xyz6FGBEsJpTk2/frLaHJcXwvD5oxWnRxrPzG0TDox7jUZXtTOF2oC688KscVyM0kWJlh60pO2Y5CAU8JlBXfmuEh1VhrG+ocDWfpUwleu97ZrgiZCtuh68FePCbWBFiPuqWhtT+kUEpo0g7btEUWPn1OlQQYKKxsaAKaReLgD6oU66G/f9MjAKXdW6eY7rlYgtkPUq0J+JnWRmEfCINw7zKBVGAhFG4ZnpBU0Y5oayz2BCxA==" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 17 18:04:15 volumio go-librespot[7221]: time="2025-12-17T18:04:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 17 18:04:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 17 18:04:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 17 18:04:15 volumio volumio[6287]: info: Tunnel connection is inactive, restarting it Dec 17 18:04:15 volumio volumio[6287]: info: Starting Tunnel 1 Dec 17 18:04:15 volumio volumio[6287]: info: Starting Tunnel Connection Checker Dec 17 18:04:16 volumio volumio[6287]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Dec 17 18:04:16 volumio volumio[6287]: info: Sending Spotify command with payload to local API: /player/volume Dec 17 18:04:16 volumio volumio[6287]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 17 18:04:16 volumio sudo[7234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 17 18:04:16 volumio sudo[7234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 17 18:04:16 volumio autossh[6883]: received signal to exit (15) Dec 17 18:04:16 volumio systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 17 18:04:16 volumio systemd[1]: sshtunnel.service: Deactivated successfully. Dec 17 18:04:16 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 17 18:04:16 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 17 18:04:16 volumio sudo[7234]: pam_unix(sudo:session): session closed for user root Dec 17 18:04:16 volumio volumio[6287]: info: Remote SSH Started Dec 17 18:04:16 volumio autossh[7237]: port set to 0, monitoring disabled Dec 17 18:04:16 volumio autossh[7237]: starting ssh (count 1) Dec 17 18:04:16 volumio autossh[7237]: ssh child pid is 7240 Dec 17 18:04:16 volumio volumio[6287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 17 18:04:16 volumio volumio[6287]: info: CoreCommandRouter::volumioGetState Dec 17 18:04:16 volumio volumio[6287]: info: CorePlayQueue::getTrack 0 Dec 17 18:04:16 volumio volumiossh-tunnel[7240]: Warning: Permanently added '[eu6.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 17 18:04:17 volumio volumio[6287]: info: Initializing connection to go-librespot Websocket Dec 17 18:04:17 volumio volumio[6287]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 17 18:04:17 volumio volumio[6287]: info: Getting Spotify volume Dec 17 18:04:17 volumio volumio[6287]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 17 18:04:17 volumio volumio[6287]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 17 18:04:17 volumio volumio[6287]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 17 18:04:17 volumio volumio[6287]: errno: -111, Dec 17 18:04:17 volumio volumio[6287]: code: 'ECONNREFUSED', Dec 17 18:04:17 volumio volumio[6287]: syscall: 'connect', Dec 17 18:04:17 volumio volumio[6287]: address: '127.0.0.1', Dec 17 18:04:17 volumio volumio[6287]: port: 9879, Dec 17 18:04:17 volumio volumio[6287]: response: undefined Dec 17 18:04:17 volumio volumio[6287]: } Dec 17 18:04:17 volumio volumio[6287]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 17 18:04:18 volumio sudo[7269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-17 18:03' Dec 17 18:04:18 volumio sudo[7269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"