Dec 30 09:10:05 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 09:10:05 volumio2 volumio[1220]: info: In handleBrowseUri, curUri=spotify Dec 30 09:10:05 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:05 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:05 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:05 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:07 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 09:10:07 volumio2 volumio[1220]: info: In handleBrowseUri, curUri=spotify/playlists Dec 30 09:10:07 volumio2 go-librespot[1800]: time="2025-12-30T09:10:07+01:00" level=trace msg="sent dealer ping" Dec 30 09:10:08 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:08 volumio2 go-librespot[1800]: time="2025-12-30T09:10:08+01:00" level=trace msg="received dealer pong" Dec 30 09:10:10 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 09:10:10 volumio2 volumio[1220]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:37i9dQZF1E368BRfGYBW7s Dec 30 09:10:11 volumio2 go-librespot[1800]: time="2025-12-30T09:10:11+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E368BRfGYBW7s" Dec 30 09:10:11 volumio2 go-librespot[1800]: time="2025-12-30T09:10:11+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Dec 30 09:10:12 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:12 volumio2 volumio[1220]: info: Preloading song: spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:4IZawwie57u00LxKWVhAop in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:5SepxuwxShK2VOVZ2QmdAH in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:40cKQPOcZczrvYYu3QMJ46 in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:7LNP6YNYDeMgBeG4JBfAdq in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:5zWZ9iNevP0397xB3jWV2z in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:7KkdYJqxvq4ZFq9gvFy06v in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5SepxuwxShK2VOVZ2QmdAH","service":"spop","name":"I Love to Love 2011","artist":"Ms Project","album":"The 80'S Remixes Collection, Vol. 1","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b27379aaf671a567a2f1d8e58324","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:273uCXd7NPrInaiNqtkOrA in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:2d8D7uk3tbAThjRkdfrx9c in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:69CuhJ2829Z4Uosm51woKp in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4IZawwie57u00LxKWVhAop","service":"spop","name":"Heartbreak Hotel","artist":"C.C. Catch","album":"Welcome To The Heartbreak Hotel","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b273dd3cf34fde6a030fc0a7171e","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:5FhRWxcqWIu3JoFS0kEPom in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:1mscYl0vNlVknI51wOWDG7 in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7LNP6YNYDeMgBeG4JBfAdq","service":"spop","name":"(I'll Never Be) Maria Magdalena - Single Verison","artist":"Sandra","album":"Ten On One","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b2731ade47900d03a0276737982b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5zWZ9iNevP0397xB3jWV2z","service":"spop","name":"Brother Louie","artist":"Modern Talking","album":"Ready For Romance","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b273be1421122cef4940f500ac06","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:12 volumio2 volumio[1220]: info: Exploding uri spotify:track:2aEuA8PSqLa17Y4hKPj5rr in service spop Dec 30 09:10:12 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:40cKQPOcZczrvYYu3QMJ46","service":"spop","name":"I Wanna Hear Your Heartbeat (Sunday Girl)","artist":"Bad Boys Blue","album":"Heartbeat","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b273714c9716a2021606cd915f2b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:4TzIw4E4pca6Ai9P0P2q9R in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7KkdYJqxvq4ZFq9gvFy06v","service":"spop","name":"D.I.S.C.O. - Single Version","artist":"Ottawan","album":"D.I.S.C.O.","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b273f6f713a49f98ec228d7f9883","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:2ITgMuOLbDcc9TVEwIQMyW in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:5ZYAuuGmA0Vf4FPOXT1lal in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:273uCXd7NPrInaiNqtkOrA","service":"spop","name":"Tarzan Boy","artist":"Baltimora","album":"Living In The Background","type":"song","duration":378,"albumart":"https://i.scdn.co/image/ab67616d0000b273de82204a5baa683ce85d57cb","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:7sos76tFGXoBgSpWbp7qZU in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:6kk07URPWTiRzULynSOVrs in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2d8D7uk3tbAThjRkdfrx9c","service":"spop","name":"Voyage voyage","artist":"Desireless","album":"François","type":"song","duration":266,"albumart":"https://i.scdn.co/image/ab67616d0000b2738f5813c842cb115f3cf1fecd","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:0MSAWjq5aWfTUNL9hv7Epd in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:53PlbcGzLTx65vjaS6tG0N in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:69CuhJ2829Z4Uosm51woKp","service":"spop","name":"Cause You Are Young - 12\" Version","artist":"C.C. Catch","album":"Ultimate C.C. Catch","type":"song","duration":285,"albumart":"https://i.scdn.co/image/ab67616d0000b273371dfbf4b449d6f2a3d9508c","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:5aoYEKyeDmXIx9Qn28rm92 in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:1fwUr7AoiR7nbchvC5s7ul in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5FhRWxcqWIu3JoFS0kEPom","service":"spop","name":"I Saw You Dancing","artist":"Yaki-Da","album":"Pride","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf4185b2736303639d783a38","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:3wqDN5EqKsBPM3Otj9wp9N in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1mscYl0vNlVknI51wOWDG7","service":"spop","name":"Everlasting Love","artist":"Sandra","album":"Ten On One","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b2731ade47900d03a0276737982b","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:5q70qg9anaoP4MMkGnu354 in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:5ep8e1ZbIjtUajhcsskkpb in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:4BeMBXhrJm1791r32174xH in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4TzIw4E4pca6Ai9P0P2q9R","service":"spop","name":"Gimme Gimme Your Lovin'","artist":"Bad Boys Blue","album":"Love Is No Crime","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b273fe4b06d7319f7fc22766ce92","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2aEuA8PSqLa17Y4hKPj5rr","service":"spop","name":"Cheri Cheri Lady","artist":"Modern Talking","album":"Let's Talk About Love","type":"song","duration":226,"albumart":"https://i.scdn.co/image/ab67616d0000b273aedd9728f5cc4b13ee49e061","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:5074Vt992hKDNhwXMhRceJ in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:1OHxngvqXwHljeAzbMuKXy in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5ZYAuuGmA0Vf4FPOXT1lal","service":"spop","name":"Voyage voyage - Euro Remix","artist":"Desireless","album":"Voyage voyage (Euro Remix)","type":"song","duration":374,"albumart":"https://i.scdn.co/image/ab67616d0000b2734a7aaac0d4c80f97082b2057","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:1QEDM8Gwaf2MUyogGWV35v in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ITgMuOLbDcc9TVEwIQMyW","service":"spop","name":"Touch My Heart","artist":"Danuta","album":"That's Eurobeat - Hi Energy Disco Vol. 3","type":"song","duration":191,"albumart":"https://i.scdn.co/image/ab67616d0000b273445e22ee4d026da8c663c493","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7sos76tFGXoBgSpWbp7qZU","service":"spop","name":"Soul Survivor - Single Version","artist":"C.C. Catch","album":"Catch The Hits","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b2738a89bd803686277ec1a04fc8","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:6nF5D6JNeOFTsMW612AZz4 in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:6tsbXUca4RkFuB6TuHRA6T in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6kk07URPWTiRzULynSOVrs","service":"spop","name":"Maniac - From \"Flashdance\"","artist":"Michael Sembello","album":"ドライブが楽しくなる洋楽ヒッツ！80年代 DANCE","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b2730946d11271fa6083bc8ea769","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:13 volumio2 volumio[1220]: info: Exploding uri spotify:track:7rbV4H1PitZR99RCndrUhp in service spop Dec 30 09:10:13 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:3HWaSYU8Q3XNuJlF6nLrfq in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0MSAWjq5aWfTUNL9hv7Epd","service":"spop","name":"In The Heat Of The Night","artist":"Sandra","album":"18 Greatest Hits","type":"song","duration":301,"albumart":"https://i.scdn.co/image/ab67616d0000b273605bafbd3a7bf46d22bf51d9","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:53PlbcGzLTx65vjaS6tG0N","service":"spop","name":"Atlantis Is Calling (S.O.S. for Love)","artist":"Modern Talking","album":"Ready For Romance","type":"song","duration":230,"albumart":"https://i.scdn.co/image/ab67616d0000b273be1421122cef4940f500ac06","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:7skyR8nK3vnDikYFBoUVw6 in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:5WIRxVCM6E0CSAPILaZLAQ in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:76deK31HfF9eGANCWsRmDm in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","service":"spop","name":"London Nights","artist":"London Boys","album":"The Twelve Commandments Of Dance","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b273db7954f973b7996676c18a66","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:1eddb9cfXiwt9EgAREpS34 in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5aoYEKyeDmXIx9Qn28rm92","service":"spop","name":"Hungry for Love","artist":"Bad Boys Blue","album":"Bad Boys Best","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b273d545ca85838422f41a64747f","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:07qWGLDIFcy1u49i6KOSOk in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3wqDN5EqKsBPM3Otj9wp9N","service":"spop","name":"Hello - Hit Version","artist":"Joy","album":"Gold - The Hit Collection (Special Edition)","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273026921e072cd31dab301e5ff","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:252PdgFP3fefju8nMF8o4Q in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5q70qg9anaoP4MMkGnu354","service":"spop","name":"I Can Lose My Heart Tonight - Maxi Version","artist":"C.C. Catch","album":"Catch The Catch","type":"song","duration":351,"albumart":"https://i.scdn.co/image/ab67616d0000b273669d56aed60c68bd3e5c872f","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:50D2X5Hbv0iNhE16tsdiEz in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:4MEadO3tY6PM6jksMMMkYY in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5ep8e1ZbIjtUajhcsskkpb","service":"spop","name":"Life - Radio Edit","artist":"Haddaway","album":"The Album","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b273efb3fd949c71bc9b5e7b31dc","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:08W9jxh8GZlYe9vIO7drlv in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4BeMBXhrJm1791r32174xH","service":"spop","name":"The Girl Of Lucifer","artist":"Monte Kristo","album":"The Girl Of Lucifer","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b27373228adb65762d42fa122784","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:3lrnlYbfVdJ5FW8ySUFyOV in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:4W3Iz3gGlzVHX4qHrWPP8u in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5074Vt992hKDNhwXMhRceJ","service":"spop","name":"Touch in the Night - Radio Version","artist":"Silent Circle","album":"No.1 (Jubiläums Edition)","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b273722206ae6845cdbbb4ed5e44","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:49bme2iuBACRtC4Hjih4GU in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:0Zezws6aRVofjz3pHrUScL in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1OHxngvqXwHljeAzbMuKXy","service":"spop","name":"A World Without You (Michelle) - '98","artist":"Bad Boys Blue","album":"Back","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b273e0b53d4bc0dd9168e9135e89","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS","service":"spop","name":"I'm Gonna Give My Heart","artist":"London Boys","album":"The Twelve Commandments Of Dance","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b273db7954f973b7996676c18a66","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:track:2ZSep9yW6E1cwDNXhRb1Qf in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:14 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::ClearQueue Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::stPlaybackTimer Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::serviceStop Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::serviceStop Dec 30 09:10:14 volumio2 volumio[1220]: info: [1767082214756] ControllerWebradio::stop Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::clearPlayQueue Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:14 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:14 volumio2 volumio[1220]: info: Adding Item to queue: spotify:user:spotify:playlist:37i9dQZF1E368BRfGYBW7s Dec 30 09:10:14 volumio2 volumio[1220]: info: Exploding uri spotify:user:spotify:playlist:37i9dQZF1E368BRfGYBW7s in service spop Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:37i9dQZF1E368BRfGYBW7s Dec 30 09:10:14 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:14 volumio2 volumio[1220]: info: Dec 30 09:10:14 volumio2 volumio[1220]: ---------------------------- MPD announces state update: player Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand stop took 37 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: info: ControllerMpd::getState Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand status Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand status took 1 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::parseState Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 30 09:10:14 volumio2 volumio[1220]: info: Dec 30 09:10:14 volumio2 volumio[1220]: ---------------------------- MPD announces state update: player Dec 30 09:10:14 volumio2 volumio[1220]: info: ControllerMpd::getState Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand status Dec 30 09:10:14 volumio2 volumio[1220]: info: Dec 30 09:10:14 volumio2 volumio[1220]: ---------------------------- MPD announces state update: player Dec 30 09:10:14 volumio2 volumio[1220]: info: ControllerMpd::getState Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand status Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand playlistinfo took 18 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand status took 17 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand status took 16 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::parseTrackInfo Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::parseState Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::parseState Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 30 09:10:14 volumio2 volumio[1220]: info: ControllerMpd::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::servicePushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"BOYS - Najpiękniejsza Dziewczyno","artist":null,"album":null,"uri":"https://waw.ic.smcdn.pl/3990-1.mp3","trackType":"mp3"} Dec 30 09:10:14 volumio2 volumio[1220]: verbose: CURRENT POSITION 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::syncState stateService stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::syncState currentStatus stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: No code Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: ------------------------------ 65ms Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand playlistinfo took 61 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: info: sendMpdCommand playlistinfo took 60 milliseconds Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::parseTrackInfo Dec 30 09:10:14 volumio2 volumio[1220]: verbose: ControllerMpd::parseTrackInfo Dec 30 09:10:14 volumio2 volumio[1220]: info: ControllerMpd::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::servicePushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"BOYS - Najpiękniejsza Dziewczyno","artist":null,"album":null,"uri":"https://waw.ic.smcdn.pl/3990-1.mp3","trackType":"mp3"} Dec 30 09:10:14 volumio2 volumio[1220]: verbose: CURRENT POSITION 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::syncState stateService stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::syncState currentStatus stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: No code Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: ControllerMpd::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::servicePushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"BOYS - Najpiękniejsza Dziewczyno","artist":null,"album":null,"uri":"https://waw.ic.smcdn.pl/3990-1.mp3","trackType":"mp3"} Dec 30 09:10:14 volumio2 volumio[1220]: verbose: CURRENT POSITION 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::syncState stateService stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::syncState currentStatus stop Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: No code Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreStateMachine::pushState Dec 30 09:10:14 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:14 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushState Dec 30 09:10:14 volumio2 volumio[1220]: info: ------------------------------ 191ms Dec 30 09:10:14 volumio2 volumio[1220]: info: ------------------------------ 190ms Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Dec 30 09:10:15 volumio2 volumio[1220]: info: touch_display: Setting screensaver timeout to 300 seconds. Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 09:10:15 volumio2 volumio[1220]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"VOX FM","artist":"","uri":"https://waw.ic.smcdn.pl/3990-1.mp3","service":""} Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 09:10:15 volumio2 volumio[1220]: info: Discovery: Getting this device information Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::volumioGetState Dec 30 09:10:15 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6nF5D6JNeOFTsMW612AZz4","service":"spop","name":"Are You Man Enough","artist":"C.C. Catch","album":"Like A Hurricane","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b27343b19ec1b86f2fff8dde4fc7","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1QEDM8Gwaf2MUyogGWV35v","service":"spop","name":"Valerie - Hit Version","artist":"Joy","album":"Gold - The Hit Collection (Special Edition)","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b273026921e072cd31dab301e5ff","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6tsbXUca4RkFuB6TuHRA6T","service":"spop","name":"Little Russian","artist":"Mr. Zivago","album":"Best Of Mr. Zivago","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b2731c4501a3d8136054fb1f0ca3","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.1 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7rbV4H1PitZR99RCndrUhp","service":"spop","name":"Lady Valentine","artist":"Monte Kristo","album":"Lady Valentine","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b273f9ff0a1d3cdffaef28db6669","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 30 09:10:15 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3HWaSYU8Q3XNuJlF6nLrfq","service":"spop","name":"Touch in the Night","artist":"Silent Circle","album":"No.1 (Jubiläums Edition)","type":"song","duration":319,"albumart":"https://i.scdn.co/image/ab67616d0000b273722206ae6845cdbbb4ed5e44","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7skyR8nK3vnDikYFBoUVw6","service":"spop","name":"Self Control - Extended Version","artist":"Laura Branigan","album":"Self Control (Expanded)","type":"song","duration":304,"albumart":"https://i.scdn.co/image/ab67616d0000b27350a05e28731e07011a7e060d","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5WIRxVCM6E0CSAPILaZLAQ","service":"spop","name":"You're A Woman - Reloaded","artist":"Bad Boys Blue","album":"30","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b27383e8f40f893f1aebdf122b87","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:76deK31HfF9eGANCWsRmDm","service":"spop","name":"Bolero (Hold Me In Your Arms Again)","artist":"Fancy","album":"Greatest Hits & Remixes","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b273584a6b88efb1a2b56981182a","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1eddb9cfXiwt9EgAREpS34","service":"spop","name":"Smoky Joe's Café","artist":"C.C. Catch","album":"Like A Hurricane","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b27343b19ec1b86f2fff8dde4fc7","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:252PdgFP3fefju8nMF8o4Q","service":"spop","name":"Moonlight Affair - Radio Edit","artist":"Cliff Turner","album":"Moonlight Affair","type":"song","duration":201,"albumart":"https://i.scdn.co/image/ab67616d0000b2733d77e8888915e8d998177f04","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:07qWGLDIFcy1u49i6KOSOk","service":"spop","name":"Girl (You're My Song)","artist":"F.R. David","album":"Best of F.R. David","type":"song","duration":221,"albumart":"https://i.scdn.co/image/ab67616d0000b27336a4809d0774a9f56acd5af5","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:50D2X5Hbv0iNhE16tsdiEz","service":"spop","name":"Love Is the Name of the Game","artist":"Patty Ryan","album":"All the Best","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b27397d3d4acbf98a1a8a4c84df5","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4MEadO3tY6PM6jksMMMkYY","service":"spop","name":"Get Closer","artist":"Valerie Dore","album":"Get Closer","type":"song","duration":214,"albumart":"https://i.scdn.co/image/ab67616d0000b2739790b952a03e098d6f44ffd6","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08W9jxh8GZlYe9vIO7drlv","service":"spop","name":"A World Without You (Michelle) - Reloaded","artist":"Bad Boys Blue","album":"30","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b27383e8f40f893f1aebdf122b87","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3lrnlYbfVdJ5FW8ySUFyOV","service":"spop","name":"Flames Of Love","artist":"Fancy","album":"Flames Of Love (Deluxe Edition)","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b2736779e84a1c296406aacdccb5","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4W3Iz3gGlzVHX4qHrWPP8u","service":"spop","name":"Good Guys Only Win in Movies - Single Version","artist":"C.C. Catch","album":"The 80s Album","type":"song","duration":229,"albumart":"https://i.scdn.co/image/ab67616d0000b2737fed13b3bcff2c1810b25d5c","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:49bme2iuBACRtC4Hjih4GU","service":"spop","name":"Words - Remix 1989","artist":"F.R. David","album":"Words (Original Single 1982)","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b27338a788989af023f7a59f1db3","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Zezws6aRVofjz3pHrUScL","service":"spop","name":"Tell By Your Eyes","artist":"Mr. Zivago","album":"Best Of Mr. Zivago","type":"song","duration":281,"albumart":"https://i.scdn.co/image/ab67616d0000b2731c4501a3d8136054fb1f0ca3","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:15 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ZSep9yW6E1cwDNXhRb1Qf","service":"spop","name":"In 100 Years","artist":"Modern Talking","album":"In The Garden Of Venus","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b273469135c8e44563384c8e8dbd","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:17 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:17 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::play index 0 Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:17 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:17 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:17 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:17 volumio2 volumio[1220]: info: [1767082217046] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:17 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=debug msg="resolved context of track" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:17 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:4IZawwie57u00LxKWVhAop","uri":"spotify:track:4IZawwie57u00LxKWVhAop","play_origin":"go-librespot"}} Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=debug msg="selected format OGG_VORBIS_160 (76f1e05ac8ec4675b613fb95d9bcc69c65209409)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=debug msg="requested aes key for file 76f1e05ac8ec4675b613fb95d9bcc69c65209409, gid: 4IZawwie57u00LxKWVhAop" Dec 30 09:10:17 volumio2 go-librespot[1800]: time="2025-12-30T09:10:17+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4IZawwie57u00LxKWVhAop: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:17 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:23 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:23 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:23 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:23 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:23 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:23 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:23 volumio2 volumio[1220]: info: [1767082223072] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:23 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=debug msg="resolved context of track" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:23 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:4IZawwie57u00LxKWVhAop","uri":"spotify:track:4IZawwie57u00LxKWVhAop","play_origin":"go-librespot"}} Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=debug msg="selected format OGG_VORBIS_160 (76f1e05ac8ec4675b613fb95d9bcc69c65209409)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=debug msg="requested aes key for file 76f1e05ac8ec4675b613fb95d9bcc69c65209409, gid: 4IZawwie57u00LxKWVhAop" Dec 30 09:10:23 volumio2 go-librespot[1800]: time="2025-12-30T09:10:23+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4IZawwie57u00LxKWVhAop: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:23 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:34 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::ClearQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::clearPlayQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:34 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::play index 20 Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:34 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:34 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:34 volumio2 volumio[1220]: info: Exploding uri spotify:track:1EZrNbsDGK4mTUxdH8LI9C in service spop Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:34 volumio2 volumio[1220]: info: Exploding uri spotify:track:0bKJvobHkOTC2xt5TUQRDG in service spop Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:34 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:34 volumio2 volumio[1220]: info: Exploding uri spotify:track:73uQbPb3F75FG7zC6Htszn in service spop Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: EXPLODING URI:spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 20 Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 20 Dec 30 09:10:34 volumio2 volumio[1220]: info: [1767082234543] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:34 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=debug msg="resolved context of track" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","play_origin":"go-librespot"}} Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=debug msg="selected format OGG_VORBIS_160 (a8d304a2083e9dd02443b62349bc3f66e4615925)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=debug msg="requested aes key for file a8d304a2083e9dd02443b62349bc3f66e4615925, gid: 1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1EZrNbsDGK4mTUxdH8LI9C","service":"spop","name":"Ice Cold Angel","artist":"DO Passion","album":"Ice Cold Angel","type":"song","duration":221,"albumart":"https://i.scdn.co/image/ab67616d0000b273bc15be0632ad10c4e9aea21e","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:34 volumio2 go-librespot[1800]: time="2025-12-30T09:10:34+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1fwUr7AoiR7nbchvC5s7ul: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:34 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:73uQbPb3F75FG7zC6Htszn","service":"spop","name":"Hello","artist":"Joy","album":"TOUCH BY TOUCH - HIT-MIX","type":"song","duration":292,"albumart":"https://i.scdn.co/image/ab67616d0000b27371aa15f4940108aed85903f9","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:34 volumio2 volumio[1220]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0bKJvobHkOTC2xt5TUQRDG","service":"spop","name":"Lovers in the Sand","artist":"Bad Boys Blue","album":"My Blue World","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b2734084be02f4ac6e6ac4225f89","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:34 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:34 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:36 volumio2 go-librespot[1800]: time="2025-12-30T09:10:36+01:00" level=trace msg="received accesspoint ping" Dec 30 09:10:36 volumio2 go-librespot[1800]: time="2025-12-30T09:10:36+01:00" level=trace msg="received accesspoint pong ack" Dec 30 09:10:36 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::ClearQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::clearPlayQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:36 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::play index 20 Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:36 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:36 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:36 volumio2 volumio[1220]: info: Using cached record of: spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 20 Dec 30 09:10:36 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:36 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 20 Dec 30 09:10:36 volumio2 volumio[1220]: info: [1767082236875] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:36 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:36 volumio2 go-librespot[1800]: time="2025-12-30T09:10:36+01:00" level=debug msg="resolved context of track" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:36 volumio2 go-librespot[1800]: time="2025-12-30T09:10:36+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:36 volumio2 go-librespot[1800]: time="2025-12-30T09:10:36+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:37 volumio2 go-librespot[1800]: time="2025-12-30T09:10:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:37 volumio2 go-librespot[1800]: time="2025-12-30T09:10:37+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:37 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","play_origin":"go-librespot"}} Dec 30 09:10:37 volumio2 go-librespot[1800]: time="2025-12-30T09:10:37+01:00" level=debug msg="selected format OGG_VORBIS_160 (a8d304a2083e9dd02443b62349bc3f66e4615925)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:37 volumio2 go-librespot[1800]: time="2025-12-30T09:10:37+01:00" level=debug msg="requested aes key for file a8d304a2083e9dd02443b62349bc3f66e4615925, gid: 1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:37 volumio2 go-librespot[1800]: time="2025-12-30T09:10:37+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1fwUr7AoiR7nbchvC5s7ul: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:37 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:37 volumio2 go-librespot[1800]: time="2025-12-30T09:10:37+01:00" level=trace msg="sent dealer ping" Dec 30 09:10:38 volumio2 go-librespot[1800]: time="2025-12-30T09:10:38+01:00" level=trace msg="received dealer pong" Dec 30 09:10:39 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:39 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:39 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:39 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 20 Dec 30 09:10:39 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:39 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 20 Dec 30 09:10:39 volumio2 volumio[1220]: info: [1767082239089] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:39 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=debug msg="resolved context of track" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:39 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","uri":"spotify:track:1fwUr7AoiR7nbchvC5s7ul","play_origin":"go-librespot"}} Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=debug msg="selected format OGG_VORBIS_160 (a8d304a2083e9dd02443b62349bc3f66e4615925)" uri="spotify:track:1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=debug msg="requested aes key for file a8d304a2083e9dd02443b62349bc3f66e4615925, gid: 1fwUr7AoiR7nbchvC5s7ul" Dec 30 09:10:39 volumio2 go-librespot[1800]: time="2025-12-30T09:10:39+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1fwUr7AoiR7nbchvC5s7ul: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:39 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:45 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::ClearQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::clearPlayQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:45 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::play index 0 Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:45 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5SepxuwxShK2VOVZ2QmdAH Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:40cKQPOcZczrvYYu3QMJ46 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5zWZ9iNevP0397xB3jWV2z Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7KkdYJqxvq4ZFq9gvFy06v Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:273uCXd7NPrInaiNqtkOrA Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2d8D7uk3tbAThjRkdfrx9c Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:69CuhJ2829Z4Uosm51woKp Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5FhRWxcqWIu3JoFS0kEPom Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1mscYl0vNlVknI51wOWDG7 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4TzIw4E4pca6Ai9P0P2q9R Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2ITgMuOLbDcc9TVEwIQMyW Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5ZYAuuGmA0Vf4FPOXT1lal Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7sos76tFGXoBgSpWbp7qZU Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6kk07URPWTiRzULynSOVrs Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0MSAWjq5aWfTUNL9hv7Epd Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:53PlbcGzLTx65vjaS6tG0N Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5aoYEKyeDmXIx9Qn28rm92 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1fwUr7AoiR7nbchvC5s7ul Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3wqDN5EqKsBPM3Otj9wp9N Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5q70qg9anaoP4MMkGnu354 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5ep8e1ZbIjtUajhcsskkpb Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4BeMBXhrJm1791r32174xH Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5074Vt992hKDNhwXMhRceJ Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1OHxngvqXwHljeAzbMuKXy Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7AaPeLJg5LE8SxqPR5Q3ZS Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1QEDM8Gwaf2MUyogGWV35v Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6nF5D6JNeOFTsMW612AZz4 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:6tsbXUca4RkFuB6TuHRA6T Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7rbV4H1PitZR99RCndrUhp Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3HWaSYU8Q3XNuJlF6nLrfq Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:7skyR8nK3vnDikYFBoUVw6 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:5WIRxVCM6E0CSAPILaZLAQ Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:76deK31HfF9eGANCWsRmDm Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1eddb9cfXiwt9EgAREpS34 Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:07qWGLDIFcy1u49i6KOSOk Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:252PdgFP3fefju8nMF8o4Q Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:50D2X5Hbv0iNhE16tsdiEz Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4MEadO3tY6PM6jksMMMkYY Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:08W9jxh8GZlYe9vIO7drlv Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:3lrnlYbfVdJ5FW8ySUFyOV Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4W3Iz3gGlzVHX4qHrWPP8u Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:49bme2iuBACRtC4Hjih4GU Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0Zezws6aRVofjz3pHrUScL Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:2ZSep9yW6E1cwDNXhRb1Qf Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:1EZrNbsDGK4mTUxdH8LI9C Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:0bKJvobHkOTC2xt5TUQRDG Dec 30 09:10:45 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:45 volumio2 volumio[1220]: info: Using cached record of: spotify:track:73uQbPb3F75FG7zC6Htszn Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:45 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:45 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:45 volumio2 volumio[1220]: info: [1767082245780] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:45 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=debug msg="resolved context of track" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:45 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:4IZawwie57u00LxKWVhAop","uri":"spotify:track:4IZawwie57u00LxKWVhAop","play_origin":"go-librespot"}} Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=debug msg="selected format OGG_VORBIS_160 (76f1e05ac8ec4675b613fb95d9bcc69c65209409)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:45 volumio2 go-librespot[1800]: time="2025-12-30T09:10:45+01:00" level=debug msg="requested aes key for file 76f1e05ac8ec4675b613fb95d9bcc69c65209409, gid: 4IZawwie57u00LxKWVhAop" Dec 30 09:10:46 volumio2 go-librespot[1800]: time="2025-12-30T09:10:46+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4IZawwie57u00LxKWVhAop: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:46 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:47 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::ClearQueue Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::clearPlayQueue Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::addQueueItems Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::addQueueItems Dec 30 09:10:47 volumio2 volumio[1220]: info: Preload queue cleared Dec 30 09:10:47 volumio2 volumio[1220]: info: Adding Item to queue: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:47 volumio2 volumio[1220]: info: Using cached record of: spotify:track:4IZawwie57u00LxKWVhAop Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPushQueue Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::saveQueue Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::updateTrackBlock Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::getTrackBlock Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreCommandRouter::volumioPlay Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::play index 0 Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::stop Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::play index undefined Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:47 volumio2 volumio[1220]: info: CoreStateMachine::startPlaybackTimer Dec 30 09:10:47 volumio2 volumio[1220]: info: CorePlayQueue::getTrack 0 Dec 30 09:10:47 volumio2 volumio[1220]: info: [1767082247991] ControllerSpotify::clearAddPlayTrack Dec 30 09:10:47 volumio2 volumio[1220]: info: Sending Spotify command with payload to local API: /player/play Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=debug msg="resolved context of track" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=trace msg="emitting websocket event: will_play" Dec 30 09:10:48 volumio2 volumio[1220]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:4IZawwie57u00LxKWVhAop","uri":"spotify:track:4IZawwie57u00LxKWVhAop","play_origin":"go-librespot"}} Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=debug msg="selected format OGG_VORBIS_160 (76f1e05ac8ec4675b613fb95d9bcc69c65209409)" uri="spotify:track:4IZawwie57u00LxKWVhAop" Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=debug msg="requested aes key for file 76f1e05ac8ec4675b613fb95d9bcc69c65209409, gid: 4IZawwie57u00LxKWVhAop" Dec 30 09:10:48 volumio2 go-librespot[1800]: time="2025-12-30T09:10:48+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4IZawwie57u00LxKWVhAop: failed retrieving audio key: failed retrieving aes key with code 1" Dec 30 09:10:48 volumio2 volumio[1220]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Dec 30 09:10:52 volumio2 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 30 09:10:53 volumio2 systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 30 09:10:53 volumio2 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 30 09:10:54 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 30 09:10:54 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 30 09:11:03 volumio2 volumio[1220]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 30 09:11:07 volumio2 go-librespot[1800]: time="2025-12-30T09:11:07+01:00" level=trace msg="sent dealer ping" Dec 30 09:11:08 volumio2 go-librespot[1800]: time="2025-12-30T09:11:08+01:00" level=trace msg="received dealer pong" Dec 30 09:11:37 volumio2 go-librespot[1800]: time="2025-12-30T09:11:37+01:00" level=trace msg="sent dealer ping" Dec 30 09:11:38 volumio2 go-librespot[1800]: time="2025-12-30T09:11:38+01:00" level=trace msg="received dealer pong" Dec 30 09:11:41 volumio2 volumio[1220]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 09:11:41 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 09:11:41 volumio2 volumio[1220]: info: Creating Spotify config file Dec 30 09:11:41 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 09:11:41 volumio2 volumio[1220]: info: Spotify config file written Dec 30 09:11:41 volumio2 sudo[5147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 09:11:41 volumio2 sudo[5147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 09:11:41 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 09:11:41 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 09:11:41 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:41 volumio2 volumio[1220]: info: Connection to go-librespot Websocket closed Dec 30 09:11:41 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:41 volumio2 go-librespot[5149]: go-librespot daemon starting... Dec 30 09:11:41 volumio2 sudo[5147]: pam_unix(sudo:session): session closed for user root Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="app state loaded" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=info msg="zeroconf server listening on port 38667" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="obtained new client token: AADX4nUprZQAhwT1k5dM4vV9yYzUl9GIvTOPFzUjtvT4jE5fahUWSdVhzSdU2BX3ky7vCfvwz43hghrMIfql6t+qzMqlGx9IhduVTTx+2+dX35gYIGIk5GPQW79njyLiBIYGsyVBe2h9TOOuaLCuaNZ6vh9p+20Ixb7QVqjqEb79Asx3QA55CsiCjbl4Vdb7xplseVXfOYTPOe8zSxGh+tzeaE0iROj75BzGixppDfVXxBeYh1mx/Anl" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="completed keyexchange" Dec 30 09:11:41 volumio2 go-librespot[5150]: time="2025-12-30T09:11:41+01:00" level=debug msg="completed challenge" Dec 30 09:11:42 volumio2 go-librespot[5150]: time="2025-12-30T09:11:42+01:00" level=info msg="authenticated AP" username="ra******73" Dec 30 09:11:42 volumio2 go-librespot[5150]: time="2025-12-30T09:11:42+01:00" level=info msg="authenticated Login5" username="ra******73" Dec 30 09:11:42 volumio2 go-librespot[5150]: time="2025-12-30T09:11:42+01:00" level=debug msg="initializing zeroconf session" username="ra******73" Dec 30 09:11:42 volumio2 volumio[1220]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 09:11:42 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 09:11:42 volumio2 volumio[1220]: info: Creating Spotify config file Dec 30 09:11:42 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 09:11:42 volumio2 volumio[1220]: info: Spotify config file written Dec 30 09:11:42 volumio2 sudo[5158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 09:11:42 volumio2 sudo[5158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 09:11:42 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 09:11:42 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 09:11:42 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:42 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:42 volumio2 go-librespot[5160]: go-librespot daemon starting... Dec 30 09:11:42 volumio2 sudo[5158]: pam_unix(sudo:session): session closed for user root Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=debug msg="app state loaded" Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 09:11:42 volumio2 go-librespot[5161]: time="2025-12-30T09:11:42+01:00" level=info msg="zeroconf server listening on port 43227" Dec 30 09:11:43 volumio2 go-librespot[5161]: time="2025-12-30T09:11:43+01:00" level=debug msg="obtained new client token: AAB5SSR3BLvmt8d/5HClpw5fQFe0uGKfmie7VnXF/hs8rJG+JSmzFU7t1q1PoDqItRHZ6qNQve67YAWl/DvhUQEEaxYeoArW2N4I/QXh8vgIhtMR3MFLmkHTrfpsU7mxv3wlqfKGIdnERYe2g+41+wh5xBdcJML71dyvWd6UhG9CN3dqqmDA758r96h/47Sa5g5jCrGarmTJA9/1Vm5kHA6fsk9DxyFT7Ok0+bTfDJ7afLHLYIWf/A==" Dec 30 09:11:43 volumio2 volumio[1220]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 09:11:43 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 09:11:43 volumio2 volumio[1220]: info: Creating Spotify config file Dec 30 09:11:43 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 09:11:43 volumio2 volumio[1220]: info: Spotify config file written Dec 30 09:11:43 volumio2 go-librespot[5161]: time="2025-12-30T09:11:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 30 09:11:43 volumio2 sudo[5169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 09:11:43 volumio2 sudo[5169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 09:11:43 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 09:11:43 volumio2 systemd[1]: go-librespot-daemon.service: Killing process 5163 (go-librespot) with signal SIGKILL. Dec 30 09:11:43 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 09:11:43 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:43 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:43 volumio2 go-librespot[5171]: go-librespot daemon starting... Dec 30 09:11:43 volumio2 sudo[5169]: pam_unix(sudo:session): session closed for user root Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="app state loaded" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=info msg="zeroconf server listening on port 34697" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="obtained new client token: AABDCu+ydwfdLRAuNY75KNGw62bsUNfZEaoC4FJmTsQ5FbP6ucbQia5zN3pcfeu/P9yP138vk5pWXVXBCuf9/9gpuxzVddfyo9OevGm4SYaH5FiknUWCKWt1+zl1RzXR/N+/hgW3Jw00AFPeMHSThutPrcjIHYm5ZTsRLxWrEfphIzX9y24ytwlF6jDT03dSSA2l6/w4dCXJ1x8A7ejMf/fRj9UjJApNHltxYo/zasP8rcC18hL6kVuX" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="completed keyexchange" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=debug msg="completed challenge" Dec 30 09:11:43 volumio2 go-librespot[5172]: time="2025-12-30T09:11:43+01:00" level=info msg="authenticated AP" username="ra******73" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=info msg="authenticated Login5" username="ra******73" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="initializing zeroconf session" username="ra******73" Dec 30 09:11:44 volumio2 volumio[1220]: info: Initializing connection to go-librespot Websocket Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="dealer connection opened" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=trace msg="starting accesspoint recv loop" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=trace msg="starting dealer recv loop" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=trace msg="received accesspoint ping" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="new websocket client" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="received connection id: MTNkYTMyMjQtYWEw...RTVDOTJDMjExMw==" Dec 30 09:11:44 volumio2 volumio[1220]: info: Connection to go-librespot Websocket established Dec 30 09:11:44 volumio2 volumio[1220]: info: go-librespot daemon successfully initialized Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=trace msg="received accesspoint pong ack" Dec 30 09:11:44 volumio2 go-librespot[5172]: time="2025-12-30T09:11:44+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 30 09:11:45 volumio2 volumio[1220]: info: go-librespot daemon successfully initialized Dec 30 09:11:45 volumio2 volumio[1220]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 09:11:45 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 09:11:45 volumio2 volumio[1220]: info: Creating Spotify config file Dec 30 09:11:45 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 09:11:45 volumio2 volumio[1220]: info: Spotify config file written Dec 30 09:11:45 volumio2 sudo[5194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 09:11:45 volumio2 sudo[5194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 09:11:45 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 09:11:45 volumio2 systemd[1]: go-librespot-daemon.service: Killing process 5175 (go-librespot) with signal SIGKILL. Dec 30 09:11:45 volumio2 volumio[1220]: info: Connection to go-librespot Websocket closed Dec 30 09:11:45 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 09:11:45 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:45 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:45 volumio2 go-librespot[5196]: go-librespot daemon starting... Dec 30 09:11:45 volumio2 sudo[5194]: pam_unix(sudo:session): session closed for user root Dec 30 09:11:45 volumio2 go-librespot[5197]: time="2025-12-30T09:11:45+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 09:11:45 volumio2 go-librespot[5197]: time="2025-12-30T09:11:45+01:00" level=debug msg="app state loaded" Dec 30 09:11:45 volumio2 go-librespot[5197]: time="2025-12-30T09:11:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 09:11:46 volumio2 go-librespot[5197]: time="2025-12-30T09:11:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 09:11:46 volumio2 go-librespot[5197]: time="2025-12-30T09:11:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 09:11:46 volumio2 go-librespot[5197]: time="2025-12-30T09:11:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 09:11:46 volumio2 go-librespot[5197]: time="2025-12-30T09:11:46+01:00" level=info msg="zeroconf server listening on port 38883" Dec 30 09:11:46 volumio2 volumio[1220]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 09:11:46 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 09:11:46 volumio2 volumio[1220]: info: Creating Spotify config file Dec 30 09:11:46 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 09:11:46 volumio2 volumio[1220]: info: Spotify config file written Dec 30 09:11:46 volumio2 volumio[1220]: info: go-librespot daemon successfully initialized Dec 30 09:11:46 volumio2 sudo[5205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 09:11:46 volumio2 sudo[5205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 09:11:46 volumio2 go-librespot[5197]: time="2025-12-30T09:11:46+01:00" level=debug msg="obtained new client token: AADUlmLrD9YGpiurDJ32CUkVzOTS3hWD/3m3Bu9IH1K5tXbZnFTs1Kl7GHflGWGyoqIEAzf4FNmtEAT60r2Spb+kmf+P4W09+kYdz3Mrq1I8kNHIPyOzFowKgL5+Ynt2shjwvU/SGT71spXtH4eoOJHKuH5K2LQFaEhRkDFXK60Kw3qvKqWnAXynRcbUAsXOQ81mdKenQ419+ihJWW586DDacnGpSFiVD9sVZXg8WtsERSPY6tpo/Psr" Dec 30 09:11:46 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 09:11:46 volumio2 systemd[1]: go-librespot-daemon.service: Killing process 5202 (n/a) with signal SIGKILL. Dec 30 09:11:46 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 09:11:46 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:46 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:46 volumio2 go-librespot[5207]: go-librespot daemon starting... Dec 30 09:11:46 volumio2 sudo[5205]: pam_unix(sudo:session): session closed for user root Dec 30 09:11:46 volumio2 go-librespot[5208]: time="2025-12-30T09:11:46+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 09:11:46 volumio2 go-librespot[5208]: time="2025-12-30T09:11:46+01:00" level=debug msg="app state loaded" Dec 30 09:11:46 volumio2 go-librespot[5208]: time="2025-12-30T09:11:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 09:11:46 volumio2 volumio[1220]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 09:11:46 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 09:11:46 volumio2 volumio[1220]: info: Creating Spotify config file Dec 30 09:11:46 volumio2 volumio[1220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 09:11:46 volumio2 volumio[1220]: info: Spotify config file written Dec 30 09:11:46 volumio2 sudo[5215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 09:11:46 volumio2 sudo[5215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 09:11:46 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 09:11:46 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 09:11:46 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:46 volumio2 systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Dec 30 09:11:46 volumio2 systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Dec 30 09:11:46 volumio2 systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Dec 30 09:11:46 volumio2 sudo[5215]: pam_unix(sudo:session): session closed for user root Dec 30 09:11:46 volumio2 volumio[1220]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Dec 30 09:11:46 volumio2 volumio[1220]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Dec 30 09:11:46 volumio2 volumio[1220]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Dec 30 09:11:46 volumio2 volumio[1220]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Dec 30 09:11:46 volumio2 volumio[1220]: followed by "systemctl start go-librespot-daemon.service" again. Dec 30 09:11:46 volumio2 volumio[1220]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Dec 30 09:11:46 volumio2 volumio[1220]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Dec 30 09:11:46 volumio2 volumio[1220]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Dec 30 09:11:46 volumio2 volumio[1220]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Dec 30 09:11:46 volumio2 volumio[1220]: followed by "systemctl start go-librespot-daemon.service" again. Dec 30 09:11:47 volumio2 volumio[1220]: info: Getting Spotify volume Dec 30 09:11:47 volumio2 volumio[1220]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 09:11:47 volumio2 volumio[1220]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 09:11:47 volumio2 volumio[1220]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 30 09:11:47 volumio2 volumio[1220]: errno: -111, Dec 30 09:11:47 volumio2 volumio[1220]: code: 'ECONNREFUSED', Dec 30 09:11:47 volumio2 volumio[1220]: syscall: 'connect', Dec 30 09:11:47 volumio2 volumio[1220]: address: '127.0.0.1', Dec 30 09:11:47 volumio2 volumio[1220]: port: 9879, Dec 30 09:11:47 volumio2 volumio[1220]: response: undefined Dec 30 09:11:47 volumio2 volumio[1220]: } Dec 30 09:11:47 volumio2 volumio[1220]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 09:11:47 volumio2 sudo[5231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 09:10' Dec 30 09:11:47 volumio2 sudo[5231]: 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"