Dec 15 14:45:00 adminvascosilva volumio[20960]: info: Loading plugin "i2s_dacs"... Dec 15 14:45:00 adminvascosilva volumio[20960]: info: I2S DAC not set, start Auto-detection Dec 15 14:45:00 adminvascosilva volumio[20960]: info: Loading plugin "volumiodiscovery"... Dec 15 14:45:00 adminvascosilva volumio[20960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:45:00 adminvascosilva volumio[20960]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:00 adminvascosilva volumio[20960]: *** WARNING *** For more information see Dec 15 14:45:00 adminvascosilva volumio[20960]: *** 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:45:00 adminvascosilva volumio[20960]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:00 adminvascosilva volumio[20960]: *** WARNING *** For more information see Dec 15 14:45:00 adminvascosilva node[20960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:45:00 adminvascosilva node[20960]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:00 adminvascosilva node[20960]: *** WARNING *** For more information see Dec 15 14:45:00 adminvascosilva node[20960]: *** 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:45:00 adminvascosilva node[20960]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:00 adminvascosilva node[20960]: *** WARNING *** For more information see Dec 15 14:45:00 adminvascosilva volumio[20960]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:45:00 adminvascosilva volumio[20960]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" 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:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" 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:45:00 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:00 adminvascosilva volumio[20960]: info: Loading plugin "spop"... Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" level=info msg="zeroconf server listening on port 36697" Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" level=debug msg="obtained new client token: AABavA/m4qL0hm/RG8bc6mqKGMQYjgoXswYQb4DgCjXx4CaXtrUQZQWqBJ583GrcqDVfNhXC32Gddix1qU79/VkGciAb/gxNO1luhdbK6f/dytZRH0m+Yi6phE1eKrApT0FaUWhY+JG3u/IqPngvs7D+e+pi8DmXjSwamCj1ftdiYwSmUVg7tsb3eCoovvQTv2snPfPwxPfVilOTtNWF+LrADxO7YLURgFh63mLNLIB/dv+UlMg=" Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" level=debug msg="completed keyexchange" Dec 15 14:45:00 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45:00Z" level=debug msg="completed challenge" Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "autostart"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Applying required configuration parameters for plugin autostart Dec 15 14:45:01 adminvascosilva volumio[20960]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "outputs"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "albumart"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Plugin example_plugin is not enabled Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "inputs"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "updater_comm"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Plugin mpdemulation is not enabled Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "rest_api"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading plugin "websocket"... Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Loading i18n strings for locale pt Dec 15 14:45:01 adminvascosilva volumio[20960]: Updating browse sources language Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::initPlayerControls Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: Express server listening on port 3000 Dec 15 14:45:01 adminvascosilva volumio[20960]: [Metrics] WebUI: 6s 218.15ms Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreStateMachine::resetVolumioState Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreStateMachine::getcurrentVolume Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:45:01 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:01 adminvascosilva volumio[20960]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:45:01 adminvascosilva volumio[21038]: Forking 3 albumart workers Dec 15 14:45:01 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809898 101 Dec 15 14:45:02 adminvascosilva volumio[20960]: 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:45:02 adminvascosilva volumio[20960]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::pushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::updateTrackBlock Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrackBlock Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::pushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::setRandom true Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::pushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:02 adminvascosilva go-librespot[21028]: time="2025-12-15T14:45: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:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Setting Device type: Raspberry PI Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Reloading queue from file Dec 15 14:45:02 adminvascosilva volumio[20960]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreStateMachine::pushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Completed loading Core Plugins Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Preparing to generate the ALSA configuration file Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Discovery: Found device adminvascosilva Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Discovery: Found device adminvascosilva Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Output device has changed, restarting MPD Dec 15 14:45:02 adminvascosilva volumio[20960]: info: ___________ START PLUGINS ___________ Dec 15 14:45:02 adminvascosilva sudo[21100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:45:02 adminvascosilva volumio[20960]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Creating MPD Configuration file Dec 15 14:45:02 adminvascosilva sudo[21100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:02 adminvascosilva sudo[21101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:45:02 adminvascosilva sudo[21100]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:02 adminvascosilva sudo[21101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:45:02 adminvascosilva volumio[20960]: info: [1765809902710] CoreMusicLibrary::Adding element Last_100 Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:45:02 adminvascosilva sudo[21104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:45:02 adminvascosilva sudo[21104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:02 adminvascosilva volumio[20960]: info: [1765809902727] CoreMusicLibrary::Adding element Webradio Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:02 adminvascosilva sudo[21104]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Initializing BBC Radios Dec 15 14:45:02 adminvascosilva sudo[21106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:45:02 adminvascosilva sudo[21106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:02 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:45:02 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:45:02 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:45:02 adminvascosilva systemd[1]: mpd.service: Consumed 3.756s CPU time. Dec 15 14:45:02 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:45:02 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:45:02 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:02 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:45:02 adminvascosilva volumio[20960]: info: Creating Spotify config file Dec 15 14:45:02 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:02 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:45:03 adminvascosilva sudo[21124]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:45:03 adminvascosilva sudo[21124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:45:03 adminvascosilva sudo[21124]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:03 adminvascosilva volumio[20960]: info: AutoStart - onStart Dec 15 14:45:03 adminvascosilva volumio[20960]: info: Volumio Calling Home Dec 15 14:45:03 adminvascosilva volumio[21059]: Starting albumart workers Dec 15 14:45:03 adminvascosilva volumio[20960]: info: MPD Permissions set Dec 15 14:45:03 adminvascosilva volumio[20960]: info: MPD Permissions set Dec 15 14:45:03 adminvascosilva volumio[20960]: info: Volumio called home Dec 15 14:45:03 adminvascosilva volumio[20960]: info: Spotify config file written Dec 15 14:45:03 adminvascosilva volumio[20960]: 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:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva sudo[21131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:45:03 adminvascosilva sudo[21131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:03 adminvascosilva volumio[21058]: Starting albumart workers Dec 15 14:45:03 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[21060]: Starting albumart workers Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:03 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:04 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:04 adminvascosilva go-librespot[21138]: go-librespot daemon starting... Dec 15 14:45:04 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:04 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:04 adminvascosilva sudo[21131]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:04 adminvascosilva volumio[20960]: info: No need to fix Spotify hosts Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=debug msg="app state loaded" Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" 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:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" 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:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" 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:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=info msg="zeroconf server listening on port 38169" Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=debug msg="obtained new client token: AACpDY9DSI9hS5YTC58e5vCCO4a1mWQeBqv3yX/LgcQ3gckOP05gEXiBcDJ4zT/awoysRTyO3/T2GoAsf1LGCibX/v2nE+8ja4LSk59vNPTSE89lBfsiCoNXOGRA8EyLoNJ55QXLHVpCTGXyrG+l2HQnOlLdDI6gCcn9VtC0DGEjzpPCz3CEYwz035Y3wyJvbik63eZGKx8ugq7BcrmgMF5/npOTb0RaD2Lt8VPu2gSHkbwtE2bPXA==" Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:04 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:04 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=debug msg="completed keyexchange" Dec 15 14:45:04 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45:04Z" level=debug msg="completed challenge" Dec 15 14:45:06 adminvascosilva mpd[21126]: 2025-12-15T14:45:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:45:06 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:45:06 adminvascosilva sudo[21106]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:06 adminvascosilva sudo[21101]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:06 adminvascosilva volumio[20960]: info: Completed starting Core Plugins Dec 15 14:45:06 adminvascosilva volumio[20960]: info: ------------------------------------------- Dec 15 14:45:06 adminvascosilva volumio[20960]: info: ----- MyVolumio plugins startup ---- Dec 15 14:45:06 adminvascosilva volumio[20960]: info: ------------------------------------------- Dec 15 14:45:06 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:45:06 adminvascosilva volumio[20960]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:45:06 adminvascosilva volumio[20960]: assert.ok(self.idling) Dec 15 14:45:06 adminvascosilva volumio[20960]: error: The expression evaluated to a falsy value: Dec 15 14:45:06 adminvascosilva volumio[20960]: assert.ok(self.idling) Dec 15 14:45:06 adminvascosilva volumio[20960]: error: updateQueue error: null Dec 15 14:45:06 adminvascosilva volumio[20960]: info: MPD running with PID21126 Dec 15 14:45:06 adminvascosilva volumio[20960]: ,establishing connection Dec 15 14:45:06 adminvascosilva volumio[20960]: error: updateQueue error: null Dec 15 14:45:07 adminvascosilva volumio[20960]: info: go-librespot daemon successfully initialized Dec 15 14:45:08 adminvascosilva sudo[21189]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:45:08 adminvascosilva sudo[21189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:08 adminvascosilva sudo[21191]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:45:08 adminvascosilva sudo[21191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:08 adminvascosilva sudo[21189]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:08 adminvascosilva sudo[21191]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:08 adminvascosilva sudo[21193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:45:08 adminvascosilva sudo[21193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:08 adminvascosilva sudo[21193]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:08 adminvascosilva volumio[20960]: info: Upmpdcli Daemon Started Dec 15 14:45:08 adminvascosilva go-librespot[21144]: time="2025-12-15T14:45: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:45:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:09 adminvascosilva volumio[20960]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 15 14:45:09 adminvascosilva sudo[21200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:45:09 adminvascosilva sudo[21200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:09 adminvascosilva sudo[21202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:45:09 adminvascosilva sudo[21202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:09 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:45:09 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:45:09 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:45:09 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:45:09 adminvascosilva sudo[21200]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:10 adminvascosilva mpd_monitor.sh[21205]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:45:09 adminvascosilva sudo[21202]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:10 adminvascosilva volumio[20960]: info: Successfully started MPD Monitor Dec 15 14:45:10 adminvascosilva volumio[20960]: info: Successfully started MPD Monitor Dec 15 14:45:10 adminvascosilva volumio[20960]: info: Initializing connection to go-librespot Websocket Dec 15 14:45:10 adminvascosilva volumio[20960]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:45:11 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 15 14:45:11 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:11 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:11 adminvascosilva go-librespot[21212]: go-librespot daemon starting... Dec 15 14:45:11 adminvascosilva volumio[20960]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:45:11 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:11Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:11 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:11Z" level=debug msg="app state loaded" Dec 15 14:45:11 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:11Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" 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:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" 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:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" 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:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" level=info msg="zeroconf server listening on port 42869" Dec 15 14:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" level=debug msg="obtained new client token: AADRiRev/JhmX815uAxyqMaA8uCRTD9UdytsH9wZU8aWgcjSobajshpjjMQgDaJpmWV8y6DVTqhi8KloGaGdHhAVf8f9G4I/A3qyWnBEhBgEtUCPGFAViUYMG9RocSUki+5sc15V0220zTfpXQfx48SzDdHOdYeAs4uwpl5xdu/15qqoNT2Gja5LVM98IpoetY26g8NlopJ2uamUWe88T0UDb/CH4brW9SGKrZ1K2iiINsgsepQ=" Dec 15 14:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" 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:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" level=debug msg="completed keyexchange" Dec 15 14:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" level=debug msg="completed challenge" Dec 15 14:45:12 adminvascosilva go-librespot[21213]: time="2025-12-15T14:45:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:45:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:13 adminvascosilva volumio[20960]: info: Initializing connection to go-librespot Websocket Dec 15 14:45:13 adminvascosilva volumio[20960]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:45:15 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:45:16 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:45:16 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:45:16 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:16 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:16 adminvascosilva volumio[20960]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:45:16 adminvascosilva volumio[20960]: info: MyVolumio login type: Token Dec 15 14:45:16 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 15 14:45:16 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:16 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:45:16 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:45:16 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:16 adminvascosilva go-librespot[21220]: go-librespot daemon starting... Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=debug msg="app state loaded" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" 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:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" 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:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" 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:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=info msg="zeroconf server listening on port 40115" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=debug msg="obtained new client token: AACVDdXmJ5+uY7TGM52SPGWlFcuJJBk951U4+2bzuFfH6LeVaHu4lRtasyqDCQLWVykkl3SOtGkNV/5EnWcNGz7akxidfEcMxSZAJpHRT42uhinGswK8RpeXBpqz1R6Ucrpb49f6l/oenNpWMM21wOIyEZyvaadL5rxPR7HGR0b7M6gh501XTGr2i0Mmg5+owDyUDJLQ4Q/ucfb0eBYMnh3QGpphXGIGVVwXUyrnvMC5/XRKvdhXsA==" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=debug msg="completed keyexchange" Dec 15 14:45:16 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:16Z" level=debug msg="completed challenge" Dec 15 14:45:17 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:45:17 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:45:17 adminvascosilva volumio[20960]: info: Streaming services startup Dec 15 14:45:17 adminvascosilva volumio[20960]: info: Starting Streaming Daemon Dec 15 14:45:17 adminvascosilva sudo[21229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:45:17 adminvascosilva sudo[21229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:17 adminvascosilva volumio[20960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:45:17 adminvascosilva sudo[21229]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:17 adminvascosilva volumio[20960]: info: Initializing connection to go-librespot Websocket Dec 15 14:45:17 adminvascosilva volumio[20960]: error: Cannot start Volumio Streaming Daemon Dec 15 14:45:17 adminvascosilva volumio[20960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:45:17 adminvascosilva volumio[20960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:45:17 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:17Z" level=debug msg="new websocket client" Dec 15 14:45:17 adminvascosilva volumio[20960]: info: Connection to go-librespot Websocket established Dec 15 14:45:17 adminvascosilva volumio[20960]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:45:18 adminvascosilva volumio[20960]: info: MyVolumio token set successfully Dec 15 14:45:18 adminvascosilva volumio[20960]: info: MYVOLUMIO: Adding device Dec 15 14:45:18 adminvascosilva volumio[20960]: info: MYVOLUMIO: Evaluating Server Dec 15 14:45:18 adminvascosilva volumio[20960]: info: MyVolumio status changed Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Streaming services startup Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Starting Streaming Daemon Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Removing audio output: Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Stoppping Tunnel 1 Dec 15 14:45:18 adminvascosilva sudo[21272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:45:18 adminvascosilva sudo[21272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:18 adminvascosilva sudo[21272]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:18 adminvascosilva sudo[21275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:45:18 adminvascosilva sudo[21275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:18 adminvascosilva volumio[20960]: error: Cannot start Volumio Streaming Daemon Dec 15 14:45:18 adminvascosilva volumio[20960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:45:18 adminvascosilva volumio[20960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:45:18 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:45:18 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:45:18 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:45:18 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:45:18 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:45:18 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:45:18 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:45:18 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:45:18 adminvascosilva sudo[21275]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Remote SSH Stopped Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Setting Geolocation for MyVolumio to eu2 Dec 15 14:45:18 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:18 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:18 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:18 adminvascosilva volumio[20960]: info: Successfully Added MyVolumio device Dec 15 14:45:19 adminvascosilva volumio[20960]: info: Updating MyVolumio device info Dec 15 14:45:19 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:19 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:19 adminvascosilva volumio[20960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:19 adminvascosilva volumio[20960]: info: Successfully Updated MyVolumio device Dec 15 14:45:20 adminvascosilva volumio[20960]: info: Getting Spotify volume Dec 15 14:45:20 adminvascosilva volumio[20960]: 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:45:20 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:20 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:20 adminvascosilva volumio[20960]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:45:20 adminvascosilva volumio[20960]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:45:20 adminvascosilva volumio[20960]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:45:20 adminvascosilva volumio[20960]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:45:20 adminvascosilva volumio[20960]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:20 adminvascosilva volumio[20960]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:20 adminvascosilva volumio[20960]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:45:20 adminvascosilva go-librespot[21221]: time="2025-12-15T14:45:20Z" 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:45:20 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:20 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:20 adminvascosilva volumio[20960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:45:20 adminvascosilva volumio[20960]: Error: socket hang up Dec 15 14:45:20 adminvascosilva volumio[20960]: at connResetException (node:internal/errors:720:14) Dec 15 14:45:20 adminvascosilva volumio[20960]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:45:20 adminvascosilva volumio[20960]: at Socket.emit (node:events:526:35) Dec 15 14:45:20 adminvascosilva volumio[20960]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:45:20 adminvascosilva volumio[20960]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:45:20 adminvascosilva volumio[20960]: code: 'ECONNRESET', Dec 15 14:45:20 adminvascosilva volumio[20960]: response: undefined Dec 15 14:45:20 adminvascosilva volumio[20960]: } Dec 15 14:45:20 adminvascosilva volumio[20960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:45:21 adminvascosilva sudo[21292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:44' Dec 15 14:45:21 adminvascosilva sudo[21292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:21 adminvascosilva sudo[21292]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:21 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:45:21 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:45:21 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:21 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:45:21 adminvascosilva systemd[1]: volumio.service: Consumed 25.822s CPU time. Dec 15 14:45:21 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:45:21 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:45:21 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 57. Dec 15 14:45:21 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:45:21 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:45:21 adminvascosilva systemd[1]: volumio.service: Consumed 25.822s CPU time. Dec 15 14:45:21 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:45:21 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:45:23 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:23 adminvascosilva volumio[21305]: info: ----- Volumio3 ---- Dec 15 14:45:23 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:23 adminvascosilva volumio[21305]: info: ----- System startup ---- Dec 15 14:45:23 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:23 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 15 14:45:23 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:23 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:23 adminvascosilva go-librespot[21326]: go-librespot daemon starting... Dec 15 14:45:23 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:23Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:23 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:23Z" level=debug msg="app state loaded" Dec 15 14:45:23 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:23Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" 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:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" 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:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" 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:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" level=info msg="zeroconf server listening on port 45587" Dec 15 14:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" level=debug msg="obtained new client token: AADDe15hrdVNVB5+mnXEX7I3lYLLd8Y04YXn19OhErf98kKjuazxGSv2bRb69yECFZ5Bze4Bnv3WA1VhbCov+TlFpgSLFiT3mrjd1PTdrn7lEqFxtsnfD2gAjZJPGEbPg5UgarlGvAhtBHYrjXwsSqnhoo42Uk9Kfyka7DajE9NA+PRcJ22I7QDRnBfodiM1Hqs6j3lP0/ZGbUQj+zglT3Jzt6GGGem9TAIQBUwI45k1qmASJvaiCA==" Dec 15 14:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" level=debug msg="completed keyexchange" Dec 15 14:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" level=debug msg="completed challenge" Dec 15 14:45:24 adminvascosilva volumio[21305]: info: MYVOLUMIO Environment detected Dec 15 14:45:24 adminvascosilva go-librespot[21327]: time="2025-12-15T14:45:24Z" 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:45:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Plugin folders cleanup Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category audio_interface Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category miscellanea Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category music_service Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category plugins.json Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category system_controller Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category user_interface Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning into folder /data/plugins/ Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category music_service Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Scanning category system_controller Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Plugin folders cleanup completed Dec 15 14:45:24 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:24 adminvascosilva volumio[21305]: info: ----- Core plugins startup ---- Dec 15 14:45:24 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Loading plugins from folder /data/plugins/ Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Loading plugin "system"... Dec 15 14:45:24 adminvascosilva volumio[21305]: info: Loading plugin "appearance"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "network"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Refreshing Cached IP Addresses Dec 15 14:45:25 adminvascosilva sudo[21342]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:45:25 adminvascosilva sudo[21342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "services"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "alsa_controller"... Dec 15 14:45:25 adminvascosilva sudo[21342]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:25 adminvascosilva sudo[21344]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:45:25 adminvascosilva sudo[21344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:25 adminvascosilva sudo[21344]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:25 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "wizard"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "networkfs"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Starting Udev Watcher for removable devices Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Ignoring mount for partition: boot Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Ignoring mount for partition: volumio Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Ignoring mount for partition: volumio_data Dec 15 14:45:25 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "upnp"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: [1765809925981] Starting Upmpd Daemon Dec 15 14:45:25 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "my_music"... Dec 15 14:45:25 adminvascosilva volumio[21305]: info: Loading plugin "mpd"... Dec 15 14:45:26 adminvascosilva volumio[21305]: info: Plugin upnp_browser is not enabled Dec 15 14:45:26 adminvascosilva volumio[21305]: info: Loading plugin "alarm-clock"... Dec 15 14:45:26 adminvascosilva volumio[21305]: info: Plugin airplay_emulation is not enabled Dec 15 14:45:26 adminvascosilva volumio[21305]: info: Loading plugin "last_100"... Dec 15 14:45:26 adminvascosilva volumio[21305]: info: Loading plugin "webradio"... Dec 15 14:45:26 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:26] [connect] Successful connection Dec 15 14:45:27 adminvascosilva volumio[21305]: info: Loading plugin "i2s_dacs"... Dec 15 14:45:27 adminvascosilva volumio[21305]: info: I2S DAC not set, start Auto-detection Dec 15 14:45:27 adminvascosilva volumio[21305]: info: Loading plugin "volumiodiscovery"... Dec 15 14:45:27 adminvascosilva volumio[21305]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:45:27 adminvascosilva node[21305]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:45:27 adminvascosilva volumio[21305]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:27 adminvascosilva node[21305]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:27 adminvascosilva volumio[21305]: *** WARNING *** For more information see Dec 15 14:45:27 adminvascosilva node[21305]: *** WARNING *** For more information see Dec 15 14:45:27 adminvascosilva volumio[21305]: *** 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:45:27 adminvascosilva node[21305]: *** 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:45:27 adminvascosilva volumio[21305]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:27 adminvascosilva node[21305]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:27 adminvascosilva volumio[21305]: *** WARNING *** For more information see Dec 15 14:45:27 adminvascosilva node[21305]: *** WARNING *** For more information see Dec 15 14:45:27 adminvascosilva volumio[21305]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:45:27 adminvascosilva volumio[21305]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:45:27 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 15 14:45:27 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:27 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:27 adminvascosilva volumio[21305]: info: Loading plugin "spop"... Dec 15 14:45:27 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:27 adminvascosilva go-librespot[21374]: go-librespot daemon starting... Dec 15 14:45:27 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:27Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:27 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:27Z" level=debug msg="app state loaded" Dec 15 14:45:27 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:27Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" 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:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" 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:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=info msg="zeroconf server listening on port 35673" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=debug msg="obtained new client token: AABLcM3wh/oegjjef+It8ulPacPSj4cYMvRmaSj49I2rFe+p/EXZOBHmG4jw7roWUA2Nc3c4DbZJ/kA2NXkuMdB4cpPVrCIH7sUfmKkCpqRFlKgLvlK2x595TMicM7SPbHjsFWUp7yXsxz0J1buM1GQw+ONiircqK+qc29GAgKBprQPtcKO2E3qlmpav5OKED27DyXZbq5Rt03Wm53u5/+dTcFqZzb3WxNLq7wMBvUPe3BQqT5FiGA==" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=debug msg="completed keyexchange" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=debug msg="completed challenge" Dec 15 14:45:28 adminvascosilva go-librespot[21376]: time="2025-12-15T14:45:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 15 14:45:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:28 adminvascosilva volumio[21305]: info: Loading plugin "autostart"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Applying required configuration parameters for plugin autostart Dec 15 14:45:29 adminvascosilva volumio[21305]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading plugin "outputs"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading plugin "albumart"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Plugin example_plugin is not enabled Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading plugin "inputs"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading plugin "updater_comm"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Plugin mpdemulation is not enabled Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading plugin "rest_api"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading plugin "websocket"... Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Loading i18n strings for locale pt Dec 15 14:45:29 adminvascosilva volumio[21305]: Updating browse sources language Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::initPlayerControls Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: Express server listening on port 3000 Dec 15 14:45:29 adminvascosilva volumio[21305]: [Metrics] WebUI: 6s 234.32ms Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreStateMachine::resetVolumioState Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreStateMachine::getcurrentVolume Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:29 adminvascosilva volumio[21305]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:45:29 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809926 101 Dec 15 14:45:29 adminvascosilva volumio[21383]: Forking 3 albumart workers Dec 15 14:45:29 adminvascosilva volumio[21305]: 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:45:29 adminvascosilva volumio[21305]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreStateMachine::pushState Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreStateMachine::updateTrackBlock Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrackBlock Dec 15 14:45:29 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Reloading queue from file Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreStateMachine::pushState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreStateMachine::setRandom true Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreStateMachine::pushState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Setting Device type: Raspberry PI Dec 15 14:45:30 adminvascosilva volumio[21305]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreStateMachine::pushState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Completed loading Core Plugins Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Preparing to generate the ALSA configuration file Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Discovery: Found device adminvascosilva Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Discovery: Found device adminvascosilva Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Output device has changed, restarting MPD Dec 15 14:45:30 adminvascosilva volumio[21305]: info: ___________ START PLUGINS ___________ Dec 15 14:45:30 adminvascosilva volumio[21305]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Creating MPD Configuration file Dec 15 14:45:30 adminvascosilva sudo[21444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:45:30 adminvascosilva sudo[21444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:30 adminvascosilva sudo[21444]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:30 adminvascosilva sudo[21445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:45:30 adminvascosilva sudo[21445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:30 adminvascosilva volumio[21305]: info: [1765809930390] CoreMusicLibrary::Adding element Last_100 Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:45:30 adminvascosilva volumio[21305]: info: [1765809930396] CoreMusicLibrary::Adding element Webradio Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:30 adminvascosilva sudo[21447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:45:30 adminvascosilva sudo[21447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:30 adminvascosilva sudo[21450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:45:30 adminvascosilva sudo[21450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Initializing BBC Radios Dec 15 14:45:30 adminvascosilva sudo[21447]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:30 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:45:30 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:45:30 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:45:30 adminvascosilva systemd[1]: mpd.service: Consumed 3.773s CPU time. Dec 15 14:45:30 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:45:30 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:45:30 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:30 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:45:30 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:45:30 adminvascosilva volumio[21305]: info: Creating Spotify config file Dec 15 14:45:30 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:30 adminvascosilva sudo[21468]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:45:30 adminvascosilva sudo[21468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:45:30 adminvascosilva sudo[21468]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:31 adminvascosilva volumio[21305]: info: AutoStart - onStart Dec 15 14:45:31 adminvascosilva volumio[21305]: info: Volumio Calling Home Dec 15 14:45:31 adminvascosilva volumio[21399]: Starting albumart workers Dec 15 14:45:31 adminvascosilva volumio[21305]: info: MPD Permissions set Dec 15 14:45:31 adminvascosilva volumio[21305]: info: MPD Permissions set Dec 15 14:45:31 adminvascosilva volumio[21305]: info: Spotify config file written Dec 15 14:45:31 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 15 14:45:31 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:31 adminvascosilva volumio[21401]: Starting albumart workers Dec 15 14:45:31 adminvascosilva sudo[21475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:45:31 adminvascosilva sudo[21475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:31 adminvascosilva volumio[21305]: 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:45:31 adminvascosilva volumio[21305]: info: Volumio called home Dec 15 14:45:31 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva go-librespot[21476]: go-librespot daemon starting... Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva go-librespot[21478]: time="2025-12-15T14:45:31Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:31 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:45:31 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:45:31 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:31 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:31 adminvascosilva go-librespot[21489]: go-librespot daemon starting... Dec 15 14:45:31 adminvascosilva sudo[21475]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:31 adminvascosilva volumio[21305]: info: No need to fix Spotify hosts Dec 15 14:45:31 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:31Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:31 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:31Z" level=debug msg="app state loaded" Dec 15 14:45:31 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:31Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:32 adminvascosilva volumio[21400]: Starting albumart workers Dec 15 14:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" 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:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" 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:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" 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:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" level=info msg="zeroconf server listening on port 44897" Dec 15 14:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" level=debug msg="obtained new client token: AAAF6JCedBTdWWjH30tif6BNRv3Z2+1k9zUEyhEBv8cMJ4pHlPkrBhQIYRzFDhrDrcJI+5YRIIMpAo6GtPoyGm2rkucWIekDKFa/rj9px5R6EtgLCE5hDCrh7kRzkwkdhfoHzEuXa/x+QjtVUnqsklFtwDnRBpqxGbzxM6YEXS/lh3fmtTQzIdaOcVu0pBWX4ZJU+OJg3qHXIDce23AcjiEKx5mX5vgFD7gt5Xo3D+7BnewjSIzN1g==" Dec 15 14:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" level=debug msg="completed keyexchange" Dec 15 14:45:32 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:32Z" level=debug msg="completed challenge" Dec 15 14:45:32 adminvascosilva volumio[21305]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 15 14:45:32 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:32 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:34 adminvascosilva go-librespot[21490]: time="2025-12-15T14:45:34Z" 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:45:34 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:34 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:34 adminvascosilva mpd[21470]: 2025-12-15T14:45:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:45:34 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:45:34 adminvascosilva sudo[21445]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:34 adminvascosilva sudo[21450]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:34 adminvascosilva volumio[21305]: info: Completed starting Core Plugins Dec 15 14:45:34 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:34 adminvascosilva volumio[21305]: info: ----- MyVolumio plugins startup ---- Dec 15 14:45:34 adminvascosilva volumio[21305]: info: ------------------------------------------- Dec 15 14:45:34 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:45:34 adminvascosilva volumio[21305]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:45:34 adminvascosilva volumio[21305]: assert.ok(self.idling) Dec 15 14:45:34 adminvascosilva volumio[21305]: error: The expression evaluated to a falsy value: Dec 15 14:45:34 adminvascosilva volumio[21305]: assert.ok(self.idling) Dec 15 14:45:34 adminvascosilva volumio[21305]: error: updateQueue error: null Dec 15 14:45:34 adminvascosilva volumio[21305]: info: MPD running with PID21470 Dec 15 14:45:34 adminvascosilva volumio[21305]: ,establishing connection Dec 15 14:45:34 adminvascosilva volumio[21305]: error: updateQueue error: null Dec 15 14:45:35 adminvascosilva volumio[21305]: info: go-librespot daemon successfully initialized Dec 15 14:45:36 adminvascosilva sudo[21543]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:45:36 adminvascosilva sudo[21543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:36 adminvascosilva sudo[21543]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:36 adminvascosilva sudo[21545]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:45:36 adminvascosilva sudo[21545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:36 adminvascosilva sudo[21545]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:36 adminvascosilva sudo[21548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:45:36 adminvascosilva sudo[21548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:36 adminvascosilva sudo[21548]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:36 adminvascosilva volumio[21305]: info: Upmpdcli Daemon Started Dec 15 14:45:37 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:45:37 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:37 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:37 adminvascosilva go-librespot[21553]: go-librespot daemon starting... Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=debug msg="app state loaded" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" 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:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" 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:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=info msg="zeroconf server listening on port 40261" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=debug msg="obtained new client token: AACSdHsEDUzzDswsd2Em/aY/BwbQEj85auOPycZrO0CXOb5Ur2w1tm0Aye0xomnR1ZKpKEA4Yh3o8rkOAE+XXSCxLeXAwJArr8q7V5r8obYaPQlCyRQblNaPItaaoDdNvQ5X3kFDjofbv4SG2yY1AV9e8c3g/z7X+/f2tgCliHayWoZBarkkiSXW7q23pMw98oaYYB0m2cLIHiOrqxomVEwCbdD59e8luAHNnbVTdFx2m8DbxulxIg==" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=debug msg="completed keyexchange" Dec 15 14:45:37 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:37Z" level=debug msg="completed challenge" Dec 15 14:45:37 adminvascosilva sudo[21562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:45:37 adminvascosilva sudo[21562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:37 adminvascosilva sudo[21564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:45:37 adminvascosilva sudo[21564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:37 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:45:37 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:45:37 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:45:37 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:45:37 adminvascosilva sudo[21562]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:37 adminvascosilva sudo[21564]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:37 adminvascosilva mpd_monitor.sh[21567]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:45:37 adminvascosilva volumio[21305]: info: Successfully started MPD Monitor Dec 15 14:45:37 adminvascosilva volumio[21305]: info: Successfully started MPD Monitor Dec 15 14:45:38 adminvascosilva volumio[21305]: info: Initializing connection to go-librespot Websocket Dec 15 14:45:38 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:38Z" level=debug msg="new websocket client" Dec 15 14:45:38 adminvascosilva volumio[21305]: info: Connection to go-librespot Websocket established Dec 15 14:45:39 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:39Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:45:39 adminvascosilva volumio[21305]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:45:41 adminvascosilva volumio[21305]: info: Getting Spotify volume Dec 15 14:45:41 adminvascosilva volumio[21305]: 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:45:41 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:41 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:41 adminvascosilva volumio[21305]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:45:41 adminvascosilva volumio[21305]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:45:41 adminvascosilva volumio[21305]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:45:41 adminvascosilva volumio[21305]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:45:41 adminvascosilva volumio[21305]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:41 adminvascosilva volumio[21305]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:41 adminvascosilva volumio[21305]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:45:42 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:45:43 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:45:43 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:45:43 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:43 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:43 adminvascosilva volumio[21305]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:45:43 adminvascosilva volumio[21305]: info: MyVolumio login type: Token Dec 15 14:45:43 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:45:43 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:45:44 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:45:44 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:45:44 adminvascosilva volumio[21305]: info: Streaming services startup Dec 15 14:45:44 adminvascosilva volumio[21305]: info: Starting Streaming Daemon Dec 15 14:45:44 adminvascosilva sudo[21576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:45:44 adminvascosilva sudo[21576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:44 adminvascosilva volumio[21305]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:45:44 adminvascosilva sudo[21576]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:44 adminvascosilva volumio[21305]: SPOTIFY: SETTING SPOTIFY VOLUME 25 Dec 15 14:45:44 adminvascosilva volumio[21305]: info: Sending Spotify command with payload to local API: /player/volume Dec 15 14:45:44 adminvascosilva volumio[21305]: error: Cannot start Volumio Streaming Daemon Dec 15 14:45:44 adminvascosilva volumio[21305]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:45:44 adminvascosilva volumio[21305]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:45:45 adminvascosilva volumio[21305]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:45:46 adminvascosilva volumio[21305]: info: MyVolumio token set successfully Dec 15 14:45:46 adminvascosilva volumio[21305]: info: MYVOLUMIO: Adding device Dec 15 14:45:46 adminvascosilva volumio[21305]: info: MYVOLUMIO: Evaluating Server Dec 15 14:45:46 adminvascosilva volumio[21305]: info: MyVolumio status changed Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Streaming services startup Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Starting Streaming Daemon Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Removing audio output: Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Stoppping Tunnel 1 Dec 15 14:45:46 adminvascosilva sudo[21618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:45:46 adminvascosilva sudo[21618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:46 adminvascosilva sudo[21620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:45:46 adminvascosilva sudo[21620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:46 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:45:46 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:45:46 adminvascosilva sudo[21618]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:46 adminvascosilva volumio[21305]: error: Cannot start Volumio Streaming Daemon Dec 15 14:45:46 adminvascosilva volumio[21305]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:45:46 adminvascosilva volumio[21305]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:45:46 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:45:46 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:45:46 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:45:46 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:45:46 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:45:46 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:45:46 adminvascosilva sudo[21620]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Remote SSH Stopped Dec 15 14:45:46 adminvascosilva volumio[21305]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:45:46 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:46 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:46 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:47 adminvascosilva volumio[21305]: info: Successfully Added MyVolumio device Dec 15 14:45:47 adminvascosilva volumio[21305]: info: Updating MyVolumio device info Dec 15 14:45:47 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:47 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:47 adminvascosilva volumio[21305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:48 adminvascosilva volumio[21305]: info: Successfully Updated MyVolumio device Dec 15 14:45:48 adminvascosilva go-librespot[21554]: time="2025-12-15T14:45:48Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 14:45:48 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:48 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:48 adminvascosilva volumio[21305]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 15 14:45:48 adminvascosilva volumio[21305]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:45:48 adminvascosilva volumio[21305]: Error: socket hang up Dec 15 14:45:48 adminvascosilva volumio[21305]: at connResetException (node:internal/errors:720:14) Dec 15 14:45:48 adminvascosilva volumio[21305]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:45:48 adminvascosilva volumio[21305]: at Socket.emit (node:events:526:35) Dec 15 14:45:48 adminvascosilva volumio[21305]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:45:48 adminvascosilva volumio[21305]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:45:48 adminvascosilva volumio[21305]: code: 'ECONNRESET', Dec 15 14:45:48 adminvascosilva volumio[21305]: response: undefined Dec 15 14:45:48 adminvascosilva volumio[21305]: } Dec 15 14:45:48 adminvascosilva volumio[21305]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:45:49 adminvascosilva sudo[21637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:44' Dec 15 14:45:49 adminvascosilva sudo[21637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:49 adminvascosilva sudo[21637]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:49 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:49] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:45:49 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:49] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:45:49 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:49 adminvascosilva systemd[1]: Starting volumio-keepalive.service - Volumio KeepAlive (start playback if stopped)... Dec 15 14:45:49 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:45:49 adminvascosilva systemd[1]: volumio.service: Consumed 25.583s CPU time. Dec 15 14:45:49 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:45:49 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:45:49 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 58. Dec 15 14:45:49 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:45:49 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:45:49 adminvascosilva systemd[1]: volumio.service: Consumed 25.583s CPU time. Dec 15 14:45:49 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:45:49 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:45:49 adminvascosilva systemd[1]: volumio-keepalive.service: Deactivated successfully. Dec 15 14:45:49 adminvascosilva systemd[1]: Finished volumio-keepalive.service - Volumio KeepAlive (start playback if stopped). Dec 15 14:45:51 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:45:51 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:51 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:51 adminvascosilva go-librespot[21675]: go-librespot daemon starting... Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=debug msg="app state loaded" Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:51 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:45:51 adminvascosilva volumio[21657]: info: ----- Volumio3 ---- Dec 15 14:45:51 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:45:51 adminvascosilva volumio[21657]: info: ----- System startup ---- Dec 15 14:45:51 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" 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:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" 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:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" 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:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=info msg="zeroconf server listening on port 34377" Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=debug msg="obtained new client token: AACkO+egvi1G7Xqk0O4spaG6zTfJ9q0/3Za2TAZ/8FXiX6sm+wtsQf4eaZzcMcXaZKjGhEDpIHxzyjJjEz4GB7vPKzeFwQq6HZje1qTb9KLSl9t1UU+7VdAM8M+/GnbRa8S1UX2LoOXaDlz0sRwucNCShCXoiD5wjTcn20tdGVzxgDP8E2fHhm0BPEXUfuxfVKiIbsNihnny0TQGbNFon8qExaXnOF0II7FCVJ5IkF5NslScufyWNA==" Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=debug msg="completed keyexchange" Dec 15 14:45:51 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45:51Z" level=debug msg="completed challenge" Dec 15 14:45:52 adminvascosilva volumio[21657]: info: MYVOLUMIO Environment detected Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Plugin folders cleanup Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category audio_interface Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category miscellanea Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category music_service Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category plugins.json Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category system_controller Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category user_interface Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning into folder /data/plugins/ Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category music_service Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Scanning category system_controller Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Plugin folders cleanup completed Dec 15 14:45:52 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:45:52 adminvascosilva volumio[21657]: info: ----- Core plugins startup ---- Dec 15 14:45:52 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Loading plugins from folder /data/plugins/ Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Loading plugin "system"... Dec 15 14:45:52 adminvascosilva volumio[21657]: info: Loading plugin "appearance"... Dec 15 14:45:53 adminvascosilva go-librespot[21676]: time="2025-12-15T14:45: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:45:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:53 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "network"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Refreshing Cached IP Addresses Dec 15 14:45:53 adminvascosilva sudo[21696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:45:53 adminvascosilva sudo[21696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:53 adminvascosilva sudo[21698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:45:53 adminvascosilva sudo[21696]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:53 adminvascosilva sudo[21698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "services"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "alsa_controller"... Dec 15 14:45:53 adminvascosilva sudo[21698]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:53 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "wizard"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "networkfs"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Starting Udev Watcher for removable devices Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Ignoring mount for partition: boot Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Ignoring mount for partition: volumio Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Ignoring mount for partition: volumio_data Dec 15 14:45:53 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "upnp"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: [1765809953848] Starting Upmpd Daemon Dec 15 14:45:53 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "my_music"... Dec 15 14:45:53 adminvascosilva volumio[21657]: info: Loading plugin "mpd"... Dec 15 14:45:54 adminvascosilva volumio[21657]: info: Plugin upnp_browser is not enabled Dec 15 14:45:54 adminvascosilva volumio[21657]: info: Loading plugin "alarm-clock"... Dec 15 14:45:54 adminvascosilva volumio[21657]: info: Plugin airplay_emulation is not enabled Dec 15 14:45:54 adminvascosilva volumio[21657]: info: Loading plugin "last_100"... Dec 15 14:45:54 adminvascosilva volumio[21657]: info: Loading plugin "webradio"... Dec 15 14:45:54 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:54] [connect] Successful connection Dec 15 14:45:55 adminvascosilva volumio[21657]: info: Loading plugin "i2s_dacs"... Dec 15 14:45:55 adminvascosilva volumio[21657]: info: I2S DAC not set, start Auto-detection Dec 15 14:45:55 adminvascosilva volumio[21657]: info: Loading plugin "volumiodiscovery"... Dec 15 14:45:55 adminvascosilva volumio[21657]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:45:55 adminvascosilva volumio[21657]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:55 adminvascosilva volumio[21657]: *** WARNING *** For more information see Dec 15 14:45:55 adminvascosilva volumio[21657]: *** 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:45:55 adminvascosilva volumio[21657]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:55 adminvascosilva volumio[21657]: *** WARNING *** For more information see Dec 15 14:45:55 adminvascosilva node[21657]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:45:55 adminvascosilva node[21657]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:55 adminvascosilva node[21657]: *** WARNING *** For more information see Dec 15 14:45:55 adminvascosilva node[21657]: *** 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:45:55 adminvascosilva node[21657]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:45:55 adminvascosilva node[21657]: *** WARNING *** For more information see Dec 15 14:45:55 adminvascosilva volumio[21657]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:45:55 adminvascosilva volumio[21657]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:45:55 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:45:55 adminvascosilva volumio[21657]: info: Loading plugin "spop"... Dec 15 14:45:56 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:45:56 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:56 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:45:56 adminvascosilva go-librespot[21728]: go-librespot daemon starting... Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=debug msg="app state loaded" Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" 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:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" 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:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" 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:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=info msg="zeroconf server listening on port 41083" Dec 15 14:45:56 adminvascosilva volumio[21657]: info: Loading plugin "autostart"... Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=debug msg="obtained new client token: AACbMoG+Q2/wuNXoAZIcsGjvG4VnyVz0UsBZYtwSV7KRWYjHZKUW9Pb2bzmAQ+zWxHasAFoB4jWsUBv0sf04k/Wz2cTZzA4jiULypuZdaqyQcTistqwibnkkZ51mFKtxVOdiYNNOU2k7kpbUMewHOspr3EKpXNCH7OPCqrsnw9FyF53KDdK9wz5fSOqjiumjOfW9EAWkDv0eDA7Gq9+LUUOuH43IfB0xQkrMvVQUfVtcFgnroIw3yA==" Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=debug msg="completed keyexchange" Dec 15 14:45:56 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45:56Z" level=debug msg="completed challenge" Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Applying required configuration parameters for plugin autostart Dec 15 14:45:57 adminvascosilva volumio[21657]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading plugin "outputs"... Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading plugin "albumart"... Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Plugin example_plugin is not enabled Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading plugin "inputs"... Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading plugin "updater_comm"... Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Plugin mpdemulation is not enabled Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading plugin "rest_api"... Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading plugin "websocket"... Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Loading i18n strings for locale pt Dec 15 14:45:57 adminvascosilva volumio[21657]: Updating browse sources language Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::initPlayerControls Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: Express server listening on port 3000 Dec 15 14:45:57 adminvascosilva volumio[21657]: [Metrics] WebUI: 6s 305.26ms Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::resetVolumioState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::getcurrentVolume Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:45:57 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:45:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809954 101 Dec 15 14:45:57 adminvascosilva volumio[21737]: Forking 3 albumart workers Dec 15 14:45:57 adminvascosilva volumio[21657]: 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:45:57 adminvascosilva volumio[21657]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::pushState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::updateTrackBlock Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrackBlock Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:45:57 adminvascosilva go-librespot[21729]: time="2025-12-15T14:45: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:45:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:45:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::pushState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::setRandom true Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreStateMachine::pushState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:57 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Reloading queue from file Dec 15 14:45:57 adminvascosilva volumio[21657]: info: Setting Device type: Raspberry PI Dec 15 14:45:58 adminvascosilva volumio[21657]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreStateMachine::pushState Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioPushState Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Completed loading Core Plugins Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Preparing to generate the ALSA configuration file Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Discovery: Found device adminvascosilva Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Discovery: Found device adminvascosilva Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioGetState Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Output device has changed, restarting MPD Dec 15 14:45:58 adminvascosilva volumio[21657]: info: ___________ START PLUGINS ___________ Dec 15 14:45:58 adminvascosilva volumio[21657]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Creating MPD Configuration file Dec 15 14:45:58 adminvascosilva sudo[21797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:45:58 adminvascosilva sudo[21799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:45:58 adminvascosilva sudo[21797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:45:58 adminvascosilva volumio[21657]: info: [1765809958264] CoreMusicLibrary::Adding element Last_100 Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:58 adminvascosilva sudo[21799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:58 adminvascosilva sudo[21797]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:45:58 adminvascosilva volumio[21657]: info: [1765809958289] CoreMusicLibrary::Adding element Webradio Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:45:58 adminvascosilva sudo[21802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:58 adminvascosilva sudo[21802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Initializing BBC Radios Dec 15 14:45:58 adminvascosilva sudo[21803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:45:58 adminvascosilva sudo[21803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:45:58 adminvascosilva sudo[21802]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:58 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:45:58 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:45:58 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:45:58 adminvascosilva systemd[1]: mpd.service: Consumed 3.801s CPU time. Dec 15 14:45:58 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:45:58 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:45:58 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:45:58 adminvascosilva volumio[21657]: info: Creating Spotify config file Dec 15 14:45:58 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:45:58 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:45:58 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:45:58 adminvascosilva sudo[21822]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:45:58 adminvascosilva sudo[21822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:45:58 adminvascosilva sudo[21822]: pam_unix(sudo:session): session closed for user root Dec 15 14:45:58 adminvascosilva systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 15 14:45:59 adminvascosilva volumio[21657]: info: AutoStart - onStart Dec 15 14:45:59 adminvascosilva volumio[21657]: info: Volumio Calling Home Dec 15 14:45:59 adminvascosilva volumio[21753]: Starting albumart workers Dec 15 14:45:59 adminvascosilva volumio[21755]: Starting albumart workers Dec 15 14:46:00 adminvascosilva volumio[21657]: info: MPD Permissions set Dec 15 14:46:00 adminvascosilva volumio[21657]: info: MPD Permissions set Dec 15 14:46:00 adminvascosilva volumio[21657]: info: Volumio called home Dec 15 14:46:00 adminvascosilva volumio[21657]: info: Spotify config file written Dec 15 14:46:00 adminvascosilva sudo[21853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:46:00 adminvascosilva sudo[21853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:00 adminvascosilva volumio[21754]: Starting albumart workers Dec 15 14:46:00 adminvascosilva volumio[21657]: 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:46:00 adminvascosilva systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 15 14:46:00 adminvascosilva systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 15 14:46:00 adminvascosilva systemd[1]: setdatetime-helper.service: Consumed 1.247s CPU time. Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:00 adminvascosilva go-librespot[21859]: go-librespot daemon starting... Dec 15 14:46:00 adminvascosilva sudo[21853]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" level=debug msg="app state loaded" Dec 15 14:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:46:00 adminvascosilva volumio[21657]: info: No need to fix Spotify hosts Dec 15 14:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" 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:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" 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:46:00 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:00Z" level=info msg="zeroconf server listening on port 37075" Dec 15 14:46:01 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:01Z" level=debug msg="obtained new client token: AADdZ2NT+5oyl6Mxrz4yvOtRARxXzfM5kLkxIuX9kSfhpFOVi+WxBAB1FSI2d6RHYCxEWyGx8jtLuQB1pUjrry+RxN6o8KA9aTA+Q5/NSlEcQaujOw/XLpwknue96oINLKtU7HrAdnXedivC3ttGa/Wqi0EgIXVf3PGGza1xz9t+UKyyIcfPQaOG2H7oC2/2vMmTkoaM6jvViXrbaojpa/fXFHtJuWaBHs6BwLWT247NZCNQpS0=" Dec 15 14:46:01 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:46:01 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioGetState Dec 15 14:46:01 adminvascosilva volumio[21657]: info: CorePlayQueue::getTrack 0 Dec 15 14:46:01 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:01Z" level=debug msg="completed keyexchange" Dec 15 14:46:01 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46:01Z" level=debug msg="completed challenge" Dec 15 14:46:01 adminvascosilva go-librespot[21868]: time="2025-12-15T14:46: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:46:01 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:46:01 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:46:01 adminvascosilva volumio[21657]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:46:01 adminvascosilva volumio[21657]: SPOTIFY: BQDyC-ZIFLN10B97d8gPy-i-OcF309oInEWrM_duQBBsk7uXWpCQjUY27VLSSftQf-2UEM-1i6FvVrUbdp3896aaT3xnyyJTYE7UT0XCyq308bm54DUQV966Pf5RS7jmWoXELFENZXZ9sg613Nz4PrkDPMlan7emoKnBNjzZ_FFrLMiI25oWYO7UnNYZdgm2JZlF6AHzxXjAQ5yumo9DEySC7XRU4bwXoG5wRlEU-Bt2BkyCxn2BFj-INDBBKbG29RY90LcwomB4RrnkXBv6Kt-kT8yDlGxxUF9BdA Dec 15 14:46:01 adminvascosilva volumio[21657]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:46:01 adminvascosilva volumio[21657]: info: New Spotify access token = BQDyC-ZIFLN10B97d8gPy-i-OcF309oInEWrM_duQBBsk7uXWpCQjUY27VLSSftQf-2UEM-1i6FvVrUbdp3896aaT3xnyyJTYE7UT0XCyq308bm54DUQV966Pf5RS7jmWoXELFENZXZ9sg613Nz4PrkDPMlan7emoKnBNjzZ_FFrLMiI25oWYO7UnNYZdgm2JZlF6AHzxXjAQ5yumo9DEySC7XRU4bwXoG5wRlEU-Bt2BkyCxn2BFj-INDBBKbG29RY90LcwomB4RrnkXBv6Kt-kT8yDlGxxUF9BdA Dec 15 14:46:01 adminvascosilva volumio[21657]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:46:02 adminvascosilva volumio[21657]: 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:46:02 adminvascosilva volumio[21657]: info: Spotify Successfully logged in Dec 15 14:46:02 adminvascosilva volumio[21657]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:46:02 adminvascosilva volumio[21657]: info: [1765809962019] CoreMusicLibrary::Adding element Spotify Dec 15 14:46:02 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:46:02 adminvascosilva volumio[21657]: Cannot find translation for source Spotify Dec 15 14:46:02 adminvascosilva mpd[21824]: 2025-12-15T14:46:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:46:02 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:46:02 adminvascosilva sudo[21799]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:02 adminvascosilva sudo[21803]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:02 adminvascosilva volumio[21657]: info: Completed starting Core Plugins Dec 15 14:46:02 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:46:02 adminvascosilva volumio[21657]: info: ----- MyVolumio plugins startup ---- Dec 15 14:46:02 adminvascosilva volumio[21657]: info: ------------------------------------------- Dec 15 14:46:02 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:46:02 adminvascosilva volumio[21657]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:46:02 adminvascosilva volumio[21657]: assert.ok(self.idling) Dec 15 14:46:02 adminvascosilva volumio[21657]: error: The expression evaluated to a falsy value: Dec 15 14:46:02 adminvascosilva volumio[21657]: assert.ok(self.idling) Dec 15 14:46:02 adminvascosilva volumio[21657]: info: MPD running with PID21824 Dec 15 14:46:02 adminvascosilva volumio[21657]: ,establishing connection Dec 15 14:46:02 adminvascosilva volumio[21657]: error: updateQueue error: null Dec 15 14:46:02 adminvascosilva volumio[21657]: error: updateQueue error: null Dec 15 14:46:03 adminvascosilva sudo[21917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:46:03 adminvascosilva sudo[21917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:03 adminvascosilva sudo[21919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:46:03 adminvascosilva sudo[21917]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:03 adminvascosilva sudo[21919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:03 adminvascosilva sudo[21919]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:03 adminvascosilva sudo[21922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:46:03 adminvascosilva sudo[21922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:03 adminvascosilva sudo[21922]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:03 adminvascosilva volumio[21657]: info: Upmpdcli Daemon Started Dec 15 14:46:03 adminvascosilva volumio[21657]: info: go-librespot daemon successfully initialized Dec 15 14:46:04 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 14:46:04 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:04 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:04 adminvascosilva go-librespot[21927]: go-librespot daemon starting... Dec 15 14:46:04 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:04Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:46:04 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:04Z" level=debug msg="app state loaded" Dec 15 14:46:04 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:04Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" 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:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" 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:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" 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:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" level=info msg="zeroconf server listening on port 41523" Dec 15 14:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" level=debug msg="obtained new client token: AACO7yfz3y18Yjyv/IPMy0j6MaB+UKe39HXUHsL0FinXKvdZKdzRzAzDJgY8xDhUhyM3Ps+Ww1dP2tzYzx5rMg4sLuitXpHPjaVjJ19ATtx7RIMjI3aBP0XrSMoNo1WitNrKBQQXC0LNYTFbka0Dd6OhoMMKRJ0kmnwvPs27S50R4W5N/HvdLwVfMJWKSFfqbvNuLbzt2PlDQK86G8Fwm3U8KDoFVRs7cmhwq5lQ0kE4hW2DQ8o=" Dec 15 14:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" level=debug msg="completed keyexchange" Dec 15 14:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46:05Z" level=debug msg="completed challenge" Dec 15 14:46:05 adminvascosilva go-librespot[21928]: time="2025-12-15T14:46: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:46:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:46:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:46:05 adminvascosilva sudo[21936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:46:05 adminvascosilva sudo[21936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:05 adminvascosilva sudo[21938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:46:05 adminvascosilva sudo[21938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:05 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:46:05 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:46:05 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:46:05 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:46:05 adminvascosilva sudo[21936]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:05 adminvascosilva mpd_monitor.sh[21941]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:46:05 adminvascosilva sudo[21938]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:05 adminvascosilva volumio[21657]: info: Successfully started MPD Monitor Dec 15 14:46:05 adminvascosilva volumio[21657]: info: Successfully started MPD Monitor Dec 15 14:46:06 adminvascosilva volumio[21657]: info: Initializing connection to go-librespot Websocket Dec 15 14:46:07 adminvascosilva volumio[21657]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:46:07 adminvascosilva volumio[21657]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:46:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 14:46:08 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:08 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:08 adminvascosilva go-librespot[21947]: go-librespot daemon starting... Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=debug msg="app state loaded" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=info msg="zeroconf server listening on port 36487" Dec 15 14:46:08 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:08Z" level=debug msg="obtained new client token: AAD7SPqE1o/QlkfIJXO1BxV3b2hfvjg8Y4sMq1egyJJiO2zJU4WDcm7GY/vmhtkwSJI4udEQw6j1LOwB5U7na/nOp3fB1YSaIVeu1vXB4snxun/cCrKtQN7AWR97H9uXzfAnXaZnudGfe9fblBTTka+TiKZLt4lP02W6A+AisdAu8HLxjXVyIFVfgXZCp2WvpEgbcQ0lLnTk4V3v0fvpIPO1gBV+JrDmIV+sYeYjsjw+tIWFetdgbg==" Dec 15 14:46:09 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:46:09 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:09Z" level=debug msg="completed keyexchange" Dec 15 14:46:09 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:09Z" level=debug msg="completed challenge" Dec 15 14:46:09 adminvascosilva go-librespot[21948]: time="2025-12-15T14:46:09Z" 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:46:09 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:46:09 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Initializing connection to go-librespot Websocket Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:46:10 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:46:11 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:46:11 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:46:11 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:11 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:11 adminvascosilva volumio[21657]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:46:11 adminvascosilva volumio[21657]: info: MyVolumio login type: Token Dec 15 14:46:11 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:46:11 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:46:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 14:46:12 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:12 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:46:12 adminvascosilva go-librespot[21955]: go-librespot daemon starting... Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=debug msg="app state loaded" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" 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:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" 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:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=info msg="zeroconf server listening on port 36215" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=debug msg="obtained new client token: AACRnKyB94tpcpBlId9YBN82I6Lsx3om7Qn6Tv0YMYKL38/Bm88+tW2tEIGJivGSwLYdk6cH8dT1plMnz7SNb+BRgUyM+r2sRUwA3bjtSYJ3insEWZACyWkXXaEGEWZU0x6Z5DlVg2JIWNG7K7hvALANKz8Sk5WBbX48Fy3QrTkopp7yOA4PaWaVxPLcj5oPT+gMkSnmaeLUZ3sfEU7kEmx/+kuaImLxQ4fq168dU/Y4C2U7aJoSbQ==" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" 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:46:12 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:46:12 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:46:12 adminvascosilva volumio[21657]: info: Streaming services startup Dec 15 14:46:12 adminvascosilva volumio[21657]: info: Starting Streaming Daemon Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:46:12 adminvascosilva sudo[21965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:46:12 adminvascosilva sudo[21965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:12 adminvascosilva volumio[21657]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=debug msg="completed keyexchange" Dec 15 14:46:12 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:12Z" level=debug msg="completed challenge" Dec 15 14:46:12 adminvascosilva sudo[21965]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:12 adminvascosilva volumio[21657]: error: Cannot start Volumio Streaming Daemon Dec 15 14:46:12 adminvascosilva volumio[21657]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:46:12 adminvascosilva volumio[21657]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:46:13 adminvascosilva volumio[21657]: info: Initializing connection to go-librespot Websocket Dec 15 14:46:13 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:13Z" level=debug msg="new websocket client" Dec 15 14:46:13 adminvascosilva volumio[21657]: info: Connection to go-librespot Websocket established Dec 15 14:46:13 adminvascosilva volumio[21657]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:46:13 adminvascosilva volumio[21657]: info: MyVolumio token set successfully Dec 15 14:46:13 adminvascosilva volumio[21657]: info: MYVOLUMIO: Adding device Dec 15 14:46:13 adminvascosilva volumio[21657]: info: MYVOLUMIO: Evaluating Server Dec 15 14:46:14 adminvascosilva volumio[21657]: info: MyVolumio status changed Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Streaming services startup Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Starting Streaming Daemon Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Removing audio output: Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Stoppping Tunnel 1 Dec 15 14:46:14 adminvascosilva sudo[22006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:46:14 adminvascosilva sudo[22006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:14 adminvascosilva sudo[22006]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:14 adminvascosilva sudo[22009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:46:14 adminvascosilva sudo[22009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:46:14 adminvascosilva volumio[21657]: error: Cannot start Volumio Streaming Daemon Dec 15 14:46:14 adminvascosilva volumio[21657]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:46:14 adminvascosilva volumio[21657]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:46:14 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:46:14 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:46:14 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:46:14 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:46:14 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:46:14 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:46:14 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:46:14 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:46:14 adminvascosilva sudo[22009]: pam_unix(sudo:session): session closed for user root Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Remote SSH Stopped Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:46:14 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:14 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:14 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:14 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:14Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:46:14 adminvascosilva go-librespot[21956]: time="2025-12-15T14:46:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 14:46:14 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:46:14 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Connection to go-librespot Websocket closed Dec 15 14:46:14 adminvascosilva volumio[21657]: info: Successfully Added MyVolumio device Dec 15 14:46:15 adminvascosilva volumio[21657]: info: Updating MyVolumio device info Dec 15 14:46:15 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:15 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:15 adminvascosilva volumio[21657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:46:15 adminvascosilva volumio[21657]: info: Successfully Updated MyVolumio device Dec 15 14:46:16 adminvascosilva volumio[21657]: info: Getting Spotify volume Dec 15 14:46:16 adminvascosilva volumio[21657]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:46:16 adminvascosilva volumio[21657]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:46:16 adminvascosilva volumio[21657]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 14:46:16 adminvascosilva volumio[21657]: errno: -111, Dec 15 14:46:16 adminvascosilva volumio[21657]: code: 'ECONNREFUSED', Dec 15 14:46:16 adminvascosilva volumio[21657]: syscall: 'connect', Dec 15 14:46:16 adminvascosilva volumio[21657]: address: '127.0.0.1', Dec 15 14:46:16 adminvascosilva volumio[21657]: port: 9879, Dec 15 14:46:16 adminvascosilva volumio[21657]: response: undefined Dec 15 14:46:16 adminvascosilva volumio[21657]: } Dec 15 14:46:16 adminvascosilva volumio[21657]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:46:16 adminvascosilva sudo[22025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:45' Dec 15 14:46:16 adminvascosilva sudo[22025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Nov 8 06:10:52 UTC 2025" VOLUMIO_VERSION="4.067" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="78c9815e90cf3bee23e5cdc5934a01e9"