Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=info msg="zeroconf server listening on port 36889" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="obtained new client token: AACy8KIa/75AkNn1FQv5K+DFkm7/3nv1ZjigN/jCY47pEVQIzzwA3WloH6wmop+wcMGkHQHOwojI+4QEYQ4J1zHdtPe+MBUqZwbVcp1MHdMPvlogq8t4Us4xeiOEzZT9SwUoeNOXFs2uuC/2kPaNypXEiums4xq1K+wYz2WyYJoBKLf+Nj7l11JEKlTYKy0LO2Lrff3OP7pTxmpi+AfnOxEjAv2Rf+KsJMdxcSYufTU06JiPtxDQ8g==" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="completed keyexchange" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=debug msg="completed challenge" Dec 15 14:32:00 adminvascosilva go-librespot[11719]: time="2025-12-15T14:32:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:00 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:00 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "network"... Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Refreshing Cached IP Addresses Dec 15 14:32:00 adminvascosilva sudo[11727]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:32:00 adminvascosilva sudo[11727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "services"... Dec 15 14:32:00 adminvascosilva sudo[11727]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "alsa_controller"... Dec 15 14:32:00 adminvascosilva sudo[11729]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:32:00 adminvascosilva sudo[11729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:00 adminvascosilva sudo[11729]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:00 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "wizard"... Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "networkfs"... Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Starting Udev Watcher for removable devices Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Ignoring mount for partition: boot Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Ignoring mount for partition: volumio Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Ignoring mount for partition: volumio_data Dec 15 14:32:00 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "upnp"... Dec 15 14:32:00 adminvascosilva volumio[11691]: info: [1765809120965] Starting Upmpd Daemon Dec 15 14:32:00 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "my_music"... Dec 15 14:32:00 adminvascosilva volumio[11691]: info: Loading plugin "mpd"... Dec 15 14:32:01 adminvascosilva volumio[11691]: info: Plugin upnp_browser is not enabled Dec 15 14:32:01 adminvascosilva volumio[11691]: info: Loading plugin "alarm-clock"... Dec 15 14:32:01 adminvascosilva volumio[11691]: info: Plugin airplay_emulation is not enabled Dec 15 14:32:01 adminvascosilva volumio[11691]: info: Loading plugin "last_100"... Dec 15 14:32:01 adminvascosilva volumio[11691]: info: Loading plugin "webradio"... Dec 15 14:32:01 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:01] [connect] Successful connection Dec 15 14:32:02 adminvascosilva volumio[11691]: info: Loading plugin "i2s_dacs"... Dec 15 14:32:02 adminvascosilva volumio[11691]: info: I2S DAC not set, start Auto-detection Dec 15 14:32:02 adminvascosilva volumio[11691]: info: Loading plugin "volumiodiscovery"... Dec 15 14:32:02 adminvascosilva volumio[11691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:02 adminvascosilva volumio[11691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:02 adminvascosilva volumio[11691]: *** WARNING *** For more information see Dec 15 14:32:02 adminvascosilva volumio[11691]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:02 adminvascosilva volumio[11691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:02 adminvascosilva volumio[11691]: *** WARNING *** For more information see Dec 15 14:32:02 adminvascosilva node[11691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:02 adminvascosilva node[11691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:02 adminvascosilva node[11691]: *** WARNING *** For more information see Dec 15 14:32:02 adminvascosilva node[11691]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:02 adminvascosilva node[11691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:02 adminvascosilva node[11691]: *** WARNING *** For more information see Dec 15 14:32:02 adminvascosilva volumio[11691]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:32:02 adminvascosilva volumio[11691]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:32:02 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:32:02 adminvascosilva volumio[11691]: info: Loading plugin "spop"... Dec 15 14:32:03 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 15 14:32:03 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:03 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:03 adminvascosilva go-librespot[11762]: go-librespot daemon starting... Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=debug msg="app state loaded" Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:03 adminvascosilva volumio[11691]: info: Loading plugin "autostart"... Dec 15 14:32:03 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:03Z" level=info msg="zeroconf server listening on port 45735" Dec 15 14:32:04 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:04Z" level=debug msg="obtained new client token: AABYzjBYmFe4gWdDdZ2JQmdsHjFBG4o9s1JkuE6rt6VKrqwAVM94A8hOpWUuNyGcD2NRElEdG962OLQkayJJzZu3cbUQrtG/XP7RjLdxLpFvK+ybVCrav3rq8LENlooVVWBZjvxoD3+RUFczp6FauBN9tHddAvztm/VK8GVugGehlY+8R4jMO47ISgY7z8wPIGmQIX0FCbpCUajp5dv1RzQi/VYXsAAAm8IaNKB8p+kuyMvhG9U=" Dec 15 14:32:04 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:04 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:04Z" level=debug msg="completed keyexchange" Dec 15 14:32:04 adminvascosilva go-librespot[11763]: time="2025-12-15T14:32:04Z" level=debug msg="completed challenge" Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Applying required configuration parameters for plugin autostart Dec 15 14:32:04 adminvascosilva volumio[11691]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading plugin "outputs"... Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading plugin "albumart"... Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Plugin example_plugin is not enabled Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading plugin "inputs"... Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading plugin "updater_comm"... Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Plugin mpdemulation is not enabled Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading plugin "rest_api"... Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading plugin "websocket"... Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Loading i18n strings for locale pt Dec 15 14:32:04 adminvascosilva volumio[11691]: Updating browse sources language Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::initPlayerControls Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: Express server listening on port 3000 Dec 15 14:32:04 adminvascosilva volumio[11691]: [Metrics] WebUI: 6s 244.44ms Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::resetVolumioState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::getcurrentVolume Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:32:04 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809121 101 Dec 15 14:32:04 adminvascosilva volumio[11770]: Forking 3 albumart workers Dec 15 14:32:04 adminvascosilva volumio[11691]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 15 14:32:04 adminvascosilva volumio[11691]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::pushState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::updateTrackBlock Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrackBlock Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::pushState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::setRandom true Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreStateMachine::pushState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:04 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:04 adminvascosilva volumio[11691]: info: Setting Device type: Raspberry PI Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Reloading queue from file Dec 15 14:32:05 adminvascosilva volumio[11691]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreStateMachine::pushState Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Completed loading Core Plugins Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Preparing to generate the ALSA configuration file Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Discovery: Found device adminvascosilva Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Output device has changed, restarting MPD Dec 15 14:32:05 adminvascosilva volumio[11691]: info: ___________ START PLUGINS ___________ Dec 15 14:32:05 adminvascosilva volumio[11691]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Creating MPD Configuration file Dec 15 14:32:05 adminvascosilva sudo[11827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:32:05 adminvascosilva sudo[11827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:32:05 adminvascosilva volumio[11691]: info: [1765809125317] CoreMusicLibrary::Adding element Last_100 Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:32:05 adminvascosilva volumio[11691]: info: [1765809125334] CoreMusicLibrary::Adding element Webradio Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:05 adminvascosilva sudo[11829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:32:05 adminvascosilva sudo[11829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:05 adminvascosilva sudo[11827]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:05 adminvascosilva sudo[11831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:32:05 adminvascosilva sudo[11831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Initializing BBC Radios Dec 15 14:32:05 adminvascosilva sudo[11831]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:05 adminvascosilva sudo[11833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:32:05 adminvascosilva sudo[11833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:05 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:32:05 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:32:05 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:32:05 adminvascosilva systemd[1]: mpd.service: Consumed 3.852s CPU time. Dec 15 14:32:05 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:05 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:32:05 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Creating Spotify config file Dec 15 14:32:05 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:05 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:32:05 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:32:05 adminvascosilva sudo[11852]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:32:05 adminvascosilva sudo[11852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:32:05 adminvascosilva sudo[11852]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:05 adminvascosilva volumio[11691]: info: AutoStart - onStart Dec 15 14:32:05 adminvascosilva volumio[11691]: info: Volumio Calling Home Dec 15 14:32:06 adminvascosilva volumio[11691]: info: MPD Permissions set Dec 15 14:32:06 adminvascosilva volumio[11691]: info: MPD Permissions set Dec 15 14:32:06 adminvascosilva volumio[11691]: info: Spotify config file written Dec 15 14:32:06 adminvascosilva sudo[11859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:32:06 adminvascosilva sudo[11859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:06 adminvascosilva volumio[11691]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 15 14:32:06 adminvascosilva volumio[11691]: info: Volumio called home Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:32:06 adminvascosilva systemd[1]: go-librespot-daemon.service: Killing process 11766 (go-librespot) with signal SIGKILL. Dec 15 14:32:06 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:32:06 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:06 adminvascosilva volumio[11691]: info: No need to fix Spotify hosts Dec 15 14:32:06 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:06 adminvascosilva go-librespot[11871]: go-librespot daemon starting... Dec 15 14:32:06 adminvascosilva sudo[11859]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:06 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:06Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:06 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:06Z" level=debug msg="app state loaded" Dec 15 14:32:06 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:06Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:06 adminvascosilva volumio[11787]: Starting albumart workers Dec 15 14:32:06 adminvascosilva volumio[11788]: Starting albumart workers Dec 15 14:32:07 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:07 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:07 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:07 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:07Z" level=info msg="zeroconf server listening on port 40151" Dec 15 14:32:07 adminvascosilva volumio[11786]: Starting albumart workers Dec 15 14:32:07 adminvascosilva volumio[11691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:32:07 adminvascosilva volumio[11691]: SPOTIFY: BQB5mdASV63vaNRi0ZC7gDbtRdlk7V0ROgLkM7bqQc4vkREer4DN9cnsEXp6JPfmIMpXWhgskRx1ipUjhEf3Kwb923yMWwIhrkfkuS3CgOcNkVnO1OhUJ6UJ2L9HtxgHrERzsKtC7l2UsC5QmtWOZNmyz28U_y3DUK9eQI0eFUd5kmE0GPsuu28HxkGg6nz43W7gFdnRTAADUze3WP1YTlxEXVxW6r0Ud-FpkFt6_M8Wbv-dcT4owjTx4UNrHR7MQ7qzp7shSYulAtzZzkatCFKBH7og6cCS1GTAgQ Dec 15 14:32:07 adminvascosilva volumio[11691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:32:07 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:07Z" level=debug msg="obtained new client token: AADN5h7KUwWragp28pP0LQ4EO+/wHBmasWWe5wPSlld/hV4Sm2opbuGJ3+bEgsFx0Q9wp8vqdeMIMB7nWpWVnTZw9cStGeqd9PPYFFv0+zDcitysZty+4rjrqx8zqsfMEXCI1CJ8RLcJCPl/wTD8zHGS1So27DvqH6/xVBIeiMvDfXkc+2e/l3eSucD55NMG7ar6up+GLMqv//qG8KCkgk2bQ6nO6ETIx9qsQNVMQEUrUIPkS9s=" Dec 15 14:32:07 adminvascosilva volumio[11691]: info: New Spotify access token = BQB5mdASV63vaNRi0ZC7gDbtRdlk7V0ROgLkM7bqQc4vkREer4DN9cnsEXp6JPfmIMpXWhgskRx1ipUjhEf3Kwb923yMWwIhrkfkuS3CgOcNkVnO1OhUJ6UJ2L9HtxgHrERzsKtC7l2UsC5QmtWOZNmyz28U_y3DUK9eQI0eFUd5kmE0GPsuu28HxkGg6nz43W7gFdnRTAADUze3WP1YTlxEXVxW6r0Ud-FpkFt6_M8Wbv-dcT4owjTx4UNrHR7MQ7qzp7shSYulAtzZzkatCFKBH7og6cCS1GTAgQ Dec 15 14:32:07 adminvascosilva volumio[11691]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:32:07 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:07 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:07 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:07 adminvascosilva volumio[11691]: SPOTIFY: User informations: {"country":"PT","display_name":"happybrands","email":"geral@happybrands.pt","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/happybrands"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/happybrands","id":"happybrands","images":[],"product":"premium","type":"user","uri":"spotify:user:happybrands"} Dec 15 14:32:07 adminvascosilva volumio[11691]: info: Spotify Successfully logged in Dec 15 14:32:07 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:32:07 adminvascosilva volumio[11691]: info: [1765809127612] CoreMusicLibrary::Adding element Spotify Dec 15 14:32:07 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:07 adminvascosilva volumio[11691]: Cannot find translation for source Spotify Dec 15 14:32:08 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:08Z" level=debug msg="completed keyexchange" Dec 15 14:32:08 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:08Z" level=debug msg="completed challenge" Dec 15 14:32:08 adminvascosilva go-librespot[11872]: time="2025-12-15T14:32:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:09 adminvascosilva mpd[11854]: 2025-12-15T14:32:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:32:09 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:32:09 adminvascosilva sudo[11833]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:09 adminvascosilva sudo[11829]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:09 adminvascosilva volumio[11691]: info: Completed starting Core Plugins Dec 15 14:32:09 adminvascosilva volumio[11691]: info: ------------------------------------------- Dec 15 14:32:09 adminvascosilva volumio[11691]: info: ----- MyVolumio plugins startup ---- Dec 15 14:32:09 adminvascosilva volumio[11691]: info: ------------------------------------------- Dec 15 14:32:09 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:32:09 adminvascosilva volumio[11691]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:32:09 adminvascosilva volumio[11691]: assert.ok(self.idling) Dec 15 14:32:09 adminvascosilva volumio[11691]: error: The expression evaluated to a falsy value: Dec 15 14:32:09 adminvascosilva volumio[11691]: assert.ok(self.idling) Dec 15 14:32:09 adminvascosilva volumio[11691]: info: MPD running with PID11854 Dec 15 14:32:09 adminvascosilva volumio[11691]: ,establishing connection Dec 15 14:32:09 adminvascosilva volumio[11691]: error: updateQueue error: null Dec 15 14:32:09 adminvascosilva volumio[11691]: error: updateQueue error: null Dec 15 14:32:09 adminvascosilva volumio[11691]: info: go-librespot daemon successfully initialized Dec 15 14:32:10 adminvascosilva volumio[11691]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:32:10 adminvascosilva volumio[11691]: info: Discovery: Found device adminvascosilva Dec 15 14:32:10 adminvascosilva volumio[11691]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:10 adminvascosilva volumio[11691]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:11 adminvascosilva sudo[11917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:32:11 adminvascosilva sudo[11917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:11 adminvascosilva sudo[11919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:32:11 adminvascosilva sudo[11919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:11 adminvascosilva sudo[11917]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:11 adminvascosilva sudo[11919]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:11 adminvascosilva sudo[11921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:32:11 adminvascosilva sudo[11921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:11 adminvascosilva sudo[11921]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:11 adminvascosilva volumio[11691]: info: Upmpdcli Daemon Started Dec 15 14:32:11 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:32:11 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:11 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:11 adminvascosilva go-librespot[11927]: go-librespot daemon starting... Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=debug msg="app state loaded" Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 14:32:11 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:11Z" level=info msg="zeroconf server listening on port 45811" Dec 15 14:32:12 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:12Z" level=debug msg="obtained new client token: AAA9+m/Bu0uFhYSI4L2Gvom6yD5MX6bRQMPcovTJW7InWVjMvj6ujifOu6VveV2qmL6yxhai0etC9UDquiNvroU+e9De4lf70v5pQB7rSXLhuij4y53AxUh+A2wTMWqAkpPhsRHFkvbfKFvPFt33kmfTQg+G34OaTUnKFhA1rf7Rj6SeT2vFWtUtMTKPm/0Dfx5qDELHA3LkMEZqK3XiRpdnDZn1HmapVmz1DYTJlKTq/rgBAGQT2Q==" Dec 15 14:32:12 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:12Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:12 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:12Z" level=debug msg="completed keyexchange" Dec 15 14:32:12 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:12Z" level=debug msg="completed challenge" Dec 15 14:32:12 adminvascosilva go-librespot[11928]: time="2025-12-15T14:32:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:12 adminvascosilva sudo[11936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:32:12 adminvascosilva sudo[11936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:12 adminvascosilva sudo[11938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:32:12 adminvascosilva sudo[11938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:12 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:32:12 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:32:12 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:32:12 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:32:12 adminvascosilva sudo[11936]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:12 adminvascosilva sudo[11938]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:12 adminvascosilva mpd_monitor.sh[11941]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:32:12 adminvascosilva volumio[11691]: info: Successfully started MPD Monitor Dec 15 14:32:12 adminvascosilva volumio[11691]: info: Successfully started MPD Monitor Dec 15 14:32:12 adminvascosilva volumio[11691]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:12 adminvascosilva volumio[11691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:14 adminvascosilva volumio[11691]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:32:15 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:32:15 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:15 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:15 adminvascosilva go-librespot[11948]: go-librespot daemon starting... Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="app state loaded" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=info msg="zeroconf server listening on port 45131" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="obtained new client token: AABarq4ARP2rE+CZPHfpq/dY0RjB6Vn993yhezyVrSTfb1KACa9LX66T32OflOtKtbviWDhstybbkjyjikCDn0KOdRoCMjJLkeRDMwlm8a4tx9sHvPnUy+k+kd+T38ARcdE/oZFI1JIGntLCG75DUvH3yLBPoTpC+psLWnTgotuBSR9b4tJrxxzDYgcpdKVcKpJ8FlcEgNr3ApEyyDaqDvLgz8b300JyCy2CmH7b8jH31xM1Hcl4uQ==" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="completed keyexchange" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=debug msg="completed challenge" Dec 15 14:32:15 adminvascosilva go-librespot[11949]: time="2025-12-15T14:32:15Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:15 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:15 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:15 adminvascosilva volumio[11691]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:15 adminvascosilva volumio[11691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:32:17 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:32:18 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:32:18 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:32:18 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:18 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:18 adminvascosilva volumio[11691]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:32:18 adminvascosilva volumio[11691]: info: MyVolumio login type: Token Dec 15 14:32:18 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:32:18 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:32:19 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:32:19 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:19 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:19 adminvascosilva go-librespot[11960]: go-librespot daemon starting... Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="app state loaded" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=info msg="zeroconf server listening on port 36205" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="obtained new client token: AABIlXZbQKudcqWXZi2tgBroxwge0eUQnFMWrejP90eUXrKIbiA0WqumllgLO77XBZqQSUF/rlBctdA6sTPJZ7xnHQgQrSntK8K/47yzOYmD63OETkeTvmGoL8esjcy4BDnm2H9QHN7171n29HuRe0zoFwybRXzsjljQ05erpwb7pT7TncVQMX1MmLZm3E5X9PRL7qNCoNKiC3tMTiXuqfCmzN95qXyDw7u4q3avtjGRexZ3aakemg==" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="completed keyexchange" Dec 15 14:32:19 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:19Z" level=debug msg="completed challenge" Dec 15 14:32:19 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:32:19 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:32:19 adminvascosilva volumio[11691]: info: Streaming services startup Dec 15 14:32:19 adminvascosilva volumio[11691]: info: Starting Streaming Daemon Dec 15 14:32:19 adminvascosilva sudo[11970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:32:19 adminvascosilva sudo[11970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:19 adminvascosilva volumio[11691]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:32:19 adminvascosilva sudo[11970]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:20 adminvascosilva volumio[11691]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:20 adminvascosilva volumio[11691]: error: Cannot start Volumio Streaming Daemon Dec 15 14:32:20 adminvascosilva volumio[11691]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:32:20 adminvascosilva volumio[11691]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:32:20 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:20Z" level=debug msg="new websocket client" Dec 15 14:32:20 adminvascosilva volumio[11691]: info: Connection to go-librespot Websocket established Dec 15 14:32:20 adminvascosilva volumio[11691]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:32:21 adminvascosilva volumio[11691]: info: MyVolumio token set successfully Dec 15 14:32:21 adminvascosilva volumio[11691]: info: MYVOLUMIO: Adding device Dec 15 14:32:21 adminvascosilva volumio[11691]: info: MYVOLUMIO: Evaluating Server Dec 15 14:32:21 adminvascosilva go-librespot[11961]: time="2025-12-15T14:32:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:21 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:21 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Connection to go-librespot Websocket closed Dec 15 14:32:21 adminvascosilva volumio[11691]: info: MyVolumio status changed Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Streaming services startup Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Starting Streaming Daemon Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Removing audio output: Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Stoppping Tunnel 1 Dec 15 14:32:21 adminvascosilva sudo[12011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:32:21 adminvascosilva sudo[12011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:21 adminvascosilva sudo[12011]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:21 adminvascosilva sudo[12014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:32:21 adminvascosilva sudo[12014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:21 adminvascosilva volumio[11691]: error: Cannot start Volumio Streaming Daemon Dec 15 14:32:21 adminvascosilva volumio[11691]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:32:21 adminvascosilva volumio[11691]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:21 adminvascosilva sudo[12014]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Remote SSH Stopped Dec 15 14:32:21 adminvascosilva volumio[11691]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:32:21 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:21 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:21 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:22 adminvascosilva volumio[11691]: info: Successfully Added MyVolumio device Dec 15 14:32:22 adminvascosilva volumio[11691]: info: Updating MyVolumio device info Dec 15 14:32:22 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:22 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:22 adminvascosilva volumio[11691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:23 adminvascosilva volumio[11691]: info: Getting Spotify volume Dec 15 14:32:23 adminvascosilva volumio[11691]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:32:23 adminvascosilva volumio[11691]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:23 adminvascosilva volumio[11691]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 14:32:23 adminvascosilva volumio[11691]: errno: -111, Dec 15 14:32:23 adminvascosilva volumio[11691]: code: 'ECONNREFUSED', Dec 15 14:32:23 adminvascosilva volumio[11691]: syscall: 'connect', Dec 15 14:32:23 adminvascosilva volumio[11691]: address: '127.0.0.1', Dec 15 14:32:23 adminvascosilva volumio[11691]: port: 9879, Dec 15 14:32:23 adminvascosilva volumio[11691]: response: undefined Dec 15 14:32:23 adminvascosilva volumio[11691]: } Dec 15 14:32:23 adminvascosilva volumio[11691]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:32:23 adminvascosilva sudo[12030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:31' Dec 15 14:32:23 adminvascosilva sudo[12030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:24 adminvascosilva sudo[12030]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:24 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:32:24 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:32:24 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:24 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:32:24 adminvascosilva systemd[1]: volumio.service: Consumed 25.783s CPU time. Dec 15 14:32:24 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:32:24 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:32:24 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 30. Dec 15 14:32:24 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:32:24 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:32:24 adminvascosilva systemd[1]: volumio.service: Consumed 25.783s CPU time. Dec 15 14:32:24 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:32:24 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:32:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 14:32:24 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:24 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:24 adminvascosilva go-librespot[12057]: go-librespot daemon starting... Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=debug msg="app state loaded" Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:24 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:24Z" level=info msg="zeroconf server listening on port 42253" Dec 15 14:32:25 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:25Z" level=debug msg="obtained new client token: AAAKBVOcqKJ7WOcBxlW6QpPRikyFQE1vHlcKZZVf2ApYGGiCN6CPG2M4L4uwN49qr2N/htF9G0WzcYx+qujXGA21sSidX+UF/FSyhqH0KwEJgVaQkP9VeK7SwXGyRM+UyPMstpPg8MHDqQcY8l5B6bj1WsSc4iYZAxGOmhfHP6mY0V7t5cscDasUXbTx9KQ3fL8pUN4HW/sJwjsS3g72dnudIpoENQQjpxObTFRRnrPFka1WXQZUVg==" Dec 15 14:32:25 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:25Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:25 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:25Z" level=debug msg="completed keyexchange" Dec 15 14:32:25 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:25Z" level=debug msg="completed challenge" Dec 15 14:32:25 adminvascosilva go-librespot[12058]: time="2025-12-15T14:32:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:25 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:25 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:26 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:26 adminvascosilva volumio[12042]: info: ----- Volumio3 ---- Dec 15 14:32:26 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:26 adminvascosilva volumio[12042]: info: ----- System startup ---- Dec 15 14:32:26 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:27 adminvascosilva volumio[12042]: info: MYVOLUMIO Environment detected Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Plugin folders cleanup Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category audio_interface Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category miscellanea Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category music_service Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category plugins.json Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category system_controller Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category user_interface Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning into folder /data/plugins/ Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category music_service Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Scanning category system_controller Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Plugin folders cleanup completed Dec 15 14:32:27 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:27 adminvascosilva volumio[12042]: info: ----- Core plugins startup ---- Dec 15 14:32:27 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Loading plugins from folder /data/plugins/ Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Loading plugin "system"... Dec 15 14:32:27 adminvascosilva volumio[12042]: info: Loading plugin "appearance"... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "network"... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Refreshing Cached IP Addresses Dec 15 14:32:28 adminvascosilva sudo[12078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "services"... Dec 15 14:32:28 adminvascosilva sudo[12078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "alsa_controller"... Dec 15 14:32:28 adminvascosilva sudo[12078]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:28 adminvascosilva sudo[12080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:32:28 adminvascosilva sudo[12080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 14:32:28 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:28 adminvascosilva sudo[12080]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:28 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:28 adminvascosilva go-librespot[12096]: go-librespot daemon starting... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "wizard"... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "networkfs"... Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="app state loaded" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Starting Udev Watcher for removable devices Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Ignoring mount for partition: boot Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Ignoring mount for partition: volumio Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Ignoring mount for partition: volumio_data Dec 15 14:32:28 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "upnp"... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: [1765809148497] Starting Upmpd Daemon Dec 15 14:32:28 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "my_music"... Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "mpd"... Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=info msg="zeroconf server listening on port 36891" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="obtained new client token: AAAqsfdUDJikE/K4cE57q3f/eElkA2qvNuN5qnRZxm53V6JGN/3zOg83iLnwfoO8ctYO1kEyh0cLOhxLkSOhd6gRwfv457rHmA5OO7UBXfITeJu38VIQQBFfIbkJhT+IX9M1PFM1q52AffNp2G3/oFcj9QJIBNigtQzqwEM9RpDcM/JeZTC7rVp/i54rkOoM22R2BOSxERH0D3b8xsrtX/pm92hTEBXAZTHIoS8Hb/RS7GVIDZ8DzA==" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Plugin upnp_browser is not enabled Dec 15 14:32:28 adminvascosilva volumio[12042]: info: Loading plugin "alarm-clock"... Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="completed keyexchange" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=debug msg="completed challenge" Dec 15 14:32:28 adminvascosilva go-librespot[12109]: time="2025-12-15T14:32:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:29 adminvascosilva volumio[12042]: info: Plugin airplay_emulation is not enabled Dec 15 14:32:29 adminvascosilva volumio[12042]: info: Loading plugin "last_100"... Dec 15 14:32:29 adminvascosilva volumio[12042]: info: Loading plugin "webradio"... Dec 15 14:32:29 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:29] [connect] Successful connection Dec 15 14:32:30 adminvascosilva volumio[12042]: info: Loading plugin "i2s_dacs"... Dec 15 14:32:30 adminvascosilva volumio[12042]: info: I2S DAC not set, start Auto-detection Dec 15 14:32:30 adminvascosilva volumio[12042]: info: Loading plugin "volumiodiscovery"... Dec 15 14:32:30 adminvascosilva volumio[12042]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:30 adminvascosilva volumio[12042]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:30 adminvascosilva volumio[12042]: *** WARNING *** For more information see Dec 15 14:32:30 adminvascosilva volumio[12042]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:30 adminvascosilva volumio[12042]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:30 adminvascosilva volumio[12042]: *** WARNING *** For more information see Dec 15 14:32:30 adminvascosilva node[12042]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:30 adminvascosilva node[12042]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:30 adminvascosilva node[12042]: *** WARNING *** For more information see Dec 15 14:32:30 adminvascosilva node[12042]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:32:30 adminvascosilva node[12042]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:32:30 adminvascosilva node[12042]: *** WARNING *** For more information see Dec 15 14:32:30 adminvascosilva volumio[12042]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:32:30 adminvascosilva volumio[12042]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:32:30 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:32:30 adminvascosilva volumio[12042]: info: Loading plugin "spop"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "autostart"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Applying required configuration parameters for plugin autostart Dec 15 14:32:31 adminvascosilva volumio[12042]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "outputs"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "albumart"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Plugin example_plugin is not enabled Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "inputs"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "updater_comm"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Plugin mpdemulation is not enabled Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "rest_api"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading plugin "websocket"... Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:32:31 adminvascosilva volumio[12042]: info: Loading i18n strings for locale pt Dec 15 14:32:31 adminvascosilva volumio[12042]: Updating browse sources language Dec 15 14:32:31 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::initPlayerControls Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:32:32 adminvascosilva volumio[12042]: Express server listening on port 3000 Dec 15 14:32:32 adminvascosilva volumio[12042]: [Metrics] WebUI: 6s 188.93ms Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::resetVolumioState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::getcurrentVolume Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 14:32:32 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:32:32 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:32 adminvascosilva go-librespot[12133]: go-librespot daemon starting... Dec 15 14:32:32 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809149 101 Dec 15 14:32:32 adminvascosilva volumio[12119]: Forking 3 albumart workers Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="app state loaded" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:32 adminvascosilva volumio[12042]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 15 14:32:32 adminvascosilva volumio[12042]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::pushState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::updateTrackBlock Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrackBlock Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::pushState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::setRandom true Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::pushState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=info msg="zeroconf server listening on port 33485" Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Reloading queue from file Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Setting Device type: Raspberry PI Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="obtained new client token: AAD0PiN+6+5zHFkbMlW5fe9MMV2GpP78QboK5VrsL1uL3OVEVcjP5Qa7R8TgLwcawXRbN07gWtHWHgL8JH0XSIbY9TseLS/jfEA4D7hwxy9ZW6GBWYOjpnlmoWTxa5zf5Dv0drVEt8ZGbvLM26RX8+PVIC3euVHI3O1XE7A8iqPpvJHoBKttg278e/Fpn8jQ4CXgAlfc00VMJF5DDbUj+HmEfvOYaYGcUDxylPF4AKIwzEoywb1g/w==" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:32 adminvascosilva volumio[12042]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreStateMachine::pushState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioPushState Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="completed keyexchange" Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=debug msg="completed challenge" Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Discovery: Found device adminvascosilva Dec 15 14:32:32 adminvascosilva go-librespot[12135]: time="2025-12-15T14:32:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Completed loading Core Plugins Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Preparing to generate the ALSA configuration file Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Discovery: Found device adminvascosilva Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:32 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Output device has changed, restarting MPD Dec 15 14:32:32 adminvascosilva volumio[12042]: info: ___________ START PLUGINS ___________ Dec 15 14:32:32 adminvascosilva volumio[12042]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:32:32 adminvascosilva volumio[12042]: info: Creating MPD Configuration file Dec 15 14:32:32 adminvascosilva sudo[12188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:32:32 adminvascosilva sudo[12188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:33 adminvascosilva sudo[12188]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:33 adminvascosilva sudo[12190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:32:33 adminvascosilva sudo[12190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:32:33 adminvascosilva volumio[12042]: info: [1765809153014] CoreMusicLibrary::Adding element Last_100 Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:32:33 adminvascosilva volumio[12042]: info: [1765809153024] CoreMusicLibrary::Adding element Webradio Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:32:33 adminvascosilva sudo[12193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:32:33 adminvascosilva sudo[12193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:33 adminvascosilva volumio[12042]: info: Initializing BBC Radios Dec 15 14:32:33 adminvascosilva sudo[12193]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:33 adminvascosilva sudo[12195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:32:33 adminvascosilva sudo[12195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:33 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:32:33 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:32:33 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:32:33 adminvascosilva systemd[1]: mpd.service: Consumed 3.861s CPU time. Dec 15 14:32:33 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:32:33 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:32:33 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:33 adminvascosilva volumio[12042]: info: Creating Spotify config file Dec 15 14:32:33 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:33 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:32:33 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:32:33 adminvascosilva sudo[12213]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:32:33 adminvascosilva sudo[12213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:32:33 adminvascosilva sudo[12213]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:33 adminvascosilva volumio[12042]: info: AutoStart - onStart Dec 15 14:32:33 adminvascosilva volumio[12042]: info: Volumio Calling Home Dec 15 14:32:34 adminvascosilva volumio[12143]: Starting albumart workers Dec 15 14:32:34 adminvascosilva volumio[12140]: Starting albumart workers Dec 15 14:32:34 adminvascosilva volumio[12142]: Starting albumart workers Dec 15 14:32:34 adminvascosilva volumio[12042]: info: MPD Permissions set Dec 15 14:32:34 adminvascosilva volumio[12042]: info: MPD Permissions set Dec 15 14:32:34 adminvascosilva volumio[12042]: info: Spotify config file written Dec 15 14:32:34 adminvascosilva sudo[12221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:32:34 adminvascosilva sudo[12221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:34 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:34 adminvascosilva volumio[12042]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 15 14:32:34 adminvascosilva volumio[12042]: info: Volumio called home Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva go-librespot[12223]: go-librespot daemon starting... Dec 15 14:32:34 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:34 adminvascosilva sudo[12221]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:34 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:34Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:34 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:34Z" level=debug msg="app state loaded" Dec 15 14:32:34 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:34Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:32:34 adminvascosilva volumio[12042]: info: No need to fix Spotify hosts Dec 15 14:32:34 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:34Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:32:34 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:34Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 14:32:34 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:34Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 14:32:35 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:35Z" level=info msg="zeroconf server listening on port 37493" Dec 15 14:32:35 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:35Z" level=debug msg="obtained new client token: AADrmCiRCWm5f3MbO5tXdRwFBif083DFgJrCQmoT/GNYt0nJEV65SHdxkmxJBL55tC4BoW7n1evtJUa6hzLZ+xy8/Y9pw0q6Lud2dl3ogANzq3gy8/IKT1Gv1YO6zMewNXhzUb+pwW/v5mrj4FL+9H5uSWDP0RMjlzvI3VVjfAxq+fzPCtwpHInkBCYZbAjEH/DEneVxuNRGzLKqeeJo88WMx9m9hUYK2SaWdcspDDrXP/nqEiE=" Dec 15 14:32:35 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:35 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:35Z" level=debug msg="completed keyexchange" Dec 15 14:32:35 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:35Z" level=debug msg="completed challenge" Dec 15 14:32:35 adminvascosilva go-librespot[12224]: time="2025-12-15T14:32:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:35 adminvascosilva volumio[12042]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:32:35 adminvascosilva volumio[12042]: SPOTIFY: BQD5c6q95f6ZLnrnAc4cEh2z7oWBy8Vb3N07oWLlBKBFS4ogTiHAmkAVcZUVlxxAZxYmh9FWxOcuF40MDSkH9s395tydbsBhDRJONclzS6gylmBzU7ef6WVfGgdNqqvaDVIlo1XrSTh3UILRMyT_pQ8taI16VLFsD3C-rlCg7-mvN2j4ZM67_7ojpj1nQDdXnHI-2F1DAD5YTcWCCQZKYbyEr93QkWFtlUiEhHoDmNd1ipSxK84lHzxmTN2OzG3tIJqjxX-ISltU_7ay43o5E1xUBx3VKn29w0nQbw Dec 15 14:32:35 adminvascosilva volumio[12042]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:32:35 adminvascosilva volumio[12042]: info: New Spotify access token = BQD5c6q95f6ZLnrnAc4cEh2z7oWBy8Vb3N07oWLlBKBFS4ogTiHAmkAVcZUVlxxAZxYmh9FWxOcuF40MDSkH9s395tydbsBhDRJONclzS6gylmBzU7ef6WVfGgdNqqvaDVIlo1XrSTh3UILRMyT_pQ8taI16VLFsD3C-rlCg7-mvN2j4ZM67_7ojpj1nQDdXnHI-2F1DAD5YTcWCCQZKYbyEr93QkWFtlUiEhHoDmNd1ipSxK84lHzxmTN2OzG3tIJqjxX-ISltU_7ay43o5E1xUBx3VKn29w0nQbw Dec 15 14:32:35 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:35 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:35 adminvascosilva volumio[12042]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:32:35 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:35 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:35 adminvascosilva volumio[12042]: SPOTIFY: User informations: {"country":"PT","display_name":"happybrands","email":"geral@happybrands.pt","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/happybrands"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/happybrands","id":"happybrands","images":[],"product":"premium","type":"user","uri":"spotify:user:happybrands"} Dec 15 14:32:35 adminvascosilva volumio[12042]: info: Spotify Successfully logged in Dec 15 14:32:35 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:32:35 adminvascosilva volumio[12042]: info: [1765809155540] CoreMusicLibrary::Adding element Spotify Dec 15 14:32:35 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:32:35 adminvascosilva volumio[12042]: Cannot find translation for source Spotify Dec 15 14:32:37 adminvascosilva mpd[12215]: 2025-12-15T14:32:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:32:37 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:32:37 adminvascosilva sudo[12195]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:37 adminvascosilva sudo[12190]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:37 adminvascosilva volumio[12042]: info: Completed starting Core Plugins Dec 15 14:32:37 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:37 adminvascosilva volumio[12042]: info: ----- MyVolumio plugins startup ---- Dec 15 14:32:37 adminvascosilva volumio[12042]: info: ------------------------------------------- Dec 15 14:32:37 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:32:37 adminvascosilva volumio[12042]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:32:37 adminvascosilva volumio[12042]: assert.ok(self.idling) Dec 15 14:32:37 adminvascosilva volumio[12042]: error: The expression evaluated to a falsy value: Dec 15 14:32:37 adminvascosilva volumio[12042]: assert.ok(self.idling) Dec 15 14:32:37 adminvascosilva volumio[12042]: info: MPD running with PID12215 Dec 15 14:32:37 adminvascosilva volumio[12042]: ,establishing connection Dec 15 14:32:37 adminvascosilva volumio[12042]: error: updateQueue error: null Dec 15 14:32:37 adminvascosilva volumio[12042]: error: updateQueue error: null Dec 15 14:32:38 adminvascosilva volumio[12042]: info: go-librespot daemon successfully initialized Dec 15 14:32:38 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 15 14:32:38 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:38 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:38 adminvascosilva go-librespot[12265]: go-librespot daemon starting... Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="app state loaded" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:38 adminvascosilva sudo[12287]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:32:38 adminvascosilva sudo[12287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:38 adminvascosilva sudo[12287]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:38 adminvascosilva sudo[12289]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:32:38 adminvascosilva sudo[12289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:38 adminvascosilva sudo[12289]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:38 adminvascosilva sudo[12292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:32:38 adminvascosilva sudo[12292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:38 adminvascosilva sudo[12292]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:38 adminvascosilva volumio[12042]: info: Upmpdcli Daemon Started Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=info msg="zeroconf server listening on port 40669" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="obtained new client token: AACvWA9OtMlr8AIOInW9XFV9jbtA8i7D4P2CbFwMGEN4q0Sig8eAaDfsYY3LrRtr8oP6MChqU+hy9b+NJje1a8L04HM7BVl2eJzab4DPwMXtFnoNJhjgzXouE4aOldvYHDW2BLveGOYCsojf9e2WgYBrKsvsSv3bxsQq5lJJrW1NmrbUJjnjftUIE5qJNhdArrUSifGQDsequMGsaJj/4n4WcHbnI/sTIUtAV/zZ/tZx2LlD76p+/w==" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="completed keyexchange" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=debug msg="completed challenge" Dec 15 14:32:38 adminvascosilva go-librespot[12268]: time="2025-12-15T14:32:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:38 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:38 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:40 adminvascosilva sudo[12299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:32:40 adminvascosilva sudo[12299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:40 adminvascosilva sudo[12301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:32:40 adminvascosilva sudo[12301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:40 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:32:40 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:32:40 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:32:40 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:32:40 adminvascosilva sudo[12299]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:40 adminvascosilva mpd_monitor.sh[12304]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:32:40 adminvascosilva volumio[12042]: info: Successfully started MPD Monitor Dec 15 14:32:40 adminvascosilva sudo[12301]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:40 adminvascosilva volumio[12042]: info: Successfully started MPD Monitor Dec 15 14:32:41 adminvascosilva volumio[12042]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:41 adminvascosilva volumio[12042]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:41 adminvascosilva systemd[1]: Starting volumio-keepalive.service - Volumio KeepAlive (start playback if stopped)... Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioGetState Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:41 adminvascosilva volumio[12042]: info: Dec 15 14:32:41 adminvascosilva volumio[12042]: ---------------------------- Client requests Volumio play Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioPlay Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CoreStateMachine::play index undefined Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:32:41 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:41 adminvascosilva volumio[12042]: info: [1765809161703] ControllerSpotify::clearAddPlayTrack Dec 15 14:32:41 adminvascosilva volumio[12042]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:32:41 adminvascosilva volumio[12042]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:41 adminvascosilva systemd[1]: volumio-keepalive.service: Deactivated successfully. Dec 15 14:32:41 adminvascosilva systemd[1]: Finished volumio-keepalive.service - Volumio KeepAlive (start playback if stopped). Dec 15 14:32:42 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 15 14:32:42 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:42 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:42 adminvascosilva go-librespot[12322]: go-librespot daemon starting... Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="app state loaded" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:42 adminvascosilva volumio[12042]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=info msg="zeroconf server listening on port 34627" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="obtained new client token: AABZGk4rgCHaPmrWwveYvB6JyazHQnm/tSIqbr0FzfayiU7ldI811EZecWjDXjvfbG87IFQk6kLJi90bvWdg2NAy62dxW9JHu4n7FiBK8mnmQCJ29Vg3zerQb36QmtiScNH+tRGqZxDo2QdVY/dOS5l9lwZXcJ36V6cACGDFnB6eD3eb0sGHrVBXNrqUoeKwdh230XNCcV2MVI1mAc4OJF44uTysLbXj7EDHvxuAUy6Jb64CCVf6Bg==" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="completed keyexchange" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=debug msg="completed challenge" Dec 15 14:32:42 adminvascosilva go-librespot[12323]: time="2025-12-15T14:32:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:42 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:42 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:44 adminvascosilva volumio[12042]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:44 adminvascosilva volumio[12042]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:32:45 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:32:45 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 15 14:32:45 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:45 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:45 adminvascosilva go-librespot[12330]: go-librespot daemon starting... Dec 15 14:32:45 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:45Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:45 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:45Z" level=debug msg="app state loaded" Dec 15 14:32:45 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:45Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=info msg="zeroconf server listening on port 45151" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="obtained new client token: AACVrjr7qxCcMyz9Xniz2ieoNmgg3r8SC5NI/K26NQG6m2ztNonKtbC+8nXwyeVaxkDK896ZheItSooWmPnGD6J838a1ZOgrKbI4kGT3lmZ7ZCt0NBxUJCypg+t/ZchUNt95l9n0sDmACBbS6pJIFcTYdy5KJWwbO2Yj72pYSU1BagraVIieNJQtESxcZyt+NQ4uAF5s+/mdXOOqWisQpPfwnQXbledY8u+0TLVT2hlLSjnLzq3sCg==" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="completed keyexchange" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=debug msg="completed challenge" Dec 15 14:32:46 adminvascosilva go-librespot[12331]: time="2025-12-15T14:32:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:46 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:32:46 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:32:46 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:46 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:46 adminvascosilva volumio[12042]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:32:46 adminvascosilva volumio[12042]: info: MyVolumio login type: Token Dec 15 14:32:46 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:32:46 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:32:47 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:32:47 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:32:47 adminvascosilva volumio[12042]: info: Streaming services startup Dec 15 14:32:47 adminvascosilva volumio[12042]: info: Starting Streaming Daemon Dec 15 14:32:47 adminvascosilva sudo[12339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:32:47 adminvascosilva sudo[12339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:47 adminvascosilva volumio[12042]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:32:47 adminvascosilva sudo[12339]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:47 adminvascosilva volumio[12042]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:47 adminvascosilva volumio[12042]: error: Cannot start Volumio Streaming Daemon Dec 15 14:32:47 adminvascosilva volumio[12042]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:32:47 adminvascosilva volumio[12042]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:32:47 adminvascosilva volumio[12042]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:48 adminvascosilva volumio[12042]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:32:48 adminvascosilva volumio[12042]: info: MyVolumio token set successfully Dec 15 14:32:48 adminvascosilva volumio[12042]: info: MYVOLUMIO: Adding device Dec 15 14:32:48 adminvascosilva volumio[12042]: info: MYVOLUMIO: Evaluating Server Dec 15 14:32:48 adminvascosilva volumio[12042]: info: MyVolumio status changed Dec 15 14:32:48 adminvascosilva volumio[12042]: info: Streaming services startup Dec 15 14:32:48 adminvascosilva volumio[12042]: info: Starting Streaming Daemon Dec 15 14:32:48 adminvascosilva volumio[12042]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:32:48 adminvascosilva volumio[12042]: info: Removing audio output: Dec 15 14:32:48 adminvascosilva volumio[12042]: info: Stoppping Tunnel 1 Dec 15 14:32:48 adminvascosilva sudo[12380]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:32:48 adminvascosilva sudo[12380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:48 adminvascosilva sudo[12380]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:48 adminvascosilva sudo[12383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:32:48 adminvascosilva sudo[12383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:48 adminvascosilva volumio[12042]: error: Cannot start Volumio Streaming Daemon Dec 15 14:32:48 adminvascosilva volumio[12042]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:32:48 adminvascosilva volumio[12042]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:32:48 adminvascosilva sudo[12383]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:48 adminvascosilva volumio[12042]: info: Remote SSH Stopped Dec 15 14:32:49 adminvascosilva volumio[12042]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:32:49 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:49 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:49 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:49 adminvascosilva volumio[12042]: info: Successfully Added MyVolumio device Dec 15 14:32:49 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 15 14:32:49 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:49 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:49 adminvascosilva go-librespot[12386]: go-librespot daemon starting... Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=debug msg="app state loaded" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=info msg="zeroconf server listening on port 41249" Dec 15 14:32:49 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:49Z" level=debug msg="obtained new client token: AAAFs4EytHhjDBhNAnL10YhvgRA48ED0Zqk7E5xDwdsXTVr+aHrX6pe0VnfjOHgcg9icQBCBsnFOYbG4Q+eUH1AISV9hB18IplHPDjN+HKz396p2R4AxOTxByVFxMWrRKsT7az60nXMp4EbD68QKljCqJWUPBZWJPJziVPRrU0vRmPLa4GlDwMajgjAS3OSDbyvku7Jb/C1vNmud2nctZzT+Dr4AndHfZ7jePszalu/5uvkVwnqM3w==" Dec 15 14:32:50 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:50Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:50 adminvascosilva volumio[12042]: info: Updating MyVolumio device info Dec 15 14:32:50 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:50 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:50 adminvascosilva volumio[12042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:32:50 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:50Z" level=debug msg="completed keyexchange" Dec 15 14:32:50 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:50Z" level=debug msg="completed challenge" Dec 15 14:32:50 adminvascosilva go-librespot[12387]: time="2025-12-15T14:32:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:50 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:50 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:50 adminvascosilva volumio[12042]: info: Successfully Updated MyVolumio device Dec 15 14:32:50 adminvascosilva volumio[12042]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:50 adminvascosilva volumio[12042]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 15 14:32:53 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:53 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:53 adminvascosilva go-librespot[12395]: go-librespot daemon starting... Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="app state loaded" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:53 adminvascosilva volumio[12042]: info: Initializing connection to go-librespot Websocket Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="new websocket client" Dec 15 14:32:53 adminvascosilva volumio[12042]: info: Connection to go-librespot Websocket established Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=info msg="zeroconf server listening on port 33805" Dec 15 14:32:53 adminvascosilva volumio[12042]: info: AutoStart - Plugin is starting Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioGetQueue Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::getQueue Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CorePlayQueue::getQueue Dec 15 14:32:53 adminvascosilva volumio[12042]: info: AutoStart - start playing Dec 15 14:32:53 adminvascosilva volumio[12042]: info: AutoStart - start playing with no specific position Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreCommandRouter::volumioPlay Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::play index 0 Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::stop Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::play index undefined Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:32:53 adminvascosilva volumio[12042]: info: CorePlayQueue::getTrack 0 Dec 15 14:32:53 adminvascosilva volumio[12042]: info: [1765809173677] ControllerSpotify::clearAddPlayTrack Dec 15 14:32:53 adminvascosilva volumio[12042]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="obtained new client token: AAB9nxwXAxS1sYbLRREYM3DisJG/lWZHWTsWvP6I6fDCJkx0ymye8GdkDg+SGkUmpVeN06HPR4g6bgS3d/oenRKiW8LQkVbD6nsUErl7ta7KcfFwRm1GoogrnmKUQhxh5jg2D/VL4Hh3NpJhaOirJ9ZOKe7uuMH7QUvgmEylulIEkaIuUVXxLd904JUfyMb7QhtaC/beu4OLUNLh0cb7qjac//fJb7I6XYV1b1ztSwTOGhFlveHLfw==" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="completed keyexchange" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=debug msg="completed challenge" Dec 15 14:32:53 adminvascosilva go-librespot[12396]: time="2025-12-15T14:32:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:53 adminvascosilva volumio[12042]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 15 14:32:53 adminvascosilva volumio[12042]: info: Connection to go-librespot Websocket closed Dec 15 14:32:56 adminvascosilva volumio[12042]: info: Getting Spotify volume Dec 15 14:32:56 adminvascosilva volumio[12042]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:32:56 adminvascosilva volumio[12042]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:32:56 adminvascosilva volumio[12042]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 14:32:56 adminvascosilva volumio[12042]: errno: -111, Dec 15 14:32:56 adminvascosilva volumio[12042]: code: 'ECONNREFUSED', Dec 15 14:32:56 adminvascosilva volumio[12042]: syscall: 'connect', Dec 15 14:32:56 adminvascosilva volumio[12042]: address: '127.0.0.1', Dec 15 14:32:56 adminvascosilva volumio[12042]: port: 9879, Dec 15 14:32:56 adminvascosilva volumio[12042]: response: undefined Dec 15 14:32:56 adminvascosilva volumio[12042]: } Dec 15 14:32:56 adminvascosilva volumio[12042]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:32:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 15 14:32:57 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:57 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:32:57 adminvascosilva go-librespot[12415]: go-librespot daemon starting... Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="app state loaded" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:32:57 adminvascosilva sudo[12425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:31' Dec 15 14:32:57 adminvascosilva sudo[12425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=info msg="zeroconf server listening on port 33287" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="obtained new client token: AAAQEVZJJsxlQM79XazwA7SoMbiWq/Kmj0+dn2k8QxDLTLMOEnLYh1RJgkxTSYgY1x/mlYXjJbT/Q4ZB2YELwIreS/CTsqOAFRGYcmoGOlNV/XTCYsE4QU7uGEFfvZUjfTjSpbPSV5n2zZdoPL285Mn/6GpVvR/mksl1OR8n9BR0WCjo7JUutxR/U5JOZJ030vE69VD2mXR4wvQpLE9AnZ1afLk+HoBxUBUlTiAYBLDtzMK8w/Qhqg==" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="completed keyexchange" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=debug msg="completed challenge" Dec 15 14:32:57 adminvascosilva go-librespot[12416]: time="2025-12-15T14:32:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:32:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:32:57 adminvascosilva sudo[12425]: pam_unix(sudo:session): session closed for user root Dec 15 14:32:57 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:57] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Dec 15 14:32:57 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:32:57] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Dec 15 14:32:57 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:32:57 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:32:57 adminvascosilva systemd[1]: volumio.service: Consumed 26.189s CPU time. Dec 15 14:32:57 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:32:57 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:32:58 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 31. Dec 15 14:32:58 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:32:58 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:32:58 adminvascosilva systemd[1]: volumio.service: Consumed 26.189s CPU time. Dec 15 14:32:58 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:32:58 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ----- Volumio3 ---- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ----- System startup ---- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: MYVOLUMIO Environment detected Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Plugin folders cleanup Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category audio_interface Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category miscellanea Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category music_service Dec 15 14:33:00 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 15 14:33:00 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category plugins.json Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category system_controller Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category user_interface Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning into folder /data/plugins/ Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category music_service Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Scanning category system_controller Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Plugin folders cleanup completed Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ----- Core plugins startup ---- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Loading plugins from folder /data/plugins/ Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Loading plugin "system"... Dec 15 14:33:00 adminvascosilva volumio[12437]: info: Loading plugin "appearance"... Dec 15 14:33:00 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:33:00 adminvascosilva go-librespot[12464]: go-librespot daemon starting... Dec 15 14:33:00 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:00Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:33:00 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:00Z" level=debug msg="app state loaded" Dec 15 14:33:00 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:00Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=info msg="zeroconf server listening on port 39565" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="obtained new client token: AAA82FYaL7dCmsZLvHL5rAOx5olldZ5hstV+w3czVK6phr2GghqpkhvZAbtlUCQRsxSnPXYBRWOZYoan1w36UoBekgKA2N5Joy9IXVtk+06Ljo9dBGg8OTzfz1E6gGdCrzVzVaKfuZtPYDoyNU7IoEZIt8+L0M1VngbVeESoWtXL0mgOJ1pTYN5ZmqpajkuI7lQyvU9ZUIK+4v3NFl8WxY+zg6KtQrunXLdRfVpM6ujMwkHIMU2v1g==" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="completed keyexchange" Dec 15 14:33:01 adminvascosilva go-librespot[12468]: time="2025-12-15T14:33:01Z" level=debug msg="completed challenge" Dec 15 14:33:01 adminvascosilva volumio[12437]: info: Loading plugin "network"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Refreshing Cached IP Addresses Dec 15 14:33:02 adminvascosilva sudo[12476]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "services"... Dec 15 14:33:02 adminvascosilva sudo[12476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "alsa_controller"... Dec 15 14:33:02 adminvascosilva sudo[12476]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:02 adminvascosilva sudo[12478]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:33:02 adminvascosilva sudo[12478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:02 adminvascosilva sudo[12478]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:02 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "wizard"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "networkfs"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Starting Udev Watcher for removable devices Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Ignoring mount for partition: boot Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Ignoring mount for partition: volumio Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Ignoring mount for partition: volumio_data Dec 15 14:33:02 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "upnp"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: [1765809182199] Starting Upmpd Daemon Dec 15 14:33:02 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "my_music"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "mpd"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Plugin upnp_browser is not enabled Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "alarm-clock"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Plugin airplay_emulation is not enabled Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "last_100"... Dec 15 14:33:02 adminvascosilva volumio[12437]: info: Loading plugin "webradio"... Dec 15 14:33:02 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:33:02] [connect] Successful connection Dec 15 14:33:03 adminvascosilva volumio[12437]: info: Loading plugin "i2s_dacs"... Dec 15 14:33:03 adminvascosilva volumio[12437]: info: I2S DAC not set, start Auto-detection Dec 15 14:33:04 adminvascosilva volumio[12437]: info: Loading plugin "volumiodiscovery"... Dec 15 14:33:04 adminvascosilva volumio[12437]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:33:04 adminvascosilva volumio[12437]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:33:04 adminvascosilva volumio[12437]: *** WARNING *** For more information see Dec 15 14:33:04 adminvascosilva volumio[12437]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:33:04 adminvascosilva volumio[12437]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:33:04 adminvascosilva volumio[12437]: *** WARNING *** For more information see Dec 15 14:33:04 adminvascosilva node[12437]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:33:04 adminvascosilva node[12437]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:33:04 adminvascosilva node[12437]: *** WARNING *** For more information see Dec 15 14:33:04 adminvascosilva node[12437]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 14:33:04 adminvascosilva node[12437]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:33:04 adminvascosilva node[12437]: *** WARNING *** For more information see Dec 15 14:33:04 adminvascosilva volumio[12437]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:33:04 adminvascosilva volumio[12437]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:33:04 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:33:04 adminvascosilva volumio[12437]: info: Loading plugin "spop"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "autostart"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Applying required configuration parameters for plugin autostart Dec 15 14:33:05 adminvascosilva volumio[12437]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "outputs"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "albumart"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Plugin example_plugin is not enabled Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "inputs"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "updater_comm"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Plugin mpdemulation is not enabled Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "rest_api"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading plugin "websocket"... Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Loading i18n strings for locale pt Dec 15 14:33:05 adminvascosilva volumio[12437]: Updating browse sources language Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::initPlayerControls Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: Express server listening on port 3000 Dec 15 14:33:05 adminvascosilva volumio[12437]: [Metrics] WebUI: 6s 197.98ms Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreStateMachine::resetVolumioState Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreStateMachine::getcurrentVolume Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:05 adminvascosilva volumio[12437]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:33:05 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:33:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809182 101 Dec 15 14:33:05 adminvascosilva volumio[12508]: Forking 3 albumart workers Dec 15 14:33:05 adminvascosilva volumio[12437]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 15 14:33:05 adminvascosilva volumio[12437]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreStateMachine::pushState Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioPushState Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreStateMachine::updateTrackBlock Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrackBlock Dec 15 14:33:05 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Reloading queue from file Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreStateMachine::pushState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioPushState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreStateMachine::setRandom true Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreStateMachine::pushState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioPushState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Setting Device type: Raspberry PI Dec 15 14:33:06 adminvascosilva volumio[12437]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreStateMachine::pushState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioPushState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Completed loading Core Plugins Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Preparing to generate the ALSA configuration file Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Discovery: Found device adminvascosilva Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioGetState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Discovery: Found device adminvascosilva Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioGetState Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Output device has changed, restarting MPD Dec 15 14:33:06 adminvascosilva volumio[12437]: info: ___________ START PLUGINS ___________ Dec 15 14:33:06 adminvascosilva volumio[12437]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Creating MPD Configuration file Dec 15 14:33:06 adminvascosilva sudo[12566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:33:06 adminvascosilva sudo[12566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:06 adminvascosilva sudo[12566]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:06 adminvascosilva sudo[12567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:33:06 adminvascosilva sudo[12567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:33:06 adminvascosilva volumio[12437]: info: [1765809186549] CoreMusicLibrary::Adding element Last_100 Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:33:06 adminvascosilva volumio[12437]: info: [1765809186575] CoreMusicLibrary::Adding element Webradio Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:33:06 adminvascosilva sudo[12570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:33:06 adminvascosilva sudo[12570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:33:06 adminvascosilva sudo[12570]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Initializing BBC Radios Dec 15 14:33:06 adminvascosilva sudo[12573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:33:06 adminvascosilva sudo[12573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:06 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:33:06 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:33:06 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:33:06 adminvascosilva systemd[1]: mpd.service: Consumed 3.791s CPU time. Dec 15 14:33:06 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:33:06 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:33:06 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:06 adminvascosilva volumio[12437]: info: Creating Spotify config file Dec 15 14:33:06 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:06 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:33:06 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:33:07 adminvascosilva sudo[12591]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:33:07 adminvascosilva sudo[12591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:33:07 adminvascosilva sudo[12591]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:07 adminvascosilva volumio[12437]: info: AutoStart - onStart Dec 15 14:33:07 adminvascosilva volumio[12437]: info: Volumio Calling Home Dec 15 14:33:07 adminvascosilva volumio[12437]: info: MPD Permissions set Dec 15 14:33:07 adminvascosilva volumio[12437]: info: MPD Permissions set Dec 15 14:33:07 adminvascosilva volumio[12526]: Starting albumart workers Dec 15 14:33:07 adminvascosilva volumio[12437]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 15 14:33:07 adminvascosilva volumio[12437]: info: Spotify config file written Dec 15 14:33:07 adminvascosilva sudo[12598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:33:07 adminvascosilva sudo[12598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:07 adminvascosilva volumio[12524]: Starting albumart workers Dec 15 14:33:07 adminvascosilva volumio[12437]: info: Volumio called home Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:33:07 adminvascosilva volumio[12525]: Starting albumart workers Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:07 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:08 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:33:08 adminvascosilva go-librespot[12602]: go-librespot daemon starting... Dec 15 14:33:08 adminvascosilva sudo[12598]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:08 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:08 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:33:08 adminvascosilva volumio[12437]: info: No need to fix Spotify hosts Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="app state loaded" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:33:08 adminvascosilva volumio[12437]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:33:08 adminvascosilva volumio[12437]: SPOTIFY: BQCZH3DfXWvtVLA44SmVehr1wPHnwVkOxUxpk3rvSJdQnMVT9auI0aDGnQO0mEN8JgdGawjM8rr6B_IH5nca9o9VnCALleZjvX4toMdtRTXeWJA0s8Ov19ZuktreIwg-KRrW5hmN6QXfkIkMzi75IB1naMc9JIA2o8gk9USKwdOyU8J8NOGBd0kysTLe1PffBlCDEItMrwVODO6tj7jDwENFMuVzYhFI6x0giAaI7Q2-Etb6Jd75E6aLeJM-rlXLXcmuj75A99wLItHfNWidjR4eJcWxiGTAIXtXlg Dec 15 14:33:08 adminvascosilva volumio[12437]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:33:08 adminvascosilva volumio[12437]: info: New Spotify access token = BQCZH3DfXWvtVLA44SmVehr1wPHnwVkOxUxpk3rvSJdQnMVT9auI0aDGnQO0mEN8JgdGawjM8rr6B_IH5nca9o9VnCALleZjvX4toMdtRTXeWJA0s8Ov19ZuktreIwg-KRrW5hmN6QXfkIkMzi75IB1naMc9JIA2o8gk9USKwdOyU8J8NOGBd0kysTLe1PffBlCDEItMrwVODO6tj7jDwENFMuVzYhFI6x0giAaI7Q2-Etb6Jd75E6aLeJM-rlXLXcmuj75A99wLItHfNWidjR4eJcWxiGTAIXtXlg Dec 15 14:33:08 adminvascosilva volumio[12437]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=info msg="zeroconf server listening on port 37737" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="obtained new client token: AAC0ih6Is6IwoQmWHA0bueF+F9uN9dogi64khfPYLGW2FuNW4tkOdDO4xqbJgp0YnFaOaXiMurCO+PPwe+smDACaUpbXBkopZoNbSdkC3ATcBh2wAYIMTy8MYbIQrIbrenGgJkYDPhD0O5hoK69sC4R41JcLMPg3H1u4ldhMiOl+wiS21CKq25gdcQWchYC2uf5TJG+n+mSJ1lawhVPiluL9JMe477ZrWqCHK8TxjI7ImUKVKTsj6g==" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="completed keyexchange" Dec 15 14:33:08 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:08Z" level=debug msg="completed challenge" Dec 15 14:33:08 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioGetState Dec 15 14:33:08 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:08 adminvascosilva volumio[12437]: SPOTIFY: User informations: {"country":"PT","display_name":"happybrands","email":"geral@happybrands.pt","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/happybrands"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/happybrands","id":"happybrands","images":[],"product":"premium","type":"user","uri":"spotify:user:happybrands"} Dec 15 14:33:08 adminvascosilva volumio[12437]: info: Spotify Successfully logged in Dec 15 14:33:08 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:33:08 adminvascosilva volumio[12437]: info: [1765809188924] CoreMusicLibrary::Adding element Spotify Dec 15 14:33:08 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:33:08 adminvascosilva volumio[12437]: Cannot find translation for source Spotify Dec 15 14:33:10 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:10Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:33:10 adminvascosilva mpd[12593]: 2025-12-15T14:33:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:33:10 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:33:10 adminvascosilva sudo[12573]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:10 adminvascosilva sudo[12567]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:10 adminvascosilva volumio[12437]: info: Completed starting Core Plugins Dec 15 14:33:10 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:10 adminvascosilva volumio[12437]: info: ----- MyVolumio plugins startup ---- Dec 15 14:33:10 adminvascosilva volumio[12437]: info: ------------------------------------------- Dec 15 14:33:10 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:33:10 adminvascosilva volumio[12437]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:33:10 adminvascosilva volumio[12437]: assert.ok(self.idling) Dec 15 14:33:10 adminvascosilva volumio[12437]: error: The expression evaluated to a falsy value: Dec 15 14:33:10 adminvascosilva volumio[12437]: assert.ok(self.idling) Dec 15 14:33:10 adminvascosilva volumio[12437]: error: updateQueue error: null Dec 15 14:33:10 adminvascosilva volumio[12437]: info: MPD running with PID12593 Dec 15 14:33:10 adminvascosilva volumio[12437]: ,establishing connection Dec 15 14:33:10 adminvascosilva volumio[12437]: error: updateQueue error: null Dec 15 14:33:11 adminvascosilva volumio[12437]: info: go-librespot daemon successfully initialized Dec 15 14:33:12 adminvascosilva sudo[12656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:33:12 adminvascosilva sudo[12656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:12 adminvascosilva sudo[12658]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:33:12 adminvascosilva sudo[12658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:12 adminvascosilva sudo[12656]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:12 adminvascosilva sudo[12658]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:12 adminvascosilva sudo[12661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:33:12 adminvascosilva sudo[12661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:12 adminvascosilva sudo[12661]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:12 adminvascosilva volumio[12437]: info: Upmpdcli Daemon Started Dec 15 14:33:13 adminvascosilva sudo[12667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:33:13 adminvascosilva sudo[12667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:13 adminvascosilva sudo[12669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:33:13 adminvascosilva sudo[12669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:13 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:33:13 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:33:13 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:33:13 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:33:13 adminvascosilva sudo[12667]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:13 adminvascosilva mpd_monitor.sh[12672]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:33:13 adminvascosilva sudo[12669]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:13 adminvascosilva volumio[12437]: info: Successfully started MPD Monitor Dec 15 14:33:13 adminvascosilva volumio[12437]: info: Successfully started MPD Monitor Dec 15 14:33:14 adminvascosilva volumio[12437]: info: Initializing connection to go-librespot Websocket Dec 15 14:33:14 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:14Z" level=debug msg="new websocket client" Dec 15 14:33:14 adminvascosilva volumio[12437]: info: Connection to go-librespot Websocket established Dec 15 14:33:15 adminvascosilva volumio[12437]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:33:17 adminvascosilva volumio[12437]: info: Getting Spotify volume Dec 15 14:33:17 adminvascosilva volumio[12437]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 15 14:33:17 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioGetState Dec 15 14:33:17 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:17 adminvascosilva volumio[12437]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:33:17 adminvascosilva volumio[12437]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:33:17 adminvascosilva volumio[12437]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:33:17 adminvascosilva volumio[12437]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:33:17 adminvascosilva volumio[12437]: info: CoreCommandRouter::volumioGetState Dec 15 14:33:17 adminvascosilva volumio[12437]: info: CorePlayQueue::getTrack 0 Dec 15 14:33:17 adminvascosilva volumio[12437]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:33:18 adminvascosilva volumio[12437]: SPOTIFY: SETTING SPOTIFY VOLUME 25 Dec 15 14:33:18 adminvascosilva volumio[12437]: info: Sending Spotify command with payload to local API: /player/volume Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:33:19 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:33:20 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:33:20 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:20 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:20 adminvascosilva volumio[12437]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:33:20 adminvascosilva volumio[12437]: info: MyVolumio login type: Token Dec 15 14:33:20 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:33:20 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:33:20 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:33:20 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:33:20 adminvascosilva volumio[12437]: info: Streaming services startup Dec 15 14:33:20 adminvascosilva volumio[12437]: info: Starting Streaming Daemon Dec 15 14:33:21 adminvascosilva sudo[12679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:33:21 adminvascosilva sudo[12679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:21 adminvascosilva volumio[12437]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:33:21 adminvascosilva sudo[12679]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:21 adminvascosilva volumio[12437]: error: Cannot start Volumio Streaming Daemon Dec 15 14:33:21 adminvascosilva volumio[12437]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:33:21 adminvascosilva volumio[12437]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:33:21 adminvascosilva volumio[12437]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:33:22 adminvascosilva volumio[12437]: info: MyVolumio token set successfully Dec 15 14:33:22 adminvascosilva volumio[12437]: info: MYVOLUMIO: Adding device Dec 15 14:33:22 adminvascosilva volumio[12437]: info: MYVOLUMIO: Evaluating Server Dec 15 14:33:22 adminvascosilva volumio[12437]: info: MyVolumio status changed Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Streaming services startup Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Starting Streaming Daemon Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Removing audio output: Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Stoppping Tunnel 1 Dec 15 14:33:22 adminvascosilva sudo[12720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:33:22 adminvascosilva sudo[12720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:22 adminvascosilva sudo[12722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:33:22 adminvascosilva sudo[12722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva sudo[12720]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva volumio[12437]: error: Cannot start Volumio Streaming Daemon Dec 15 14:33:22 adminvascosilva volumio[12437]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:33:22 adminvascosilva volumio[12437]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 14:33:22 adminvascosilva sudo[12722]: pam_unix(sudo:session): session closed for user root Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Remote SSH Stopped Dec 15 14:33:22 adminvascosilva volumio[12437]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:33:22 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:22 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:22 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:23 adminvascosilva volumio[12437]: info: Successfully Added MyVolumio device Dec 15 14:33:23 adminvascosilva volumio[12437]: info: Updating MyVolumio device info Dec 15 14:33:23 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:23 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:23 adminvascosilva volumio[12437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:33:23 adminvascosilva volumio[12437]: info: Successfully Updated MyVolumio device Dec 15 14:33:25 adminvascosilva go-librespot[12611]: time="2025-12-15T14:33:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed requesting login5 endpoint: faield unmarshalling LoginResponse: proto:\u00a0cannot parse invalid wire-format data" Dec 15 14:33:25 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:33:25 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:33:25 adminvascosilva volumio[12437]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 15 14:33:25 adminvascosilva volumio[12437]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:33:25 adminvascosilva volumio[12437]: Error: socket hang up Dec 15 14:33:25 adminvascosilva volumio[12437]: at connResetException (node:internal/errors:720:14) Dec 15 14:33:25 adminvascosilva volumio[12437]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:33:25 adminvascosilva volumio[12437]: at Socket.emit (node:events:526:35) Dec 15 14:33:25 adminvascosilva volumio[12437]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:33:25 adminvascosilva volumio[12437]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:33:25 adminvascosilva volumio[12437]: code: 'ECONNRESET', Dec 15 14:33:25 adminvascosilva volumio[12437]: response: undefined Dec 15 14:33:25 adminvascosilva volumio[12437]: } Dec 15 14:33:25 adminvascosilva volumio[12437]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:33:26 adminvascosilva sudo[12740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:32' Dec 15 14:33:26 adminvascosilva sudo[12740]: 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Nov 8 06:10:52 UTC 2025" VOLUMIO_VERSION="4.067" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="78c9815e90cf3bee23e5cdc5934a01e9"