Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "network"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Refreshing Cached IP Addresses Dec 15 14:29:00 adminvascosilva sudo[9549]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:29:00 adminvascosilva sudo[9549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "services"... Dec 15 14:29:00 adminvascosilva sudo[9551]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "alsa_controller"... Dec 15 14:29:00 adminvascosilva sudo[9551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:00 adminvascosilva sudo[9549]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:00 adminvascosilva sudo[9551]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:00 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "wizard"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "networkfs"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Starting Udev Watcher for removable devices Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Ignoring mount for partition: boot Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Ignoring mount for partition: volumio Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Ignoring mount for partition: volumio_data Dec 15 14:29:00 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "upnp"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: [1765808940251] Starting Upmpd Daemon Dec 15 14:29:00 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "my_music"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "mpd"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Plugin upnp_browser is not enabled Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "alarm-clock"... Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Plugin airplay_emulation is not enabled Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "last_100"... Dec 15 14:29:00 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:29:00] [connect] Successful connection Dec 15 14:29:00 adminvascosilva volumio[9509]: info: Loading plugin "webradio"... Dec 15 14:29:02 adminvascosilva volumio[9509]: info: Loading plugin "i2s_dacs"... Dec 15 14:29:02 adminvascosilva volumio[9509]: info: I2S DAC not set, start Auto-detection Dec 15 14:29:02 adminvascosilva volumio[9509]: info: Loading plugin "volumiodiscovery"... Dec 15 14:29:02 adminvascosilva volumio[9509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:29:02 adminvascosilva volumio[9509]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:02 adminvascosilva volumio[9509]: *** WARNING *** For more information see Dec 15 14:29:02 adminvascosilva volumio[9509]: *** 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:29:02 adminvascosilva volumio[9509]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:02 adminvascosilva volumio[9509]: *** WARNING *** For more information see Dec 15 14:29:02 adminvascosilva node[9509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:29:02 adminvascosilva node[9509]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:02 adminvascosilva node[9509]: *** WARNING *** For more information see Dec 15 14:29:02 adminvascosilva node[9509]: *** 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:29:02 adminvascosilva node[9509]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:02 adminvascosilva node[9509]: *** WARNING *** For more information see Dec 15 14:29:02 adminvascosilva volumio[9509]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:29:02 adminvascosilva volumio[9509]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:29:02 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:29:02 adminvascosilva volumio[9509]: info: Loading plugin "spop"... Dec 15 14:29:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 15 14:29:02 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:02 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:02 adminvascosilva go-librespot[9581]: go-librespot daemon starting... Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=debug msg="app state loaded" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" 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:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" 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:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" 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:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=info msg="zeroconf server listening on port 38747" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=debug msg="obtained new client token: AAABAWBIBtf75EjHfbFkN7g2YDiKXdukcNVSKQHlQmR4yjGvxZH5d2XvWt0hIT6DZogGTA84Yjcz/+FRmtJcznpebarow/uFqLafn7Qr/rLdHjobpA6ZjUBVz20n070FIn4UXzi3LXThmeQhzRP4whJvZit4+pqf9YqJLZFGTWVbAUN8XvjzMTlEYEewxsQKluvGmICyikKuShEnfCoXSUwCBgumw0HeD/1HqKN8yjzC+tqfrNbKGw==" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=debug msg="completed keyexchange" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" level=debug msg="completed challenge" Dec 15 14:29:02 adminvascosilva go-librespot[9582]: time="2025-12-15T14:29:02Z" 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:29:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "autostart"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Applying required configuration parameters for plugin autostart Dec 15 14:29:03 adminvascosilva volumio[9509]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "outputs"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "albumart"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Plugin example_plugin is not enabled Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "inputs"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "updater_comm"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Plugin mpdemulation is not enabled Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "rest_api"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading plugin "websocket"... Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Loading i18n strings for locale pt Dec 15 14:29:03 adminvascosilva volumio[9509]: Updating browse sources language Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::initPlayerControls Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: Express server listening on port 3000 Dec 15 14:29:03 adminvascosilva volumio[9509]: [Metrics] WebUI: 6s 225.98ms Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreStateMachine::resetVolumioState Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreStateMachine::getcurrentVolume Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:29:03 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:03 adminvascosilva volumio[9509]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:29:03 adminvascosilva volumio[9590]: Forking 3 albumart workers Dec 15 14:29:03 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:29:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808940 101 Dec 15 14:29:04 adminvascosilva volumio[9509]: 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:29:04 adminvascosilva volumio[9509]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::pushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::updateTrackBlock Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrackBlock Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Reloading queue from file Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Setting Device type: Raspberry PI Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::pushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::setRandom true Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::pushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreStateMachine::pushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Completed loading Core Plugins Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Preparing to generate the ALSA configuration file Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Discovery: Found device adminvascosilva Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Discovery: Found device adminvascosilva Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Output device has changed, restarting MPD Dec 15 14:29:04 adminvascosilva volumio[9509]: info: ___________ START PLUGINS ___________ Dec 15 14:29:04 adminvascosilva volumio[9509]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Creating MPD Configuration file Dec 15 14:29:04 adminvascosilva sudo[9647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:29:04 adminvascosilva sudo[9647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:04 adminvascosilva sudo[9649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:29:04 adminvascosilva sudo[9647]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:04 adminvascosilva sudo[9649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:04 adminvascosilva sudo[9651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:29:04 adminvascosilva volumio[9509]: info: [1765808944499] CoreMusicLibrary::Adding element Last_100 Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:04 adminvascosilva sudo[9651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:04 adminvascosilva sudo[9651]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:29:04 adminvascosilva volumio[9509]: info: [1765808944511] CoreMusicLibrary::Adding element Webradio Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:04 adminvascosilva sudo[9655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:29:04 adminvascosilva sudo[9655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Initializing BBC Radios Dec 15 14:29:04 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:29:04 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:29:04 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:29:04 adminvascosilva systemd[1]: mpd.service: Consumed 3.948s CPU time. Dec 15 14:29:04 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:29:04 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:29:04 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:04 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:29:04 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:29:04 adminvascosilva volumio[9509]: info: Creating Spotify config file Dec 15 14:29:04 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:04 adminvascosilva sudo[9672]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:29:04 adminvascosilva sudo[9672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:29:04 adminvascosilva sudo[9672]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:05 adminvascosilva volumio[9509]: info: AutoStart - onStart Dec 15 14:29:05 adminvascosilva volumio[9509]: info: Volumio Calling Home Dec 15 14:29:05 adminvascosilva volumio[9608]: Starting albumart workers Dec 15 14:29:05 adminvascosilva volumio[9509]: info: MPD Permissions set Dec 15 14:29:05 adminvascosilva volumio[9509]: info: MPD Permissions set Dec 15 14:29:05 adminvascosilva volumio[9509]: info: Volumio called home Dec 15 14:29:05 adminvascosilva volumio[9509]: info: Spotify config file written Dec 15 14:29:05 adminvascosilva volumio[9607]: Starting albumart workers Dec 15 14:29:05 adminvascosilva volumio[9509]: 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:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva sudo[9679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:29:05 adminvascosilva sudo[9679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:05 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:05 adminvascosilva volumio[9606]: Starting albumart workers Dec 15 14:29:06 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:06 adminvascosilva go-librespot[9686]: go-librespot daemon starting... Dec 15 14:29:06 adminvascosilva sudo[9679]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:06 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:06 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:06 adminvascosilva volumio[9509]: info: No need to fix Spotify hosts Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=debug msg="app state loaded" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" 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:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" 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:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" 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:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=info msg="zeroconf server listening on port 41657" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=debug msg="obtained new client token: AAAs9zJ14r9CYhzFxYsi+SNFyb3iOgZkisE2cgJMas7TNK89WbWV7S6XacJ1eWJwoUFYBMiNJMKrnBcsglIre3fDsuHe5Ya/7NsgYpY5iQqQfFz7xUmz5zbY+G9Ubq6RCwZzmNv9cVibk9ggIak0uLv7M9++T2CRo6JixjiVOnD3+Lb1bhaF8ZYRJvQTUNG9uydXm6dlr6BaA0jBzUTUtwWJQjQBkwemOylKtuGEVbpwWHJGabcZSA==" Dec 15 14:29:06 adminvascosilva volumio[9509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:29:06 adminvascosilva volumio[9509]: SPOTIFY: BQAxGBeXyW7bgmen9nohVGC8Qvr97jOO2aFEgbblP2BhENee5Z-kBPfar_PPLjVVYGeL7UQZ_Flo3sOJacOowkddMxlDn4WXya7nmRkcS9rB-NZD2oy9-5lLiWwPO-6BxeqG_yStqlVRK1PENOy8O4pOzJwAj4eP0VKRc_VB0ON16hTqYRbqwkilPyw8yyW_qeFqan4eYqqpR4seTaFEB-FqWOJHI5Zx00w80tq_drfpFOUvmc0by_goWZI_EWDl1PIFVKotIcHzS2tC5BxnFslyczwZrt2XTch77g Dec 15 14:29:06 adminvascosilva volumio[9509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:29:06 adminvascosilva volumio[9509]: info: New Spotify access token = BQAxGBeXyW7bgmen9nohVGC8Qvr97jOO2aFEgbblP2BhENee5Z-kBPfar_PPLjVVYGeL7UQZ_Flo3sOJacOowkddMxlDn4WXya7nmRkcS9rB-NZD2oy9-5lLiWwPO-6BxeqG_yStqlVRK1PENOy8O4pOzJwAj4eP0VKRc_VB0ON16hTqYRbqwkilPyw8yyW_qeFqan4eYqqpR4seTaFEB-FqWOJHI5Zx00w80tq_drfpFOUvmc0by_goWZI_EWDl1PIFVKotIcHzS2tC5BxnFslyczwZrt2XTch77g Dec 15 14:29:06 adminvascosilva volumio[9509]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=debug msg="completed keyexchange" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" level=debug msg="completed challenge" Dec 15 14:29:06 adminvascosilva go-librespot[9692]: time="2025-12-15T14:29:06Z" 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:29:06 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:06 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:06 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:06 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:07 adminvascosilva volumio[9509]: 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:29:07 adminvascosilva volumio[9509]: info: Spotify Successfully logged in Dec 15 14:29:07 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:29:07 adminvascosilva volumio[9509]: info: [1765808947135] CoreMusicLibrary::Adding element Spotify Dec 15 14:29:07 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:07 adminvascosilva volumio[9509]: Cannot find translation for source Spotify Dec 15 14:29:08 adminvascosilva mpd[9674]: 2025-12-15T14:29:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:29:08 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:29:08 adminvascosilva sudo[9655]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:08 adminvascosilva sudo[9649]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:08 adminvascosilva volumio[9509]: info: Completed starting Core Plugins Dec 15 14:29:08 adminvascosilva volumio[9509]: info: ------------------------------------------- Dec 15 14:29:08 adminvascosilva volumio[9509]: info: ----- MyVolumio plugins startup ---- Dec 15 14:29:08 adminvascosilva volumio[9509]: info: ------------------------------------------- Dec 15 14:29:08 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:29:08 adminvascosilva volumio[9509]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:29:08 adminvascosilva volumio[9509]: assert.ok(self.idling) Dec 15 14:29:08 adminvascosilva volumio[9509]: error: The expression evaluated to a falsy value: Dec 15 14:29:08 adminvascosilva volumio[9509]: assert.ok(self.idling) Dec 15 14:29:08 adminvascosilva volumio[9509]: error: updateQueue error: null Dec 15 14:29:08 adminvascosilva volumio[9509]: info: MPD running with PID9674 Dec 15 14:29:08 adminvascosilva volumio[9509]: ,establishing connection Dec 15 14:29:08 adminvascosilva volumio[9509]: error: updateQueue error: null Dec 15 14:29:09 adminvascosilva volumio[9509]: info: go-librespot daemon successfully initialized Dec 15 14:29:09 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 15 14:29:09 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:09 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:09 adminvascosilva go-librespot[9723]: go-librespot daemon starting... Dec 15 14:29:09 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:09Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:09 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:09Z" level=debug msg="app state loaded" Dec 15 14:29:09 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:09Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" 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:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" 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:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" 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:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" level=info msg="zeroconf server listening on port 36199" Dec 15 14:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" level=debug msg="obtained new client token: AACefUykrtOAnCndLBUZXBPivh8m3TKNMfb3pKmre4vaPOJz13UdTwEDxDA6lZnNuUpFNqhfbVSPlrCi9o8U+ZSWQmM4XVZP2vpznwITIPpLtxUVlUXYhQlXBk6PYhlWEb40Zo6CIWK2K67L6DbdxhHiHVoIcArvWZAvPiiSUIxZnJXyBXgEcm9vKo95BqGOS5daJUm14goIi38PZ5cVy2ZbeotdfzVQHJP/ZePaZ9FNIHsNnGA=" Dec 15 14:29:10 adminvascosilva sudo[9746]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:10 adminvascosilva sudo[9746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:10 adminvascosilva sudo[9746]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:10 adminvascosilva sudo[9748]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:29:10 adminvascosilva sudo[9748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:10 adminvascosilva sudo[9748]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:10 adminvascosilva sudo[9751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:29:10 adminvascosilva sudo[9751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" level=debug msg="completed keyexchange" Dec 15 14:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" level=debug msg="completed challenge" Dec 15 14:29:10 adminvascosilva sudo[9751]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:10 adminvascosilva volumio[9509]: info: Upmpdcli Daemon Started Dec 15 14:29:10 adminvascosilva go-librespot[9724]: time="2025-12-15T14:29:10Z" 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:29:10 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:10 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:11 adminvascosilva sudo[9758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:29:11 adminvascosilva sudo[9758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:11 adminvascosilva sudo[9760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:29:11 adminvascosilva sudo[9760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:11 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:29:11 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:29:11 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:29:11 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:29:11 adminvascosilva sudo[9760]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:11 adminvascosilva sudo[9758]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:11 adminvascosilva mpd_monitor.sh[9763]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:29:11 adminvascosilva volumio[9509]: info: Successfully started MPD Monitor Dec 15 14:29:11 adminvascosilva volumio[9509]: info: Successfully started MPD Monitor Dec 15 14:29:12 adminvascosilva volumio[9509]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:12 adminvascosilva volumio[9509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:29:13 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 15 14:29:13 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:13 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:13 adminvascosilva go-librespot[9769]: go-librespot daemon starting... Dec 15 14:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" level=debug msg="app state loaded" Dec 15 14:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:13 adminvascosilva volumio[9509]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" 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:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" 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:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" 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:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" level=info msg="zeroconf server listening on port 44705" Dec 15 14:29:13 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:13Z" level=debug msg="obtained new client token: AADiBOaeKwIvx/fKNCJluK9jSq068PlknmXvchC3n9fHOGaEbnKxnec3TQrad679EkJ6zq2DQ1RcWM1q1qiKK9zlVzRnr4ZqaOnkOrNOmJF7qhd1YMI2wipWBGjSSO5c9JkbSpJoPZSEPCDRdq5EedIteIMW4NyIEQa3hOnLyqkg/+n12gQNdBE5FcVL++ODwIdjKEUVs+yCjeAlK1onR99lg8W8oaFbUqUD/YHaIEQ2B8ZPU0bpug==" Dec 15 14:29:14 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:14 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:14Z" level=debug msg="completed keyexchange" Dec 15 14:29:14 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:14Z" level=debug msg="completed challenge" Dec 15 14:29:14 adminvascosilva go-librespot[9770]: time="2025-12-15T14:29:14Z" 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:29:14 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:14 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:15 adminvascosilva volumio[9509]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:15 adminvascosilva volumio[9509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:29:16 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:29:17 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 15 14:29:17 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:17 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:17 adminvascosilva go-librespot[9777]: go-librespot daemon starting... Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=debug msg="app state loaded" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" 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:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" 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:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" 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:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=info msg="zeroconf server listening on port 42605" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=debug msg="obtained new client token: AAAFPFt/j2uSdRmyTIpcU/wM9qMukLoRXRNK3JT0q4S+Z1r9GRCedFM8TpKGPXphDtHTDsvpNHCDEbGsp23cm7qMQArp1RZrOKIiGgoY5aJqRGGyZUDJJ0wHoD2skwgZjR/N8iY+lfLsNRpkn9OZCmhgO8cwUsDL613UunvbYhT4P6nhyeMGxKJqueSwMzpThHOLf9rsvjNJAcx3nmp810qpm7ND0RJPUYy85JiGABel1yHuABlfaw==" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=debug msg="completed keyexchange" Dec 15 14:29:17 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:17Z" level=debug msg="completed challenge" Dec 15 14:29:17 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:29:17 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:29:17 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:17 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:17 adminvascosilva volumio[9509]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:29:17 adminvascosilva volumio[9509]: info: MyVolumio login type: Token Dec 15 14:29:18 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:29:18 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:29:18 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:29:18 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:29:18 adminvascosilva volumio[9509]: info: Streaming services startup Dec 15 14:29:18 adminvascosilva volumio[9509]: info: Starting Streaming Daemon Dec 15 14:29:18 adminvascosilva sudo[9786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:29:18 adminvascosilva sudo[9786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:18 adminvascosilva volumio[9509]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:29:19 adminvascosilva sudo[9786]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:19 adminvascosilva volumio[9509]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:19 adminvascosilva volumio[9509]: error: Cannot start Volumio Streaming Daemon Dec 15 14:29:19 adminvascosilva volumio[9509]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:29:19 adminvascosilva volumio[9509]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:29:19 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:19Z" level=debug msg="new websocket client" Dec 15 14:29:19 adminvascosilva volumio[9509]: info: Connection to go-librespot Websocket established Dec 15 14:29:19 adminvascosilva volumio[9509]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:29:20 adminvascosilva volumio[9509]: info: MyVolumio token set successfully Dec 15 14:29:20 adminvascosilva volumio[9509]: info: MYVOLUMIO: Adding device Dec 15 14:29:20 adminvascosilva volumio[9509]: info: MYVOLUMIO: Evaluating Server Dec 15 14:29:20 adminvascosilva volumio[9509]: info: MyVolumio status changed Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Streaming services startup Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Starting Streaming Daemon Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Removing audio output: Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Stoppping Tunnel 1 Dec 15 14:29:20 adminvascosilva sudo[9827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:29:20 adminvascosilva sudo[9827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:20 adminvascosilva sudo[9827]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:20 adminvascosilva sudo[9830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:29:20 adminvascosilva sudo[9830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:20 adminvascosilva volumio[9509]: error: Cannot start Volumio Streaming Daemon Dec 15 14:29:20 adminvascosilva volumio[9509]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:29:20 adminvascosilva volumio[9509]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:29:20 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:29:20 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:29:20 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:29:20 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:29:20 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:29:20 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:29:20 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:29:20 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:29:20 adminvascosilva sudo[9830]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Remote SSH Stopped Dec 15 14:29:20 adminvascosilva volumio[9509]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:29:20 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:20 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:20 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:21 adminvascosilva volumio[9509]: info: Successfully Added MyVolumio device Dec 15 14:29:21 adminvascosilva volumio[9509]: info: Updating MyVolumio device info Dec 15 14:29:21 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:21 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:21 adminvascosilva volumio[9509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:22 adminvascosilva volumio[9509]: info: Successfully Updated MyVolumio device Dec 15 14:29:22 adminvascosilva volumio[9509]: info: Getting Spotify volume Dec 15 14:29:22 adminvascosilva volumio[9509]: 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:29:22 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:22 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:22 adminvascosilva volumio[9509]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:29:22 adminvascosilva volumio[9509]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:29:22 adminvascosilva volumio[9509]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:29:22 adminvascosilva volumio[9509]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:29:22 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:22 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:22 adminvascosilva volumio[9509]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:29:23 adminvascosilva volumio[9509]: SPOTIFY: SETTING SPOTIFY VOLUME 25 Dec 15 14:29:23 adminvascosilva volumio[9509]: info: Sending Spotify command with payload to local API: /player/volume Dec 15 14:29:25 adminvascosilva volumio[9509]: info: AutoStart - Plugin is starting Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioGetQueue Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::getQueue Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CorePlayQueue::getQueue Dec 15 14:29:25 adminvascosilva volumio[9509]: info: AutoStart - start playing Dec 15 14:29:25 adminvascosilva volumio[9509]: info: AutoStart - start playing with no specific position Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreCommandRouter::volumioPlay Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::play index 0 Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::stop Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::play index undefined Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:29:25 adminvascosilva volumio[9509]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:25 adminvascosilva volumio[9509]: info: [1765808965187] ControllerSpotify::clearAddPlayTrack Dec 15 14:29:25 adminvascosilva volumio[9509]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:29:29 adminvascosilva go-librespot[9778]: time="2025-12-15T14:29:29Z" 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:29:29 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:29 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:29 adminvascosilva volumio[9509]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 15 14:29:29 adminvascosilva volumio[9509]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 15 14:29:29 adminvascosilva volumio[9509]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:29:29 adminvascosilva volumio[9509]: Error: socket hang up Dec 15 14:29:29 adminvascosilva volumio[9509]: at connResetException (node:internal/errors:720:14) Dec 15 14:29:29 adminvascosilva volumio[9509]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:29:29 adminvascosilva volumio[9509]: at Socket.emit (node:events:526:35) Dec 15 14:29:29 adminvascosilva volumio[9509]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:29:29 adminvascosilva volumio[9509]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:29:29 adminvascosilva volumio[9509]: code: 'ECONNRESET', Dec 15 14:29:29 adminvascosilva volumio[9509]: response: undefined Dec 15 14:29:29 adminvascosilva volumio[9509]: } Dec 15 14:29:29 adminvascosilva volumio[9509]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:29:30 adminvascosilva sudo[9861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:28' Dec 15 14:29:30 adminvascosilva sudo[9861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:30 adminvascosilva sudo[9861]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:31 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:29:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:29:31 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:29:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:29:31 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:31 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:29:31 adminvascosilva systemd[1]: volumio.service: Consumed 27.410s CPU time. Dec 15 14:29:31 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:29:31 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:29:31 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24. Dec 15 14:29:31 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:29:31 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:29:31 adminvascosilva systemd[1]: volumio.service: Consumed 27.410s CPU time. Dec 15 14:29:31 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:29:31 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:29:33 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 15 14:29:33 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:33 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:33 adminvascosilva go-librespot[9895]: go-librespot daemon starting... Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=debug msg="app state loaded" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" 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:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" 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:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" 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:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=info msg="zeroconf server listening on port 37041" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=debug msg="obtained new client token: AAAWc6KW+hboQsTHKv5Fm42fR5MAP18CZg+iWNVjpH0eHJROAH4H0LCYosmsRZEfsjzvFsG00KIgx89ErzNGRA54GHnhYXHUJKPH+max2oOz7o7enQJXakFtFFeIQGIbUMqkVhL3IYT5TxJ3TjOA7UZUJ/KP74DQX9HtmlAcx7fsP6+9gLoP3UElEN9OhcttyNAsR3P1fWvPTj6LsMCiY1rIiEOudo9Rg+XwlpnIvpLRB8hGMXA6Hg==" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:33 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:33 adminvascosilva volumio[9877]: info: ----- Volumio3 ---- Dec 15 14:29:33 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:33 adminvascosilva volumio[9877]: info: ----- System startup ---- Dec 15 14:29:33 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=debug msg="completed keyexchange" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" level=debug msg="completed challenge" Dec 15 14:29:33 adminvascosilva go-librespot[9896]: time="2025-12-15T14:29:33Z" 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:29:33 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:33 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:34 adminvascosilva volumio[9877]: info: MYVOLUMIO Environment detected Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Plugin folders cleanup Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category audio_interface Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category miscellanea Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category music_service Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category plugins.json Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category system_controller Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category user_interface Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning into folder /data/plugins/ Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category music_service Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Scanning category system_controller Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Plugin folders cleanup completed Dec 15 14:29:34 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:34 adminvascosilva volumio[9877]: info: ----- Core plugins startup ---- Dec 15 14:29:34 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Loading plugins from folder /data/plugins/ Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Loading plugin "system"... Dec 15 14:29:34 adminvascosilva volumio[9877]: info: Loading plugin "appearance"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "network"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Refreshing Cached IP Addresses Dec 15 14:29:35 adminvascosilva sudo[9916]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "services"... Dec 15 14:29:35 adminvascosilva sudo[9916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "alsa_controller"... Dec 15 14:29:35 adminvascosilva sudo[9918]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:29:35 adminvascosilva sudo[9918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:35 adminvascosilva sudo[9916]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:35 adminvascosilva sudo[9918]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:35 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "wizard"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "networkfs"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Starting Udev Watcher for removable devices Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Ignoring mount for partition: boot Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Ignoring mount for partition: volumio Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Ignoring mount for partition: volumio_data Dec 15 14:29:35 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "upnp"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: [1765808975771] Starting Upmpd Daemon Dec 15 14:29:35 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "my_music"... Dec 15 14:29:35 adminvascosilva volumio[9877]: info: Loading plugin "mpd"... Dec 15 14:29:36 adminvascosilva volumio[9877]: info: Plugin upnp_browser is not enabled Dec 15 14:29:36 adminvascosilva volumio[9877]: info: Loading plugin "alarm-clock"... Dec 15 14:29:36 adminvascosilva volumio[9877]: info: Plugin airplay_emulation is not enabled Dec 15 14:29:36 adminvascosilva volumio[9877]: info: Loading plugin "last_100"... Dec 15 14:29:36 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:29:36] [connect] Successful connection Dec 15 14:29:36 adminvascosilva volumio[9877]: info: Loading plugin "webradio"... Dec 15 14:29:36 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 15 14:29:36 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:36 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:36 adminvascosilva go-librespot[9946]: go-librespot daemon starting... Dec 15 14:29:36 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:36Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:36 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:36Z" level=debug msg="app state loaded" Dec 15 14:29:36 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:36Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" 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:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" 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:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" 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:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" level=info msg="zeroconf server listening on port 42039" Dec 15 14:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" level=debug msg="obtained new client token: AAAbnsB9g66YfDHQpcx+gDqAhWPqy1cN2kpB/iFGoLfIavFHwKuNiRLxEH8eC4zZgVM6ooLKH/Br7Io6GFySFEd5E+qM2lF9vUPFBUFcNQbwvXUAY9C9VaIcGjnoJ8zgU+k0tt/rn0VuZIiZu2p/hRtk2GLdKywCVYfqy3NWAdzrcNRkHG8qpUhVFyCQI2QXfHYGbQFLvuEXvb2SLL8uh0KdeqcMRPZpdw4cQTeu3V0PouiSTIg=" Dec 15 14:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" level=debug msg="completed keyexchange" Dec 15 14:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" level=debug msg="completed challenge" Dec 15 14:29:37 adminvascosilva go-librespot[9947]: time="2025-12-15T14:29:37Z" 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:29:37 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:37 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:37 adminvascosilva volumio[9877]: info: Loading plugin "i2s_dacs"... Dec 15 14:29:37 adminvascosilva volumio[9877]: info: I2S DAC not set, start Auto-detection Dec 15 14:29:37 adminvascosilva volumio[9877]: info: Loading plugin "volumiodiscovery"... Dec 15 14:29:37 adminvascosilva volumio[9877]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:29:37 adminvascosilva volumio[9877]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:37 adminvascosilva volumio[9877]: *** WARNING *** For more information see Dec 15 14:29:37 adminvascosilva volumio[9877]: *** 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:29:37 adminvascosilva volumio[9877]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:37 adminvascosilva volumio[9877]: *** WARNING *** For more information see Dec 15 14:29:37 adminvascosilva node[9877]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:29:37 adminvascosilva node[9877]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:37 adminvascosilva node[9877]: *** WARNING *** For more information see Dec 15 14:29:37 adminvascosilva node[9877]: *** 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:29:37 adminvascosilva node[9877]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:29:37 adminvascosilva node[9877]: *** WARNING *** For more information see Dec 15 14:29:37 adminvascosilva volumio[9877]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:29:37 adminvascosilva volumio[9877]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:29:37 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:29:37 adminvascosilva volumio[9877]: info: Loading plugin "spop"... Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Loading plugin "autostart"... Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Applying required configuration parameters for plugin autostart Dec 15 14:29:38 adminvascosilva volumio[9877]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Loading plugin "outputs"... Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Loading plugin "albumart"... Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Plugin example_plugin is not enabled Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Loading plugin "inputs"... Dec 15 14:29:38 adminvascosilva volumio[9877]: info: Loading plugin "updater_comm"... Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Plugin mpdemulation is not enabled Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Loading plugin "rest_api"... Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Loading plugin "websocket"... Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Loading i18n strings for locale pt Dec 15 14:29:39 adminvascosilva volumio[9877]: Updating browse sources language Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::initPlayerControls Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: Express server listening on port 3000 Dec 15 14:29:39 adminvascosilva volumio[9877]: [Metrics] WebUI: 6s 223.72ms Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::resetVolumioState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::getcurrentVolume Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:29:39 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:29:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808976 101 Dec 15 14:29:39 adminvascosilva volumio[9877]: 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:29:39 adminvascosilva volumio[9956]: Forking 3 albumart workers Dec 15 14:29:39 adminvascosilva volumio[9877]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::pushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::updateTrackBlock Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrackBlock Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Reloading queue from file Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::pushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::setRandom true Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::pushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Setting Device type: Raspberry PI Dec 15 14:29:39 adminvascosilva volumio[9877]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreStateMachine::pushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:39 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioPushState Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Completed loading Core Plugins Dec 15 14:29:39 adminvascosilva volumio[9877]: info: Preparing to generate the ALSA configuration file Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Discovery: Found device adminvascosilva Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Discovery: Found device adminvascosilva Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Output device has changed, restarting MPD Dec 15 14:29:40 adminvascosilva volumio[9877]: info: ___________ START PLUGINS ___________ Dec 15 14:29:40 adminvascosilva sudo[10013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:29:40 adminvascosilva sudo[10013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:40 adminvascosilva volumio[9877]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Creating MPD Configuration file Dec 15 14:29:40 adminvascosilva sudo[10014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:29:40 adminvascosilva sudo[10014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:40 adminvascosilva sudo[10013]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:29:40 adminvascosilva volumio[9877]: info: [1765808980116] CoreMusicLibrary::Adding element Last_100 Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:29:40 adminvascosilva volumio[9877]: info: [1765808980139] CoreMusicLibrary::Adding element Webradio Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:29:40 adminvascosilva sudo[10017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:29:40 adminvascosilva sudo[10017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Initializing BBC Radios Dec 15 14:29:40 adminvascosilva sudo[10020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:29:40 adminvascosilva sudo[10020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:40 adminvascosilva sudo[10017]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:40 adminvascosilva systemd[1]: Starting volumio-keepalive.service - Volumio KeepAlive (start playback if stopped)... Dec 15 14:29:40 adminvascosilva volumio[9877]: info: Creating Spotify config file Dec 15 14:29:40 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:40 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:29:40 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:29:40 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:29:40 adminvascosilva systemd[1]: mpd.service: Consumed 3.904s CPU time. Dec 15 14:29:40 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:29:40 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:29:40 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:29:40 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:29:40 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:29:40 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 15 14:29:40 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:40 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:40 adminvascosilva go-librespot[10047]: go-librespot daemon starting... Dec 15 14:29:40 adminvascosilva go-librespot[10048]: time="2025-12-15T14:29:40Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:40 adminvascosilva sudo[10046]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:29:40 adminvascosilva sudo[10046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:29:40 adminvascosilva sudo[10046]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:40 adminvascosilva go-librespot[10048]: time="2025-12-15T14:29:40Z" level=info msg="zeroconf server listening on port 37535" Dec 15 14:29:40 adminvascosilva volumio[9877]: info: AutoStart - onStart Dec 15 14:29:41 adminvascosilva volumio[9877]: info: Volumio Calling Home Dec 15 14:29:41 adminvascosilva volumio[9972]: Starting albumart workers Dec 15 14:29:41 adminvascosilva volumio[9877]: info: MPD Permissions set Dec 15 14:29:41 adminvascosilva volumio[9877]: info: MPD Permissions set Dec 15 14:29:41 adminvascosilva volumio[9877]: info: Volumio called home Dec 15 14:29:41 adminvascosilva volumio[9877]: info: Spotify config file written Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:41 adminvascosilva sudo[10063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:29:41 adminvascosilva sudo[10063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:41 adminvascosilva volumio[9877]: 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:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9971]: Starting albumart workers Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:29:41 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:29:41 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:29:41 adminvascosilva volumio[9877]: info: No need to fix Spotify hosts Dec 15 14:29:41 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:41 adminvascosilva go-librespot[10077]: go-librespot daemon starting... Dec 15 14:29:41 adminvascosilva volumio[9973]: Starting albumart workers Dec 15 14:29:41 adminvascosilva sudo[10063]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:41 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:41Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:41 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:41Z" level=debug msg="app state loaded" Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" 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:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" 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:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" 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:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" level=info msg="zeroconf server listening on port 40981" Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" level=debug msg="obtained new client token: AADeHa4MvTDVFJ7GL/05jR00Sv/8bPQECRxZyB7K84sD9Bh3k73pUR33dC1AwaWZHy4hliqTktyhpTl4WOn8ugLi3IqNIFxRDLFrOiPCAuQ0wyYcu407NKFjsIO4ODHI0OzjgMUjbrRJoVPPl8KeE1FAvz2bciNzP1h4BAgbgH1r/6udDTRghRNkcHRMVRzC4AXB/uSC7Y5qgN5vZXib4BK1L8FRZOj6VNgsfqRMVxWAfzfywC8sxw==" Dec 15 14:29:42 adminvascosilva volumio[9877]: info: Dec 15 14:29:42 adminvascosilva volumio[9877]: ---------------------------- Client requests Volumio play Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioPlay Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CoreStateMachine::play index undefined Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:42 adminvascosilva volumio[9877]: info: [1765808982571] ControllerSpotify::clearAddPlayTrack Dec 15 14:29:42 adminvascosilva volumio[9877]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" level=debug msg="completed keyexchange" Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29:42Z" level=debug msg="completed challenge" Dec 15 14:29:42 adminvascosilva go-librespot[10078]: time="2025-12-15T14:29: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:29:42 adminvascosilva volumio[9877]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:29:42 adminvascosilva volumio[9877]: SPOTIFY: BQBmMPwGRWKACD9yGFTqUfbE_HLzbDut9AH7mti8IRkEINgkEKTgen_aB05IhQTUBrBJagoZpiFeTBV-CojEVQ7goE6UWX4vo7OJhh1Z2iFb_OsYfNTJrjqoqDR1LnyM584_yopBlYXi9HoI6UVN93HpMfWBorz02_eEtD_K958Z9oB7zWw3hdRCgowbtzPleyLoWrzRGUj4vyqL76sIpFk6IDwHD1fg3ppi8gQrt6vYPMoixRpPJbu-Cp1UnznZAnVnj64gh-8F2q1kDF5SUNILq6Bi4pjRI2SAaA Dec 15 14:29:42 adminvascosilva volumio[9877]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:29:42 adminvascosilva volumio[9877]: info: New Spotify access token = BQBmMPwGRWKACD9yGFTqUfbE_HLzbDut9AH7mti8IRkEINgkEKTgen_aB05IhQTUBrBJagoZpiFeTBV-CojEVQ7goE6UWX4vo7OJhh1Z2iFb_OsYfNTJrjqoqDR1LnyM584_yopBlYXi9HoI6UVN93HpMfWBorz02_eEtD_K958Z9oB7zWw3hdRCgowbtzPleyLoWrzRGUj4vyqL76sIpFk6IDwHD1fg3ppi8gQrt6vYPMoixRpPJbu-Cp1UnznZAnVnj64gh-8F2q1kDF5SUNILq6Bi4pjRI2SAaA Dec 15 14:29:42 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:42 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:42 adminvascosilva volumio[9877]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:29:42 adminvascosilva systemd[1]: volumio-keepalive.service: Deactivated successfully. Dec 15 14:29:42 adminvascosilva systemd[1]: Finished volumio-keepalive.service - Volumio KeepAlive (start playback if stopped). Dec 15 14:29:42 adminvascosilva volumio[9877]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioGetState Dec 15 14:29:42 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:29:42 adminvascosilva volumio[9877]: 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:29:43 adminvascosilva volumio[9877]: info: Spotify Successfully logged in Dec 15 14:29:43 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:29:43 adminvascosilva volumio[9877]: info: [1765808983019] CoreMusicLibrary::Adding element Spotify Dec 15 14:29:43 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:29:43 adminvascosilva volumio[9877]: Cannot find translation for source Spotify Dec 15 14:29:44 adminvascosilva mpd[10057]: 2025-12-15T14:29:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:29:44 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:29:44 adminvascosilva sudo[10020]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:44 adminvascosilva sudo[10014]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:44 adminvascosilva volumio[9877]: info: Completed starting Core Plugins Dec 15 14:29:44 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:44 adminvascosilva volumio[9877]: info: ----- MyVolumio plugins startup ---- Dec 15 14:29:44 adminvascosilva volumio[9877]: info: ------------------------------------------- Dec 15 14:29:44 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:29:44 adminvascosilva volumio[9877]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:29:44 adminvascosilva volumio[9877]: assert.ok(self.idling) Dec 15 14:29:44 adminvascosilva volumio[9877]: error: The expression evaluated to a falsy value: Dec 15 14:29:44 adminvascosilva volumio[9877]: assert.ok(self.idling) Dec 15 14:29:44 adminvascosilva volumio[9877]: error: updateQueue error: null Dec 15 14:29:44 adminvascosilva volumio[9877]: info: MPD running with PID10057 Dec 15 14:29:44 adminvascosilva volumio[9877]: ,establishing connection Dec 15 14:29:44 adminvascosilva volumio[9877]: error: updateQueue error: null Dec 15 14:29:45 adminvascosilva volumio[9877]: info: go-librespot daemon successfully initialized Dec 15 14:29:45 adminvascosilva sudo[10124]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:29:45 adminvascosilva sudo[10124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:45 adminvascosilva sudo[10124]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:45 adminvascosilva sudo[10126]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:29:45 adminvascosilva sudo[10126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:45 adminvascosilva sudo[10126]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:45 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:29:45 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:45 adminvascosilva sudo[10129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:29:45 adminvascosilva sudo[10129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:45 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:45 adminvascosilva go-librespot[10131]: go-librespot daemon starting... Dec 15 14:29:45 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:45Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:45 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:45Z" level=debug msg="app state loaded" Dec 15 14:29:45 adminvascosilva sudo[10129]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:45 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:45Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:45 adminvascosilva volumio[9877]: info: Upmpdcli Daemon Started Dec 15 14:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29: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:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29: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:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29: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:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:46Z" level=info msg="zeroconf server listening on port 41645" Dec 15 14:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:46Z" level=debug msg="obtained new client token: AADx/DWBDIgvpO08vyV4FHery/G3sFqz2P3Ntda4r8COM7fB52UGtmWm2UeHFHZK5geSWaykfrzBmeyfIrdUvrxCrwz8IajJiSWTNIPsnrZdAeVqK7HZv9+lqBNDzEmwW51PkuP/JJcuD7ZmbxWXVm4/mIbdjFbbAmglFi+RuV6ZO6bhgd3fGrxdhd/iXiSmGRBQ6NUUil2TiVtc4JJmY6zP4JOoNhhZgxpKzEhyDGD2Wc5+SEo=" Dec 15 14:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:46Z" level=debug msg="completed keyexchange" Dec 15 14:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29:46Z" level=debug msg="completed challenge" Dec 15 14:29:46 adminvascosilva go-librespot[10133]: time="2025-12-15T14:29: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:29:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:47 adminvascosilva sudo[10146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:29:47 adminvascosilva sudo[10146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:47 adminvascosilva sudo[10148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:29:47 adminvascosilva sudo[10148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:47 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:29:47 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:29:47 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:29:47 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:29:47 adminvascosilva sudo[10148]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:47 adminvascosilva sudo[10146]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:47 adminvascosilva mpd_monitor.sh[10151]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:29:47 adminvascosilva volumio[9877]: info: Successfully started MPD Monitor Dec 15 14:29:47 adminvascosilva volumio[9877]: info: Successfully started MPD Monitor Dec 15 14:29:48 adminvascosilva volumio[9877]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:48 adminvascosilva volumio[9877]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:29:49 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:29:49 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:49 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:49 adminvascosilva go-librespot[10157]: go-librespot daemon starting... Dec 15 14:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:49Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:49Z" level=debug msg="app state loaded" Dec 15 14:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:49Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:49 adminvascosilva volumio[9877]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29: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:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29: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:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29: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:29:49 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:49Z" level=info msg="zeroconf server listening on port 43449" Dec 15 14:29:50 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:50Z" level=debug msg="obtained new client token: AACXJZoG7BFzalSyhRhIROCIBVmqsL/owU6E1wBRYpu8ZL0D1kv2vn97lSzdpK3WQ6z8KOVCNLkpgsfVgpw2woVosfoGaEQQZAqmLPLPg8Us/2g87U9/gtcR24hMumllPBLq5Yz8VVQdvDrQplLTzfe21Nx8EE3q1dCQSu4DHpK4Js7BU5Nj+xbFoI5ddSK/yLhuXBfkuOxlzoiTyeolo9Vg9Pm9E/mAfpAfWSrhv0bnR708lyKWZQ==" Dec 15 14:29:50 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:50Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:50 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:50Z" level=debug msg="completed keyexchange" Dec 15 14:29:50 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29:50Z" level=debug msg="completed challenge" Dec 15 14:29:50 adminvascosilva go-librespot[10158]: time="2025-12-15T14:29: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:29:50 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:50 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:51 adminvascosilva volumio[9877]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:51 adminvascosilva volumio[9877]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:29:52 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:29:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:29:53 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:53 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:53 adminvascosilva go-librespot[10165]: go-librespot daemon starting... Dec 15 14:29:53 adminvascosilva systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="app state loaded" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:53 adminvascosilva systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. Dec 15 14:29:53 adminvascosilva systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. Dec 15 14:29:53 adminvascosilva systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=info msg="zeroconf server listening on port 36965" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="obtained new client token: AADg749CDn1vI7zadP4I5XVb2FGaSRFOTa+GWrGWigte2Qp1q3Iuj3rWKImB1CI0KfLeTQSCojQxYrprXyQ0XMFbYnsTXdiabS6RtCZehCnqZWW0kGWUR2PrXKcJJpIPl0S/q+kGsyt9dJMIHIkXSctIhKddkcnrbV7/gTq9vz1mUu99MQhKomDZ+bnOBJ6znGi5OtJ+M4d3OV8bPAGcyWGeEimgZ+bKoctNbg5ebhxtLR0jKNfMpw==" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:53 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:29:53 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:29:53 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:53 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:53 adminvascosilva volumio[9877]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="completed keyexchange" Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29:53Z" level=debug msg="completed challenge" Dec 15 14:29:53 adminvascosilva volumio[9877]: info: MyVolumio login type: Token Dec 15 14:29:53 adminvascosilva go-librespot[10166]: time="2025-12-15T14:29: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:29:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:53 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:29:53 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:29:54 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:29:54 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:29:54 adminvascosilva volumio[9877]: info: Streaming services startup Dec 15 14:29:54 adminvascosilva volumio[9877]: info: Starting Streaming Daemon Dec 15 14:29:54 adminvascosilva sudo[10176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:29:54 adminvascosilva sudo[10176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:54 adminvascosilva volumio[9877]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:29:54 adminvascosilva sudo[10176]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:54 adminvascosilva volumio[9877]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:55 adminvascosilva volumio[9877]: error: Cannot start Volumio Streaming Daemon Dec 15 14:29:55 adminvascosilva volumio[9877]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:29:55 adminvascosilva volumio[9877]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:29:55 adminvascosilva volumio[9877]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:29:55 adminvascosilva volumio[9877]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:29:55 adminvascosilva volumio[9877]: info: MyVolumio token set successfully Dec 15 14:29:55 adminvascosilva volumio[9877]: info: MYVOLUMIO: Adding device Dec 15 14:29:55 adminvascosilva volumio[9877]: info: MYVOLUMIO: Evaluating Server Dec 15 14:29:56 adminvascosilva volumio[9877]: info: MyVolumio status changed Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Streaming services startup Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Starting Streaming Daemon Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Removing audio output: Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Stoppping Tunnel 1 Dec 15 14:29:56 adminvascosilva sudo[10218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:29:56 adminvascosilva sudo[10218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:56 adminvascosilva sudo[10218]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:56 adminvascosilva sudo[10221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:29:56 adminvascosilva sudo[10221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:29:56 adminvascosilva volumio[9877]: error: Cannot start Volumio Streaming Daemon Dec 15 14:29:56 adminvascosilva volumio[9877]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:29:56 adminvascosilva volumio[9877]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:29:56 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:29:56 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:29:56 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:29:56 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:29:56 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:29:56 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:29:56 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:29:56 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:29:56 adminvascosilva sudo[10221]: pam_unix(sudo:session): session closed for user root Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Remote SSH Stopped Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:29:56 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:56 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:56 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:56 adminvascosilva volumio[9877]: info: Successfully Added MyVolumio device Dec 15 14:29:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 14:29:57 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:57 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:29:57 adminvascosilva go-librespot[10223]: go-librespot daemon starting... Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=debug msg="app state loaded" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29: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-gew4.spotify.com:80]" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" 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:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" 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:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=info msg="zeroconf server listening on port 36599" Dec 15 14:29:57 adminvascosilva volumio[9877]: info: Updating MyVolumio device info Dec 15 14:29:57 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:57 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:57 adminvascosilva volumio[9877]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=debug msg="obtained new client token: AABgcZOjKbHWWpeIt8c3bPfNl8SzcGwW5EgSlSDhNpBWTo06TqrM83Fnhd2dQUTF8LWWU72AhgkWRcvuhiWsZkuKLXqP7Wo80isMVImB+rtFLfBZv38Z2adTKT/OHK+v2TasimgTn3STHyWurClp+CwnruYMiYVc9M+A/QUlYizpWlL8NBWkDAzUxVafBpSkqvvHD6VjF65eflpoj7PHHeLRo0eDepk/5BhS9pQmzWXKKJj3BSDSiw==" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=debug msg="completed keyexchange" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29:57Z" level=debug msg="completed challenge" Dec 15 14:29:57 adminvascosilva go-librespot[10224]: time="2025-12-15T14:29: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:29:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:29:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:29:57 adminvascosilva volumio[9877]: info: Successfully Updated MyVolumio device Dec 15 14:29:58 adminvascosilva volumio[9877]: info: Initializing connection to go-librespot Websocket Dec 15 14:29:58 adminvascosilva volumio[9877]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:30:00 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 14:30:00 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:00 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:00 adminvascosilva go-librespot[10232]: go-librespot daemon starting... Dec 15 14:30:00 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:00Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:00 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:00Z" level=debug msg="app state loaded" Dec 15 14:30:00 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:00Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:00 adminvascosilva volumio[9877]: info: AutoStart - Plugin is starting Dec 15 14:30:00 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioGetQueue Dec 15 14:30:00 adminvascosilva volumio[9877]: info: CoreStateMachine::getQueue Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CorePlayQueue::getQueue Dec 15 14:30:01 adminvascosilva volumio[9877]: info: AutoStart - start playing Dec 15 14:30:01 adminvascosilva volumio[9877]: info: AutoStart - start playing with no specific position Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreCommandRouter::volumioPlay Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::play index 0 Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::stop Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::play index undefined Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:30:01 adminvascosilva volumio[9877]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:01 adminvascosilva volumio[9877]: info: [1765809001006] ControllerSpotify::clearAddPlayTrack Dec 15 14:30:01 adminvascosilva volumio[9877]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:30:01 adminvascosilva volumio[9877]: info: Initializing connection to go-librespot Websocket Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" level=debug msg="new websocket client" Dec 15 14:30:01 adminvascosilva volumio[9877]: info: Connection to go-librespot Websocket established Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30: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:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30: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:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30: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:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" level=info msg="zeroconf server listening on port 35131" Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" level=debug msg="obtained new client token: AABSeCtxrPhEtusTSXbInRQg5Tu8/BGizdhoV3aOfTtSgOZPA9C1a7FqfaJyfUuaFk+ASEBlbyWTjg8qtB1amwMvrDvzWu/j3bS6FtfpWkJgoSE2M4c76m7UkakDo8WBKw2sXMuuNeBcBQm7ZIkRw/+WFiFP14TUexe5wSEZK7wDR2l04PXG8kI+GwbtgfEO+D7aW2Twcb/SpZTopq9SdKylyQ8nwlI6X+Hv/rfJNjFLwhad098=" Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" 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:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" level=debug msg="completed keyexchange" Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" level=debug msg="completed challenge" Dec 15 14:30:01 adminvascosilva go-librespot[10233]: time="2025-12-15T14:30:01Z" 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:30:01 adminvascosilva volumio[9877]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 15 14:30:01 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:01 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:01 adminvascosilva volumio[9877]: info: Connection to go-librespot Websocket closed Dec 15 14:30:04 adminvascosilva volumio[9877]: info: Getting Spotify volume Dec 15 14:30:04 adminvascosilva volumio[9877]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:30:04 adminvascosilva volumio[9877]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:30:04 adminvascosilva volumio[9877]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 14:30:04 adminvascosilva volumio[9877]: errno: -111, Dec 15 14:30:04 adminvascosilva volumio[9877]: code: 'ECONNREFUSED', Dec 15 14:30:04 adminvascosilva volumio[9877]: syscall: 'connect', Dec 15 14:30:04 adminvascosilva volumio[9877]: address: '127.0.0.1', Dec 15 14:30:04 adminvascosilva volumio[9877]: port: 9879, Dec 15 14:30:04 adminvascosilva volumio[9877]: response: undefined Dec 15 14:30:04 adminvascosilva volumio[9877]: } Dec 15 14:30:04 adminvascosilva volumio[9877]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:30:04 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 14:30:04 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:04 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:04 adminvascosilva go-librespot[10255]: go-librespot daemon starting... Dec 15 14:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" level=debug msg="app state loaded" Dec 15 14:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:04 adminvascosilva sudo[10265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:29' Dec 15 14:30:04 adminvascosilva sudo[10265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" 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:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" 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:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" 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:30:04 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:04Z" level=info msg="zeroconf server listening on port 34073" Dec 15 14:30:05 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:05Z" level=debug msg="obtained new client token: AABxrBiI1QKORpDb2jJoYd2T+lFQScxY8qNuDScqOjFfwbm4R9xoDbMkd8S07KCNiI//2Y05BtXPWsD2cjWKLFeygnYtPd6ZJuZLxkxRmz4cRwBtFgjbf8CChI1ly9cm/CtuS5sFiOd7z8SXn4lwvsd1rCCFbOH+byZwzXw8rfL61rY5KV6LuJTIMWFsuZqWjKlteVqOAUXXXUggxylPQDxDsJa8yA2oSQWYsvPwjb6g8Vah8STwmw==" Dec 15 14:30:05 adminvascosilva sudo[10265]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:05 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:05Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:05 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:05Z" level=debug msg="completed keyexchange" Dec 15 14:30:05 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:05Z" level=debug msg="completed challenge" Dec 15 14:30:05 adminvascosilva go-librespot[10256]: time="2025-12-15T14:30:05Z" 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:30:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:05 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:05] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Dec 15 14:30:05 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:05] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Dec 15 14:30:05 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:05 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:30:05 adminvascosilva systemd[1]: volumio.service: Consumed 26.746s CPU time. Dec 15 14:30:05 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:30:05 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:30:05 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 25. Dec 15 14:30:05 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:30:05 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:30:05 adminvascosilva systemd[1]: volumio.service: Consumed 26.746s CPU time. Dec 15 14:30:05 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:30:05 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:30:07 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:07 adminvascosilva volumio[10282]: info: ----- Volumio3 ---- Dec 15 14:30:07 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:07 adminvascosilva volumio[10282]: info: ----- System startup ---- Dec 15 14:30:07 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:08 adminvascosilva volumio[10282]: info: MYVOLUMIO Environment detected Dec 15 14:30:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 15 14:30:08 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:08 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:08 adminvascosilva go-librespot[10309]: go-librespot daemon starting... Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Plugin folders cleanup Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category audio_interface Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=debug msg="app state loaded" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category miscellanea Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category music_service Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category plugins.json Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category system_controller Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category user_interface Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning into folder /data/plugins/ Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category music_service Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Scanning category system_controller Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Plugin folders cleanup completed Dec 15 14:30:08 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:08 adminvascosilva volumio[10282]: info: ----- Core plugins startup ---- Dec 15 14:30:08 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Loading plugins from folder /data/plugins/ Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Loading plugin "system"... Dec 15 14:30:08 adminvascosilva volumio[10282]: info: Loading plugin "appearance"... Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" 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:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" 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:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" 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:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=info msg="zeroconf server listening on port 46023" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=debug msg="obtained new client token: AACnWYJ9yeHQFmpbmPeo8McC4Ki1bQPXGZZ6UL63apFB8vt5bVGIIVCnGJTzPFE3toiOkXN2nagoAfhCXAvbIa8dbxd5lKSo3wL6C1hM/A4SkWgX4CoQaG7iQFEqKT/WiI4XCinoZUay1lMguOxjQDiXdrUzOIlz6q2DHVbtj1G6Cs1WglL7fCADFgFU+UxuZrDTpsVa6tSD37SghTdctRe4HSHZLtgdDNaFpIMlUSaURGLB3cghZQ==" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=debug msg="completed keyexchange" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30:08Z" level=debug msg="completed challenge" Dec 15 14:30:08 adminvascosilva go-librespot[10310]: time="2025-12-15T14:30: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:30:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "network"... Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Refreshing Cached IP Addresses Dec 15 14:30:09 adminvascosilva sudo[10321]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:30:09 adminvascosilva sudo[10321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:09 adminvascosilva sudo[10323]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "services"... Dec 15 14:30:09 adminvascosilva sudo[10323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:09 adminvascosilva sudo[10321]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "alsa_controller"... Dec 15 14:30:09 adminvascosilva sudo[10323]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:09 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "wizard"... Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "networkfs"... Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Starting Udev Watcher for removable devices Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Ignoring mount for partition: boot Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Ignoring mount for partition: volumio Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Ignoring mount for partition: volumio_data Dec 15 14:30:09 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "upnp"... Dec 15 14:30:09 adminvascosilva volumio[10282]: info: [1765809009724] Starting Upmpd Daemon Dec 15 14:30:09 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "my_music"... Dec 15 14:30:09 adminvascosilva volumio[10282]: info: Loading plugin "mpd"... Dec 15 14:30:10 adminvascosilva volumio[10282]: info: Plugin upnp_browser is not enabled Dec 15 14:30:10 adminvascosilva volumio[10282]: info: Loading plugin "alarm-clock"... Dec 15 14:30:10 adminvascosilva volumio[10282]: info: Plugin airplay_emulation is not enabled Dec 15 14:30:10 adminvascosilva volumio[10282]: info: Loading plugin "last_100"... Dec 15 14:30:10 adminvascosilva volumio[10282]: info: Loading plugin "webradio"... Dec 15 14:30:10 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:10] [connect] Successful connection Dec 15 14:30:11 adminvascosilva volumio[10282]: info: Loading plugin "i2s_dacs"... Dec 15 14:30:11 adminvascosilva volumio[10282]: info: I2S DAC not set, start Auto-detection Dec 15 14:30:11 adminvascosilva volumio[10282]: info: Loading plugin "volumiodiscovery"... Dec 15 14:30:11 adminvascosilva volumio[10282]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:30:11 adminvascosilva volumio[10282]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:11 adminvascosilva volumio[10282]: *** WARNING *** For more information see Dec 15 14:30:11 adminvascosilva volumio[10282]: *** 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:30:11 adminvascosilva volumio[10282]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:11 adminvascosilva volumio[10282]: *** WARNING *** For more information see Dec 15 14:30:11 adminvascosilva node[10282]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:30:11 adminvascosilva node[10282]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:11 adminvascosilva node[10282]: *** WARNING *** For more information see Dec 15 14:30:11 adminvascosilva node[10282]: *** 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:30:11 adminvascosilva node[10282]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:11 adminvascosilva node[10282]: *** WARNING *** For more information see Dec 15 14:30:11 adminvascosilva volumio[10282]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:30:11 adminvascosilva volumio[10282]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:30:11 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:30:11 adminvascosilva volumio[10282]: info: Loading plugin "spop"... Dec 15 14:30:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 15 14:30:12 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:12 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:12 adminvascosilva go-librespot[10353]: go-librespot daemon starting... Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="app state loaded" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=info msg="zeroconf server listening on port 39605" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="obtained new client token: AADW+XaomkvtMhWboOth41ZIk2mucPVyRZj5XlOUus8tREFKdLtekLuFI4jMke3ebsA/L4MCc7F8sr9PWfk+wmfA+0Z8TeRcXbUYVlHpaP8G4eZkUXcvwTz9ldZ5PedkokyN061VgguTx3OSgXrEPJH6kOE8mNaYjoV9xRRIlyNBZZ6W8Ew8RuXReKMQ3uxVjr/dde437UjO+YpUyODeaQwQMp9KDvyqbuUF6q86grXoHtQovsEn5A==" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "autostart"... Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="completed keyexchange" Dec 15 14:30:12 adminvascosilva go-librespot[10354]: time="2025-12-15T14:30:12Z" level=debug msg="completed challenge" Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Applying required configuration parameters for plugin autostart Dec 15 14:30:12 adminvascosilva volumio[10282]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "outputs"... Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "albumart"... Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Plugin example_plugin is not enabled Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "inputs"... Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "updater_comm"... Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Plugin mpdemulation is not enabled Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "rest_api"... Dec 15 14:30:12 adminvascosilva volumio[10282]: info: Loading plugin "websocket"... Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Loading i18n strings for locale pt Dec 15 14:30:13 adminvascosilva volumio[10282]: Updating browse sources language Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::initPlayerControls Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: Express server listening on port 3000 Dec 15 14:30:13 adminvascosilva volumio[10282]: [Metrics] WebUI: 6s 202.24ms Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::resetVolumioState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::getcurrentVolume Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:30:13 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809010 101 Dec 15 14:30:13 adminvascosilva volumio[10361]: Forking 3 albumart workers Dec 15 14:30:13 adminvascosilva volumio[10282]: 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:30:13 adminvascosilva volumio[10282]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::pushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::updateTrackBlock Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrackBlock Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Reloading queue from file Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::pushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::setRandom true Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::pushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Setting Device type: Raspberry PI Dec 15 14:30:13 adminvascosilva volumio[10282]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreStateMachine::pushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Completed loading Core Plugins Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Preparing to generate the ALSA configuration file Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Discovery: Found device adminvascosilva Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Discovery: Found device adminvascosilva Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Output device has changed, restarting MPD Dec 15 14:30:13 adminvascosilva volumio[10282]: info: ___________ START PLUGINS ___________ Dec 15 14:30:13 adminvascosilva volumio[10282]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Creating MPD Configuration file Dec 15 14:30:13 adminvascosilva sudo[10418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:30:13 adminvascosilva sudo[10418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:13 adminvascosilva sudo[10418]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:13 adminvascosilva sudo[10419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:30:13 adminvascosilva sudo[10419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:30:13 adminvascosilva volumio[10282]: info: [1765809013920] CoreMusicLibrary::Adding element Last_100 Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:30:13 adminvascosilva volumio[10282]: info: [1765809013927] CoreMusicLibrary::Adding element Webradio Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:13 adminvascosilva sudo[10422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:30:13 adminvascosilva sudo[10422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:13 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:30:13 adminvascosilva volumio[10282]: info: Initializing BBC Radios Dec 15 14:30:13 adminvascosilva sudo[10422]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:13 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:30:13 adminvascosilva sudo[10424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:30:13 adminvascosilva sudo[10424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:14 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:30:14 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:14 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:30:14 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:30:14 adminvascosilva systemd[1]: mpd.service: Consumed 3.906s CPU time. Dec 15 14:30:14 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:30:14 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:30:14 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:30:14 adminvascosilva volumio[10282]: info: Creating Spotify config file Dec 15 14:30:14 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:14 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:30:14 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:30:14 adminvascosilva sudo[10442]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:30:14 adminvascosilva sudo[10442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:30:14 adminvascosilva sudo[10442]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:14 adminvascosilva volumio[10282]: info: AutoStart - onStart Dec 15 14:30:14 adminvascosilva volumio[10282]: info: Volumio Calling Home Dec 15 14:30:15 adminvascosilva volumio[10282]: info: MPD Permissions set Dec 15 14:30:15 adminvascosilva volumio[10282]: info: MPD Permissions set Dec 15 14:30:15 adminvascosilva volumio[10282]: info: Volumio called home Dec 15 14:30:15 adminvascosilva volumio[10282]: info: Spotify config file written Dec 15 14:30:15 adminvascosilva sudo[10449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:30:15 adminvascosilva sudo[10449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:15 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:30:15 adminvascosilva systemd[1]: go-librespot-daemon.service: Killing process 10359 (go-librespot) with signal SIGKILL. Dec 15 14:30:15 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:30:15 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:15 adminvascosilva volumio[10377]: Starting albumart workers Dec 15 14:30:15 adminvascosilva volumio[10282]: 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:30:15 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva go-librespot[10451]: go-librespot daemon starting... Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva sudo[10449]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:15 adminvascosilva volumio[10376]: Starting albumart workers Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="app state loaded" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:15 adminvascosilva volumio[10282]: info: No need to fix Spotify hosts Dec 15 14:30:15 adminvascosilva volumio[10379]: Starting albumart workers Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=info msg="zeroconf server listening on port 35289" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="obtained new client token: AABnZrtPFxUumTjayRODm7uX8mqiSrSpoCePAiwlOd60tp5nXBhPauhlELiirvIv4yakrs5DK3KEB2SftsdtVtnUJXkqmpzoy8F5gD7WlJvEKf5uV0qiB652h0ba8+Ki3DUCOu9tbq0Uc+kBSr5X+xka/22583DO5uxE3mKXZVYBH4Ah9xMs9L0vU7Kzv9EwRg1+L1NvGZbTr6QFinDAUeDTZfnVzPXvgSJ5KkTOICW+AnZBIM8PYw==" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="completed keyexchange" Dec 15 14:30:15 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:15Z" level=debug msg="completed challenge" Dec 15 14:30:16 adminvascosilva go-librespot[10452]: time="2025-12-15T14:30:16Z" 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:30:16 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:16 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:16 adminvascosilva volumio[10282]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:30:16 adminvascosilva volumio[10282]: SPOTIFY: BQDVbOI94DZyrVUDzMTBvPt58iViTZYYItA3tpRxT_8mipVRA5W5OXLi4asvOLikEff0a_pwBv-K0HbphAzw2d2NDfwXxzUud5-S-P86sTsJNbi_OwRnb0QLKz8jvraxmA7BsQUJYLU_V_aZC35E67KgEMYwIYPPxohY0_v7lvrjAg-IonNEGXIeaWwe9XMBU74hs2TnDwYppCJ2V6B17lXNZOqZlHuFS9_XBfdeht8HGYdMIDDP_0gCeqfSNhzfh4ysFo3WD7TNWh6m3a5_eiFO2OMCwk-V8tD9QQ Dec 15 14:30:16 adminvascosilva volumio[10282]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:30:16 adminvascosilva volumio[10282]: info: New Spotify access token = BQDVbOI94DZyrVUDzMTBvPt58iViTZYYItA3tpRxT_8mipVRA5W5OXLi4asvOLikEff0a_pwBv-K0HbphAzw2d2NDfwXxzUud5-S-P86sTsJNbi_OwRnb0QLKz8jvraxmA7BsQUJYLU_V_aZC35E67KgEMYwIYPPxohY0_v7lvrjAg-IonNEGXIeaWwe9XMBU74hs2TnDwYppCJ2V6B17lXNZOqZlHuFS9_XBfdeht8HGYdMIDDP_0gCeqfSNhzfh4ysFo3WD7TNWh6m3a5_eiFO2OMCwk-V8tD9QQ Dec 15 14:30:16 adminvascosilva volumio[10282]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:30:16 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:16 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:16 adminvascosilva volumio[10282]: 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:30:16 adminvascosilva volumio[10282]: info: Spotify Successfully logged in Dec 15 14:30:16 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:30:16 adminvascosilva volumio[10282]: info: [1765809016375] CoreMusicLibrary::Adding element Spotify Dec 15 14:30:16 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:16 adminvascosilva volumio[10282]: Cannot find translation for source Spotify Dec 15 14:30:18 adminvascosilva mpd[10444]: 2025-12-15T14:30:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:30:18 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:30:18 adminvascosilva sudo[10424]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:18 adminvascosilva sudo[10419]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:18 adminvascosilva volumio[10282]: info: Completed starting Core Plugins Dec 15 14:30:18 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:18 adminvascosilva volumio[10282]: info: ----- MyVolumio plugins startup ---- Dec 15 14:30:18 adminvascosilva volumio[10282]: info: ------------------------------------------- Dec 15 14:30:18 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:30:18 adminvascosilva volumio[10282]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:30:18 adminvascosilva volumio[10282]: assert.ok(self.idling) Dec 15 14:30:18 adminvascosilva volumio[10282]: error: The expression evaluated to a falsy value: Dec 15 14:30:18 adminvascosilva volumio[10282]: assert.ok(self.idling) Dec 15 14:30:18 adminvascosilva volumio[10282]: error: updateQueue error: null Dec 15 14:30:18 adminvascosilva volumio[10282]: info: MPD running with PID10444 Dec 15 14:30:18 adminvascosilva volumio[10282]: ,establishing connection Dec 15 14:30:18 adminvascosilva volumio[10282]: error: updateQueue error: null Dec 15 14:30:18 adminvascosilva volumio[10282]: info: go-librespot daemon successfully initialized Dec 15 14:30:19 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:30:19 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:19 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:19 adminvascosilva go-librespot[10493]: go-librespot daemon starting... Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="app state loaded" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=info msg="zeroconf server listening on port 33215" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="obtained new client token: AAD+EMlVA70OZWI4veJ3r85M47CyDXjCwF83XeoswdH81ChmV3eIcBJsA4htEfZsy2CM9DCVRpqy1uAEntRbFQCXzTbc8Tud1jKZljYMvFVxW3WBvuVrhuhQqzBjBu6eys0SUyogWWk9g8LjlV3io4JNweGZy4tL+K0D00IrNyikukZJUP4l7S8QYF5DY5GDJYqe86171PxDXc2F8774d+xigTvP4hS94Qq9gA9HhmEDE4szhmdjBw==" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="completed keyexchange" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" level=debug msg="completed challenge" Dec 15 14:30:19 adminvascosilva go-librespot[10494]: time="2025-12-15T14:30:19Z" 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:30:19 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:19 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:19 adminvascosilva sudo[10516]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:30:19 adminvascosilva sudo[10516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:19 adminvascosilva sudo[10518]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:30:19 adminvascosilva sudo[10518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:19 adminvascosilva sudo[10516]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:19 adminvascosilva sudo[10518]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:19 adminvascosilva sudo[10521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:30:19 adminvascosilva sudo[10521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:19 adminvascosilva sudo[10521]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:19 adminvascosilva volumio[10282]: info: Upmpdcli Daemon Started Dec 15 14:30:21 adminvascosilva sudo[10525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:30:21 adminvascosilva sudo[10525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:21 adminvascosilva sudo[10527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:30:21 adminvascosilva sudo[10527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:21 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:30:21 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:30:21 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:30:21 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:30:21 adminvascosilva sudo[10525]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:21 adminvascosilva mpd_monitor.sh[10530]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:30:21 adminvascosilva volumio[10282]: info: Successfully started MPD Monitor Dec 15 14:30:21 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:30:21 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:30:21 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:30:21 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:30:21 adminvascosilva sudo[10527]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:21 adminvascosilva mpd_monitor.sh[10533]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:30:21 adminvascosilva volumio[10282]: info: Successfully started MPD Monitor Dec 15 14:30:21 adminvascosilva volumio[10282]: info: Initializing connection to go-librespot Websocket Dec 15 14:30:21 adminvascosilva volumio[10282]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:30:22 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:30:22 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:22 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:22 adminvascosilva go-librespot[10537]: go-librespot daemon starting... Dec 15 14:30:22 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:22Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:22 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:22Z" level=debug msg="app state loaded" Dec 15 14:30:22 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:22Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=info msg="zeroconf server listening on port 39121" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="obtained new client token: AAAoaMPjpx6rBRPeFJlPgRltLf+/k9QMuY9zEVGZmg8i/iYmct1qnKJYMgWY+4G8GnPSRC2S3hmBGt69HhkJbGN/UCcl/u5nIctssL2Af7nXto9YrAvYpx5CPJ6AetmaXu/QsdBhv4ItaAWAzyoot92cmR6cGnAdw8/NIM/SAXB3WkzHJ3BZHoK93tX2kojZdfEcqljH6DsatKnCBzeVe87cgh6KZJURFUW7vB0wRe2YpUNNoy0=" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="completed keyexchange" Dec 15 14:30:23 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:23Z" level=debug msg="completed challenge" Dec 15 14:30:23 adminvascosilva volumio[10282]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:30:24 adminvascosilva volumio[10282]: info: Initializing connection to go-librespot Websocket Dec 15 14:30:24 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:24Z" level=debug msg="new websocket client" Dec 15 14:30:24 adminvascosilva volumio[10282]: info: Connection to go-librespot Websocket established Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:30:26 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:30:27 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:30:27 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:30:27 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:27 adminvascosilva volumio[10282]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:27 adminvascosilva volumio[10282]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:30:27 adminvascosilva volumio[10282]: info: MyVolumio login type: Token Dec 15 14:30:27 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:30:27 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:30:28 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:30:28 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:30:28 adminvascosilva volumio[10282]: info: Streaming services startup Dec 15 14:30:28 adminvascosilva volumio[10282]: info: Starting Streaming Daemon Dec 15 14:30:28 adminvascosilva sudo[10547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:30:28 adminvascosilva sudo[10547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:28 adminvascosilva volumio[10282]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:30:28 adminvascosilva sudo[10547]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:28 adminvascosilva volumio[10282]: info: Getting Spotify volume Dec 15 14:30:28 adminvascosilva volumio[10282]: error: Cannot start Volumio Streaming Daemon Dec 15 14:30:28 adminvascosilva volumio[10282]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:30:28 adminvascosilva volumio[10282]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:30:28 adminvascosilva volumio[10282]: 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:30:28 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:28 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:28 adminvascosilva volumio[10282]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:30:28 adminvascosilva volumio[10282]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:30:28 adminvascosilva volumio[10282]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:30:28 adminvascosilva volumio[10282]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:30:28 adminvascosilva volumio[10282]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:28 adminvascosilva volumio[10282]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:28 adminvascosilva volumio[10282]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:30:29 adminvascosilva go-librespot[10538]: time="2025-12-15T14:30:29Z" 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:30:29 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:29 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:29 adminvascosilva volumio[10282]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:30:29 adminvascosilva volumio[10282]: Error: socket hang up Dec 15 14:30:29 adminvascosilva volumio[10282]: at connResetException (node:internal/errors:720:14) Dec 15 14:30:29 adminvascosilva volumio[10282]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:30:29 adminvascosilva volumio[10282]: at Socket.emit (node:events:526:35) Dec 15 14:30:29 adminvascosilva volumio[10282]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:30:29 adminvascosilva volumio[10282]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:30:29 adminvascosilva volumio[10282]: code: 'ECONNRESET', Dec 15 14:30:29 adminvascosilva volumio[10282]: response: undefined Dec 15 14:30:29 adminvascosilva volumio[10282]: } Dec 15 14:30:29 adminvascosilva volumio[10282]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:30:29 adminvascosilva sudo[10582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:29' Dec 15 14:30:29 adminvascosilva sudo[10582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:29 adminvascosilva sudo[10582]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:30 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:30:30 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:30:30 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:30 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:30:30 adminvascosilva systemd[1]: volumio.service: Consumed 25.154s CPU time. Dec 15 14:30:30 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:30:30 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:30:30 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26. Dec 15 14:30:30 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:30:30 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:30:30 adminvascosilva systemd[1]: volumio.service: Consumed 25.154s CPU time. Dec 15 14:30:30 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:30:30 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:30:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:30:32 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:32 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:32 adminvascosilva go-librespot[10614]: go-librespot daemon starting... Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=debug msg="app state loaded" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30: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-gew4.spotify.com:80]" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" 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:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" 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:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=info msg="zeroconf server listening on port 37451" Dec 15 14:30:32 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:32 adminvascosilva volumio[10598]: info: ----- Volumio3 ---- Dec 15 14:30:32 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:32 adminvascosilva volumio[10598]: info: ----- System startup ---- Dec 15 14:30:32 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=debug msg="obtained new client token: AAAD/T1YdUqJig2hU+d9tIaCfXOvd8i/LjzMcD4cJCrG/L65y44EeV/8umU1vX3/F8tLd5klWk6ID3KfIhZf1gg1PpwjfXUkeG9XGr0GfqjHVNI3KSV2JwQo330k/5tW6XoL8yI6mXLjcgT0hPY5crBeFtiYlkvUwaSXC9bsfxI5ansR9FKhA0nh2X/LkZ68inORw3ISmrDIvLw7/zbzwQEdkCWM0ldr3/2M1w1kbmVQxbcZAVv0IQ==" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" 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:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=debug msg="completed keyexchange" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30:32Z" level=debug msg="completed challenge" Dec 15 14:30:32 adminvascosilva go-librespot[10615]: time="2025-12-15T14:30: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:30:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:33 adminvascosilva volumio[10598]: info: MYVOLUMIO Environment detected Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Plugin folders cleanup Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category audio_interface Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category miscellanea Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category music_service Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category plugins.json Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category system_controller Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category user_interface Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning into folder /data/plugins/ Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category music_service Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Scanning category system_controller Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Plugin folders cleanup completed Dec 15 14:30:33 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:33 adminvascosilva volumio[10598]: info: ----- Core plugins startup ---- Dec 15 14:30:33 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Loading plugins from folder /data/plugins/ Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Loading plugin "system"... Dec 15 14:30:33 adminvascosilva volumio[10598]: info: Loading plugin "appearance"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "network"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Refreshing Cached IP Addresses Dec 15 14:30:34 adminvascosilva sudo[10638]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:30:34 adminvascosilva sudo[10638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "services"... Dec 15 14:30:34 adminvascosilva sudo[10640]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:30:34 adminvascosilva sudo[10638]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "alsa_controller"... Dec 15 14:30:34 adminvascosilva sudo[10640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:34 adminvascosilva sudo[10640]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:34 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "wizard"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "networkfs"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Starting Udev Watcher for removable devices Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Ignoring mount for partition: boot Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Ignoring mount for partition: volumio Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Ignoring mount for partition: volumio_data Dec 15 14:30:34 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "upnp"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: [1765809034723] Starting Upmpd Daemon Dec 15 14:30:34 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "my_music"... Dec 15 14:30:34 adminvascosilva volumio[10598]: info: Loading plugin "mpd"... Dec 15 14:30:35 adminvascosilva volumio[10598]: info: Plugin upnp_browser is not enabled Dec 15 14:30:35 adminvascosilva volumio[10598]: info: Loading plugin "alarm-clock"... Dec 15 14:30:35 adminvascosilva volumio[10598]: info: Plugin airplay_emulation is not enabled Dec 15 14:30:35 adminvascosilva volumio[10598]: info: Loading plugin "last_100"... Dec 15 14:30:35 adminvascosilva volumio[10598]: info: Loading plugin "webradio"... Dec 15 14:30:35 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:35] [connect] Successful connection Dec 15 14:30:35 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 14:30:35 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:35 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:35 adminvascosilva go-librespot[10668]: go-librespot daemon starting... Dec 15 14:30:35 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:35Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:35 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:35Z" level=debug msg="app state loaded" Dec 15 14:30:35 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:35Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" 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:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" 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:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" 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:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" level=info msg="zeroconf server listening on port 38437" Dec 15 14:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" level=debug msg="obtained new client token: AABpu7HGPNrpnv9IzK4rsVoZT84+eFyd9cO2fYnwCujEJfIk2lE9P3fFJCeIPpYEMPiFsMRpW56MrTQ0bJ15S3GfsnbQt6cWfFIEleftTTTHMBSJtLe6IlEx5fwFVMFLP6iHP1wQ8JItC6EmnU7kx7cD9Cs+5ONiNbX08XFewj5RgWyIzdNOfR22hrbtIWeqmLj4UnST5AoPmGM82oRqalymKcczoOmIAOhL7wui28xa4goAJAE=" Dec 15 14:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" level=debug msg="completed keyexchange" Dec 15 14:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" level=debug msg="completed challenge" Dec 15 14:30:36 adminvascosilva go-librespot[10669]: time="2025-12-15T14:30:36Z" 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:30:36 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:36 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:36 adminvascosilva volumio[10598]: info: Loading plugin "i2s_dacs"... Dec 15 14:30:36 adminvascosilva volumio[10598]: info: I2S DAC not set, start Auto-detection Dec 15 14:30:36 adminvascosilva volumio[10598]: info: Loading plugin "volumiodiscovery"... Dec 15 14:30:36 adminvascosilva volumio[10598]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:30:36 adminvascosilva volumio[10598]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:36 adminvascosilva volumio[10598]: *** WARNING *** For more information see Dec 15 14:30:36 adminvascosilva volumio[10598]: *** 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:30:36 adminvascosilva volumio[10598]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:36 adminvascosilva volumio[10598]: *** WARNING *** For more information see Dec 15 14:30:36 adminvascosilva node[10598]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:30:36 adminvascosilva node[10598]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:36 adminvascosilva node[10598]: *** WARNING *** For more information see Dec 15 14:30:36 adminvascosilva node[10598]: *** 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:30:36 adminvascosilva node[10598]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:30:36 adminvascosilva node[10598]: *** WARNING *** For more information see Dec 15 14:30:36 adminvascosilva volumio[10598]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:30:36 adminvascosilva volumio[10598]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:30:36 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:30:36 adminvascosilva volumio[10598]: info: Loading plugin "spop"... Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Loading plugin "autostart"... Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Applying required configuration parameters for plugin autostart Dec 15 14:30:37 adminvascosilva volumio[10598]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Loading plugin "outputs"... Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Loading plugin "albumart"... Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Plugin example_plugin is not enabled Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Loading plugin "inputs"... Dec 15 14:30:37 adminvascosilva volumio[10598]: info: Loading plugin "updater_comm"... Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Plugin mpdemulation is not enabled Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Loading plugin "rest_api"... Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Loading plugin "websocket"... Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Loading i18n strings for locale pt Dec 15 14:30:38 adminvascosilva volumio[10598]: Updating browse sources language Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::initPlayerControls Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: Express server listening on port 3000 Dec 15 14:30:38 adminvascosilva volumio[10598]: [Metrics] WebUI: 6s 235.04ms Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::resetVolumioState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::getcurrentVolume Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:30:38 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:30:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809035 101 Dec 15 14:30:38 adminvascosilva volumio[10598]: 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:30:38 adminvascosilva volumio[10678]: Forking 3 albumart workers Dec 15 14:30:38 adminvascosilva volumio[10598]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::pushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::updateTrackBlock Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrackBlock Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::pushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::setRandom true Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::pushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Setting Device type: Raspberry PI Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Reloading queue from file Dec 15 14:30:38 adminvascosilva volumio[10598]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreStateMachine::pushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioPushState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Discovery: Found device adminvascosilva Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Completed loading Core Plugins Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Preparing to generate the ALSA configuration file Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Discovery: Found device adminvascosilva Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:38 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:30:38 adminvascosilva volumio[10598]: info: Output device has changed, restarting MPD Dec 15 14:30:38 adminvascosilva volumio[10598]: info: ___________ START PLUGINS ___________ Dec 15 14:30:39 adminvascosilva volumio[10598]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:30:39 adminvascosilva volumio[10598]: info: Creating MPD Configuration file Dec 15 14:30:39 adminvascosilva sudo[10738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:30:39 adminvascosilva sudo[10737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:30:39 adminvascosilva sudo[10737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:39 adminvascosilva sudo[10738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:39 adminvascosilva sudo[10737]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:30:39 adminvascosilva volumio[10598]: info: [1765809039069] CoreMusicLibrary::Adding element Last_100 Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:30:39 adminvascosilva volumio[10598]: info: [1765809039082] CoreMusicLibrary::Adding element Webradio Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:30:39 adminvascosilva volumio[10598]: info: Initializing BBC Radios Dec 15 14:30:39 adminvascosilva sudo[10742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:30:39 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:30:39 adminvascosilva sudo[10744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:30:39 adminvascosilva sudo[10744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:39 adminvascosilva sudo[10742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:39 adminvascosilva sudo[10742]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:39 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:30:39 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:30:39 adminvascosilva systemd[1]: mpd.service: Consumed 3.936s CPU time. Dec 15 14:30:39 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:30:39 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:30:39 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:39 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:30:39 adminvascosilva volumio[10598]: info: Creating Spotify config file Dec 15 14:30:39 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:39 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:30:39 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:30:39 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:30:39 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:30:39 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:30:39 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:30:39 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:30:39 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:30:39 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 14:30:39 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:39 adminvascosilva sudo[10763]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:30:39 adminvascosilva sudo[10763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:30:39 adminvascosilva sudo[10763]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:39 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:39 adminvascosilva go-librespot[10764]: go-librespot daemon starting... Dec 15 14:30:39 adminvascosilva go-librespot[10766]: time="2025-12-15T14:30:39Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:39 adminvascosilva volumio[10598]: info: AutoStart - onStart Dec 15 14:30:39 adminvascosilva volumio[10598]: info: Volumio Calling Home Dec 15 14:30:40 adminvascosilva go-librespot[10766]: time="2025-12-15T14:30:40Z" level=info msg="zeroconf server listening on port 34215" Dec 15 14:30:40 adminvascosilva volumio[10695]: Starting albumart workers Dec 15 14:30:40 adminvascosilva volumio[10598]: info: MPD Permissions set Dec 15 14:30:40 adminvascosilva volumio[10696]: Starting albumart workers Dec 15 14:30:40 adminvascosilva volumio[10598]: info: MPD Permissions set Dec 15 14:30:40 adminvascosilva volumio[10598]: info: Volumio called home Dec 15 14:30:40 adminvascosilva volumio[10598]: info: Spotify config file written Dec 15 14:30:40 adminvascosilva sudo[10778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:30:40 adminvascosilva sudo[10778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:40 adminvascosilva volumio[10598]: 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:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10697]: Starting albumart workers Dec 15 14:30:40 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva systemd[1]: Starting volumio-keepalive.service - Volumio KeepAlive (start playback if stopped)... Dec 15 14:30:40 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:30:40 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:40 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:40 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:30:40 adminvascosilva go-librespot[10796]: go-librespot daemon starting... Dec 15 14:30:40 adminvascosilva volumio[10598]: info: No need to fix Spotify hosts Dec 15 14:30:40 adminvascosilva sudo[10778]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:40 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:40Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:40 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:40Z" level=debug msg="app state loaded" Dec 15 14:30:40 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:40Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" 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:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" 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:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" 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:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" level=info msg="zeroconf server listening on port 40219" Dec 15 14:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" level=debug msg="obtained new client token: AAD0yXigxKaKtkG+M/+PML9cI4tDNsXhfYEn3YkRjCBy7trWlyfB862BHXO8najBT4im8Jz7aDhT9rG3FjNM1mL7+eC5biWDpW48BmllrRAzc4137CXxesHjkcKLCumJglEI91h8MLhJnajH7TL3t22pgzsRGwRcbtXRY5ZsjT6ixSw7kofS8dhmPyZgwa+NrhVjbbjRHT1SETBSZoWPHtCE27NaiS4oYm9yqoL0Xsx3Q6apz1biZQ==" Dec 15 14:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" level=debug msg="completed keyexchange" Dec 15 14:30:41 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:41Z" level=debug msg="completed challenge" Dec 15 14:30:41 adminvascosilva volumio[10598]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:30:41 adminvascosilva volumio[10598]: SPOTIFY: BQBUirtwYidwM_Ljv9Q01X_Yb62-PjawyPRqcKnV-nb3IrdSjtUArroPuqNVKXAXmeDUQ9lFmBwlWjA2l5gL4CGWn8kHeyxRWKfBx7SU3IIHiac4n4GhMDGujtUmm-ROwn2hcZ6U8wYNfdKgdIAhTrqPkmSCMY0oBwCgczmlPIz52XYofqdjrNJOHTNald-tx2pjn8yuZWO18AvVgRT8gOp7SkYzo-e25RL7OM2jeNHSjA0gaZU4L7ZyXPkMiJrZJcxHbDyUJBorSARUNzBU5eg_vmm5W3N3hdpAUg Dec 15 14:30:41 adminvascosilva volumio[10598]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:30:41 adminvascosilva volumio[10598]: info: New Spotify access token = BQBUirtwYidwM_Ljv9Q01X_Yb62-PjawyPRqcKnV-nb3IrdSjtUArroPuqNVKXAXmeDUQ9lFmBwlWjA2l5gL4CGWn8kHeyxRWKfBx7SU3IIHiac4n4GhMDGujtUmm-ROwn2hcZ6U8wYNfdKgdIAhTrqPkmSCMY0oBwCgczmlPIz52XYofqdjrNJOHTNald-tx2pjn8yuZWO18AvVgRT8gOp7SkYzo-e25RL7OM2jeNHSjA0gaZU4L7ZyXPkMiJrZJcxHbDyUJBorSARUNzBU5eg_vmm5W3N3hdpAUg Dec 15 14:30:41 adminvascosilva volumio[10598]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioGetState Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:41 adminvascosilva volumio[10598]: info: Dec 15 14:30:41 adminvascosilva volumio[10598]: ---------------------------- Client requests Volumio play Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioPlay Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CoreStateMachine::play index undefined Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:30:41 adminvascosilva volumio[10598]: info: CorePlayQueue::getTrack 0 Dec 15 14:30:41 adminvascosilva volumio[10598]: info: [1765809041980] ControllerSpotify::clearAddPlayTrack Dec 15 14:30:41 adminvascosilva volumio[10598]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:30:42 adminvascosilva systemd[1]: volumio-keepalive.service: Deactivated successfully. Dec 15 14:30:42 adminvascosilva systemd[1]: Finished volumio-keepalive.service - Volumio KeepAlive (start playback if stopped). Dec 15 14:30:42 adminvascosilva volumio[10598]: 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:30:42 adminvascosilva volumio[10598]: info: Spotify Successfully logged in Dec 15 14:30:42 adminvascosilva volumio[10598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:30:42 adminvascosilva volumio[10598]: info: [1765809042105] CoreMusicLibrary::Adding element Spotify Dec 15 14:30:42 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:30:42 adminvascosilva volumio[10598]: Cannot find translation for source Spotify Dec 15 14:30:42 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:42Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:30:43 adminvascosilva go-librespot[10798]: time="2025-12-15T14:30:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 14:30:43 adminvascosilva volumio[10598]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 15 14:30:43 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:43 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:43 adminvascosilva mpd[10769]: 2025-12-15T14:30:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:30:43 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:30:43 adminvascosilva sudo[10738]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:43 adminvascosilva sudo[10744]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:43 adminvascosilva volumio[10598]: info: Completed starting Core Plugins Dec 15 14:30:43 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:43 adminvascosilva volumio[10598]: info: ----- MyVolumio plugins startup ---- Dec 15 14:30:43 adminvascosilva volumio[10598]: info: ------------------------------------------- Dec 15 14:30:43 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:30:43 adminvascosilva volumio[10598]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:30:43 adminvascosilva volumio[10598]: assert.ok(self.idling) Dec 15 14:30:43 adminvascosilva volumio[10598]: error: The expression evaluated to a falsy value: Dec 15 14:30:43 adminvascosilva volumio[10598]: assert.ok(self.idling) Dec 15 14:30:43 adminvascosilva volumio[10598]: error: updateQueue error: null Dec 15 14:30:43 adminvascosilva volumio[10598]: info: MPD running with PID10769 Dec 15 14:30:43 adminvascosilva volumio[10598]: ,establishing connection Dec 15 14:30:43 adminvascosilva volumio[10598]: error: updateQueue error: null Dec 15 14:30:44 adminvascosilva volumio[10598]: info: go-librespot daemon successfully initialized Dec 15 14:30:44 adminvascosilva sudo[10851]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:30:44 adminvascosilva sudo[10851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:44 adminvascosilva sudo[10851]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:44 adminvascosilva sudo[10853]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:30:44 adminvascosilva sudo[10853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:44 adminvascosilva sudo[10853]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:44 adminvascosilva sudo[10856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:30:44 adminvascosilva sudo[10856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:44 adminvascosilva sudo[10856]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:44 adminvascosilva volumio[10598]: info: Upmpdcli Daemon Started Dec 15 14:30:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:30:46 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:46 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:46 adminvascosilva go-librespot[10861]: go-librespot daemon starting... Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=debug msg="app state loaded" Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:46 adminvascosilva sudo[10870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:30:46 adminvascosilva sudo[10870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:46 adminvascosilva sudo[10872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:30:46 adminvascosilva sudo[10872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:46 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:30:46 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:30:46 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30: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:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30: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:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30: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:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=info msg="zeroconf server listening on port 45999" Dec 15 14:30:46 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:30:46 adminvascosilva sudo[10870]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:46 adminvascosilva sudo[10872]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:46 adminvascosilva volumio[10598]: info: Successfully started MPD Monitor Dec 15 14:30:46 adminvascosilva mpd_monitor.sh[10875]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:30:46 adminvascosilva volumio[10598]: info: Successfully started MPD Monitor Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=debug msg="obtained new client token: AADu8n8ot8IH1o+SAzYmGnl6X4aQR2dV3uSgq8NDGCBh30NWHgBTGw8NR/vzZP8jV0LM6ndyn+JQmvcPgvBwvJQEEhRkGu2x1VIucuHT8/vrn/deZ2DqAr0Rdx+955vnonjQYjGF9tvXbq7WV7LUzRr2pnTWjQAepmPmIeiu0LKMz469NwumCGs/6II8EL8751uMpiRIykABxDtajuF48JfR+E5u49TqmPFzQ0uCedaM6MY90Piniw==" Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" 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:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=debug msg="completed keyexchange" Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30:46Z" level=debug msg="completed challenge" Dec 15 14:30:46 adminvascosilva go-librespot[10862]: time="2025-12-15T14:30: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:30:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:46 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:47 adminvascosilva volumio[10598]: info: Initializing connection to go-librespot Websocket Dec 15 14:30:47 adminvascosilva volumio[10598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:30:48 adminvascosilva volumio[10598]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:30:50 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:30:50 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:50 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:50 adminvascosilva go-librespot[10881]: go-librespot daemon starting... Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=debug msg="app state loaded" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" 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:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" 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:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" 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:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=info msg="zeroconf server listening on port 33897" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=debug msg="obtained new client token: AAC7q4cj7eH4zBYOzH8pQWmTZ8LH3rbHASP5jnoK8yZe/2X6L0x5LSUWbrVhrPC59eZmd4o0o8qjY4DV5Gdx91P6MA5lGEbo8x7OD1lEnaX2zI5xmtubf0Z2eZjWNIEtCsQcG90b/ZKs2hq4FHqADEfm6WVqSEjSI+OAZZ4IXqeygzc63XjQKD9mZZxPqrXXgAzyGH5Z/dBPfGktCGUhOrh2HpZvNUBhgugInAEobVtnInaGz7VdNw==" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=debug msg="completed keyexchange" Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=debug msg="completed challenge" Dec 15 14:30:50 adminvascosilva volumio[10598]: info: Initializing connection to go-librespot Websocket Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=debug msg="new websocket client" Dec 15 14:30:50 adminvascosilva volumio[10598]: info: Connection to go-librespot Websocket established Dec 15 14:30:50 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:50Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:30:51 adminvascosilva go-librespot[10882]: time="2025-12-15T14:30:51Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 14:30:51 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:30:51 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Connection to go-librespot Websocket closed Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:30:51 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:30:52 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:30:52 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:30:52 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:52 adminvascosilva volumio[10598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:30:52 adminvascosilva volumio[10598]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:30:52 adminvascosilva volumio[10598]: info: MyVolumio login type: Token Dec 15 14:30:52 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:30:52 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:30:53 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:30:53 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:30:53 adminvascosilva volumio[10598]: info: Streaming services startup Dec 15 14:30:53 adminvascosilva volumio[10598]: info: Starting Streaming Daemon Dec 15 14:30:53 adminvascosilva sudo[10891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:30:53 adminvascosilva sudo[10891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:53 adminvascosilva volumio[10598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:30:53 adminvascosilva sudo[10891]: pam_unix(sudo:session): session closed for user root Dec 15 14:30:53 adminvascosilva volumio[10598]: info: Getting Spotify volume Dec 15 14:30:53 adminvascosilva volumio[10598]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:30:53 adminvascosilva volumio[10598]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:30:53 adminvascosilva volumio[10598]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 14:30:53 adminvascosilva volumio[10598]: errno: -111, Dec 15 14:30:53 adminvascosilva volumio[10598]: code: 'ECONNREFUSED', Dec 15 14:30:53 adminvascosilva volumio[10598]: syscall: 'connect', Dec 15 14:30:53 adminvascosilva volumio[10598]: address: '127.0.0.1', Dec 15 14:30:53 adminvascosilva volumio[10598]: port: 9879, Dec 15 14:30:53 adminvascosilva volumio[10598]: response: undefined Dec 15 14:30:53 adminvascosilva volumio[10598]: } Dec 15 14:30:53 adminvascosilva volumio[10598]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:30:54 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:30:54 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:54 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:30:54 adminvascosilva go-librespot[10909]: go-librespot daemon starting... Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=debug msg="app state loaded" Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" 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:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" 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:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" 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:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=info msg="zeroconf server listening on port 45325" Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=debug msg="obtained new client token: AADHQnLzkvblpTPonDb1dKLQqRsIUOvp582ep8E1UDXLXJdVdl+2EcWLdVLattZMpFggif3urG4OvoPmJlxV6V+pT5Um4rYiIl2YF4Fle/vXTQC03yKRey78WZYpAaiYUuGLoretGBAHtW3RenCZHJ4CLAVnCRhr7wfg5tUvATf4qlBpUauZZVbufPtp2Q1UrI+anBzPV6dV9F+5n3cTwHIQ6Eb6WxxSrmUFXQlFP527FAyafBCQ+A==" Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:30:54 adminvascosilva sudo[10919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:29' Dec 15 14:30:54 adminvascosilva sudo[10919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=debug msg="completed keyexchange" Dec 15 14:30:54 adminvascosilva go-librespot[10910]: time="2025-12-15T14:30:54Z" level=debug msg="completed challenge" 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"