Feb 18 20:47:58 volumio volumio[1229]: info: CorePlayQueue::getTrack 1 Feb 18 20:47:58 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:47:58 volumio volumio[1229]: info: Prefetching next song Feb 18 20:47:58 volumio volumio[1229]: info: [1771447678686] ControllerSpotify::prefetch Feb 18 20:47:58 volumio volumio[1229]: info: Sending Spotify command with payload to local API: /player/add_to_queue Feb 18 20:48:03 volumio volumio[1229]: info: CoreStateMachine::startPlaybackTimer Feb 18 20:48:03 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:03 volumio volumio[1229]: info: CoreStateMachine::pushState Feb 18 20:48:03 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:03 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 20:48:03 volumio volumio[1229]: info: CoreCommandRouter::volumioPushState Feb 18 20:48:03 volumio volumio5-onboarding[1520]: time=2026-02-18T20:48:03.725Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.51:49324 @ 0x2156db0" state=STATUS_STOPPED positionMs=500 volume=86 Feb 18 20:48:03 volumio volumio5-onboarding[1520]: time=2026-02-18T20:48:03.726Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.51:49324 @ 0x2156db0" id=spotify:track:7uPqgIr1ogZ0A4AJFDPtxS title="Milady - Remastered 1997" Feb 18 20:48:03 volumio volumio[1229]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 18 20:48:03 volumio volumio[1229]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 18 20:48:03 volumio volumio[1229]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 18 20:48:13 volumio volumio[1229]: info: Received OAUTH Data Feb 18 20:48:13 volumio volumio[1229]: info: Executing Spotify Oauth Login Feb 18 20:48:13 volumio volumio[1229]: info: Saving Spotify Refresh Token Feb 18 20:48:13 volumio sudo[3785]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 20:48:13 volumio sudo[3785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:13 volumio sudo[3785]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:13 volumio sudo[3787]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 20:48:13 volumio sudo[3787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:13 volumio sudo[3787]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:13 volumio volumio[1229]: verbose: New Socket.io Connection to 192.168.0.36 from 192.168.0.51 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::volumioGetVisibleSources Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:13 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 18 20:48:13 volumio volumio[1229]: info: Received Get System Info Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 18 20:48:13 volumio volumio[1229]: info: Discovery: Getting this device information Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:13 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:13 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:13 volumio volumio[1229]: info: Listing playlists Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: BQCOWdxfyGLgSucgaUVVozotYg2iS4g4Ow2FUjAGjtIbFdUxJfLXcYFbrydt6Z2lniMbp_bgGBjUHdx5AC6pGLju8VelvKVxT9yt1vX9KERgC8Nc3H1V_TpRv_M2WAgbD8rxFtpkM-YkQo2UdQI5ovAU_WbDxR3Ta71q8cp5m6HZVDh6W97PzhOCzPsskwq180Kpw1myJwQQIf0DAU5SyenrjE3cj5f_NFifgaw8W76Vj1mF4I3HGtS7SeYkSHIDyXYx7R-LNhfOfEUJsxi-FCrMuHQ339H0Ykm6QL78niDZGpWHVva6e1ktnLJH Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:13 volumio volumio[1229]: info: New Spotify access token = BQCOWdxfyGLgSucgaUVVozotYg2iS4g4Ow2FUjAGjtIbFdUxJfLXcYFbrydt6Z2lniMbp_bgGBjUHdx5AC6pGLju8VelvKVxT9yt1vX9KERgC8Nc3H1V_TpRv_M2WAgbD8rxFtpkM-YkQo2UdQI5ovAU_WbDxR3Ta71q8cp5m6HZVDh6W97PzhOCzPsskwq180Kpw1myJwQQIf0DAU5SyenrjE3cj5f_NFifgaw8W76Vj1mF4I3HGtS7SeYkSHIDyXYx7R-LNhfOfEUJsxi-FCrMuHQ339H0Ykm6QL78niDZGpWHVva6e1ktnLJH Feb 18 20:48:13 volumio volumio[1229]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: User informations: {"country":"CO","display_name":"Matteo","email":"matteo.zama@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ljsdachsz2tg3jhd3nm3wdemnq"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ljsdachsz2tg3jhd3nm3wdemnq","id":"31ljsdachsz2tg3jhd3nm3wdemnq","images":[],"product":"premium","type":"user","uri":"spotify:user:31ljsdachsz2tg3jhd3nm3wdemnq"} Feb 18 20:48:13 volumio volumio[1229]: info: Creating Spotify config file Feb 18 20:48:13 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:13 volumio volumio[1229]: info: Spotify config file written Feb 18 20:48:13 volumio sudo[3793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:48:13 volumio sudo[3793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:13 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:48:13 volumio volumio[1229]: info: Connection to go-librespot Websocket closed Feb 18 20:48:13 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:48:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:13 volumio go-librespot[3795]: go-librespot daemon starting... Feb 18 20:48:13 volumio sudo[3793]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:13 volumio go-librespot[3796]: time="2026-02-18T20:48:13Z" level=info msg="running go-librespot 0.6.2" Feb 18 20:48:13 volumio go-librespot[3796]: time="2026-02-18T20:48:13Z" level=debug msg="app state loaded" Feb 18 20:48:13 volumio go-librespot[3796]: time="2026-02-18T20:48:13Z" level=debug msg="stored credentials not found" Feb 18 20:48:13 volumio go-librespot[3796]: time="2026-02-18T20:48:13Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: BQDW0SW1xr4hhjw0OSJt1DDMDE4s9Ofu6Y9nBt5VyhVv9R3fI3MQMM0987LKlyN4IIMAlHcEDrooE3Cb6rokn0rMqDuQ22-kMOHLwg2FEiBOyHDLzJo98EmYqQUk6hKbl-e1OK5Rk1Sn6kHo8gUTTUelLyqX8qkXSQSrnpnKSEbcX68iOuXs33Fvfgg9Od4BBGXzFFIx0RPxSwUl6m5bN_99dYm_XZxHyt7HFaFSZWkALyTBDS1lmd26Sn8EQ0aSJMEOLVCG-yMm2hFm0vIDkOHUgPjdMJXwKadLr7cOqIdygnDZxlcGl-kejgE8 Feb 18 20:48:13 volumio volumio[1229]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 20:48:13 volumio volumio[1229]: info: New Spotify access token = BQDW0SW1xr4hhjw0OSJt1DDMDE4s9Ofu6Y9nBt5VyhVv9R3fI3MQMM0987LKlyN4IIMAlHcEDrooE3Cb6rokn0rMqDuQ22-kMOHLwg2FEiBOyHDLzJo98EmYqQUk6hKbl-e1OK5Rk1Sn6kHo8gUTTUelLyqX8qkXSQSrnpnKSEbcX68iOuXs33Fvfgg9Od4BBGXzFFIx0RPxSwUl6m5bN_99dYm_XZxHyt7HFaFSZWkALyTBDS1lmd26Sn8EQ0aSJMEOLVCG-yMm2hFm0vIDkOHUgPjdMJXwKadLr7cOqIdygnDZxlcGl-kejgE8 Feb 18 20:48:13 volumio volumio[1229]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=info msg="zeroconf server listening on port 46333" Feb 18 20:48:14 volumio volumio[1229]: SPOTIFY: User informations: {"country":"CO","display_name":"Matteo","email":"matteo.zama@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ljsdachsz2tg3jhd3nm3wdemnq"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ljsdachsz2tg3jhd3nm3wdemnq","id":"31ljsdachsz2tg3jhd3nm3wdemnq","images":[],"product":"premium","type":"user","uri":"spotify:user:31ljsdachsz2tg3jhd3nm3wdemnq"} Feb 18 20:48:14 volumio volumio[1229]: info: Spotify Successfully logged in Feb 18 20:48:14 volumio volumio[1229]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 20:48:14 volumio volumio[1229]: info: [1771447694035] CoreMusicLibrary::Adding element Spotify Feb 18 20:48:14 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 20:48:14 volumio volumio[1229]: Cannot find translation for source Spotify Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="obtained new client token: AACWXljaCIBemRfVz/5bUQ/0xbySK+GORHUi4ScK3Nqguia7vGuL6V6vXkTeZaN5HZYPoRpdBT8fAedqaMAPp7T26PG2J5HFcw77vAITCdApCxOw/DfoAeJiz0IGXohdTkT7fqBEUVB+UrMY0MdGhnBQSB+9LVLOCmrckqw7juaJkIEC7Zx84JnE51uQZ4s3xiyk2TrxKHsUc7qm0bHbI3S9s4CeVoLtAUYLOWLiM5YnP8/Amy6q" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="completed keyexchange" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="completed challenge" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=info msg="authenticated AP" username="31************************nq" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=info msg="authenticated Login5" username="31************************nq" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="stored credentials" username="31************************nq" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="initializing zeroconf session" username="31************************nq" Feb 18 20:48:14 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="dealer connection opened" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=trace msg="starting accesspoint recv loop" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=trace msg="starting dealer recv loop" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=trace msg="received accesspoint ping" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=debug msg="received connection id: ZDdmMGRhMmYtNDgw...NEM0RjVEMTAwNg==" Feb 18 20:48:14 volumio go-librespot[3796]: time="2026-02-18T20:48:14Z" level=trace msg="received accesspoint pong ack" Feb 18 20:48:15 volumio go-librespot[3796]: time="2026-02-18T20:48:15Z" level=debug msg="put connect state because NEW_DEVICE" Feb 18 20:48:15 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 18 20:48:15 volumio volumio[1229]: info: Received Get System Info Feb 18 20:48:15 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 18 20:48:15 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 18 20:48:15 volumio volumio[1229]: info: Discovery: Getting this device information Feb 18 20:48:15 volumio volumio[1229]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:15 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:15 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 18 20:48:16 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 18 20:48:16 volumio volumio[1229]: info: Received Get System Info Feb 18 20:48:16 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 18 20:48:16 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 18 20:48:16 volumio volumio[1229]: info: Discovery: Getting this device information Feb 18 20:48:16 volumio volumio[1229]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:16 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:16 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 18 20:48:16 volumio volumio[1229]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:16 volumio go-librespot[3796]: time="2026-02-18T20:48:16Z" level=debug msg="new websocket client" Feb 18 20:48:16 volumio volumio[1229]: info: Connection to go-librespot Websocket established Feb 18 20:48:16 volumio volumio[1229]: info: go-librespot daemon successfully initialized Feb 18 20:48:18 volumio volumio[1229]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 18 20:48:18 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 18 20:48:18 volumio volumio[1229]: info: Creating Spotify config file Feb 18 20:48:18 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:18 volumio volumio[1229]: info: Spotify config file written Feb 18 20:48:18 volumio sudo[3806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:48:18 volumio sudo[3806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:48:18 volumio systemd[1]: go-librespot-daemon.service: Killing process 3804 (go-librespot) with signal SIGKILL. Feb 18 20:48:18 volumio volumio[1229]: info: Connection to go-librespot Websocket closed Feb 18 20:48:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:48:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:18 volumio go-librespot[3808]: go-librespot daemon starting... Feb 18 20:48:18 volumio sudo[3806]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=info msg="running go-librespot 0.6.2" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=debug msg="app state loaded" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=info msg="zeroconf server listening on port 36813" Feb 18 20:48:18 volumio go-librespot[3809]: time="2026-02-18T20:48:18Z" level=debug msg="obtained new client token: AACfAU/6Re9vquw9TuQVCC1lRvvqZsoDt0YlRL/JbecDdckYw9tbxUG9h6VfArGNWHjRR5YmyhuWf2NEzpZjlKhAvBkpV0k5Ax7j8j22u2iTV9i2EzlCnpgR7uoGpT/igIYAXy6TGA/9OyAEKkkhuFVUe3n1zyCbUORDh5RJRHqP6dFwbtgNmUNGxs33Gh76rl1BF24TCGOTgJGldRoKv/EAp2cjs+pIZ9dbp9YrlHM9IBODUFkvfqg=" Feb 18 20:48:19 volumio go-librespot[3809]: time="2026-02-18T20:48:19Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 18 20:48:19 volumio go-librespot[3809]: time="2026-02-18T20:48:19Z" level=debug msg="completed keyexchange" Feb 18 20:48:19 volumio go-librespot[3809]: time="2026-02-18T20:48:19Z" level=debug msg="completed challenge" Feb 18 20:48:19 volumio go-librespot[3809]: time="2026-02-18T20:48:19Z" level=info msg="authenticated AP" username="31************************nq" Feb 18 20:48:19 volumio go-librespot[3809]: time="2026-02-18T20:48:19Z" level=info msg="authenticated Login5" username="31************************nq" Feb 18 20:48:19 volumio go-librespot[3809]: time="2026-02-18T20:48:19Z" level=debug msg="initializing zeroconf session" username="31************************nq" Feb 18 20:48:19 volumio volumio[1229]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 18 20:48:19 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 18 20:48:19 volumio volumio[1229]: info: Creating Spotify config file Feb 18 20:48:19 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:19 volumio volumio[1229]: info: Spotify config file written Feb 18 20:48:19 volumio sudo[3819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:48:19 volumio sudo[3819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:48:19 volumio systemd[1]: go-librespot-daemon.service: Killing process 3813 (go-librespot) with signal SIGKILL. Feb 18 20:48:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:48:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:19 volumio go-librespot[3821]: go-librespot daemon starting... Feb 18 20:48:19 volumio sudo[3819]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=info msg="running go-librespot 0.6.2" Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=debug msg="app state loaded" Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:19 volumio volumio[1229]: info: Getting Spotify volume Feb 18 20:48:19 volumio volumio[1229]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Feb 18 20:48:19 volumio volumio[1229]: info: CoreCommandRouter::volumioGetState Feb 18 20:48:19 volumio volumio[1229]: info: CorePlayQueue::getTrack 2 Feb 18 20:48:19 volumio volumio[1229]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 18 20:48:19 volumio volumio[1229]: info: Initializing connection to go-librespot Websocket Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=debug msg="new websocket client" Feb 18 20:48:19 volumio volumio[1229]: info: Connection to go-librespot Websocket established Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 20:48:19 volumio go-librespot[3823]: time="2026-02-18T20:48:19Z" level=info msg="zeroconf server listening on port 35237" Feb 18 20:48:19 volumio volumio[1229]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 18 20:48:19 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 18 20:48:19 volumio volumio[1229]: info: Creating Spotify config file Feb 18 20:48:19 volumio volumio[1229]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 20:48:19 volumio volumio[1229]: info: Spotify config file written Feb 18 20:48:19 volumio sudo[3833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 20:48:19 volumio sudo[3833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 20:48:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 20:48:19 volumio systemd[1]: go-librespot-daemon.service: Killing process 3826 (go-librespot) with signal SIGKILL. Feb 18 20:48:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 20:48:19 volumio volumio[1229]: info: Connection to go-librespot Websocket closed Feb 18 20:48:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:19 volumio volumio[1229]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:48:19 volumio volumio[1229]: Error: socket hang up Feb 18 20:48:19 volumio volumio[1229]: at connResetException (node:internal/errors:720:14) Feb 18 20:48:19 volumio volumio[1229]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 20:48:19 volumio volumio[1229]: at Socket.emit (node:events:526:35) Feb 18 20:48:19 volumio volumio[1229]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 20:48:19 volumio volumio[1229]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 20:48:19 volumio volumio[1229]: code: 'ECONNRESET', Feb 18 20:48:19 volumio volumio[1229]: response: undefined Feb 18 20:48:19 volumio volumio[1229]: } Feb 18 20:48:19 volumio volumio[1229]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 20:48:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 20:48:19 volumio sudo[3833]: pam_unix(sudo:session): session closed for user root Feb 18 20:48:19 volumio go-librespot[3835]: go-librespot daemon starting... Feb 18 20:48:19 volumio go-librespot[3847]: time="2026-02-18T20:48:19Z" level=info msg="running go-librespot 0.6.2" Feb 18 20:48:19 volumio go-librespot[3847]: time="2026-02-18T20:48:19Z" level=debug msg="app state loaded" Feb 18 20:48:20 volumio go-librespot[3847]: time="2026-02-18T20:48:20Z" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 20:48:20 volumio go-librespot[3847]: time="2026-02-18T20:48:20Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 18 20:48:20 volumio go-librespot[3847]: time="2026-02-18T20:48:20Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 18 20:48:20 volumio go-librespot[3847]: time="2026-02-18T20:48:20Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 18 20:48:20 volumio go-librespot[3847]: time="2026-02-18T20:48:20Z" level=info msg="zeroconf server listening on port 32935" Feb 18 20:48:20 volumio sudo[3859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 20:47' Feb 18 20:48:20 volumio sudo[3859]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"