Dec 25 14:01:00 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 25 14:01:00 volumio mpd[1441]: exception: No database Dec 25 14:01:02 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 24. Dec 25 14:01:02 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:02 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:02 volumio upmpdcli[2604]: Could not open config: /tmp/upmpdcli.conf Dec 25 14:01:02 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 25 14:01:02 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 25 14:01:04 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 25 14:01:04 volumio mpd[1441]: exception: No database Dec 25 14:01:07 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 14:01:07 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 25 14:01:08 volumio sudo[2622]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 14:01:08 volumio sudo[2622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:01:08 volumio sudo[2622]: pam_unix(sudo:session): session closed for user root Dec 25 14:01:08 volumio sudo[2624]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 14:01:08 volumio sudo[2624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:01:08 volumio sudo[2624]: pam_unix(sudo:session): session closed for user root Dec 25 14:01:08 volumio volumio[1181]: verbose: New Socket.io Connection to 10.0.20.51 from 192.168.69.48 UA: Mozilla/5.0 (Android 16; Mobile; rv:146.0) Gecko/146.0 Firefox/146.0 Engine version: 3 Transport: polling Total Clients: 9 Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetVisibleSources Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:01:08 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 14:01:08 volumio volumio[1181]: info: Received Get System Info Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:01:08 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:01:08 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:01:08 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:01:08 volumio volumio[1181]: info: Listing playlists Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 14:01:08 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 25 14:01:09 volumio volumio[1181]: info: CoreCommandRouter::volumioGetQueue Dec 25 14:01:09 volumio volumio[1181]: info: CoreStateMachine::getQueue Dec 25 14:01:09 volumio volumio[1181]: info: CorePlayQueue::getQueue Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 14:01:10 volumio volumio[1181]: info: Received Get System Info Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:01:10 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:01:10 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 14:01:10 volumio volumio[1181]: info: Received Get System Info Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:01:10 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:01:10 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:01:10 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:01:17 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 14:01:17 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 25 14:01:18 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 25. Dec 25 14:01:18 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:18 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:18 volumio upmpdcli[2644]: Could not open config: /tmp/upmpdcli.conf Dec 25 14:01:18 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 25 14:01:18 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 25 14:01:18 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 14:01:26 volumio volumio[1181]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 25 14:01:26 volumio volumio[1181]: info: Received Get System Version Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 14:01:26 volumio volumio[1181]: info: Received Get System Info Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:01:26 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:01:26 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:01:26 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:01:31 volumio volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 25 14:01:33 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 26. Dec 25 14:01:33 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:33 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:33 volumio upmpdcli[2664]: Could not open config: /tmp/upmpdcli.conf Dec 25 14:01:33 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 25 14:01:33 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 25 14:01:48 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 27. Dec 25 14:01:48 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:48 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:01:48 volumio upmpdcli[2694]: Could not open config: /tmp/upmpdcli.conf Dec 25 14:01:48 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 25 14:01:48 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 25 14:02:03 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28. Dec 25 14:02:03 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:02:03 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:02:03 volumio upmpdcli[2712]: Could not open config: /tmp/upmpdcli.conf Dec 25 14:02:03 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 25 14:02:03 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 25 14:02:13 volumio volumio[1181]: info: Received OAUTH Data Dec 25 14:02:13 volumio volumio[1181]: info: Executing Spotify Oauth Login Dec 25 14:02:13 volumio volumio[1181]: info: Saving Spotify Refresh Token Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: BQCYQJ_sqp6tAzZoIHxZwXxs2ACajwHJxRpZos2j6r4on0YMVZCC01ft308Irf2C5RJS8P1wGMQx5lZYIIexLpZuPahCt5OBAFQpi-1HQ2EzSiiFFng2HozhDfgmXu3nkeel9FToBXL4DoESbmNZQSx92c-B1tEqvnIo0-sUW9LH1wmXBCJoXQbLH4Tp_j6tx0k7DmB3TpN2x7MK6ZLt7LeTOeYWU1fd3UXNmytc9xVgOJNMUr-BDWEMhScKE4dXXz8KdEZeyD_3X620n5XzDhMEFIwwKza-SQgaObbJVb_wVWh2enZH3G5NMkRK Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 25 14:02:14 volumio volumio[1181]: info: New Spotify access token = BQCYQJ_sqp6tAzZoIHxZwXxs2ACajwHJxRpZos2j6r4on0YMVZCC01ft308Irf2C5RJS8P1wGMQx5lZYIIexLpZuPahCt5OBAFQpi-1HQ2EzSiiFFng2HozhDfgmXu3nkeel9FToBXL4DoESbmNZQSx92c-B1tEqvnIo0-sUW9LH1wmXBCJoXQbLH4Tp_j6tx0k7DmB3TpN2x7MK6ZLt7LeTOeYWU1fd3UXNmytc9xVgOJNMUr-BDWEMhScKE4dXXz8KdEZeyD_3X620n5XzDhMEFIwwKza-SQgaObbJVb_wVWh2enZH3G5NMkRK Dec 25 14:02:14 volumio volumio[1181]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 25 14:02:14 volumio sudo[2732]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 14:02:14 volumio sudo[2732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:14 volumio sudo[2732]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:14 volumio sudo[2734]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 14:02:14 volumio sudo[2734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:14 volumio sudo[2734]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:14 volumio volumio[1181]: verbose: New Socket.io Connection to 10.0.20.51 from 192.168.69.48 UA: Mozilla/5.0 (Android 16; Mobile; rv:146.0) Gecko/146.0 Firefox/146.0 Engine version: 3 Transport: polling Total Clients: 9 Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: User informations: {"country":"DE","display_name":"John","email":"neosteamlol@googlemail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31fryj377fyrnsyemqmbag6lbmni"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31fryj377fyrnsyemqmbag6lbmni","id":"31fryj377fyrnsyemqmbag6lbmni","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85ec86889569c9edf72f028060","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82ec86889569c9edf72f028060","width":64}],"product":"premium","type":"user","uri":"spotify:user:31fryj377fyrnsyemqmbag6lbmni"} Dec 25 14:02:14 volumio volumio[1181]: info: Creating Spotify config file Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 25 14:02:14 volumio volumio[1181]: info: Spotify config file written Dec 25 14:02:14 volumio sudo[2739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 14:02:14 volumio sudo[2739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:14 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 14:02:14 volumio systemd[1]: go-librespot-daemon.service: Killing process 2546 (go-librespot) with signal SIGKILL. Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 25 14:02:14 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 14:02:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:14 volumio volumio[1181]: info: Connection to go-librespot Websocket closed Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: BQBmsP_kJ2krvfOPk0TKjuSI7gqwYgig98_Xmc6pnlOjbqkfmu16UwwaaoE7YdR56NVWN8jKrs-_nd-7y3USkGUrhMFMgYYboqjrgUWK_Rm8oQDosYtH0dahzuMc1vIje1KQxBTruxBfsW8FeEYtA2c_a6K-EO6qBiyOg_Jl0r4MNNVYXn0FhybwU2-_P7BUCn0EvhWZtOt4iXdR9qxZ4wDa2eVTFy8xVPtkhxoYW9kSnsD2qOSs3Ok_dRJmv_B4Byo1QYS8c4PPKV5Y8OY2ux0Tvfa_2cJjeSvua4ieFEK_7vu6EHZVyxsiu26D Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 25 14:02:14 volumio volumio[1181]: info: New Spotify access token = BQBmsP_kJ2krvfOPk0TKjuSI7gqwYgig98_Xmc6pnlOjbqkfmu16UwwaaoE7YdR56NVWN8jKrs-_nd-7y3USkGUrhMFMgYYboqjrgUWK_Rm8oQDosYtH0dahzuMc1vIje1KQxBTruxBfsW8FeEYtA2c_a6K-EO6qBiyOg_Jl0r4MNNVYXn0FhybwU2-_P7BUCn0EvhWZtOt4iXdR9qxZ4wDa2eVTFy8xVPtkhxoYW9kSnsD2qOSs3Ok_dRJmv_B4Byo1QYS8c4PPKV5Y8OY2ux0Tvfa_2cJjeSvua4ieFEK_7vu6EHZVyxsiu26D Dec 25 14:02:14 volumio volumio[1181]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 25 14:02:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:14 volumio go-librespot[2741]: go-librespot daemon starting... Dec 25 14:02:14 volumio sudo[2739]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::volumioGetVisibleSources Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:14 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+01:00" level=info msg="running go-librespot 0.4.0" Dec 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+01:00" level=debug msg="app state loaded" Dec 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+01:00" level=debug msg="stored credentials not found" Dec 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 14:02:14 volumio volumio[1181]: info: Received Get System Info Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:02:14 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:14 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:14 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:14 volumio volumio[1181]: info: Listing playlists Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 14:02:14 volumio volumio[1181]: SPOTIFY: User informations: {"country":"DE","display_name":"John","email":"neosteamlol@googlemail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31fryj377fyrnsyemqmbag6lbmni"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31fryj377fyrnsyemqmbag6lbmni","id":"31fryj377fyrnsyemqmbag6lbmni","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85ec86889569c9edf72f028060","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82ec86889569c9edf72f028060","width":64}],"product":"premium","type":"user","uri":"spotify:user:31fryj377fyrnsyemqmbag6lbmni"} Dec 25 14:02:14 volumio volumio[1181]: info: Spotify Successfully logged in Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 25 14:02:14 volumio volumio[1181]: info: [1766667734902] CoreMusicLibrary::Adding element Spotify Dec 25 14:02:14 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 14:02:14 volumio volumio[1181]: Cannot find translation for source Jellyfin Dec 25 14:02:14 volumio volumio[1181]: Cannot find translation for source Spotify Dec 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+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 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+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 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+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 25 14:02:14 volumio go-librespot[2742]: time="2025-12-25T14:02:14+01:00" level=info msg="zeroconf server listening on port 39331" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="obtained new client token: AADt6weCV6Mc89Ceb44n1i1ZmJtkAFwOE6rEiNbpMUX4UV9xfA+jDLKgUtERG2SEBPzuz6aMg29XXBJjn8l0Z9BzPKAWTJgutqyHx7kMK9WwaTY5npOYs66RdCU+dNnt7Z6/xwCMc0yBOF5i+I6JbXuo7th/AiDd7iR5qIr+setbcblkDdM2NOtr0357w4Co519L9gFC+H4rqJLm5I8PQBmN5M/pOIM8w2Emy90Pwna73r75/kofM4q/" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="completed keyexchange" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="completed challenge" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=info msg="authenticated AP" username="31************************ni" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=info msg="authenticated Login5" username="31************************ni" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="stored credentials" username="31************************ni" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="initializing zeroconf session" username="31************************ni" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="dealer connection opened" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=trace msg="starting accesspoint recv loop" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=trace msg="starting dealer recv loop" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=trace msg="received accesspoint ping" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="received connection id: NzA1OTdkNzUtYTM3...NzZFNzVCQTVGNw==" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 25 14:02:15 volumio go-librespot[2742]: time="2025-12-25T14:02:15+01:00" level=trace msg="received accesspoint pong ack" Dec 25 14:02:16 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 14:02:16 volumio volumio[1181]: info: Received Get System Info Dec 25 14:02:16 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:02:16 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:02:16 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:02:16 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:16 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:16 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:02:16 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 25 14:02:17 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 14:02:17 volumio volumio[1181]: info: Received Get System Info Dec 25 14:02:17 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 14:02:17 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 14:02:17 volumio volumio[1181]: info: Discovery: Getting this device information Dec 25 14:02:17 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:17 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:17 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 14:02:17 volumio volumio[1181]: info: Initializing connection to go-librespot Websocket Dec 25 14:02:17 volumio volumio[1181]: info: Connection to go-librespot Websocket established Dec 25 14:02:17 volumio go-librespot[2742]: time="2025-12-25T14:02:17+01:00" level=debug msg="new websocket client" Dec 25 14:02:17 volumio volumio[1181]: info: go-librespot daemon successfully initialized Dec 25 14:02:19 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 29. Dec 25 14:02:19 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:02:19 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 25 14:02:19 volumio upmpdcli[2764]: Could not open config: /tmp/upmpdcli.conf Dec 25 14:02:19 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 25 14:02:19 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 25 14:02:20 volumio volumio[1181]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 25 14:02:20 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 25 14:02:20 volumio volumio[1181]: info: Creating Spotify config file Dec 25 14:02:20 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 14:02:20 volumio volumio[1181]: info: Spotify config file written Dec 25 14:02:20 volumio sudo[2766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 14:02:20 volumio sudo[2766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:20 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 14:02:20 volumio systemd[1]: go-librespot-daemon.service: Killing process 2745 (go-librespot) with signal SIGKILL. Dec 25 14:02:20 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 14:02:20 volumio volumio[1181]: info: Connection to go-librespot Websocket closed Dec 25 14:02:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:20 volumio go-librespot[2768]: go-librespot daemon starting... Dec 25 14:02:20 volumio sudo[2766]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=info msg="running go-librespot 0.4.0" Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=debug msg="app state loaded" Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 25 14:02:20 volumio volumio[1181]: info: Getting Spotify volume Dec 25 14:02:20 volumio volumio[1181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 25 14:02:20 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:20 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:20 volumio volumio[1181]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 25 14:02:20 volumio volumio[1181]: info: Initializing connection to go-librespot Websocket Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=debug msg="new websocket client" Dec 25 14:02:20 volumio volumio[1181]: info: Connection to go-librespot Websocket established Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+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 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+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 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+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 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=info msg="zeroconf server listening on port 36867" Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=debug msg="obtained new client token: AAD5wZZP1AuhGg1jZKKyKaKFM41x/TFYB95pUrtW/PcvVxQIpkcWNekZzRuDwsRHdyp+Duv6eC4EJ7SB4rV00tBo4BwDDWrxHnDOys5GTC/zScHPwFV3QncaLMpX2oLRZvhlbBSRBDykTgBAGF93O3CKJNRHXyR8CCZcaY4boejNu7hUxr2RL5brEUtbWk+NDaUnuMfxmOykcLc7Ctf6BEFLO5iQXz6gT9FvLR2KGJtRcwNb1lNZOF2BryM=" Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=debug msg="completed keyexchange" Dec 25 14:02:20 volumio go-librespot[2769]: time="2025-12-25T14:02:20+01:00" level=debug msg="completed challenge" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=info msg="authenticated AP" username="31************************ni" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=info msg="authenticated Login5" username="31************************ni" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="initializing zeroconf session" username="31************************ni" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="dealer connection opened" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=trace msg="starting accesspoint recv loop" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=trace msg="starting dealer recv loop" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=trace msg="received accesspoint ping" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 25 14:02:21 volumio volumio[1181]: info: Spotify volume: 100 Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="received connection id: NjQ4YTIyM2EtODYw...REZEOUYyNzYyMw==" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=trace msg="received accesspoint pong ack" Dec 25 14:02:21 volumio go-librespot[2769]: time="2025-12-25T14:02:21+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 25 14:02:21 volumio volumio[1181]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 25 14:02:21 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 25 14:02:21 volumio volumio[1181]: info: Creating Spotify config file Dec 25 14:02:21 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 14:02:21 volumio volumio[1181]: info: Spotify config file written Dec 25 14:02:21 volumio sudo[2777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 14:02:21 volumio sudo[2777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:21 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 14:02:21 volumio systemd[1]: go-librespot-daemon.service: Killing process 2772 (go-librespot) with signal SIGKILL. Dec 25 14:02:21 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 14:02:21 volumio volumio[1181]: info: Connection to go-librespot Websocket closed Dec 25 14:02:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:21 volumio go-librespot[2780]: go-librespot daemon starting... Dec 25 14:02:21 volumio sudo[2777]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:21 volumio go-librespot[2781]: time="2025-12-25T14:02:21+01:00" level=info msg="running go-librespot 0.4.0" Dec 25 14:02:21 volumio go-librespot[2781]: time="2025-12-25T14:02:21+01:00" level=debug msg="app state loaded" Dec 25 14:02:21 volumio go-librespot[2781]: time="2025-12-25T14:02:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+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 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+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 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+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 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=info msg="zeroconf server listening on port 44497" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="obtained new client token: AAAxeY11dP1KeSpsodIwlok0Vpj/6CHCzftyGXlAMCBrythNd+YeSVNIrK3nYqnn4M4hE2T7IwMvoTRAw+sI2HTX+FTL8mFTbBlLsAZCEHXwT1UeCY/J1d5xc1vgRP1JgL+1QtWzme+gwt2Fu7IlLe8WxS/HDP0oCdWFwCpp0h8XjICE4kbHuFDg7oeahOXFJ5XQuXKSpTGP6/1MMaOPODPDjHbn/EuRNokTtKUBCUTwAaQojPXEXYQ5" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="completed keyexchange" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="completed challenge" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=info msg="authenticated AP" username="31************************ni" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=info msg="authenticated Login5" username="31************************ni" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="initializing zeroconf session" username="31************************ni" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="dealer connection opened" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=trace msg="starting accesspoint recv loop" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=trace msg="starting dealer recv loop" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=trace msg="received accesspoint ping" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="received connection id: Y2ZkYWFlNzktYzA2...NzY1RUJERjdEMQ==" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=trace msg="received accesspoint pong ack" Dec 25 14:02:22 volumio go-librespot[2781]: time="2025-12-25T14:02:22+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 25 14:02:22 volumio volumio[1181]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 25 14:02:22 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 25 14:02:22 volumio volumio[1181]: info: Creating Spotify config file Dec 25 14:02:22 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 14:02:23 volumio volumio[1181]: info: Spotify config file written Dec 25 14:02:23 volumio sudo[2790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 14:02:23 volumio sudo[2790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Killing process 2788 (go-librespot) with signal SIGKILL. Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 14:02:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:23 volumio go-librespot[2792]: go-librespot daemon starting... Dec 25 14:02:23 volumio sudo[2790]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+01:00" level=info msg="running go-librespot 0.4.0" Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+01:00" level=debug msg="app state loaded" Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+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]" Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+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]" Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+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]" Dec 25 14:02:23 volumio volumio[1181]: info: go-librespot daemon successfully initialized Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+01:00" level=info msg="zeroconf server listening on port 43195" Dec 25 14:02:23 volumio volumio[1181]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 25 14:02:23 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 25 14:02:23 volumio volumio[1181]: info: Creating Spotify config file Dec 25 14:02:23 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 14:02:23 volumio volumio[1181]: info: Spotify config file written Dec 25 14:02:23 volumio go-librespot[2793]: time="2025-12-25T14:02:23+01:00" level=debug msg="obtained new client token: AAAYBasFnxhmOBKsg+uxk9lb5c6K98ohfV1b5XHw1KKtIOo4EThig6m0otwu7Zr8ecGhmhHDeUN2Jw9aeNO0i4u6ESK/Ss1hDZLZE9nielO3hBxqzgmugFLy6c0Z6kgz7dC5CzUQ7UXDI01yiN8erHDOJYAgZr7MTYePfD6RSkmmh6J916joWcrFVASqqqhoYaZ5HynN0dTVn6jjPp8YnnB0QgfvbUoSoADvFJjh7cMMGK3RPphK+MPdirk=" Dec 25 14:02:23 volumio sudo[2802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 14:02:23 volumio sudo[2802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Killing process 2800 (go-librespot) with signal SIGKILL. Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 14:02:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:23 volumio go-librespot[2804]: go-librespot daemon starting... Dec 25 14:02:23 volumio sudo[2802]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:23 volumio go-librespot[2805]: time="2025-12-25T14:02:23+01:00" level=info msg="running go-librespot 0.4.0" Dec 25 14:02:23 volumio go-librespot[2805]: time="2025-12-25T14:02:23+01:00" level=debug msg="app state loaded" Dec 25 14:02:23 volumio go-librespot[2805]: time="2025-12-25T14:02:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 25 14:02:23 volumio volumio[1181]: info: Getting Spotify volume Dec 25 14:02:23 volumio volumio[1181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 25 14:02:23 volumio volumio[1181]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 25 14:02:23 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 25 14:02:23 volumio volumio[1181]: info: Creating Spotify config file Dec 25 14:02:23 volumio volumio[1181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 14:02:23 volumio volumio[1181]: info: CoreCommandRouter::volumioGetState Dec 25 14:02:23 volumio volumio[1181]: info: CorePlayQueue::getTrack 0 Dec 25 14:02:23 volumio volumio[1181]: info: Spotify config file written Dec 25 14:02:23 volumio volumio[1181]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 25 14:02:23 volumio volumio[1181]: SPOTIFY: SPOTIFY VOLUME 100 Dec 25 14:02:23 volumio volumio[1181]: SPOTIFY: VOLUMIO VOLUME 86 Dec 25 14:02:23 volumio volumio[1181]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 25 14:02:23 volumio volumio[1181]: info: Setting Spotify Volume from Volumio: 86 Dec 25 14:02:23 volumio sudo[2812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 14:02:23 volumio sudo[2812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 14:02:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Killing process 2810 (go-librespot) with signal SIGKILL. Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 14:02:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Dec 25 14:02:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Dec 25 14:02:23 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Dec 25 14:02:23 volumio sudo[2812]: pam_unix(sudo:session): session closed for user root Dec 25 14:02:23 volumio volumio[1181]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 14:02:24 volumio volumio[1181]: Error: socket hang up Dec 25 14:02:24 volumio volumio[1181]: at connResetException (node:internal/errors:720:14) Dec 25 14:02:24 volumio volumio[1181]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 25 14:02:24 volumio volumio[1181]: at Socket.emit (node:events:526:35) Dec 25 14:02:24 volumio volumio[1181]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 25 14:02:24 volumio volumio[1181]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 25 14:02:24 volumio volumio[1181]: code: 'ECONNRESET', Dec 25 14:02:24 volumio volumio[1181]: response: undefined Dec 25 14:02:24 volumio volumio[1181]: } Dec 25 14:02:24 volumio volumio[1181]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 14:02:26 volumio sudo[2845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-25 14:01' Dec 25 14:02:26 volumio sudo[2845]: 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"