Feb 09 01:30:32 volumio volumio[7751]: info: Received OAUTH Data Feb 09 01:30:32 volumio volumio[7751]: info: Executing Spotify Oauth Login Feb 09 01:30:32 volumio volumio[7751]: info: Saving Spotify Refresh Token Feb 09 01:30:32 volumio volumio[7751]: info: New Spotify access tokenBQD91PDMJA... Feb 09 01:30:32 volumio volumio[7751]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 01:30:32 volumio volumio[7751]: SPOTIFY: User informations: {"country":"DE","display_name":"Marian Dinisoara","email":"marian90tm@yahoo.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/marian90tm"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/marian90tm","id":"marian90tm","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1230177727010301&height=300&width=300&ext=1773184846&hash=AT9uwlHSGBLJBkH8om8fv8sp","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1230177727010301&height=50&width=50&ext=1773184846&hash=AT_Km_xM2-aqh7yR0iUxTrvI","width":64}],"product":"premium","type":"user","uri":"spotify:user:marian90tm"} Feb 09 01:30:32 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:32 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:32 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:32 volumio sudo[14191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:32 volumio sudo[14191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:32 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:32 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:32 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.146s CPU time. Feb 09 01:30:32 volumio volumio[7751]: info: Connection to go-librespot Websocket closed Feb 09 01:30:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:32 volumio sudo[14191]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:32 volumio go-librespot[14194]: go-librespot daemon starting... Feb 09 01:30:32 volumio volumio[7751]: info: New Spotify access tokenBQCiSFSkkH... Feb 09 01:30:32 volumio volumio[7751]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 01:30:32 volumio go-librespot[14195]: time="2026-02-09T01:30:32+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 01:30:32 volumio go-librespot[14195]: time="2026-02-09T01:30:32+01:00" level=debug msg="app state loaded" Feb 09 01:30:32 volumio go-librespot[14195]: time="2026-02-09T01:30:32+01:00" level=debug msg="stored credentials not found" Feb 09 01:30:32 volumio go-librespot[14195]: time="2026-02-09T01:30:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 01:30:32 volumio volumio[7751]: SPOTIFY: User informations: {"country":"DE","display_name":"Marian Dinisoara","email":"marian90tm@yahoo.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/marian90tm"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/marian90tm","id":"marian90tm","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1230177727010301&height=300&width=300&ext=1773184846&hash=AT9uwlHSGBLJBkH8om8fv8sp","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1230177727010301&height=50&width=50&ext=1773184846&hash=AT_Km_xM2-aqh7yR0iUxTrvI","width":64}],"product":"premium","type":"user","uri":"spotify:user:marian90tm"} Feb 09 01:30:32 volumio volumio[7751]: info: Spotify Successfully logged in Feb 09 01:30:32 volumio volumio[7751]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 01:30:32 volumio volumio[7751]: info: [1770597032923] CoreMusicLibrary::Adding element Spotify Feb 09 01:30:32 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 01:30:32 volumio volumio[7751]: Cannot find translation for source Mixcloud Feb 09 01:30:32 volumio volumio[7751]: Cannot find translation for source YouTube Music Feb 09 01:30:32 volumio volumio[7751]: Cannot find translation for source SoundCloud Feb 09 01:30:32 volumio volumio[7751]: Cannot find translation for source Spotify Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+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-gew1.spotify.com:80]" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=info msg="zeroconf server listening on port 38645" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="obtained new client token: AAC7wYGZbkKDsOBnw9VR0bBAyXU43f8ycMLW6NYb0wP6R1WV0iWsvPN75/ZhIxpQRYWqBIJCVUULEVpf7WuWlvatEtaSPyJg+jXRE/AN31e811T2uInQSzL+fXNT+rhfFNDyGkHh2qVxgg60CAeAp7CDTc4XknUg8TNPaF8VB0Eq+Cqjn/8ofWPtveXNj3+jeGSMgTYHOVpCF9GC91UhgN7xv4ihE8M7kbaIuE1DeKuRLbkk/j9oOhG5" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="completed keyexchange" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="completed challenge" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=info msg="authenticated AP" username="ma******tm" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=info msg="authenticated Login5" username="ma******tm" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="stored credentials" username="ma******tm" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="initializing zeroconf session" username="ma******tm" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="dealer connection opened" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=trace msg="starting accesspoint recv loop" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=trace msg="starting dealer recv loop" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=trace msg="received accesspoint ping" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=debug msg="received connection id: ZDgzMzk3MjAtNGNl...NDE5MkRDRDQyQQ==" Feb 09 01:30:33 volumio go-librespot[14195]: time="2026-02-09T01:30:33+01:00" level=trace msg="received accesspoint pong ack" Feb 09 01:30:34 volumio go-librespot[14195]: time="2026-02-09T01:30:34+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 09 01:30:35 volumio volumio[7751]: info: Initializing connection to go-librespot Websocket Feb 09 01:30:35 volumio go-librespot[14195]: time="2026-02-09T01:30:35+01:00" level=debug msg="new websocket client" Feb 09 01:30:35 volumio volumio[7751]: info: Connection to go-librespot Websocket established Feb 09 01:30:35 volumio volumio[7751]: info: go-librespot daemon successfully initialized Feb 09 01:30:36 volumio sudo[14206]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 01:30:36 volumio sudo[14206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:36 volumio sudo[14206]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:36 volumio sudo[14208]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 01:30:36 volumio sudo[14208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:36 volumio sudo[14208]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:36 volumio volumio[7751]: verbose: New Socket.io Connection to 192.168.0.89 from 192.168.0.238 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::volumioGetVisibleSources Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:36 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 09 01:30:36 volumio volumio[7751]: info: Received Get System Info Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 09 01:30:36 volumio volumio[7751]: info: Discovery: Getting this device information Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:36 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:36 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:36 volumio volumio[7751]: info: Listing playlists Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 09 01:30:36 volumio volumio[7751]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 09 01:30:37 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 09 01:30:38 volumio volumio[7751]: info: Received Get System Info Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 09 01:30:38 volumio volumio[7751]: info: Discovery: Getting this device information Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:38 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 09 01:30:38 volumio volumio[7751]: info: Getting Spotify volume Feb 09 01:30:38 volumio volumio[7751]: info: Spotify volume: 100 Feb 09 01:30:38 volumio volumio[7751]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 09 01:30:38 volumio volumio[7751]: info: Initializing connection to go-librespot Websocket Feb 09 01:30:38 volumio go-librespot[14195]: time="2026-02-09T01:30:38+01:00" level=debug msg="new websocket client" Feb 09 01:30:38 volumio volumio[7751]: info: Connection to go-librespot Websocket established Feb 09 01:30:38 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:38 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:38 volumio volumio[7751]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 09 01:30:38 volumio volumio[7751]: SPOTIFY: SPOTIFY VOLUME 100 Feb 09 01:30:38 volumio volumio[7751]: SPOTIFY: VOLUMIO VOLUME 86 Feb 09 01:30:38 volumio volumio[7751]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 09 01:30:38 volumio volumio[7751]: info: Setting Spotify Volume from Volumio: 86 Feb 09 01:30:39 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 09 01:30:39 volumio volumio[7751]: info: Received Get System Info Feb 09 01:30:39 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 09 01:30:39 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 09 01:30:39 volumio volumio[7751]: info: Discovery: Getting this device information Feb 09 01:30:39 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:39 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:39 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 09 01:30:40 volumio volumio[7751]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Feb 09 01:30:40 volumio volumio[7751]: info: Sending Spotify command with payload to local API: /player/volume Feb 09 01:30:40 volumio go-librespot[14195]: time="2026-02-09T01:30:40+01:00" level=debug msg="update volume requested to 56360/65535" Feb 09 01:30:40 volumio go-librespot[14195]: time="2026-02-09T01:30:40+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 09 01:30:40 volumio go-librespot[14195]: time="2026-02-09T01:30:40+01:00" level=trace msg="emitting websocket event: volume" Feb 09 01:30:40 volumio volumio[7751]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Feb 09 01:30:40 volumio volumio[7751]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Feb 09 01:30:40 volumio volumio[7751]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Feb 09 01:30:40 volumio volumio[7751]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Feb 09 01:30:41 volumio volumio[7751]: info: Getting Spotify volume Feb 09 01:30:41 volumio volumio[7751]: info: Spotify volume: 86 Feb 09 01:30:41 volumio volumio[7751]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 09 01:30:41 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:41 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:41 volumio volumio[7751]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 09 01:30:46 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 09 01:30:50 volumio volumio[7751]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 09 01:30:50 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 09 01:30:50 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:50 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:50 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:50 volumio sudo[14241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:50 volumio sudo[14241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:50 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:50 volumio systemd[1]: go-librespot-daemon.service: Killing process 14204 (go-librespot) with signal SIGKILL. Feb 09 01:30:50 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:50 volumio volumio[7751]: info: Connection to go-librespot Websocket closed Feb 09 01:30:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:50 volumio volumio[7751]: info: Connection to go-librespot Websocket closed Feb 09 01:30:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:50 volumio go-librespot[14243]: go-librespot daemon starting... Feb 09 01:30:50 volumio sudo[14241]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+01:00" level=debug msg="app state loaded" Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+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]" Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+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]" Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+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]" Feb 09 01:30:50 volumio go-librespot[14244]: time="2026-02-09T01:30:50+01:00" level=info msg="zeroconf server listening on port 40137" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="obtained new client token: AADHwsmbQslewZH1uYi1D27JxYQlhDq3C98/gyaZsYsGnuD3hqwaOCYqQnivYVvHo9y7RlYjO9izf4k8fbvcUi/IJ8eN7P1ijztc+0IIY8lF4CL4lAZinglwVLFpEcRDIgDfAsH4KDRjeR8Lf/c7qrS9CLdoLri4Aj7p0sPZ9v9D8etRKjlYphg9Om3lzLH/Yhk1pCvL0ZrdMHJWf8xFj+06NbogDaNWy7Mf8H7ZYXiAdlSZtYbA7A==" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="completed keyexchange" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="completed challenge" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=info msg="authenticated AP" username="ma******tm" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=info msg="authenticated Login5" username="ma******tm" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="initializing zeroconf session" username="ma******tm" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="dealer connection opened" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=trace msg="starting accesspoint recv loop" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=trace msg="starting dealer recv loop" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=trace msg="received accesspoint ping" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="received connection id: MjcxMGJkZGItZWZm...NzFDQUVEOEFBNw==" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=trace msg="received accesspoint pong ack" Feb 09 01:30:51 volumio go-librespot[14244]: time="2026-02-09T01:30:51+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 09 01:30:52 volumio volumio[7751]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 09 01:30:52 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 09 01:30:52 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:52 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:52 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:52 volumio sudo[14254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:52 volumio sudo[14254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:52 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:52 volumio systemd[1]: go-librespot-daemon.service: Killing process 14249 (go-librespot) with signal SIGKILL. Feb 09 01:30:52 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:52 volumio go-librespot[14256]: go-librespot daemon starting... Feb 09 01:30:52 volumio sudo[14254]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=debug msg="app state loaded" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+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-gew1.spotify.com:80]" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=info msg="zeroconf server listening on port 34123" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=debug msg="obtained new client token: AAAjGrPn19V9hE4nsrmAeNhqcIeUgpkXNE9FZxKIN2ieqz/iOduZmAxB2woNqJbDJD4+q0nTsbFg3ph0PB5QkAvBZpJJaLI8qII7ty95FWDLCSqdLOcyxIQPuUgurR/lMXvwX7n+yX37y9+GMXt5dXTJd6htHq3FpGGkEbyTu8cbwWmqlQLLLiCwNsR1yNQXmWXv1qC5JWxmJNrUHjfjj7eB/oXUwXjOPpV1Ya7UWxHXjsBki2aseAKA" Feb 09 01:30:52 volumio go-librespot[14257]: time="2026-02-09T01:30:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="completed keyexchange" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="completed challenge" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=info msg="authenticated AP" username="ma******tm" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=info msg="authenticated Login5" username="ma******tm" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="initializing zeroconf session" username="ma******tm" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="dealer connection opened" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=trace msg="starting accesspoint recv loop" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=trace msg="starting dealer recv loop" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=trace msg="received accesspoint ping" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="received connection id: MjQ2YTVkMWMtMDIx...RjQ3QzlCOTVGRQ==" Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=trace msg="received accesspoint pong ack" Feb 09 01:30:53 volumio volumio[7751]: info: Initializing connection to go-librespot Websocket Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="new websocket client" Feb 09 01:30:53 volumio volumio[7751]: info: Connection to go-librespot Websocket established Feb 09 01:30:53 volumio volumio[7751]: info: go-librespot daemon successfully initialized Feb 09 01:30:53 volumio go-librespot[14257]: time="2026-02-09T01:30:53+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 09 01:30:53 volumio volumio[7751]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 09 01:30:53 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 09 01:30:53 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:53 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:53 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:53 volumio sudo[14268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:53 volumio sudo[14268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:53 volumio volumio[7751]: info: Connection to go-librespot Websocket closed Feb 09 01:30:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:53 volumio go-librespot[14270]: go-librespot daemon starting... Feb 09 01:30:53 volumio sudo[14268]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:53 volumio go-librespot[14271]: time="2026-02-09T01:30:53+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 01:30:53 volumio go-librespot[14271]: time="2026-02-09T01:30:53+01:00" level=debug msg="app state loaded" Feb 09 01:30:53 volumio go-librespot[14271]: time="2026-02-09T01:30:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 01:30:54 volumio go-librespot[14271]: time="2026-02-09T01:30:54+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]" Feb 09 01:30:54 volumio go-librespot[14271]: time="2026-02-09T01:30:54+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]" Feb 09 01:30:54 volumio go-librespot[14271]: time="2026-02-09T01:30:54+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]" Feb 09 01:30:54 volumio go-librespot[14271]: time="2026-02-09T01:30:54+01:00" level=info msg="zeroconf server listening on port 34693" Feb 09 01:30:54 volumio volumio[7751]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 09 01:30:54 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:54 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:54 volumio go-librespot[14271]: time="2026-02-09T01:30:54+01:00" level=debug msg="obtained new client token: AAC34BmpgWiJeWes9VY36Uno+VrAKnHslU+0t1AJe549PkFFJICrn6n60arkzaNxOKq+F9pJPhvQur9VXVUAm8JkDvq0LX41W5h6X1ZhV85XylyGAH1q1XIcmNJxCgDUxCrAfi3sOMbBlk1N6nLbs6OFtqcvnov3puB44C9En8oTijDA68UVPt5MP6PcqjHevCLPPYKp9g8oNn8awreYbtBMW4FI35ZHpHAa5uNfuegTjdIbzJJFMi2t" Feb 09 01:30:54 volumio sudo[14281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:54 volumio sudo[14281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:54 volumio go-librespot[14271]: time="2026-02-09T01:30:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 09 01:30:54 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:54 volumio systemd[1]: go-librespot-daemon.service: Killing process 14279 (go-librespot) with signal SIGKILL. Feb 09 01:30:54 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:54 volumio go-librespot[14283]: go-librespot daemon starting... Feb 09 01:30:54 volumio sudo[14281]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+01:00" level=debug msg="app state loaded" Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+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]" Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+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]" Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+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]" Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+01:00" level=info msg="zeroconf server listening on port 40727" Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 09 01:30:54 volumio volumio[7751]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 09 01:30:54 volumio volumio[7751]: info: Received Get System Version Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 01:30:54 volumio volumio[7751]: info: Received Get System Info Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 09 01:30:54 volumio volumio[7751]: info: Discovery: Getting this device information Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:54 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:54 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 09 01:30:54 volumio go-librespot[14285]: time="2026-02-09T01:30:54+01:00" level=debug msg="obtained new client token: AABLOaMrgnTa2JAowws01pb1I2Eg1UIKo0u0v89hljkHd+iSSr5hDSmSW46gtqpyrJf1cWU6y/Oqn2aGuw5h3uccVaiFJ+mtrHl667Ukeq/lOvfOSP0vPBnj8VofJeIxodSeAbZY3wJ/jSzcJ5DAd5AtD4/BVx8nSc3lRY98D+qLf92OGG0vCRKg144FIbfv/9/qMc7iaH530ASlrmhKgHO+9GMntIz45XA+pw79FMo4uHv+cF6DFV9V" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="completed keyexchange" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="completed challenge" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=info msg="authenticated AP" username="ma******tm" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=info msg="authenticated Login5" username="ma******tm" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="initializing zeroconf session" username="ma******tm" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="dealer connection opened" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=trace msg="starting accesspoint recv loop" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=trace msg="starting dealer recv loop" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=trace msg="received accesspoint ping" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="received connection id: YWY1NjY3ZDctOTE4...OUY5MzM1REM4Mw==" Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=trace msg="received accesspoint pong ack" Feb 09 01:30:55 volumio volumio[7751]: info: go-librespot daemon successfully initialized Feb 09 01:30:55 volumio go-librespot[14285]: time="2026-02-09T01:30:55+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 09 01:30:56 volumio volumio[7751]: info: Getting Spotify volume Feb 09 01:30:56 volumio volumio[7751]: info: Spotify volume: 100 Feb 09 01:30:56 volumio volumio[7751]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 09 01:30:56 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Feb 09 01:30:56 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Feb 09 01:30:56 volumio volumio[7751]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Feb 09 01:30:56 volumio volumio[7751]: SPOTIFY: SPOTIFY VOLUME 100 Feb 09 01:30:56 volumio volumio[7751]: SPOTIFY: VOLUMIO VOLUME 86 Feb 09 01:30:56 volumio volumio[7751]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 09 01:30:56 volumio volumio[7751]: info: Setting Spotify Volume from Volumio: 86 Feb 09 01:30:56 volumio volumio[7751]: info: Initializing connection to go-librespot Websocket Feb 09 01:30:56 volumio go-librespot[14285]: time="2026-02-09T01:30:56+01:00" level=debug msg="new websocket client" Feb 09 01:30:56 volumio volumio[7751]: info: Connection to go-librespot Websocket established Feb 09 01:30:56 volumio volumio[7751]: info: Initializing connection to go-librespot Websocket Feb 09 01:30:56 volumio go-librespot[14285]: time="2026-02-09T01:30:56+01:00" level=debug msg="new websocket client" Feb 09 01:30:56 volumio volumio[7751]: info: Connection to go-librespot Websocket established Feb 09 01:30:56 volumio volumio[7751]: info: go-librespot daemon successfully initialized Feb 09 01:30:57 volumio volumio[7751]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 09 01:30:57 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 09 01:30:57 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:57 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:57 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:57 volumio sudo[14295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:57 volumio sudo[14295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:57 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:57 volumio systemd[1]: go-librespot-daemon.service: Killing process 14289 (go-librespot) with signal SIGKILL. Feb 09 01:30:57 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:57 volumio volumio[7751]: info: Connection to go-librespot Websocket closed Feb 09 01:30:57 volumio volumio[7751]: info: Connection to go-librespot Websocket closed Feb 09 01:30:57 volumio volumio[7751]: info: go-librespot daemon successfully initialized Feb 09 01:30:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:57 volumio go-librespot[14297]: go-librespot daemon starting... Feb 09 01:30:57 volumio sudo[14295]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+01:00" level=debug msg="app state loaded" Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 01:30:57 volumio volumio[7751]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 09 01:30:57 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 09 01:30:57 volumio volumio[7751]: info: Creating Spotify config file Feb 09 01:30:57 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 01:30:57 volumio volumio[7751]: info: Spotify config file written Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+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]" Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+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]" Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+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]" Feb 09 01:30:57 volumio go-librespot[14298]: time="2026-02-09T01:30:57+01:00" level=info msg="zeroconf server listening on port 43595" Feb 09 01:30:57 volumio sudo[14308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 01:30:57 volumio sudo[14308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 01:30:57 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 01:30:57 volumio systemd[1]: go-librespot-daemon.service: Killing process 14299 (go-librespot) with signal SIGKILL. Feb 09 01:30:57 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 01:30:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:57 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Feb 09 01:30:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Feb 09 01:30:57 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Feb 09 01:30:57 volumio sudo[14308]: pam_unix(sudo:session): session closed for user root Feb 09 01:30:57 volumio volumio[7751]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 09 01:30:57 volumio volumio[7751]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 09 01:30:57 volumio volumio[7751]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 09 01:30:57 volumio volumio[7751]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 09 01:30:57 volumio volumio[7751]: followed by "systemctl start go-librespot-daemon.service" again. Feb 09 01:30:57 volumio volumio[7751]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 09 01:30:57 volumio volumio[7751]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 09 01:30:57 volumio volumio[7751]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 09 01:30:57 volumio volumio[7751]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 09 01:30:57 volumio volumio[7751]: followed by "systemctl start go-librespot-daemon.service" again. Feb 09 01:30:58 volumio volumio[7751]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Feb 09 01:30:58 volumio volumio[7751]: info: Sending Spotify command with payload to local API: /player/volume Feb 09 01:30:58 volumio volumio[7751]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 01:30:58 volumio volumio[7751]: info: Initializing connection to go-librespot Websocket Feb 09 01:30:58 volumio volumio[7751]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 01:30:59 volumio volumio[7751]: info: Getting Spotify volume Feb 09 01:30:59 volumio volumio[7751]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 01:30:59 volumio volumio[7751]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 01:30:59 volumio volumio[7751]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 01:30:59 volumio volumio[7751]: errno: -111, Feb 09 01:30:59 volumio volumio[7751]: code: 'ECONNREFUSED', Feb 09 01:30:59 volumio volumio[7751]: syscall: 'connect', Feb 09 01:30:59 volumio volumio[7751]: address: '127.0.0.1', Feb 09 01:30:59 volumio volumio[7751]: port: 9879, Feb 09 01:30:59 volumio volumio[7751]: response: undefined Feb 09 01:30:59 volumio volumio[7751]: } Feb 09 01:30:59 volumio volumio[7751]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 01:31:00 volumio sudo[14338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 01:30' Feb 09 01:31:00 volumio sudo[14338]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"